feat(timing): book each turn's head and tail as their own buckets - #165
feat(timing): book each turn's head and tail as their own buckets#165uipreliga wants to merge 27 commits into
Conversation
|
Claude finished @uipreliga's task in 1m 37s —— View job Code Review in Progress
|
d809c93 to
7483b67
Compare
Measured live on all five harnesses, generation + tool left 0.1%-42% of the turn unexplained, and the whole remainder sat in two places: before the first generation window opened, and after the last one closed. EventCollector now measures both between the agent's own AgentStart/AgentEnd stamps and the first/last AssistantMessage, and publishes them on TurnRecord. One live turn per harness, residual after all four buckets: antigravity wall 14348 ms startup 0.0 teardown 3.5 -0.010 ms claude-code wall 13295 ms startup 0.0 teardown 834.7 +0.086 ms codex wall 11842 ms startup 5075.2 teardown 13.9 -0.019 ms opencode wall 8157 ms startup 3047.9 teardown 33.1 +0.022 ms pi wall 6906 ms startup 345.4 teardown 26.6 +0.621 ms The turn now reconciles to under a millisecond everywhere. The residual sign flips, so the invariant is |residual| < 1 ms rather than <= wall: head and tail are measured between event stamps while duration_seconds is the agent's own monotonic span, and the field descriptions say so. The head is NOT decomposed further, deliberately. Its composition differs per harness and the stream carries no marker to split it: OpenCode's process spawns in 3 ms and its first event lands at 3921 ms, so CLI boot, provider resolution, dispatch and TTFT are fused. claude-code and Antigravity read a measured 0.0 because their first window already covers dispatch — which is also why nothing folds that time OUT of their generation: for an in-process SDK it IS the generation. Hence names for the interval measured, not for what it contains. `agents/_timing.py` moves to `coder_eval/timing.py`. It is stdlib-only, but importing anything under `agents/` executes that package's __init__, which imports every agent, which imports streaming — so the collector could not reach it. A cycle-free leaf beside the other shared arithmetic, mirroring models/cli_match.py's rationale. Both fields join the golden-stream scrub list. They are measured wall values like duration_seconds and generation_duration_ms beside them; left unscrubbed they drifted 24 of 68 golden tests on an unchanged re-run. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
`harness_startup_ms` / `harness_teardown_ms` were cited as CE058-guarded but matched neither `_TIMING_NAME` nor `_TIMING_CONSTRUCTORS`, so the guard the head/tail work leans on did not exist for the two fields it was named for. Add one alternation arm (`[a-z_]*_(?:startup|teardown)_ms`, leading segment required like the `_duration_ms` arm) and `TurnRecord` to the constructor set, which is what arms form 1. Mutating the real collector call site from `harness_startup_ms=startup_ms` to `0.0` now fires the rule. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
… strip The Unaccounted cell was reporting a harness's CLI boot as unexplained time: opencode's ~3.4s head and claude-code's ~1.0s tail are measured intervals, not residual. Parse `harness_startup_ms` / `harness_teardown_ms` off each turn, sum them across the task's iterations, render them as their own Startup and Teardown cells, and subtract both so Unaccounted is a true residual. Aggregation is `null` — never 0 — when no turn measured that end, mirroring the TurnRecord fields' own contract; a measured 0 (an in-process SDK whose first generation window already covers dispatch) is preserved and renders as `0ms`. An older run without either field renders exactly as before, including the 25% red threshold, which now reads the corrected number in both directions. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…y contain Extend `assert_timing_captured` with the one thing the golden replays can support: a turn that produced an assistant message reports both buckets, and a turn that produced none reports neither. Keyed on that message rather than on `expect_generation_window` — `codex_e_orphan_tool` and `claude_i_in_loop_deadline_break` clear the flag while still having a head and a tail, so the flag would have left them unchecked. No golden regeneration: all 27 dumps already carried both fields and still match. `HARNESS_PARITY.md` gains the rows this change exists to publish — what the FIRST generation window covers per harness, and the measured head and tail — plus the reason the head is deliberately not split into CLI boot vs TTFT, and a Known-divergences note for `TurnStartEvent`'s inconsistent emission point. Live verification (15 runs, 3 turns × 5 harnesses) corrected the identity itself: `Σ tool` books overlapping tool calls twice, and one Pi turn overlapped a Write and a Bash by 18.4 ms, producing exactly an 18.3 ms residual. The tool term is the UNION (`timing.py::busy_ms`), as it already is where a harness subtracts tool time out of a generation window. With all four buckets and the union, every harness reconciles to under 0.012% of wall clock. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Three defects the final review found, each breaking the invariant the change exists to establish. **A placeholder stamp was read as a window bound.** Codex's rollout rebuild, both its sub-agent recovery builders and Claude's synthesized terminal message all stamp `started_at == completed_at == now()` at APPEND time and declare `generation_duration_ms=None` to say no window was measurable. `_overhead_ms` read those stamps anyway, so a Codex turn rebuilt from its rollout — stamped at turn end — booked the ENTIRE TURN as harness startup. Skip them, the same exemption CE059 already makes for the same reason. **The bounds depended on append order.** Codex appends recovered sub-agent messages after the parent's last flush, so `generations[-1]` is not the last generation. Use min/max instead of the first and last list entries. **The four buckets were not disjoint.** Generation windows are tool-subtracted; the head and tail were not. A tool that escapes every window — Antigravity force-closes an orphan at finalization, inside the tail, and backgrounds anything over ten seconds — was counted both as tool and as head or tail. On the committed `antigravity_d_orphaned_tool` fixture that is a residual of -86% of wall clock. `decompose_turn` now subtracts tool time from both ends via the same `busy_ms` the windows use. Also: reset the terminal event when a new turn starts, so the one collector that outlives a turn (EarlyStopWatcher, across retries) cannot pair this attempt's start with the last attempt's end and publish the clamped inversion as a measured 0.0; stop `decompose_run.py` double-counting a sub-agent's generation against its parent Agent call's interval; and say plainly in HARNESS_PARITY.md that claude-code's and antigravity's `0.0` head is a clamped value rather than a measured interval. One golden dump changes, by two lines: `codex_g_items_rebuild` now honestly reports `null` for both buckets instead of a number derived from a placeholder. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The first is the valuable one: a golden-corpus assertion of the four-bucket identity would have caught this work's worst defect, and it is blocked only because 5 of 27 fixtures stamp generations on a clock that is not commensurable with their agent events. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…harness The post-fix re-verification doubled the sample. Figures move by 5-30% with CLI cache warmth, which is why the table already says to read their order of magnitude. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…ntity The golden corpus could not catch a DOUBLE-COUNT, only an absence. That is how the head/tail work shipped a defect where an orphaned tool was booked both in the tool union and in the tail: `antigravity_d_orphaned_tool` reconciled at -86% of its own wall clock while all 72 golden tests passed. Unify the clocks first, because the assertion is meaningless without it. Codex stamped its SDK items at a fixed 2027 epoch and OpenCode a month in the past, while both agents stamp their own lifecycle events with `now()` — so a codex replay recorded a `harness_startup_ms` of ~126 days and no presence-only check could see it. Both catalogues stay declarative with an absolute base; the runners now shift that base onto the replay's own clock, which keeps every derived duration exact (a 250 ms command stays 250 ms) and fixes only the era. No golden dump changes — these stamps are scrubbed. Then assert it: generation + UNION(tool) + head + tail cannot exceed `duration_seconds`, because the four are disjoint. The threshold is relative with an absolute floor, which is what makes it work at fixture scale — the defect reads +55% of wall but only +0.175 ms, so an absolute-only bound generous enough to survive scheduler jitter would have missed it. Mutation-verified: reintroducing the defect fails the antigravity fixture. 22 of 27 scenarios are checked. The other 5 inject SDK stamps in integer MILLISECONDS — 17 to 900 ms of declared item time against a replay that runs in well under one — so no rebasing makes them commensurable and they are exempt via `FICTIONAL_DURATIONS`, named individually with the reason. Closing that last gap needs the agent's own clock faked, not the fixtures' rebased. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The question was whether to emit `AgentStartEvent` before `_build_claude_query`, so the head became a measurement rather than a clamped negative. Measured first: the build is 0.03 ms, and 0.10 ms with four plugin roots — not the hundreds of milliseconds the review hypothesised, because the transport is constructed lazily and plugin resolution is path work. So: no. Moving the emit would not change the number anyway — `last_event_wall`, which becomes the first window's start, is stamped before the build too, so the build sits inside msg0's generation window either way. It would only convert a -0.03 ms clamp into a +0.03 ms measurement, and it would cost the event its `model=effective_model`, which the build resolves and the live renderers display. Surfacing the build cost would need the window re-seeded after it, which is the generation-window seeding change HARNESS_PARITY.md already rules out for an in-process SDK. Both rejections rest on the build being cheap, so guard that rather than leaving it as a claim in a commit message: `TestClaudeHeadIsStructurallyZero` holds it under 50 ms (~300x headroom, best-of-5 so a loaded runner cannot trip it) and its docstring carries the reasoning. The parity doc now states the measured figures instead of implying an unquantified gap. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Live verification on a task with concurrent tool calls — the earlier runs all used `hello_date`, which has none — found the four-bucket identity failing on claude-code alone, by 482 ms and 340 ms on two ~18-25 s turns. The residual equals the generation/tool overlap to within 1.4 ms on every claude-code turn measured, including the two whose overlap was under a millisecond and which reconciled to within 0.1 ms. Cause is a documented exemption whose premise does not hold: claude-code is the one harness that does not subtract tool time from its generation windows, on the reasoning that a tool's execution falls between two windows. A tool's timer starts at the EMISSION carrying its tool_use block, and one assistant turn spans several emissions, so a later emission's window runs concurrently with a tool already timing. The other four harnesses overlapped by ~2.0-2.3 s on the same task and reconciled to within 1.2 ms, because they subtract it. This predates the head/tail work — generation-vs-tool timing is older — but that work's identity is what made it visible, and the parity table was claiming "yes" for all five. Correct the table and the paragraph, state the measurement, and track the fix as a candidate: applying `busy_ms` here changes a published `generation_duration_ms` on the most-used harness, so it needs its own golden regeneration and live pass rather than a quiet amendment here. Also warn in the new golden identity assertion's failure text, so a future claude-code fixture that trips it is not misdiagnosed as a fresh double-count. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
claude-code was the one harness that did not, and the reason it was exempt is measurably wrong. The premise was that because it marks the end of the previous SDK event and reads again when the next message arrives, a tool's execution falls BETWEEN two windows. But a tool's timer starts at the EMISSION carrying its `tool_use` block, and one assistant turn spans several emissions, so a later emission's window runs concurrently with a tool already timing. Measured on a task with five parallel writes, five reads and two concurrent `Bash` calls: 482 ms and 340 ms of overlap on two ~18-25 s turns, and the four-bucket residual came out at exactly -481 ms and -339 ms. The other four harnesses overlapped by ~2.0-2.3 s on the same task and still reconciled to within 1.2 ms, because they subtract it. Two claude-code turns in the same batch whose overlap happened to be under a millisecond reconciled to 0.1 ms, which is what isolated the cause to the missing subtraction rather than to anything about the head and tail. The subtraction cannot happen while flushing: a tool issued by an earlier emission is still running when the next window closes, so its interval does not exist yet. `_subtract_tool_time_from_windows` therefore runs once at finalization, when every span is known, and uses the same `busy_ms` union the other four use — the union and not the sum, because these tools overlap each other too. Sub-agent emissions are skipped: their own tools are not in this command list, and the Agent call that spawned them already spans their run. Re-verified live, same task: claude-code 481 ms / 2.691% -> 1.4 ms / 0.006% over four turns that all carried overlapping tool calls, and all five harnesses reconcile (worst 1.7 ms, 0.012%). `generation_duration_ms` now means the same thing on every harness, so the parity table's identity row is "yes" for all five without a caveat. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The Step stream carries no message id, so every Antigravity `AssistantMessage` was recorded with `message_id: None`. The evalboard groups assistant emissions by that field and falls back to a wall-clock gap threshold when either side lacks one — and PR #164 made this harness's generation windows contiguous, so the gap is now exactly 0 ms and the fallback folds a whole turn's generations into one timeline row. Synthesize the id the way Codex does (`{turn_id}-msg-{gen_index}`), reusing the `_assistant_turns` counter that already counts appended generations, read before its increment so the first id is `-msg-0`. Totals are unaffected: the evalboard sums token buckets across a group, and the turn/generation counts come from `_assistant_turns` Python-side. Only display granularity was lost. The five regenerated goldens are the regression sensor (`message_id` is not scrubbed); the new unit assertion pins the exact id strings, so moving the increment above the append fails loudly instead of silently making the ids 1-based. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Antigravity omitted the kwarg and nothing failed: the field defaulted to None on every message, the evalboard summed the collapsed group so the totals stayed right, and the golden snapshots had ratified the null the day they were written. A snapshot is regenerated from whatever the code currently does, so it catches a later change and never an initial omission — which is why the author-time rule is worth its cost and is the only one of the three sensors that would have failed on the day this shipped. Unlike CE058/CE059 it derives its constructor set from each module's own `coder_eval.models` imports rather than hardcoding the spelling. That closes the blind spot CE058's own docstring concedes: claude_code_agent binds only `AssistantMessage as AssistantMessageTelemetry`, so a name list guards that file's two construction sites purely by coincidence, and an arbitrary `as Msg` is missed outright. Widening the other two the same way is recorded in .claude/harness-candidates.md — it changes two shipped rules and needs its own per-rule mutation check. Verified non-vacuous: stripping the Phase 1 kwarg yields exactly one violation, at the site it came from; the clean tree yields zero, with no suppression anywhere. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Record the per-harness `message_id` source in the Timing-capture table and give the rationale one home: the evalboard groups assistant emissions by the field and falls back to a wall-clock gap when either side lacks one, which cannot split windows that are contiguous by construction. The source comment and the CE060 docstring point here rather than restating it, and this is the only place the 100 ms numeral is written outside runs.ts. The table row names both synthetic sub-agent forms, since a row titled "message_id source" that omits them reads as wrong the first time somebody greps it. Nothing goes in Known divergences — this is a fix. On the consumer side, tighten the existing message_id-splitting case from a 10 ms to a 0 ms gap so the fixture matches the shape this harness really emits. No second case: runs.ts short-circuits on the two ids before the gap is computed, so 10 ms and 0 ms take the identical branch and a parallel case would test nothing new. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Two findings, each raised independently by both final reviewers. CE060's rename-safety was half delivered. Deriving the constructor set from the module's imports removes the local-BINDING spelling, but the class's own name was still a string literal here, so renaming the model — the likelier rename, since the alias exists only because two AssistantMessage types collide — would have disarmed the rule exactly as it disarms the name lists CE060 argues against. It now reads `AssistantMessage.__name__`, the way CE056 imports IN_CONTAINER_ENV. The import walk also traded the alias gap for an import-FORM gap that the docstring's "one remaining blind spot" did not mention: only an absolute `from coder_eval.models import ...` bound anything, so a relative import went silently blind for a whole file (and agents/ does use relative imports), as did every module-alias spelling. Both now fire, verified case by case; the attribute spelling is matched on the attribute alone, deliberately, because the module binding it arrives through is the part a class-binding walk cannot see. What remains — a re-export through an intermediate module — is now stated as such. The attribute test was retargeted at the module-alias form, since with a direct import beside it it had been passing for the wrong reason. The prose in all three surfaces claimed "only granularity was lost", which is measurably false: a grouped emission is one API call to the evalboard's thinking-cost simulator, whose cache cascade is quadratic in that count, so a single-shot Antigravity run had every coefficient pinned at zero; the Messages count and the 10 s slow-generation bar were per-turn too. All three move toward the figure they were always meant to report, so this fix corrects them — but a trend compared across it is not comparing like with like, and the docs now say so. Also: the table gave OpenCode's `None` case where the CE060 docstring asserted it, so the two surfaces in one diff disagreed, and the remaining nulls are not legacy-only. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Three candidates, all deferred with the reason stated rather than the work done: the within-turn-only nature of a synthetic message_id (a negative property over two languages, and the obvious assertion would pass today while catching nothing), the absence of any evalboard test fed by a Python golden (needs a loader and a scrub-aware timestamp story), and the model field's claude-only description (the plan scoped out model changes; no mechanical guard is obvious). A fourth was attempted and dropped: a vitest case asserting that two null-id messages at a 0 ms gap collapse. Its mutation check showed it takes the identical `gap <= SAME_EMISSION_GAP_MS` branch as the existing 50 ms legacy case, so it could not fail for the reason it claimed — which is what the plan's own argument against a parallel case said. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Review feedback on #165. `EventCollector._overhead_ms` bracketed the turn's generation span with every `AssistantMessage`, sub-agent emissions included — unlike its two sibling call sites (`codex_agent._token_usage_from_messages` and `scripts/timing/decompose_run.py`), which both filter on `parent_tool_use_id` for the same reason. A sub-agent's generations sit inside the spawning Agent call's own interval, and the identity the head and tail complete sums generation over the main thread ONLY. Letting a sub-agent message bracket the span shrinks the head or the tail by time no bucket then claims; Codex's recovered child messages carry the CHILD's clock, so it can move either end. Mutation-verified: dropping the filter fails both new cases. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The module docstring named Antigravity and Codex as the only harnesses that interleave tool execution into a generation window. That stopped being true in the same release: #164 gave OpenCode and Pi tiled windows (so a call open at a boundary runs inside two of them), and this branch gives claude-code tool subtraction. All five now subtract, and all five subtract the union. Also names the TypeScript twin and the corpus that holds the two in step, which the docstring did not mention at all. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
ac4e88f to
0c9a067
Compare
…ntity The only sensor for `Σ generation + ∪ tool + head + tail ≈ duration` is one-sided: `_scrub.py` asserts `overshoot <= ...`, which catches a bucket claiming MORE time than the turn contains and says nothing at all about one claiming less. An unmeasured bucket — the defect the next four phases move numbers to fix — passes every test in the suite today. `--max-residual-pct` gates on `abs(share)` per turn, so both signs count. It skips a turn on the turn's OWN `crashed` flag and head/tail pair, never on the record's `final_status`: the orchestrator preserves a crashed partial across a retry, so a SUCCESS record can hold a crashed turn, and an `execute` corpus finalizes every row as NOT_GRADED, which is not a statement about timing. Both skips are counted independently — short-circuiting left the no-window tally reading 0 on the one corpus that contains it. An empty gateable set exits non-zero when a threshold was asked for. A gate that passes because it measured nothing is the failure this file exists to remove. Report-only on landing: nothing passes the flag. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Codex, opencode and pi each carried their own copy of the same window arithmetic — tile from the mark, defend the start with min(), bound the still-open calls at the boundary, subtract the UNION, clamp at zero — plus three near-identical paragraphs explaining why subtracting an open call here does not double-subtract it later. One helper, one docstring. A pure refactor: the golden master passes with NO regeneration, and the three call sites were checked argument by argument against the formulas they replace. Codex's min() moves from the epoch-millisecond domain into the datetime domain, which is safe because `_ms_to_dt` is strictly monotone over ms-spaced inputs, and its `item_start` stays guarded so `_ms_to_dt(None)` cannot fire a third `datetime.now()`. `mark` is keyword-only with no default: a reducer cannot open a window without stating what it tiles from. That constrains the call shape, not the value — pi still passes its own turn start, and the docstring says so rather than claiming the defect is already gone. Antigravity is NOT migrated here. Its span is monotonic while its tool spans are wall, so this signature cannot express it without either dead code or a moved number; it migrates in 5/6, with the deletion of that split. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…l time Both reducers cleared their tool-span list at turn/step START, which is after the window that list feeds has already opened at the mark. A call closing in the gap therefore had its span wiped before the next flush could subtract it, and the window published that call's execution as model time while the call's own duration_ms counted the same milliseconds again. Reproduced against the real state objects, not argued: a call opening at 100, still running when the step finishes at 1000, closing at 1500, with the next window tiling 1000 -> 2000. OpenCode published 1000.0 for a window whose model time was 500.0 — a 100% overstatement, and it needs the non-terminal tool path, which is why the CLI's usual one-shot `completed` event hides it and the measured corpus reads 0.00%. Pi gets the same reset move AND a `gen_mark`, in one commit and in that order. It was the last harness measuring from its own turn start, so every inter-turn gap fell in no bucket — but it was protected from the span-reset defect BY not tiling, so tiling it without moving the reset first would take a correct harness and introduce the 500 ms double-count. The reset is the value here; Pi's tiling gap measures 0.25 ms median over 25 real window pairs. The golden corpus cannot see any of this: `_scrub.py` masks every timing value to a placeholder, and its identity assertion is an upper bound, so under-accounting passes it silently. So both harnesses gain an ms-exact `generation + UNION(tool) == span` test across the boundary, and the reset move is mutation-pinned on each. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Pi shipped measuring its generation window from its own turn_start while four sibling reducers tiled from a mark, so every inter-turn gap fell in no bucket. Nothing caught it: the parity doc asserted the four-bucket identity, the only sensor for that identity checks one side, and Pi's own tests were written against Pi's own arithmetic. A sixth harness rolling its own window would arrive the same way — with a green suite by construction. So the rule is about PROVENANCE, not values: a module in agents/ that publishes a measured `generation_duration_ms` must import `close_window`. Separate id from CE058/CE059/CE060, which are about the values a message carries — one invariant per id is what makes a noqa mean one thing. Its weakness is stated in its own docstring rather than left to be discovered: it proves the helper is imported, never that a given call used it. The value is always a local, so no AST rule can trace it. The sensors for the arithmetic are tests/test_timing_close_window.py and the per-reducer window tests. Two suppressions, not the one the plan predicted. claude-code's is permanent — it subtracts tool time once at finalization across every emission, a shape `close_window` cannot take without a mode flag. Antigravity's is marked TEMPORARY and comes out in 5/6 with its clock conversion. A test pins that exactly these two files need suppressing, so a noqa cannot outlive its reason. CE060 already owned the alias resolution both rules need, so it moves to a shared `_model_ctor.py` rather than being copied: a new import spelling now needs one fix, not two. Every behavioural CE060 test is unchanged. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Antigravity read its window span off time.monotonic() while unioning wall-clock tool intervals and subtracting one from the other. That is the only reason the window could go negative at all, and the clamp underneath it published a 0.0 indistinguishable from a real instant generation, with a debug line as the only trace. One basis makes the disagreement unrepresentable, so the branch and the clamp are deleted rather than left unreachable — a test greps the source to say so. It moves onto close_window in the same commit, which is the only point the two could be exchanged without either dead code or a moved number, and its temporary CE061 suppression comes out with it. Pi's stamps were naive-LOCAL datetime.now(). A DST transition or an NTP step inside a turn lands directly in a generation window — an hour in a field measured in milliseconds, on nightly runs that start at 04:18 and run for hours. A monotonic-derived stamp cannot express it. Codex and OpenCode keep theirs: their tool spans are the CLI's own epoch stamps, unreachable from the host, so converting only the window bounds would put two bases inside one busy_ms subtraction — relocating the defect instead of removing it. This narrows the hazard from five harnesses to two; the parity doc says so rather than implying it is solved. The clock is INJECTED into the turn-state constructors, not read from a module global, and that is the phase's largest blast radius rather than a style choice: a derived stamp does not read datetime.now(), so the four existing monkeypatches would have stopped reaching the reducer and those tests would have quietly measured the real clock and passed. Verified by hand on both harnesses that deleting the injected fake now FAILS. Deadlines stay on raw time.monotonic(), commented at one site per harness: a deadline must not move when the wall clock steps. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Corrects the Pi row, which still claimed a window opening at its own `turn_start`, and adds two rows the table never had: which clock basis each harness's recorded stamps come from, and which of them build their window through the shared helper. The identity row gets a footnote rather than a bare "yes". Its committed sensor is one-sided — it catches a bucket claiming more time than the turn contains and nothing about one claiming less — and it cannot see the magnitudes at all, because the golden scrubber masks every timing value to a placeholder. A doc that asserts an invariant should say what actually checks it. Folds in the time-to-first-token design, which was living in an uncommitted scratch note that had gone stale in four separate ways — including naming a file that never existed. The design is recorded as rules with reasons (name it `first_delta_latency_ms`, never a fifth bucket, first delta of ANY kind, never 0.0) and deliberately without a table of private attribute names, since transcribing those is how the note died: one of them was deleted in 5/6. Nothing is implemented here. No field, no reducer change, no model change. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
A duplicate `turn_end` / `step_finish` with no intervening start republished the previous window in full. `close_window`'s `min(mark, item_start)` exists to stop a backwards clock from inverting a span, but a start stamp left in place after its turn was PUBLISHED is not a backwards clock — it is a stale value sitting before the mark, so the guard reopened the next window back at the previous turn's start. Reproduced by driving the real state object: 3000 ms of generation published for a 2000 ms turn, which `decompose_run.py` would read as a large negative residual and the evalboard would simply sum. The stamp is now cleared at the flush alongside the mark and the span list, for the same reason they are: it has been spent. Regression test on both harnesses. `close_window`'s own docstring had gone stale in the way it was written to prevent. Phase 2 wrote it, then 3/6 gave pi the mark it said pi lacked and 5/6 migrated the antigravity window it said the signature could not express — so the shared helper disagreed with the parity doc about which harnesses use it. The gate script now counts turns it cannot time at all. They were the one exclusion with no tally, in a file built around not discarding evidence silently. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…h now() `c_reasoning_placeholder` and `h_no_turn_completed_crash` injected no item stamps, so `_flush_message` took `_ms_to_dt(None)` for BOTH window bounds — two adjacent `datetime.now()` reads. They collide at microsecond resolution often enough that `assert_timing_captured`'s `completed_at > started_at` failed roughly one run in twenty under parallel load, naming a different scenario each time and giving no hint of the cause. Two separate reviewers of this branch hit it on two different scenarios. Real bounds fix it, at the cost of joining `FICTIONAL_DURATIONS`: integer-ms SDK stamps cannot reconcile against a replay that runs in under a millisecond. That trade is stated where the set is defined. It costs little — a window of width zero reconciled trivially, so the identity check it gives up was near-vacuous, and what replaces it is a stable bounds-span assertion. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…lue move A whole phase of the timing plan was written expecting the golden master to go red when generation numbers changed. It never did: the scrubber masks every timing value, and the one assertion that reads magnitudes is one-sided. Record what closing it would actually take, since it is more than a tolerance constant. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
| # A reducer cannot open a window without STATING what it tiles from. | ||
| # The value is still the caller's to get right — see the docstring. | ||
| with pytest.raises(TypeError): | ||
| close_window(MARK, _at(1000), closed_spans=[], open_started_ats=[]) # type: ignore[misc] |
uipreliga
left a comment
There was a problem hiding this comment.
Review: coder_eval — pr:165
Scope: pr:165 · branch feat/turn-head-tail-timing · 48426ae · 2026-09-12T10:05Z · workflow variant
Change class: complex — rewrites per-turn timing bookkeeping across five agent reducers, adds a new shared timing.py window/residual module, new head/tail token buckets on TurnRecord, three new CE lint rules, and changes the evalboard's timeline decomposition; correctness requires reasoning about control flow and invariants
This is a strong, unusually well-reasoned timing refactor — security is clean at 10/10, the new timing.py seam removes five hand-rolled copies of the window arithmetic, and no confirmed finding is a live correctness bug — but the real risks are that its highest-traffic new code is unguarded and unasserted: an unchecked naive/aware datetime subtraction on every agent's success path can report a completed turn as a crash, claude-code's new tool-time subtraction mutates a persisted metric with literally zero test coverage, and the two sensors meant to police the four-bucket identity are themselves duplicated, partly wrong, and outside CI; fix those four and this merges comfortably at 9.3/10.
Summary
| Axis | Score | 🔴 | 🟠 | 🟡 | 🔵 | Top Issue |
|---|---|---|---|---|---|---|
| 1. Code Quality & Style | 9.5 / 10 | 0 | 0 | 1 | 0 | The four-bucket decomposition / record->tool-span extraction is restated in the gate script and the golden sensor instead of living in the new timing.py both import |
| 2. Type Safety | 9.4 / 10 | 0 | 0 | 1 | 1 | decompose_turn's parameter contract is looser than its sibling close_window: four interchangeable positional `datetime |
| 3. Test Health | 8.8 / 10 | 0 | 1 | 0 | 2 | claude-code's new tool-time subtraction changes every published generation_duration_ms with zero committed coverage (neutering it leaves the suite green) |
| 4. Security | 10 / 10 | 0 | 0 | 0 | 0 | — |
| 5. Architecture & Design | 8.8 / 10 | 0 | 0 | 2 | 2 | The timing seam centralizes the window arithmetic but not the window state machine — this PR replicates OpenCode's 3-part machine into Pi (pi_agent.py:642-656 vs opencode_agent.py:746-761) |
| 6. Error Handling & Resilience | 9 / 10 | 0 | 0 | 2 | 0 | decompose_turn's two subtractions (new in this PR, now on every agent's success path via build_turn_record) are unguarded against a naive/aware stamp mix — a TypeError there turns a completed turn into an AgentCrashError with the trajectory discarded |
| 7. API Surface & Maintainability | 9.4 / 10 | 0 | 0 | 1 | 1 | New 285-line scripts/timing/decompose_run.py sits outside every CI gate (ruff/pyright/tests): 6 pyright errors, zero tests for its exit-code gate |
| 8. Evaluation Harness Quality | 9.5 / 10 | 0 | 0 | 1 | 0 | assert_timing_captured omits the collector's main-thread filter, so the golden head/tail assertion contradicts the producer (and its own identity block 24 lines lower) for any timed sub-agent generation |
Overall Score: 9.3 / 10 · Weakest Axis: Test Health at 8.8 / 10
Totals: 🔴 0 · 🟠 1 · 🟡 8 · 🔵 6 across 8 axes.
Blockers
- [Axis 3] claude-code's new tool-time subtraction changes every published generation_duration_ms with zero committed coverage (neutering it leaves the suite green) (
src/coder_eval/agents/claude_code_agent.py:593) —_ClaudeTurnState._subtract_tool_time_from_windows(new, 47 lines,src/coder_eval/agents/claude_code_agent.py:593, called at:644fromfinalize) mutates a PERSISTED metric on the most-used harness:
overlap = busy_ms(spans, emission.started_at, emission.completed_at) # :632
if overlap > 0.0: # :633
emission.generation_duration_ms = max(emission.generation_duration_ms - overlap, 0.0) # :634grep -n "_subtract_tool_time_from_windows" pr-165 returns exactly 5 hits: 2 in src/coder_eval/agents/claude_code_agent.py, 1 in docs/agents/HARNESS_PARITY.md, 1 in .claude/harness-candidates.md, and ZERO in tests/.
Mutation-verified two ways from the prepared worktree at HEAD 48426ae:
- Replacing the call at
:644with a no-op →uv run pytest tests/ --ignore=tests/test_judge_litellm.py --ignore=tests/test_litellm_judge_live.pyreports5066 passed, 13 skipped. Not one assertion depends on the subtraction. - Instrumenting the
if overlap > 0.0branch with a file-append probe → the branch fires 9 times across the same suite. So the code is executed (and therefore shows as covered at 95.93%) while its effect is never asserted — coverage without verification.
The two existing sensors structurally cannot catch it: tests/_fixtures/golden_streams/_scrub.py:29 lists generation_duration_ms in SCRUB_KEYS, so every claude golden snapshot masks the value to <scrubbed>; and assert_timing_captured's four-bucket check is an upper bound (assert overshoot <= max(_IDENTITY_FLOOR_MS, _IDENTITY_SHARE * wall_ms), _IDENTITY_FLOOR_MS = 0.1, _IDENTITY_SHARE = 0.20) on replays whose whole turn is sub-millisecond, so the 0.1 ms floor swallows any claude-scale overlap.
The PR's own .claude/harness-candidates.md:583 records this change as re-measuring claude-code from 481 ms / 2.691% to 1.4 ms / 0.006% — a live re-measurement, not a test. The sibling harnesses each got a direct reducer test for exactly this arithmetic (e.g. tests/test_opencode_agent.py::TestGenerationWindowExcludesToolExecution::test_the_published_window_reconciles_to_its_own_bounds, tests/test_pi_agent.py at the same shape); claude-code did not.
Add a direct unit test in tests/test_agent_telemetry.py: drive _ClaudeTurnState with two emissions and a CommandTelemetry whose [execution_started_at, execution_completed_at] straddles both windows, call finalize, and assert the exact post-subtraction generation_duration_ms on each — mirroring test_the_published_window_reconciles_to_its_own_bounds. Include the clamp case (a window entirely covered by tool execution reads 0.0, not negative) and the two continue guards at :626-631 (a parent_tool_use_id-tagged sub-agent message and a generation_duration_ms=None message are both left untouched).
Non-blocking, but please consider before merge
- [Axis 1] The four-bucket decomposition / record->tool-span extraction is restated in the gate script and the golden sensor instead of living in the new timing.py both import (
scripts/timing/decompose_run.py:49) —scripts/timing/decompose_run.py:40-69andtests/_fixtures/golden_streams/_scrub.py:120-139ship the same two helpers with only the names changed.decompose_run.py:49:
def _tool_ms(turn: dict) -> float:
spans = []
for command in turn.get("commands") or []:
start = _parse(command.get("execution_started_at"))
end = _parse(command.get("execution_completed_at"))
if start is not None and end is not None and end >= start:
spans.append((start, end))
if not spans:
return 0.0
return busy_ms(spans, min(s for s, _ in spans), max(e for _, e in spans))_scrub.py:120 is the identical body under _tool_union_ms/_parse_stamp. The four-bucket assembly around it is duplicated too: decompose_run.py:89-110 (generation_ms main-thread sum + startup_ms/teardown_ms + _residual_ms) against _scrub.py:248-266 (generation_ms sum + bucket_sum + overshoot). The main-thread predicate (role == "assistant" and parent_tool_use_id is None plus a measurable-duration test) is then restated a third and fourth time in typed form at src/coder_eval/streaming/collector.py:152-157 and src/coder_eval/agents/claude_code_agent.py:627-628.
This PR created src/coder_eval/timing.py precisely so this arithmetic is "defined once and shared" (its own module docstring), and both copies already import busy_ms from it — so the home exists and was only half-used. Move the task.json-shaped decomposition (_parse + tool-union + the main-thread generation sum + the bucket sum/residual) into coder_eval/timing.py (or a small timing_record.py leaf) and have _scrub.py and decompose_run.py both call it. As shipped, the gate and the sensor that are supposed to cross-check each other are the same code pasted twice, so a defect in the shared shape is invisible to both.
2. [Axis 2] decompose_turn's parameter contract is looser than its sibling close_window: four interchangeable positional datetime | None params plus an omissible tool_spans whose default is the documented double-count (src/coder_eval/timing.py:166) — Read at tmp/pr-165-worktree/src/coder_eval/timing.py:166-172:
def decompose_turn(
first_started_at: datetime | None,
last_completed_at: datetime | None,
agent_started_at: datetime | None,
agent_ended_at: datetime | None,
tool_spans: list[tuple[datetime, datetime]] | None = None,
) -> tuple[float | None, float | None]:Two type holes, both in a hot new module every reducer and EventCollector depend on:
(a) Params 1-4 are four consecutive positional parameters of the IDENTICAL type datetime | None. Transposing first_started_at with agent_started_at (or last_completed_at with agent_ended_at) type-checks cleanly under pyright and produces a silently clamped 0.0 head/tail via max(elapsed - busy_ms(...), 0.0) at lines 227/230 — i.e. the exact "measured, and instant" reading that this PR's whole CE058 rationale exists to make unrepresentable. The sole caller (streaming/collector.py:275-279) passes all four positionally, so no test can catch a swap either.
(b) tool_spans defaults to None, yet the function's own docstring at lines 182-191 states that omitting it is wrong, not merely less precise: "tool_spans is what keeps those four buckets DISJOINT, and omitting it is a double-count rather than a lost refinement ... measured on the committed antigravity_d_orphaned_tool fixture as a residual of -86% of wall clock." A parameter whose omission the author has measured at -86% should not be omissible.
The same file already states the correct discipline for the sibling helper at lines 109-116 (def close_window(\n *,) and defends it in its docstring at lines 128-133: "It is keyword-only and has NO default so that no reducer can open a window without stating what it tiles from — which is the defect pi shipped with." Apply the same rule here: make decompose_turn keyword-only (*,) and make tool_spans required with no default. Both are one-line edits with one call site to update.
3. [Axis 5] The timing seam centralizes the window arithmetic but not the window state machine — this PR replicates OpenCode's 3-part machine into Pi (pi_agent.py:642-656 vs opencode_agent.py:746-761) (src/coder_eval/agents/pi_agent.py:642) — timing.py::close_window is a pure function that takes the window state as five arguments, so the state itself — the tile mark, the per-window span list, and the "spent" item start — stays owned by each reducer, and this PR replicates that 3-part machine from OpenCode into Pi essentially verbatim. pi_agent.py:642-656 vs opencode_agent.py:746-761 differ only in identifiers:
# pi_agent.py:642-656
# A message was appended, so the next window starts where this one
# ended. Only a finished turn advances the mark: ...
# it, and only with it — see `on_turn_start`.
self.gen_mark = completed
self.turn_tool_spans = []
# And so is this turn's own start stamp, because it has now been SPENT.
...
self.turn_started_at = None
# opencode_agent.py:746-761
self.gen_mark = completed
self.step_tool_spans = []
...
self.step_started_at = None
The same pair repeats at pi_agent.py:322-323 / opencode_agent.py:324-325 (the gen_mark field) and pi_agent.py:384-388 / opencode_agent.py:373-376 (the "deliberately NOT reset here" note, whose Pi copy literally says see the identical note in opencode_agent.on_step_start). Antigravity keeps a third copy (self._gen_mark_wall / self._tool_spans_since_mark, antigravity_agent.py:1095-1096). The duplicated part is exactly where the PR's own comments say the defects were ("Reproduced: 3000 ms of generation for a 2000 ms turn", pi_agent.py:655).
Codex proves the per-window span list is unnecessary state: codex_agent.py:492-495 passes the whole accumulated self.commands list every flush and never clears it, because busy_ms already drops spans outside [started, now] (if min(e, hi) > max(s, lo), timing.py:95). Three reducers therefore maintain error-prone, hand-cleared state that a fourth demonstrates is not needed. Fold the state into the seam — e.g. a small GenerationWindow in timing.py owning mark, spans and pending_start, with window.add_span(...) / window.close(now) — so a new harness inherits the bookkeeping rather than re-deriving it; drop the per-window lists in favour of Codex's clip-only shape.
4. [Axis 5] decompose_turn measures the turn head/tail by subtracting TurnClock-derived message stamps from raw datetime.now() AgentStart/AgentEnd stamps, leaving Pi and Antigravity a two-basis subtraction in the harness_startup_ms/harness_teardown_ms buckets (src/coder_eval/streaming/collector.py:167) — TurnClock's docstring states the invariant the module exists for: "A turn's bounds and its durations have to share a basis or they can disagree, and the disagreement lands in a field measured in milliseconds" (timing.py:31-32), citing Antigravity mixing a monotonic span with wall intervals as "the only reason its window could go negative at all". The PR's own primary new consumer breaks that invariant. _overhead_ms pairs message stamps with agent-event stamps:
# collector.py:163-167
return decompose_turn(
min(m.started_at for m in generations),
max(m.completed_at for m in generations),
self._agent_start_at,
self._agent_end.timestamp if self._agent_end is not None else None,
and self._agent_start_at = event.timestamp (collector.py:79), where timestamp: datetime = Field(default_factory=datetime.now) (streaming/events.py:89) — a RAW wall read. For the two harnesses this PR migrated, m.started_at / m.completed_at are TurnClock-derived (self.clock.now(), pi_agent.py:605 / antigravity_agent.py:1038), i.e. monotonic-anchored. decompose_turn then computes tail = agent_ended_at - last_completed_at (timing.py:229) across the two bases, and busy_ms(spans, last_completed_at, agent_ended_at) clips TurnClock-derived tool spans against a raw wall bound. An NTP step or DST transition mid-turn — the exact case TurnClock's docstring calls reachable ("Nightly runs start at 04:18 and run for hours", timing.py:41-42) — lands whole in harness_teardown_ms, a milliseconds field, and silently breaks the four-bucket identity. Either stamp AgentStartEvent/AgentEndEvent from the same TurnClock on the harnesses that have one (pass it to the event constructor), or record the turn's head/tail bounds on the clock itself and hand them to the collector, rather than reading two clocks into one subtraction.
5. [Axis 6] decompose_turn's two subtractions (new in this PR, now on every agent's success path via build_turn_record) are unguarded against a naive/aware stamp mix — a TypeError there turns a completed turn into an AgentCrashError with the trajectory discarded (src/coder_eval/timing.py:226) — decompose_turn subtracts stamps it is handed with no awareness check:
226: elapsed = (first_started_at - agent_started_at).total_seconds() * 1000.0and busy_ms has the same exposure one level down at
95: clipped = sorted((max(s, lo), min(e, hi)) for s, e in spans if min(e, hi) > max(s, lo))Both are now on the SUCCESS path of every agent, because EventCollector._overhead_ms (streaming/collector.py:163-173) calls decompose_turn unconditionally from build_turn_record(). In pi_agent.py that call sits inside the turn's try:
1128: state.finalize(status)
1132: record = collector.build_turn_record()
1133: self._end_turn_ok()so a TypeError: can't subtract offset-naive and offset-aware datetimes escapes into except Exception as e: (line 1143) -> _crash_turn(...) -> AgentCrashError. _crash_turn then calls _capture_partial_turn, which re-invokes build_turn_record() and raises again — swallowed by agent.py:_capture_partial_turn, leaving pending_turn = None. Net effect: a turn that ran to completion is reported as a crash, its whole trajectory is discarded, and the retry machinery re-runs it at full API cost, with an error message naming neither the field nor the harness.
Every in-tree stamp is naive today, so this is a SEAM defect, not a live one — but the seam is the documented coder_eval.plugins agent SPI (CLAUDE.md, "Adding a New Agent"), and coder_eval_uipath's Delegate agent already ships out of tree. A third-party reducer that stamps AssistantMessage.started_at with datetime.now(timezone.utc) breaks every turn it records. Add one _require_same_awareness(a, b, ...) guard used by both decompose_turn's two subtractions and busy_ms's clip, raising a message that names which pair disagreed, which side is aware, and that the fix is naive-local stamps (so the plugin's tool spans and window bounds keep one basis). Leave the empty-span case unchecked — nothing is compared there and it has always returned 0.0.
6. [Axis 6] An unresolved tool has no execution bounds on claude-code/codex, so its run-time is booked as harness_teardown_ms — the opposite of antigravity's answer for the identical orphan (src/coder_eval/agents/claude_code_agent.py:619) — Both the per-window subtraction and the head/tail subtraction require BOTH bounds:
616: spans = [
617: (c.execution_started_at, c.execution_completed_at)
618: for c in commands
619: if c.execution_started_at is not None and c.execution_completed_at is not None
620: ]
621: if not spans:
622: returnand in streaming/collector.py:
169: (c.execution_started_at, c.execution_completed_at)
170: for c in self._commands.values()
171: if c.execution_started_at is not None and c.execution_completed_at is not NoneOn claude-code both stamps are written only when a tool RESULT arrives (claude_code_agent.py:1871-1872); _finalize_commands (line 1428-1437) deliberately leaves an unresolved command at duration_ms = None and never touches the execution bounds. Codex is the same shape — close_open_tools publishes the start telemetry verbatim, so execution_completed_at stays None.
Failure scenario: a claude-code turn issues Bash: sleep 600 at t=5s; the tool never returns; turn_timeout fires and finalize(TIMEOUT, crashed=True) emits AgentEndEvent at t=300s. spans is empty, _subtract_tool_time_from_windows returns at line 622, and decompose_turn computes tail = max((300-5)*1000 - busy_ms([], ...), 0) = 295000.0. The record therefore claims 295 s of harness_teardown_ms, a field models/results.py describes as "SDK/CLI finalization, result assembly and process teardown". Antigravity force-closes the same orphan WITH a bound —
1139: orphan = tel.model_copy(update={"result_status": "unknown", "execution_completed_at": self.clock.now()})— so the identical event yields harness_teardown_ms ~= 0 plus 295 s in the tool union there. docs/agents/HARNESS_PARITY.md:32 describes claude-code's bounds as "derived from the measured duration" with no "or neither" qualifier (it gives codex exactly that qualifier), and line 35 claims the four-bucket identity holds for all five without naming the orphan case. Per the repo's own parity rule, a divergence must be fixed or documented: either stamp execution_completed_at at force-close on claude-code/codex (the sibling behaviour, and the bound is real — the tool ran until the turn died), or add a row to the parity table and to harness_teardown_ms's description saying an unbounded orphan's run-time is absorbed into the tail on those two harnesses.
7. [Axis 7] New 285-line scripts/timing/decompose_run.py sits outside every CI gate (ruff/pyright/tests): 6 pyright errors, zero tests for its exit-code gate (scripts/timing/decompose_run.py:21) — The file's own docstring records the gap instead of closing it: lines 21-23 read "Not wired into make: it needs live runs, not fixtures. NOTE scripts/ is / outside the Makefile's LINT_PATHS, so this file is neither formatted nor / ruff-checked — keep it small and dependency-free". That contradicts the Makefile's own stated rationale two lines above LINT_PATHS (Makefile:18-22): ".github/scripts/ is in scope on purpose: release tooling that lives in a real / module ... is exactly what ruff, pyright and pytest can see — leaving it unlinted would forfeit the reason it was extracted." The exclusion is not theoretical: running the repo's own pyright on this file reports 6 errors under settings pyproject.toml explicitly sets to "error" (reportMissingTypeArgument = "error" at pyproject.toml:347, reportImplicitStringConcatenation = "error" at :355) — decompose_run.py:49 def _tool_ms(turn: dict) -> float:, :72 def _turn_buckets(turn: dict) -> ..., :113 def _never_measured(turn: dict) -> bool: plus three implicit-concat sites at :251, :258, :277. Those three dict annotations are exactly where the cross-repo task.json contract is parsed, untyped. There is also no test: git grep decompose_run tests/ returns only prose references in docstrings (tests/test_pi_agent.py:1197,1335; tests/test_codex_agent.py:2307; tests/test_opencode_agent.py:1912), [tool.pytest.ini_options] testpaths = ["tests"], and [tool.coverage.run] source = ["src/coder_eval"]. Meanwhile docs/agents/HARNESS_PARITY.md:46 promotes this file as the ONLY two-sided sensor for the four-bucket identity ("The two-sided check is scripts/timing/decompose_run.py --max-residual-pct N"), so a silent regression in it disarms the one gate the PR's own docs lean on. Fix: add scripts/ to LINT_PATHS in the Makefile and to pyright's include, type the three turn: dict params as dict[str, Any], and add a small unit test for _turn_buckets / _residual_ms / the --max-residual-pct exit code over a synthetic turn dict (no live run needed — the inputs are plain dicts).
8. [Axis 8] assert_timing_captured omits the collector's main-thread filter, so the golden head/tail assertion contradicts the producer (and its own identity block 24 lines lower) for any timed sub-agent generation (tests/_fixtures/golden_streams/_scrub.py:231) — assert_timing_captured builds its key as measurable = [m for m in assistant if m.get("generation_duration_ms") is not None] (line 231) and then asserts harness_startup_ms/harness_teardown_ms are non-None whenever measurable is non-empty (line 235). The producer it claims to mirror applies a THIRD restriction: streaming/collector.py:156-159 filters ... and m.generation_duration_ms is not None and m.parent_tool_use_id is None. The same function already gets this right 17 lines lower — its identity block (line 248-252) filters m.get("parent_tool_use_id") is None with the comment "Main thread only" — so the omission is internal to one function, not a design choice. Consequence: a turn whose only measurable generations are sub-agent ones makes the collector return (None, None) — which tests/test_event_collector.py:576 test_a_turn_whose_only_generations_are_sub_agent_reports_no_overhead pins as CORRECT — while this assertion fails with "harness_startup_ms is None on a turn carrying 1 measurable generation window(s)", blaming the collector for behaviour its own unit test ratifies. Unreachable on today's corpus only because both Codex sub-agent recovery builders and Claude's _synthesize_subagent_terminal_message stamp generation_duration_ms=None; the first harness that recovers a TIMED child generation turns the golden gate red for the wrong reason. Fix: add and m.get("parent_tool_use_id") is None to line 231 and update the docstring paragraph beginning "Both halves of that key are load-bearing" to say three, not two.
Nits
6 🔵 Low findings are omitted here to fit GitHub's 65 536-character comment limit. They are in the full report (tmp/code-review-260912-0305/00-summary.md and the per-axis files).
What's Missing
Parallel paths:
- 🟡 claude-code was left outside the window seam this PR created.
timing.py::close_windowis called by codex, opencode, pi and antigravity; claude-code instead gets a bespoke 42-line_ClaudeTurnState._subtract_tool_time_from_windows(src/coder_eval/agents/claude_code_agent.py:593-634) plus the repo's only permanent# noqa: CE061. The three tiling reducers additionally each keep their own copy of the same 3-part state machine (mark / per-window span list / spent item-start) — this PR replicated it fromopencode_agent.py:746-761intopi_agent.py:642-656essentially verbatim, andantigravity_agent.py:1096-1097holds a third variant — whilecodex_agent.py:492-496proves the per-window span list is unnecessary state (it passes the never-clearedself.commandsand letsbusy_msclip). The seam owns the arithmetic and nothing owns the bookkeeping, which is where every defect the PR's own comments describe actually lived ("3000 ms of generation for a 2000 ms turn",pi_agent.py:655). (trigger: src/coder_eval/timing.py) (restates: Axis 5: The timing seam centralizes the window arithmetic but not the window state machine) - 🟡
TurnClockwas adopted by 2 of 5 harnesses, and on those two the turn's own outer bounds still come from a different clock.EventCollector._overhead_ms(src/coder_eval/streaming/collector.py:163-172) pairs TurnClock-derived message stamps withAgentStartEvent/AgentEndEvent.timestamp, whose default is a rawdatetime.now()(streaming/events.py:89) — neither pi nor antigravity passes atimestamp=kwarg (pi_agent.py:1029,:743;antigravity_agent.py:587,:1167), even though both already construct the clock before emitting the start event. The parity table documents that codex/opencode are deliberately unconverted, but says nothing about the event stamps, so the module's own stated invariant ("a turn's bounds and its durations have to share a basis",timing.py:31-32) is unmet for the turn head and tail on exactly the two harnesses the PR converted. (trigger: src/coder_eval/timing.py) (restates: Axis 5: decompose_turn measures the turn head/tail by subtracting TurnClock-derived message stamps from raw datetime.now() AgentStart/AgentEnd stamps) - 🟡 The golden sensor's generation filter was not kept in step with the producer it mirrors.
collector._overhead_msapplies three restrictions (isinstance AssistantMessage,generation_duration_ms is not None,parent_tool_use_id is None—streaming/collector.py:156-161);tests/_fixtures/golden_streams/_scrub.py:231applies only the first two, while the same function's identity block 24 lines lower (:255) does apply the main-thread filter. The first harness that recovers a timed child generation turns the golden gate red for behaviourtests/test_event_collector.py:575ratifies as correct. _(trigger: tests/_fixtures/golden_streams/scrub.py) (restates: Axis 8: assert_timing_captured omits the collector's main-thread filter) - 🔵 The four-bucket decomposition was re-derived in two places instead of in the module created to own it.
scripts/timing/decompose_run.py:40-69andtests/_fixtures/golden_streams/_scrub.py:120-139ship body-identical_parse/_tool_mshelpers and near-identical bucket assembly, and both already importbusy_msfrom the newcoder_eval.timing— so the shared home exists and was half-used. The two copies have already drifted (decompose_run.py:96guards the generation sum with anisinstancetest the_scrub.pycopy lacks), which matters because the script is documented as the two-sided cross-check on the sensor it duplicates. (trigger: src/coder_eval/timing.py) (restates: Axis 1: The four-bucket decomposition / record->tool-span extraction is restated in the gate script and the golden sensor)
Tests:
- 🟠 No test covers the new claude-code tool-time subtraction, the one change in this PR that alters a persisted metric on the most-used harness.
_subtract_tool_time_from_windows(src/coder_eval/agents/claude_code_agent.py:593, called at:644) has zero hits undertests/; replacing the call with a no-op leaves the whole suite green (5659 passed, identical to baseline). The two existing sensors cannot see it:SCRUB_KEYSmasksgeneration_duration_msin every golden, and the four-bucket identity is an upper bound with a 0.1 ms floor over sub-millisecond replays. The other four harnesses each got a directTestGenerationWindowExcludesToolExecutionreducer test for this exact arithmetic; claude-code is the only one without, and it is the only one whose subtraction is bespoke. (trigger: src/coder_eval/agents/claude_code_agent.py) (restates: Axis 3: claude-code's new tool-time subtraction changes every published generation_duration_ms with zero committed coverage) - 🟡 The new operator gate has no test and sits outside every automated gate.
scripts/timing/decompose_run.py(+285, the first Python file ever added underscripts/) is excluded from pyright'sinclude, fromtestpaths, fromcoverage.source, and from the ruff paths CI actually runs (pr-checks.yml:87/:90hardcodesrc/ tests/). It reports 6 pyright errors under settings this repo sets to "error", including three untypedturn: dictparams at the point where the cross-repotask.jsoncontract is parsed. Its inputs are plain dicts, so_turn_buckets/_residual_ms/ the--max-residual-pctexit code are all unit-testable with no live run. (trigger: scripts/timing/decompose_run.py) (restates: Axis 7: New 285-line scripts/timing/decompose_run.py sits outside every CI gate) - 🔵 The evalboard's new prop wiring is untested across its two hops.
page.tsx:368-369forwardsharnessStartupMs/harnessTeardownMstoCostExplorerSection, which forwards them again toMessageTimelineSection(_sections.tsx:862-863). No test rendersCostExplorerSectionat all (git grep CostExplorerSection evalboard/**/__tests__is empty) — the newmessage-timeline.test.tsxblock rendersMessageTimelineSectiondirectly. Because both props are optional and the consumer coalesces with?? 0, dropping either forward silently renders "—" in both cells and restores the old (over-large) Unaccounted number with every test still green — the same "nothing failed" shape the PR's own CE060 story describes. (trigger: evalboard/app/runs/[id]/[...task]/page.tsx) - 🔵
decompose_turn, the newest public function of the new module, has no direct test.busy_msandclose_windoweach got one (tests/test_timing_union_parity.py,tests/test_timing_close_window.py);decompose_turnis reached only throughEventCollector, whose guards make both of its documented never-measured arms (timing.py:225,:228) unreachable — they show as the module's only two partial branches. Its "Nonemeans never measured" contract is stated but never asserted at the helper. (trigger: src/coder_eval/timing.py) (restates: Axis 3: decompose_turn's documented never-measured guards are never exercised)
Downstream consumers:
- 🟡 claude-code's
generation_duration_mschanged definition and no consumer of that number was reviewed or updated. The PR's test plan states "waves 2–3 touch noevalboard/file" — true of the files, not of the values they render. Every claude-code emission now loses its overlapping tool time (the PR measures 482 ms and 340 ms on two ~18–25 s turns), which shifts: the timeline's Generation cell and per-block split,thinkingShare = thinkingMs / attributableGenMs(_sections.tsx:407), theSLOW_GEN_MS = 10_000red-bar threshold (_sections.tsx:36) — a 10.3 s window that sheds 400 ms stops being flagged — andthinkingSim.ts:301/315, which weights per-message token attribution bygenerationMsand therefore re-distributes simulated thinking cost across a claude turn. None of these is wrong afterwards; the gap is that the value change is unstated, so nobody checked whether any of them encodes the old magnitudes. (trigger: src/coder_eval/agents/claude_code_agent.py) - 🔵 The new buckets stop at the task page; the surface that exists to compare harnesses was not extended.
TaskDetailgainsharnessStartupMs/harnessTeardownMs(evalboard/lib/runs.ts:367-370), butTaskResultSummary,RunPoint/lib/overview.tsand_overview/wall-clock-chart.tsxdo not — and that chart exists precisely for this comparison ("codex runs the suite in roughly a third of claude-code's wall clock"). The PR's headline numbers are per-harness constants (codex ~3.1 s, opencode ~2.5 s, claude/antigravity ~0 per turn), so the only ways to see them over a suite are opening one task page at a time or running the unscheduleddecompose_run.pyby hand. (trigger: evalboard/lib/runs.ts)
Display & mapping dicts:
- 🟡 The Python report renderers were not extended for the new record fields, so the shareable reports and the evalboard now disagree about what a turn's time is made of. The evalboard grew Startup and Teardown cells and a corrected Unaccounted;
reports.py::_generate_generation_metrics_section(:341-361) still emits| Task ID | Total Latency | Turns | Asst Turns | Avg Turn Latency |, andreports_html.py::_render_generation_metrics(:935-964) still renders the same four stats — and CLAUDE.md callsreports_html.py"the evalboard's static twin". Neither file appears in the diff, andgit grep harness_startup_ms src/returns onlymodels/,streaming/andtiming.py: no Python renderer reads either field. A run shared asrun.mdorreport.html(the artifacts a CI gate and an offline reviewer get) cannot see the buckets this PR exists to add, and both renderers already readturns[i].duration_secondsat exactly the level the new fields live at. (trigger: src/coder_eval/models/results.py)
Daily/nightly:
- 🟡 The only two-sided identity gate ships unscheduled, and the PR does not say who runs it or against which nightly runs.
docs/agents/HARNESS_PARITY.md:46namesscripts/timing/decompose_run.py --max-residual-pct Nas the two-sided check, and the same paragraph plus the PR body concede it is "report-only and nothing runs it on a schedule". Meanwhile the committed sensor is one-sided (overshoot <= max(0.1 ms, 20%)) and magnitude-blind (SCRUB_KEYSmasksgeneration_duration_msand both bounds), so a per-harness timing regression on the nightly ships with the suite green — which is exactly what happened for the two defects this PR found by live measurement rather than by a red test. Acknowledging the gap in prose is not the same as closing it: a nightly step (or amaketarget over the previous night'stask.jsoncorpus) is the missing piece, and the gate already exits non-zero on an empty gateable set for this reason. (trigger: scripts/timing/decompose_run.py) - 🔵 No statement of blast radius on the run-record corpus the nightly and the external pipeline consume.
task.jsongains twoTurnRecordfields (additive and optional, so old readers are safe) and, on the most-used harness, one existing field changes meaning. Nothing marks the boundary inside the record itself — onlyenvironment_info.git_commitdistinguishes a pre-change claude run from a post-change one — so the blob-synced historical corpus now holds two definitions of claude-code generation time under one field name, and any longitudinal comparison on the evalboard silently mixes them. Also unstated: what the external eval-runner /coder-eval-uipathconsumer does with the new keys, and that a partially-copied run directory (the known-partial evalboard copy path) renders the new cells as "—" rather than as an error. (trigger: src/coder_eval/models/results.py)
Harness & Lint Improvements
Static checks (lint / type):
- [ce-lint] CE064 — an agent-event stamp must come from the turn clock. New rule
tests/lint/rules/ce064_event_stamp_from_turn_clock.py, wired intotests/lint/runner.py::ALL_RULES. Insrc/coder_eval/agents/, any module that uses aTurnClockmust passtimestamp=EXPLICITLY to everyAgentStartEvent/AgentEndEvent/TurnStartEvent/TurnEndEventit constructs. Same shape as CE060 (the kwarg must be PRESENT, not statically non-None), so reuse_model_ctor's import-alias resolution rather than hardcoding the class spelling. Prevents: Finding A5 (two-basis subtraction).StreamEvent.timestampdefaults to a rawdatetime.now()(streaming/events.py:89) and neither converted harness overrides it — pi_agent.py:1029-1034/:743, antigravity_agent.py:587/:1167 — while their message bounds and tool spans are TurnClock-derived, sodecompose_turnsubtracts across two bases and a mid-turn NTP/DST step lands whole inharness_teardown_ms. - [ce-lint] CE065 — a
TurnClockis injected, never defaulted. New rule intests/lint/rules/: insrc/coder_eval/agents/, a parameter annotatedTurnClock(orTurnClock | None) may not carry a default, andTurnClock()may not be constructed inside a turn-state__init__. This isclose_window's own documented discipline (timing.py:127-133: "keyword-only and has NO default so that no reducer can open a window without stating what it tiles from") applied to the clock itself. Prevents: Finding A5-low (injection contract diverges): pi_agent.py:272clock: TurnClock | None = None+ :285self.clock = clock or TurnClock(), withcommunicatenever passing one — so on the production path the lifetime is invisible and the parameter exists only for tests, against antigravity_agent.py:816's requiredclock: TurnClock. It is also the prerequisite for CE064's fix and for the clock-step and un-scrubbed-golden harness items below. - [pyright] Make
decompose_turn's four bounds untransposable by type. Replace the four baredatetime | Nonepositional parameters (src/coder_eval/timing.py:234-239) with two distinct frozen dataclasses —GenerationBounds(first_started_at, last_completed_at)andAgentBounds(started_at, ended_at)— or twoNewTypes. No config flip is needed:typeCheckingMode = "standard"already rejects a nominal-type mismatch, so the swap becomes a typecheck error atmake typecheckinstead of silence. Prevents: Finding A2/A1/A7 (signature discipline). Transposingfirst_started_atwithagent_started_attype-checks cleanly today and yields an inverted interval →busy_ms0.0 →max(elapsed - 0.0, 0.0)clamped to a MEASURED0.0at timing.py:227/230 — the exact 'timed and instant' reading the CE058 rationale exists to make unrepresentable, and invisible to every test (the golden corpus scrubs both fields and asserts presence only). - [ce-lint] CE066 — every public function in
src/coder_eval/timing.pyis keyword-only and default-free. New rule: a module-leveldefintiming.pywhose name does not start with_must declare*before its first parameter and may not give any parameter a default. Narrow file scope keeps it noise-free; the invariant is already stated in the module forclose_windowand simply not applied to its two siblings. Prevents: Finding A2 part (b):tool_spans: ... | None = None(timing.py:239) is omissible even though the function's own docstring (lines 182-191 in the reviewed revision) measures the omission as a double-count of −86% of wall clock on the committedantigravity_d_orphaned_toolfixture. Also removes part (a)'s positional-ordering hazard if the dataclass fix above is not taken. - [ruff] Put
scripts/inside the format/lint gate. Addscripts/toLINT_PATHS(Makefile:22) AND to the hardcoded path arguments in.github/workflows/pr-checks.yml(ruff format --checkat :87,ruff checkat :90, plus the Windows mirror at :391/:394) — CI does not readLINT_PATHS, so editing the Makefile alone changes nothing in CI. Prevents: Finding A7 (the new 285-linescripts/timing/decompose_run.pysits outside every CI gate) and A7-low (--helpreflow). The file's own docstring records the exclusion instead of closing it, directly contradicting the Makefile's stated rationale two lines aboveLINT_PATHS— and the file is now the two-sided residual gate thatpr-checks.yml:604actually runs. - [pyright] Add
"scripts"to[tool.pyright] include(pyproject.toml:307). This fails immediately and usefully: 6 errors already exist under settings the project sets to"error"—turn: dictat decompose_run.py:49/:72/:113 (reportMissingTypeArgument, pyproject.toml:347) and implicit string concatenation at :251/:258/:277 (reportImplicitStringConcatenation, :355). Type the three parametersdict[str, Any]. Prevents: Finding A7. Those three untypeddictparameters are exactly where the cross-repotask.jsoncontract is parsed, in the only two-sided sensor for the four-bucket identity — a silent regression there disarms the gatedocs/agents/HARNESS_PARITY.md:46leans on. - [ce-lint] CE067 — lint-path parity between the Makefile and CI. A whole-tree check (a
@pytest.mark.linttest class, like CE028/CE035, not aBaseRule): the path arguments toruff format/ruff checkin.github/workflows/pr-checks.ymlmust equalLINT_PATHSin the Makefile, and pyright'sincludemust cover the same tree. Prevents: The second-order cause of Finding A7 — and a live instance: CI lintssrc/ tests/and never.github/scripts/, which the Makefile comment claims is "in scope on purpose". Without this, the two fixes above drift apart again the next time a path is added on one side only. - [ce-lint] CE068 — no bare
task.jsontiming-field literal outside the record decoder (CE053's shape, new domain). Forbid the string literalsexecution_started_at,execution_completed_at,generation_duration_ms,parent_tool_use_id,harness_startup_ms,harness_teardown_msas dict keys anywhere except one decoder module (coder_eval/timing.pyor atiming_record.pyleaf) and the pydantic models that declare them. Enforcing it requires the extraction the finding recommends: move_parse+ the tool-union + the main-thread generation sum + the bucket/residual assembly into the shared module and have both consumers import it. Prevents: Findings A1/A5 (the decomposition is pasted twice) and A8 (assert_timing_capturedomits the producer's main-thread filter). Both copies have ALREADY drifted, which is the argument: decompose_run.py:96 guards the generation sum with anisinstancethe_scrub.py:252-256copy lacks, and_scrub.py:231omits theparent_tool_use_id is Nonepredicate thatstreaming/collector.py:156-159applies and that the same function applies correctly 20 lines lower — so the gate and the sensor that are meant to cross-check each other are the same code, half-diverged. - [ce-lint] CE069 — a force-closed tool must carry both execution bounds. New rule: in
src/coder_eval/agents/, an assignment ormodel_copy(update={...})that setsresult_statusto an unresolved/unknown sentinel must setexecution_completed_atin the same statement. Prevents: Finding A6 (orphan run-time booked as teardown). antigravity_agent.py:1139 does it; claude_code_agent.py:1427-1437 and codex_agent.py:769-782 do not, so a hungBash: sleep 600killed byturn_timeoutproduces 295 s ofharness_startup_ms/harness_teardown_ms— a field documented as "SDK/CLI finalization, result assembly and process teardown" — while the identical event on antigravity lands in the tool union. Per the repo's parity rule, a divergence is fixed or documented; this makes 'fixed' the default and forces a deliberate# noqaotherwise. - [ce-lint] CE070 — one stamp basis: no tz-aware datetime in the stamp producers. Ban
datetime.now(<arg>),.astimezone(, andtimezone.utcinsrc/coder_eval/agents/andsrc/coder_eval/streaming/, so every stamp reachingdecompose_turn/busy_msis naive-local by construction. Stated boundary: lint cannot reach out-of-tree SPI agents (coder_eval_uipath), and the framework's own naiveStreamEvent.timestampdefault makes a merely UTC-stamping plugin break on its first turn — so the runtime_require_same_awareness(a, b, ...)guard the finding recommends is still required. The rule kills the in-tree class; the guard names the disagreeing pair for a plugin. Prevents: Finding A6 (unguarded naive/aware subtraction). Today aTypeErrorat timing.py:226 escapes pi_agent.py's turntry→_crash_turn→AgentCrashError, and_capture_partial_turnre-invokesbuild_turn_record()and raises again (swallowed), so a completed turn is reported as a crash, its trajectory is discarded, and the retry machinery re-runs it at full API cost with an error naming neither the field nor the harness. - [ce-lint] CE071 — every registered agent has a generation-window reconciliation test (registry-derived coverage, CE036's shape). For each module in
src/coder_eval/agents/that registers an agent kind, require a test namedtest_the_published_window_reconciles_to_its_own_boundsin the matchingtests/test_<kind>_agent.py(or the shared telemetry module). Declare the blind spot in the rule's docstring: it proves a test EXISTS, never that any assertion depends on the subtraction — the mutation gate in the harness bucket is its complement. Prevents: Finding A3/A8 (high):_ClaudeTurnState._subtract_tool_time_from_windows(claude_code_agent.py:593, called at :644) mutates a persisted metric on the most-used harness with zero committed coverage —git grepreturns 5 hits, none intests/— while codex, opencode, pi and antigravity each got exactly that test. Neutering the call leaves the suite at the same 5659 passed. - [ce-lint] CE072 — CLAUDE.md structural parity. A derived test in the exact style of the existing CE030 prose check (
tests/test_custom_lint.py:1100-1117): every top-levelsrc/coder_eval/*.pymodule must have a row in CLAUDE.md's Directory Structure tree, and everytests/lint/rules/ceNNN_*.pyid must appear in CLAUDE.md's "Recent additions" prose. Prevents: Finding A5/A1/A7/A8-low (four axes reported it):src/coder_eval/timing.py— a new top-level module owning the four-bucket arithmetic — has no tree row, andgrep -c CE061 CLAUDE.mdreturns 0 while CE060 from the same diff was indexed. The tree enumerates every other top-level module, so the omission is drift, not a convention. - [ce-lint] CE073 —
ArgumentParser(description=__doc__)must passformatter_class=argparse.RawDescriptionHelpFormatter. A five-line AST rule; only reachable oncescripts/is in lint scope, which is itself the point. Prevents: Finding A7-low: the defaultHelpFormatterre-wraps the module docstring, collapsing the one usage line an operator needs to copy into mid-paragraph prose and dumping maintainer-only notes ("scripts/is outside the Makefile's LINT_PATHS…") into--helpoutput. - [ce-lint] Assert the
FICTIONAL_DURATIONSledger instead of describing it. Intests/test_agent_golden_master.py, assertlen(FICTIONAL_DURATIONS) + checked == len(expected/*.json)with the exempt set enumerated — the shapeTestCE061WindowViaCloseWindow::test_each_suppression_is_load_bearingalready uses — and add a parity assertion against the count sentence in.claude/harness-candidates.md:562. Prevents: Finding A3-low: that ledger claims "22 of 27 scenarios are checked… the remaining 5 are exempt" while the committed frozenset holds 7 entries (real figure: 20 of 27). It is the document a future author consults before deciding the identity hole is closed, so a stale count there directly overstates coverage.
Harness improvements (not statically reachable):
- A mutation gate for the timing seam. Add a
make mutate-timingtarget (or a pytest-driven harness) that applies a fixed, committed list of scripted mutations and asserts each turns the suite RED: no-op_subtract_tool_time_from_windows; transposedecompose_turn's head/tail argument pairs; drop themax(..., 0.0)clamp; drop theparent_tool_use_idfilter in_overhead_ms. Run it inpr-checks.ymlbeside the custom-lint step. Why not static: A lint rule can see that a test file and a test name exist (CE071), but never that any assertion depends on the code under test. Finding A3 was proved exactly this way: the mutated and unmutated trees both report 5659 passed, 13 skipped, and the branch is executed 9 times — so it shows as covered at 95.93% while its effect is never asserted. Prevents: A3/A8 high (claude-code tool-time subtraction with zero effective coverage); A3-low (decompose_turn's two never-measured guards, both arcs permanently partial). - Stop scrubbing the timing values in the golden corpus. With the clock injectable on every harness (CE065), replay each scenario against a scripted clock and pin the exact milliseconds for
generation_duration_ms, both window bounds, bothexecution_*_atstamps andharness_startup_ms/harness_teardown_ms, instead of the<scrubbed>placeholder (_scrub.py:29 SCRUB_KEYS). Why not static: Needs a recorded event stream replayed through a real reducer; the values are only deterministic once a clock is injected, which is a runtime property no AST rule can establish. Prevents: A3/A8 high (a claude generation window can move by seconds with every golden green); A6 (orphan attribution invisible); A8 (assert_timing_captured's divergence from its producer). - Make the committed identity sensor two-sided and orphan-aware. Extend the ms-exact contract module so it asserts
-tol <= residual <= tolrather than onlyovershoot <= max(0.1 ms, 20% of wall), and add one case per harness where a tool never resolves, asserting WHERE the hung tool's time is booked. The scenarios already exist (claude_f_orphaned_tool,codex_e_orphan_tool,antigravity_d_orphaned_tool,opencode_d_,pi_d_); only the attribution assertion is missing. Why not static: An undercount is an arithmetic outcome of a replayed stream, not a code shape — and on sub-millisecond synthetic replays the existing 0.1 ms floor swallows any claude-scale overlap, so the tolerance itself has to be made real by a scripted clock. Prevents: A6 (unbounded orphan booked asharness_teardown_mson claude-code and codex, the opposite of antigravity's answer for the identical event); A3/A8 high. - A cross-harness parity replay. One synthetic event script driven through all five reducers, asserting the four buckets agree within tolerance for the same input — including an orphaned tool and a multi-generation turn. Why not static: Parity is a property of five implementations' OUTPUTS on one input. No rule over a single file's AST can compare them, and
docs/agents/HARNESS_PARITY.md:35currently asserts the identity holds for all five with no orphan carve-out — a claim nothing verifies. Prevents: A6 (claude-code/codex vs antigravity orphan divergence); A5 (the replicated window state machine, whose copies are currently correct only by hand); A5 (two-basis head/tail on the two converted harnesses). - A clock-step resilience case. With
TurnClockrequired (CE065) and event stamps clock-derived (CE064), drive a full turn whose wall clock jumps forward and then backward mid-turn, and asserthead + Σ generation + ∪ tool + tail <= duration_secondsstill holds against the MONOTONICduration_secondsboth converted harnesses publish (pi_agent.py:764, antigravity_agent.py:1181). Why not static: Needs simulated time across a whole turn; the defect only manifests under a real clock step, which is precisely the standard the codebase accepted when it addedTurnClock("Nightly runs start at 04:18 and run for hours, so it is reachable rather than theoretical"). Prevents: A5 (raw-wall AgentStart/AgentEnd stamps subtracted from TurnClock-derived message bounds; a forward step inflates the tail whileduration_secondsis unmoved, violating the new corpus invariant, and a backward step silently clamps to 0.0). - Test and cover
scripts/timing/decompose_run.py. Unit tests over synthetic turn dicts for_turn_buckets,_residual_msand the--max-residual-pctexit code (no live run needed — the inputs are plain dicts), and addscriptsto[tool.coverage.run] source. Why not static: The gate's contract is an exit code and a threshold comparison — behaviour, not shape. Static inclusion (the ruff/pyright entries above) fixes the annotations; only a test fixes the gate semantics. Prevents: A7 (the file is the ONLY two-sided residual sensor, is invoked bypr-checks.yml:604, and has zero tests — a silent regression in it disarms the gate the docs lean on); A1/A5 (the duplicated decomposition it hosts). - Fold the window STATE machine into the timing seam, not just the arithmetic. Add a small
GenerationWindowtocoder_eval/timing.pyowningmark,spansandpending_start, withadd_span()/close(now), and adopt Codex's clip-only shape — drop the hand-cleared per-window span lists entirely, sincebusy_msalready discards spans outside[lo, hi](timing.py:95, and codex_agent.py:492-496 proves it by never clearingself.commands). Why not static: CE061/CE063 can only prove that a window's arithmetic came from the shared helper — CE061's own docstring concedes this ("proves the module IMPORTS the helper, never that any particular call used it"). No rule can prove a hand-cleared list was cleared at the right MOMENT, and that bookkeeping is where every defect on this branch lived: 'clearing the list now wipes the span beforestep_finishcan subtract it' (opencode_agent.py:376-377) and '3000 ms of generation for a 2000 ms turn' (pi_agent.py:655). Prevents: A5 (the 3-part machine replicated verbatim from OpenCode into Pi by this PR, with a third variant in antigravity and a fourth in codex). - Pin the documented
Nonecondition ofharness_startup_ms/harness_teardown_mswith the fixture that already contradicts it, and reword both descriptions to the producer's real predicate (no assistant message with a measurablegeneration_duration_mson the main thread). Namecodex_g_items_rebuild.json— one assistant message, both fieldsnull— in an explicit test so the contract and the corpus cannot drift apart again. Why not static: Prose-vs-behaviour agreement needs semantic judgment: no rule can read "None when the turn produced no assistant message" and compare it to a three-predicate filter instreaming/collector.py. CE054-style key round-tripping proves a key is written, not that its description is true. Prevents: A2/A7-low (both new field descriptions atmodels/results.py:339,348state aNonecondition the PR's own committed golden fixture contradicts — ontask.json, which is the cross-repo contract surface). - Write the contract down where an out-of-tree harness will read it: in
docs/agents/HARNESS_PARITY.mdand thecoder_eval.pluginsSPI section of CLAUDE.md, state that (a) an agent's event stamps and its message/tool stamps must come from ONE clock, (b) stamps must be tz-naive local, and (c) a new harness inherits the window state fromtiming.pyrather than re-deriving it. Add the orphan-attribution row the parity table is missing. Why not static: This repo's lint never runs against out-of-tree SPI agents —coder_eval_uipath's Delegate agent already ships separately — so for third-party reducers the documented contract plus the runtime_require_same_awarenessguard are the only available enforcement. Prevents: A6 (naive/aware mix reaching a plugin's first turn as a spuriousAgentCrashError); A5 (two-basis stamps); A5 (state-machine re-derivation); A6 (undocumented orphan divergence —HARNESS_PARITY.md:32gives codex an 'or neither' qualifier that claude-code lacks, and :35 claims the identity for all five).
Top 5 Priority Actions
- Guard the two new subtractions in
src/coder_eval/timing.py:226(and thebusy_msclip at:95) against a naive/aware datetime mix with a_require_same_awarenesshelper that names the disagreeing pair — today a third-party SPI agent that stamps its messagesdatetime.now(timezone.utc)whileStreamEvent.timestampkeeps its naive default turns every completed turn into anAgentCrashErrorwith the trajectory discarded and a full-cost retry, changing final_status for identical agent output. - Add a direct reducer test for
_ClaudeTurnState._subtract_tool_time_from_windows(src/coder_eval/agents/claude_code_agent.py:593, called at:644) covering the overlap, the clamp-to-zero case and the twocontinueguards at:628-631— neutering the call leaves all 5659 tests green, the goldens scrubgeneration_duration_ms, and the four other harnesses each already have this test, so the most-used harness mutates a persisted metric with zero assertions behind it. - Stamp
execution_completed_atwhen claude-code and codex force-close an unresolved tool (src/coder_eval/agents/claude_code_agent.py:619,codex_agent.py:769-782), matching antigravity'santigravity_agent.py:1139, or document the divergence indocs/agents/HARNESS_PARITY.md— otherwise a 600 s hung Bash killed byturn_timeoutpublishes ~295 s ofharness_teardown_ms("SDK/CLI finalization and process teardown") on two harnesses and ~0 ms plus a tool-union span on a third, for the identical event. - Make
decompose_turnkeyword-only andtool_spansrequired (src/coder_eval/timing.py:166), following the discipline its own siblingclose_windowstates at:128-133— four consecutive positionaldatetime | Noneparams let a transposition type-check cleanly and clamp to a measured0.0head or tail, the exact reading CE058 exists to make unrepresentable, and the omissibletool_spansdefault is a double-count the docstring itself measures at -86% of wall clock. - Close the gap in the sensors that guard the four-bucket identity: add the missing
parent_tool_use_id is Nonemain-thread filter attests/_fixtures/golden_streams/_scrub.py:231(it contradicts both the producer atstreaming/collector.py:156-161and the unit test attests/test_event_collector.py:575), and bringscripts/timing/decompose_run.py— the only two-sided residual gate, 285 lines, 6 pyright errors, no test — under ruff/pyright/pytest by editing.github/workflows/pr-checks.ymland pyright'sinclude, not onlyLINT_PATHS.
Stats: 0 🔴 · 1 🟠 · 8 🟡 · 6 🔵 across 8 axes reviewed.

What and why
A turn's wall clock was only partly explained. Generation windows and tool execution were measured; the turn's head (turn start → first generation window opens) and tail (last window closes → turn end) were not, so they surfaced as
Unaccountedin the evalboard. On OpenCode that was ~2.5 s per turn of CLI boot reported as unexplained time.Both are now booked as optional
TurnRecordfields, computed once at theEventCollectorseam.The head's composition genuinely differs per harness and is deliberately not decomposed. On an in-process SDK the first window already covers dispatch and TTFT, so it reads
0.0; on a subprocess harness it fuses CLI boot, provider resolution, dispatch and TTFT with no marker between them (measured on OpenCode: the process spawns in ~3 ms, its first event lands at ~3.9 s). The fields are named for the interval they measure, never for what they contain —docs/agents/HARNESS_PARITY.mdrecords the per-harness composition.The invariant
Nonemeans never measured;0.0means measured and instant. These stay distinguishable end to end, Python model →task.json→ TypeScript → rendered cell (—vs0ms). CE058 is widened to cover both new names and theTurnRecordconstructor.The identity, and the three defects that closed it
Σ generation + ∪ tool + head + tail ≈ duration_seconds. Each of these was found by measurement, not by reading:Writeand aBashby 18.4 ms and produced exactly an 18.3 ms residual.antigravity_d_orphaned_toolfixture that is −86% of wall clock, with all 72 golden tests passing.claude-codedid not subtract tool time from its generation windows at all. It was exempt on the premise that a tool's execution falls between two windows — but a tool's timer starts at the emission carrying itstool_useblock, and one assistant turn spans several emissions, so a later emission's window runs concurrently with a tool already timing. Measured at 482 ms and 340 ms of double-count on two ~18–25 s turns. It cannot subtract while flushing (a tool from an earlier emission is still running when the next window closes), so_subtract_tool_time_from_windowsruns once at finalization.Also fixed: placeholder
now()stamps (rollout rebuild, sub-agent recovery, synthesized terminal — all of which declaregeneration_duration_ms=None) were read as window bounds, so a Codex turn rebuilt from its rollout booked the entire turn as startup; bounds depended on list append order; a collector outliving a turn could pair this attempt's start with the last attempt's end; and the head/tail bracket is taken on main-thread messages only, since a sub-agent's generations bubble into the same stream and the spawning Agent call's own interval already spans them.Wave 2 —
message_id, and CE060Antigravity omitted the
message_idkwarg, so the field defaulted toNoneon every message it ever recorded. The evalboard groups assistant emissions bymessage_idand falls back to a wall-clock gap when either side lacks one — and that fallback cannot split a harness whose windows are contiguous, so a whole turn's generations collapsed into one timeline row. Nothing failed: the consumer sums a group, so the totals stayed right, and the golden snapshots had ratified thenullon the day they were written.The damage was not only granularity. A grouped emission is one API call to the evalboard's thinking-cost simulator, whose prompt-cache cascade is quadratic in that count, so a single-shot Antigravity run had every cascade coefficient pinned at zero.
CE060 now requires the kwarg, and derives its constructor set from each module's own
coder_eval.modelsimports rather than a hardcoded name list — which is what catchesAssistantMessage as AssistantMessageTelemetryinclaude_code_agent.py, a spelling CE058 guards only by coincidence.Wave 3 — one window helper, one clock basis
Four reducers had copy-pasted the same window arithmetic, and Pi had shipped a variant of it that measured from its own
turn_startwhile its siblings tiled from a mark — so every inter-turn gap fell into no bucket. Nothing caught it, because the identity above is asserted on one side only.scripts/timing/decompose_run.pygains a two-sided gate (--max-residual-pct,--min-turn-ms,--include-crashed). It filters on the turn's owncrashedflag and head/tail pair, never the record'sfinal_status: the orchestrator preserves a crashed partial across a retry, and anexecutecorpus finalizes every row asNOT_GRADED, which says nothing about timing. An empty gateable set exits non-zero when a threshold was requested — a gate that passes because it measured nothing is the failure it exists to remove. Report-only on landing; nothing runs it on a schedule.timing.py::close_window()is now the single window implementation; codex, opencode, pi and antigravity all call it.markis keyword-only with no default, so no reducer can open a window without stating what it tiles from. claude-code is the documented exception (it subtracts once at finalization) and carries the only# noqa: CE061.duration_mscounted it again. Driving the real state objects: window 2 published 1000.0 ms where 500.0 is correct. It needs the non-terminal tool path, which is why the CLI's usual one-shotcompletedevent hides it. Pi was protected from it only by not tiling, so itsgen_markand the reset move had to land in one commit, reset first.TurnClockgives antigravity and pi one(wall, monotonic)pair per turn. Antigravity's span was monotonic while its tool intervals were wall — the only reason its window could go negative, behind a clamp indistinguishable from a real instant generation. That branch, its debug line and_gen_mark_monotonicare deleted, not left unreachable. Pi's stamps were naive-local, so a DST transition or NTP step inside a turn landed directly in a generation window. Codex and OpenCode are deliberately not converted: their tool spans are the CLI's own epoch stamps, so converting only the bounds would put two bases inside onebusy_mssubtraction. The hazard is narrowed from five harnesses to two, and the parity doc says so rather than implying it is solved.datetime.now(), so the four existing monkeypatches would have stopped reaching the reducer and those tests would have quietly measured the real clock and passed. Verified by hand on both harnesses that deleting the injected fake now fails.agents/publishing a measuredgeneration_duration_msto importclose_window. Its own docstring states its blind spot: it proves the helper is imported, never that a given call used it. The alias resolution CE060 already owned moved into a sharedtests/lint/rules/_model_ctor.pythat both rules consume.Found in review of that wave and fixed here: a duplicate
turn_end/step_finishwith no intervening start republished the previous window in full — the spent start stamp sat before the mark, soclose_window's backwards-clockmin()reopened the next window at the previous turn's start. Reproduced at 3000 ms of generation for a 2000 ms turn. The stamp is now cleared at the flush alongside the mark and the span list.Live verification
The first pass used
tasks/hello_date, which has no concurrent tools and no sub-agents — so it never exercised the code the fixes touch, and defect 3 survived it. A second pass added a task issuing five parallel writes, five reads and two concurrentBashcalls, plus a sub-agent delegation. Five harnesses, 13 turns of which 9 carried overlapping tool calls:claude-code went from 481 ms / 2.691% → 1.4 ms / 0.007% on the same task.
Re-measured after wave 3, same task, one turn per harness, through the new gate:
The gate exits 0 at
--max-residual-pct 5and0.01, and 1 at0.0001, naming each offending file and turn index — so it is armed rather than vacuously green. A separate sub-agent run reconciles to 1.833 ms on 12.6 s (0.015%) with the sub-agent's 4425.7 ms of nested generation correctly excluded; including it would drive the residual to about −35%.Guard added
The golden corpus could catch an absence but not a double-count. The fixture clocks are now unified — codex stamped its items at a fixed 2027 epoch and opencode a month in the past, while both agents stamp
now(), so a codex replay recorded aharness_startup_msof ~126 days — andassert_timing_capturedasserts the identity. The threshold is relative with an absolute floor, which is what makes it work: defect 2 read +55% of wall but only +0.175 ms.Mutation-verified: reintroducing defect 2 fails
test_antigravity_golden[d_orphaned_tool]; restoring either span reset to turn/step start turns five wave-3 tests red. 20 of 27 scenarios are identity-checked; 7 inject SDK stamps in integer milliseconds (17–900 ms of declared item time against a sub-millisecond replay), so no rebasing makes them commensurable — exempt viaFICTIONAL_DURATIONS, each named with its reason.Two of those exemptions were added here, and the trade is stated where the set is defined:
codex_c_reasoning_placeholderandcodex_h_no_turn_completed_crashinjected no item stamps at all, so_flush_messagetook_ms_to_dt(None)for both window bounds — two adjacentdatetime.now()reads that collide at microsecond resolution often enough to failcompleted_at > started_atroughly one run in twenty under parallel load, naming a different scenario each time. Their identity check was near-vacuous anyway (a zero-width window reconciles trivially), so real bounds buy a stable bounds-span assertion.Known and documented, not fixed
_scrub.py'sSCRUB_KEYSmasksgeneration_duration_msand both bounds to a placeholder, and the one assertion that reads magnitudes is an upper bound. So the committed suite cannot see a per-harness generation number move in either direction — a whole phase of wave 3 was planned expecting the golden master to go red, and it never did. The two-sided check exists but runs by hand against livetask.json. Interim cover is an ms-exactgeneration + ∪ tool == spantest on pi and opencode. Deferred to.claude/harness-candidates.mdwith what closing it would take.0.0head is a clamped negative, not a measured interval — their first window opens before theAgentStartEventstamp. Measured at 0.03 ms (0.10 ms with four plugin roots), so it is the sub-millisecond skew the clamp exists for.TestClaudeHeadIsStructurallyZeropins the build cost so the reasoning can't rot silently.antigravity_d_orphaned_toolfixture.TurnClockremoves it for antigravity and pi; those two keep the CLI's epoch stamps, which cannot be re-derived host-side.first_delta_latency_ms, neverttft_ms, because four harnesses' windows tile so the interval fuses queueing and tool time) and that it is never a fifth bucket. No field, reducer or model change ships for it here..claude/harness-candidates.md: no TypeScript counterpart to CE058, the naive/aware datetime assumption, and widening CE058/CE059 to resolve aliases the way CE060 and CE061 do.Test plan
make verify— 5340 passed, 2 skipped, 92.72% coveragemake lint— 593, including the new CE060 and CE061make evalboard-verify— 742 tests, tsc, build (wave 1; waves 2–3 touch noevalboard/file)hello_dateruns for head/tail magnitudes, 26 runs on a concurrent-tool + sub-agent task across all five harnesses, plus a post-wave-3 re-measurement of all five through the new gate🤖 Generated with Claude Code