mirror of
https://github.com/pchuan98/codex.git
synced 2026-07-01 00:31:56 +08:00
[codex-analytics] guardian review TTFT plumbing and emission (#17696)
## Why Guardian analytics includes time-to-first-token, but the Guardian reviewer runs as a normal Codex session and `TurnCompleteEvent` did not expose TTFT. The timing needs to flow through the standard turn-completion protocol so Guardian review analytics can consume the same value as the rest of the session machinery. ## What changed Adds optional `time_to_first_token_ms` to `TurnCompleteEvent` and populates it from `TurnTiming`. The value is carried through app-server thread history, rollout reconstruction, TUI/app-server adapters, and Guardian review session handling. Guardian review analytics now captures TTFT from the reviewer turn-complete event when available. Existing tests and fixtures are updated to set the new optional field to `None` where TTFT is not relevant. ## Verification - `cargo clippy -p codex-tui --tests -- -D warnings` - `cargo clippy -p codex-core --lib --tests -- -D warnings` --- [//]: # (BEGIN SAPLING FOOTER) Stack created with [Sapling](https://sapling-scm.com). Best reviewed with [ReviewStack](https://reviewstack.dev/openai/codex/pull/17696). * __->__ #17696 * #17695 * #17693 * #18278 * #18953
This commit is contained in:
committed by
GitHub
Unverified
parent
37aadeaa13
commit
213b17b7a3
@@ -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,
|
||||
}),
|
||||
];
|
||||
|
||||
@@ -2267,6 +2270,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(),
|
||||
@@ -2304,6 +2308,7 @@ mod tests {
|
||||
last_agent_message: None,
|
||||
completed_at: None,
|
||||
duration_ms: None,
|
||||
time_to_first_token_ms: None,
|
||||
}),
|
||||
];
|
||||
|
||||
@@ -2356,6 +2361,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(),
|
||||
@@ -2393,6 +2399,7 @@ mod tests {
|
||||
last_agent_message: None,
|
||||
completed_at: None,
|
||||
duration_ms: None,
|
||||
time_to_first_token_ms: None,
|
||||
}),
|
||||
];
|
||||
|
||||
@@ -2567,6 +2574,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(),
|
||||
@@ -2585,6 +2593,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(),
|
||||
@@ -2596,6 +2605,7 @@ mod tests {
|
||||
last_agent_message: None,
|
||||
completed_at: None,
|
||||
duration_ms: None,
|
||||
time_to_first_token_ms: None,
|
||||
}),
|
||||
];
|
||||
|
||||
@@ -2630,6 +2640,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(),
|
||||
@@ -2686,6 +2697,7 @@ mod tests {
|
||||
last_agent_message: None,
|
||||
completed_at: None,
|
||||
duration_ms: None,
|
||||
time_to_first_token_ms: None,
|
||||
})),
|
||||
];
|
||||
|
||||
@@ -2931,6 +2943,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(),
|
||||
@@ -2990,6 +3003,7 @@ mod tests {
|
||||
last_agent_message: None,
|
||||
completed_at: None,
|
||||
duration_ms: None,
|
||||
time_to_first_token_ms: None,
|
||||
}),
|
||||
];
|
||||
|
||||
@@ -3041,6 +3055,7 @@ mod tests {
|
||||
last_agent_message: None,
|
||||
completed_at: None,
|
||||
duration_ms: None,
|
||||
time_to_first_token_ms: None,
|
||||
})),
|
||||
];
|
||||
|
||||
@@ -3089,6 +3104,7 @@ mod tests {
|
||||
last_agent_message: None,
|
||||
completed_at: None,
|
||||
duration_ms: None,
|
||||
time_to_first_token_ms: None,
|
||||
})),
|
||||
];
|
||||
|
||||
|
||||
@@ -3107,6 +3107,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,
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -278,6 +278,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));
|
||||
@@ -1221,6 +1222,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;
|
||||
@@ -1307,6 +1309,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;
|
||||
|
||||
@@ -714,8 +714,13 @@ async fn run_review_on_session(
|
||||
}
|
||||
analytics_result.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 analytics_result,
|
||||
)
|
||||
.await;
|
||||
if matches!(outcome.0, GuardianReviewSessionOutcome::Completed(_)) {
|
||||
if outcome.2
|
||||
&& let Some(total_token_usage) = review_session.codex.session.total_token_usage().await
|
||||
@@ -757,6 +762,7 @@ async fn wait_for_guardian_review(
|
||||
review_session: &GuardianReviewSession,
|
||||
deadline: tokio::time::Instant,
|
||||
external_cancel: Option<&CancellationToken>,
|
||||
analytics_result: &mut GuardianReviewAnalyticsResult,
|
||||
) -> (GuardianReviewSessionOutcome, bool, bool) {
|
||||
let timeout = tokio::time::sleep_until(deadline);
|
||||
tokio::pin!(timeout);
|
||||
@@ -782,6 +788,9 @@ async fn wait_for_guardian_review(
|
||||
match event {
|
||||
Ok(event) => match event.msg {
|
||||
EventMsg::TurnComplete(turn_complete) => {
|
||||
analytics_result.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
|
||||
{
|
||||
|
||||
@@ -1074,6 +1074,10 @@ async fn guardian_review_request_layout_matches_model_visible_request_snapshot()
|
||||
request_reasoning_effort
|
||||
);
|
||||
assert_eq!(metadata.had_prior_review_context, Some(false));
|
||||
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");
|
||||
|
||||
@@ -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(
|
||||
|
||||
@@ -1644,6 +1644,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,
|
||||
},
|
||||
)),
|
||||
];
|
||||
@@ -1829,6 +1830,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 {
|
||||
@@ -1854,6 +1856,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;
|
||||
@@ -1931,6 +1934,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 {
|
||||
@@ -1949,6 +1953,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 {
|
||||
@@ -1976,6 +1981,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;
|
||||
@@ -2022,6 +2028,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 {
|
||||
@@ -2045,6 +2052,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 {
|
||||
@@ -2068,6 +2076,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;
|
||||
@@ -5644,6 +5653,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
|
||||
));
|
||||
|
||||
@@ -556,11 +556,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;
|
||||
|
||||
|
||||
@@ -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;
|
||||
|
||||
@@ -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> {
|
||||
|
||||
@@ -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(),
|
||||
|
||||
@@ -2112,6 +2112,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)]
|
||||
|
||||
@@ -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,
|
||||
}),
|
||||
});
|
||||
}
|
||||
|
||||
@@ -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,
|
||||
}),
|
||||
});
|
||||
|
||||
@@ -1072,6 +1076,7 @@ async fn user_message_during_user_shell_command_is_queued_not_steered() {
|
||||
last_agent_message: Some("done".to_string()),
|
||||
completed_at: None,
|
||||
duration_ms: None,
|
||||
time_to_first_token_ms: None,
|
||||
}),
|
||||
});
|
||||
|
||||
@@ -1411,6 +1416,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,
|
||||
}),
|
||||
});
|
||||
|
||||
|
||||
@@ -686,6 +686,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);
|
||||
@@ -712,6 +713,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!(
|
||||
@@ -726,6 +728,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,
|
||||
}),
|
||||
});
|
||||
|
||||
@@ -749,6 +752,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);
|
||||
|
||||
@@ -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,
|
||||
}),
|
||||
});
|
||||
|
||||
|
||||
@@ -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);
|
||||
|
||||
@@ -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) {
|
||||
|
||||
Reference in New Issue
Block a user