Fix #1470: Claude OTEL and transcript-sweep lanes disagree on which row carries a turn's usage, so a collapsed turn can total zero tokens

[philcunliffe]

Feature or issue

The transcript backfill sweep and the OTEL listener put a turn's usage on
different rows. LLP 0035 #one-carrier
fixes the carrier as the last assistant row of a response, and the sweep
follows it (backfill.js, last block line per message.id). The OTEL lane did
not: responseGapMessages parked usage on the last body-derived block only
when the response carried no text block, so on a [text, tool_use] turn -
the ordinary tool-calling shape - the assistant_response row claimed the
turn's usage while the sweep stamped the tool_use row.

That was survivable while the two lanes gave the same tool call different
part_ids. #1468 (LLP 0389) made a body-derived row settle onto the transcript
line's uuid, so the twin rows now collapse, and with the carriers disagreeing a
collapse can keep the sweep's text row (no usage) and the OTEL lane's tool row
(no usage): the turn totals zero tokens. It needs only a mixed commit
order, which the scheduled backfill.sweep_cron produces whenever it observes a
transcript whose text line has landed and whose tool_use line has not.

Reproduced against the real backfill provider, the real projection, and the
real settlement enricher on a [text, tool_use] transcript plus the matching
event stream and spooled response body:

sweep    tool_call  c0ffee11-...-7a8b9c0d1e2f#0   usage={"input_tokens":12,"output_tokens":34}
OTEL     text       22222222-...-222222222222#0   usage={"input_tokens":12,"output_tokens":34}

Solution

• responseGapMessages now decides on the response body's shape rather than on
  "does it contain text": the last gap block carries the turn's usage and
  stop_reason exactly when the body's last content block is a gap block
  (kept[last] === content[last]). That is the same block the sweep picks, so
  the two lanes name one carrier and a collapsed pair still totals the turn
  once. A response ending in text still leaves both to the assistant_response
  event, which is that response's last row.
• The projection cannot know at assistant_response time whether a body
  follows, and the exporter can split a turn across POSTs, so ordering is not
  assumed: the single pending api_request record in usageByRequestId is the
  arbiter, and whichever of the two rows reaches it first claims and removes
  it. In the order Claude Code actually exports (api_request,
  api_response_body, assistant_response) the body row claims it; in the
  reverse order the text row does and the placement degrades to the pre-fix one,
  still counted once. The body's own usage block stays a fallback only for a
  text-less response, which produces no assistant_response that could have
  claimed the record - so a text-bearing turn can never be counted twice.
• llp/0390-otel-usage-rides-the-response-last-block.decision.md records the
  decision (#carrier-is-the-last-block, #claim-order-arbitrates); LLP 0035 gets
  the Extended-by forward ref. Both code sites carry @ref annotations.

Verification. Two tests added to test/plugins/claude-otel-body-overlap.test.js,
the file #1468 created (its existing fixture is a tool-only response, precisely
the shape where the two lanes already agreed, so it could not see this):

• a [text, tool_use] turn: both lanes stamp the response usage on the same row
• a [text, tool_use] turn split across the two lanes still totals its tokens once

Both run the real backfill provider over an on-disk transcript and the real
listener projection plus the real settlement enricher over the spooled response
body. On the unmodified base (fix stashed, tests kept) they fail:

not ok 3 - a [text, tool_use] turn: both lanes stamp the response usage on the same row
    + actual - expected
    +   '22222222-2222-4222-8222-222222222222#0'
    -   'c0ffee11-2b3c-4d5e-8f60-7a8b9c0d1e2f#0'
not ok 4 - a [text, tool_use] turn split across the two lanes still totals its tokens once
  expected: 34
  actual: 0

With the fix both pass. npm test: 6171 pass, 0 fail, 1 skipped.
npm run typecheck: clean. (Both were also clean on the base in this
environment after a fresh npm install.)

CPU and memory pass. The added work per spooled response body is two array
index reads and one reference comparison (endsInGap), computed once per body,
not per block; hasText is the same single Array.some the code already did.
No new allocation, no new map or set, and no new retained state: the usage
index is the one that was already there, and the claim is the same Map.delete
under the same USAGE_INDEX_LIMIT cap. The hasText gate strictly reduces
work in the reversed-order case (no anthropicMessageAttributes(body) call).
Nothing here scales with session length or uptime. No CPU or memory concern.

Scope note (not fixed here). The api_request record is claimed whole, so
the per-request cost_usd, duration_ms, and speed move to the tool row with
the tokens. On a tool-calling turn those now sit on a body-derived row that a
collapse can drop in favour of the sweep's copy, which widens #1472 (a collapsed
row losing the OTEL-only fields the sweep has no source for) from text-less
turns to text-bearing tool turns as well. Splitting the record so a turn's
tokens and its cost land on different rows would trade that for a worse shape,
so where those fields belong is left to #1472. LLP 0390's consequences say so.

Fixes #1470

#1482

[philcunliffe]

neutral review round: 90530eff (fix/issue-1470)

Verdict: approve with fixes applied. The behavior change is correct, minimal, and
lands where LLP 0035 #one-carrier says it should. Two of the PR's own claims about
its consequences were measurably wrong, and one real consequence was unclaimed.
All three were documentation, not code; I fixed them in 0dfc643a and added the
one assertion that pins the unclaimed half. No change to the fix itself.

How I verified

Fresh worktree at 90530eff, fresh npm install. Beyond the suite I built a probe
that drives the real backfill provider, the real projection, and the real
settlement enricher over a [text, tool_use] transcript plus the matching spooled
body, with an api_request that also carries cost_usd / duration_ms / speed,
and swept all four sweep-vs-OTEL commit orders in both event orders, at 90530eff
and at origin/master. Output totals (output_tokens, cost_usd) after settlement:

sweep committed	master (both orders)	90530ef, forward order	90530ef, reverse order
text row only	0 tok / 0 cost	34 tok / 0.0042	0 tok / 0 cost
tool row only	68 tok / 0.0042	34 tok / 0 cost	68 tok / 0.0042
both rows	34 tok / 0 cost	34 tok / 0 cost	34 tok / 0 cost
neither	34 tok / 0.0042	34 tok / 0.0042	34 tok / 0.0042

"forward order" is api_request, api_response_body, assistant_response, which is
what Claude Code emits. That table is the basis for everything below.

Findings

1. MINOR (fixed) - llp/0390-...decision.md:65: the decision heading claimed a property the change does not have.
### One api_request record arbitrates, so order does not matter and the body's
"makes the question moot". Order does not matter for the COUNT. It very much matters
for the CARRIER, which is what the decision is for: in the reverse order the text row
claims the record, the placement is the pre-fix one, and #1470's zero-token collapse
is still fully reachable (table row 1, right column: 0 tokens). The doc did say the
reverse "degrades to the pre-fix one, counted once", but never said the pre-fix
placement is the bug, so a reader takes "order does not matter" at face value.
This matters more than usual because the doc lands Accepted, and per CLAUDE.md an
Accepted LLP is settled: a wrong claim here cannot be edited later, only superseded.
Fixed: heading is now "so no order double-counts", and the section separates the
property that survives every order (one stamped row) from the one that does not
(carrier agreement), names why the emitted order is the good one (the body event's
event.timestamp precedes the response event's), and records why the residual is
accepted rather than designed out (order-independence would mean holding every
assistant_response row back for a body event that has no end-of-turn marker to
wait on).

2. MINOR (fixed) - llp/0390-...decision.md Consequences, and the PR body's scope note: the #1472 "widening" is overstated.
The claim is that the loss "now reaches text-bearing tool turns as well as the
text-less ones it already reached". It does not reach a new shape. Both rows of a
[text, tool_use] turn already collide with the sweep's twin (text rows have always
agreed on part_id via message.uuid; #1468 made the tool rows agree too), so on
master those fields were already lost on that shape whenever the sweep's text row
committed first - table row 1, master column: cost 0. What the change does is move
which commit order loses them, text-first to tool-first: 2 of 4 orders before, 2 of
4 after. Fixed in the LLP consequence. I did not edit the PR body (out of scope for
this rung); its scope note carries the same overstatement and could be trimmed on the
next push.

3. MINOR (fixed, and pinned) - the PR undersells itself: it also removes the pre-existing 2x over-count.
Table row 2: master totals 68 tokens for that turn, 90530eff totals 34. #1470's
own table lists that over-count as the other mixed-order case, and one carrier removes
it along with the zero. Neither the PR body nor LLP 0390 mentioned it. Added as a
consequence, and pinned by extending the existing split-lane test with the opposite
commit order (test/plugins/claude-otel-body-overlap.test.js:545-558, "must not count
its tokens twice either").

4. INFO (not actionable here, not this PR's) - flaky test.
test/core/containment-refusal-stderr.test.js:1381 ("a JSONL close that lands after
destroy but before the error event is still diagnosed") failed once in five full runs
with EBADF: bad file descriptor, fstat. It touches nothing this PR changes and
fails the same way on master. Not filing: it is a pre-existing flake, and per CLAUDE.md
it does not belong in this diff.

The five claims

1. endsInGap = kept[last] === content[last] picks the same block the sweep picks. CONFIRMED.
gapBlocks is content.filter(...), so it preserves references and the identity
comparison is exact and cheap. Walked every shape against the sweep's
lastBlockIndexByMessageId rule (claude/src/backfill.js:517-535):
[text] (kept empty, early return, assistant_response carries - sweep's single line
carries), [tool_use] (true, both on the tool row), [text, tool_use] (true, both on
the tool row - the bug), [text, tool, tool] (true, both on the last tool),
[thinking, text] (false, both on the text row), [thinking, tool_use] (true, both on
the tool row), [tool_use, text] (false, both on the text row). Empty/edge bodies:
kept.length === 0 returns before the predicate, and content is non-empty by then,
so neither index read can be on an empty array. One residual, pre-existing and not this
PR's: a response whose LAST block is neither text nor a GAP_BLOCK_TYPE makes
endsInGap false while the sweep still stamps that trailing line - but the sweep's
stampUsage is computed before its own message filter, so it drops usage entirely in
that case. Exotic, and out of scope for a smallest-change fix.

2. Ordering is not assumed and nothing double-counts. CONFIRMED for the count, NOT for the carrier (finding 1).
claimUsage (bodies.js:451) and messageFromEvent (projection.js:347-350) both do
get-then-delete on the one usageByRequestId entry, so exactly one row is ever stamped.
I traced every path that could stamp twice and found none: same-batch either order;
split across POSTs either way; api_request arriving after the body; an
assistant_response suppressed by the !response || !uuid guard (which returns before
the claim, so it cannot consume the record); an exporter retry after a successful write
(the body file is already unlinked, so no gap row, and the record is already claimed);
and restoreUnclaimedUsage on a failed write (restores and re-projects the same inputs).
Reverse order degrades to the pre-fix placement, counted once - confirmed by probe, 34
tokens within the lane. What that degradation does NOT do is preserve the fix, which is
what finding 1 is about.

3. The body's own usage is a fallback only for a text-less response. CONFIRMED.
?? (hasText ? undefined : anthropicMessageAttributes(body)). A text-less response
produces no assistant_response, so no row can have claimed the record, so the fallback
cannot double-count. One improvement the PR does not mention: an empty-text response
([{type:'text',text:''}, tool_use]) suppresses the assistant_response row via the
!response guard; on master !hasText blocked claimUsage too and the tokens were lost
outright, whereas now endsInGap lets the tool row claim the api_request record. Strictly better.

4. LLP 0390 vs LLP 0035 and the repo's LLP rules. CONFIRMED, after the finding-1/2 edits.
LLP 0035 gains only a forward-ref (Extended-by: in the header block); nothing it
settled is edited. Compliant with "Accepted docs are settled". Filename convention
(NNNN-slug.decision.md), header fields, and Systems are right.
node scripts/llp-numbers.js check reports "1 LLP number minted against
refs/remotes/origin/master, no collision". @ref validation: all four annotations
(bodies.js:361 #carrier-is-the-last-block, bodies.js:377 and projection.js:342
#claim-order-arbitrates, and the test-file header [tests] ref) resolve to anchors
that exist in the new doc, each is attached directly above the construct it explains
with no blank line breaking attachment, and each says something the code and filename
do not. Not mechanical. No em dashes, no semicolons, no NUL bytes, no new runtime deps,
no invented columns or config keys.

5. The #1472 widening claim. PARTIALLY ACCURATE - see finding 2.
Accurate that cost_usd / duration_ms / speed move with the tokens, because
usageFromApiRequest returns one object claimed whole (projection.js:406-440).
Accurate that a tool-calling turn now loses them in an ordering where it previously
kept them (table row 2: 0.0042 to 0). Inaccurate that this reaches a shape #1472 did
not already reach - table row 1 shows master losing them on the same text-bearing turn.
Corrected in LLP 0390; the PR body still says it the old way. Not fixing #1472 here, as
instructed.

CPU and memory pass

Explicit pass over responseGapMessages, messageFromEvent, and the affected
listener path.

• Added per-body work is O(1): endsInGap is two array index reads and one
  reference comparison, computed once per spooled response body, outside the block
  loop. No allocation.
• hasText is unchanged - the same single Array.some over content the code
  already ran, still hoisted out of the loop, still short-circuiting.
• No new retained state. No new Map, Set, array, or closure. usageByRequestId
  is the index that was already there, still bounded by USAGE_INDEX_LIMIT (512) and
  still trimmed oldest-first by trimUsageIndex, including on the
  restoreUnclaimedUsage path. The claim is the same Map.delete.
• Nothing scales with session length, transcript size, or uptime. Cost per response
  body is a function of that body's block count only, exactly as before.
• One small net reduction: in the reversed-order and text-bearing cases the
  hasText guard skips the anthropicMessageAttributes(body) call and the object it
  would have allocated, which master made unconditionally.
• The doc and test edits in 0dfc643a add no runtime work. The added test assertion
  is one extra settleBatch over three rows in an existing test; full-suite wall time
  was unchanged (16.5s before, 16.5s after).

No CPU or memory concern.

Result

Fixes pushed as 0dfc643a (LLP 0390 wording, one test assertion). Verified present with
git diff 90530eff..0dfc643a: heading at llp/0390-...md:65, reworded consequence at
:100-113, assertion at test/plugins/claude-otel-body-overlap.test.js:556.
npm test: 6171 pass, 0 fail, 1 skipped. npm run typecheck: clean.
Reconfirmed both new tests still fail on master's source with the test file kept
(0 !== 34, and the carrier mismatch), so the reproduction still holds at the new head.

[philcunliffe]

Round 2 review (final) of 0dfc643a

Verdict: approve after the three documentation/test fixes pushed as b9508344. The source change is correct, minimal, and I could not break it. All three findings are in round 1's own additions (the LLP prose and the test coverage around it), not in the fix. Nothing remains open.

1. Is the residual honestly and correctly stated in LLP 0390? Not quite; fixed.

Two problems in llp/0390-otel-usage-rides-the-response-last-block.decision.md:77-90.

Finding A (Medium, doc correctness): the stated mechanism was the wrong one. The paragraph said the body row claims the record because "the body event's event.timestamp precedes the response event's". It does not. projectClaudeTelemetryEvents walks events in the order the batch supplies (projection.js:101), flattenClaudeTelemetryEvents never sorts, and nothing on this path reads event.timestamp for ordering. What decides the claim is the event's position in the stream. The timestamp corroborates the emission order; it does not cause the outcome. Left as written, a future reader would reasonably conclude the projector is timestamp-ordered and that sorting is therefore already in force, which is the sort of belief that produces the next #1470.

Finding B (Medium, doc correctness): the residual named only half of what it lets through. The doc said the reverse order leaves "#1470's zero-token collapse" reachable. The reverse order restores the pre-fix placement exactly, so the 2x over-count is equally reachable. Verified empirically: I ran the split-lane test with assistant_response moved ahead of api_response_body and instrumented the two mixed commit orders.

event order	first mixed order	second mixed order
master (no fix)	0 tokens	68 tokens
PR, forward order (api_response_body first)	34	34
PR, reverse order	0	68

The Consequences bullet that says naming one carrier "removes it along with the zero" carried no order caveat either.

I also could not find any in-repo evidence for the upstream emission order: no fixture, no capture under research/, and docs/ACCEPTANCE.md does not record it (api_response_body is only mentioned there as expected absent from claude_telemetry_events). "the body event is always the earlier of the two" was therefore an unpinnable "always".

Fixed by rewriting the paragraph to (a) name the real mechanism (batch position, event.timestamp explicitly not read), (b) say BOTH #1470 shapes stay reachable in the reverse order, (c) mark the emission order as upstream shape no fixture here pins, the kind of drift claude_otel_shape_check exists to catch, and note it degrades to the pre-fix behavior rather than to anything worse; and by adding the order caveat to the Consequences bullet. The residual itself is genuinely accepted, not a defect: the alternative the doc rejects (holding assistant_response rows back with no end-of-turn marker to wait on) is worse, and the cheaper in-batch variant does not survive the exporter splitting a turn across POSTs.

2. Is the corrected #1472 characterisation accurate? Yes.

Verified independently. usageFromApiRequest (projection.js:416-442) builds one object carrying both attributes.usage and attributes.claude.{cost_usd,duration_ms,speed}, and claimUsage takes it whole, so the OTEL-only fields do move with the tokens. Both rows of a [text, tool_use] turn collide with a sweep twin (the text row by message.uuid, the tool row via the LLP 0389 match-key), so the field loss is a race in both placements: before the change the loss needed the sweep's TEXT row to commit first, after it the sweep's TOOL row. Two independent races, two outcomes each: 2 of 4 orders before, 2 of 4 after. Round 1's correction stands. No in-app consumer reads attributes.claude.cost_usd on this path (grep over src/ and the plugin workspace finds only opencode/hermes fields of similar name), consistent with the "not load-bearing" claim.

3. Is the newly claimed 2x over-count removal real, and does the extended test pin it? Yes to both.

Real: instrumented on master, the second mixed order totals 68 for a 34-token turn (both surviving rows carry their own copy). With the fix it is 34.

Pinned: the assertion fails independently of the first one. Reverting only bodies.js/projection.js makes test 4 fail at 0 !== 34 before it reaches the second assertion, so I ran the second half in isolation against master's source and it reports 68, i.e. it would fail on its own if only the over-count regressed. The endsInGap predicate is also pinned by test 3 (carrier identity).

4. LLP hygiene: clean.

• node scripts/llp-numbers.js check: "1 LLP number minted against refs/remotes/origin/master, no collision".
• LLP 0035 gains only the **Extended-by:** header line; its decision text, including #one-carrier, is byte-identical. Format matches the corpus convention (0012/0013/0014/0016/0021/0027).
• Every @ref anchor resolves: 0390#carrier-is-the-last-block, 0390#claim-order-arbitrates, 0035#one-carrier (the <a id> at 0035:73), 0262#migration, 0027#decision, 0389#match-key-on-bodies. Each is attached to the construct it describes (const endsInGap, the carrier branch, messageFromEvent's usage lookup, the test file header) and each says something the code does not: why identity comparison is the predicate, and why one claimable record is the arbiter. None mechanical.
• The fix matches what 0035#one-carrier actually requires ("the last assistant row of the response ... a tool_use on tool-calling turns, else the final text") and what the sweep does (backfill.js:521, lastBlockIndexByMessageId).

5. Repo conventions: clean.

No semicolons added, no em dash (U+2014) anywhere in the diff, no smart quotes, no NBSP, no NUL. No new runtime dependency. No new column, config key, or schema field: endsInGap is a local, and stop_reason/attributes.usage are existing columns. The source change is 2 files, 8 net lines.

Finding C (Low, test coverage): the fallback guard was untested. Fixed.

bodies.js:383-384 changed the fallback from ?? anthropicMessageAttributes(body) to ?? (hasText ? undefined : anthropicMessageAttributes(body)). That guard is what stops this lane double-counting when the text row claimed the record first, and LLP 0390 records it as a decision. Mutation check: restoring the unconditional fallback left the entire 6170-test suite green (the one failure in that run, daemon-retention-enforcement, is unrelated and passes 3/3 in isolation on clean HEAD). Added test/plugins/claude-telemetry-bodies.test.js, "a text-bearing response body ending in a tool_use never falls back to its own usage": the reverse event order, asserting exactly one carrier and that it is the assistant_response row. The same mutation now fails that test and nothing else. Also renamed the neighbouring test, whose title still stated the superseded predicate ("a response body with a text block") that this PR replaces with "ends in a text block"; its fixture already ends in text, so only the title was stale.

CPU and memory pass

No CPU or memory concern.

• endsInGap is two array index reads and one reference comparison per response body, O(1), no allocation. gapBlocks uses Array.prototype.filter, which preserves element references, so the identity comparison is sound and needs no deep compare. content.length >= 1 is guaranteed by the kept.length === 0 early return above it.
• hasText is one content.some(...) pass per response body, and it was already there before this PR: no new pass, no new scan of a hot path. Bodies are per-API-response and already fully walked by gapBlocks.
• projection.js is unchanged except for a comment. No change to usageByRequestId lifetime, growth, or eviction: USAGE_INDEX_LIMIT (512) and the oldest-first trim are untouched, and the claim is still a Map.delete. The fix cannot leave more entries resident than before: on a [text, tool_use] turn exactly one row still claims the record, just a different one. restoreUnclaimedUsage on write failure still re-applies the cap.
• The new test allocates one small literal body and no filesystem work (it passes a synthetic spooledBodies map), so it adds no measurable suite time.
• Per-row memory is unchanged: the same attributes object is stamped on one row either way, and stop_reason moves rather than duplicating.

Verification

• npm test: 6172 pass, 0 fail (6170 before, +2 from the added test and the retained neighbour).
• npm run typecheck: clean.
• node scripts/llp-numbers.js check: clean.
• Fixes verified landed with git diff 0dfc643a..b9508344: llp/0390-...decision.md (+19/-15) and test/plugins/claude-telemetry-bodies.test.js (+46/-1); no source file touched by this round.

Pushed as b9508344.

[philcunliffe]

Ship risk: low

Who could be affected: People reading token or cost totals for Claude Code sessions HypAware recorded, where the same session was picked up both live and by the scheduled catch-up read of the session transcript.

What could happen:

• Totals for a turn where Claude answers with some text and then runs a tool get more accurate, not less: today such a turn can report zero tokens, or twice its real tokens, depending on which copy of it was saved first.
• If a future Claude Code release changed the order it reports things in, these turns would go back to today's behaviour. They would not get worse than today.
• Sessions already recorded are left exactly as they are; this only affects what gets written from now on.

Why this level: The change only affects which saved line of a conversation carries the token count, and only for Claude Code recorded through the live listener. It cannot lose a conversation, change what is stored about it, alter any setting, or affect any other tool HypAware records. Nothing is rewritten, so there is nothing to undo.

What was checked: The real recording code was run for a text-then-tool turn in six different arrival orders, and for six response shapes, and compared line by line against the current release. In every case exactly one line carried the tokens, the total was right or identical to today, and no case came out worse. The full test suite (6172 tests) and type checking both pass.