openai/codex
1
0
Fork 0
mirror of https://github.com/openai/codex.git synced 2026-10-27 18:48:37 +00:00
Code Issues Packages Projects Releases Wiki Activity

Merge 6033f53637 into sapling-pr-archive-rhan-oai

Browse Source
This commit is contained in:
rhan-oai
2026-04-20 14:20:14 -07:00
committed by GitHub
parent 3c32c2e341 6033f53637
commit 638386fbf5
22 changed files with 275 additions and 61 deletions
Download Patch File Download Diff File Expand all files Collapse all files
codex-rs/app-server-protocol/src/protocol/thread_history.rs
+16
View File
@@ -1357,6 +1357,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
];
@@ -1431,6 +1432,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
];
@@ -1754,6 +1756,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
];
@@ -2264,6 +2267,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
EventMsg::TurnStarted(TurnStartedEvent {
turn_id: "turn-b".into(),
@@ -2301,6 +2305,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
];
@@ -2353,6 +2358,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
EventMsg::TurnStarted(TurnStartedEvent {
turn_id: "turn-b".into(),
@@ -2390,6 +2396,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
];
@@ -2564,6 +2571,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
EventMsg::TurnStarted(TurnStartedEvent {
turn_id: "turn-b".into(),
@@ -2582,6 +2590,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
EventMsg::AgentMessage(AgentMessageEvent {
message: "still in b".into(),
@@ -2593,6 +2602,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
];
@@ -2627,6 +2637,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
EventMsg::TurnStarted(TurnStartedEvent {
turn_id: "turn-b".into(),
@@ -2683,6 +2694,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
];
@@ -2928,6 +2940,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
EventMsg::Error(ErrorEvent {
message: "request-level failure".into(),
@@ -2987,6 +3000,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
];
@@ -3038,6 +3052,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
];
@@ -3086,6 +3101,7 @@ mod tests {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
];
codex-rs/app-server/src/bespoke_event_handling.rs
+1
View File
@@ -3074,6 +3074,7 @@ mod tests {
last_agent_message: None,
completed_at: Some(TEST_TURN_COMPLETED_AT),
duration_ms: Some(TEST_TURN_DURATION_MS),
time_to_first_token_ms: None,
}
}
codex-rs/core/src/agent/control_tests.rs
+3
View File
@@ -279,6 +279,7 @@ async fn on_event_updates_status_from_task_complete() {
last_agent_message: Some("done".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}));
let expected = AgentStatus::Completed(Some("done".to_string()));
assert_eq!(status, Some(expected));
@@ -1229,6 +1230,7 @@ async fn multi_agent_v2_completion_ignores_dead_direct_parent() {
last_agent_message: Some("done".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
)
.await;
@@ -1315,6 +1317,7 @@ async fn multi_agent_v2_completion_queues_message_for_direct_parent() {
last_agent_message: Some("done".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
)
.await;
codex-rs/core/src/guardian/analytics.rs
+2 -2
View File
@@ -158,9 +158,9 @@ impl GuardianReviewAnalyticsResult {
guardian_model: Some(metadata.guardian_model),
guardian_reasoning_effort: metadata.guardian_reasoning_effort,
had_prior_review_context: Some(metadata.had_prior_review_context),
reviewed_action_truncated: false,
reviewed_action_truncated: metadata.reviewed_action_truncated,
token_usage: metadata.token_usage,
time_to_first_token_ms: None,
time_to_first_token_ms: metadata.time_to_first_token_ms,
completed_at: metadata.completed_at,
}
}
codex-rs/core/src/guardian/approval_request.rs
+42 -22
View File
@@ -167,32 +167,49 @@ fn guardian_command_source_tool_name(source: GuardianCommandSource) -> &'static
}
}
fn truncate_guardian_action_value(value: Value) -> Value {
fn truncate_guardian_action_value(value: Value) -> (Value, bool) {
match value {
Value::String(text) => Value::String(guardian_truncate_text(
&text,
GUARDIAN_MAX_ACTION_STRING_TOKENS,
)),
Value::Array(values) => Value::Array(
values
Value::String(text) => {
let (text, truncated) =
guardian_truncate_text(&text, GUARDIAN_MAX_ACTION_STRING_TOKENS);
(Value::String(text), truncated)
}
Value::Array(values) => {
let mut truncated = false;
let values = values
.into_iter()
.map(truncate_guardian_action_value)
.collect::<Vec<_>>(),
),
.map(|value| {
let (value, value_truncated) = truncate_guardian_action_value(value);
truncated |= value_truncated;
value
})
.collect::<Vec<_>>();
(Value::Array(values), truncated)
}
Value::Object(values) => {
let mut entries = values.into_iter().collect::<Vec<_>>();
entries.sort_by(|(left, _), (right, _)| left.cmp(right));
Value::Object(
entries
.into_iter()
.map(|(key, value)| (key, truncate_guardian_action_value(value)))
.collect(),
)
let mut truncated = false;
let values = entries
.into_iter()
.map(|(key, value)| {
let (value, value_truncated) = truncate_guardian_action_value(value);
truncated |= value_truncated;
(key, value)
})
.collect();
(Value::Object(values), truncated)
}
other => other,
other => (other, false),
}
}
#[derive(Debug, Clone, PartialEq, Eq)]
pub(crate) struct FormattedGuardianAction {
pub(crate) text: String,
pub(crate) truncated: bool,
}
pub(crate) fn guardian_approval_request_to_json(
action: &GuardianApprovalRequest,
) -> serde_json::Result<Value> {
@@ -382,10 +399,13 @@ pub(crate) fn guardian_request_turn_id<'a>(
}
}
pub(crate) fn format_guardian_action_pretty(
pub(crate) fn format_guardian_action_pretty_with_truncation(
action: &GuardianApprovalRequest,
) -> serde_json::Result<String> {
let mut value = guardian_approval_request_to_json(action)?;
value = truncate_guardian_action_value(value);
serde_json::to_string_pretty(&value)
) -> serde_json::Result<FormattedGuardianAction> {
let value = guardian_approval_request_to_json(action)?;
let (value, truncated) = truncate_guardian_action_value(value);
Ok(FormattedGuardianAction {
text: serde_json::to_string_pretty(&value)?,
truncated,
})
}
codex-rs/core/src/guardian/mod.rs
+1 -1
View File
@@ -63,7 +63,7 @@ pub(crate) struct GuardianRejection {
}
#[cfg(test)]
use approval_request::format_guardian_action_pretty;
use approval_request::format_guardian_action_pretty_with_truncation;
#[cfg(test)]
use approval_request::guardian_assessment_action;
#[cfg(test)]
codex-rs/core/src/guardian/prompt.rs
+11 -9
View File
@@ -19,7 +19,7 @@ use super::GUARDIAN_RECENT_ENTRY_LIMIT;
use super::GuardianApprovalRequest;
use super::GuardianAssessment;
use super::TRUNCATION_TAG;
use super::approval_request::format_guardian_action_pretty;
use super::approval_request::format_guardian_action_pretty_with_truncation;
/// Transcript entry retained for guardian review after filtering.
#[derive(Debug, PartialEq, Eq)]
@@ -56,6 +56,7 @@ impl GuardianTranscriptEntryKind {
pub(crate) struct GuardianPromptItems {
pub(crate) items: Vec<UserInput>,
pub(crate) transcript_cursor: GuardianTranscriptCursor,
pub(crate) reviewed_action_truncated: bool,
}
/// Points to the end of the transcript that the guardian has already reviewed.
@@ -91,7 +92,7 @@ pub(crate) async fn build_guardian_prompt_items(
parent_history_version: history.history_version(),
transcript_entry_count: transcript_entries.len(),
};
let planned_action_json = format_guardian_action_pretty(&request)?;
let planned_action = format_guardian_action_pretty_with_truncation(&request)?;
let prompt_shape = match mode {
GuardianPromptMode::Full => GuardianPromptShape::Full,
@@ -176,11 +177,12 @@ pub(crate) async fn build_guardian_prompt_items(
.to_string(),
);
push_text("Planned action JSON:\n".to_string());
push_text(format!("{planned_action_json}\n"));
push_text(format!("{}\n", planned_action.text));
push_text(">>> APPROVAL REQUEST END\n".to_string());
Ok(GuardianPromptItems {
items,
transcript_cursor,
reviewed_action_truncated: planned_action.truncated,
})
}
@@ -240,7 +242,7 @@ fn render_guardian_transcript_entries_with_offset(
} else {
GUARDIAN_MAX_MESSAGE_ENTRY_TOKENS
};
let text = guardian_truncate_text(&entry.text, token_cap);
let (text, _) = guardian_truncate_text(&entry.text, token_cap);
let rendered = format!(
"[{}] {}: {}",
index + entry_number_offset + 1,
@@ -420,20 +422,20 @@ pub(crate) fn collect_guardian_transcript_entries(
entries
}
pub(crate) fn guardian_truncate_text(content: &str, token_cap: usize) -> String {
pub(crate) fn guardian_truncate_text(content: &str, token_cap: usize) -> (String, bool) {
if content.is_empty() {
return String::new();
return (String::new(), false);
}
let max_bytes = approx_bytes_for_tokens(token_cap);
if content.len() <= max_bytes {
return content.to_string();
return (content.to_string(), false);
}
let omitted_tokens = approx_tokens_from_byte_count(content.len().saturating_sub(max_bytes));
let marker = format!("<{TRUNCATION_TAG} omitted_approx_tokens=\"{omitted_tokens}\" />");
if max_bytes <= marker.len() {
return marker;
return (marker, true);
}
let available_bytes = max_bytes.saturating_sub(marker.len());
@@ -441,7 +443,7 @@ pub(crate) fn guardian_truncate_text(content: &str, token_cap: usize) -> String
let suffix_budget = available_bytes.saturating_sub(prefix_budget);
let (prefix, suffix) = split_guardian_truncation_bounds(content, prefix_budget, suffix_budget);
format!("{prefix}{marker}{suffix}")
(format!("{prefix}{marker}{suffix}"), true)
}
fn split_guardian_truncation_bounds(
codex-rs/core/src/guardian/review_session.rs
+30 -13
View File
@@ -74,7 +74,9 @@ pub(crate) struct GuardianReviewSessionMetadata {
pub(crate) guardian_reasoning_effort: Option<String>,
pub(crate) had_prior_review_context: bool,
pub(crate) completed_at: u64,
pub(crate) reviewed_action_truncated: bool,
pub(crate) token_usage: Option<TokenUsage>,
pub(crate) time_to_first_token_ms: Option<u64>,
}
pub(crate) struct GuardianReviewSessionParams {
@@ -639,7 +641,9 @@ async fn run_review_on_session(
guardian_reasoning_effort: guardian_reasoning_effort.map(|effort| effort.to_string()),
had_prior_review_context: had_prior_review_context(&prompt_mode),
completed_at: 0,
reviewed_action_truncated: false,
token_usage: None,
time_to_first_token_ms: None,
};
if send_followup_reminder {
append_guardian_followup_reminder(review_session).await;
@@ -665,6 +669,7 @@ async fn run_review_on_session(
prompt_mode,
)
.await?;
let reviewed_action_truncated = prompt_items.reviewed_action_truncated;
// A fresh Guardian review session may not have token info yet. Treat that
// as a zero baseline so the first review can still report usage.
let token_usage_at_review_start = review_session
@@ -692,8 +697,9 @@ async fn run_review_on_session(
})
.await?;
Ok::<(GuardianTranscriptCursor, TokenUsage), anyhow::Error>((
Ok::<(GuardianTranscriptCursor, bool, TokenUsage), anyhow::Error>((
prompt_items.transcript_cursor,
reviewed_action_truncated,
token_usage_at_review_start,
))
}),
@@ -703,19 +709,26 @@ async fn run_review_on_session(
Ok(submit_result) => submit_result,
Err(outcome) => return (outcome, false, guardian_metadata),
};
let (transcript_cursor, token_usage_at_review_start) = match submit_result {
Ok(submit_result) => submit_result,
Err(err) => {
return (
GuardianReviewSessionOutcome::PromptBuildFailed(err),
false,
guardian_metadata,
);
}
};
let (transcript_cursor, reviewed_action_truncated, token_usage_at_review_start) =
match submit_result {
Ok(submit_result) => submit_result,
Err(err) => {
return (
GuardianReviewSessionOutcome::PromptBuildFailed(err),
false,
guardian_metadata,
);
}
};
guardian_metadata.reviewed_action_truncated = reviewed_action_truncated;
let outcome =
wait_for_guardian_review(review_session, deadline, params.external_cancel.as_ref()).await;
let outcome = wait_for_guardian_review(
review_session,
deadline,
params.external_cancel.as_ref(),
&mut guardian_metadata,
)
.await;
if matches!(outcome.0, GuardianReviewSessionOutcome::Completed(_)) {
if outcome.2
&& let Some(total_token_usage) = review_session.codex.session.total_token_usage().await
@@ -758,6 +771,7 @@ async fn wait_for_guardian_review(
review_session: &GuardianReviewSession,
deadline: tokio::time::Instant,
external_cancel: Option<&CancellationToken>,
metadata: &mut GuardianReviewSessionMetadata,
) -> (GuardianReviewSessionOutcome, bool, bool) {
let timeout = tokio::time::sleep_until(deadline);
tokio::pin!(timeout);
@@ -783,6 +797,9 @@ async fn wait_for_guardian_review(
match event {
Ok(event) => match event.msg {
EventMsg::TurnComplete(turn_complete) => {
metadata.time_to_first_token_ms = turn_complete
.time_to_first_token_ms
.and_then(|ms| u64::try_from(ms).ok());
if turn_complete.last_agent_message.is_none()
&& let Some(error_message) = last_error_message
{
codex-rs/core/src/guardian/tests.rs
+91 -10
View File
@@ -570,11 +570,12 @@ fn collect_guardian_transcript_entries_includes_recent_tool_calls_and_output() {
fn guardian_truncate_text_keeps_prefix_suffix_and_xml_marker() {
let content = "prefix ".repeat(200) + &" suffix".repeat(200);
let truncated = guardian_truncate_text(&content, /*token_cap*/ 20);
let (truncated, was_truncated) = guardian_truncate_text(&content, /*token_cap*/ 20);
assert!(truncated.starts_with("prefix"));
assert!(truncated.contains("<truncated omitted_approx_tokens=\""));
assert!(truncated.ends_with("suffix"));
assert!(was_truncated);
}
#[test]
@@ -587,11 +588,29 @@ fn format_guardian_action_pretty_truncates_large_string_fields() -> serde_json::
patch: patch.clone(),
};
let rendered = format_guardian_action_pretty(&action)?;
let rendered = format_guardian_action_pretty_with_truncation(&action)?;
assert!(rendered.contains("\"tool\": \"apply_patch\""));
assert!(rendered.contains("<truncated omitted_approx_tokens="));
assert!(rendered.len() < patch.len());
assert!(rendered.text.contains("\"tool\": \"apply_patch\""));
assert!(rendered.text.contains("<truncated omitted_approx_tokens="));
assert!(rendered.text.len() < patch.len());
assert!(rendered.truncated);
Ok(())
}
#[test]
fn format_guardian_action_pretty_reports_no_truncation_for_small_payload() -> serde_json::Result<()>
{
let action = GuardianApprovalRequest::ApplyPatch {
id: "patch-1".to_string(),
cwd: test_path_buf("/tmp").abs(),
files: Vec::new(),
patch: "line\n".to_string(),
};
let rendered = format_guardian_action_pretty_with_truncation(&action)?;
assert!(rendered.text.contains("\"tool\": \"apply_patch\""));
assert!(!rendered.truncated);
Ok(())
}
@@ -922,14 +941,44 @@ async fn guardian_review_request_layout_matches_model_visible_request_snapshot()
.await;
let GuardianReviewSessionResult {
outcome: GuardianReviewOutcome::Completed(assessment),
..
metadata,
} = outcome
else {
panic!("expected guardian assessment");
};
let metadata = metadata.expect("guardian session metadata");
assert_eq!(assessment.outcome, GuardianAssessmentOutcome::Allow);
assert_ne!(
metadata.guardian_thread_id,
session.conversation_id.to_string()
);
ThreadId::from_string(&metadata.guardian_thread_id)
.expect("guardian thread id should be a valid UUID");
assert!(matches!(
metadata.guardian_session_kind,
codex_analytics::GuardianReviewSessionKind::TrunkNew
));
let request = request_log.single_request();
let request_body = request.body_json();
let request_model = request_body
.get("model")
.and_then(|value| value.as_str())
.expect("guardian request should include a model");
let request_reasoning_effort = request_body
.get("reasoning")
.and_then(|reasoning| reasoning.get("effort"))
.and_then(|value| value.as_str());
assert_eq!(metadata.guardian_model.as_str(), request_model);
assert_eq!(
metadata.guardian_reasoning_effort.as_deref(),
request_reasoning_effort
);
assert!(!metadata.had_prior_review_context);
assert!(
metadata.time_to_first_token_ms.is_some(),
"guardian review metadata should capture TTFT when the nested turn completes"
);
let mut settings = Settings::clone_current();
settings.set_snapshot_path("snapshots");
settings.set_prepend_module_to_snapshot(false);
@@ -1135,28 +1184,60 @@ async fn guardian_reuses_prompt_cache_key_and_appends_prior_reviews() -> anyhow:
let GuardianReviewSessionResult {
outcome: GuardianReviewOutcome::Completed(first_assessment),
..
metadata: first_metadata,
} = first_outcome
else {
panic!("expected first guardian assessment");
};
let first_metadata = first_metadata.expect("first guardian session metadata");
let GuardianReviewSessionResult {
outcome: GuardianReviewOutcome::Completed(second_assessment),
..
metadata: second_metadata,
} = second_outcome
else {
panic!("expected second guardian assessment");
};
let second_metadata = second_metadata.expect("second guardian session metadata");
let GuardianReviewSessionResult {
outcome: GuardianReviewOutcome::Completed(third_assessment),
..
metadata: third_metadata,
} = third_outcome
else {
panic!("expected third guardian assessment");
};
let third_metadata = third_metadata.expect("third guardian session metadata");
assert_eq!(first_assessment.outcome, GuardianAssessmentOutcome::Allow);
assert_eq!(second_assessment.outcome, GuardianAssessmentOutcome::Allow);
assert_eq!(third_assessment.outcome, GuardianAssessmentOutcome::Allow);
assert!(matches!(
first_metadata.guardian_session_kind,
codex_analytics::GuardianReviewSessionKind::TrunkNew
));
assert!(matches!(
second_metadata.guardian_session_kind,
codex_analytics::GuardianReviewSessionKind::TrunkReused
));
assert!(matches!(
third_metadata.guardian_session_kind,
codex_analytics::GuardianReviewSessionKind::TrunkReused
));
ThreadId::from_string(&first_metadata.guardian_thread_id)
.expect("first guardian thread id should be a valid UUID");
ThreadId::from_string(&second_metadata.guardian_thread_id)
.expect("second guardian thread id should be a valid UUID");
ThreadId::from_string(&third_metadata.guardian_thread_id)
.expect("third guardian thread id should be a valid UUID");
assert!(!first_metadata.had_prior_review_context);
assert!(second_metadata.had_prior_review_context);
assert!(third_metadata.had_prior_review_context);
assert_eq!(
first_metadata.guardian_thread_id,
second_metadata.guardian_thread_id
);
assert_eq!(
second_metadata.guardian_thread_id,
third_metadata.guardian_thread_id
);
let requests = request_log.requests();
assert_eq!(requests.len(), 3);
codex-rs/core/src/session/rollout_reconstruction_tests.rs
+20
View File
@@ -151,6 +151,7 @@ async fn record_initial_history_resumed_hydrates_previous_turn_settings_from_lif
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
];
@@ -218,6 +219,7 @@ async fn reconstruct_history_rollback_keeps_history_and_metadata_in_sync_for_com
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
@@ -245,6 +247,7 @@ async fn reconstruct_history_rollback_keeps_history_and_metadata_in_sync_for_com
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::ThreadRolledBack(
@@ -314,6 +317,7 @@ async fn reconstruct_history_rollback_keeps_history_and_metadata_in_sync_for_inc
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
@@ -403,6 +407,7 @@ async fn reconstruct_history_rollback_skips_non_user_turns_for_history_and_metad
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
@@ -429,6 +434,7 @@ async fn reconstruct_history_rollback_skips_non_user_turns_for_history_and_metad
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
@@ -446,6 +452,7 @@ async fn reconstruct_history_rollback_skips_non_user_turns_for_history_and_metad
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::ThreadRolledBack(
@@ -518,6 +525,7 @@ async fn reconstruct_history_rollback_counts_inter_agent_assistant_turns() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
@@ -537,6 +545,7 @@ async fn reconstruct_history_rollback_counts_inter_agent_assistant_turns() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::ThreadRolledBack(
@@ -604,6 +613,7 @@ async fn reconstruct_history_rollback_clears_history_and_metadata_when_exceeding
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::ThreadRolledBack(
@@ -653,6 +663,7 @@ async fn record_initial_history_resumed_rollback_skips_only_user_turns() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
// Standalone task turn (no UserMessage) should not consume rollback skips.
@@ -670,6 +681,7 @@ async fn record_initial_history_resumed_rollback_skips_only_user_turns() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::ThreadRolledBack(
@@ -723,6 +735,7 @@ async fn record_initial_history_resumed_rollback_drops_incomplete_user_turn_comp
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
@@ -879,6 +892,7 @@ async fn reconstruct_history_legacy_compaction_without_replacement_history_clear
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
];
@@ -949,6 +963,7 @@ async fn record_initial_history_resumed_turn_context_after_compaction_reestablis
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
];
@@ -1052,6 +1067,7 @@ async fn record_initial_history_resumed_aborted_turn_without_id_clears_active_tu
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
@@ -1160,6 +1176,7 @@ async fn record_initial_history_resumed_unmatched_abort_preserves_active_turn_fo
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
@@ -1193,6 +1210,7 @@ async fn record_initial_history_resumed_unmatched_abort_preserves_active_turn_fo
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
];
@@ -1276,6 +1294,7 @@ async fn record_initial_history_resumed_trailing_incomplete_turn_compaction_clea
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
@@ -1427,6 +1446,7 @@ async fn record_initial_history_resumed_replaced_incomplete_compacted_turn_clear
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
RolloutItem::EventMsg(EventMsg::TurnStarted(
codex-rs/core/src/session/tests.rs
+10
View File
@@ -1776,6 +1776,7 @@ async fn record_initial_history_forked_hydrates_previous_turn_settings() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
},
)),
];
@@ -1961,6 +1962,7 @@ async fn thread_rollback_recomputes_previous_turn_settings_and_reference_context
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
RolloutItem::EventMsg(EventMsg::TurnStarted(
codex_protocol::protocol::TurnStartedEvent {
@@ -1986,6 +1988,7 @@ async fn thread_rollback_recomputes_previous_turn_settings_and_reference_context
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
])
.await;
@@ -2063,6 +2066,7 @@ async fn thread_rollback_restores_cleared_reference_context_item_after_compactio
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
RolloutItem::EventMsg(EventMsg::TurnStarted(
codex_protocol::protocol::TurnStartedEvent {
@@ -2081,6 +2085,7 @@ async fn thread_rollback_restores_cleared_reference_context_item_after_compactio
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
RolloutItem::EventMsg(EventMsg::TurnStarted(
codex_protocol::protocol::TurnStartedEvent {
@@ -2108,6 +2113,7 @@ async fn thread_rollback_restores_cleared_reference_context_item_after_compactio
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
])
.await;
@@ -2154,6 +2160,7 @@ async fn thread_rollback_persists_marker_and_replays_cumulatively() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
RolloutItem::EventMsg(EventMsg::TurnStarted(
codex_protocol::protocol::TurnStartedEvent {
@@ -2177,6 +2184,7 @@ async fn thread_rollback_persists_marker_and_replays_cumulatively() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
RolloutItem::EventMsg(EventMsg::TurnStarted(
codex_protocol::protocol::TurnStartedEvent {
@@ -2200,6 +2208,7 @@ async fn thread_rollback_persists_marker_and_replays_cumulatively() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
])
.await;
@@ -5813,6 +5822,7 @@ async fn task_finish_emits_turn_item_lifecycle_for_leftover_pending_user_input()
EventMsg::TurnComplete(TurnCompleteEvent {
turn_id,
last_agent_message: None,
time_to_first_token_ms: None,
..
}) if turn_id == tc.sub_id
));
codex-rs/core/src/tasks/mod.rs
+5
View File
@@ -567,11 +567,16 @@ impl Session {
.turn_timing_state
.completed_at_and_duration_ms()
.await;
let time_to_first_token_ms = turn_context
.turn_timing_state
.time_to_first_token_ms()
.await;
let event = EventMsg::TurnComplete(TurnCompleteEvent {
turn_id: turn_context.sub_id.clone(),
last_agent_message,
completed_at,
duration_ms,
time_to_first_token_ms,
});
self.send_event(turn_context.as_ref(), event).await;
codex-rs/core/src/tools/handlers/multi_agents_tests.rs
+3
View File
@@ -1155,6 +1155,7 @@ async fn multi_agent_v2_list_agents_returns_completed_status_and_last_task_messa
last_agent_message: Some("done".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
)
.await;
@@ -1633,6 +1634,7 @@ async fn multi_agent_v2_followup_task_completion_notifies_parent_on_every_turn()
last_agent_message: Some("first done".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
)
.await;
@@ -1661,6 +1663,7 @@ async fn multi_agent_v2_followup_task_completion_notifies_parent_on_every_turn()
last_agent_message: Some("second done".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
)
.await;
codex-rs/core/src/turn_timing.rs
+14 -4
View File
@@ -74,6 +74,13 @@ impl TurnTimingState {
(completed_at, duration_ms)
}
pub(crate) async fn time_to_first_token_ms(&self) -> Option<i64> {
let state = self.state.lock().await;
state
.time_to_first_token()
.map(|duration| i64::try_from(duration.as_millis()).unwrap_or(i64::MAX))
}
pub(crate) async fn record_ttft_for_response_event(
&self,
event: &ResponseEvent,
@@ -102,14 +109,17 @@ fn now_unix_timestamp_secs() -> i64 {
}
impl TurnTimingStateInner {
fn time_to_first_token(&self) -> Option<Duration> {
Some(self.first_token_at?.duration_since(self.started_at?))
}
fn record_turn_ttft(&mut self) -> Option<Duration> {
if self.first_token_at.is_some() {
return None;
}
let started_at = self.started_at?;
let first_token_at = Instant::now();
self.first_token_at = Some(first_token_at);
Some(first_token_at.duration_since(started_at))
self.started_at?;
self.first_token_at = Some(Instant::now());
self.time_to_first_token()
}
fn record_turn_ttfm(&mut self) -> Option<Duration> {
codex-rs/core/tests/suite/resume_warning.rs
+1
View File
@@ -70,6 +70,7 @@ fn resume_history(
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})),
],
rollout_path: rollout_path.to_path_buf(),
codex-rs/protocol/src/protocol.rs
+4
View File
@@ -2091,6 +2091,10 @@ pub struct TurnCompleteEvent {
#[serde(default, skip_serializing_if = "Option::is_none")]
#[ts(type = "number | null", optional)]
pub duration_ms: Option<i64>,
/// Duration between turn start and the first model token in milliseconds, if known.
#[serde(default, skip_serializing_if = "Option::is_none")]
#[ts(type = "number | null", optional)]
pub time_to_first_token_ms: Option<i64>,
}
#[derive(Debug, Clone, Deserialize, Serialize, JsonSchema, TS)]
codex-rs/tui/src/app/app_server_adapter.rs
+2
View File
@@ -785,6 +785,7 @@ fn append_terminal_turn_events(events: &mut Vec<Event>, turn: &Turn, include_fai
last_agent_message: None,
completed_at: turn.completed_at,
duration_ms: turn.duration_ms,
time_to_first_token_ms: None,
}),
}),
TurnStatus::Interrupted => events.push(Event {
@@ -816,6 +817,7 @@ fn append_terminal_turn_events(events: &mut Vec<Event>, turn: &Turn, include_fai
last_agent_message: None,
completed_at: turn.completed_at,
duration_ms: turn.duration_ms,
time_to_first_token_ms: None,
}),
});
}
codex-rs/tui/src/chatwidget/tests/exec_flow.rs
+5
View File
@@ -654,6 +654,7 @@ async fn unified_exec_wait_after_final_agent_message_snapshot() {
last_agent_message: Some("Final response.".into()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -699,6 +700,7 @@ async fn unified_exec_wait_before_streamed_agent_message_snapshot() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -766,6 +768,7 @@ async fn unified_exec_waiting_multiple_empty_snapshots() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -846,6 +849,7 @@ async fn unified_exec_non_empty_then_empty_snapshots() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -1359,6 +1363,7 @@ async fn turn_complete_keeps_unified_exec_processes() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
codex-rs/tui/src/chatwidget/tests/plan_mode.rs
+4
View File
@@ -648,6 +648,7 @@ async fn plan_implementation_popup_skips_replayed_turn_complete() {
last_agent_message: Some("Plan details".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})]);
let popup = render_bottom_popup(&chat, /*width*/ 80);
@@ -674,6 +675,7 @@ async fn plan_implementation_popup_shows_once_when_replay_precedes_live_turn_com
last_agent_message: Some("Plan details".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
})]);
let replay_popup = render_bottom_popup(&chat, /*width*/ 80);
assert!(
@@ -688,6 +690,7 @@ async fn plan_implementation_popup_shows_once_when_replay_precedes_live_turn_com
last_agent_message: Some("Plan details".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -711,6 +714,7 @@ async fn plan_implementation_popup_shows_once_when_replay_precedes_live_turn_com
last_agent_message: Some("Plan details".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
let duplicate_popup = render_bottom_popup(&chat, /*width*/ 80);
codex-rs/tui/src/chatwidget/tests/review_mode.rs
+2
View File
@@ -314,6 +314,7 @@ async fn steer_rejection_queues_review_follow_up_before_existing_queued_messages
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -335,6 +336,7 @@ async fn steer_rejection_queues_review_follow_up_before_existing_queued_messages
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
codex-rs/tui/src/chatwidget/tests/slash_commands.rs
+5
View File
@@ -807,6 +807,7 @@ async fn slash_copy_state_tracks_turn_complete_final_reply() {
last_agent_message: Some("Final reply **markdown**".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -839,6 +840,7 @@ async fn slash_copy_state_tracks_plan_item_completion() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -925,6 +927,7 @@ async fn slash_copy_state_is_preserved_during_running_task() {
last_agent_message: Some("Previous completed reply".to_string()),
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
chat.on_task_started();
@@ -955,6 +958,7 @@ async fn slash_copy_tracks_replayed_legacy_agent_message_when_turn_complete_omit
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
let _ = drain_insert_history(&mut rx);
@@ -992,6 +996,7 @@ async fn slash_copy_uses_agent_message_item_when_turn_complete_omits_final_text(
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
let _ = drain_insert_history(&mut rx);
codex-rs/tui/src/chatwidget/tests/status_and_layout.rs
+3
View File
@@ -1315,6 +1315,7 @@ async fn status_line_branch_refreshes_after_turn_complete() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -1665,6 +1666,7 @@ async fn multiple_agent_messages_in_single_turn_emit_multiple_headers() {
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
@@ -2610,6 +2612,7 @@ printf 'fenced within fenced\n'
last_agent_message: None,
completed_at: None,
duration_ms: None,
time_to_first_token_ms: None,
}),
});
for lines in drain_insert_history(&mut rx) {