Repository navigation
Speed widgets (output/input/total-speed) over-report ~3x: per-content-block JSONL entries are summed without dedup #643
Description
Summary
The speed widgets (output-speed, input-speed, total-speed) over-report by roughly 3x. The speed collector in src/utils/jsonl-metrics.ts (collectSpeedMetricRecord) pushes one request per usage-bearing assistant entry, but Claude Code writes one JSONL entry per content block (thinking, text, each tool_use), all sharing the same message.id and the same usage. Every block therefore adds the whole response's output_tokens again.
This is the same root cause as #549, but in a separate code path: the token widgets at least have the stop_reason filter, while the speed path has no de-duplication at all, so a fix scoped to the token-summing path would leave the speed widgets inflated.
Environment
- ccstatusline 2.2.30 (latest on npm)
- Claude Code 2.1.288, Windows 11
Measurement (one session)
| assistant entries with usage | unique message.id |
summed output_tokens |
duration (union of intervals) | Out | |
|---|---|---|---|---|---|
| ccstatusline today | 423 | 167 | 615,503 | 2,094 s | 294 t/s |
deduped by message.id |
167 | 167 | 189,141 | 2,094 s | 90 t/s |
For comparison, timing the model's streamed responses directly inside Claude Code during the same session gave ~86–105 t/s, which matches the deduped figure.
All 163 messages I inspected had byte-identical output_tokens on every entry of the same id (and a non-null stop_reason on each), e.g.:
message …Dk5PWQc thinking:2573 thinking:2573 tool_use:2573 -> counted as 7,719 output tokens
message …NRssrkb thinking:344 text:344 tool_use:344 -> counted as 1,032
Suggested fix
De-duplicate by message.id inside the speed collector: keep one request per id with the max token counts, widen its interval to cover all of the id's entries, and keep the latest timestamp (used for the windowed metrics).
// createSpeedMetricCollector(): add `requestsByMessageId: new Map<string, SpeedRequest>()`
const usage = parseUsageTokens(data.message.usage);
// Claude Code writes one transcript row per content block (thinking / text / tool_use),
// each carrying the whole response's usage: count each message.id once.
const messageId = typeof data.message.id === 'string' && data.message.id !== '' ? data.message.id : null;
const existing = messageId === null ? undefined : state.requestsByMessageId.get(messageId);
if (existing) {
existing.inputTokens = Math.max(existing.inputTokens, usage.input);
existing.outputTokens = Math.max(existing.outputTokens, usage.output);
if (timestampMs !== null && (existing.assistantTimestampMs === null || timestampMs > existing.assistantTimestampMs)) {
existing.assistantTimestampMs = timestampMs;
}
if (interval) {
existing.interval = existing.interval
? { startMs: Math.min(existing.interval.startMs, interval.startMs), endMs: Math.max(existing.interval.endMs, interval.endMs) }
: interval;
}
return;
}
const request = { inputTokens: usage.input, outputTokens: usage.output, assistantTimestampMs: timestampMs, interval };
state.requests.push(request);
if (messageId !== null) {
state.requestsByMessageId.set(messageId, request);
}Taking the max also covers the older streaming-partial shape described in #549 (partials carry a lower output_tokens than the final entry). Entries without an id keep today's behaviour.
I applied this change to the built dist/ccstatusline.js locally: on the same transcript output-speed went from 294 t/s to 90 t/s, and the other widgets were unchanged. If #549 lands a shared "dedupe by message.id" helper, the speed collector could reuse it.
Activity
z1pp090 commentedon Oct 11, 2026
Same root cause as #549 in the speed path. In #595,
collectSpeedMetricRecordnow keeps one request permessage.id(the last row, which has the finalizedoutput_tokens) instead of one per content block, so the ~3x inflation inoutput-speed/input-speed/total-speedshould go away. The PR adds a test for the speed path ("counts one speed request per API response, not per content-block row").Your table (423 entries vs 167 unique ids, 294 t/s vs ~90 t/s) would be a good check against the branch. Related to #595.
LXZ56156 commentedon Oct 21, 2026
Additional data point on 2.2.32 (PR #595 is not in the published package yet).
I can confirm the ~3x inflation on a DeepSeek (Anthropic-compatible) transcript. For the same 30-second window:
message.id: 211 t/sSo the dedup in #595 is the right fix for the main issue.
However, even after dedup, one sample still dominates the window. From the same transcript:
output_tokens= 4977The short interval appears to be a tool-result → assistant write, not the actual generation time. With the merged-interval denominator, this one sample is enough to push the widget back to 800+ t/s even when every
message.idis counted once.Suggestion: when flushing the latest row per
message.id, also treat a single request as implausible whenoutput_tokens / intervalexceeds a reasonable ceiling (e.g. 500 t/s for current models), and exclude it from both the output sum and the merged interval — or clamp its interval tooutput_tokens / ceiling. That keeps the normal 100–250 t/s samples and removes the short-interval spikes.I'm happy to test a branch build if useful.
z1pp090 commentedon Oct 22, 2026
Thanks for the data point — the short interval is real, and the cause is in #595 itself: Claude Code can write a tool result between content blocks of the same response (it starts running a tool as soon as its block arrives). #595 kept the last row of each
message.id, so its interval started at that tool result instead of the user row before the first block. In my own transcripts that happens in about 10% of responses (207 of 2020).I've pushed acde650 to #595: the interval now starts before the first block of each response, with a test for this case. That should remove the spikes without a speed ceiling, which could hide real samples from faster models. If you can run your transcript against the branch, I'd like to know whether the 9049 t/s sample comes down to a normal value.
LXZ56156 commentedon Oct 22, 2026
Thanks — I reimplemented the
pendingStartMslogic from acde650 in a small script and ran it against the same DeepSeek transcript (not a branch build yet). Results for the same 30-second window:The window average is the same here because the intervals overlap, but the single-request outliers are gone:
The 9049/9132 t/s sample comes down to 315 t/s, which is normal. The first-block start fixes it without a ceiling. Happy to run a real branch build if you want a second confirmation.
z1pp090 commentedon Oct 22, 2026
Thanks, that's the confirmation I was hoping for: the outliers go away and the window average doesn't change, as expected when the intervals overlap.
If you have time, a run on a real branch build would be a good second confirmation for the review, since your script only reimplements the interval start and the build also covers the parsing and dedup. From a clone:
Then point
statusLine.commandin~/.claude/settings.jsontonode /path/to/clone/dist/ccstatusline.js. If the speed widgets on the same DeepSeek session stay around 200–300 t/s with no spikes, the fix holds end to end.LXZ56156 commentedon Oct 22, 2026
End-to-end confirmation on a real branch build.
Built acde650 from your fork (
bun install && bun run build), then rannode dist/ccstatusline.js --config <temp>with the same DeepSeek transcript and anoutput-speedwidget at 30 s:Stable, no spikes, in the expected 200–300 t/s range. The end-to-end path (parsing + dedup + first-block interval) holds. Thanks for the fix.