diff --git a/src/providers/codex/mod.rs b/src/providers/codex/mod.rs index 280f9d34..c97cf22f 100644 --- a/src/providers/codex/mod.rs +++ b/src/providers/codex/mod.rs @@ -404,16 +404,59 @@ impl CodexProvider { let error = empty_buffered_completion_error(); drop_live_continuation_for_retry(&mut continuation); if attempt >= MAX_EMPTY_COMPLETION_RETRIES { + log.warn( + "codex_empty_completion_exhausted", + Some(empty_completion_exhausted_fields( + &req_id, + transport, + &resolved.model, + attempt + 1, + "max_attempts", + upstream_started_at.elapsed().as_millis(), + )), + ); abort_compaction_attempt(ctx.session_id.as_deref(), compaction_attempt); abort_continuation_for_owner(&request_continuation); return map_codex_error_to_response(&error); } let delay = compute_backoff_delay(attempt, None); if delay.exceeds_budget { + log.warn( + "codex_empty_completion_exhausted", + Some(empty_completion_exhausted_fields( + &req_id, + transport, + &resolved.model, + attempt + 1, + "backoff_budget", + upstream_started_at.elapsed().as_millis(), + )), + ); abort_compaction_attempt(ctx.session_id.as_deref(), compaction_attempt); abort_continuation_for_owner(&request_continuation); return map_codex_error_to_response(&error); } + log.warn( + "codex_empty_completion_retry", + Some(serde_json::Map::from_iter([ + ("reqId".to_string(), serde_json::json!(&req_id)), + ( + "configuredTransport".to_string(), + serde_json::json!(transport), + ), + ("model".to_string(), serde_json::json!(&resolved.model)), + ("failedAttempt".to_string(), serde_json::json!(attempt + 1)), + ( + "maxAttempts".to_string(), + serde_json::json!(MAX_EMPTY_COMPLETION_RETRIES + 1), + ), + ("delayMs".to_string(), serde_json::json!(delay.wait_ms)), + ( + "ms".to_string(), + serde_json::json!(upstream_started_at.elapsed().as_millis()), + ), + ])), + ); attempt += 1; sleep(delay.wait_ms).await; }; @@ -726,6 +769,7 @@ async fn live_stream_response( transport: config::CodexTransport, ) -> Response { let model = model.to_string(); + let started_at = Instant::now(); let request_continuation = continuation.clone(); let mut cleanup = LiveRequestStateCleanup::new( request_continuation.clone(), @@ -796,6 +840,7 @@ async fn live_stream_response( request_continuation.clone(), request_body.clone(), compaction, + transport, ) .await { @@ -825,11 +870,37 @@ async fn live_stream_response( continue; } if attempt >= MAX_RETRYABLE_LIVE_STREAM_RETRIES { + if is_empty_completion_error(&error) { + create_logger("codex").warn( + "codex_empty_completion_exhausted", + Some(empty_completion_exhausted_fields( + &ctx.req_id, + transport.as_str(), + &model, + attempt + 1, + "max_attempts", + started_at.elapsed().as_millis(), + )), + ); + } cleanup.abort(); return map_codex_error_to_response(&error); } let delay = compute_backoff_delay(attempt, error.retry_after.as_deref()); if delay.exceeds_budget { + if is_empty_completion_error(&error) { + create_logger("codex").warn( + "codex_empty_completion_exhausted", + Some(empty_completion_exhausted_fields( + &ctx.req_id, + transport.as_str(), + &model, + attempt + 1, + "backoff_budget", + started_at.elapsed().as_millis(), + )), + ); + } cleanup.abort(); return map_codex_error_to_response(&error); } @@ -861,6 +932,7 @@ async fn live_stream_response_once( request_continuation: ContinuationReservation, request_body: translate::request::ResponsesRequest, compaction: LiveStreamCompaction, + configured_transport: config::CodexTransport, ) -> LiveStreamStart { let estimated_input_tokens = count_translated_tokens(&request_body); let mut translator = LiveStreamTranslator::with_estimated_input_tokens( @@ -943,6 +1015,18 @@ async fn live_stream_response_once( && is_codex_success_terminal_event(&payload) && !translator.has_semantic_output() { + create_logger("codex").warn( + "codex_empty_completion_retry", + Some(serde_json::Map::from_iter([ + ("reqId".to_string(), serde_json::json!(&ctx.req_id)), + ( + "configuredTransport".to_string(), + serde_json::json!(configured_transport.as_str()), + ), + ("model".to_string(), serde_json::json!(model)), + ("stream".to_string(), serde_json::json!(true)), + ])), + ); return provider_retry(&upstream_events, empty_live_completion_error()); } if translator.has_semantic_output() && !pending_chunk.is_empty() { @@ -1265,6 +1349,39 @@ where (headers, Body::from_stream(stream)).into_response() } +/// True when *error* is the empty-completion 503 rather than some other +/// retryable failure sharing the live-stream retry loop. +fn is_empty_completion_error(error: &client::CodexError) -> bool { + error.detail.as_deref() == Some(EMPTY_CODEX_COMPLETION_DETAIL) +} + +/// Log fields for giving up on an empty completion, on either exit. +/// +/// `reason` separates the two: `"max_attempts"` when the retry budget ran +/// out, `"backoff_budget"` when the next delay would have exceeded the +/// backoff budget. They produce the same 503, so the log is the only place +/// the difference is visible. +fn empty_completion_exhausted_fields( + req_id: &str, + configured_transport: &str, + model: &str, + attempts: u32, + reason: &str, + elapsed_ms: u128, +) -> serde_json::Map { + serde_json::Map::from_iter([ + ("reqId".to_string(), serde_json::json!(req_id)), + ( + "configuredTransport".to_string(), + serde_json::json!(configured_transport), + ), + ("model".to_string(), serde_json::json!(model)), + ("attempts".to_string(), serde_json::json!(attempts)), + ("reason".to_string(), serde_json::json!(reason)), + ("ms".to_string(), serde_json::json!(elapsed_ms)), + ]) +} + fn empty_buffered_completion_error() -> client::CodexError { client::CodexError { status: 503, @@ -2008,6 +2125,7 @@ mod tests { compact_boundary: false, attempt: None, }, + config::CodexTransport::Http, ) .await { @@ -2181,6 +2299,35 @@ mod tests { assert_eq!(response.headers()["x-should-retry"], "false"); } + #[test] + fn empty_completion_exhausted_fields_distinguish_the_two_give_up_reasons() { + let max = empty_completion_exhausted_fields( + "req-1", + "auto", + "gpt-6-sol", + 11, + "max_attempts", + 157_000, + ); + assert_eq!(max["reqId"], "req-1"); + assert_eq!(max["configuredTransport"], "auto"); + assert!(max.get("transport").is_none()); + assert_eq!(max["model"], "gpt-6-sol"); + assert_eq!(max["attempts"], 11); + assert_eq!(max["reason"], "max_attempts"); + assert_eq!(max["ms"], 157_000); + + let budget = empty_completion_exhausted_fields( + "req-1", + "websocket", + "gpt-6-sol", + 4, + "backoff_budget", + 20_000, + ); + assert_eq!(budget["reason"], "backoff_budget"); + } + #[test] fn live_start_statusless_websocket_handshake_error_is_retryable() { let err = client::CodexError {