fix(timing): account for generation and tool time on every harness by uipreliga · Pull Request #164 · UiPath/coder_eval

uipreliga · 2026-09-11T02:53:10Z

Per-task wall clock, LLM generation time and tool-execution time were only
correct for one harness. Measured across 4 run.json + 46 task.json files:

harness	wall clock accounted for, before
claude-code	97%
codex	72%
antigravity	15%

Antigravity recorded no generation time at all — the reducer read
datetime.now() once per flush and passed it as both message bounds with a
hardcoded generation_duration_ms=0.0, so every task page showed 0ms of
generation and a 0% thinking/tool/text breakdown, for months, with nothing
failing. Codex discarded the millisecond timestamps its SDK already delivers
and published the SDK item's own duration_ms instead: 0.0 for 70 of 211
sampled commands, absent for 25 more, and no execution bounds at all, so no
Codex tool call could be placed on a timeline.

What changed

The contract. AssistantMessage.generation_duration_ms is now
float | None. None means never measured; 0.0 means measured and took
no measurable time. Every producer that used to conflate them is fixed —
including two the audit missed: Claude published a measured 0.0 for every
command force-closed without a tool result, and the simulator's trailing turn
reported 0s, halving avg_turn in the HTML report for every simulation task.

Generation time excludes tool execution. Four of five harnesses interleave
tool calls into a single generation window, so the span between a message's own
bounds legitimately contains time the model did not spend generating. All four
now subtract the union of the closed tool intervals, clipped to the window,
through one shared helper. The union matters: these harnesses run tools
concurrently, and summing durations over-subtracts by exactly the overlap —
four concurrent 400ms calls inside a 1000ms window total 1600ms and clamp
generation back to the 0.0 this PR exists to remove.

Attribution. A mixed-kind emission's generation time and output tokens are
apportioned by one content-size weight vector. Previously all the time went to
the first block kind a priority chain tested (98.5% thinking on codex, 99.8% on
delegate), and the same output tokens were counted twice — once to thinking,
once to the tool — for 93% of Delegate's emissions.

The page says what it cannot account for. A new Unaccounted cell shows
wall clock minus generation minus tool execution, so the figures are displayed
against what they must reconcile to rather than each being individually
well-formed. The run-list Duration column now counts only rows that executed:
a codex nightly rendered "1300 tasks · 15h 29m" describing 397 tasks.

Guardrails

CE058 — an unknown timing value may not become a numeric literal. Five
syntactic forms, one id, including the if x is None: x = 0.0 guard where a
live instance was hiding and the model_copy(update={...}) dict a
keyword-only rule cannot see.
CE059 — an AssistantMessage may not take one clock read as both bounds.
It exempts a call that passes generation_duration_ms=None: saying "no window
was measurable" in the field built to say it is not a claim two stamps have to
support.
assert_timing_captured — a replay-based golden sensor. An AST rule cannot
see that an SDK returned 0.0; this runs the real reducer and asserts a
resolved command carries both bounds and a duration, and that a turn which
streamed a generation reports a positive window whose stamps actually span it.
Golden coverage for every built-in harness. antigravity, opencode and
pi had no recorded stream at all — the three whose timing was worst. The
coverage test derives from AgentKind with an allowlist of exclusions, so the
next harness cannot ship timing-blind.

Numbers that move (correct, not regressions)

The cost simulator's thinking projection, for Codex and Delegate. Both a
smaller thinkingMs and a no-longer-double-counted thinkingOutputTokens
feed it.
avg_command_time_ms. A Claude command force-closed without a result now
leaves both sides of the average instead of dragging it toward zero; and on
Codex, fileChange and generic tool calls carry a duration they previously
lacked, so the figure now covers every tool call rather than shell commands
alone.
Codex duration_ms changed meaning — the item's lifecycle (queueing and
approval included) rather than the SDK's narrower command-run figure, which it
deliberately overrides.

docs/agents/HARNESS_PARITY.md gains a ## Timing capture section covering all
five harnesses, and names the two divergences left open (Antigravity's
orphan-poll wait, Delegate's missing bounds — both out of tree or deliberately
deferred).

Verification

make verify — 5209 passed, coverage 92.70%
make evalboard-verify — 724 passed, tsc --noEmit + next build clean
make lint — 555 (CE058/CE059 included)
No task or experiment YAML changed; no new model, criterion, agent or config
field, so no registry, merge-layer or -D surface is touched.

Reviewed phase by phase, then once across the whole diff. That last pass is what
caught OpenCode and Pi carrying the identical double-count — which no phase
covered and an earlier draft of the parity table wrongly denied.

🤖 Generated with Claude Code

github-actions · 2026-09-11T02:54:19Z

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

Code Review in Progress

Todo List

Read .github/code_review.md for review standards
Review CLAUDE.md for project conventions
Analyze the full diff (git diff origin/main...HEAD)
Review key modified files with full context
Check cross-file consistency
Analyze what's missing
Provide structured review feedback

Starting code review...

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>

bai-uipath

Approve both. The instrumentation is solid: the four-bucket identity closed to ~1ms on a live concurrent-tool task I ran against the stacked branch. The summary strip is the one thing worth a pass before merge.

UI improvements

The strip flattens two levels into one row. Five buckets that sum to the task wall clock sit beside a three-way split of one of them, which sums to Generation instead. Moving the per-kind split onto its own line would separate them.
"tool" means two unrelated things in the same row. Time spent writing tool arguments, and time tools spent running. Renaming the sub-cell to "tool args" fixes it.
Unaccounted flips sign when tools overlap. It subtracts the sum of per-tool durations where the identity uses the union, so concurrent tools get counted twice. On a task with two concurrent sleeps it rendered -615ms amber where the honest answer is +2.5s of sandbox setup and grading.
The execution bounds that needs are already in task.json, and already in scope where the per-tool duration is set, so it should be a small change.

Minor, fix if you agree

No parity test covers the TS decomposition against the Python one. Every current TS test asserts against the sum, so the suite agrees with the bug above.
opencode and pi don't subtract still-open tools the way antigravity and codex do, though the argument applies to them equally now their windows tile.
The collector's head/tail measurement doesn't exclude sub-agent messages, unlike its two sibling call sites.
Delegate in coder_eval_uipath keeps both defects this removes, while sitting outside the new rules' scope.
#165 hasn't run the gating workflows, since its base is a feature branch. Verify, lint, pyright and the evalboard suite were all green locally against its head.

Two reporting fixes to the same surface: time figures that are each well-formed but never say what they should reconcile to. A. The task page's timeline strip gains an `Unaccounted` cell — task wall clock minus generation minus tool execution — so a harness that stops reporting one of them is visible on the page instead of reading as fast. Tinted red at or above a 25% residual. A negative residual (parallel tool calls, or a tool closing inside a generation window) renders signed and untinted rather than clamped: an overlap is a signal, not unreported time. `fmtMs` is now sign-aware so that reads as `-1.2s`, not `-1200ms`. B. The run list's Duration column now counts only what ran. Mature-skipped rows are carried-forward passes with no duration, so summing over them divides real seconds by a task count that never executed — a codex nightly rendered "1300 tasks · 15h 29m" describing 397 tasks. The two duplicated duration derivations in runs.ts collapse into one exported `deriveRunDuration`, which excludes those rows from both the sum and the `every()` completeness guard, and reports `executedTasks` alongside. Both run tables now name that count next to the duration when the two differ. `tasksExecuted` is carried through `RunSummary` / `RunOverview` / `ScopedRun` / `RunListingRow` rather than recomputed per consumer: the whole-run count comes from the same helper that produced the duration (over run.json's task_results), while `overview.tasks` drops rows with no task_id, so a recount could disagree with the duration's own denominator. A run with no mature skips renders exactly as before. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

`AssistantMessage.generation_duration_ms` was a required `float`, so a harness with no measurable window had to invent one — and every producer that did wrote `0.0`, which reads downstream as a real, instant generation. It is now `float | None` with `default=None`, aligning it with `UserMessage.generation_duration_ms` in the same module. Every live "unknown became zero" producer is fixed: - Codex's rollout rebuild and both sub-agent syntheses record `None` — Turn items carry no per-item timestamps and a sub-agent generation arrives as a tool result, so no window was ever measurable. - Claude's sub-agent terminal message, same reason. - Claude's `_finalize_commands` no longer coerces an orphaned command's `duration_ms` to `0.0`. Its `result_status` is already "unknown"; unknown status and unknown duration are the same fact. The command now leaves BOTH sides of `avg_command_time_ms` instead of dragging the average toward zero. - `analysis.py`'s two slowest-command coalescings are gone: the duration travels alongside its command as a pair, so it stays a float and an untimed command simply is not ranked. `avg_command_time_ms` reports `None` when nothing was timed rather than "0ms average". - The simulator's trailing standalone turn passes a real `duration_seconds`. It defaulted to 0.0 with no caller supplying it, which halved `avg_turn` in the HTML report for every simulation task. Two lint rules make the class permanently detectable. CE058: an unknown timing value may not become a numeric literal — five syntactic forms, one id, including the `if x is None: x = 0.0` guard where the live Claude instance was hiding and the `model_copy(update={...})` dict a keyword-only rule cannot see. CE059: an `AssistantMessage` may not take one clock read as both bounds; it exempts a call that passes `generation_duration_ms=None`, because saying "no window was measurable" in the field built to say it is not a claim the two stamps have to support. Antigravity's flush keeps its `0.0` under both noqas for one more commit; the next one replaces it with a real measured window and deletes them. Golden snapshots move in exactly four places, all `"<scrubbed>" -> null`. No token bucket moves; `assert_reconciliation` passes unchanged. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

The reducer read `datetime.now()` once per flush and passed it as BOTH `started_at` and `completed_at`, with a hardcoded `generation_duration_ms=0.0`. Every Antigravity row therefore reported no generation time at all: the task page's Generation cell read 0ms and its thinking/tool/text breakdown rendered 0%, for months, with nothing failing. 15% of wall clock was accounted for, against 97% on claude-code. The window is now marked at the turn's start (both stamps from one instant, captured in `communicate()`) and advanced by each flush that actually emits a message — never by the early-returning no-op flush, whose guard precedes every clock read. Tool execution that closes inside a window is subtracted, because this harness interleaves tool calls into one generation: the Step for the tool arrives and only a later `usage_metadata` Step cuts the message. The subtraction is the UNION of the closed intervals, clipped to the window — not the sum of their durations. Antigravity resolves several calls from one Step and backgrounds anything over ten seconds, so the intervals overlap; summing them over-subtracts by exactly the overlap, and four concurrent 400ms calls inside a 1000ms window would total 1600ms and clamp the result back to the 0.0 this commit exists to remove. Clipping is the other half: a tool that opened before the window only spent part of its life inside it. Do not "simplify" the subtraction to resetting the mark on tool end. A harness-local Read can close 8ms after it opens while 6.4s of model time separates the two flushes around it (measured: 2026-09-09_04-18-50/skill-rpa-uia-google-search), so a reset reports 8ms and loses the 6.4s. A controlled-clock test pins this. With the union clipped to the window, `max(0.0, ...)` is now only a clock-jitter guard — the span is monotonic while the intervals are wall — and a negative result logs at debug, since a clamped 0.0 is otherwise indistinguishable from a real instant generation. Still deliberately unaccounted (audit P2-1): time spent waiting on a tool that is STILL open contributes nothing to any subtraction, so an orphan-poll turn's window includes the wait. Token buckets are untouched and `assert_reconciliation` passes unchanged. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

…g them The Codex SDK reports `started_at_ms` and `completed_at_ms` on every item notification. The agent read the start (for message windows) and threw both away for telemetry, publishing the SDK item's own `duration_ms` instead: `0.0` for 70 of 211 commands in one nightly, absent for 25 more, and no `execution_started_at` / `execution_completed_at` at all, so no Codex tool call could be placed on a timeline. One `_item_timing` helper now resolves timing for all three telemetry builders, so a command, a file change and an MCP call cannot disagree. Both raw stamps are checked BEFORE conversion — `_ms_to_dt(None)` is `datetime.now()`, so pairing a real stamp with a missing one would fabricate an interval running to the present moment. Without stamps the SDK's own duration is used only when it reports something: a `0` there is an unreported duration, not an instant command. `timestamp` becomes the tool's own start rather than `datetime.now()` at completion, which placed every call after its own execution; nothing orders on it (`collector._ordered_commands` sorts on `sequence_number`). Orphans keep their known start — the SDK marks `started_at_ms` required, so it IS knowable — while completion and duration stay None. Codex was the only harness whose unresolved calls could not be placed on a timeline. Publishing those bounds exposed a double-count the plan had assumed away. `_flush_message`'s generation window is seeded from the first item's start and extended to the LAST item's completion, so any generation containing a tool call already contains that tool's execution: a tool-only emission reported 250ms of "generation" beside a 250ms `echo hi`, and a collab scenario put 1790ms of generation-plus-tool inside a 900ms window. Left alone, the task page's new Unaccounted cell would have read -98% on every Codex row. The window now subtracts the union of the closed tool intervals clipped to it — the same treatment, and now the same shared helper (`agents/_timing.py::busy_ms`, moved out of the Antigravity agent), as the previous commit. Generation + tool execution equals the window exactly. The golden snapshots cannot catch a swapped stamp — the scrubber masks every non-null timestamp, so they assert presence, not value — so the wiring has its own end-to-end test that reads the values back. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

The message reducer assumed one block kind per emission, which is a Claude CLI property. Everywhere else it breaks, and it breaks twice. TIME: all of a raw's generationMs went to the first kind the priority chain tested. Measured 98.5% thinking on codex and 99.8% on delegate, where 93% of emissions carry more than one kind. OUTPUT: the first pass handed a raw's ENTIRE outputTokens to its tool blocks, and flush() then added the same whole figure to thinkingOutSum whenever the raw also carried a thinking block. The same tokens were counted twice for 93% of Delegate's emissions, inflating the cost simulator's thinking lever. Both are now apportioned by ONE content-size weight vector per raw, computed once and stored, so the two can never disagree. Weights are content size and depend on no output figure: deriving thinking as `outputTokens - toolWeight` looks natural and is always 0 when a tool is present (150 of 174 sampled emissions), which would produce the exact mirror of the bug — 100% tool, 0% thinking. `splitByWeight` puts `tool` first so it is never the remainder kind. The tool share is also computed in the first pass, and if one site rounded while the other took the remainder they disagreed at a tie and the parts over-summed by a token — the same double-count, one decimal down. A rounding sweep pins it. Single-kind emissions take an explicit path and are byte-identical to before, including per-tool figures; claude-code pages must not move. A mixed emission with nothing sizeable to weigh by lands in a new `mixedGenMs`, rendered as "unsplit" — the timeline legend already uses MIXED for "multiple block types", which is the case this cell is normally empty for. Per-kind percentages all divide by the whole so they sum to 100%; only the red thinking tint uses the attributable part. Codex's `_flush_message` no longer concentrates a generation's whole duration on its first sub-message. It splits by output-token share — a real per-spec measurement, unlike the evalboard's content-size proxy — while input and cache tokens stay on the first sub-message, because those are per-call billing figures and were never the generation's to divide. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

… sensor Only claude-code and codex had golden coverage, so the three harnesses whose timing was worst had no recorded stream at all. Antigravity, OpenCode and Pi now each have one, with the `_step` / `_FakeProcess` / event-builder helpers MOVED out of the agent test modules and imported back rather than copied — those modules' own tests are unchanged. `assert_timing_captured` is the sensor an AST rule cannot be. It replays the real reducer and asserts what static analysis cannot see: that a resolved command carries both execution bounds and a duration, and that a turn which streamed a generation reports a positive window somewhere. It runs on the UNSCRUBBED dump, because the scrubber masks values while preserving None and present-vs-absent is the whole assertion. It is a scenario-level floor rather than a per-entry rule, and that is forced by the snapshots: `claude_d_subagent_terminal` holds two content-bearing messages of which exactly one is legitimately None, so no flag could express "this one but not that one". The exemptions live in one `NO_GENERATION_WINDOW` set beside the coverage mapping, not as a field on five dissimilar dataclasses, and each names its reason. Strict is the default: a new scenario is asserted to have a window until someone says otherwise. Two of those exemptions were not in the plan's table, which was computed from snapshots where the value is scrubbed and so could not see them: `claude_i_in_loop_deadline_break` drives a scripted constant clock, and two Codex scenarios have zero-width windows by stream shape. A third candidate was fixed instead of exempted — `codex_b_command_execution` gained a reply, so it carries real generation content rather than being tool-only. Fix the fixture before weakening the sensor. Coverage is derived from `AgentKind`, excluding only NONE (agentless) and UNKNOWN (a sentinel), each with its reason — an allowlist of exclusions, so a new member fails until someone decides. The negative cases run the real check against a mutated copy rather than restating its condition. `HARNESS_PARITY.md` gains a `## Timing capture` section: where each field comes from per harness, why `generation_duration_ms` is model-generation time rather than the span between its own bounds, why Codex leaves `generation_completed_at` unset, and the two divergences left open — Antigravity's orphan-poll wait and Delegate's missing bounds — both also recorded in the deferred-work file. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

The cross-cutting review caught that the change stopped at three of five harnesses while the parity table it adds claimed all five. OpenCode and Pi carry the identical double-count removed from Codex: both mark a generation window at `step_start` / `turn_start` and close it at `step_finish` / `turn_end`, and every tool call runs INSIDE that window while also publishing its own measured duration. Replayed through the real reducers, a 1s tool inside one step produced `Unaccounted: -99%` — in the very cell added to catch this. Both now subtract the same union of closed tool intervals, via the same `busy_ms`, making it four call sites for one helper. The parity table and its prose say four harnesses interleave, not two, and name claude-code as the one that does not need the subtraction (it marks the end of the previous SDK event, so tool time falls between windows rather than inside one). The Unaccounted cell also double-counted every sub-agent on every harness. A sub-agent's emissions carry a `parentToolUseId` and its spawning Agent call's duration already spans the whole sub-agent run, so summing over all messages counted its generation twice — a 140s claude-code task with a 120s Agent call containing 90s of sub-agent generation reported -57%. The strip now sums the main thread only. A negative residual gets its own amber tint: overlap is a different fact from a large positive residual, and identical grey hid it. `scopeRunTasks` was a third duration derivation that phase 1 missed, so the Duration column used one definition unfiltered and another with a tag filter active — and a single mature-skipped row with no duration flipped the all-present guard, rendering "—" for a run whose executed rows were all timed. `assert_timing_captured` now also requires the recorded bounds to span the window it reports. Two harnesses take the duration from a monotonic clock and the bounds from the wall clock, so a reducer can publish a healthy duration beside two stamps that collapsed — which is exactly the case CE059's docstring claims this sensor covers and, until now, it did not. The cost simulator picked its primary model by generation time, under a comment asserting that "generation time is recorded for every emission" — a premise this change invalidated. With every window null it weighed all models at zero and the first one encountered won, so a Haiku sub-agent listed before the main Opus message priced the whole task at Haiku rates. It now falls back to output tokens, then to an equal vote. CE058 ships five syntactic forms; CLAUDE.md and the rule's own docstring still said four, omitting the `model_copy(update={...})` dict — the shape the Antigravity DONE path actually writes through. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

…llow-up Surfaced by the timing-capture final review but out of that change's scope (token accounting was explicitly excluded, and the validator is untouched by it). A real bug rather than a guardrail candidate: a legacy record's full-prompt input_tokens is adopted as the UNCACHED slice, so the computed total adds the cache buckets a second time. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

…ity double-counting an open tool Live runs of tasks/hello_date across all five harnesses — the invariant no unit test can prove against a real SDK — found two defects. Codex published `generation_duration_ms=0.0` on a message carrying 98 output tokens, reproducibly. Its window was seeded from the item's EXECUTION stamp, so a tool-only emission's window equalled the tool's own interval and the subtraction clamped to zero, while the 2694 ms that generated the item sat in the preceding gap attributed to nothing. Only 15.8% of a 17 s turn was accounted for, which is also why clause 3 passed there: it under-measured too heavily to breach anything. Windows now tile from the previous flush's end, kept in the SDK's own clock — seeding the mark from time.time() would mix our clock with the SDK's inside a single subtraction. Three live runs: 64-86%. Antigravity broke the branch's headline invariant. Sum(generation) + Sum(command) exceeded the turn's own duration_seconds by 0.26 ms, because a tool still OPEN at flush time had its already-elapsed portion published as generation and then counted again as its duration_ms. These contiguous windows have no slack to absorb that: 5 pre-fix runs ranged -0.26 to +8.69 ms out of ~12 s, so it was a coin flip rather than a rounding artifact. Open calls are now subtracted too, bounded at the flush; when one later closes, the DONE path hands its full interval to the next window, where busy_ms clips it to the post-flush remainder, so nothing is subtracted twice. 12 post-fix runs are all positive (min +0.23 ms). This replaces the comment deferring the case to audit P2-1. Codex gets the same open-tool treatment, since tiling is what makes that double-count reachable there. Both new tests fail without their fix (Codex 0.0 vs 1900.0; Antigravity 300.0 vs 100.0). Final sweep: 5/5 harnesses pass all three clauses. Known and deliberately not papered over: Codex's remaining 14-36% is the latency before the SDK's first item stamp, which the stream gives no way to measure, and Antigravity's margin stays thin by construction because its windows tile ~100% of the turn. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

OpenCode bounded each window at `step_start`/`step_finish`, but the CLI announces a step only once it is already producing one, so the model time that PRODUCED the step landed in the gap before it and was attributed to nothing. Measured on tasks/hello_date with a live claude-haiku-4.5: gaps of 857 ms and 851 ms carrying no tool at all (the Write inside them took 7 ms). Same defect and same fix as the Codex half of 237437b — a `gen_mark` carrying the previous step's finish. The first window deliberately does NOT tile: everything before the first `step_start` is CLI process spawn, and folding it in would report Node's boot as model generation. Four live runs, before -> after: accounted 33.9% -> 57.9% inter-message gaps 1788 ms -> 0 ms That is the whole of the gap bucket, and it is all that this change claims. The remaining 42% is one bucket, `head` (3376 ms of spawn + time-to-first- token), which is real wall time that is neither model nor tool and has no home in a TurnRecord that carries only those two. So OpenCode stays above the evalboard's 25% Unaccounted threshold on a short task; closing that needs the harness-overhead bucket, not a wider window. Noted so the next reader does not mistake a partial recovery for the finished job. All three clauses still hold (headroom 2.7-5.0 s across the four runs), and both new tests fail without the fix (200.0 vs 1000.0). Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

Review feedback on #164. The task page's Unaccounted residual subtracted the SUM of the per-tool durations where the identity uses their UNION, so two concurrent tools were counted twice and the cell went negative: -615ms amber on a task with two concurrent sleeps whose honest residual was +2.5s of sandbox setup and grading. `CommandTelemetry` already records `execution_started_at` / `execution_completed_at`, and the evalboard already had them in scope where it sets `durationMs`, so the fix is to carry them onto `MessageToolUse` and union the intervals. A call the harness timed but did not bound still contributes its own duration, so no run loses tool time. `busyMs` is the TypeScript twin of the harness's `busy_ms`; the two answer the same question about the same task.json, so neither owns the numbers — `tests/_fixtures/timing_union_cases.json` does, and both suites replay it. The summary strip flattened two levels into one row: five buckets that sum to the task's wall clock, beside a three-way split of one of them that sums to Generation. The split now has its own row under a `Generation split` label, and its `tool` cell is `tool args` — time the model spent WRITING a call, next to a `Tool exec` cell that is time the tool spent RUNNING. The bare word named both. OpenCode and Pi now subtract a still-open tool bounded at the window end, as Antigravity and Codex already do. The argument applies to them equally now that their windows tile: without it the part of a straddling call that ran before the boundary is published as generation while the call's own `duration_ms` counts it again. Also: the three test modules CodeQL flagged imported their agent module with both `import` and `from ... import`; the local imports are hoisted. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

uipreliga · 2026-09-12T00:23:36Z

Thanks — every point landed. The five for this PR are in 7483b67f (which also rebases the branch onto main); the sixth is on the #165 branch.

The strip

Unaccounted flips sign when tools overlap. Confirmed and fixed. You were right that the bounds were already in reach: CommandTelemetry.execution_started_at / execution_completed_at are in task.json, and the evalboard already had the CommandEntry in scope where it sets durationMs. They now travel onto MessageToolUse as execStartMs / execEndMs, and the cell unions the intervals instead of summing durations. A call the harness timed but did not bound still contributes its own durationMs, so no run silently loses tool time to the change.

Two levels in one row. The per-kind split moved to its own row under a Generation split label. The top row's Generation + Tool exec + Unaccounted sum to the wall clock; the bottom row sums to Generation. The caveat about apportionment moved with the split, since it qualifies that and not the measured total above it.

"tool" naming. Now tool args, one row below Tool exec. The bare word did name both.

Minor

No parity test. Added, and pointed at the root of the divergence rather than at the rendered cell: busyMs (TS) and busy_ms (Python) answer the same question about the same task.json, so neither owns the numbers — tests/_fixtures/timing_union_cases.json does, and both suites replay all 14 cases. The Python half also fails if the TS half stops reading the file, so a corpus only one side replays can't survive. On top of that, toolExecutionMs has its own cases for the concurrent, sequential, cross-message, unbounded-fallback and never-timed shapes.

One implementation note: the helpers live in evalboard/lib/timing.ts, not runs.ts. runs.ts reads node:fs, so a client component importing a value from it fails the Next.js build — only types may cross that boundary.

OpenCode and Pi don't subtract still-open tools. Fixed both, mirroring Antigravity and Codex. Agreed the argument applies equally now their windows tile: without it the part of a straddling call that ran before the boundary is published as generation while the call's own duration_ms counts it again.

The collector's head/tail doesn't exclude sub-agent messages. Fixed on the #165 branch — _overhead_ms now filters parent_tool_use_id is None, which is the rule codex_agent._token_usage_from_messages and scripts/timing/decompose_run.py already apply. It matters in both directions: the identity sums generation over the main thread only, so bracketing the span with a sub-agent message shrinks the head or the tail by time no bucket then claims, and Codex's recovered child messages carry the child's clock. Mutation-verified — dropping the filter fails both new cases. It'll appear on that branch when I push its rebase onto the new base.

Not fixed

Delegate in coder_eval_uipath. Acknowledged, and left alone: it's a separate repo, so it needs its own PR. Worth noting the exposure is real — it sits outside CE058/CE059's scope, so nothing will catch a reintroduction there either.

#165 hasn't run the gating workflows. Still true while its base is a feature branch. GitHub retargets it to main when this merges, at which point they run for real.

Also in this push

The three CodeQL alerts (a module imported with both import and from … import in the agent test modules) are cleared — the local imports are hoisted.

Verification

make verify — 5239 passed, 92.71% coverage
make lint — 555
evalboard — tsc clean, 749 tests, next build

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>

The module docstring named Antigravity and Codex as the only harnesses that interleave tool execution into a generation window. That stopped being true in the same release: #164 gave OpenCode and Pi tiled windows (so a call open at a boundary runs inside two of them), and this branch gives claude-code tool subtraction. All five now subtract, and all five subtract the union. Also names the TypeScript twin and the corpus that holds the two in step, which the docstring did not mention at all. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

uipreliga requested review from CarlesUIPath, akshaylive, bai-uipath and tmatup as code owners September 11, 2026 02:53

github-advanced-security Bot found potential problems Sep 11, 2026

View reviewed changes

Comment thread tests/test_antigravity_agent.py Fixed

Comment thread tests/test_opencode_agent.py Fixed

Comment thread tests/test_pi_agent.py Fixed

github-advanced-security Bot found potential problems Sep 11, 2026

View reviewed changes

Comment thread tests/test_opencode_agent.py Fixed

uipreliga mentioned this pull request Sep 11, 2026

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

Open

bai-uipath approved these changes Sep 11, 2026

View reviewed changes

uipreliga and others added 11 commits September 11, 2026 17:13

uipreliga force-pushed the fix/timing-capture-and-reporting branch from d809c93 to 7483b67 Compare September 12, 2026 00:17

uipreliga merged commit 87102a3 into main Sep 12, 2026
15 checks passed

uipreliga deleted the fix/timing-capture-and-reporting branch September 12, 2026 00:27

Navigation Menu

Uh oh!

fix(timing): account for generation and tool time on every harness - #164

fix(timing): account for generation and tool time on every harness#164
uipreliga merged 11 commits into
mainfrom
fix/timing-capture-and-reporting

uipreliga commented Sep 11, 2026

Uh oh!

github-actions Bot commented Sep 11, 2026 •

edited

Loading

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

bai-uipath left a comment

Uh oh!

uipreliga commented Sep 12, 2026

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

Uh oh!

Conversation

uipreliga commented Sep 11, 2026

What changed

Guardrails

Numbers that move (correct, not regressions)

Verification

Uh oh!

github-actions Bot commented Sep 11, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Code Review in Progress

Todo List

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

bai-uipath left a comment

Choose a reason for hiding this comment

UI improvements

Minor, fix if you agree

Uh oh!

uipreliga commented Sep 12, 2026

The strip

Minor

Not fixed

Also in this push

Verification

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

github-actions Bot commented Sep 11, 2026 •

edited

Loading