feat(timing): book each turn's head and tail as their own buckets - #165
Conversation
|
Claude finished @uipreliga's task in 1m 37s —— View job Code Review in Progress
|
d809c93 to
7483b67
Compare
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>
ac4e88f to
0c9a067
Compare
uipreliga
left a comment
There was a problem hiding this comment.
Review: coder_eval — pr:165
Scope: pr:165 · branch feat/turn-head-tail-timing · 48426ae · 2026-09-12T10:05Z · workflow variant
Change class: complex — rewrites per-turn timing bookkeeping across five agent reducers, adds a new shared timing.py window/residual module, new head/tail token buckets on TurnRecord, three new CE lint rules, and changes the evalboard's timeline decomposition; correctness requires reasoning about control flow and invariants
This is a strong, unusually well-reasoned timing refactor — security is clean at 10/10, the new timing.py seam removes five hand-rolled copies of the window arithmetic, and no confirmed finding is a live correctness bug — but the real risks are that its highest-traffic new code is unguarded and unasserted: an unchecked naive/aware datetime subtraction on every agent's success path can report a completed turn as a crash, claude-code's new tool-time subtraction mutates a persisted metric with literally zero test coverage, and the two sensors meant to police the four-bucket identity are themselves duplicated, partly wrong, and outside CI; fix those four and this merges comfortably at 9.3/10.
Summary
| Axis | Score | 🔴 | 🟠 | 🟡 | 🔵 | Top Issue |
|---|---|---|---|---|---|---|
| 1. Code Quality & Style | 9.5 / 10 | 0 | 0 | 1 | 0 | The four-bucket decomposition / record->tool-span extraction is restated in the gate script and the golden sensor instead of living in the new timing.py both import |
| 2. Type Safety | 9.4 / 10 | 0 | 0 | 1 | 1 | decompose_turn's parameter contract is looser than its sibling close_window: four interchangeable positional `datetime |
| 3. Test Health | 8.8 / 10 | 0 | 1 | 0 | 2 | claude-code's new tool-time subtraction changes every published generation_duration_ms with zero committed coverage (neutering it leaves the suite green) |
| 4. Security | 10 / 10 | 0 | 0 | 0 | 0 | — |
| 5. Architecture & Design | 8.8 / 10 | 0 | 0 | 2 | 2 | The timing seam centralizes the window arithmetic but not the window state machine — this PR replicates OpenCode's 3-part machine into Pi (pi_agent.py:642-656 vs opencode_agent.py:746-761) |
| 6. Error Handling & Resilience | 9 / 10 | 0 | 0 | 2 | 0 | decompose_turn's two subtractions (new in this PR, now on every agent's success path via build_turn_record) are unguarded against a naive/aware stamp mix — a TypeError there turns a completed turn into an AgentCrashError with the trajectory discarded |
| 7. API Surface & Maintainability | 9.4 / 10 | 0 | 0 | 1 | 1 | New 285-line scripts/timing/decompose_run.py sits outside every CI gate (ruff/pyright/tests): 6 pyright errors, zero tests for its exit-code gate |
| 8. Evaluation Harness Quality | 9.5 / 10 | 0 | 0 | 1 | 0 | assert_timing_captured omits the collector's main-thread filter, so the golden head/tail assertion contradicts the producer (and its own identity block 24 lines lower) for any timed sub-agent generation |
Overall Score: 9.3 / 10 · Weakest Axis: Test Health at 8.8 / 10
Totals: 🔴 0 · 🟠 1 · 🟡 8 · 🔵 6 across 8 axes.
Blockers
- [Axis 3] claude-code's new tool-time subtraction changes every published generation_duration_ms with zero committed coverage (neutering it leaves the suite green) (
src/coder_eval/agents/claude_code_agent.py:593) —_ClaudeTurnState._subtract_tool_time_from_windows(new, 47 lines,src/coder_eval/agents/claude_code_agent.py:593, called at:644fromfinalize) mutates a PERSISTED metric on the most-used harness:
overlap = busy_ms(spans, emission.started_at, emission.completed_at) # :632
if overlap > 0.0: # :633
emission.generation_duration_ms = max(emission.generation_duration_ms - overlap, 0.0) # :634grep -n "_subtract_tool_time_from_windows" pr-165 returns exactly 5 hits: 2 in src/coder_eval/agents/claude_code_agent.py, 1 in docs/agents/HARNESS_PARITY.md, 1 in .claude/harness-candidates.md, and ZERO in tests/.
Mutation-verified two ways from the prepared worktree at HEAD 48426ae:
- Replacing the call at
:644with a no-op →uv run pytest tests/ --ignore=tests/test_judge_litellm.py --ignore=tests/test_litellm_judge_live.pyreports5066 passed, 13 skipped. Not one assertion depends on the subtraction. - Instrumenting the
if overlap > 0.0branch with a file-append probe → the branch fires 9 times across the same suite. So the code is executed (and therefore shows as covered at 95.93%) while its effect is never asserted — coverage without verification.
The two existing sensors structurally cannot catch it: tests/_fixtures/golden_streams/_scrub.py:29 lists generation_duration_ms in SCRUB_KEYS, so every claude golden snapshot masks the value to <scrubbed>; and assert_timing_captured's four-bucket check is an upper bound (assert overshoot <= max(_IDENTITY_FLOOR_MS, _IDENTITY_SHARE * wall_ms), _IDENTITY_FLOOR_MS = 0.1, _IDENTITY_SHARE = 0.20) on replays whose whole turn is sub-millisecond, so the 0.1 ms floor swallows any claude-scale overlap.
The PR's own .claude/harness-candidates.md:583 records this change as re-measuring claude-code from 481 ms / 2.691% to 1.4 ms / 0.006% — a live re-measurement, not a test. The sibling harnesses each got a direct reducer test for exactly this arithmetic (e.g. tests/test_opencode_agent.py::TestGenerationWindowExcludesToolExecution::test_the_published_window_reconciles_to_its_own_bounds, tests/test_pi_agent.py at the same shape); claude-code did not.
Add a direct unit test in tests/test_agent_telemetry.py: drive _ClaudeTurnState with two emissions and a CommandTelemetry whose [execution_started_at, execution_completed_at] straddles both windows, call finalize, and assert the exact post-subtraction generation_duration_ms on each — mirroring test_the_published_window_reconciles_to_its_own_bounds. Include the clamp case (a window entirely covered by tool execution reads 0.0, not negative) and the two continue guards at :626-631 (a parent_tool_use_id-tagged sub-agent message and a generation_duration_ms=None message are both left untouched).
Non-blocking, but please consider before merge
- [Axis 1] The four-bucket decomposition / record->tool-span extraction is restated in the gate script and the golden sensor instead of living in the new timing.py both import (
scripts/timing/decompose_run.py:49) —scripts/timing/decompose_run.py:40-69andtests/_fixtures/golden_streams/_scrub.py:120-139ship the same two helpers with only the names changed.decompose_run.py:49:
def _tool_ms(turn: dict) -> float:
spans = []
for command in turn.get("commands") or []:
start = _parse(command.get("execution_started_at"))
end = _parse(command.get("execution_completed_at"))
if start is not None and end is not None and end >= start:
spans.append((start, end))
if not spans:
return 0.0
return busy_ms(spans, min(s for s, _ in spans), max(e for _, e in spans))_scrub.py:120 is the identical body under _tool_union_ms/_parse_stamp. The four-bucket assembly around it is duplicated too: decompose_run.py:89-110 (generation_ms main-thread sum + startup_ms/teardown_ms + _residual_ms) against _scrub.py:248-266 (generation_ms sum + bucket_sum + overshoot). The main-thread predicate (role == "assistant" and parent_tool_use_id is None plus a measurable-duration test) is then restated a third and fourth time in typed form at src/coder_eval/streaming/collector.py:152-157 and src/coder_eval/agents/claude_code_agent.py:627-628.
This PR created src/coder_eval/timing.py precisely so this arithmetic is "defined once and shared" (its own module docstring), and both copies already import busy_ms from it — so the home exists and was only half-used. Move the task.json-shaped decomposition (_parse + tool-union + the main-thread generation sum + the bucket sum/residual) into coder_eval/timing.py (or a small timing_record.py leaf) and have _scrub.py and decompose_run.py both call it. As shipped, the gate and the sensor that are supposed to cross-check each other are the same code pasted twice, so a defect in the shared shape is invisible to both.
2. [Axis 2] decompose_turn's parameter contract is looser than its sibling close_window: four interchangeable positional datetime | None params plus an omissible tool_spans whose default is the documented double-count (src/coder_eval/timing.py:166) — Read at tmp/pr-165-worktree/src/coder_eval/timing.py:166-172:
def decompose_turn(
first_started_at: datetime | None,
last_completed_at: datetime | None,
agent_started_at: datetime | None,
agent_ended_at: datetime | None,
tool_spans: list[tuple[datetime, datetime]] | None = None,
) -> tuple[float | None, float | None]:Two type holes, both in a hot new module every reducer and EventCollector depend on:
(a) Params 1-4 are four consecutive positional parameters of the IDENTICAL type datetime | None. Transposing first_started_at with agent_started_at (or last_completed_at with agent_ended_at) type-checks cleanly under pyright and produces a silently clamped 0.0 head/tail via max(elapsed - busy_ms(...), 0.0) at lines 227/230 — i.e. the exact "measured, and instant" reading that this PR's whole CE058 rationale exists to make unrepresentable. The sole caller (streaming/collector.py:275-279) passes all four positionally, so no test can catch a swap either.
(b) tool_spans defaults to None, yet the function's own docstring at lines 182-191 states that omitting it is wrong, not merely less precise: "tool_spans is what keeps those four buckets DISJOINT, and omitting it is a double-count rather than a lost refinement ... measured on the committed antigravity_d_orphaned_tool fixture as a residual of -86% of wall clock." A parameter whose omission the author has measured at -86% should not be omissible.
The same file already states the correct discipline for the sibling helper at lines 109-116 (def close_window(\n *,) and defends it in its docstring at lines 128-133: "It is keyword-only and has NO default so that no reducer can open a window without stating what it tiles from — which is the defect pi shipped with." Apply the same rule here: make decompose_turn keyword-only (*,) and make tool_spans required with no default. Both are one-line edits with one call site to update.
3. [Axis 5] The timing seam centralizes the window arithmetic but not the window state machine — this PR replicates OpenCode's 3-part machine into Pi (pi_agent.py:642-656 vs opencode_agent.py:746-761) (src/coder_eval/agents/pi_agent.py:642) — timing.py::close_window is a pure function that takes the window state as five arguments, so the state itself — the tile mark, the per-window span list, and the "spent" item start — stays owned by each reducer, and this PR replicates that 3-part machine from OpenCode into Pi essentially verbatim. pi_agent.py:642-656 vs opencode_agent.py:746-761 differ only in identifiers:
# pi_agent.py:642-656
# A message was appended, so the next window starts where this one
# ended. Only a finished turn advances the mark: ...
# it, and only with it — see `on_turn_start`.
self.gen_mark = completed
self.turn_tool_spans = []
# And so is this turn's own start stamp, because it has now been SPENT.
...
self.turn_started_at = None
# opencode_agent.py:746-761
self.gen_mark = completed
self.step_tool_spans = []
...
self.step_started_at = None
The same pair repeats at pi_agent.py:322-323 / opencode_agent.py:324-325 (the gen_mark field) and pi_agent.py:384-388 / opencode_agent.py:373-376 (the "deliberately NOT reset here" note, whose Pi copy literally says see the identical note in opencode_agent.on_step_start). Antigravity keeps a third copy (self._gen_mark_wall / self._tool_spans_since_mark, antigravity_agent.py:1095-1096). The duplicated part is exactly where the PR's own comments say the defects were ("Reproduced: 3000 ms of generation for a 2000 ms turn", pi_agent.py:655).
Codex proves the per-window span list is unnecessary state: codex_agent.py:492-495 passes the whole accumulated self.commands list every flush and never clears it, because busy_ms already drops spans outside [started, now] (if min(e, hi) > max(s, lo), timing.py:95). Three reducers therefore maintain error-prone, hand-cleared state that a fourth demonstrates is not needed. Fold the state into the seam — e.g. a small GenerationWindow in timing.py owning mark, spans and pending_start, with window.add_span(...) / window.close(now) — so a new harness inherits the bookkeeping rather than re-deriving it; drop the per-window lists in favour of Codex's clip-only shape.
4. [Axis 5] decompose_turn measures the turn head/tail by subtracting TurnClock-derived message stamps from raw datetime.now() AgentStart/AgentEnd stamps, leaving Pi and Antigravity a two-basis subtraction in the harness_startup_ms/harness_teardown_ms buckets (src/coder_eval/streaming/collector.py:167) — TurnClock's docstring states the invariant the module exists for: "A turn's bounds and its durations have to share a basis or they can disagree, and the disagreement lands in a field measured in milliseconds" (timing.py:31-32), citing Antigravity mixing a monotonic span with wall intervals as "the only reason its window could go negative at all". The PR's own primary new consumer breaks that invariant. _overhead_ms pairs message stamps with agent-event stamps:
# collector.py:163-167
return decompose_turn(
min(m.started_at for m in generations),
max(m.completed_at for m in generations),
self._agent_start_at,
self._agent_end.timestamp if self._agent_end is not None else None,
and self._agent_start_at = event.timestamp (collector.py:79), where timestamp: datetime = Field(default_factory=datetime.now) (streaming/events.py:89) — a RAW wall read. For the two harnesses this PR migrated, m.started_at / m.completed_at are TurnClock-derived (self.clock.now(), pi_agent.py:605 / antigravity_agent.py:1038), i.e. monotonic-anchored. decompose_turn then computes tail = agent_ended_at - last_completed_at (timing.py:229) across the two bases, and busy_ms(spans, last_completed_at, agent_ended_at) clips TurnClock-derived tool spans against a raw wall bound. An NTP step or DST transition mid-turn — the exact case TurnClock's docstring calls reachable ("Nightly runs start at 04:18 and run for hours", timing.py:41-42) — lands whole in harness_teardown_ms, a milliseconds field, and silently breaks the four-bucket identity. Either stamp AgentStartEvent/AgentEndEvent from the same TurnClock on the harnesses that have one (pass it to the event constructor), or record the turn's head/tail bounds on the clock itself and hand them to the collector, rather than reading two clocks into one subtraction.
5. [Axis 6] decompose_turn's two subtractions (new in this PR, now on every agent's success path via build_turn_record) are unguarded against a naive/aware stamp mix — a TypeError there turns a completed turn into an AgentCrashError with the trajectory discarded (src/coder_eval/timing.py:226) — decompose_turn subtracts stamps it is handed with no awareness check:
226: elapsed = (first_started_at - agent_started_at).total_seconds() * 1000.0and busy_ms has the same exposure one level down at
95: clipped = sorted((max(s, lo), min(e, hi)) for s, e in spans if min(e, hi) > max(s, lo))Both are now on the SUCCESS path of every agent, because EventCollector._overhead_ms (streaming/collector.py:163-173) calls decompose_turn unconditionally from build_turn_record(). In pi_agent.py that call sits inside the turn's try:
1128: state.finalize(status)
1132: record = collector.build_turn_record()
1133: self._end_turn_ok()so a TypeError: can't subtract offset-naive and offset-aware datetimes escapes into except Exception as e: (line 1143) -> _crash_turn(...) -> AgentCrashError. _crash_turn then calls _capture_partial_turn, which re-invokes build_turn_record() and raises again — swallowed by agent.py:_capture_partial_turn, leaving pending_turn = None. Net effect: a turn that ran to completion is reported as a crash, its whole trajectory is discarded, and the retry machinery re-runs it at full API cost, with an error message naming neither the field nor the harness.
Every in-tree stamp is naive today, so this is a SEAM defect, not a live one — but the seam is the documented coder_eval.plugins agent SPI (CLAUDE.md, "Adding a New Agent"), and coder_eval_uipath's Delegate agent already ships out of tree. A third-party reducer that stamps AssistantMessage.started_at with datetime.now(timezone.utc) breaks every turn it records. Add one _require_same_awareness(a, b, ...) guard used by both decompose_turn's two subtractions and busy_ms's clip, raising a message that names which pair disagreed, which side is aware, and that the fix is naive-local stamps (so the plugin's tool spans and window bounds keep one basis). Leave the empty-span case unchecked — nothing is compared there and it has always returned 0.0.
6. [Axis 6] An unresolved tool has no execution bounds on claude-code/codex, so its run-time is booked as harness_teardown_ms — the opposite of antigravity's answer for the identical orphan (src/coder_eval/agents/claude_code_agent.py:619) — Both the per-window subtraction and the head/tail subtraction require BOTH bounds:
616: spans = [
617: (c.execution_started_at, c.execution_completed_at)
618: for c in commands
619: if c.execution_started_at is not None and c.execution_completed_at is not None
620: ]
621: if not spans:
622: returnand in streaming/collector.py:
169: (c.execution_started_at, c.execution_completed_at)
170: for c in self._commands.values()
171: if c.execution_started_at is not None and c.execution_completed_at is not NoneOn claude-code both stamps are written only when a tool RESULT arrives (claude_code_agent.py:1871-1872); _finalize_commands (line 1428-1437) deliberately leaves an unresolved command at duration_ms = None and never touches the execution bounds. Codex is the same shape — close_open_tools publishes the start telemetry verbatim, so execution_completed_at stays None.
Failure scenario: a claude-code turn issues Bash: sleep 600 at t=5s; the tool never returns; turn_timeout fires and finalize(TIMEOUT, crashed=True) emits AgentEndEvent at t=300s. spans is empty, _subtract_tool_time_from_windows returns at line 622, and decompose_turn computes tail = max((300-5)*1000 - busy_ms([], ...), 0) = 295000.0. The record therefore claims 295 s of harness_teardown_ms, a field models/results.py describes as "SDK/CLI finalization, result assembly and process teardown". Antigravity force-closes the same orphan WITH a bound —
1139: orphan = tel.model_copy(update={"result_status": "unknown", "execution_completed_at": self.clock.now()})— so the identical event yields harness_teardown_ms ~= 0 plus 295 s in the tool union there. docs/agents/HARNESS_PARITY.md:32 describes claude-code's bounds as "derived from the measured duration" with no "or neither" qualifier (it gives codex exactly that qualifier), and line 35 claims the four-bucket identity holds for all five without naming the orphan case. Per the repo's own parity rule, a divergence must be fixed or documented: either stamp execution_completed_at at force-close on claude-code/codex (the sibling behaviour, and the bound is real — the tool ran until the turn died), or add a row to the parity table and to harness_teardown_ms's description saying an unbounded orphan's run-time is absorbed into the tail on those two harnesses.
7. [Axis 7] New 285-line scripts/timing/decompose_run.py sits outside every CI gate (ruff/pyright/tests): 6 pyright errors, zero tests for its exit-code gate (scripts/timing/decompose_run.py:21) — The file's own docstring records the gap instead of closing it: lines 21-23 read "Not wired into make: it needs live runs, not fixtures. NOTE scripts/ is / outside the Makefile's LINT_PATHS, so this file is neither formatted nor / ruff-checked — keep it small and dependency-free". That contradicts the Makefile's own stated rationale two lines above LINT_PATHS (Makefile:18-22): ".github/scripts/ is in scope on purpose: release tooling that lives in a real / module ... is exactly what ruff, pyright and pytest can see — leaving it unlinted would forfeit the reason it was extracted." The exclusion is not theoretical: running the repo's own pyright on this file reports 6 errors under settings pyproject.toml explicitly sets to "error" (reportMissingTypeArgument = "error" at pyproject.toml:347, reportImplicitStringConcatenation = "error" at :355) — decompose_run.py:49 def _tool_ms(turn: dict) -> float:, :72 def _turn_buckets(turn: dict) -> ..., :113 def _never_measured(turn: dict) -> bool: plus three implicit-concat sites at :251, :258, :277. Those three dict annotations are exactly where the cross-repo task.json contract is parsed, untyped. There is also no test: git grep decompose_run tests/ returns only prose references in docstrings (tests/test_pi_agent.py:1197,1335; tests/test_codex_agent.py:2307; tests/test_opencode_agent.py:1912), [tool.pytest.ini_options] testpaths = ["tests"], and [tool.coverage.run] source = ["src/coder_eval"]. Meanwhile docs/agents/HARNESS_PARITY.md:46 promotes this file as the ONLY two-sided sensor for the four-bucket identity ("The two-sided check is scripts/timing/decompose_run.py --max-residual-pct N"), so a silent regression in it disarms the one gate the PR's own docs lean on. Fix: add scripts/ to LINT_PATHS in the Makefile and to pyright's include, type the three turn: dict params as dict[str, Any], and add a small unit test for _turn_buckets / _residual_ms / the --max-residual-pct exit code over a synthetic turn dict (no live run needed — the inputs are plain dicts).
8. [Axis 8] assert_timing_captured omits the collector's main-thread filter, so the golden head/tail assertion contradicts the producer (and its own identity block 24 lines lower) for any timed sub-agent generation (tests/_fixtures/golden_streams/_scrub.py:231) — assert_timing_captured builds its key as measurable = [m for m in assistant if m.get("generation_duration_ms") is not None] (line 231) and then asserts harness_startup_ms/harness_teardown_ms are non-None whenever measurable is non-empty (line 235). The producer it claims to mirror applies a THIRD restriction: streaming/collector.py:156-159 filters ... and m.generation_duration_ms is not None and m.parent_tool_use_id is None. The same function already gets this right 17 lines lower — its identity block (line 248-252) filters m.get("parent_tool_use_id") is None with the comment "Main thread only" — so the omission is internal to one function, not a design choice. Consequence: a turn whose only measurable generations are sub-agent ones makes the collector return (None, None) — which tests/test_event_collector.py:576 test_a_turn_whose_only_generations_are_sub_agent_reports_no_overhead pins as CORRECT — while this assertion fails with "harness_startup_ms is None on a turn carrying 1 measurable generation window(s)", blaming the collector for behaviour its own unit test ratifies. Unreachable on today's corpus only because both Codex sub-agent recovery builders and Claude's _synthesize_subagent_terminal_message stamp generation_duration_ms=None; the first harness that recovers a TIMED child generation turns the golden gate red for the wrong reason. Fix: add and m.get("parent_tool_use_id") is None to line 231 and update the docstring paragraph beginning "Both halves of that key are load-bearing" to say three, not two.
Nits
6 🔵 Low findings are omitted here to fit GitHub's 65 536-character comment limit. They are in the full report (tmp/code-review-260912-0305/00-summary.md and the per-axis files).
What's Missing
Parallel paths:
- 🟡 claude-code was left outside the window seam this PR created.
timing.py::close_windowis called by codex, opencode, pi and antigravity; claude-code instead gets a bespoke 42-line_ClaudeTurnState._subtract_tool_time_from_windows(src/coder_eval/agents/claude_code_agent.py:593-634) plus the repo's only permanent# noqa: CE061. The three tiling reducers additionally each keep their own copy of the same 3-part state machine (mark / per-window span list / spent item-start) — this PR replicated it fromopencode_agent.py:746-761intopi_agent.py:642-656essentially verbatim, andantigravity_agent.py:1096-1097holds a third variant — whilecodex_agent.py:492-496proves the per-window span list is unnecessary state (it passes the never-clearedself.commandsand letsbusy_msclip). The seam owns the arithmetic and nothing owns the bookkeeping, which is where every defect the PR's own comments describe actually lived ("3000 ms of generation for a 2000 ms turn",pi_agent.py:655). (trigger: src/coder_eval/timing.py) (restates: Axis 5: The timing seam centralizes the window arithmetic but not the window state machine) - 🟡
TurnClockwas adopted by 2 of 5 harnesses, and on those two the turn's own outer bounds still come from a different clock.EventCollector._overhead_ms(src/coder_eval/streaming/collector.py:163-172) pairs TurnClock-derived message stamps withAgentStartEvent/AgentEndEvent.timestamp, whose default is a rawdatetime.now()(streaming/events.py:89) — neither pi nor antigravity passes atimestamp=kwarg (pi_agent.py:1029,:743;antigravity_agent.py:587,:1167), even though both already construct the clock before emitting the start event. The parity table documents that codex/opencode are deliberately unconverted, but says nothing about the event stamps, so the module's own stated invariant ("a turn's bounds and its durations have to share a basis",timing.py:31-32) is unmet for the turn head and tail on exactly the two harnesses the PR converted. (trigger: src/coder_eval/timing.py) (restates: Axis 5: decompose_turn measures the turn head/tail by subtracting TurnClock-derived message stamps from raw datetime.now() AgentStart/AgentEnd stamps) - 🟡 The golden sensor's generation filter was not kept in step with the producer it mirrors.
collector._overhead_msapplies three restrictions (isinstance AssistantMessage,generation_duration_ms is not None,parent_tool_use_id is None—streaming/collector.py:156-161);tests/_fixtures/golden_streams/_scrub.py:231applies only the first two, while the same function's identity block 24 lines lower (:255) does apply the main-thread filter. The first harness that recovers a timed child generation turns the golden gate red for behaviourtests/test_event_collector.py:575ratifies as correct. _(trigger: tests/_fixtures/golden_streams/scrub.py) (restates: Axis 8: assert_timing_captured omits the collector's main-thread filter) - 🔵 The four-bucket decomposition was re-derived in two places instead of in the module created to own it.
scripts/timing/decompose_run.py:40-69andtests/_fixtures/golden_streams/_scrub.py:120-139ship body-identical_parse/_tool_mshelpers and near-identical bucket assembly, and both already importbusy_msfrom the newcoder_eval.timing— so the shared home exists and was half-used. The two copies have already drifted (decompose_run.py:96guards the generation sum with anisinstancetest the_scrub.pycopy lacks), which matters because the script is documented as the two-sided cross-check on the sensor it duplicates. (trigger: src/coder_eval/timing.py) (restates: Axis 1: The four-bucket decomposition / record->tool-span extraction is restated in the gate script and the golden sensor)
Tests:
- 🟠 No test covers the new claude-code tool-time subtraction, the one change in this PR that alters a persisted metric on the most-used harness.
_subtract_tool_time_from_windows(src/coder_eval/agents/claude_code_agent.py:593, called at:644) has zero hits undertests/; replacing the call with a no-op leaves the whole suite green (5659 passed, identical to baseline). The two existing sensors cannot see it:SCRUB_KEYSmasksgeneration_duration_msin every golden, and the four-bucket identity is an upper bound with a 0.1 ms floor over sub-millisecond replays. The other four harnesses each got a directTestGenerationWindowExcludesToolExecutionreducer test for this exact arithmetic; claude-code is the only one without, and it is the only one whose subtraction is bespoke. (trigger: src/coder_eval/agents/claude_code_agent.py) (restates: Axis 3: claude-code's new tool-time subtraction changes every published generation_duration_ms with zero committed coverage) - 🟡 The new operator gate has no test and sits outside every automated gate.
scripts/timing/decompose_run.py(+285, the first Python file ever added underscripts/) is excluded from pyright'sinclude, fromtestpaths, fromcoverage.source, and from the ruff paths CI actually runs (pr-checks.yml:87/:90hardcodesrc/ tests/). It reports 6 pyright errors under settings this repo sets to "error", including three untypedturn: dictparams at the point where the cross-repotask.jsoncontract is parsed. Its inputs are plain dicts, so_turn_buckets/_residual_ms/ the--max-residual-pctexit code are all unit-testable with no live run. (trigger: scripts/timing/decompose_run.py) (restates: Axis 7: New 285-line scripts/timing/decompose_run.py sits outside every CI gate) - 🔵 The evalboard's new prop wiring is untested across its two hops.
page.tsx:368-369forwardsharnessStartupMs/harnessTeardownMstoCostExplorerSection, which forwards them again toMessageTimelineSection(_sections.tsx:862-863). No test rendersCostExplorerSectionat all (git grep CostExplorerSection evalboard/**/__tests__is empty) — the newmessage-timeline.test.tsxblock rendersMessageTimelineSectiondirectly. Because both props are optional and the consumer coalesces with?? 0, dropping either forward silently renders "—" in both cells and restores the old (over-large) Unaccounted number with every test still green — the same "nothing failed" shape the PR's own CE060 story describes. (trigger: evalboard/app/runs/[id]/[...task]/page.tsx) - 🔵
decompose_turn, the newest public function of the new module, has no direct test.busy_msandclose_windoweach got one (tests/test_timing_union_parity.py,tests/test_timing_close_window.py);decompose_turnis reached only throughEventCollector, whose guards make both of its documented never-measured arms (timing.py:225,:228) unreachable — they show as the module's only two partial branches. Its "Nonemeans never measured" contract is stated but never asserted at the helper. (trigger: src/coder_eval/timing.py) (restates: Axis 3: decompose_turn's documented never-measured guards are never exercised)
Downstream consumers:
- 🟡 claude-code's
generation_duration_mschanged definition and no consumer of that number was reviewed or updated. The PR's test plan states "waves 2–3 touch noevalboard/file" — true of the files, not of the values they render. Every claude-code emission now loses its overlapping tool time (the PR measures 482 ms and 340 ms on two ~18–25 s turns), which shifts: the timeline's Generation cell and per-block split,thinkingShare = thinkingMs / attributableGenMs(_sections.tsx:407), theSLOW_GEN_MS = 10_000red-bar threshold (_sections.tsx:36) — a 10.3 s window that sheds 400 ms stops being flagged — andthinkingSim.ts:301/315, which weights per-message token attribution bygenerationMsand therefore re-distributes simulated thinking cost across a claude turn. None of these is wrong afterwards; the gap is that the value change is unstated, so nobody checked whether any of them encodes the old magnitudes. (trigger: src/coder_eval/agents/claude_code_agent.py) - 🔵 The new buckets stop at the task page; the surface that exists to compare harnesses was not extended.
TaskDetailgainsharnessStartupMs/harnessTeardownMs(evalboard/lib/runs.ts:367-370), butTaskResultSummary,RunPoint/lib/overview.tsand_overview/wall-clock-chart.tsxdo not — and that chart exists precisely for this comparison ("codex runs the suite in roughly a third of claude-code's wall clock"). The PR's headline numbers are per-harness constants (codex ~3.1 s, opencode ~2.5 s, claude/antigravity ~0 per turn), so the only ways to see them over a suite are opening one task page at a time or running the unscheduleddecompose_run.pyby hand. (trigger: evalboard/lib/runs.ts)
Display & mapping dicts:
- 🟡 The Python report renderers were not extended for the new record fields, so the shareable reports and the evalboard now disagree about what a turn's time is made of. The evalboard grew Startup and Teardown cells and a corrected Unaccounted;
reports.py::_generate_generation_metrics_section(:341-361) still emits| Task ID | Total Latency | Turns | Asst Turns | Avg Turn Latency |, andreports_html.py::_render_generation_metrics(:935-964) still renders the same four stats — and CLAUDE.md callsreports_html.py"the evalboard's static twin". Neither file appears in the diff, andgit grep harness_startup_ms src/returns onlymodels/,streaming/andtiming.py: no Python renderer reads either field. A run shared asrun.mdorreport.html(the artifacts a CI gate and an offline reviewer get) cannot see the buckets this PR exists to add, and both renderers already readturns[i].duration_secondsat exactly the level the new fields live at. (trigger: src/coder_eval/models/results.py)
Daily/nightly:
- 🟡 The only two-sided identity gate ships unscheduled, and the PR does not say who runs it or against which nightly runs.
docs/agents/HARNESS_PARITY.md:46namesscripts/timing/decompose_run.py --max-residual-pct Nas the two-sided check, and the same paragraph plus the PR body concede it is "report-only and nothing runs it on a schedule". Meanwhile the committed sensor is one-sided (overshoot <= max(0.1 ms, 20%)) and magnitude-blind (SCRUB_KEYSmasksgeneration_duration_msand both bounds), so a per-harness timing regression on the nightly ships with the suite green — which is exactly what happened for the two defects this PR found by live measurement rather than by a red test. Acknowledging the gap in prose is not the same as closing it: a nightly step (or amaketarget over the previous night'stask.jsoncorpus) is the missing piece, and the gate already exits non-zero on an empty gateable set for this reason. (trigger: scripts/timing/decompose_run.py) - 🔵 No statement of blast radius on the run-record corpus the nightly and the external pipeline consume.
task.jsongains twoTurnRecordfields (additive and optional, so old readers are safe) and, on the most-used harness, one existing field changes meaning. Nothing marks the boundary inside the record itself — onlyenvironment_info.git_commitdistinguishes a pre-change claude run from a post-change one — so the blob-synced historical corpus now holds two definitions of claude-code generation time under one field name, and any longitudinal comparison on the evalboard silently mixes them. Also unstated: what the external eval-runner /coder-eval-uipathconsumer does with the new keys, and that a partially-copied run directory (the known-partial evalboard copy path) renders the new cells as "—" rather than as an error. (trigger: src/coder_eval/models/results.py)
Harness & Lint Improvements
Static checks (lint / type):
- [ce-lint] CE064 — an agent-event stamp must come from the turn clock. New rule
tests/lint/rules/ce064_event_stamp_from_turn_clock.py, wired intotests/lint/runner.py::ALL_RULES. Insrc/coder_eval/agents/, any module that uses aTurnClockmust passtimestamp=EXPLICITLY to everyAgentStartEvent/AgentEndEvent/TurnStartEvent/TurnEndEventit constructs. Same shape as CE060 (the kwarg must be PRESENT, not statically non-None), so reuse_model_ctor's import-alias resolution rather than hardcoding the class spelling. Prevents: Finding A5 (two-basis subtraction).StreamEvent.timestampdefaults to a rawdatetime.now()(streaming/events.py:89) and neither converted harness overrides it — pi_agent.py:1029-1034/:743, antigravity_agent.py:587/:1167 — while their message bounds and tool spans are TurnClock-derived, sodecompose_turnsubtracts across two bases and a mid-turn NTP/DST step lands whole inharness_teardown_ms. - [ce-lint] CE065 — a
TurnClockis injected, never defaulted. New rule intests/lint/rules/: insrc/coder_eval/agents/, a parameter annotatedTurnClock(orTurnClock | None) may not carry a default, andTurnClock()may not be constructed inside a turn-state__init__. This isclose_window's own documented discipline (timing.py:127-133: "keyword-only and has NO default so that no reducer can open a window without stating what it tiles from") applied to the clock itself. Prevents: Finding A5-low (injection contract diverges): pi_agent.py:272clock: TurnClock | None = None+ :285self.clock = clock or TurnClock(), withcommunicatenever passing one — so on the production path the lifetime is invisible and the parameter exists only for tests, against antigravity_agent.py:816's requiredclock: TurnClock. It is also the prerequisite for CE064's fix and for the clock-step and un-scrubbed-golden harness items below. - [pyright] Make
decompose_turn's four bounds untransposable by type. Replace the four baredatetime | Nonepositional parameters (src/coder_eval/timing.py:234-239) with two distinct frozen dataclasses —GenerationBounds(first_started_at, last_completed_at)andAgentBounds(started_at, ended_at)— or twoNewTypes. No config flip is needed:typeCheckingMode = "standard"already rejects a nominal-type mismatch, so the swap becomes a typecheck error atmake typecheckinstead of silence. Prevents: Finding A2/A1/A7 (signature discipline). Transposingfirst_started_atwithagent_started_attype-checks cleanly today and yields an inverted interval →busy_ms0.0 →max(elapsed - 0.0, 0.0)clamped to a MEASURED0.0at timing.py:227/230 — the exact 'timed and instant' reading the CE058 rationale exists to make unrepresentable, and invisible to every test (the golden corpus scrubs both fields and asserts presence only). - [ce-lint] CE066 — every public function in
src/coder_eval/timing.pyis keyword-only and default-free. New rule: a module-leveldefintiming.pywhose name does not start with_must declare*before its first parameter and may not give any parameter a default. Narrow file scope keeps it noise-free; the invariant is already stated in the module forclose_windowand simply not applied to its two siblings. Prevents: Finding A2 part (b):tool_spans: ... | None = None(timing.py:239) is omissible even though the function's own docstring (lines 182-191 in the reviewed revision) measures the omission as a double-count of −86% of wall clock on the committedantigravity_d_orphaned_toolfixture. Also removes part (a)'s positional-ordering hazard if the dataclass fix above is not taken. - [ruff] Put
scripts/inside the format/lint gate. Addscripts/toLINT_PATHS(Makefile:22) AND to the hardcoded path arguments in.github/workflows/pr-checks.yml(ruff format --checkat :87,ruff checkat :90, plus the Windows mirror at :391/:394) — CI does not readLINT_PATHS, so editing the Makefile alone changes nothing in CI. Prevents: Finding A7 (the new 285-linescripts/timing/decompose_run.pysits outside every CI gate) and A7-low (--helpreflow). The file's own docstring records the exclusion instead of closing it, directly contradicting the Makefile's stated rationale two lines aboveLINT_PATHS— and the file is now the two-sided residual gate thatpr-checks.yml:604actually runs. - [pyright] Add
"scripts"to[tool.pyright] include(pyproject.toml:307). This fails immediately and usefully: 6 errors already exist under settings the project sets to"error"—turn: dictat decompose_run.py:49/:72/:113 (reportMissingTypeArgument, pyproject.toml:347) and implicit string concatenation at :251/:258/:277 (reportImplicitStringConcatenation, :355). Type the three parametersdict[str, Any]. Prevents: Finding A7. Those three untypeddictparameters are exactly where the cross-repotask.jsoncontract is parsed, in the only two-sided sensor for the four-bucket identity — a silent regression there disarms the gatedocs/agents/HARNESS_PARITY.md:46leans on. - [ce-lint] CE067 — lint-path parity between the Makefile and CI. A whole-tree check (a
@pytest.mark.linttest class, like CE028/CE035, not aBaseRule): the path arguments toruff format/ruff checkin.github/workflows/pr-checks.ymlmust equalLINT_PATHSin the Makefile, and pyright'sincludemust cover the same tree. Prevents: The second-order cause of Finding A7 — and a live instance: CI lintssrc/ tests/and never.github/scripts/, which the Makefile comment claims is "in scope on purpose". Without this, the two fixes above drift apart again the next time a path is added on one side only. - [ce-lint] CE068 — no bare
task.jsontiming-field literal outside the record decoder (CE053's shape, new domain). Forbid the string literalsexecution_started_at,execution_completed_at,generation_duration_ms,parent_tool_use_id,harness_startup_ms,harness_teardown_msas dict keys anywhere except one decoder module (coder_eval/timing.pyor atiming_record.pyleaf) and the pydantic models that declare them. Enforcing it requires the extraction the finding recommends: move_parse+ the tool-union + the main-thread generation sum + the bucket/residual assembly into the shared module and have both consumers import it. Prevents: Findings A1/A5 (the decomposition is pasted twice) and A8 (assert_timing_capturedomits the producer's main-thread filter). Both copies have ALREADY drifted, which is the argument: decompose_run.py:96 guards the generation sum with anisinstancethe_scrub.py:252-256copy lacks, and_scrub.py:231omits theparent_tool_use_id is Nonepredicate thatstreaming/collector.py:156-159applies and that the same function applies correctly 20 lines lower — so the gate and the sensor that are meant to cross-check each other are the same code, half-diverged. - [ce-lint] CE069 — a force-closed tool must carry both execution bounds. New rule: in
src/coder_eval/agents/, an assignment ormodel_copy(update={...})that setsresult_statusto an unresolved/unknown sentinel must setexecution_completed_atin the same statement. Prevents: Finding A6 (orphan run-time booked as teardown). antigravity_agent.py:1139 does it; claude_code_agent.py:1427-1437 and codex_agent.py:769-782 do not, so a hungBash: sleep 600killed byturn_timeoutproduces 295 s ofharness_startup_ms/harness_teardown_ms— a field documented as "SDK/CLI finalization, result assembly and process teardown" — while the identical event on antigravity lands in the tool union. Per the repo's parity rule, a divergence is fixed or documented; this makes 'fixed' the default and forces a deliberate# noqaotherwise. - [ce-lint] CE070 — one stamp basis: no tz-aware datetime in the stamp producers. Ban
datetime.now(<arg>),.astimezone(, andtimezone.utcinsrc/coder_eval/agents/andsrc/coder_eval/streaming/, so every stamp reachingdecompose_turn/busy_msis naive-local by construction. Stated boundary: lint cannot reach out-of-tree SPI agents (coder_eval_uipath), and the framework's own naiveStreamEvent.timestampdefault makes a merely UTC-stamping plugin break on its first turn — so the runtime_require_same_awareness(a, b, ...)guard the finding recommends is still required. The rule kills the in-tree class; the guard names the disagreeing pair for a plugin. Prevents: Finding A6 (unguarded naive/aware subtraction). Today aTypeErrorat timing.py:226 escapes pi_agent.py's turntry→_crash_turn→AgentCrashError, and_capture_partial_turnre-invokesbuild_turn_record()and raises again (swallowed), so a completed turn is reported as a crash, its trajectory is discarded, and the retry machinery re-runs it at full API cost with an error naming neither the field nor the harness. - [ce-lint] CE071 — every registered agent has a generation-window reconciliation test (registry-derived coverage, CE036's shape). For each module in
src/coder_eval/agents/that registers an agent kind, require a test namedtest_the_published_window_reconciles_to_its_own_boundsin the matchingtests/test_<kind>_agent.py(or the shared telemetry module). Declare the blind spot in the rule's docstring: it proves a test EXISTS, never that any assertion depends on the subtraction — the mutation gate in the harness bucket is its complement. Prevents: Finding A3/A8 (high):_ClaudeTurnState._subtract_tool_time_from_windows(claude_code_agent.py:593, called at :644) mutates a persisted metric on the most-used harness with zero committed coverage —git grepreturns 5 hits, none intests/— while codex, opencode, pi and antigravity each got exactly that test. Neutering the call leaves the suite at the same 5659 passed. - [ce-lint] CE072 — CLAUDE.md structural parity. A derived test in the exact style of the existing CE030 prose check (
tests/test_custom_lint.py:1100-1117): every top-levelsrc/coder_eval/*.pymodule must have a row in CLAUDE.md's Directory Structure tree, and everytests/lint/rules/ceNNN_*.pyid must appear in CLAUDE.md's "Recent additions" prose. Prevents: Finding A5/A1/A7/A8-low (four axes reported it):src/coder_eval/timing.py— a new top-level module owning the four-bucket arithmetic — has no tree row, andgrep -c CE061 CLAUDE.mdreturns 0 while CE060 from the same diff was indexed. The tree enumerates every other top-level module, so the omission is drift, not a convention. - [ce-lint] CE073 —
ArgumentParser(description=__doc__)must passformatter_class=argparse.RawDescriptionHelpFormatter. A five-line AST rule; only reachable oncescripts/is in lint scope, which is itself the point. Prevents: Finding A7-low: the defaultHelpFormatterre-wraps the module docstring, collapsing the one usage line an operator needs to copy into mid-paragraph prose and dumping maintainer-only notes ("scripts/is outside the Makefile's LINT_PATHS…") into--helpoutput. - [ce-lint] Assert the
FICTIONAL_DURATIONSledger instead of describing it. Intests/test_agent_golden_master.py, assertlen(FICTIONAL_DURATIONS) + checked == len(expected/*.json)with the exempt set enumerated — the shapeTestCE061WindowViaCloseWindow::test_each_suppression_is_load_bearingalready uses — and add a parity assertion against the count sentence in.claude/harness-candidates.md:562. Prevents: Finding A3-low: that ledger claims "22 of 27 scenarios are checked… the remaining 5 are exempt" while the committed frozenset holds 7 entries (real figure: 20 of 27). It is the document a future author consults before deciding the identity hole is closed, so a stale count there directly overstates coverage.
Harness improvements (not statically reachable):
- A mutation gate for the timing seam. Add a
make mutate-timingtarget (or a pytest-driven harness) that applies a fixed, committed list of scripted mutations and asserts each turns the suite RED: no-op_subtract_tool_time_from_windows; transposedecompose_turn's head/tail argument pairs; drop themax(..., 0.0)clamp; drop theparent_tool_use_idfilter in_overhead_ms. Run it inpr-checks.ymlbeside the custom-lint step. Why not static: A lint rule can see that a test file and a test name exist (CE071), but never that any assertion depends on the code under test. Finding A3 was proved exactly this way: the mutated and unmutated trees both report 5659 passed, 13 skipped, and the branch is executed 9 times — so it shows as covered at 95.93% while its effect is never asserted. Prevents: A3/A8 high (claude-code tool-time subtraction with zero effective coverage); A3-low (decompose_turn's two never-measured guards, both arcs permanently partial). - Stop scrubbing the timing values in the golden corpus. With the clock injectable on every harness (CE065), replay each scenario against a scripted clock and pin the exact milliseconds for
generation_duration_ms, both window bounds, bothexecution_*_atstamps andharness_startup_ms/harness_teardown_ms, instead of the<scrubbed>placeholder (_scrub.py:29 SCRUB_KEYS). Why not static: Needs a recorded event stream replayed through a real reducer; the values are only deterministic once a clock is injected, which is a runtime property no AST rule can establish. Prevents: A3/A8 high (a claude generation window can move by seconds with every golden green); A6 (orphan attribution invisible); A8 (assert_timing_captured's divergence from its producer). - Make the committed identity sensor two-sided and orphan-aware. Extend the ms-exact contract module so it asserts
-tol <= residual <= tolrather than onlyovershoot <= max(0.1 ms, 20% of wall), and add one case per harness where a tool never resolves, asserting WHERE the hung tool's time is booked. The scenarios already exist (claude_f_orphaned_tool,codex_e_orphan_tool,antigravity_d_orphaned_tool,opencode_d_,pi_d_); only the attribution assertion is missing. Why not static: An undercount is an arithmetic outcome of a replayed stream, not a code shape — and on sub-millisecond synthetic replays the existing 0.1 ms floor swallows any claude-scale overlap, so the tolerance itself has to be made real by a scripted clock. Prevents: A6 (unbounded orphan booked asharness_teardown_mson claude-code and codex, the opposite of antigravity's answer for the identical event); A3/A8 high. - A cross-harness parity replay. One synthetic event script driven through all five reducers, asserting the four buckets agree within tolerance for the same input — including an orphaned tool and a multi-generation turn. Why not static: Parity is a property of five implementations' OUTPUTS on one input. No rule over a single file's AST can compare them, and
docs/agents/HARNESS_PARITY.md:35currently asserts the identity holds for all five with no orphan carve-out — a claim nothing verifies. Prevents: A6 (claude-code/codex vs antigravity orphan divergence); A5 (the replicated window state machine, whose copies are currently correct only by hand); A5 (two-basis head/tail on the two converted harnesses). - A clock-step resilience case. With
TurnClockrequired (CE065) and event stamps clock-derived (CE064), drive a full turn whose wall clock jumps forward and then backward mid-turn, and asserthead + Σ generation + ∪ tool + tail <= duration_secondsstill holds against the MONOTONICduration_secondsboth converted harnesses publish (pi_agent.py:764, antigravity_agent.py:1181). Why not static: Needs simulated time across a whole turn; the defect only manifests under a real clock step, which is precisely the standard the codebase accepted when it addedTurnClock("Nightly runs start at 04:18 and run for hours, so it is reachable rather than theoretical"). Prevents: A5 (raw-wall AgentStart/AgentEnd stamps subtracted from TurnClock-derived message bounds; a forward step inflates the tail whileduration_secondsis unmoved, violating the new corpus invariant, and a backward step silently clamps to 0.0). - Test and cover
scripts/timing/decompose_run.py. Unit tests over synthetic turn dicts for_turn_buckets,_residual_msand the--max-residual-pctexit code (no live run needed — the inputs are plain dicts), and addscriptsto[tool.coverage.run] source. Why not static: The gate's contract is an exit code and a threshold comparison — behaviour, not shape. Static inclusion (the ruff/pyright entries above) fixes the annotations; only a test fixes the gate semantics. Prevents: A7 (the file is the ONLY two-sided residual sensor, is invoked bypr-checks.yml:604, and has zero tests — a silent regression in it disarms the gate the docs lean on); A1/A5 (the duplicated decomposition it hosts). - Fold the window STATE machine into the timing seam, not just the arithmetic. Add a small
GenerationWindowtocoder_eval/timing.pyowningmark,spansandpending_start, withadd_span()/close(now), and adopt Codex's clip-only shape — drop the hand-cleared per-window span lists entirely, sincebusy_msalready discards spans outside[lo, hi](timing.py:95, and codex_agent.py:492-496 proves it by never clearingself.commands). Why not static: CE061/CE063 can only prove that a window's arithmetic came from the shared helper — CE061's own docstring concedes this ("proves the module IMPORTS the helper, never that any particular call used it"). No rule can prove a hand-cleared list was cleared at the right MOMENT, and that bookkeeping is where every defect on this branch lived: 'clearing the list now wipes the span beforestep_finishcan subtract it' (opencode_agent.py:376-377) and '3000 ms of generation for a 2000 ms turn' (pi_agent.py:655). Prevents: A5 (the 3-part machine replicated verbatim from OpenCode into Pi by this PR, with a third variant in antigravity and a fourth in codex). - Pin the documented
Nonecondition ofharness_startup_ms/harness_teardown_mswith the fixture that already contradicts it, and reword both descriptions to the producer's real predicate (no assistant message with a measurablegeneration_duration_mson the main thread). Namecodex_g_items_rebuild.json— one assistant message, both fieldsnull— in an explicit test so the contract and the corpus cannot drift apart again. Why not static: Prose-vs-behaviour agreement needs semantic judgment: no rule can read "None when the turn produced no assistant message" and compare it to a three-predicate filter instreaming/collector.py. CE054-style key round-tripping proves a key is written, not that its description is true. Prevents: A2/A7-low (both new field descriptions atmodels/results.py:339,348state aNonecondition the PR's own committed golden fixture contradicts — ontask.json, which is the cross-repo contract surface). - Write the contract down where an out-of-tree harness will read it: in
docs/agents/HARNESS_PARITY.mdand thecoder_eval.pluginsSPI section of CLAUDE.md, state that (a) an agent's event stamps and its message/tool stamps must come from ONE clock, (b) stamps must be tz-naive local, and (c) a new harness inherits the window state fromtiming.pyrather than re-deriving it. Add the orphan-attribution row the parity table is missing. Why not static: This repo's lint never runs against out-of-tree SPI agents —coder_eval_uipath's Delegate agent already ships separately — so for third-party reducers the documented contract plus the runtime_require_same_awarenessguard are the only available enforcement. Prevents: A6 (naive/aware mix reaching a plugin's first turn as a spuriousAgentCrashError); A5 (two-basis stamps); A5 (state-machine re-derivation); A6 (undocumented orphan divergence —HARNESS_PARITY.md:32gives codex an 'or neither' qualifier that claude-code lacks, and :35 claims the identity for all five).
Top 5 Priority Actions
- Guard the two new subtractions in
src/coder_eval/timing.py:226(and thebusy_msclip at:95) against a naive/aware datetime mix with a_require_same_awarenesshelper that names the disagreeing pair — today a third-party SPI agent that stamps its messagesdatetime.now(timezone.utc)whileStreamEvent.timestampkeeps its naive default turns every completed turn into anAgentCrashErrorwith the trajectory discarded and a full-cost retry, changing final_status for identical agent output. - Add a direct reducer test for
_ClaudeTurnState._subtract_tool_time_from_windows(src/coder_eval/agents/claude_code_agent.py:593, called at:644) covering the overlap, the clamp-to-zero case and the twocontinueguards at:628-631— neutering the call leaves all 5659 tests green, the goldens scrubgeneration_duration_ms, and the four other harnesses each already have this test, so the most-used harness mutates a persisted metric with zero assertions behind it. - Stamp
execution_completed_atwhen claude-code and codex force-close an unresolved tool (src/coder_eval/agents/claude_code_agent.py:619,codex_agent.py:769-782), matching antigravity'santigravity_agent.py:1139, or document the divergence indocs/agents/HARNESS_PARITY.md— otherwise a 600 s hung Bash killed byturn_timeoutpublishes ~295 s ofharness_teardown_ms("SDK/CLI finalization and process teardown") on two harnesses and ~0 ms plus a tool-union span on a third, for the identical event. - Make
decompose_turnkeyword-only andtool_spansrequired (src/coder_eval/timing.py:166), following the discipline its own siblingclose_windowstates at:128-133— four consecutive positionaldatetime | Noneparams let a transposition type-check cleanly and clamp to a measured0.0head or tail, the exact reading CE058 exists to make unrepresentable, and the omissibletool_spansdefault is a double-count the docstring itself measures at -86% of wall clock. - Close the gap in the sensors that guard the four-bucket identity: add the missing
parent_tool_use_id is Nonemain-thread filter attests/_fixtures/golden_streams/_scrub.py:231(it contradicts both the producer atstreaming/collector.py:156-161and the unit test attests/test_event_collector.py:575), and bringscripts/timing/decompose_run.py— the only two-sided residual gate, 285 lines, 6 pyright errors, no test — under ruff/pyright/pytest by editing.github/workflows/pr-checks.ymland pyright'sinclude, not onlyLINT_PATHS.
Stats: 0 🔴 · 1 🟠 · 8 🟡 · 6 🔵 across 8 axes reviewed.
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>
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
…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
Clears the three entries registered under "From the turn-timing P0–P3 run" in .claude/harness-candidates.md. claude-code now derives every wall stamp a turn records from one injected `TurnClock`: both window bounds, the fallback tool timestamp, and the tool span. Sharing raw `datetime.now()` had already removed the bounds-vs-span disagreement; it left both sides naive-local, where a DST transition or an NTP step inside a turn lands directly in a generation window — an hour-long jump in a millisecond field, on nightly runs that start at 04:18 and last hours. `_resolve_pending_command` takes the reading as an argument rather than reading a clock of its own: it stamps the span that is clipped against those bounds, so a second basis at that one call site would put two clocks inside one subtraction. `turn_start_time` and the turn deadline stay raw monotonic — a deadline must not move when the wall clock steps. One raw `datetime.now()` is left deliberately, on the synthesized sub-agent terminal message, and the code says why: those bounds are an admitted placeholder that `subtract_tool_time` and `_overhead_ms`'s head/tail bracket both exclude, so no arithmetic reads them and there is no basis to share. The clock is INJECTED, not read from a module global. That is load-bearing for the sensor rather than cosmetic: a derived stamp escapes a monkeypatched `datetime`, so the old patch would have left tests/test_timing_identity_contract.py measuring the real clock and passing by accident. It is re-pointed at the injected clock, keeps `time.monotonic` patched (the tool duration is still monotonic-measured), and reverting the conversion now fails it by ~10^7 ms. pi `_close_tool` stamps `execution_completed_at` and derives `duration_ms` only when the status is not UNRESOLVED — the guard the old comment claimed and the code did not have (it tested `execution_started_at is not None`, which an orphan passes). The sweep's instant is not a completion anybody observed, and the manufactured pair read as a measured span the collector took back out of a generation window the tool never occupied. `execution_started_at` is kept: the CLI really did emit that start, and one bound alone forms no span. pi `on_turn_end` clears `turn_text_parts` / `turn_tool_ids` beside `turn_started_at`, on the argument that comment already made — all three have been SPENT into the message just appended. The timing half of that reset had a unit test that stayed green while the content half republished the previous turn's text as its own assistant message and re-listed the same `tool_use_ids`, so the two are now asserted separately. Both pi defects were captured in committed goldens. Regenerated with GOLDEN_REGEN=1, and the run before it failed on exactly those two scenarios: pi_d loses a `duration_ms` and an `execution_completed_at` to `null`, pi_f's second message loses the republished text block. Nothing else moved. Registered but NOT fixed: antigravity stamps a completion on its own orphan sweep the same way (no `duration_ms`). `timing.decompose_turn`'s docstring reasons about that stamp landing in the tail and the antigravity_d residual was measured against it, so it needs its own fixture re-derivation rather than a ride-along. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01FpDo37ypvLjLiWXFsEkg6k
`decompose_turn` computes the head and the tail by subtracting a generation
window bound from an AgentStart/AgentEnd timestamp, so the two have to
share a basis. The three harnesses that own a `TurnClock` derived their
window bounds from it and let the bracket fall back to
`StreamEvent.timestamp`'s `default_factory=datetime.now` — a
monotonic-derived stamp and a raw wall stamp inside one subtraction, which
is the exact split `TurnClock` exists to remove, reintroduced at the one
seam the clock did not own.
Measured, not hypothetical. Instrumenting `decompose_turn` on a live
antigravity turn printed:
PROBE tail: elapsed=-0.017000ms busy=0.000000ms raw=-0.017000ms
last_completed = 09:05:22.033099
agent_end = 09:05:22.033082
an AgentEndEvent stamped 17 us BEFORE its own last message finished, which
cannot happen: the event is constructed strictly after the final flush.
`decompose_turn` clamped the negative and published `0.0` — "measured, and
instant", the CE058 confusion reached from the other direction — for a
harness whose real tail is ~0.1 ms. After the fix the same task records
0.035 ms, a real measurement rather than a clamp.
It only showed on one harness because the drift between the two clocks is
tens of microseconds, so it can flip a sign only where the true interval is
itself that small. Antigravity is the only harness that spawns its process
once in `start()` and holds it across turns, so nothing happens between its
last flush and its AgentEndEvent; every other harness books a head of
0.2-6 s and a tail of 7-543 ms, where the drift is invisible. Invisible is
not absent, so the fix is applied at every clocked site: that is what makes
the subtraction single-basis rather than usually-close, which is not a
property a millisecond field can rest on.
Note this was widened by the previous commit. claude-code's bounds used to
be raw `datetime.now()` — the same basis as the events — so its subtraction
was single-basis until the TurnClock conversion.
CE064 keeps it fixed: in `agents/`, a module that imports `TurnClock` must
pass an explicit `timestamp=` to AgentStartEvent/AgentEndEvent. Scope is
DERIVED from that import, never a harness list — codex and opencode take
their spans from the CLI's own epoch stamps and deliberately have no clock,
so a raw `datetime.now()` bracket is consistent with their bounds and the
rule must not fire on them; the day either adopts a clock the rule starts
applying with no edit here. The rule checks presence, not spelling, because
the three harnesses reach their clock three different ways and pinning a
spelling would make it a syntax check on their internals; what it removes
is the silent case, a default nobody chose, which is the one that shipped.
Mutation-checked against the real tree.
`_model_ctor.reaches_models_module` is generalized to `reaches_module` so
CE064 reuses the binding resolver rather than copying it (the argument that
file already makes for CE060/CE061 sharing it). Its relative-import matcher
compared a single `rpartition` tail, which was right only while every
target was one segment deep and silently missed `coder_eval.streaming.events`
outright — a rule blind for a whole file rather than a near miss. It now
matches any segment-wise suffix. CE060/CE061 behaviour is unchanged.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01FpDo37ypvLjLiWXFsEkg6k
Three fixes to make the published numbers mean what they say. 1. A row's EXEC cell is the UNION of its tool calls, not their sum, and goes through the same `toolExecutionMs` the header strip uses so the two cannot answer one question two ways. Summing double-books concurrent calls: one measured antigravity turn issued two `sleep 2` Bash calls overlapping almost entirely and the cell read 4.1s for 2.1s of wall clock — more tool time in one message than the whole task's Tool exec cell, which is impossible on its face. The comment on that line claimed parity with the strip; that stopped being true when `toolExecutionMs` was changed to union and this line was not. Expanding a row still shows each call's own wall clock, so sequential calls add up to the row total and concurrent ones deliberately do not — which is where the concurrency becomes visible. 2. `EvaluationResult.setup_ms` and `grading_ms`, so the evalboard's Unaccounted cell is a residual rather than a name for the setup phase. It held ~1.9s of known, constant orchestrator cost on every row — 10% of a 19s task, and it would read 60% of a 3s one. Measured after the split: 1.9% (claude-code) and 7.3% (pi), and what remains is post-AgentEnd subprocess reaping, post_run, cleanup and persistence, which is why the remainder is larger for the harnesses that drain a CLI. They are TASK-scoped and deliberately NOT a fifth and sixth member of the turn's four buckets. Folding setup into the first turn's `harness_startup_ms` is wrong three times over: it breaks the turn identity (head + generation + tool + tail == the turn's span) by construction; a dialog-mode task runs N turns against ONE setup, so turn 1 would stop being comparable with turns 2..N; and it is not harness time at all — measured at ~1.86s for claude-code and pi alike on the same machine, which is the tell that it is the orchestrator's own. `grading_ms` accumulates on the SuccessChecker rather than at the four orchestrator call sites, so a fifth cannot be added without it, and in a `finally` so a grade that raises still books the time it spent. Both are `None` rather than 0.0 when never measured — an ungraded `execute` row grades nothing (CE058). `setup_ms` is CARRIED on a detached re-grade (a fact about the run, like `duration_seconds`; a re-grade ADOPTS a workspace instead of provisioning one) and `grading_ms` RECOMPUTED (the verdict came from this pass). The fail-closed field partition in tests/test_seed_from_prior_result.py caught both as unclassified, which is that sensor working. The evalboard's own CE058 twin caught the two new `?? 0` subtractions and its staleness check caught the allowlist entry for the line this change removed. Both new row-union tests were mutation-checked: restoring the sum makes them read 4.0s against an expected 3.0s. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01FpDo37ypvLjLiWXFsEkg6k
The field's own description said "from the task starting until the agent
phase begins" and the mark sat at `_setup()`, which is not the same
instant. Instrumenting the seams on a live claude-code task showed what
fell in the gap:
get_version_info() 733.0 ms
post_run 32.1 ms
_cleanup() 1.4 ms
_finalize_result (writes task.json) 1.9 ms
eval-loop preamble + post-AgentEnd 4.7 ms
------------------------------------------------
residual 758.4 ms (4.3% of wall clock)
97% of the residual was ONE call. `utils.get_version_info()` shells out for
the git commit and every CLI's `--version` — timed directly at 733 ms — and
it runs while `EvaluationResult` is being constructed, which is before
`_setup()` is reached. So the largest item in a phase named "setup" was
outside it, and landed in the report's residual where it read as a real
unknown.
Moving the mark beside `start_time` makes the field mean what it says.
Measured after: 42.3 ms, 0.26% of a 16.4 s task, down from 758 ms (4.3%)
and from ~1.9 s (10%) before any of this work. What is left is the tail of
that table — post_run, sandbox preservation, persistence, post-AgentEnd
reaping — with no single nameable phase in it, which is what "unaccounted"
should mean.
Worth stating plainly rather than leaving implied: `setup_ms` now carries a
~733 ms constant that is instrumentation overhead, not work any task
needed. Naming a cost is not the same as removing it; caching
`get_version_info()` across a batch run would take ~0.7 s off every task in
a suite and is recorded in the doc as the follow-up.
Verified on claude-code only. Pi could not be re-measured: its CLI began
hanging with zero stream events partway through this session, reproduced
standalone outside the harness on the same prompt, and its last successful
run (09:30:46) postdates the last commit touching `pi_agent.py` (09:21:53)
by nine minutes — so the hang is external and the pi figure is simply not
claimed here.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01FpDo37ypvLjLiWXFsEkg6k
CE064 declares its own blind spot: it can only see that `timestamp=` is passed, never that the value came from the turn's clock, because the three clocked harnesses legitimately reach theirs three ways (a `communicate` local, `state.clock`, `self.clock`). Pinning a spelling would make the rule a syntax check on their internal structure. So the rule removes the SILENT case — a default nobody chose — and a behavioural test has to cover the rest. That test cannot be written against real time. A bracket left on `StreamEvent.timestamp`'s `default_factory=datetime.now` lands within microseconds of a clock-derived one; an assertion comparing the two would pass either way, which is the same "green sensor that measured nothing" this branch keeps registering. `tests/_bracket_clock.py` injects a `TurnClock` stand-in anchored at 2027-01-15 — ~1.1e10 ms out, the device `test_timing_identity_contract` already uses — so a reverted argument fails by a year. Verified by mutation, one site at a time: deleting any one of the six fails at least one test. The same fixture carries the second half. It advances on the real monotonic clock, so with the bracket and the window bounds finally sharing a basis the head and tail come out as small positive measurements. Antigravity asserts `harness_teardown_ms > 0.0` directly, which is the published defect: its tail was the `0.0` `decompose_turn` produced by clamping a negative that two clocks disagreeing had created. Also records CE064 on the two doc surfaces, and adds the lint arm the pre-committed test class was missing — it aliased the EVENT class but never `TurnClock`, so nothing asserted that an aliased clock import still puts a module in scope. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
`generation_duration_ms` is a field each reducer PUBLISHES, and nothing checked it against the bounds published beside it. Deriving it at the collector instead was the alternative, and was cut: it costs five reducers, a regeneration of every golden, and a rewrite of CE059 — whose exemption keys on the kwarg being present at the call site, so removing it makes three legitimate placeholder sites start claiming a window. This assertion is what makes that deferral safe, and the docstring says so, because the next reader will otherwise re-derive the decision. It overlaps CE061 on purpose. All five reducers build the window with `close_window(mark=…, now=…)` and write `completed_at=now`, and CE061 forces that shape statically, so the equality is largely true by construction. What this adds is the runtime half: a reducer bypassing the helper in a way an import-level check cannot see, and a third-party agent registered through the `coder_eval.plugins` SPI, which lives outside `agents/` where no rule scoped to that directory reaches it — the same exposure `_require_same_awareness` at this seam is for, and the same trade: it raises rather than degrading, because the condition is unreachable without a reducer bug. Measured before writing it: zero violations from any reducer across the full suite. The 17 that did fail were all hand-built fixtures in one file, modelling a shape no reducer produces — a `generation_duration_ms=1.0` beside bounds seconds apart. They are corrected rather than exempted, at three seams rather than seventeen call sites, and two `TestReconciliation` cases needed distinct windows: messages sharing one instant are grouped as a Codex-style split and then sum to twice the window they claim. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
… is checked Two findings from the phase review, both of which left the guard weaker than its own docstring claimed. The anchor was a written date four months out, so `timestamp >= ANCHOR` would have been satisfied by exactly the raw `datetime.now()` stamp it exists to reject the moment wall time passed 2027-01-15 — a green sensor measuring nothing, on a date nobody would have connected to this test. It is now computed relative to import. (`test_timing_identity_contract`'s fixed EPOCH_MS is not the same hazard: that timeline is fully synthetic and never compared against real time.) And `assert_overhead_is_measured` only caught one of the two reverts. A defaulted AgentStartEvent blows the upper bound by the whole anchor offset, but a defaulted AgentEndEvent fails the other way — it lands BEFORE its own last message, `decompose_turn` clamps the negative, and the published `0.0` sails through an upper bound. Measured: deleting the end-event argument on pi and claude-code left that test green, and only the sibling assertion caught it. A strict `> 0.0` on the tail is the fix, hoisted into the shared helper rather than left as antigravity's local extra — it holds on all three, and antigravity is merely where the margin is thinnest (0.007-0.03 ms, since it alone holds its process across turns). Re-verified by mutation with only that test selected. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
The two languages disagreed about one policy. `toolExecutionMs` folded a call with a `durationMs` and no execution bounds into its union; Python has always dropped it, because `main_thread_tool_spans` filters on `is not None`. So the same task.json produced two different tool totals depending on which surface read it, and the four-bucket identity held on one side only. The union is the side that has to win. A duration with no start and end cannot be placed on the timeline, so it cannot be unioned with anything — adding it to a union double-books whatever it overlapped and can drive the residual negative, which destroys the disjointness the identity rests on. That time is not lost: it reads as Unaccounted, which is exactly what that cell means, a duration the harness measured but cannot place. MEASURED BLAST RADIUS, because someone comparing an August dashboard before and after will otherwise read this as data loss. 9336 of 12170 commands in the run history on disk are unbounded — every one a codex `Bash`, ~28.8 million ms, ~8 h in aggregate. On historical codex runs that much moves out of Tool exec and into Unaccounted. The population is CLOSED: this branch's own `_item_timing` work took codex from 0% bounded before 2026-09-10 to 100% after, so no future run joins it, and a fifth bucket to serve a shrinking historical population would be YAGNI. Going forward the only producer is the out-of-tree `delegate-sdk`, which both divergence records now say so. Neither implementation owns the policy: `unbounded_cases` in the shared corpus does, and both suites replay it — Python through the production SELECTOR rather than through `union_ms`, since the `is not None` filter one layer up is the thing being pinned. The timeline tests moved with it. Their strip fixtures declared `durationMs` with `execStartMs: null`, a shape no in-tree harness has produced since 2026-09-10; they are bounded now, every asserted number unchanged, and the fallback test is inverted rather than deleted. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
The parity table's `clock basis` row called OpenCode "CLI epoch ms, `datetime.now()` only as a fallback". That contradicted the table's own RAW window row ten lines above it — "harness clock: previous `step_finish` to this one" — and the code agrees with the second, not the first. OpenCode's window bounds are host `datetime.now()` (`opencode_agent.py:362`, `:696`) while its TOOL SPANS are CLI epoch ms (`:406`, `:462`). It is MIXED, and the row now says so. That misstatement was load-bearing, which is why it is worth more than a cell edit. The paragraph explaining why Codex and OpenCode are not converted gave them ONE reason — "converting only the window bounds would put two bases inside one `busy_ms` subtraction" — and that describes a state OpenCode is already in. Codex is the one it is true of: both halves come from `_ms_to_dt`, so converting either alone creates the mix. OpenCode's real argument is different and smaller: a monotonic-derived anchor would trade a narrow NTP exposure on the bounds for intra-turn drift against the CLI's own tool stamps. The two now have separate, true reasons. `TurnClock`'s docstring was asserting a current property of two other modules, which is the shape that drifted here in the first place. It now names which harnesses use it and points at the table, which is the designated SSOT for per-harness composition. And the tree stated two positions on one clamp. `decompose_turn` defends it — a measured inversion IS a real zero, both ends were observed — while `_seed_first_generation_window` called the identical clamp "the exact confusion CE058 exists to prevent". The second is reworded to say what it actually meant: the head was measured against the WRONG INSTANT, which is a different fault from the clamp. The clamp itself is untouched. Also registers the two findings this plan cut on evidence — A2-full (it retires neither lint rule it claimed to, and the new seam assertion guards the property at runtime) and C2's counter (CE064 removed the reachable cause) — each with the trigger that would reopen it, so the reasoning is not re-derived later. No executable line changed. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
Three changes that all serve the same end: one producer per published figure. `main_thread_tool_spans` and `subtract_tool_time` move out of `streaming/collector.py` into `timing.py`, the declared cycle-free home for timing rules. `reports_stats` was reaching across a layer into `streaming/` to get the span SELECTOR, which is the rule the collector measures all four buckets against; a report module importing from the capture layer to borrow it is the shape that ends with a second typed copy. `timing.py` gains a `coder_eval.models` import, verified cycle-free at runtime: importing models loads neither `timing` nor `streaming`. `TurnRecord` gains ONE field, `tool_union_ms`, written by the collector from the same span set the head and tail are measured against. It is the one bucket a dict consumer cannot cheaply reproduce — union arithmetic plus a sub-agent filter. `generation_total_ms` was considered and cut: the reconciliation entry exists so a consumer SUMS the message stream rather than reading a separate aggregate, and storing a generation total would create a value that can silently disagree with the stream `subtract_tool_time` has just rewritten. CE058 had to widen for it, and that is a deliverable rather than a detail: its `_TIMING_NAME` matched `duration_ms`, `[a-z_]*_duration_ms` and the `harness_*` pair, and `tool_union_ms` matched none of them — so `TurnRecord(tool_union_ms=0.0)` would have shipped outside the None-vs-0 guard every sibling bucket has, even though `TurnRecord` was already in the rule's constructor set. Naming the field `tool_union_duration_ms` to inherit the generic arm for free was rejected: the two fields beside it needed their own arm for the same reason, and one spelling across the buckets is worth two lines of regex. `_overhead_ms`'s `tool_spans` parameter is now required. Its fallback would have built a SECOND span set, which the comment at its only call site already said must never happen — the subtraction and the head/tail have to agree about which calls exist, or the buckets stop being disjoint. `reports_stats` prefers the stored value and falls back to deriving it, with `is not None` rather than truthiness: a stored `0.0` is a measurement (spans were recorded and occupied no measurable time) and must not be silently replaced by a re-derivation. All 34 goldens regenerated; every diff is exactly one added key, `null` where the fixture recorded no bounded span and scrubbed where it did. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
`_scrub.py` and `decompose_run.py` each carried their own sub-agent-id derivation, stamp parser and span builder — three copies of one rule with the typed original, agreeing only because someone kept checking. They agreed by luck once at a real cost: the collector filtered its GENERATIONS to the main thread and then passed EVERY command as a tool span, and nothing failed, because a child nests inside the parent Agent call whose interval the union already covers. Codex's recovered child tools carry the CHILD's clock, so the nesting was never guaranteed. Both now validate the raw dict into a `TurnRecord` and call the one typed selector. That costs NO new production code: `TurnRecord` declares no `model_config`, so pydantic's default `extra="ignore"` applies, and a raw `task.json` turn validates — measured on 2466 turns across 2248 files, 17 days and all six agent types, zero failures. Verified again here over 400 real records, still zero. They stay SENSORS rather than restatements. Each still builds its own span set and computes its own union; what is now shared is the selection and `union_ms`, and what is not is the bookkeeping around them, which is where every timing defect on this branch actually lived. On top of that each CROSS-CHECKS the stored `tool_union_ms` against what it independently computed, skipping when the field is absent — which is every record written before it existed. A disagreement is its own named breach in the live gate, and it exits non-zero independently of `--max-residual-pct`, because a finding that cannot fail the gate is prose. The corpus moves to `scripts/timing/corpus/` and is re-scrubbed to be model-valid. Two of its five records deliberately preserve defects the live code no longer has, and stale-by-design data under `tests/_fixtures/` invites the next reader to point a test at it and pin a fixed defect as expected behaviour; the README now says outright that no test may read the directory. The re-scrub restores what the original one had stripped below what the model requires — `user_input`, `agent_output` and each command's `timestamp`, as neutral placeholders, none of them a wall-clock magnitude. The script's table over the moved corpus is byte-identical to its pre-move output. Three fixture families had to become model-valid for the same reason, which is the visible cost of the sensors no longer accepting anything dict-shaped. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
…tion `reports_stats.turn_time_buckets` already said the rule in its own docstring — the evalboard, the markdown report and the HTML report must not each grow their own version — and had exactly one caller. It now has three, and none of the other two sums anything. The `run.json` row projection is where the markdown report's numbers come from. It cannot be otherwise: `task_results[*].iterations` is a deliberate 6-key projection with no `messages`, no `commands` and no `harness_*_ms`, so validating it into a `TurnRecord` there is impossible. The builder already has the `EvaluationResult` in scope, so it calls `turn_time_buckets` once and adds four task-level keys; `reports.py` reads four numbers with `.get()` and renders a dash for each key a `run.json` written before this change does not carry — which is every existing run directory. `build_task_event` emits four optional dimensions, each omitted rather than coalesced when unmeasured, mirroring `Score` verbatim. A dashboard averaging `StartupMs` with no filter would read a laundered zero as a harness that booted instantly, which is indistinguishable from a run predating the capture. `_format_ms` moves into `formatting.py` as `format_ms`, shared by both report renderers. Two renderers formatting the same bucket two ways is how one surface comes to print `0ms` where the other prints a dash — the None-vs-0 distinction thrown away at the last step, after the producer went to the trouble of making it. The Performance section's guard becomes `is not None`. `analysis.py` returns `None` for "nothing timed" and a float otherwise, so a genuine measured 0.0 average — every command resolving faster than the clock's resolution — suppressed the whole section rather than reporting it. On the evalboard, `sumHarnessOverhead` becomes `sumTurnBuckets` and gains the tool total; the task page prefers the stored sum and falls back to computing the union from the message stream for a legacy run. The two agree by construction now that `toolExecutionMs` applies the same bounded-spans-only policy as the Python selector, which is why Phase 3 had to land first. The Generation cell keeps computing from the stream on both sides and has no stored twin by design — the reconciliation entry exists so a consumer sums that stream. The mixed sourcing is deliberate and is commented as such on each side. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
`on_tool_use` read `state["time"]` and re-wrapped it as a dict twice, identically — once at the top and again immediately before closing the tool. `state` is bound once at the start of the function and nothing between the two rebinds or mutates it, so the second read produced the same value from the same source. The test that comes with it is the point, since the deletion is behaviour-preserving by construction and would pass either way: the two events it feeds carry DIFFERENT `time` payloads, so a close that took its `end` stamp from the wrong read would fail it. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
Three findings from the final multi-model review, all in the arithmetic the change moved rather than in what it added. The seam assertion's tolerance was one NANOSECOND expressed in milliseconds. The exposure that check is actually for is a third-party agent registered through the `coder_eval.plugins` SPI — and that is precisely the producer most likely to record microsecond-precision bounds while publishing a duration rounded to whole milliseconds, which the check would have rejected by 0.4 ms, crashing every one of its turns. A guard that kills legitimate producers is relocating a defect, not removing one. One millisecond is the coarsest unit a field named `_ms` can honestly be published in, and it still catches the defect class by three to six orders of magnitude: a reducer that narrowed a window by subtracting its own tool time is off by tens to thousands of milliseconds. The apportioning loop rounded every share but the last to six places while the last took the remainder. Rounding each earlier share UP can push the running total past the net, and the last member then receives a NEGATIVE duration. It needs a net well under a microsecond — a window almost entirely covered by tool execution — so it had never been seen, but a negative generation is an invariant break rather than a rounding artifact, and the remainder already prevents the drift the rounding was there for. `toolExecutionMs` derived its extent with `Math.min(...spans.map(…))`, which passes one ARGUMENT per span; a long enough trace throws RangeError and the whole task page fails to render. Folded instead, which is how the Python twin's generator `min`/`max` already behaves. Also states, where the code is rather than in a commit message, why the `raw_total <= 0` skip has to run BEFORE the assertion: `close_window` clamps a measured inversion to `0.0` while its bounds still say `completed_at < started_at`, so checking first would kill the turn on exactly the shape `decompose_turn` deliberately tolerates. A reviewer read that ordering as a bypass, which is a fair reading of code that did not say so. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
`scripts/timing/corpus/` is stale by design: two of its five records preserve defects the live code no longer has — claude-code reconciling at -481 ms, and a `0.0` head on two harnesses. Its README says so, and says that re-recording it after a change would destroy the only thing it is good for. The danger is that a test pointed at it looks entirely reasonable: a green assertion over real recorded numbers, quietly pinning a fixed defect as expected behaviour. Moving it out of `tests/_fixtures/` removed the invitation; this removes the possibility. Until now the rule lived only in prose, which is the shape this repo converts to a check. Three arms, because a guard on a directory that has moved guards nothing: the corpus still exists where the rule says, no test module references it, and the README still states the rule so the prose and the check cannot drift apart. Mutation-verified — a probe module naming the path fails it by name. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
…ndary The None-vs-0.0 contract this branch exists to enforce broke at exactly the seam it introduced. `toolExecutionMs` returns `number`, never null, so the new `storedToolMs ?? toolExecutionMs(mainThread)` fallback turned "no bounded span was recorded" into `0ms` — a measurement claim — while every Python surface rendered a dash for the same run. Three comments asserted the two sides "agree by construction", which was true of the bounded-spans FILTER and not of this. It is not a legacy-only case, which is what makes it worth a fix rather than a note. A turn that simply ran no tools produces the same empty span list, and so does one whose calls were all TIMED BUT UNBOUNDED — the historical-codex and out-of-tree `delegate-sdk` population this branch's own comments quantify at ~8 h. Claiming those took no time is the one thing certainly false about them. `measuredToolExecutionMs` is the missing layer, and it mirrors the Python split rather than inventing one: `union_ms` returns `0.0` for an empty span list because that is what a union of nothing is, and the shared corpus pins both sides on exactly that; the None decision sits one layer up, where `main_thread_tool_spans` returns a list and its caller turns an empty one into `None`. `toolExecutionMs` is therefore untouched and the corpus still pins it. The per-row EXEC cell moves to the same helper, replacing a `durationMs != null` guard that asked whether the harness TIMED anything rather than whether it BOUNDED anything. Separately, `decompose_run.py` checked its two new breach classes AFTER the no-gateable-turns arm, so a corpus whose turns were all under `--min-turn-ms` printed a real validation failure to stderr and exited 0 — the "measured nothing, reported success" shape that arm exists to refuse. Neither class is a residual question, so neither may depend on a turn being long enough to gate on. CI always passes `--max-residual-pct`, so it was not reachable there; the standalone invocation the script's own header documents is where it bit. `main()`'s exit code now has end-to-end tests, including the arm-order case directly. It had none: every other property of that script was asserted on its helpers, and the exit code is the only thing CI actually reads. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01LkF1Up5DfjWR7HsyFpVAZr
`on_user_message` reset the generation mark to `self.clock.now()`, so the
next window opened when the tool RESULT arrived instead of tiling from the
previous emission's close. Everything in between — SDK transport, CLI
processing, next-request dispatch — fell into no bucket at all, and the
four-bucket identity stopped closing.
The live stream delivers TWO user messages per tool call, and the mark was
reset on each, so the window opened at the LAST one. Traced on
`tasks/dataset_example.yaml`:
msg2 (issues the Write) closes 27.773889 -> 28.067824
user message #1 28.080804 <- mark reset here
user message #2 30.009645 <- and again, 1.93s later
msg3 window opened at 30.009645 (should be 28.067824)
1.94 s lost from an 11.7 s turn. CI's residual gate has been failing on
exactly these two rows (16.668% and 16.325% on the runner, 21-28% locally).
Same task after the fix: 0.02%, worst turn 4.5 ms — the known
`turn_start_time`-vs-`AgentStartEvent` baseline and nothing else.
The tool's own interval is not double-counted: it is a separate bucket and
`subtract_tool_time` clips the tool union out of every window it overlaps,
once, for all five harnesses. That central subtraction is precisely what
lets the reducer leave its mark alone — the same rule pi follows with
`gen_mark`, and the one pi was explicitly fixed for.
WHY THIS SURVIVED, which is worth more than the one-line fix. Three ways to
write a test for it cannot fail, and I wrote two of them before getting one
that does:
1. A tool-heavy shape. Three concurrent `sleep 3` calls make the tool
union absorb the interval; every live probe I ran read 0.05% and I
concluded the harness was healthy. The defect needs a FAST tool.
2. A single tool result. claude-code reconstructs `execution_started_at`
by subtracting the measured duration from the resolve instant, so with
one message the discarded interval and the tool's own span are the
SAME milliseconds — `subtract_tool_time` removes them either way and
the identity closes with or without the bug. This is why the existing
`_claude_turn` case passed throughout.
3. A duplicate tool RESULT as the second message. That re-resolves the
call and stretches the tool span over the very interval being probed.
`test_a_slow_tool_result_round_trip_is_not_lost` scripts the shape that
discriminates: a 20 ms tool, then a second user message carrying no tool
result 2 s later. Mutation-checked — restoring the reset fails that case by
exactly -2000 ms and leaves the other seven green, which is the production
situation reproduced in the suite.
No golden regeneration: `_scrub.py::SCRUB_KEYS` masks every timing value, so
the corpus cannot see this class of change. That is a known property of the
goldens, not an oversight, and it is the reason the ms-exact identity
contract exists alongside them.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01FpDo37ypvLjLiWXFsEkg6k
Unused since it landed in 5237eb4. `scripts/` sits outside the Makefile's LINT_PATHS — which this file's own docstring already notes — so ruff never looked at it and CodeQL was the first thing to say so, as a `py/unused-import` alert that turned the PR's CodeQL check red. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Mgy33fwSvD5dPx8qD2bXJe
CE058 form 4 fires on `if x.duration_ms is None: x.duration_ms = 0.0`: it keys on the `if` test naming a TIMING attribute. The live `_finalize_commands` defect matched only because it happened to spell the inner guard that way. The assignment sat inside an enclosing `if cmd.result_status is None:` block, and writing the literal under THAT guard instead — which reads just as naturally and books the identical lie — was invisible to all five forms. Verified by mutation: `cmd.duration_ms = 0.0` in that block passed all 626 lint tests. So the rule was one plausible refactor away from silent on the exact defect it was written for. A guard is evidence about a value only when the guard names the value; with no guard there is no evidence at all, which is strictly worse and must not be the case the rule misses. Form 6 is a plain assignment of a ZERO literal to a timing-named target, and the narrowing is the point. Under `is None` the guard PROVES the value was never measured, so form 4 rejects any invented number. A bare assignment proves nothing — `cmd.duration_ms = elapsed_ms` is how a real one is written and a literal 1234.0 is a plausible factory or replay — so only the placeholder zero is the tell. Same narrowing form 1 already makes on constructor keywords. Forms 4 and 6 overlap on the zero case, so form 4 registers what it flags and form 6 skips it. Ordering-safe rather than lucky: `visit_If` runs its check before `generic_visit` descends into the body. One defect, one violation — otherwise a `# noqa` silences half of it. `test_allows_a_guard_on_a_different_receiver` changed rather than being deleted. Its property — form 4 keys on the RECEIVER, so a guard about `a` must not vouch for `b` — is still real and now uses a non-zero literal to stay a form-4 test. The zero spelling gets its own case asserting form 6 claims it, because `b.duration_ms = 0.0` under a guard naming `a` is an ungrounded zero. Clean on the tree today: zero-literal assignments to a timing-named target across all of src/coder_eval/ = 0. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01Mgy33fwSvD5dPx8qD2bXJe
88e8dc4 to
bfec0dd
Compare

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