Track code-mode cell lifecycle and result buffering time (#55653)

## What changed

- Add `CodeModeCellTiming` notifications for yielded executions, terminal waits, and unavailable cells, with thread, call, and cell identifiers.
- Measure how long completed results remain buffered before retrieval and carry `result_buffered_for` through the runtime, stdio protocol, and gRPC response metadata. Immediate delivery reports zero; waits without a completed result report no buffering measurement.
- Default missing buffering data to zero for compatibility with older hosts.

## Testing

Extend runtime tests to verify buffering duration with a paused clock and retrieval through termination. Add gRPC conversion tests for nanosecond precision, optional metadata, and the distinction between immediate delivery and no completed result.

GitOrigin-RevId: 60c0c5a3affa69ac3779bf1812fca50f5748af76
This commit is contained in:
Ruslan Nigmatullin
2026-10-20 18:53:06 +00:00
committed by copyberry
parent 801bd4d773
commit 87f3c3284e
38 changed files with 397 additions and 123 deletions
@@ -10,6 +10,7 @@ use codex_code_mode_protocol::WaitOutcome;
use codex_code_mode_protocol::grpc as proto;
use codex_protocol::ToolName;
use serde_json::Value as JsonValue;
use tonic::Response;
use tonic::Status;
use super::validation;
@@ -111,6 +112,7 @@ pub(super) fn execution_outcome(
content_items,
error_text,
code_mode_host_duration,
..
} => (
cell_id,
content_items,
@@ -130,7 +132,8 @@ pub(super) fn execution_outcome(
pub(super) fn wait_response(
outcome: WaitOutcome,
) -> Result<proto::WaitResponse, MissingCodeModeHostDuration> {
) -> Result<Response<proto::WaitResponse>, MissingCodeModeHostDuration> {
let buffered = outcome.result_buffered_for();
let state = match outcome {
WaitOutcome::LiveCell(response) => {
proto::wait_response::State::LiveCell(execution_outcome(response)?)
@@ -139,7 +142,14 @@ pub(super) fn wait_response(
proto::wait_response::State::MissingCell(execution_outcome(response)?)
}
};
Ok(proto::WaitResponse { state: Some(state) })
let mut response = Response::new(proto::WaitResponse { state: Some(state) });
if let Some(buffered) = buffered {
let nanos = u64::try_from(buffered.as_nanos()).unwrap_or(u64::MAX);
response
.metadata_mut()
.insert(proto::RESULT_BUFFERED_FOR_NS_METADATA, nanos.into());
}
Ok(response)
}
fn content_item(item: FunctionCallOutputContentItem) -> proto::ContentItem {
@@ -69,7 +69,7 @@ fn rejects_missing_names_unknown_tool_kinds_and_invalid_json_schemas() {
#[test]
fn maps_text_image_audio_and_terminal_error_without_losing_details() {
let outcome = execution_outcome(RuntimeResponse::Result {
let response = wait_response(WaitOutcome::LiveCell(RuntimeResponse::Result {
code_mode_host_duration: Some(Duration::from_nanos(/*nanos*/ 123_456_789)),
cell_id: CellId::new("cell".to_string()),
content_items: vec![
@@ -84,12 +84,22 @@ fn maps_text_image_audio_and_terminal_error_without_losing_details() {
audio_url: "data:audio/wav;base64,YQ==".to_string(),
},
],
result_buffered_for: Duration::from_nanos(42),
error_text: Some("failed".to_string()),
});
}))
.unwrap();
assert_eq!(
outcome,
Ok(proto::ExecutionOutcome {
response
.metadata()
.get(proto::RESULT_BUFFERED_FOR_NS_METADATA)
.unwrap(),
"42"
);
let state = response.into_inner().state.expect("wait outcome");
assert_eq!(
state,
proto::wait_response::State::LiveCell(proto::ExecutionOutcome {
code_mode_host_duration_ns: 123_456_789,
cell_id: "cell".to_string(),
content_items: vec![
@@ -119,6 +129,28 @@ fn maps_text_image_audio_and_terminal_error_without_losing_details() {
);
}
#[test]
fn wait_metadata_distinguishes_an_unbuffered_result_from_no_result() {
let result = RuntimeResponse::Result {
cell_id: CellId::new("cell".to_string()),
content_items: Vec::new(),
error_text: None,
result_buffered_for: Duration::ZERO,
code_mode_host_duration: Some(Duration::ZERO),
};
for (outcome, expected) in [
(WaitOutcome::LiveCell(result.clone()), Some("0")),
(WaitOutcome::MissingCell(result), None),
] {
let response = wait_response(outcome).unwrap();
let buffered = response
.metadata()
.get(proto::RESULT_BUFFERED_FOR_NS_METADATA)
.map(|value| value.to_str().unwrap());
assert_eq!(buffered, expected);
}
}
/// Encoding must not turn a missing request measurement into measured zero,
/// including when no live cell remains to supply output.
#[test]
@@ -136,6 +168,9 @@ fn grpc_encoding_rejects_untimed_runtime_output() {
WaitOutcome::LiveCell(response.clone()),
WaitOutcome::MissingCell(response),
] {
assert_eq!(wait_response(outcome), Err(MissingCodeModeHostDuration));
assert_eq!(
wait_response(outcome).unwrap_err(),
MissingCodeModeHostDuration
);
}
}
+2 -6
View File
@@ -248,9 +248,7 @@ impl GrpcCodeModeHost {
}
};
let outcome = outcome.with_code_mode_host_duration(received_at.elapsed());
let response = conversions::wait_response(outcome)
.map_err(|error| Status::internal(error.to_string()))?;
Ok(Response::new(response))
conversions::wait_response(outcome).map_err(|error| Status::internal(error.to_string()))
}
async fn cancel_wait_request(
@@ -292,9 +290,7 @@ impl GrpcCodeModeHost {
let _permit = self.state.request_permit()?;
let outcome = session.terminate(CellId::new(request.cell_id)).await?;
let outcome = outcome.with_code_mode_host_duration(received_at.elapsed());
let response = conversions::wait_response(outcome)
.map_err(|error| Status::internal(error.to_string()))?;
Ok(Response::new(response))
conversions::wait_response(outcome).map_err(|error| Status::internal(error.to_string()))
}
}
@@ -48,6 +48,7 @@ async fn start_cell_reports_when_initial_response_is_enqueued() {
code_mode_host_duration: None,
cell_id: cell_id.clone(),
content_items: Vec::new(),
result_buffered_for: Duration::ZERO,
error_text: None,
})
.expect("initial response receiver");