Skip to content

fix: count each API response once in speed and token metrics - #622

Open
iy88 wants to merge 2 commits into
sirmalloc:mainfrom
iy88:fix/speed-metrics-duplicate-usage
Open

iy88 wants to merge 2 commits into
sirmalloc:mainfrom
iy88:fix/speed-metrics-duplicate-usage

Conversation

@iy88

@iy88 iy88 commented Sep 29, 2026

Copy link
Copy Markdown

Problem

Claude Code logs a single assistant response as one JSONL record per content
block
(thinking / text / tool_use). All of those records share a
message.id, and each repeats that response's usage. Because the records are
written after the response settles, every one already carries the final usage
and the final stop_reason.

Both metric paths treated a record as a request, so each response was counted
once per block.

Measured over 42 real session transcripts:

main transcript over-count
speed: outputTokens 2.47x
tokens: outputTokens 2.79x
tokens: inputTokens 2.90x
tokens: cachedTokens 2.53x

Reproduced end-to-end with a real status line (39 MB session, 713 records / 311
responses):

before  Out: 408.2 t/s  |  Out: 10.1k  |  In:  328.8k
after   Out: 154.7 t/s  |  Out:  3.8k  |  In:   88.1k

Note README.md has promised the fixed behaviour since v2.2.9 — "Streaming
duplicate JSONL entries are deduped so token widgets do not overcount live
Claude Code output"
— but the existing guard only skips records whose
stop_reason is null, and no such record exists in a main transcript (4474 of
4477 carry the final truthy value). This change makes that promise hold.

Fix

Count a message.id once, from its last record, which is the one holding the
response's final usage. Verified on the corpus: in 2823 of 2823 multi-record
groups the last record carries the group's maximum output tokens.

  • speed (buildSpeedMetrics): the token sum now runs over a set reduced to
    one request per message id.
  • tokens (accumulateTokenMetricEntry): a later record of the same message id
    replaces that id's earlier share instead of adding to it.

Three deliberate non-changes:

  • The time denominator is untouched. Every record still contributes its
    [lastUserTimestamp → recordTimestamp] interval and mergeIntervals unions
    them. Verified across 82 metric sets (41 sessions × {main, subagents} ×
    {sessionAverage, 60/300/900s windows}): 0 duration differences.
  • contextLength and the mostRecent* / post-compaction tracking are unchanged
    (they are max-by-timestamp, not sums) — 0 differences on the corpus.
  • Records without a message.id cannot be grouped and keep the previous
    one-record-per-request behaviour, so older transcripts are unaffected.

SpeedMetrics.requestCount now counts distinct responses rather than records; it
has no non-test consumer.

Tests

Nine tests added; both fixture helpers gained an optional id field (omitting it
leaves existing fixtures byte-identical, so the 33 pre-existing cases in that file
behave identically).

Eight of the nine fail on main; the ninth pins the invariant that the
per-message-id map is reset together with the totals it describes (a build with a
stale map fails exactly that test and produces negative totals):

main:  34 pass, 8 fail
fix:   42 pass, 0 fail

Full suite 2367 pass / 0 fail. bun run lint and bun run build clean.

…ent blocks

A response is logged as one record per content block (thinking / text /
tool_use) sharing a message id, so summing usage over every record counted one
response once per block. Main transcripts repeat the same usage on each record;
subagent transcripts repeat the input and zero the output until it settles.
Across 41 real sessions this inflated output tokens 2.47x and input tokens
2.92x, over-reporting throughput by the same factor (408.2 t/s against a true
154.7 t/s on a 39 MB session).

Count a message id's usage once, from its last record, which is the one
carrying the response's final usage in both shapes. Earlier records keep
contributing their intervals, so the active duration is unchanged. requestCount
now counts responses rather than records.

Records without a message id cannot be grouped and keep the previous
one-record-per-request behaviour, so older transcripts are unaffected.

The token widgets share this duplication through collectTokenMetricRecord;
left for a separate change.
The token metrics carried the same duplication as the speed metrics: a response
is logged once per content block with its usage repeated on every record, and
collectTokenMetricRecord accumulated each one.

Its stop_reason guard is meant to skip intermediate streaming entries, but those
do not exist in main transcripts - Claude Code writes the records after the
response settled, so 4474 of 4477 records already carry the final truthy
stop_reason and the guard never fires. README.md has promised the deduped result
since v2.2.9 ("Streaming duplicate JSONL entries are deduped so token widgets do
not overcount").

Count a message id once instead, replacing an earlier record's share when a later
one arrives, since the record written last holds the response's final usage. That
map is reset together with the totals it describes, so no share can outlive them.
Entries without a message id keep the previous behaviour.

Across the 42 main transcripts this removes 2.79x of output tokens, 2.90x of
input tokens and 2.53x of cached tokens, while contextLength is untouched.
whycantfindaname pushed a commit to whycantfindaname/ccstatusline that referenced this pull request Oct 1, 2026
Merged from the jason/beta4-local-fixes Trellis build (compat-repair base):
bounded stdin reads in shared hooks (sirmalloc#590), research dispatch may write the
task research dir (sirmalloc#634), scoped archive commits (sirmalloc#622, sirmalloc#630), list filter
traversal (sirmalloc#631), remove-subtask link check (sirmalloc#632), hooks.local.json ignore
(sirmalloc#633).
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant