[codex] emit per-request TTFT completion telemetry (#30883)

## Why

Codex telemetry pipeline needs a per-request TTFT value. The existing
`codex.turn_ttft` is recorded once per turn, so it cannot represent
later inference requests in the same turn and can miss the beginning of
hidden reasoning.

This restores the low-volume per-request signal proposed in
https://github.com/bk-nvidia/codex/pull/3 without bringing back
per-WebSocket-event TRACE logging.

## What changed

- start a timer when each mapped Responses stream begins
- latch the timer on the first `response.output_item.added`, including
an empty hidden-reasoning item
- attach `ttft_ms` to the existing `codex.sse_event` /
`response.completed` telemetry record
- cover the new completion field with an integration test

## Semantics

The value is per inference request, not per turn. It measures
mapped-stream-to-first-output-item latency, matching the
customer-proposed metric. For HTTP, the stream is already established
before timing begins, so request setup and response-header latency are
excluded.

`response.output_item.added` is a client-visible proxy for the start of
hidden reasoning; this does not claim access to the server's internal
first raw-token timestamp.

## Validation

- `just test -p codex-otel` (47 passed)
- `just test -p codex-core process_sse_emits_completed_telemetry` (1
passed after the final timer-placement change)
- attempted `just test -p codex-core`: 2,855 passed and 53 failed
because of unrelated local-environment failures (missing
`test_stdio_server` fixture binary, shell startup noise, and
timing-sensitive tests); the focused telemetry test passed in that run
as well
This commit is contained in:
xli-oai authored and GitHub committed 2026-07-02 04:45:03 -07:00
1 parent 129ea2aaf5
commit 6ff670bd03
3 files changed
+27 -12

No files matched your search

+18 -12
View File
@@ -567,19 +567,22 @@ async fn process_sse_emits_completed_telemetry() {
mount_sse_once(
&server,
sse(vec![serde_json::json!({
"type": "response.completed",
"response": {
"id": "resp1",
"usage": {
"input_tokens": 3,
"input_tokens_details": { "cached_tokens": 1 },
"output_tokens": 5,
"output_tokens_details": { "reasoning_tokens": 2 },
"total_tokens": 9
sse(vec![
ev_reasoning_item_added("reasoning-1", &[]),
serde_json::json!({
"type": "response.completed",
"response": {
"id": "resp1",
"usage": {
"input_tokens": 3,
"input_tokens_details": { "cached_tokens": 1 },
"output_tokens": 5,
"output_tokens_details": { "reasoning_tokens": 2 },
"total_tokens": 9
}
}
}
})]),
}),
]),
)
.await;
@@ -612,6 +615,9 @@ async fn process_sse_emits_completed_telemetry() {
&& line.contains("cached_token_count=1")
&& line.contains("reasoning_token_count=2")
&& line.contains("tool_token_count=9")
&& extract_log_field(line, "ttft_ms")
.and_then(|ttft_ms| ttft_ms.parse::<i64>().ok())
.is_some()
})
.map(|_| Ok(()))
.unwrap_or(Err("missing response.completed telemetry".to_string()))