[hooks] Expose per-model-request timing in rollout for observability integrations

Open 💬 3 comments Opened Aug 7, 2026 by yunhungo

Feature request

Please expose stable timing for each model sampling request in the persisted rollout available through the Stop hook's transcript_path, or provide an equivalent model lifecycle hook.

For each sampling request, observability integrations need:

  • model request start time
  • first output time, or the existing per-request ttft_ms
  • model response completion time
  • a stable correlation key linking those timings to emitted response_item records, token usage, and the existing turn_id

This would allow integrations to map the lifecycle to Langfuse generation.startTime, generation.completionStartTime, and generation.endTime without inferring model timing from tool events.

Current behavior

The current HookEventName enum contains these actual variants:

PreToolUse, PermissionRequest, PostToolUse, PreCompact, PostCompact, SessionStart, SessionEnd, UserPromptSubmit, SubagentStart, SubagentStop, and Stop.

There is no model-request, response-start, first-output, or response-completed hook. Source: HookEventName.

The current StopRequest contains these actual fields:

session_id, turn_id, cwd, transcript_path, model, permission_mode, stop_hook_active, last_assistant_message, and target.

Source: StopRequest.

A real Codex rollout contains a turn-level terminal record with this field shape (values redacted; field names are unchanged):

{
  "timestamp": "<redacted>",
  "type": "event_msg",
  "payload": {
    "type": "task_complete",
    "turn_id": "<redacted>",
    "started_at": "<redacted>",
    "completed_at": "<redacted>",
    "duration_ms": "<redacted>",
    "time_to_first_token_ms": "<redacted>"
  }
}

The public protocol defines the same actual fields on TurnCompleteEvent, and documents time_to_first_token_ms as the duration between turn start and the first model token. Source: TurnCompleteEvent.

A turn can contain multiple sampling requests separated by tools, so this turn-scoped value cannot identify completion start for later generations.

The relevant per-request rollout boundary currently has this actual field shape (values redacted; field names are unchanged):

{
  "timestamp": "<redacted>",
  "type": "response_item",
  "payload": {
    "type": "custom_tool_call",
    "id": "<redacted>",
    "status": "completed",
    "call_id": "<redacted>",
    "name": "exec",
    "internal_chat_message_metadata_passthrough": {
      "turn_id": "<redacted>"
    }
  }
}
{
  "timestamp": "<redacted>",
  "type": "event_msg",
  "payload": {
    "type": "token_count",
    "info": {
      "last_token_usage": {
        "input_tokens": "<redacted>",
        "cached_input_tokens": "<redacted>",
        "cache_write_input_tokens": "<redacted>",
        "output_tokens": "<redacted>",
        "reasoning_output_tokens": "<redacted>",
        "total_tokens": "<redacted>"
      }
    }
  }
}

These records do not expose the enclosing sampling request's start, first output, or completion timestamps. A post-hoc tracing integration therefore has to infer generation boundaries from response_item and token_count; in tool-calling turns that can make generation timing collapse onto, or include, tool execution.

Existing signals that could be reused

Codex already computes relevant timing internally:

  • TurnCompleteEvent.time_to_first_token_ms is exposed, but it is turn-scoped.
  • PR #30883 attaches the actual per-request field ttft_ms to the existing codex.sse_event / response.completed telemetry record.
  • ItemStartedEvent.started_at_ms and ItemCompletedEvent.started_at_ms / completed_at_ms describe item lifecycles, not the enclosing model sampling request. Source: ItemStartedEvent and ItemCompletedEvent.

The requested change could reuse the existing per-request ttft_ms measurement rather than measure TTFT again. Please persist/expose it together with model-request start and response-completion timing at the hook/rollout boundary. The exact new schema is intentionally left to maintainers; all field names shown above are fields Codex already emits or defines today.

Reproduction

  1. Configure a Stop hook that reads transcript_path.
  2. Run a turn with multiple model requests separated by tool calls.
  3. Inspect the rollout around response_item and event_msg.token_count.
  4. Attempt to reconstruct one generation observation per model request.
  5. The turn-level time_to_first_token_ms cannot be assigned to later requests, and no per-request model lifecycle is available.

Related

  • #30883 added per-request TTFT completion telemetry.
  • #33420 requests a streamed assistant-message hook, but assistant text deltas do not cover reasoning-only or tool-call responses and do not provide request start.
  • #37317 discusses native OTel response signals and their volume.
  • #35363 added item start times, which helps item timing but does not establish the model-request lifecycle.

View original on GitHub ↗

3 Comments

yunhungo · 20 days ago

Implementation is ready in the fork:

GitHub currently reports that this repository limits opening pull requests to collaborators, so the upstream PR could not be created from this account. The comparison is ready for a collaborator to review or open as a PR.

yunhungo · 20 days ago

Implementation summary (ready for review if invited)

The proposed change is fully implemented in the fork branch:
https://github.com/yunhungo/codex/tree/codex/per-request-rollout-timing
(commit 9fb70b9e "Persist per-response model timing", based on upstream 3b366654)

Design (following the issue's request to reuse existing signals):

  • New ModelResponseTiming on RawResponseCompletedEvent:
  • request_started_at_ms: wall-clock timestamp taken immediately before the transport request
  • first_output_at_ms: wall-clock timestamp of the first response.output_item.added
  • completed_at_ms: wall-clock timestamp when response.completed is observed
  • ttft_ms: the existing mapped-stream-to-first-output latency, reused (not re-measured)
  • turn_id added to RawResponseCompletedEvent as the correlation key linking timing to the enclosing turn, response_item records, and token usage
  • should_persist_event_msg in codex-rs/rollout now persists RawResponseCompleted so Stop hook consumers can read it via transcript_path (previously dropped)
  • Serialization stays backward compatible: new fields are optional with serde(default, skip_serializing_if)
  • Same timing propagated through codex-api SSE and RawResponseCompletedNotification (JSON schema + TS types + precomputed bundles), and through compact paths

Tests: new end-to-end mock-server test codex-rs/core/tests/suite/raw_response_timing.rs asserts the persisted rollout contains exactly one RawResponseCompleted per response with a non-empty turn_id and monotonic timing (request_started_at_ms <= first_output_at_ms <= completed_at_ms), matching the issue's reconstruction scenario.

Happy to rebase onto latest main and address review feedback if the team would like to take this forward.

boombx403-byte · 9 days ago

Hi @yunhungo, this subagent persistence/history issue aligns with some boundary anomalies observed in multi-agent rollouts. Codex Rescue Alpha5 provides read-only lifecycle and subagent boundary diagnostics, cleanly separating historical start markers from current live execution state without altering the source rollout.

If you have access to the local session, you can run a non-destructive check:

pip install codex-rescue==0.1.0a5
codex-rescue doctor --latest

No raw session data is required, and please redact private paths if you share any output.