[codex-analytics] add core item timing production

2026-05-10 14:22:30 +00:00 · 2026-05-02 20:56:20 -07:00
24 changed files with 223 additions and 6 deletions
--- a/codex-rs/app-server-client/src/lib.rs
+++ b/codex-rs/app-server-client/src/lib.rs
@@ -1134,6 +1134,7 @@ mod tests {
        ServerNotification::ItemCompleted(codex_app_server_protocol::ItemCompletedNotification {
            thread_id: "thread".to_string(),
            turn_id: "turn".to_string(),
+            completed_at_ms: None,
            item: codex_app_server_protocol::ThreadItem::AgentMessage {
                id: "item".to_string(),
                text: text.to_string(),
@@ -2007,6 +2008,7 @@ mod tests {
                    codex_app_server_protocol::ItemCompletedNotification {
                        thread_id: "thread".to_string(),
                        turn_id: "turn".to_string(),
+                        completed_at_ms: None,
                        item: codex_app_server_protocol::ThreadItem::AgentMessage {
                            id: "item".to_string(),
                            text: "hello".to_string(),
--- a/codex-rs/app-server-protocol/schema/json/ServerNotification.json
+++ b/codex-rs/app-server-protocol/schema/json/ServerNotification.json
@@ -1932,6 +1932,14 @@
    },
    "ItemCompletedNotification": {
      "properties": {
+        "completedAtMs": {
+          "description": "Unix timestamp (in milliseconds) when this item lifecycle completed, if known.",
+          "format": "int64",
+          "type": [
+            "integer",
+            "null"
+          ]
+        },
        "item": {
          "$ref": "#/definitions/ThreadItem"
        },
@@ -2030,6 +2038,14 @@
        "item": {
          "$ref": "#/definitions/ThreadItem"
        },
+        "startedAtMs": {
+          "description": "Unix timestamp (in milliseconds) when this item lifecycle started, if known.",
+          "format": "int64",
+          "type": [
+            "integer",
+            "null"
+          ]
+        },
        "threadId": {
          "type": "string"
        },
--- a/codex-rs/app-server-protocol/schema/json/codex_app_server_protocol.schemas.json
+++ b/codex-rs/app-server-protocol/schema/json/codex_app_server_protocol.schemas.json
@@ -10109,6 +10109,14 @@
      "ItemCompletedNotification": {
        "$schema": "http://json-schema.org/draft-07/schema#",
        "properties": {
+          "completedAtMs": {
+            "description": "Unix timestamp (in milliseconds) when this item lifecycle completed, if known.",
+            "format": "int64",
+            "type": [
+              "integer",
+              "null"
+            ]
+          },
          "item": {
            "$ref": "#/definitions/v2/ThreadItem"
          },
@@ -10213,6 +10221,14 @@
          "item": {
            "$ref": "#/definitions/v2/ThreadItem"
          },
+          "startedAtMs": {
+            "description": "Unix timestamp (in milliseconds) when this item lifecycle started, if known.",
+            "format": "int64",
+            "type": [
+              "integer",
+              "null"
+            ]
+          },
          "threadId": {
            "type": "string"
          },
--- a/codex-rs/app-server-protocol/schema/json/codex_app_server_protocol.v2.schemas.json
+++ b/codex-rs/app-server-protocol/schema/json/codex_app_server_protocol.v2.schemas.json
@@ -6762,6 +6762,14 @@
    "ItemCompletedNotification": {
      "$schema": "http://json-schema.org/draft-07/schema#",
      "properties": {
+        "completedAtMs": {
+          "description": "Unix timestamp (in milliseconds) when this item lifecycle completed, if known.",
+          "format": "int64",
+          "type": [
+            "integer",
+            "null"
+          ]
+        },
        "item": {
          "$ref": "#/definitions/ThreadItem"
        },
@@ -6866,6 +6874,14 @@
        "item": {
          "$ref": "#/definitions/ThreadItem"
        },
+        "startedAtMs": {
+          "description": "Unix timestamp (in milliseconds) when this item lifecycle started, if known.",
+          "format": "int64",
+          "type": [
+            "integer",
+            "null"
+          ]
+        },
        "threadId": {
          "type": "string"
        },
--- a/codex-rs/app-server-protocol/schema/json/v2/ItemCompletedNotification.json
+++ b/codex-rs/app-server-protocol/schema/json/v2/ItemCompletedNotification.json
@@ -1370,6 +1370,14 @@
    }
  },
  "properties": {
+    "completedAtMs": {
+      "description": "Unix timestamp (in milliseconds) when this item lifecycle completed, if known.",
+      "format": "int64",
+      "type": [
+        "integer",
+        "null"
+      ]
+    },
    "item": {
      "$ref": "#/definitions/ThreadItem"
    },
--- a/codex-rs/app-server-protocol/schema/json/v2/ItemStartedNotification.json
+++ b/codex-rs/app-server-protocol/schema/json/v2/ItemStartedNotification.json
@@ -1373,6 +1373,14 @@
    "item": {
      "$ref": "#/definitions/ThreadItem"
    },
+    "startedAtMs": {
+      "description": "Unix timestamp (in milliseconds) when this item lifecycle started, if known.",
+      "format": "int64",
+      "type": [
+        "integer",
+        "null"
+      ]
+    },
    "threadId": {
      "type": "string"
    },
--- a/codex-rs/app-server-protocol/schema/typescript/v2/ItemCompletedNotification.ts
+++ b/codex-rs/app-server-protocol/schema/typescript/v2/ItemCompletedNotification.ts
@@ -3,4 +3,8 @@
 // This file was generated by [ts-rs](https://github.com/Aleph-Alpha/ts-rs). Do not edit this file manually.
 import type { ThreadItem } from "./ThreadItem";

-export type ItemCompletedNotification = { item: ThreadItem, threadId: string, turnId: string, };
+export type ItemCompletedNotification = { item: ThreadItem, threadId: string, turnId: string,
+/**
+ * Unix timestamp (in milliseconds) when this item lifecycle completed, if known.
+ */
+completedAtMs: number | null, };
--- a/codex-rs/app-server-protocol/schema/typescript/v2/ItemStartedNotification.ts
+++ b/codex-rs/app-server-protocol/schema/typescript/v2/ItemStartedNotification.ts
@@ -3,4 +3,8 @@
 // This file was generated by [ts-rs](https://github.com/Aleph-Alpha/ts-rs). Do not edit this file manually.
 import type { ThreadItem } from "./ThreadItem";

-export type ItemStartedNotification = { item: ThreadItem, threadId: string, turnId: string, };
+export type ItemStartedNotification = { item: ThreadItem, threadId: string, turnId: string,
+/**
+ * Unix timestamp (in milliseconds) when this item lifecycle started, if known.
+ */
+startedAtMs: number | null, };
--- a/codex-rs/app-server-protocol/src/protocol/event_mapping.rs
+++ b/codex-rs/app-server-protocol/src/protocol/event_mapping.rs
@@ -73,6 +73,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id: response.turn_id,
                item,
+                completed_at_ms: None,
            })
        }
        EventMsg::McpToolCallBegin(begin_event) => {
@@ -91,6 +92,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                started_at_ms: None,
            })
        }
        EventMsg::McpToolCallEnd(end_event) => {
@@ -131,6 +133,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                completed_at_ms: None,
            })
        }
        EventMsg::CollabAgentSpawnBegin(begin_event) => {
@@ -149,6 +152,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                started_at_ms: None,
            })
        }
        EventMsg::CollabAgentSpawnEnd(end_event) => {
@@ -187,6 +191,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                completed_at_ms: None,
            })
        }
        EventMsg::CollabAgentInteractionBegin(begin_event) => {
@@ -206,6 +211,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                started_at_ms: None,
            })
        }
        EventMsg::CollabAgentInteractionEnd(end_event) => {
@@ -233,6 +239,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                completed_at_ms: None,
            })
        }
        EventMsg::CollabWaitingBegin(begin_event) => {
@@ -256,6 +263,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                started_at_ms: None,
            })
        }
        EventMsg::CollabWaitingEnd(end_event) => {
@@ -291,6 +299,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                completed_at_ms: None,
            })
        }
        EventMsg::CollabCloseBegin(begin_event) => {
@@ -309,6 +318,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                started_at_ms: None,
            })
        }
        EventMsg::CollabCloseEnd(end_event) => {
@@ -341,6 +351,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                completed_at_ms: None,
            })
        }
        EventMsg::CollabResumeBegin(begin_event) => {
@@ -359,6 +370,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                started_at_ms: None,
            })
        }
        EventMsg::CollabResumeEnd(end_event) => {
@@ -391,6 +403,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item,
+                completed_at_ms: None,
            })
        }
        EventMsg::AgentMessageContentDelta(event) => {
@@ -440,6 +453,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item: item_started_event.item.into(),
+                started_at_ms: item_started_event.started_at_ms,
            })
        }
        EventMsg::ItemCompleted(item_completed_event) => {
@@ -447,6 +461,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item: item_completed_event.item.into(),
+                completed_at_ms: item_completed_event.completed_at_ms,
            })
        }
        EventMsg::PatchApplyUpdated(event) => {
@@ -462,6 +477,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item: build_command_execution_begin_item(&exec_command_begin_event),
+                started_at_ms: None,
            })
        }
        EventMsg::ExecCommandOutputDelta(exec_command_output_delta_event) => {
@@ -490,6 +506,7 @@ pub fn item_event_to_server_notification(
                thread_id,
                turn_id,
                item: build_command_execution_end_item(&exec_command_end_event),
+                completed_at_ms: None,
            })
        }
        _ => unreachable!("unsupported item event"),
@@ -564,6 +581,7 @@ mod tests {
            ItemStartedNotification {
                thread_id: "thread-1".to_string(),
                turn_id: "turn-1".to_string(),
+                started_at_ms: None,
                item: ThreadItem::CollabAgentToolCall {
                    id: event.call_id,
                    tool: CollabAgentTool::ResumeAgent,
@@ -601,6 +619,7 @@ mod tests {
            ItemCompletedNotification {
                thread_id: "thread-2".to_string(),
                turn_id: "turn-2".to_string(),
+                completed_at_ms: None,
                item: ThreadItem::CollabAgentToolCall {
                    id: event.call_id,
                    tool: CollabAgentTool::ResumeAgent,
@@ -643,6 +662,7 @@ mod tests {
            ItemStartedNotification {
                thread_id: "thread-1".to_string(),
                turn_id: "turn_1".to_string(),
+                started_at_ms: None,
                item: ThreadItem::McpToolCall {
                    id: begin_event.call_id,
                    server: begin_event.invocation.server,
@@ -680,6 +700,7 @@ mod tests {
            ItemStartedNotification {
                thread_id: "thread-2".to_string(),
                turn_id: "turn_2".to_string(),
+                started_at_ms: None,
                item: ThreadItem::McpToolCall {
                    id: begin_event.call_id,
                    server: begin_event.invocation.server,
@@ -732,6 +753,7 @@ mod tests {
            ItemCompletedNotification {
                thread_id: "thread-3".to_string(),
                turn_id: "turn_3".to_string(),
+                completed_at_ms: None,
                item: ThreadItem::McpToolCall {
                    id: end_event.call_id,
                    server: end_event.invocation.server,
@@ -777,6 +799,7 @@ mod tests {
            ItemCompletedNotification {
                thread_id: "thread-4".to_string(),
                turn_id: "turn_4".to_string(),
+                completed_at_ms: None,
                item: ThreadItem::McpToolCall {
                    id: end_event.call_id,
                    server: end_event.invocation.server,
--- a/codex-rs/app-server-protocol/src/protocol/thread_history.rs
+++ b/codex-rs/app-server-protocol/src/protocol/thread_history.rs
@@ -1354,6 +1354,7 @@ mod tests {
                    id: "user-item-id".to_string(),
                    content: Vec::new(),
                }),
+                started_at_ms: None,
            }),
            EventMsg::TurnComplete(TurnCompleteEvent {
                turn_id: turn_id.to_string(),
--- a/codex-rs/app-server-protocol/src/protocol/v2.rs
+++ b/codex-rs/app-server-protocol/src/protocol/v2.rs
@@ -6878,6 +6878,9 @@ pub struct ItemStartedNotification {
    pub item: ThreadItem,
    pub thread_id: String,
    pub turn_id: String,
+    /// Unix timestamp (in milliseconds) when this item lifecycle started, if known.
+    #[ts(type = "number | null")]
+    pub started_at_ms: Option<i64>,
 }

 #[derive(Serialize, Deserialize, Debug, Clone, PartialEq, JsonSchema, TS)]
@@ -6940,6 +6943,9 @@ pub struct ItemCompletedNotification {
    pub item: ThreadItem,
    pub thread_id: String,
    pub turn_id: String,
+    /// Unix timestamp (in milliseconds) when this item lifecycle completed, if known.
+    #[ts(type = "number | null")]
+    pub completed_at_ms: Option<i64>,
 }

 #[derive(Serialize, Deserialize, Debug, Clone, PartialEq, JsonSchema, TS)]
--- a/codex-rs/app-server/src/bespoke_event_handling.rs
+++ b/codex-rs/app-server/src/bespoke_event_handling.rs
@@ -817,6 +817,7 @@ pub(crate) async fn apply_bespoke_event_handling(
                thread_id: conversation_id.to_string(),
                turn_id: turn_id.clone(),
                item,
+                started_at_ms: None,
            };
            outgoing
                .send_server_notification(ServerNotification::ItemStarted(notification))
@@ -967,6 +968,7 @@ pub(crate) async fn apply_bespoke_event_handling(
                thread_id: conversation_id.to_string(),
                turn_id: event_turn_id.clone(),
                item: item.clone(),
+                started_at_ms: None,
            };
            outgoing
                .send_server_notification(ServerNotification::ItemStarted(started))
@@ -975,6 +977,7 @@ pub(crate) async fn apply_bespoke_event_handling(
                thread_id: conversation_id.to_string(),
                turn_id: event_turn_id.clone(),
                item,
+                completed_at_ms: None,
            };
            outgoing
                .send_server_notification(ServerNotification::ItemCompleted(completed))
@@ -1024,6 +1027,7 @@ pub(crate) async fn apply_bespoke_event_handling(
                thread_id: conversation_id.to_string(),
                turn_id: event_turn_id.clone(),
                item: item.clone(),
+                started_at_ms: None,
            };
            outgoing
                .send_server_notification(ServerNotification::ItemStarted(started))
@@ -1032,6 +1036,7 @@ pub(crate) async fn apply_bespoke_event_handling(
                thread_id: conversation_id.to_string(),
                turn_id: event_turn_id.clone(),
                item,
+                completed_at_ms: None,
            };
            outgoing
                .send_server_notification(ServerNotification::ItemCompleted(completed))
@@ -1378,6 +1383,7 @@ async fn start_command_execution_item(
                exit_code: None,
                duration_ms: None,
            },
+            started_at_ms: None,
        };
        outgoing
            .send_server_notification(ServerNotification::ItemStarted(notification))
@@ -1426,6 +1432,7 @@ async fn complete_command_execution_item(
        thread_id: conversation_id.to_string(),
        turn_id,
        item,
+        completed_at_ms: None,
    };
    outgoing
        .send_server_notification(ServerNotification::ItemCompleted(notification))
@@ -1480,6 +1487,7 @@ pub(crate) async fn maybe_emit_hook_prompt_item_completed(
                .map(codex_app_server_protocol::HookPromptFragment::from)
                .collect(),
        },
+        completed_at_ms: None,
    };
    outgoing
        .send_server_notification(ServerNotification::ItemCompleted(notification))
--- a/codex-rs/core/src/session/mod.rs
+++ b/codex-rs/core/src/session/mod.rs
@@ -41,6 +41,7 @@ use crate::session_prefix::format_subagent_notification_message;
 use crate::skills::SkillRenderSideEffects;
 use crate::skills_load_input_from_config;
 use crate::turn_metadata::TurnMetadataState;
+use crate::turn_timing::now_unix_timestamp_ms;
 use async_channel::Receiver;
 use async_channel::Sender;
 use chrono::Local;
@@ -1641,6 +1642,7 @@ impl Session {
                thread_id: self.conversation_id,
                turn_id: turn_context.sub_id.clone(),
                item: item.clone(),
+                started_at_ms: Some(now_unix_timestamp_ms()),
            }),
        )
        .await;
@@ -1658,6 +1660,7 @@ impl Session {
                thread_id: self.conversation_id,
                turn_id: turn_context.sub_id.clone(),
                item,
+                completed_at_ms: Some(now_unix_timestamp_ms()),
            }),
        )
        .await;
--- a/codex-rs/core/src/turn_timing.rs
+++ b/codex-rs/core/src/turn_timing.rs
@@ -107,7 +107,7 @@ fn now_unix_timestamp_secs() -> i64 {
    now_unix_timestamp_ms() / 1000
 }

-fn now_unix_timestamp_ms() -> i64 {
+pub(crate) fn now_unix_timestamp_ms() -> i64 {
    let duration = SystemTime::now()
        .duration_since(UNIX_EPOCH)
        .unwrap_or_default();
--- a/codex-rs/core/tests/suite/items.rs
+++ b/codex-rs/core/tests/suite/items.rs
@@ -303,6 +303,15 @@ async fn web_search_item_is_emitted() -> anyhow::Result<()> {
        })
        .await?;

+    let started = wait_for_event_match(&codex, |ev| match ev {
+        EventMsg::ItemStarted(ItemStartedEvent {
+            item: TurnItem::WebSearch(item),
+            started_at_ms,
+            ..
+        }) => Some((item.clone(), *started_at_ms)),
+        _ => None,
+    })
+    .await;
    let begin = wait_for_event_match(&codex, |ev| match ev {
        EventMsg::WebSearchBegin(event) => Some(event.clone()),
        _ => None,
@@ -311,16 +320,20 @@ async fn web_search_item_is_emitted() -> anyhow::Result<()> {
    let completed = wait_for_event_match(&codex, |ev| match ev {
        EventMsg::ItemCompleted(ItemCompletedEvent {
            item: TurnItem::WebSearch(item),
+            completed_at_ms,
            ..
-        }) => Some(item.clone()),
+        }) => Some((item.clone(), *completed_at_ms)),
        _ => None,
    })
    .await;

    assert_eq!(begin.call_id, "web-search-1");
-    assert_eq!(completed.id, begin.call_id);
+    assert_eq!(started.0.id, begin.call_id);
+    assert!(started.1.is_some());
+    assert_eq!(completed.0.id, begin.call_id);
+    assert!(completed.1.is_some());
    assert_eq!(
-        completed.action,
+        completed.0.action,
        WebSearchAction::Search {
            query: Some("weather seattle".to_string()),
            queries: None,
@@ -369,11 +382,29 @@ async fn image_generation_call_event_is_emitted() -> anyhow::Result<()> {
        })
        .await?;

+    let started = wait_for_event_match(&codex, |ev| match ev {
+        EventMsg::ItemStarted(ItemStartedEvent {
+            item: TurnItem::ImageGeneration(item),
+            started_at_ms,
+            ..
+        }) => Some((item.clone(), *started_at_ms)),
+        _ => None,
+    })
+    .await;
    let begin = wait_for_event_match(&codex, |ev| match ev {
        EventMsg::ImageGenerationBegin(event) => Some(event.clone()),
        _ => None,
    })
    .await;
+    let completed = wait_for_event_match(&codex, |ev| match ev {
+        EventMsg::ItemCompleted(ItemCompletedEvent {
+            item: TurnItem::ImageGeneration(item),
+            completed_at_ms,
+            ..
+        }) => Some((item.clone(), *completed_at_ms)),
+        _ => None,
+    })
+    .await;
    let end = wait_for_event_match(&codex, |ev| match ev {
        EventMsg::ImageGenerationEnd(event) => Some(event.clone()),
        _ => None,
@@ -381,6 +412,10 @@ async fn image_generation_call_event_is_emitted() -> anyhow::Result<()> {
    .await;

    assert_eq!(begin.call_id, call_id);
+    assert_eq!(started.0.id, call_id);
+    assert!(started.1.is_some());
+    assert_eq!(completed.0.id, call_id);
+    assert!(completed.1.is_some());
    assert_eq!(end.call_id, call_id);
    assert_eq!(end.status, "completed");
    assert_eq!(end.revised_prompt, Some("A tiny blue square".to_string()));
--- a/codex-rs/exec/src/event_processor_with_jsonl_output_tests.rs
+++ b/codex-rs/exec/src/event_processor_with_jsonl_output_tests.rs
@@ -20,6 +20,7 @@ fn failed_turn_does_not_overwrite_output_last_message_file() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

--- a/codex-rs/exec/tests/event_processor_with_json_output.rs
+++ b/codex-rs/exec/tests/event_processor_with_json_output.rs
@@ -181,6 +181,7 @@ fn command_execution_started_and_completed_translate_to_thread_events() {
            item: command_item,
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
        }));
    assert_eq!(
        started,
@@ -216,6 +217,7 @@ fn command_execution_started_and_completed_translate_to_thread_events() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));
    assert_eq!(
@@ -250,6 +252,7 @@ fn empty_reasoning_items_are_ignored() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -274,6 +277,7 @@ fn unsupported_items_do_not_consume_synthetic_ids() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -295,6 +299,7 @@ fn unsupported_items_do_not_consume_synthetic_ids() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -327,6 +332,7 @@ fn reasoning_items_emit_summary_not_raw_content() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -362,6 +368,7 @@ fn web_search_completion_preserves_query_and_action() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -399,6 +406,7 @@ fn web_search_start_and_completion_reuse_item_id() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
        }));

    let completed = processor.collect_thread_events(ServerNotification::ItemCompleted(
@@ -413,6 +421,7 @@ fn web_search_start_and_completion_reuse_item_id() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -472,6 +481,7 @@ fn mcp_tool_call_begin_and_end_emit_item_events() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
        }));
    let completed = processor.collect_thread_events(ServerNotification::ItemCompleted(
        ItemCompletedNotification {
@@ -492,6 +502,7 @@ fn mcp_tool_call_begin_and_end_emit_item_events() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -559,6 +570,7 @@ fn mcp_tool_call_failure_sets_failed_status() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -604,6 +616,7 @@ fn mcp_tool_call_defaults_arguments_and_preserves_structured_content() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
        }));
    let completed = processor.collect_thread_events(ServerNotification::ItemCompleted(
        ItemCompletedNotification {
@@ -627,6 +640,7 @@ fn mcp_tool_call_defaults_arguments_and_preserves_structured_content() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -695,6 +709,7 @@ fn collab_spawn_begin_and_end_emit_item_events() {
            },
            thread_id: "thread-parent".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
        }));
    let completed = processor.collect_thread_events(ServerNotification::ItemCompleted(
        ItemCompletedNotification {
@@ -717,6 +732,7 @@ fn collab_spawn_begin_and_end_emit_item_events() {
            },
            thread_id: "thread-parent".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -795,6 +811,7 @@ fn file_change_completion_maps_change_kinds() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -845,6 +862,7 @@ fn file_change_declined_maps_to_failed_status() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -882,6 +900,7 @@ fn agent_message_item_updates_final_message() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -916,6 +935,7 @@ fn agent_message_item_started_is_ignored() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
        }));

    assert_eq!(
@@ -940,6 +960,7 @@ fn reasoning_item_completed_uses_synthetic_id() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -1296,6 +1317,7 @@ fn turn_completion_reconciles_started_items_from_turn_items() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
        }));
    assert_eq!(
        started,
@@ -1378,6 +1400,7 @@ fn turn_completion_overwrites_stale_final_message_from_turn_items() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -1426,6 +1449,7 @@ fn turn_completion_preserves_streamed_final_message_when_turn_items_are_empty()
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

@@ -1470,6 +1494,7 @@ fn failed_turn_clears_stale_final_message() {
            },
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
        },
    ));

--- a/codex-rs/protocol/src/protocol.rs
+++ b/codex-rs/protocol/src/protocol.rs
@@ -1828,6 +1828,9 @@ pub struct ItemStartedEvent {
    pub thread_id: ThreadId,
    pub turn_id: String,
    pub item: TurnItem,
+    #[serde(default, skip_serializing_if = "Option::is_none")]
+    #[ts(optional)]
+    pub started_at_ms: Option<i64>,
 }

 impl HasLegacyEvent for ItemStartedEvent {
@@ -1853,6 +1856,9 @@ pub struct ItemCompletedEvent {
    pub thread_id: ThreadId,
    pub turn_id: String,
    pub item: TurnItem,
+    #[serde(default, skip_serializing_if = "Option::is_none")]
+    #[ts(optional)]
+    pub completed_at_ms: Option<i64>,
 }

 pub trait HasLegacyEvent {
@@ -4592,6 +4598,7 @@ mod tests {
                    queries: None,
                },
            }),
+            started_at_ms: None,
        };

        let legacy_events = event.as_legacy_events(/*show_raw_agent_reasoning*/ false);
@@ -4608,6 +4615,7 @@ mod tests {
            thread_id: ThreadId::new(),
            turn_id: "turn-1".into(),
            item: TurnItem::UserMessage(UserMessageItem::new(&[])),
+            started_at_ms: None,
        };

        assert!(
@@ -4629,6 +4637,7 @@ mod tests {
                result: String::new(),
                saved_path: None,
            }),
+            started_at_ms: None,
        };

        let legacy_events = event.as_legacy_events(/*show_raw_agent_reasoning*/ false);
@@ -4659,6 +4668,7 @@ mod tests {
                stdout: None,
                stderr: None,
            }),
+            started_at_ms: None,
        };

        let legacy_events = event.as_legacy_events(/*show_raw_agent_reasoning*/ false);
@@ -4686,6 +4696,7 @@ mod tests {
                result: "Zm9v".into(),
                saved_path: Some(test_path_buf("/tmp/ig-1.png").abs()),
            }),
+            completed_at_ms: None,
        };

        let legacy_events = event.as_legacy_events(/*show_raw_agent_reasoning*/ false);
@@ -4725,6 +4736,7 @@ mod tests {
                stdout: Some("Done!".into()),
                stderr: Some(String::new()),
            }),
+            completed_at_ms: None,
        };

        let legacy_events = event.as_legacy_events(/*show_raw_agent_reasoning*/ false);
--- a/codex-rs/tui/src/app/tests.rs
+++ b/codex-rs/tui/src/app/tests.rs
@@ -2597,6 +2597,7 @@ async fn inactive_thread_file_change_approval_recovers_buffered_changes() {
        ServerNotification::ItemStarted(ItemStartedNotification {
            thread_id: thread_id.to_string(),
            turn_id: "turn-approval".to_string(),
+            started_at_ms: None,
            item: ThreadItem::FileChange {
                id: "patch-approval".to_string(),
                changes: vec![FileUpdateChange {
@@ -4697,6 +4698,7 @@ async fn replace_chat_widget_reseeds_collab_agent_metadata_for_replay() {
                    codex_app_server_protocol::ItemStartedNotification {
                        thread_id: "thread-1".to_string(),
                        turn_id: "turn-1".to_string(),
+                        started_at_ms: None,
                        item: ThreadItem::CollabAgentToolCall {
                            id: "wait-1".to_string(),
                            tool: codex_app_server_protocol::CollabAgentTool::Wait,
--- a/codex-rs/tui/src/chatwidget/tests/app_server.rs
+++ b/codex-rs/tui/src/chatwidget/tests/app_server.rs
@@ -16,6 +16,7 @@ async fn collab_spawn_end_shows_requested_model_and_effort() {
        ServerNotification::ItemStarted(ItemStartedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
            item: AppServerThreadItem::CollabAgentToolCall {
                id: "call-spawn".to_string(),
                tool: AppServerCollabAgentTool::SpawnAgent,
@@ -34,6 +35,7 @@ async fn collab_spawn_end_shows_requested_model_and_effort() {
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::CollabAgentToolCall {
                id: "call-spawn".to_string(),
                tool: AppServerCollabAgentTool::SpawnAgent,
@@ -90,6 +92,7 @@ async fn live_app_server_user_message_item_completed_does_not_duplicate_rendered
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::UserMessage {
                id: "user-1".to_string(),
                content: vec![AppServerUserInput::Text {
@@ -135,6 +138,7 @@ async fn live_app_server_turn_completed_clears_working_status_after_answer_item(
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::AgentMessage {
                id: "msg-1".to_string(),
                text: "Yes. What do you need?".to_string(),
@@ -287,6 +291,7 @@ async fn live_app_server_file_change_item_started_preserves_changes() {
        ServerNotification::ItemStarted(ItemStartedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
            item: AppServerThreadItem::FileChange {
                id: "patch-1".to_string(),
                changes: vec![FileUpdateChange {
@@ -320,6 +325,7 @@ async fn live_app_server_command_execution_strips_shell_wrapper() {
        ServerNotification::ItemStarted(ItemStartedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
            item: AppServerThreadItem::CommandExecution {
                id: "cmd-1".to_string(),
                command: command.clone(),
@@ -341,6 +347,7 @@ async fn live_app_server_command_execution_strips_shell_wrapper() {
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::CommandExecution {
                id: "cmd-1".to_string(),
                command,
@@ -396,6 +403,7 @@ async fn live_app_server_collab_wait_items_render_history() {
        ServerNotification::ItemStarted(ItemStartedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
            item: AppServerThreadItem::CollabAgentToolCall {
                id: "wait-1".to_string(),
                tool: AppServerCollabAgentTool::Wait,
@@ -418,6 +426,7 @@ async fn live_app_server_collab_wait_items_render_history() {
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::CollabAgentToolCall {
                id: "wait-1".to_string(),
                tool: AppServerCollabAgentTool::Wait,
@@ -471,6 +480,7 @@ async fn live_app_server_collab_spawn_completed_renders_requested_model_and_effo
        ServerNotification::ItemStarted(ItemStartedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
            item: AppServerThreadItem::CollabAgentToolCall {
                id: "spawn-1".to_string(),
                tool: AppServerCollabAgentTool::SpawnAgent,
@@ -490,6 +500,7 @@ async fn live_app_server_collab_spawn_completed_renders_requested_model_and_effo
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::CollabAgentToolCall {
                id: "spawn-1".to_string(),
                tool: AppServerCollabAgentTool::SpawnAgent,
--- a/codex-rs/tui/src/chatwidget/tests/helpers.rs
+++ b/codex-rs/tui/src/chatwidget/tests/helpers.rs
@@ -654,6 +654,7 @@ pub(super) fn handle_agent_reasoning_final(chat: &mut ChatWidget) {
                .last_turn_id
                .clone()
                .unwrap_or_else(|| "turn-1".to_string()),
+            completed_at_ms: None,
            item: AppServerThreadItem::Reasoning {
                id: "reasoning-1".to_string(),
                summary: Vec::new(),
@@ -672,6 +673,7 @@ pub(super) fn handle_entered_review_mode(chat: &mut ChatWidget, review: impl Int
                .last_turn_id
                .clone()
                .unwrap_or_else(|| "turn-1".to_string()),
+            started_at_ms: None,
            item: AppServerThreadItem::EnteredReviewMode {
                id: "review-start".to_string(),
                review: review.into(),
@@ -700,6 +702,7 @@ pub(super) fn handle_exited_review_mode(chat: &mut ChatWidget) {
                .last_turn_id
                .clone()
                .unwrap_or_else(|| "turn-1".to_string()),
+            completed_at_ms: None,
            item: AppServerThreadItem::ExitedReviewMode {
                id: "review-end".to_string(),
                review: String::new(),
@@ -756,6 +759,7 @@ pub(super) fn handle_patch_apply_begin(
        ServerNotification::ItemStarted(ItemStartedNotification {
            thread_id: thread_id(chat),
            turn_id: turn_id.into(),
+            started_at_ms: None,
            item: AppServerThreadItem::FileChange {
                id: call_id.into(),
                changes: file_update_changes_from_tui(changes),
@@ -777,6 +781,7 @@ pub(super) fn handle_patch_apply_end(
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: thread_id(chat),
            turn_id: turn_id.into(),
+            completed_at_ms: None,
            item: AppServerThreadItem::FileChange {
                id: call_id.into(),
                changes: file_update_changes_from_tui(changes),
@@ -796,6 +801,7 @@ pub(super) fn handle_view_image_tool_call(
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: thread_id(chat),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::ImageView {
                id: call_id.into(),
                path,
@@ -815,6 +821,7 @@ pub(super) fn handle_image_generation_end(
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: thread_id(chat),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::ImageGeneration {
                id: call_id.into(),
                status: "completed".to_string(),
@@ -972,6 +979,7 @@ pub(super) fn handle_exec_begin(chat: &mut ChatWidget, item: AppServerThreadItem
                .last_turn_id
                .clone()
                .unwrap_or_else(|| "turn-1".to_string()),
+            started_at_ms: None,
            item,
        }),
        /*replay_kind*/ None,
@@ -1011,6 +1019,7 @@ pub(super) fn complete_assistant_message(
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: chat.thread_id.map(|id| id.to_string()).unwrap_or_default(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::AgentMessage {
                id: item_id.to_string(),
                text: text.to_string(),
@@ -1053,6 +1062,7 @@ pub(super) fn complete_user_message_for_inputs(
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: chat.thread_id.map(|id| id.to_string()).unwrap_or_default(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::UserMessage {
                id: item_id.to_string(),
                content,
@@ -1194,6 +1204,7 @@ pub(super) fn handle_exec_end(chat: &mut ChatWidget, item: AppServerThreadItem)
                .last_turn_id
                .clone()
                .unwrap_or_else(|| "turn-1".to_string()),
+            completed_at_ms: None,
            item,
        }),
        /*replay_kind*/ None,
--- a/codex-rs/tui/src/chatwidget/tests/history_replay.rs
+++ b/codex-rs/tui/src/chatwidget/tests/history_replay.rs
@@ -801,6 +801,7 @@ async fn live_reasoning_summary_is_not_rendered_twice_when_item_completes() {
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::Reasoning {
                id: "reasoning-1".to_string(),
                summary: vec!["Summary only".to_string()],
--- a/codex-rs/tui/src/chatwidget/tests/review_mode.rs
+++ b/codex-rs/tui/src/chatwidget/tests/review_mode.rs
@@ -154,6 +154,7 @@ async fn live_app_server_review_prompt_item_is_not_rendered() {
        ServerNotification::ItemStarted(ItemStartedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            started_at_ms: None,
            item: review_mode_item.clone(),
        }),
        /*replay_kind*/ None,
@@ -166,6 +167,7 @@ async fn live_app_server_review_prompt_item_is_not_rendered() {
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: review_mode_item,
        }),
        /*replay_kind*/ None,
@@ -176,6 +178,7 @@ async fn live_app_server_review_prompt_item_is_not_rendered() {
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: "thread-1".to_string(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::UserMessage {
                id: "review-prompt".to_string(),
                content: vec![AppServerUserInput::Text {
--- a/codex-rs/tui/src/chatwidget/tests/slash_commands.rs
+++ b/codex-rs/tui/src/chatwidget/tests/slash_commands.rs
@@ -1149,6 +1149,7 @@ async fn slash_copy_state_tracks_plan_item_completion() {
        ServerNotification::ItemCompleted(ItemCompletedNotification {
            thread_id: String::new(),
            turn_id: "turn-1".to_string(),
+            completed_at_ms: None,
            item: AppServerThreadItem::Plan {
                id: "plan-1".to_string(),
                text: plan_text.clone(),