Rebase + split of #161: cache attribution (draft, review only) - #181
Closed
teamchong wants to merge 7 commits into
Closed
Rebase + split of #161: cache attribution (draft, review only)#181teamchong wants to merge 7 commits into
teamchong wants to merge 7 commits into
Conversation
…essages[0] `historyImageSha8` hashed the image blocks on `messages[0]`, described in its own docstring as "the synthetic history message". It is not: whenever a slab anchor exists, `collapseHistory` returns `[...head, syntheticUser, ...tail]` and transform.ts passes `protectedPrefix = slabAnchorIdx + 1`, so on every Claude Code request `messages[0]` is the protected slab message. The field that exists to prove history-image byte-identity was therefore reporting SLAB stability under the history name — a drifting collapse boundary still showed a rock-steady `history_image_sha8` in events.jsonl, which is precisely the signal #11 attribution relies on. Locate the synthetic message by its banner, the same way `cachePrefixDigest` does. Also split the pinned-prefix digest per layer. `cache_prefix_sha8` proves THAT the cacheable prefix moved but never WHICH layer moved, and the layers fail for different reasons and need different fixes: tools drift when the client loads a deferred tool, system drifts when volatile text (env, git status) rides inside the pinned span, and the imaged head drifts when a collapse boundary or marker placement moves. Emit `cache_prefix_tools_sha8` / `cache_prefix_system_sha8` / `cache_prefix_head_sha8` alongside the aggregate so one session of telemetry names the culprit instead of narrowing it to "somewhere in the prefix". Motivation: a production session showed 530/530 requests with a unique `cache_prefix_sha8` at a constant `cache_prefix_bytes`, 0 cache_read across 87M cache_create tokens — with the aggregate hash alone the cause could not be attributed, and `history_image_sha8` looked stable because it was measuring the wrong message. (cherry picked from commit fa73143)
…t attribution `cachePrefixDigest` hashed every block up to and including the message that carries pxpipe's imaged prefix. That is not the span Anthropic caches: caching ends at the LAST cache_control marker, and after a history collapse the two differ by construction. The synthetic message's newest freeze chunk re-renders on every turn BY DESIGN (append-only rendering: only completed chunks are frozen) and it sits AFTER the pinned marker — so the boundary-scoped digest changes every single turn even when the cached span is byte-stable, and `cache_prefix_sha8` reads "pxpipe busted its own cache" on healthy traffic. Emit `cache_prefix_marked_sha8` / `_marked_bytes` / `_marker_pos` alongside: the digest through the breakpoint, its size, and where the breakpoint sits as `m<msg>.b<block>`. The marked digest is the one that must hold turn over turn; the marker position makes a roaming breakpoint — a bust cause in its own right, previously invisible — a one-field diagnosis. Tests pin the contract that decides whether cache_read happens at all: two consecutive turns of one session keep the marked span byte-identical while the live tail grows. (cherry picked from commit d7b8655)
…xists renderStatsTableFragment read s.eventsWithBaseline, but stats.ts emits eventsWithUsage; the missing field made the comparison false for every session, so the "cache hit (by events)" row silently rendered "-" no matter what the cache did. The type carried the stale name too, so tsc had no chance to catch it. Test pins the value to its own row (the table renders as one line, so a bare toContain passes on a neighbouring number) and fails with '-' against the old expression. (cherry picked from commit c6c5db6c2916b89cc5ef8114adbdbe02f5acd383)
The 100-image limit is a property of the wire, not of pxpipe: it counts
the images the client sent (pasted screenshots, pictures a tool returned)
together with every image we add. We priced only our own, so a request
that arrived already full got imaged further and came back 400/500 —
two sessions became unresumable.
Every imaging path now spends from one shared headroom:
imageHeadroom() = cap - margin - ours - theirs
and the caller's images are counted once, before any rewrite, at both
nesting levels (top-level and inside tool_result).
The gate is quantitative, not boolean. A first cut asked "is there ANY
room left?" and then emitted a whole 15-page slab into it: 94 client
images + a 400k slab put 109 images on the wire. Now:
- the slab must fit whole or not at all — imaging half of it would
re-key the cache prefix on every turn whose client-image count moved;
- each tool_result pages against the LIVE headroom, not a fixed 10;
- after rendering we verify the real page count, because paging is
budgeted at denseGeo.cols while rendering happens at o.cols;
- the history collapse is skipped entirely at zero headroom — its
budget floors at 1, so it would otherwise emit exactly one image
and still fail the request.
Degrading means "do not emit this turn", never "un-emit": each turn is
re-derived from the client's own text transcript, so our images are
never stranded there.
Telemetry: native_images and image_budget_skips reach the event log, and
passthrough_reasons loses an allow-list that swallowed exactly the two
reasons worth diagnosing (kept_sharp, image_budget).
Measured, 300 turns + 60k slab + 60k tool_result:
clients= 0 | slab=3 toolres=3 hist=50 | wire= 56 | text 233k
clients=50 | slab=3 toolres=3 hist=44 | wire=100 | text 206k
clients=80 | slab=3 toolres=3 hist=11 | wire= 97 | text 809k
clients=90 | slab=3 toolres=1 hist= 0 | wire= 94 | text 1053k
Client images always win; we shrink to fit. What remains is a cliff, not
a slope: the collapse is our only reducer and it is image-based, so at a
full wire we drop from compressed straight to raw.
(cherry picked from commit cdae551)
…ge count Three gaps, all of the same kind: the code knew something and never said it. markCacheDead() existed but nothing ever called it. A rejected request never populated a prefix cache, so the append-only freeze it was protecting protects nothing — but only the transform side knew that, and the proxy never told it. responseLeftNoCache() now names the rule and the response path applies it: 413, any 5xx, and a 400 whose body says the prompt is too long. Everything else stays warm on purpose. A 401, a 404, a rate limit say nothing about the cache, and guessing "cold" there would re-cut a live grid and burn the whole prefix as cache_create — the exact cost this module exists to avoid. imageCount is what we RENDERED, and the wire disagrees: the history collapse replaces whole messages, so a tool_result image inside the collapsed range is never sent. Measured on a tool-heavy shape: 91 rendered, 49 on the wire. info.wireImages now counts the outgoing body itself, and the event carries it whenever it differs from the render count. The event log gains history_freeze_step, history_budget_trimmed and history_pack_fill, so the adaptive grid is finally observable: until now nothing recorded whether it had coarsened, why, or whether a repack landed on a cache we believed dead. The dashboard says the same in words, but only when there is something to say: "6 images came from your side and count against the same 100-image request cap · 48 rendered pages never went out — the history collapse absorbed those messages (49 on the wire)". A quiet turn stays quiet. Not fixed here: those 48 absorbed pages are content loss, not just miscounting. An imaged tool_result serializes into the history as "[tool_result]\n[image]", so the tool output survives only as the factsheet's exact identifiers. The cure is ordering — collapse before imaging — which changes the outgoing bytes for every session and re-keys every cache once, so it wants its own change. (cherry picked from commit 0f2ac30)
…clock The history collapse may re-cut its grid for density only when no prefix cache exists — a re-cut changes every chunk's bytes and re-keys the whole prefix. That decision was made from an idle timer set to the ephemeral 5-minute TTL, and it was wrong most of the times it fired. Measured over 143 gaps on a production host: past a 5.5-minute gap the cache was still warm in 66% of cases, past 15 minutes in 40%, past an hour in 13%. Claude Code marks some blocks with the 1-hour TTL, so the short constant never described this traffic. The visible damage was one session repacked three times in an hour on ~10-minute gaps — freeze step 10 → 80 → 160 → 1280, each step re-keying the prefix at 60-98k cache_create. Every one of those turns had just *written* a cache, which the clock could not see. noteCacheOutcome() now feeds each response's usage back into the session store: a cache_read proves the prefix was live, a cache_create proves one was just written. Either way the next turn must not re-cut. Absence of caching is deliberately NOT read as a dead cache. A request with no cache_control marker reports both counters zero for its whole life, and treating that as "cold" repacks the grid on every turn to reclaim something that never existed — the append-only e2e tests caught this, which is why `everCacheAlive` gates it. Cold now means: one existed, and stopped appearing. The clock remains only as a backstop for responses whose accounting never arrived, at an hour rather than five minutes — the point where the measurements say warmth becomes the exception. Repack cost this addresses: 1.41M cache_create tokens across 20 requests, 20% of all create in the sample, a quarter of it spent re-keying caches that were still alive. Two mutations verified against the tests: dropping the everCacheAlive gate fails 3, reverting to the timer fails 5. (cherry picked from commit 570ce26)
Production settled a rule I had guessed. Of 20871 requests on ber-dev-tr-ai the 5xx population was 177 × `529 overloaded`, 2 × `500`, 1 × `503` — and 129 of 250 repacks fired directly after one of them. A 529 means the provider declined to process the request. The prefix cache it never touched is still there, so marking the session dead re-cut the grid and threw a live cache away for nothing. That is the same failure the wall-clock rule had, reintroduced through a blanket `status >= 500`. `responseLeftNoCache` now fires only on a 413 or a 400 whose body says the prompt was too long — the two cases where the request itself was refused for its size. Nothing is lost by dropping the 5xx branch: a cache that genuinely died shows up on the next turn as a response reporting neither a read nor a write, which noteCacheOutcome already handles, accurately and for free. (cherry picked from commit 67bb85ccc66bb2cc97e6eda15859845542c02471)
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
3 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Rebase and split of #161 by @qba-leo-martens onto current
main. All commits retain Leo's authorship — this is his work, reorganised, not reauthored. #161 remains the original record.Opened as a draft: this is for review, not merge.
What changed vs #161
main(post-Strip the billing header wherever it appears, not just line 1 #180, security: add disclosure policy, threat model, and CI audit gate #164, Prompt cache broken almost every turn: per-turn billing header re-injected into system, assumed session-stable #177)..github/workflows/ci.ymlcommit — unrelated to attribution, and it blocks pushes for tokens withoutworkflowscope.Two clusters, and they are not equally ready
Cluster 1 — cache attribution (the actual point of #161). Digest the MARKED span rather than the boundary message; report history-image hash from the history message; divide the dashboard hit-rate by the right field; decide cold from the provider's accounting; treat a transient 5xx as not-a-dead-cache.
This is verified working on live traffic. Sample turn:
That ~35KB delta is the gap the PR exists to surface, and it's non-zero on real traffic.
Cluster 2 — image pricing/caps (
fix(images), ~1,099 lines). This is arguably its own feature PR. It is live-affecting: on the same turn,image_count 65->wire_images 63,collapsed_images 61. It is actively dropping images. It deserves separate scrutiny and possibly separate landing.Known defect, not yet fixed
The branch renames telemetry fields with no migration:
cached_tokenscache_read_tokensinput_tokens(incl. cached)input_tokens(fresh only)Any consumer still reading
cached_tokenssees a cliff to zero at the cutover and will read it as "caching broke". It didn't; the field moved. Historical charts break at the boundary. Worth fixing before merge, or at minimum documenting.Status
Currently running live locally as a soak test since 23:25. Not proposed for merge until cluster 2 gets its own review.