Skip to content

Commit 5f61818

Browse files
committed
Add live hook profiling to launch readiness benchmark
1 parent 0e906db commit 5f61818

23 files changed

Lines changed: 2223 additions & 176 deletions

docs/agent-conversation-profile.md

Lines changed: 34 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -10,9 +10,10 @@ records.
1010
`experiment/agent-conversation-profile-modern-codex.mjs` is a compatibility
1111
variant for newer Codex JSONL streams. It keeps the same CLI and output shape,
1212
but additionally recognizes Codex `agent_message`, `command_execution`,
13-
`mcp_tool_call`, `file_change`, and turn/thread lifecycle records. Use it for
14-
recent `codex exec --json` captures when the original profiler reports most of
15-
the run as `unknown` or double-counts started/completed MCP calls.
13+
`mcp_tool_call`, `file_change`, live harness `harness.phase` records, and
14+
turn/thread lifecycle records. Use it for recent `codex exec --json` captures
15+
when the original profiler reports most of the run as `unknown`, double-counts
16+
started/completed MCP calls, or needs to consume live Codex hook timings.
1617

1718
## Usage
1819

@@ -41,9 +42,12 @@ export paths so the run is deterministic and auditable.
4142
The output directory contains:
4243

4344
- `combined.perfetto.json`: one combined Chrome trace JSON file with one track
44-
per conversation.
45-
- `<left-label>.perfetto.json`: split trace for the left conversation.
46-
- `<right-label>.perfetto.json`: split trace for the right conversation.
45+
per profile row, including conversation, activity, tool group, and command
46+
group.
47+
- `<left-label>.perfetto.json`: split trace for the left conversation, with one
48+
track per activity or tool command group.
49+
- `<right-label>.perfetto.json`: split trace for the right conversation, with
50+
one track per activity or tool command group.
4751
- `combined.snakeviz.prof`: combined synthetic Python pstats profile for
4852
SnakeViz.
4953
- `<left-label>.snakeviz.prof`: SnakeViz profile for the left conversation.
@@ -103,14 +107,17 @@ Viewer profiles and the `Time By Activity` summary use derived activity buckets
103107
that are meant for high-level agent timing:
104108

105109
- `tool`: time spent running an agent action until it completes. This is
106-
derived from tool-call and file-change records and, when a matching result
107-
exists, spans from the start timestamp to the result timestamp. Tool-result
108-
and file-change-result records remain in the raw kind summary but are not
109-
counted as separate activity because their time is represented by the parent
110-
tool span.
111-
- `reasoning`: reasoning or thinking records.
112-
- `user_query`: user-message records.
113-
- `agent_response`: assistant text response records.
110+
derived from live hook phases when present, otherwise from tool-call and
111+
file-change records.
112+
- `reasoning`: reasoning or thinking records. In hook-instrumented traces, this
113+
is the measured model span from prompt/result handoff until the next tool
114+
call. In raw Codex traces without hook phases, this is inferred from
115+
turn-start-to-first-item gaps and tool-result or file-change-result gaps until
116+
the next Codex item.
117+
- `user_query`: user-message records. In hook-instrumented traces, this comes
118+
from `UserPromptSubmit` and the session-start boundary.
119+
- `agent_response`: assistant text response records. In hook-instrumented
120+
traces, this comes from the final model span ending at `Stop`.
114121
- `system`: system-message records.
115122
- `other`: non-metadata records that do not fit the activity model.
116123

@@ -121,14 +128,17 @@ is the loc subcommand, for example `status`, `diff`, `push`, or `create-page`.
121128
Shell commands that run more than one loc subcommand join the subcommands with
122129
`+`, for example `diff+status`. For non-loc shell calls, the detail is the
123130
executable name such as `git`, `gh`, `sed`, or `find`; for non-shell tools, it is
124-
the tool name such as `list_issues` or `API-post-search`.
131+
the tool name such as `list_issues` or `API-post-search`. Flattened viewer rows
132+
include the tool group in the command frame, for example
133+
`command:loc:diff+status` or `command:non_loc:git`.
125134

126135
Harness metadata records, such as Claude terminal `result:success` records,
127136
`system:turn_duration`, `system:local_command`, attachments, file-history
128-
deltas, and hook summaries, are excluded from Perfetto traces, viewer profiles,
129-
and `totals_by_activity` because they can duplicate elapsed time that is already
130-
represented by user, assistant, reasoning, and tool spans. They are reported
131-
separately under `metadata` and in the Markdown `Excluded Metadata` section.
137+
deltas, and raw `harness.hook` summaries, are excluded from Perfetto traces,
138+
viewer profiles, and `totals_by_activity` because they can duplicate elapsed
139+
time that is already represented by user, assistant, reasoning, and tool spans.
140+
They are reported separately under `metadata` and in the Markdown
141+
`Excluded Metadata` section.
132142

133143
## Timing Model
134144

@@ -142,6 +152,11 @@ record has a start timestamp but no duration, the script infers the end from
142152
the next timestamp in the same conversation. If there is no next timestamp, it
143153
uses `--default-duration-ms` or `1000ms`.
144154

155+
For the Codex launch-readiness harness, live Codex hooks write `harness.phase`
156+
records during the running session. The modern profiler prefers those measured
157+
phase records for any activity bucket they cover and leaves the underlying raw
158+
Codex stream records in the audit-oriented kind and metadata summaries.
159+
145160
Top-level wall time is computed from non-metadata event spans when any are
146161
present. Metadata timestamps can still act as run-boundary markers, but metadata
147162
durations do not extend wall time; this keeps terminal aggregate records from

0 commit comments

Comments
 (0)