[codex-analytics] guardian review TTFT plumbing and emission

This commit is contained in:
rhan-oai
2026-04-13 14:02:45 -07:00
parent 996334d969
commit d772b643ba
16 changed files with 94 additions and 0 deletions
+3
View File
@@ -275,6 +275,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));
@@ -1225,6 +1226,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;
@@ -1311,6 +1313,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;
@@ -148,6 +148,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,
},
)),
];
@@ -215,6 +216,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(
@@ -242,6 +244,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(
@@ -311,6 +314,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(
@@ -400,6 +404,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(
@@ -426,6 +431,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(
@@ -443,6 +449,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(
@@ -515,6 +522,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(
@@ -534,6 +542,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(
@@ -601,6 +610,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(
@@ -650,6 +660,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.
@@ -667,6 +678,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(
@@ -720,6 +732,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(
@@ -876,6 +889,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,
},
)),
];
@@ -945,6 +959,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,
},
)),
];
@@ -1046,6 +1061,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(
@@ -1153,6 +1169,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(
@@ -1186,6 +1203,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,
},
)),
];
@@ -1268,6 +1286,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(
@@ -1418,6 +1437,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(
+10
View File
@@ -1446,6 +1446,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,
},
)),
];
@@ -1631,6 +1632,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 {
@@ -1656,6 +1658,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;
@@ -1733,6 +1736,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 {
@@ -1751,6 +1755,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 {
@@ -1778,6 +1783,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;
@@ -1824,6 +1830,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 {
@@ -1847,6 +1854,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 {
@@ -1870,6 +1878,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;
@@ -4830,6 +4839,7 @@ async fn task_finish_emits_turn_item_lifecycle_for_leftover_pending_user_input()
turn_id,
last_agent_message: None,
..
time_to_first_token_ms: None,
}) if turn_id == tc.sub_id
));
}
+5
View File
@@ -527,11 +527,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;
@@ -1154,6 +1154,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;
@@ -1631,6 +1632,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;
@@ -1659,6 +1661,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;
+10
View File
@@ -74,6 +74,16 @@ impl TurnTimingState {
(completed_at, duration_ms)
}
pub(crate) async fn time_to_first_token_ms(&self) -> Option<i64> {
let state = self.state.lock().await;
let started_at = state.started_at?;
let first_token_at = state.first_token_at?;
Some(
i64::try_from(first_token_at.duration_since(started_at).as_millis())
.unwrap_or(i64::MAX),
)
}
pub(crate) async fn record_ttft_for_response_event(
&self,
event: &ResponseEvent,
@@ -69,6 +69,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(),