Skip to content

feat(timing): book each turn's head and tail as their own buckets - #165

Open
uipreliga wants to merge 35 commits into
mainfrom
feat/turn-head-tail-timing
Open

feat(timing): book each turn's head and tail as their own buckets#165
uipreliga wants to merge 35 commits into
mainfrom
feat/turn-head-tail-timing

Conversation

@uipreliga

@uipreliga uipreliga commented Sep 11, 2026

Copy link
Copy Markdown
Collaborator

#164 has merged; base is now main and this PR carries 27 commits in three waves: the head/tail buckets it opened with, then message_id (CE060), then a timing-architecture pass (CE061, close_window, TurnClock).

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 Unaccounted in the evalboard. On OpenCode that was ~2.5 s per turn of CLI boot reported as unexplained time.

Both are now booked as optional TurnRecord fields, computed once at the EventCollector seam.

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.md records the per-harness composition.

The invariant

None means never measured; 0.0 means measured and instant. These stay distinguishable end to end, Python model → task.json → TypeScript → rendered cell ( vs 0ms). CE058 is widened to cover both new names and the TurnRecord constructor.

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:

  1. The tool term must be the union, not the sum. One Pi turn overlapped a Write and a Bash by 18.4 ms and produced exactly an 18.3 ms residual.
  2. The four buckets were not disjoint. Generation windows are tool-subtracted; the head and tail were not. A tool escaping every window — Antigravity force-closes an orphan at finalization, inside the tail — was counted twice. On the committed antigravity_d_orphaned_tool fixture that is −86% of wall clock, with all 72 golden tests passing.
  3. claude-code did 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 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 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_windows runs once at finalization.

Also fixed: placeholder now() stamps (rollout rebuild, sub-agent recovery, synthesized terminal — all of which declare generation_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 CE060

Antigravity omitted the message_id kwarg, so the field defaulted to None on every message it ever recorded. The evalboard groups assistant emissions by message_id and 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 the null on 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.models imports rather than a hardcoded name list — which is what catches AssistantMessage as AssistantMessageTelemetry in claude_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_start while 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.py gains a two-sided gate (--max-residual-pct, --min-turn-ms, --include-crashed). It filters on the turn's own crashed flag and head/tail pair, never the record's final_status: the orchestrator preserves a crashed partial across a retry, and an execute corpus finalizes every row as NOT_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. mark is 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.
  • A reproduced 100% overstatement. Both pi and opencode cleared their tool-span list at turn/step startafter the window it feeds had already opened at the mark — so a call closing in the gap lost its span and the window published that call's execution as model time while the call's own duration_ms counted 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-shot completed event hides it. Pi was protected from it only by not tiling, so its gen_mark and the reset move had to land in one commit, reset first.
  • TurnClock gives 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_monotonic are 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 one busy_ms subtraction. The hazard is narrowed from five harnesses to two, and the parity doc says so rather than implying it is solved.
  • The clock is injected, not read from a module global. That is the phase's real blast radius: 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.
  • CE061 requires any module in agents/ publishing a measured generation_duration_ms to import close_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 shared tests/lint/rules/_model_ctor.py that both rules consume.

Found in review of that wave and fixed here: a duplicate turn_end / step_finish with no intervening start republished the previous window in full — the spent start stamp sat before the mark, so close_window's backwards-clock min() 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 concurrent Bash calls, plus a sub-agent delegation. Five harnesses, 13 turns of which 9 carried overlapping tool calls:

harness worst |residual| % of wall
antigravity 0.047 ms 0.000%
claude-code 1.351 ms 0.007%
codex 0.376 ms 0.002%
opencode 0.326 ms 0.002%
pi 1.718 ms 0.012%

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:

harness wall residual % of wall
antigravity 11.2 s −0.025 ms 0.000%
pi 18.6 s −0.115 ms 0.001%
opencode 22.3 s −0.145 ms 0.001%
codex 20.0 s −0.127 ms 0.001%
claude-code 23.6 s +0.766 ms 0.003%

The gate exits 0 at --max-residual-pct 5 and 0.01, and 1 at 0.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 a harness_startup_ms of ~126 days — and assert_timing_captured asserts 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 via FICTIONAL_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_placeholder and codex_h_no_turn_completed_crash injected no item stamps at all, so _flush_message took _ms_to_dt(None) for both window bounds — two adjacent datetime.now() reads that collide at microsecond resolution often enough to fail completed_at > started_at roughly 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

  • The golden corpus pins that a timing value exists, never what it is. _scrub.py's SCRUB_KEYS masks generation_duration_ms and 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 live task.json. Interim cover is an ms-exact generation + ∪ tool == span test on pi and opencode. Deferred to .claude/harness-candidates.md with what closing it would take.
  • claude-code's and antigravity's 0.0 head is a clamped negative, not a measured interval — their first window opens before the AgentStartEvent stamp. Measured at 0.03 ms (0.10 ms with four plugin roots), so it is the sub-millisecond skew the clamp exists for. TestClaudeHeadIsStructurallyZero pins the build cost so the reasoning can't rot silently.
  • "A tool outside every generation window" has no live coverage — defect 2's fix rests on unit tests and the antigravity_d_orphaned_tool fixture.
  • A genuinely backwards clock on codex or opencode can still overlap two windows. TurnClock removes it for antigravity and pi; those two keep the CLI's epoch stamps, which cannot be re-derived host-side.
  • Time to first token is not measured and cannot be derived from what is recorded. The parity doc now carries the design — including the naming rule (first_delta_latency_ms, never ttft_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.
  • Other guards deferred to .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 verify5340 passed, 2 skipped, 92.72% coverage
  • make lint593, including the new CE060 and CE061
  • make evalboard-verify — 742 tests, tsc, build (wave 1; waves 2–3 touch no evalboard/ file)
  • Live: 30 hello_date runs 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

@github-actions

github-actions Bot commented Sep 11, 2026

Copy link
Copy Markdown

Claude finished @uipreliga's task in 1m 37s —— View job


Code Review in Progress

Todo List:

  • Read .github/code_review.md for review standards
  • Read CLAUDE.md for project conventions
  • Review the diff (git diff origin/fix/timing-capture-and-reporting...HEAD)
  • Examine changed files for cross-file consistency
  • Check timing identity invariant implementation
  • Verify test coverage for the new timing fields
  • Complete review and provide feedback

@uipreliga
uipreliga force-pushed the fix/timing-capture-and-reporting branch from d809c93 to 7483b67 Compare September 12, 2026 00:17
Base automatically changed from fix/timing-capture-and-reporting to main September 12, 2026 00:27
uipreliga and others added 18 commits September 11, 2026 17:40
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>
@uipreliga
uipreliga force-pushed the feat/turn-head-tail-timing branch from ac4e88f to 0c9a067 Compare September 12, 2026 00:48
uipreliga and others added 2 commits September 11, 2026 18:33
…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>
uipreliga and others added 7 commits September 11, 2026 19:06
…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>
Comment thread tests/test_timing_close_window.py Fixed
uipreliga and others added 5 commits September 11, 2026 21:59
Nothing in the suite could see a timing VALUE move. The golden corpus masks
`generation_duration_ms`, both window bounds, both `execution_*_at` stamps and
both head/tail fields to a placeholder, and its identity check is one-sided
(`overshoot <= ...`), so an UNDERCOUNT — the defect class this area keeps
producing — passed every test. A prototype of the next phase changed published
generation figures on two harnesses and left all 5340 tests green.

`tests/test_timing_identity_contract.py` is that sensor. Each of the five
harnesses drives its own reducer off a clock the test moves by hand, then feeds
the messages and commands it produced through a real `EventCollector` — the
same seam production measures the head and tail at — and asserts

    head + Σ generation + UNION(tool) + tail == the scripted span

with `pytest.approx`, an equality and so two-sided. Magnitudes are real only
where a scripted clock makes them real, which is why this cannot live in
`_scrub.py`: those replays run in ~0.3 ms of synthetic wall clock, where a
relative bound passes essentially anything. That file gains one docstring
paragraph saying where the two-sided check went and why, and no code change.

`test_the_sensor_sees_a_window_that_stops_tiling` is the gating mutation check,
committed rather than attested: it re-drives the pi case with tiling defeated —
the defect pi actually shipped — and asserts both the exact 600 ms the mutation
loses and that the identity assertion fires. `test_every_built_in_harness_has_a_case`
derives its set from `AgentKind` (not the open registry, which a third-party
plugin also populates), so a sixth built-in harness fails here rather than
shipping unmeasured.

`coder_eval.timing.union_ms` extracts the `min`/`max`/`busy_ms` tail the golden
sensor and the live residual gate had each copied. The shared corpus gains a
`union_cases` array replayed by BOTH suites — TypeScript through
`toolExecutionMs`, which derives its own extent and was the untested half.

CI gets the live two-sided gate at no infrastructure cost: the smoke-pass step
already runs a real agent and leaves real `task.json` files, so
`decompose_run.py --max-residual-pct 5` is one step against them. It covers
claude-code only (`experiments/default.yaml`), which the step name says.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01DLBDYGjbKkJ4Xg9a2QtabU
They were the two newest reducers, the two that shipped the generation-mark
defect, and the two with the thinnest golden corpus: 2 scenarios each against
9 for claude and 8 for codex. OpenCode now has 5 and Pi 6.

Each gains the three shapes the older harnesses already cover — two tiled
generations with a tool between them, an orphan force-closed at finalization,
and a crash whose partial record must survive — plus, on Pi, the duplicate
`turn_end` its reducer explicitly promises to survive and that had a unit test
and no snapshot. The crash scenarios need an `expects` knob, so both scenario
dataclasses now carry the one `ClaudeScenario` already had, for the same
reason: a crash partial is a real capture path and nobody was comparing it
against a snapshot on these two harnesses.

Only `opencode_c_multi_step_tiling` is exempted from the identity check, and
the reason is structural rather than convenient: OpenCode takes its tool bounds
from the CLI payload, so every tool-resolving scenario of that harness injects
millisecond stamps into a sub-millisecond replay. Pi derives its from its own
TurnClock, so all four of its new scenarios stay inside the sensor.

Also corrects the pi fixtures' text event. `_handle_line` dispatches on the
outer `type`, and `text` is in neither the dispatch chain nor the recognized
vocabulary, so the bare `{"type": "text"}` line `a_single_text_turn` used
reached no handler: it captured nothing, and the snapshot's `agent_output` was
empty under a scenario named for text. The new `_text()` helper emits the real
`message_update` / `text_delta` shape, which is why that snapshot changes.

Two Pi defects the new snapshots make visible are CAPTURED AND ANNOTATED, not
fixed — this phase changes no `src/` file:

* `f_duplicate_turn_end` shows `turn_text_parts` / `turn_tool_ids` cleared only
  in `on_turn_start`, so the second `turn_end` republishes the first turn's
  text as its own assistant message. `on_turn_end`'s own comment makes exactly
  this argument for the sibling `turn_started_at` reset it does perform.
* `d_orphaned_tool` shows a `duration_ms` and a subtracted span published for a
  call that never returned — `_close_tool` guards on
  `execution_started_at is not None` while its comment claims it guards on
  "resolved", and the `execution_completed_at` is only the instant the sweep
  ran. claude-code leaves that field None here on purpose.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01DLBDYGjbKkJ4Xg9a2QtabU
`decompose_turn` subtracts stamps it is handed. Hand it one aware and one naive
and Python raises "can't subtract offset-naive and offset-aware datetimes" from
inside the arithmetic, straight out of `EventCollector.build_turn_record`,
killing the turn with a message naming neither the field nor the harness.
`busy_ms` has the same exposure one level down, where the clipping compares
each span against the window bounds and the bare error reads "can't compare".

`_require_same_awareness` replaces both with a statement of which pair
disagreed, which side is aware, and what to do about it. One helper rather than
two inline guards, so there is one wording; a test drives all five call sites
and asserts the advice half is identical across them.

This is unreachable from this repo, and that is the point. Every stamp in
`agents/` and `streaming/` is a naive `datetime.now()` — zero `timezone.utc`,
`astimezone` or `tzinfo` hits — so the guard protects the SEAM, not a live
defect. Which is also why it is a guard and not a lint rule: the exposure that
actually matters is a third-party agent registered through the
`coder_eval.plugins` SPI, which lives outside `src/coder_eval/agents/` and which
no rule scoped to that directory could ever see. The message addresses that
reader directly, and tells them to make their stamps naive local rather than
normalizing here — so their tool spans and their window bounds keep one basis.

Only the MIX raises: all-naive and all-aware both work unchanged.

An empty span list is checked NOT AT ALL, bounds included. The comprehension
never runs, nothing is compared and nothing is subtracted, so there is no pair
for the guard to be about, and raising there would reject a call that has always
returned `0.0`. The mixed-bounds empty case is what pins this — the naive one
passes either way and cannot tell the two behaviours apart.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01DLBDYGjbKkJ4Xg9a2QtabU
The field answered a different question per harness. codex, opencode and pi
measured the wall clock before their CLI emitted its first event. claude-code
and antigravity measured NOTHING: both stamped their first generation window's
mark when the turn state was built, before `AgentStartEvent` was emitted, so
`decompose_turn`'s `max(..., 0.0)` produced the `0.0` they published. A clamped
inversion presented as "measured, and instant" — the exact confusion CE058
exists to prevent everywhere else — while everything those harnesses spent
before their first model output was booked as the first generation instead:
~3.6 s per turn on claude-code and ~4.7 s on antigravity, inflating every
generation figure, the Generation split and the 10 s slow-generation bar on the
two most-used harnesses.

The head is now defined once, for all five: wall clock from the turn starting
until the harness first observed model output. That instant is also where the
harness opens its first generation window, so the two buckets stay disjoint and
the four-bucket identity still closes — verified to the millisecond by
`test_timing_identity_contract.py`, which is the only thing in the suite that
could see this move. `GOLDEN_REGEN=1` produces a ZERO diff: `SCRUB_KEYS` masks
every value that changed, which is the audit's P1 demonstrated on the very
change it was written about.

Both re-seeds fire ONCE per turn. `message_start` and `Step` each arrive many
times, and re-seeding on every one would stop the windows tiling and drop the
gap before the next emission into no bucket — the defect Pi shipped with.
Neither flag needs a reset: a fresh turn state is built per `communicate()`.

Antigravity's is gated on the step SOURCE. The SDK streams SYSTEM and USER
steps as well as MODEL ones, and seeding on those would put the mark before the
model spoke and hand the remainder back to the first generation — the defect
being fixed, one layer in. An unrecognized source degrades to the old
behaviour rather than to a wrong one.

The rejection this overturns rested on claude-code being an in-process SDK. It
is not: `claude-agent-sdk` spawns the `claude` CLI over `anyio.open_process`
and `_pump_messages` calls `query()` once per `communicate()` — a fresh CLI per
turn. All 8 sites asserting otherwise are gone; the old reasoning is kept in
HARNESS_PARITY.md as labelled HISTORY rather than deleted.

Nor was antigravity the in-process counterexample it was described as. It
spawns a `localharness` binary too — once, in `start()`, held across turns. The
distinction that matters is WHEN a harness spawns its process, not whether, and
that is what the docs now say.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01DLBDYGjbKkJ4Xg9a2QtabU
Tool execution came out of a generation window in five places: four inside
`close_window` as the reducer flushed, claude-code once at finalization. The
head and the tail were already computed ONCE, centrally, at the collector — and
that asymmetry was the complexity. Every timing defect on this branch lived in
the per-reducer bookkeeping around the subtraction rather than in the
subtraction itself: when to reset a span list (clearing it at `step_start` wiped
a span before the flush could subtract it, a 100% overstatement of that window),
when to clear a spent start stamp (a second flush with no intervening start
republished the previous span — 3000 ms of generation for a 2000 ms turn), when
to advance the mark.

`EventCollector.subtract_tool_time` now does it once, for all five. A reducer
publishes the RAW window and keeps only the genuinely harness-shaped decision,
which is where that window opens. Three span lists, their reset rules, the
bounding of still-open calls and `close_window`'s two span parameters are gone.
CE063 stops a sixth harness rebuilding them; CE061 is exemption-free, since
claude-code now calls the same shrunken helper as the other four.

Grouping is on the BOUNDS, not `message_id`. Codex splits one window into
thinking and action sub-messages that share a pair of bounds; subtracting from
each separately takes the overlap twice and the parts stop summing. OpenCode and
Pi can legitimately carry `message_id is None`, so keying on the id would
collapse a turn's id-less messages into one group instead.

Non-mutating, and the reason is aliasing rather than repeated calls: every agent
builds its terminal event as `AgentEndEvent(messages=list(...))`, which copies
the LIST and not the messages, so an in-place write would reach back into the
agent's own live state from the collector.

Two behaviour changes, each with its own named test rather than hidden in a
number:

* A call still open when a window closes is no longer subtracted at that
  boundary. The collector sees every span at once, so it comes out of the
  windows the call's REAL interval overlaps, once it resolves. A call that never
  resolves was never timed and contributes nothing.
* claude-code's window is measured on ONE clock. Its duration was a monotonic
  delta while its bounds were wall stamps — the split `TurnClock` exists to
  remove — and central subtraction makes that untenable, because it clips WALL
  spans against those WALL bounds. `turn_start_time` stays monotonic: the
  deadline must not move when the wall clock steps.

Also fixes the P3 thread mix, and the divergence fixing it created. `_overhead_ms`
filtered its generations to the main thread and passed EVERY command, so its
claim to keep all four buckets on one thread held only because a child nests
inside the parent Agent call. Filtering there alone then made the LIVE residual
gate compute a different tool total than the harness — the worst place for a
drift, since it is the only two-sided sensor. All three implementations
(`_main_thread_tool_spans`, `_scrub.py`, `decompose_run.py`) now filter, and
`TestTheThreeToolUnionsAgree` pins them together.

`tests/_fixtures/timing_runs/` commits one scrubbed run per harness. Its README
states plainly what the plan asked it to be and what it cannot be: the script
reads STORED fields, so over a fixed corpus it prints the identical table before
and after any code change. Its own claude-code row still reconciles at -481 ms
and books a 0.0 head — both long fixed — which is the argument.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01DLBDYGjbKkJ4Xg9a2QtabU

@uipreliga uipreliga left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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

  1. [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 :644 from finalize) 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)  # :634

grep -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 :644 with a no-op → uv run pytest tests/ --ignore=tests/test_judge_litellm.py --ignore=tests/test_litellm_judge_live.py reports 5066 passed, 13 skipped. Not one assertion depends on the subtraction.
  • Instrumenting the if overlap > 0.0 branch 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

  1. [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-69 and tests/_fixtures/golden_streams/_scrub.py:120-139 ship 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.0

and 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:            return

and 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 None

On 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_window is 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 from opencode_agent.py:746-761 into pi_agent.py:642-656 essentially verbatim, and antigravity_agent.py:1096-1097 holds a third variant — while codex_agent.py:492-496 proves the per-window span list is unnecessary state (it passes the never-cleared self.commands and lets busy_ms clip). 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)
  • 🟡 TurnClock was 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 with AgentStartEvent/AgentEndEvent.timestamp, whose default is a raw datetime.now() (streaming/events.py:89) — neither pi nor antigravity passes a timestamp= 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_ms applies three restrictions (isinstance AssistantMessage, generation_duration_ms is not None, parent_tool_use_id is Nonestreaming/collector.py:156-161); tests/_fixtures/golden_streams/_scrub.py:231 applies 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 behaviour tests/test_event_collector.py:575 ratifies 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-69 and tests/_fixtures/golden_streams/_scrub.py:120-139 ship body-identical _parse/_tool_ms helpers and near-identical bucket assembly, and both already import busy_ms from the new coder_eval.timing — so the shared home exists and was half-used. The two copies have already drifted (decompose_run.py:96 guards the generation sum with an isinstance test the _scrub.py copy 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 under tests/; 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_KEYS masks generation_duration_ms in 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 direct TestGenerationWindowExcludesToolExecution reducer 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 under scripts/) is excluded from pyright's include, from testpaths, from coverage.source, and from the ruff paths CI actually runs (pr-checks.yml:87/:90 hardcode src/ tests/). It reports 6 pyright errors under settings this repo sets to "error", including three untyped turn: dict params at the point where the cross-repo task.json contract is parsed. Its inputs are plain dicts, so _turn_buckets / _residual_ms / the --max-residual-pct exit 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-369 forwards harnessStartupMs/harnessTeardownMs to CostExplorerSection, which forwards them again to MessageTimelineSection (_sections.tsx:862-863). No test renders CostExplorerSection at all (git grep CostExplorerSection evalboard/**/__tests__ is empty) — the new message-timeline.test.tsx block renders MessageTimelineSection directly. 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_ms and close_window each got one (tests/test_timing_union_parity.py, tests/test_timing_close_window.py); decompose_turn is reached only through EventCollector, 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 "None means 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_ms changed definition and no consumer of that number was reviewed or updated. The PR's test plan states "waves 2–3 touch no evalboard/ 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), the SLOW_GEN_MS = 10_000 red-bar threshold (_sections.tsx:36) — a 10.3 s window that sheds 400 ms stops being flagged — and thinkingSim.ts:301/315, which weights per-message token attribution by generationMs and 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. TaskDetail gains harnessStartupMs/harnessTeardownMs (evalboard/lib/runs.ts:367-370), but TaskResultSummary, RunPoint/lib/overview.ts and _overview/wall-clock-chart.tsx do 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 unscheduled decompose_run.py by 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 |, and reports_html.py::_render_generation_metrics (:935-964) still renders the same four stats — and CLAUDE.md calls reports_html.py "the evalboard's static twin". Neither file appears in the diff, and git grep harness_startup_ms src/ returns only models/, streaming/ and timing.py: no Python renderer reads either field. A run shared as run.md or report.html (the artifacts a CI gate and an offline reviewer get) cannot see the buckets this PR exists to add, and both renderers already read turns[i].duration_seconds at 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:46 names scripts/timing/decompose_run.py --max-residual-pct N as 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_KEYS masks generation_duration_ms and 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 a make target over the previous night's task.json corpus) 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.json gains two TurnRecord fields (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 — only environment_info.git_commit distinguishes 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-uipath consumer 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 into tests/lint/runner.py::ALL_RULES. In src/coder_eval/agents/, any module that uses a TurnClock must pass timestamp= EXPLICITLY to every AgentStartEvent / AgentEndEvent / TurnStartEvent / TurnEndEvent it 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.timestamp defaults to a raw datetime.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, so decompose_turn subtracts across two bases and a mid-turn NTP/DST step lands whole in harness_teardown_ms.
  • [ce-lint] CE065 — a TurnClock is injected, never defaulted. New rule in tests/lint/rules/: in src/coder_eval/agents/, a parameter annotated TurnClock (or TurnClock | None) may not carry a default, and TurnClock() may not be constructed inside a turn-state __init__. This is close_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:272 clock: TurnClock | None = None + :285 self.clock = clock or TurnClock(), with communicate never passing one — so on the production path the lifetime is invisible and the parameter exists only for tests, against antigravity_agent.py:816's required clock: 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 bare datetime | None positional parameters (src/coder_eval/timing.py:234-239) with two distinct frozen dataclasses — GenerationBounds(first_started_at, last_completed_at) and AgentBounds(started_at, ended_at) — or two NewTypes. No config flip is needed: typeCheckingMode = "standard" already rejects a nominal-type mismatch, so the swap becomes a typecheck error at make typecheck instead of silence. Prevents: Finding A2/A1/A7 (signature discipline). Transposing first_started_at with agent_started_at type-checks cleanly today and yields an inverted interval → busy_ms 0.0 → max(elapsed - 0.0, 0.0) clamped to a MEASURED 0.0 at 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.py is keyword-only and default-free. New rule: a module-level def in timing.py whose 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 for close_window and 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 committed antigravity_d_orphaned_tool fixture. Also removes part (a)'s positional-ordering hazard if the dataclass fix above is not taken.
  • [ruff] Put scripts/ inside the format/lint gate. Add scripts/ to LINT_PATHS (Makefile:22) AND to the hardcoded path arguments in .github/workflows/pr-checks.yml (ruff format --check at :87, ruff check at :90, plus the Windows mirror at :391/:394) — CI does not read LINT_PATHS, so editing the Makefile alone changes nothing in CI. Prevents: Finding A7 (the new 285-line scripts/timing/decompose_run.py sits outside every CI gate) and A7-low (--help reflow). The file's own docstring records the exclusion instead of closing it, directly contradicting the Makefile's stated rationale two lines above LINT_PATHS — and the file is now the two-sided residual gate that pr-checks.yml:604 actually 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: dict at decompose_run.py:49/:72/:113 (reportMissingTypeArgument, pyproject.toml:347) and implicit string concatenation at :251/:258/:277 (reportImplicitStringConcatenation, :355). Type the three parameters dict[str, Any]. Prevents: Finding A7. Those three untyped dict parameters are exactly where the cross-repo task.json contract is parsed, in the only two-sided sensor for the four-bucket identity — a silent regression there disarms the gate docs/agents/HARNESS_PARITY.md:46 leans on.
  • [ce-lint] CE067 — lint-path parity between the Makefile and CI. A whole-tree check (a @pytest.mark.lint test class, like CE028/CE035, not a BaseRule): the path arguments to ruff format / ruff check in .github/workflows/pr-checks.yml must equal LINT_PATHS in the Makefile, and pyright's include must cover the same tree. Prevents: The second-order cause of Finding A7 — and a live instance: CI lints src/ 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.json timing-field literal outside the record decoder (CE053's shape, new domain). Forbid the string literals execution_started_at, execution_completed_at, generation_duration_ms, parent_tool_use_id, harness_startup_ms, harness_teardown_ms as dict keys anywhere except one decoder module (coder_eval/timing.py or a timing_record.py leaf) 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_captured omits the producer's main-thread filter). Both copies have ALREADY drifted, which is the argument: decompose_run.py:96 guards the generation sum with an isinstance the _scrub.py:252-256 copy lacks, and _scrub.py:231 omits the parent_tool_use_id is None predicate that streaming/collector.py:156-159 applies 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 or model_copy(update={...}) that sets result_status to an unresolved/unknown sentinel must set execution_completed_at in 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 hung Bash: sleep 600 killed by turn_timeout produces 295 s of harness_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 # noqa otherwise.
  • [ce-lint] CE070 — one stamp basis: no tz-aware datetime in the stamp producers. Ban datetime.now(<arg>), .astimezone(, and timezone.utc in src/coder_eval/agents/ and src/coder_eval/streaming/, so every stamp reaching decompose_turn/busy_ms is naive-local by construction. Stated boundary: lint cannot reach out-of-tree SPI agents (coder_eval_uipath), and the framework's own naive StreamEvent.timestamp default 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 a TypeError at timing.py:226 escapes pi_agent.py's turn try_crash_turnAgentCrashError, and _capture_partial_turn re-invokes build_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 named test_the_published_window_reconciles_to_its_own_bounds in the matching tests/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 grep returns 5 hits, none in tests/ — 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-level src/coder_eval/*.py module must have a row in CLAUDE.md's Directory Structure tree, and every tests/lint/rules/ceNNN_*.py id 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, and grep -c CE061 CLAUDE.md returns 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 pass formatter_class=argparse.RawDescriptionHelpFormatter. A five-line AST rule; only reachable once scripts/ is in lint scope, which is itself the point. Prevents: Finding A7-low: the default HelpFormatter re-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 --help output.
  • [ce-lint] Assert the FICTIONAL_DURATIONS ledger instead of describing it. In tests/test_agent_golden_master.py, assert len(FICTIONAL_DURATIONS) + checked == len(expected/*.json) with the exempt set enumerated — the shape TestCE061WindowViaCloseWindow::test_each_suppression_is_load_bearing already 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-timing target (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; transpose decompose_turn's head/tail argument pairs; drop the max(..., 0.0) clamp; drop the parent_tool_use_id filter in _overhead_ms. Run it in pr-checks.yml beside 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, both execution_*_at stamps and harness_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 <= tol rather than only overshoot <= 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 as harness_teardown_ms on 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:35 currently 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 TurnClock required (CE065) and event stamps clock-derived (CE064), drive a full turn whose wall clock jumps forward and then backward mid-turn, and assert head + Σ generation + ∪ tool + tail <= duration_seconds still holds against the MONOTONIC duration_seconds both 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 added TurnClock ("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 while duration_seconds is 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_ms and the --max-residual-pct exit code (no live run needed — the inputs are plain dicts), and add scripts to [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 by pr-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 GenerationWindow to coder_eval/timing.py owning mark, spans and pending_start, with add_span() / close(now), and adopt Codex's clip-only shape — drop the hand-cleared per-window span lists entirely, since busy_ms already discards spans outside [lo, hi] (timing.py:95, and codex_agent.py:492-496 proves it by never clearing self.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 before step_finish can 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 None condition of harness_startup_ms/harness_teardown_ms with the fixture that already contradicts it, and reword both descriptions to the producer's real predicate (no assistant message with a measurable generation_duration_ms on the main thread). Name codex_g_items_rebuild.json — one assistant message, both fields null — 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 in streaming/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 at models/results.py:339,348 state a None condition the PR's own committed golden fixture contradicts — on task.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.md and the coder_eval.plugins SPI 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 from timing.py rather 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_awareness guard are the only available enforcement. Prevents: A6 (naive/aware mix reaching a plugin's first turn as a spurious AgentCrashError); A5 (two-basis stamps); A5 (state-machine re-derivation); A6 (undocumented orphan divergence — HARNESS_PARITY.md:32 gives codex an 'or neither' qualifier that claude-code lacks, and :35 claims the identity for all five).

Top 5 Priority Actions

  1. Guard the two new subtractions in src/coder_eval/timing.py:226 (and the busy_ms clip at :95) against a naive/aware datetime mix with a _require_same_awareness helper that names the disagreeing pair — today a third-party SPI agent that stamps its messages datetime.now(timezone.utc) while StreamEvent.timestamp keeps its naive default turns every completed turn into an AgentCrashError with the trajectory discarded and a full-cost retry, changing final_status for identical agent output.
  2. 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 two continue guards at :628-631 — neutering the call leaves all 5659 tests green, the goldens scrub generation_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.
  3. Stamp execution_completed_at when 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's antigravity_agent.py:1139, or document the divergence in docs/agents/HARNESS_PARITY.md — otherwise a 600 s hung Bash killed by turn_timeout publishes ~295 s of harness_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.
  4. Make decompose_turn keyword-only and tool_spans required (src/coder_eval/timing.py:166), following the discipline its own sibling close_window states at :128-133 — four consecutive positional datetime | None params let a transposition type-check cleanly and clamp to a measured 0.0 head or tail, the exact reading CE058 exists to make unrepresentable, and the omissible tool_spans default is a double-count the docstring itself measures at -86% of wall clock.
  5. Close the gap in the sensors that guard the four-bucket identity: add the missing parent_tool_use_id is None main-thread filter at tests/_fixtures/golden_streams/_scrub.py:231 (it contradicts both the producer at streaming/collector.py:156-161 and the unit test at tests/test_event_collector.py:575), and bring scripts/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.yml and pyright's include, not only LINT_PATHS.

Stats: 0 🔴 · 1 🟠 · 8 🟡 · 6 🔵 across 8 axes reviewed.

uipreliga and others added 3 commits September 12, 2026 07:00
…one-vs-0 guard

**Phase 6.** `reports_html.py` is described in CLAUDE.md as the evalboard's
static twin, and it rendered only Total Latency / Turns / Avg Turn Latency — so
anyone reading the artifact rather than the dashboard got none of the wall-clock
accounting this branch added. The card now shows Startup / Generation / Tool
exec / Teardown / Unaccounted.

The arithmetic is in `reports_stats.turn_time_buckets` and the renderer only
formats, because putting the sums in `_render_generation_metrics` would make it
the fourth place these buckets are aggregated. For the same reason the
main-thread span rule is no longer restated there: `main_thread_tool_spans` moves
out of `EventCollector` to module level and both consume it. A second typed copy
of that rule is exactly how two surfaces come to publish two different tool
totals for one run.

Three None-vs-0 distinctions the first draft got wrong, each measured:

* `tool_ms` returned `0.0` for a run that recorded no bounded span at all,
  rendering `0ms` — "measured and instant" — where nobody measured anything. It
  is `None` unless some turn recorded a span.
* `unaccounted_ms` was computed from a `duration_seconds` that is a
  non-optional float defaulting to `0.0`, so an untimed run rendered a
  fabricated negative residual instead of a dash. The evalboard keeps its own
  null for this case.
* The docstring claimed every bucket went `None` when nothing measured it,
  while two of five could not.

Display and arithmetic differ on purpose and say so: an unmeasured bucket shows
as an em dash and sums as `0.0`, so its time surfaces in Unaccounted rather than
vanishing — the rule `decompose_run.py::_turn_buckets` already applies. The
Unaccounted label states that it includes sandbox setup and grading, so it is
not comparable with the per-turn residual.

**Phase 7.** `no-zero-coalesce.test.ts` is the TypeScript counterpart to CE058.
There is no eslint in `evalboard/`, so it is a vitest source scan. An ALLOWLIST
rather than a ban, because the residual arithmetic uses `?? 0` correctly —
subtracting only what was measured is the whole point — so a blanket ban fires
on right code.

It scans for timing names (`Ms`, `Seconds`, `duration`) rather than every
`?? 0`, and that narrowing is deliberate: a blanket scan matches 58
occurrences, about half token and cache buckets where zero is a fine answer
because tokens are counted rather than measured. An allowlist that long is one
nobody reads. Blind spots are declared in the file. Two meta-tests keep it
honest — a negative control, so the scan cannot pass by matching nothing, and an
assertion that every allowlist entry is still present, so an entry cannot
outlive its reason. Both caught real problems in the allowlist before it landed.

`AssistantMessage.message_id` no longer names one harness of five. Its census is
taken from the agents rather than from the plan, which had it off by one: three
schemes, not two — passed through on claude-code, opencode and pi; synthesized
on codex and antigravity; and claude-code synthesizes in exactly one place, the
sub-agent terminal message that is never streamed.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01DLBDYGjbKkJ4Xg9a2QtabU
Two independent final reviews over the whole 7-phase change. No Critical and no
High: the Phase 4 x Phase 5 interaction was attacked directly (a re-seeded mark
landing inside a tool span; an open call clipped differently now that the
collector subtracts) and the algebra holds on every harness.

The findings that mattered were all the same shape — a claim that had stopped
being true:

* `tests/test_timing_identity_contract.py` was a FIFTH tool-union
  implementation that disagreed with the other four. It filtered generations to
  the main thread and then unioned every command, so the sensor built to police
  this identity was asserting a different one. Latent only because no case has a
  sub-agent command yet — the first one added would have reported a false
  regression. It now calls production's own `main_thread_tool_spans`.
* CE061's docstring and violation MESSAGE still described the architecture
  Phase 5 deleted: a permanent claude-code suppression that no longer exists,
  and an instruction to subtract the tool union inside the reducer, which CE063
  now forbids and which would recreate double subtraction. Both models flagged
  it independently. It now states what it owns and points at CE063 for the rest.
* `HARNESS_PARITY.md`'s `[^identity]` footnote still said the only committed
  sensor is one-sided, in the same file that gained 269 lines describing the
  two-sided one. All three sensors are now named with what each can and cannot
  see.
* The `opencode_c_multi_step_tiling` exemption claimed "the snapshot still
  records [the tiling]". It does not: `SCRUB_KEYS` masks both bounds and the
  duration, so nothing about where a window opened survives into the JSON. The
  comment now says what the snapshot actually pins (structure, blocks, tokens)
  and where the tiling IS asserted.

Also fixed, from the same pass: antigravity's signal is the first MODEL-source
`Step` and the table said "the first `Step`"; claude-code's seed docstring still
said "the two marks" after Phase 5 deleted the monotonic one; the seed's
degradation list did not mention that `include_partial_messages=false` reaches
it through `-D`; the TS scanner's comment-stripping blind spot was undeclared;
and two counts in `harness-candidates.md` disagreed with the file they describe.

CE062 is now documented as deliberately unused. The ids jump 061 to 063, and an
id is a permanent anchor — a suppression carrying 062 in an older branch must
never start meaning something new.

One test was removed rather than repaired.
`test_generation_and_tool_time_account_for_the_turn` asserted the buckets cover
at least half the turn, on the REAL clock. Phase 4 added the head to that sum
and kept the bound; under `-n auto` the denominator inflates while the measured
buckets do not, so it failed as a scheduler-noise detector. The share it reached
for is asserted exactly, on a scripted clock, in the contract test.

NOT fixed, deliberately: a reviewer flagged `EventCollector` retaining
`_commands` and `_turn_starts` across a retry's `AgentStartEvent` as High. It is
pre-existing and untouched here, and the claimed blast radius is wrong — the
persisted record, the reports and `max_turns` all read the agent's OWN collector,
which is fresh per `communicate()`. Only `EarlyStopWatcher`'s long-lived
collector accumulates, where carrying a turn's whole engagement across retries
is arguably what a live verdict wants. Recorded as a follow-up rather than
changed blind.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01DLBDYGjbKkJ4Xg9a2QtabU
Six entries, each with why it is not a rule today rather than just what it is.
Two are prose-vs-artifact defects a lint rule would have to parse English to
catch; one needs a decision about intent before any guard could be right; three
are code defects the golden corpus now captures but that were out of the plan's
scope to fix.

The three-way tool-union divergence this run also surfaced is NOT here: it was
guarded the same day by TestTheThreeToolUnionsAgree, which is the point of the
promote-or-defer split.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01DLBDYGjbKkJ4Xg9a2QtabU
# 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)) # type: ignore[misc]
while its tool time was silently subtracted a second time centrally.
"""
with pytest.raises(TypeError):
close_window(mark=MARK, now=_at(1000), closed_spans=[]) # type: ignore[call-arg]
with pytest.raises(TypeError):
close_window(mark=MARK, now=_at(1000), closed_spans=[]) # type: ignore[call-arg]
with pytest.raises(TypeError):
close_window(mark=MARK, now=_at(1000), open_started_ats=[]) # type: ignore[call-arg]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants