Add trace instrumentation for turn startup and response streaming (#56515)

## What changed

- Record time spent waiting for each stream event in `codex.response.receive_wait_ms` on the existing `handle_responses` span.
- Add trace spans for startup prewarm consumption, turn-start lifecycle callbacks, assistant text flushing, and response stream error handling.
- Include the turn ID and lifecycle phase on the turn-start span and the request type on the error-handling span.

GitOrigin-RevId: 7792508c830ef05b03aed01eb840ca7e6577ad0b
This commit is contained in:
bkotsopoulos
2026-10-23 16:09:06 +00:00
committed by copyberry
parent bca6f238cb
commit 810501d60d
4 changed files with 13 additions and 0 deletions
+1
View File
@@ -54,6 +54,7 @@ pub(crate) struct ExhaustedResponseRetry {
/// Returns `Ok(())` when the caller should retry the request loop, or the original error when
/// it is terminal or the retry budget is exhausted.
#[tracing::instrument(level = "trace", skip_all, fields(request = ?request))]
pub(crate) async fn handle_response_stream_error(
retry_state: &mut ResponsesStreamRetryState,
max_retries: u64,
@@ -286,6 +286,7 @@ impl Session {
));
}
#[tracing::instrument(level = "trace", skip_all)]
pub(crate) async fn consume_startup_prewarm_for_regular_turn(
&self,
cancellation_token: &CancellationToken,
+10
View File
@@ -2,6 +2,7 @@ use std::collections::HashMap;
use std::collections::HashSet;
use std::sync::Arc;
use std::sync::atomic::Ordering;
use std::time::Instant;
use crate::client::ModelClientSession;
use crate::client_common::Prompt;
@@ -2418,6 +2419,7 @@ async fn emit_streamed_assistant_text_delta(
}
/// Flush buffered assistant text parser state when an assistant message item ends.
#[instrument(level = "trace", skip_all)]
async fn flush_assistant_text_segments_for_item(
sess: &Session,
turn_context: &TurnContext,
@@ -2430,6 +2432,7 @@ async fn flush_assistant_text_segments_for_item(
}
/// Flush any remaining buffered assistant text parser state at response completion.
#[instrument(level = "trace", skip_all)]
async fn flush_assistant_text_segments_all(
sess: &Session,
turn_context: &TurnContext,
@@ -2815,14 +2818,21 @@ async fn try_run_sampling_request(
gen_ai.usage.output_tokens = field::Empty,
codex.usage.reasoning_output_tokens = field::Empty,
codex.usage.total_tokens = field::Empty,
codex.response.receive_wait_ms = field::Empty,
);
let receive_started = Instant::now();
let event = stream
.next()
.instrument(trace_span!(parent: &handle_responses, "receiving"))
.or_cancel(&preempt)
.or_cancel(&cancellation_token)
.await;
// Split the existing iteration span without adding another span per streamed delta.
handle_responses.record(
"codex.response.receive_wait_ms",
receive_started.elapsed().as_secs_f64() * 1000.0,
);
// Account for an already-received terminal error even if cancellation raced it.
// Cancellation still stops ordinary stream events before they can run tools.
let event = match event {
+1
View File
@@ -13,6 +13,7 @@ use crate::session::session::Session;
use crate::session::turn_context::TurnContext;
impl Session {
#[tracing::instrument(level = "trace", skip_all, fields(turn_id = %turn_context.sub_id, phase = ?phase))]
pub(super) async fn emit_turn_start_lifecycle(
self: &Arc<Self>,
turn_context: &TurnContext,