Files
codex/codex-rs/core/src/turn_timing_tests.rs
mchen-oai ccec84b148 Add turn start timestamp to turn metadata (#19473)
## Why
- Without change: MCP tool calls receive
`_meta["x-codex-turn-metadata"]` with `session_id` and `turn_id`.
- Issue: MCP servers may want the turn start timestamp to measure
internal latency relative to turn start.

## What Changed
- With change: turn metadata now includes `turn_started_at_unix_ms`,
which is propagated to MCP tool calls in
`_meta["x-codex-turn-metadata"]`.

## Verification
- `codex-rs/core/src/mcp_tool_call_tests.rs`
- `codex-rs/core/src/turn_metadata_tests.rs`
- `codex-rs/core/src/turn_timing_tests.rs`
- `codex-rs/core/tests/responses_headers.rs`
- `codex-rs/core/tests/suite/search_tool.rs`
2026-04-28 16:36:59 +00:00

149 lines
4.3 KiB
Rust

use codex_protocol::items::AgentMessageItem;
use codex_protocol::items::TurnItem;
use codex_protocol::models::ContentItem;
use codex_protocol::models::FunctionCallOutputPayload;
use codex_protocol::models::ResponseItem;
use pretty_assertions::assert_eq;
use std::time::Instant;
use std::time::SystemTime;
use std::time::UNIX_EPOCH;
use super::TurnTimingState;
use super::response_item_records_turn_ttft;
use crate::ResponseEvent;
#[tokio::test]
async fn turn_timing_state_records_ttft_only_once_per_turn() {
let state = TurnTimingState::default();
assert_eq!(
state
.record_ttft_for_response_event(&ResponseEvent::OutputTextDelta("hi".to_string()))
.await,
None
);
state.mark_turn_started(Instant::now()).await;
assert_eq!(
state
.record_ttft_for_response_event(&ResponseEvent::Created)
.await,
None
);
assert!(
state
.record_ttft_for_response_event(&ResponseEvent::OutputTextDelta("hi".to_string()))
.await
.is_some()
);
assert_eq!(
state
.record_ttft_for_response_event(&ResponseEvent::OutputTextDelta("again".to_string()))
.await,
None
);
}
#[tokio::test]
async fn turn_timing_state_records_ttfm_independently_of_ttft() {
let state = TurnTimingState::default();
state.mark_turn_started(Instant::now()).await;
assert!(
state
.record_ttft_for_response_event(&ResponseEvent::OutputTextDelta("hi".to_string()))
.await
.is_some()
);
assert!(
state
.record_ttfm_for_turn_item(&TurnItem::AgentMessage(AgentMessageItem {
id: "msg-1".to_string(),
content: Vec::new(),
phase: None,
memory_citation: None,
}))
.await
.is_some()
);
assert_eq!(
state
.record_ttfm_for_turn_item(&TurnItem::AgentMessage(AgentMessageItem {
id: "msg-2".to_string(),
content: Vec::new(),
phase: None,
memory_citation: None,
}))
.await,
None
);
}
#[tokio::test]
async fn turn_timing_state_records_turn_started_epoch_millis() {
let state = TurnTimingState::default();
let before = SystemTime::now()
.duration_since(UNIX_EPOCH)
.expect("system time should be after unix epoch")
.as_millis();
let started_at_unix_ms = state.mark_turn_started(Instant::now()).await;
let after = SystemTime::now()
.duration_since(UNIX_EPOCH)
.expect("system time should be after unix epoch")
.as_millis();
assert!(u128::try_from(started_at_unix_ms).is_ok_and(|ms| before <= ms && ms <= after));
assert_eq!(
state.started_at_unix_secs().await,
Some(started_at_unix_ms / 1000)
);
}
#[test]
fn response_item_records_turn_ttft_for_first_output_signals() {
assert!(response_item_records_turn_ttft(
&ResponseItem::FunctionCall {
id: None,
name: "shell".to_string(),
namespace: None,
arguments: "{}".to_string(),
call_id: "call-1".to_string(),
}
));
assert!(response_item_records_turn_ttft(
&ResponseItem::CustomToolCall {
id: None,
status: None,
call_id: "call-2".to_string(),
name: "custom".to_string(),
input: "echo hi".to_string(),
}
));
assert!(response_item_records_turn_ttft(&ResponseItem::Message {
id: None,
role: "assistant".to_string(),
content: vec![ContentItem::OutputText {
text: "hello".to_string(),
}],
phase: None,
}));
}
#[test]
fn response_item_records_turn_ttft_ignores_empty_non_output_items() {
assert!(!response_item_records_turn_ttft(&ResponseItem::Message {
id: None,
role: "assistant".to_string(),
content: vec![ContentItem::OutputText {
text: String::new(),
}],
phase: None,
}));
assert!(!response_item_records_turn_ttft(
&ResponseItem::FunctionCallOutput {
call_id: "call-1".to_string(),
output: FunctionCallOutputPayload::from_text("ok".to_string()),
}
));
}