Skip to content

An unparseable body leaves spool_bytes reporting bytes it already deleted (#904) - #912

Merged
philcunliffe merged 2 commits into
masterfrom
fix/issue-904
Aug 19, 2026
Merged

An unparseable body leaves spool_bytes reporting bytes it already deleted (#904)#912
philcunliffe merged 2 commits into
masterfrom
fix/issue-904

Conversation

@philcunliffe

Copy link
Copy Markdown
Contributor

Triage of PR #851 recorded five deferred findings on #904. One of them is reachable from master today; the other four are not, and they are listed below with the reason.

Fixed: finding 3, the unparseable-body arm leaves spool_bytes drifted high

What was wrong. loadSpooledBodies deletes a body file that fails to parse (an undeleted body is a raw prompt sitting on disk) and counts it in unparseable, but reported no size for it. The receive handler subtracts spooled.consumedBytes for the projected arm only, so an unparseable body left state.spoolBytes at its pre-batch value: hyp status published bytes for a file that was already off the disk, for up to the 60s spool-sweep interval, until the sweep restated the gauge.

Root cause. The byte accounting is caller-side (state.spoolBytes = Math.max(0, state.spoolBytes - spooled.consumedBytes) in hypaware-core/plugins-workspace/claude/src/telemetry/source.js), and loadSpooledBodies returned no field the caller could subtract for the deletion it performed itself. The .catch(() => {}) on the unlink also hid whether the file actually left the disk.

Fix. loadSpooledBodies now returns unparseableBytes, accumulated only once fs.rm resolves, so a file that could not be removed (EPERM, a read-only spool) keeps occupying the cap rather than being subtracted out from under it. The receive handler deducts it beside the existing state.bodiesUnparseable += spooled.unparseable.

Regression test. New test/plugins/claude-telemetry-unparseable-body.test.js, two cases:

  • End-to-end through the real transport (listener on an ephemeral port, fake gateway, OTLP/JSON over the wire, a seeded unparseable body so the start-time sweep primes the gauge, and a recorded session context so the batch reaches the READ path rather than the policy-drop path): posts an api_request_body naming that file, then asserts the file is gone and the published spool_bytes is 0.
  • The reader half alone: loadSpooledBodies reports unparseableBytes equal to the file's size while consumedBytes stays 0.

Before the fix (at b1afa7c2):

not ok 1 - an unparseable body brings the published spool_bytes down with it
    expected: 0   actual: 15
not ok 2 - loadSpooledBodies reports the bytes an unparseable body took with it
    undefined !== 15

After the fix: # tests 2 / # pass 2 / # fail 0. Full suite npm test: # tests 4486 / # pass 4485 / # fail 0 / # skipped 1. npm run typecheck clean.

Gate met: behavioural finding, failing-then-passing regression test.

Still deferred

Findings 1, 2 and 4 are not reachable from master. All three describe code that PR #851 introduces and that PR is still open (fix/issue-843, head 1378a82c, state OPEN). Verified against origin/master:

These three should be picked up on top of #851, either as review comments on that PR or as a follow-up once it merges. Fixing them here would have meant re-implementing #851's changes on a second branch.

Finding 5 needs a maintainer decision and is out of an autonomous worker's authority. It asks whether "a retried batch re-projects from the same inputs, so those inputs must survive a failed write" belongs in LLP 0257, which is Accepted. Under CLAUDE.md an Accepted LLP is a record: the change is a new request extending 0257, plus an Extended-by: forward-ref on the old doc. Whether that clause belongs in the spec at all, and what it should say, is the judgement call the issue explicitly routes to a maintainer, so no LLP was minted.

Note on merge order

This branch touches telemetry/bodies.js and telemetry/source.js, which #851 also touches. The hunks are disjoint (this one is inside loadSpooledBodies and at its call site; #851's are in deleteSpooledBodies, the refusal log, the write-failure catch, and the timestamp max), so a textual conflict is unlikely but possible. If #851 merges first, rebase this branch onto it.

Fixes #904

@philcunliffe

Copy link
Copy Markdown
Contributor Author

Heads-up: PR #913 fixes the same defect as this PR. Issues #904 and #905 each carried the same deferred finding, so two issue-fix workers landed independent fixes for it in the same tick.

#913 is labelled neutral:stuck with the full comparison and the choice for you to make; this PR keeps riding the normal ladder in the meantime, purely because it was opened first. Merging both would double-apply the change and conflict.

@philcunliffe

Copy link
Copy Markdown
Contributor Author

Neutral review of cb2d905a - verdict: findings (3 actionable, all fixed in b7e19826)

The change itself is sound and correctly scoped: loadSpooledBodies reports unparseableBytes, the single call site subtracts it, the retry path cannot double-subtract (a deleted file re-reads as missing), and the sweep restates the gauge absolutely so no drift accumulates. I confirmed the new tests are real regressions: reverting both source files and running test/plugins/claude-telemetry-unparseable-body.test.js gives # fail 2 at the head's own expected values (0 !== 15, undefined !== 15).

Three actionable findings, all low severity (the gauge is observability-only; enforceClaudeBodySpoolCap re-scans the directory, so capacity enforcement never depends on state.spoolBytes). All three are fixed and pushed.

1. Low - correctness: a forced remove resolves for a file that is already gone, so one deletion could be subtracted twice

hypaware-core/plugins-workspace/claude/src/telemetry/bodies.js:110 (at cb2d905a)

await fs.rm(file, { force: true })
// Sized only once the unlink succeeded, matching the projected arm:
unparseableBytes += raw.length

force: true suppresses ENOENT, so "the unlink succeeded" does not prove this call removed the file. The receive handler is not serialized, so two reads of the same body_ref can be in flight at once (an exporter client-timeout retry overlapping the original it retries). Both readFiles complete before either unlink, both bodies are unparseable, and both add raw.length - spool_bytes comes down by twice one deletion. Bounded by the Math.max(0, ...) clamp and corrected by the next sweep, but it is exactly the accounting this PR exists to make right.

Not hypothetical in this codebase: the open PR #851 records the same ENOENT trap for deleteSpooledBodies ("fs.rm(..., { force: true }) succeeds on a missing path, so counting its return alone reported every vanished ref as one more deletion").

Fixed by using fs.unlink, which rejects with ENOENT so the second caller reports nothing. New regression case two overlapping reads of one unparseable body report its bytes once in test/plugins/claude-telemetry-unparseable-body.test.js:201; it is deterministic (both reads are issued before either resolves), and measured 30 bytes before the fix vs 15 after for one 15-byte file.

2. Low - the comment describes code that is not on this head

bodies.js:112 (at cb2d905a): "Sized only once the unlink succeeded, matching the projected arm". The projected arm does not do this: source.js:720 subtracts spooled.consumedBytes unconditionally, whether or not deleteSpooledBodies removed anything (it swallows failures and returns only a count). The two arms match only after PR #851 rewrites that line. The same comment also says an undeleted file is "still occupying the cap", but state.spoolBytes never feeds the cap.

Fixed: the comment now states what the code does and why the unlink has to be the one that removed the file.

3. Low - @ref honesty: wrong anchor, and a gloss the code does not deliver

Both new annotations (bodies.js:114, source.js:640 at cb2d905a) cited LLP 0253#byte-cap with the gloss "the published byte size is what is on disk, whichever arm removed the file".

  • Wrong anchor: 0253#byte-cap settles the cap and the eviction direction. The published gauge is LLP 0257#status-and-health S16 ("details carrying ... the spool's current byte size and eviction count"), which is already the anchor on the neighbouring spool_bytes detail at source.js:302.
  • Overclaim: the policy-drop arm (suppressSession -> deleteSpooledBodiesForEvents) still deletes bodies without touching state.spoolBytes, so the identical drift remains for session-ignore and withheld-cwd batches.

Fixed: anchors moved to 0257#status-and-health (code and the test file header), and the overclaim replaced with a note naming the arm that still lacks the subtraction.

Not actionable here, recorded for the maintainer

Verification

At b7e19826: npm test -> # tests 4487 / # pass 4486 / # fail 0 / # skipped 1. npm run typecheck clean. npm run smoke -- claude_telemetry_capture ok. No em dashes, no semicolons introduced. Each fix verified by inspecting the pushed tree, not by a green suite: fs.unlink at bodies.js:117, 0257#status-and-health at bodies.js:121, source.js:645 and the test header, and the new test at test/plugins/claude-telemetry-unparseable-body.test.js:201. Local runs are advisory; CI is the authority.

@philcunliffe

philcunliffe commented Aug 19, 2026

Copy link
Copy Markdown
Contributor Author

Neutral review of b7e19826 - verdict: clean (0 actionable findings, nothing pushed)

This head is the previous round's fix commit. I re-reviewed the whole PR diff against origin/master from a clean detached worktree, not just the fix delta, and found nothing actionable. No commits were pushed this round; origin/fix/issue-904 is still b7e19826.

The change, re-derived independently

loadSpooledBodies now reports unparseableBytes (hypaware-core/plugins-workspace/claude/src/telemetry/bodies.js:69, :81, :124, :141) and the one call site subtracts it (hypaware-core/plugins-workspace/claude/src/telemetry/source.js:646). I confirmed each accounting property that has to hold:

  • Single call site. loadSpooledBodies is called exactly once in production code (source.js:635); no other consumer sees the widened return shape, and no .d.ts declares it, so nothing else needed updating.
  • Placed before the throw. The subtraction sits at source.js:646, ahead of the recordProjectedExchange try/catch at :673-699. That is correct: the file is gone whether or not the dataset write succeeds, so the gauge must move even on the error path.
  • Retry cannot double-subtract. On the exporter's retry the deleted file fails readFile and lands in the missing arm (bodies.js:96-104), contributing no bytes.
  • The sweep cannot re-inflate it. sweepSpool assigns absolutely (source.js:159, state.spoolBytes = swept.spoolBytes), so a subtraction can never accumulate into permanent drift; the worst case is one sweep interval of a bounded error.
  • Units match. raw.length is a Buffer byte length, the same quantity the sweep sums from f.size (telemetry/spool.js:132).
  • The unlink swap is behaviour-preserving on the error side. fs.unlink and fs.rm(..., { force: true }) differ only on ENOENT, which is exactly the case the fix needs to distinguish; EISDIR/EPERM reject on both and are caught identically (bodies.js:128-132).

Verification of the previous round's three fixes (all landed in the tree, not just green)

Checked git diff cb2d905a..b7e19826 and the file contents at head, per finding:

  1. fs.unlink replaces fs.rm(file, { force: true }) at bodies.js:117.
  2. The bodies.js:109-115 comment now describes the ENOENT-distinguishing unlink and the EPERM case, and no longer claims to match the projected arm or to feed the cap.
  3. Both @refs moved off 0253#byte-cap onto 0257#status-and-health: bodies.js:121, source.js:644, and the test-file header test/plugins/claude-telemetry-unparseable-body.test.js:12. I verified the anchor exists (llp/0257-claude-telemetry-listener-source.spec.md:81, {#status-and-health}) and that S16 (:83-85) really is the clause that owns "the spool's current byte size", matching the neighbouring annotation at source.js:300.

The tests are real regressions (measured, not assumed)

  • With both source files reverted to origin/master: # tests 3 / # pass 0 / # fail 3.
  • With only bodies.js reverted to cb2d905a (the pre-fix-round head): cases 1 and 2 pass, case 3 two overlapping reads of one unparseable body report its bytes once fails with expected: 15, actual: 30 - exactly the double-subtraction the round-1 finding predicted.
  • Case 3 is deterministic rather than timing-dependent: Promise.all issues both readFiles before either resolves, so both reads always observe the file and only one unlink can win.
  • The integration case is deterministic too: await sweepSpool() completes before start() resolves (source.js:191), so the seeded file is always priced into spool_bytes before the POST.

Style and ref hygiene

No em dashes and no semicolons introduced anywhere in the diff. JSDoc-only types, no @typedef, no inline import('...') types. The one new inline-return-shape field is added to the existing @returns block rather than a new type.

Recorded for the maintainer, no change made

  • The policy-drop arm still drifts the same way. suppressSession -> deleteSpooledBodiesForEvents (source.js:401, bodies.js:189-210) deletes bodies for an ignored session or a withheld cwd and returns { deleted, refused } with no byte total, so state.spoolBytes is untouched there. This is pre-existing on master, out of scope for Follow-up: deferred review findings from PR #851 #904's finding 3, and the head's comment at source.js:640-642 names it honestly rather than overclaiming. Closing it needs the deletion helpers to report bytes, which is what PR Deferred #843 findings: listener counters, the refusal log, and the usage a failed batch consumed #851 adds.
  • Merge sequencing with Deferred #843 findings: listener counters, the refusal log, and the usage a failed batch consumed #851 is unchanged. Both branches rewrite the same loadSpooledBodies hunk; whichever lands second must rebase, and the merged result has to keep unparseableBytes alongside Deferred #843 findings: listener counters, the refusal log, and the usage a failed batch consumed #851's byte-reporting deletes.
  • Duplicate fix in The unparseable-body arm takes its bytes off spool_bytes (#905 finding 3) #913 is already tracked by the crossref comment above and is a maintainer choice, not a code finding.
  • A failed unlink of an unparseable body is now silent by omission (hypaware-core/plugins-workspace/claude/src/telemetry/bodies.js:128-132). The catch is empty, so an EPERM (a hardened read-only spool, a restrictively permissioned body file) leaves a raw prompt on disk while the batch still logs claude.telemetry.body_unparseable exactly as it would for a clean delete. The old .catch(() => {}) was equally silent, so this is not a regression, and the byte accounting stays right either way (the bytes are correctly NOT subtracted). But the code now knows the delete failed, and the doc comment right above it is the one that says an undeleted body is a raw prompt sitting on disk - a ctx.log.warn with an error_kind, or an undeletable count in the return shape, would surface a privacy-relevant state for free. Recorded rather than pushed: it widens the return contract, and it sits naturally next to the drop-arm byte reporting above.
  • The subtraction trades an over-report for a smaller under-report, not for accuracy. A body written after the last sweep was never priced into state.spoolBytes, so deleting it drives the gauge below the spool true size until the next sweep (source.js:646). Same approximation the projected arm already makes with consumedBytes, and the right direction of error (claiming to hold content already deleted is the worse failure), but the fix is narrower than "the gauge is now accurate."
  • Editorial only: the PR body says the new test file has "two cases"; it has three since the round-1 fix added the race case. Not worth a push on its own.

Checks run at b7e19826

npm test -> # tests 4487 / # pass 4486 / # fail 0 / # skipped 1. tsc -p tsconfig.json --noEmit clean. npm run smoke -- claude_telemetry_capture ok. GitHub checks green on this head (test 22/24, typecheck 22/24, duplicate-numbers). Local runs are advisory; CI is the authority.

@philcunliffe
philcunliffe marked this pull request as ready for review August 19, 2026 08:46
@philcunliffe philcunliffe added the neutral:approved neutral reviewed this and holds it for a maintainer merge (own or adopted PR; LLP 0025/0030) label Aug 19, 2026
test and others added 2 commits August 19, 2026 11:57
…eted (#904)

Deferred finding 3 from PR #851's triage. `loadSpooledBodies` deletes a
body file that does not parse (an undeleted body is a raw prompt sitting
on disk) but reported only a count, so the listener's call site had no
size to subtract from `state.spoolBytes`. The gauge stayed at its
pre-batch value until the next sweep restated it, up to the 60s sweep
interval, and `hyp status` published bytes for a file already off disk.

`loadSpooledBodies` now returns `unparseableBytes`, sized only once the
unlink actually succeeded (a file still on disk is still occupying the
cap), and the receive handler subtracts it beside the existing
`bodiesUnparseable` counter.

Findings 1, 2 and 4 are not reachable from master: they describe code
PR #851 introduces and that PR is still open. Finding 5 is a spec
question for a maintainer. All four remain deferred on #904.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…and the refs name the spec that owns the gauge

Three review findings on the unparseable-body byte accounting.

`fs.rm(file, { force: true })` RESOLVES for a path that is already gone, so
"sized only once the unlink succeeded" did not hold: two reads of the same
`body_ref` in flight at once (the receive handler is not serialized, so an
exporter retry overlaps the original it retries) both read the file, both
call it unparseable, and both added `raw.length` - `spool_bytes` came down by
twice one deletion. `fs.unlink` makes the guard the comment describes real:
the second call rejects with ENOENT and reports nothing. New regression case
proves it, 30 bytes before and 15 after for one 15-byte file.

The comment claimed the sizing matched the projected arm. It does not on this
head: the projected arm subtracts `spooled.consumedBytes` unconditionally at
the call site whether or not `deleteSpooledBodies` removed anything. It also
said an undeleted file is "occupying the cap", but `state.spoolBytes` is a
published gauge only - the cap is enforced by `enforceClaudeBodySpoolCap`
re-scanning the directory. Both claims replaced with what the code does.

Both `@ref`s cited LLP 0253#byte-cap with a gloss reading "whichever arm
removed the file". The published gauge is LLP 0257 S16's duty
(#status-and-health), not the cap's, and the "whichever arm" claim is not
true: the policy-drop arm still deletes bodies without subtracting, because
the delete-unread path reports no bytes. Anchors moved to 0257 and the
overclaim replaced with a note of the arm that still lacks it.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@philcunliffe
philcunliffe merged commit 2fa5841 into master Aug 19, 2026
10 checks passed
@philcunliffe
philcunliffe deleted the fix/issue-904 branch August 19, 2026 19:03
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

neutral:approved neutral reviewed this and holds it for a maintainer merge (own or adopted PR; LLP 0025/0030)

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Follow-up: deferred review findings from PR #851

1 participant