add runtime TTFT to turn events

codex-rs/analytics/src/analytics_client_tests.rs

@@ -594,6 +594,27 @@ async fn ingest_turn_prerequisites(
     include_resolved_config: bool,
     include_started: bool,
     include_token_usage: bool,
+) {
+    ingest_turn_prerequisites_with_ttft(
+        reducer,
+        out,
+        include_initialize,
+        include_resolved_config,
+        include_started,
+        include_token_usage,
+        /*time_to_first_token_ms*/ Some(321),
+    )
+    .await;
+}
+
+async fn ingest_turn_prerequisites_with_ttft(
+    reducer: &mut AnalyticsReducer,
+    out: &mut Vec<TrackEventRequest>,
+    include_initialize: bool,
+    include_resolved_config: bool,
+    include_started: bool,
+    include_token_usage: bool,
+    time_to_first_token_ms: Option<u64>,
 ) {
     if include_initialize {
         ingest_initialize(reducer, out).await;
@@ -672,6 +693,7 @@ async fn ingest_turn_prerequisites(
                 TurnProfileFact {
                     turn_id: "turn-2".to_string(),
                     profile: sample_turn_profile(),
+                    time_to_first_token_ms,
                 },
             ))),
             out,
@@ -793,6 +815,7 @@ async fn ingest_complete_child_turn(
             TurnProfileFact {
                 turn_id: turn_id.to_string(),
                 profile: sample_turn_profile(),
+                time_to_first_token_ms: Some(321),
             },
         ))),
         AnalyticsFact::Notification(Box::new(sample_turn_completed_notification(
@@ -3474,6 +3497,7 @@ fn turn_event_serializes_expected_shape() {
             after_last_sampling_ms: 134,
             sampling_request_count: 2,
             sampling_retry_count: 1,
+            time_to_first_token_ms: Some(321),
             duration_ms: Some(1234),
             started_at: Some(455),
             completed_at: Some(456),
@@ -3546,6 +3570,7 @@ fn turn_event_serializes_expected_shape() {
                 "after_last_sampling_ms": 134,
                 "sampling_request_count": 2,
                 "sampling_retry_count": 1,
+                "time_to_first_token_ms": 321,
                 "duration_ms": 1234,
                 "started_at": 455,
                 "completed_at": 456
@@ -3863,6 +3888,10 @@ async fn turn_lifecycle_emits_turn_event() {
     assert_eq!(payload["event_params"]["started_at"], json!(455));
     assert_eq!(payload["event_params"]["completed_at"], json!(456));
     assert_eq!(payload["event_params"]["duration_ms"], json!(1234));
+    assert_eq!(
+        payload["event_params"]["time_to_first_token_ms"],
+        json!(321)
+    );
     assert_eq!(payload["event_params"]["input_tokens"], json!(123));
     assert_eq!(payload["event_params"]["cached_input_tokens"], json!(45));
     assert_eq!(payload["event_params"]["output_tokens"], json!(140));
@@ -4262,6 +4291,10 @@ async fn turn_lifecycle_emits_failed_turn_event() {
         payload["event_params"]["codex_error_http_status_code"],
         json!(null)
     );
+    assert_eq!(
+        payload["event_params"]["time_to_first_token_ms"],
+        json!(321)
+    );
 }
 
 #[tokio::test]
@@ -4295,6 +4328,48 @@ async fn turn_lifecycle_emits_interrupted_turn_event_without_error() {
     assert_eq!(payload["event_params"]["status"], json!("interrupted"));
     assert_eq!(payload["event_params"]["turn_error"], json!(null));
     assert_eq!(payload["event_params"]["codex_error_kind"], json!(null));
+    assert_eq!(payload["event_params"]["duration_ms"], json!(1234));
+    assert_eq!(
+        payload["event_params"]["time_to_first_token_ms"],
+        json!(321)
+    );
+}
+
+#[tokio::test]
+async fn turn_lifecycle_without_qualifying_output_emits_null_ttft() {
+    let mut reducer = AnalyticsReducer::default();
+    let mut out = Vec::new();
+
+    ingest_turn_prerequisites_with_ttft(
+        &mut reducer,
+        &mut out,
+        /*include_initialize*/ true,
+        /*include_resolved_config*/ true,
+        /*include_started*/ true,
+        /*include_token_usage*/ false,
+        /*time_to_first_token_ms*/ None,
+    )
+    .await;
+    reducer
+        .ingest(
+            AnalyticsFact::Notification(Box::new(sample_turn_completed_notification(
+                "thread-2",
+                "turn-2",
+                AppServerTurnStatus::Completed,
+                /*codex_error_info*/ None,
+            ))),
+            &mut out,
+        )
+        .await;
+
+    assert_eq!(out.len(), 1);
+    let payload = serde_json::to_value(&out[0]).expect("serialize turn event");
+    assert_eq!(payload["event_params"]["status"], json!("completed"));
+    assert_eq!(payload["event_params"]["duration_ms"], json!(1234));
+    assert_eq!(
+        payload["event_params"]["time_to_first_token_ms"],
+        json!(null)
+    );
 }
 
 #[tokio::test]

codex-rs/analytics/src/events.rs

@@ -893,6 +893,7 @@ pub(crate) struct CodexTurnEventParams {
     pub(crate) after_last_sampling_ms: u64,
     pub(crate) sampling_request_count: u32,
     pub(crate) sampling_retry_count: u32,
+    pub(crate) time_to_first_token_ms: Option<u64>,
     pub(crate) duration_ms: Option<u64>,
     pub(crate) started_at: Option<u64>,
     pub(crate) completed_at: Option<u64>,

codex-rs/analytics/src/facts.rs

@@ -116,6 +116,7 @@ pub struct TurnProfile {
 pub struct TurnProfileFact {
     pub turn_id: String,
     pub profile: TurnProfile,
+    pub time_to_first_token_ms: Option<u64>,
 }
 
 #[derive(Clone)]

codex-rs/analytics/src/reducer.rs

@@ -340,6 +340,7 @@ struct TurnState {
     started_at: Option<u64>,
     token_usage: Option<TokenUsage>,
     profile: Option<TurnProfile>,
+    time_to_first_token_ms: Option<u64>,
     completed: Option<CompletedTurnState>,
     codex_error: Option<TurnCodexError>,
     latest_diff: Option<String>,
@@ -654,9 +655,14 @@ impl AnalyticsReducer {
         input: TurnProfileFact,
         out: &mut Vec<TrackEventRequest>,
     ) {
-        let TurnProfileFact { turn_id, profile } = input;
+        let TurnProfileFact {
+            turn_id,
+            profile,
+            time_to_first_token_ms,
+        } = input;
         let turn_state = self.turns.entry(turn_id.clone()).or_default();
         turn_state.profile = Some(profile);
+        turn_state.time_to_first_token_ms = time_to_first_token_ms;
         self.maybe_emit_turn_event(&turn_id, out).await;
     }
 
@@ -2563,6 +2569,7 @@ fn codex_turn_event_params(
         after_last_sampling_ms,
         sampling_request_count,
         sampling_retry_count,
+        time_to_first_token_ms: turn_state.time_to_first_token_ms,
         duration_ms: completed.duration_ms,
         started_at,
         completed_at: Some(completed.completed_at),

codex-rs/core/src/tasks/mod.rs

@@ -739,6 +739,8 @@ impl Session {
             .track_turn_profile(TurnProfileFact {
                 turn_id: turn_context.sub_id.clone(),
                 profile: turn_context.turn_timing_state.complete_profile(),
+                time_to_first_token_ms: time_to_first_token_ms
+                    .and_then(|duration_ms| u64::try_from(duration_ms).ok()),
             });
         self.emit_turn_stop_lifecycle(turn_context.extension_data.as_ref())
             .await;
@@ -853,11 +855,18 @@ impl Session {
             .turn_timing_state
             .completed_at_and_duration_ms()
             .await;
+        let time_to_first_token_ms = task
+            .turn_context
+            .turn_timing_state
+            .time_to_first_token_ms()
+            .await;
         self.services
             .analytics_events_client
             .track_turn_profile(TurnProfileFact {
                 turn_id: task.turn_context.sub_id.clone(),
                 profile: task.turn_context.turn_timing_state.complete_profile(),
+                time_to_first_token_ms: time_to_first_token_ms
+                    .and_then(|duration_ms| u64::try_from(duration_ms).ok()),
             });
         let event = EventMsg::TurnAborted(TurnAbortedEvent {
             turn_id: Some(task.turn_context.sub_id.clone()),