mirror of
https://github.com/openai/codex.git
synced 2026-09-05 15:18:41 +00:00
## Why App-server deployments can consume structured JSON logs for operational measurements without requiring an OTEL exporter. Existing tool-result telemetry reports the handler outcome, but it does not separate time spent waiting to dispatch from time spent executing the handler. A compact completion event for the outer, direct tool call lets consumers measure those phases and correlate them with a conversation and turn. Code-mode calls are intentionally excluded so nested runtime calls do not create overlapping events that are easy to double-count. ## What changed - Added a [`ToolCallTimingGuard`](141110a73c/codex-rs/core/src/tools/parallel.rs (L32)) around direct tool calls. Event-only strings and timing state are captured only when the `codex_core::tools::parallel` `INFO` target is enabled. - Added a [`codex.tool_call`](141110a73c/codex-rs/core/src/tools/parallel.rs (L313)) completion event with conversation, turn, tool, call, trace, dispatch, handler, and total timing fields. - Recorded the execution-start marker after the dispatch lock is acquired. Event emission snapshots that marker once so a concurrently starting dispatch cannot produce internally inconsistent fields. - Limited the event to `ToolCallSource::Direct`; [unit coverage](141110a73c/codex-rs/core/src/tools/parallel.rs (L365)) verifies code-mode calls are ignored. - Added [cancellation coverage](141110a73c/codex-rs/core/src/tools/parallel.rs (L408)) that holds the execution gate and verifies a call cancelled before admission emits exactly one dispatch-only timing event. - Added reusable [`JsonLogCapture`](141110a73c/codex-rs/app-server/tests/common/json_logging.rs (L15)) support, a [JSON-logging-specific `TestAppServer` constructor](141110a73c/codex-rs/app-server/tests/common/test_app_server.rs (L172)), and an [end-to-end app-server test](141110a73c/codex-rs/app-server/tests/suite/logging.rs (L52)) that drives a direct `exec_command` through the public v2 JSON-RPC API and validates the emitted JSON event. Exec-server-specific request and process timing remains in the stacked PR #30901. ## Suggested logging filter ```bash LOG_FORMAT=json \ RUST_LOG='warn,codex_core::tools::parallel=info' \ codex app-server ``` ## Event example Identifier and timing values are illustrative. ### `codex.tool_call` ```json { "timestamp": "2026-06-27T03:45:20.443Z", "level": "INFO", "fields": { "message": "tool call completed", "event.name": "codex.tool_call", "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736", "conversation.id": "67e55044-10b1-426f-9247-bb680e5fe0c8", "turn_id": "019f04f8-6ac2-78f1-8625-f04a6d35af18", "tool_name": "exec_command", "call_id": "call_7b8483", "tool_source": "direct", "execution_started": true, "dispatch_duration_ms": 12, "handler_duration_ms": 431, "total_duration_ms": 443 }, "target": "codex_core::tools::parallel" } ``` If execution never starts, `execution_started` is `false`, `handler_duration_ms` is `0`, and `dispatch_duration_ms` covers the full observed lifetime. If a duration cannot be represented as an unsigned 64-bit millisecond value, all three duration fields are omitted rather than populated with a sentinel that could corrupt downstream calculations. ## Test plan - `just test -p codex-core tool_call_timing_guard_ignores_code_mode_source` - `just test -p codex-core cancellation_before_dispatch_admission_logs_dispatch_only_timing` - `just test -p codex-app-server app_server_emits_structured_tool_call_timing_event` --- [//]: # (BEGIN SAPLING FOOTER) Stack created with [Sapling](https://sapling-scm.com). Best reviewed with [ReviewStack](https://reviewstack.dev/openai/codex/pull/30334). * __->__ #30334