fix(sweep): stop crediting declined turns, see the prefix bust, and name the fallback failure - #211
Conversation
… on a write ExtractSweep.Offload has two return paths and only the tail one set rep.Skipped, so every turn that declined at the inventory floor -- which is every turn outside the pre-expiry window, where phase 1 collects no candidates at all -- reported itself as having mutated the request. dash/event.go computes Mutated as !Reverted && !Skipped, and GateN is a no-op at n<=0, so those turns recorded neither a gate nor a skip: 29,321 of 29,372 production rows read mutated=1, acted=0, skipped=0. No dollar figure is affected (acted derives from saved_gross and is correct); the mutated census is. Guard the outcome once in a defer so both exits and any future one are covered. Separately, sweep_prefix_cache_read_ZERO tested only for a zero cache read, so a PARTIAL hit silenced it however large the write. Three production asks re-created the agent's own prefix for 704,925 opus cache_write tokens, $3.42 and 73% of this component's entire spend -- and two of the three had read 39,805 tokens of a stable sub-prefix, leaving $2.26 of that uncounted. A read is not evidence against a write: count them separately, since they name different failures with different fixes. Signed-off-by: Osher-Elhadad <Osher.Elhadad@ibm.com>
The proxy writes cg.db and cg-control.db with default names into whatever directory it is started from, so a proxy run inside a checkout leaves production-shaped tenant data in the working tree -- untracked, but one git add -A away from being committed to a repo with three remotes. Found while preparing this branch: cg.db and cg-control.db were both sitting untracked in the working tree. Both were 0 bytes with no tables, so nothing leaked this time. Signed-off-by: Osher-Elhadad <Osher.Elhadad@ibm.com>
The question "would the free character window have done as well as the paid model leg?" had never been measured, and it is the one arm that answers it without spending anything: with model == nil, strategyOrder collapses to ["deterministic"] and no call is issued. Skips without CG_H0_DIR, so it costs CI nothing, and the doc comment carries the export query so the corpus can be rebuilt from any dashboard DB. Two things the comment records because they decide how the output may be read. before_gz is capped at defaultContentCap = 16<<10 BYTES, so 46.4 % of production blobs are truncated and must be excluded. And the untruncated population tops out at 6,405 candidate tokens, so the 8-15k band -- the only size band whose measured cost per MTok saved clears break-even -- has no representation at all, and 62 % of the corpus sits below 3k where the paid leg is already underwater. The comparison is therefore biased toward the free leg and cannot speak to the paid leg's one winning case. Filename note in the source too, because it cost real time: a file ending _arm_test.go is read by Go as the GOARCH filename build constraint, lands in IgnoredGoFiles everywhere else, and 'go test' then reports "no tests to run" and PASSES. The first version of this file was silently never compiled. Signed-off-by: Osher-Elhadad <Osher.Elhadad@ibm.com>
Widening the prefix-counter condition to admit a partial hit that WROTE also put the block_fallback branch on that path, where it still said "the prefix ask read nothing from cache" -- false when CacheRead is 39,805 and the write is 260,604. Branch the reason so the two cases stay distinguishable. Two things the new test records rather than fixes, because both are pre-existing and neither is covered by the evidence behind this branch. The Rejection string is unreachable today: on this path the fallback deliberately never runs, so foldFallback returns early, rec.Component stays "" and Offload discards the whole row on its `call.rec.Component != ""` guard -- the same missing-row class the comment at foldFallback documents for the no-asker path. Adding a row where none existed is a behaviour change, so the test asserts the counters instead, which are what a reader actually gets. And state the behaviour change plainly: block_fallback: true previously declined only on a zero read and now also declines on any partial hit that wrote. A write on the agent own prefix bills at 1.25x fresh on the agent model rather than a tenth of it, so declining is the point of the switch -- but it is a policy change to a config-gated brake, not just a counter split. Signed-off-by: Osher-Elhadad <Osher.Elhadad@ibm.com>
Carries the per-band cost measurement (873 production calls) and the per-session replay multiplier, and derives the floor from them, so the next edit has to argue with the data. No config literal changes: the shipped 3000 already clears the derived bound of 2000. Two corrections are baked into the guard because the first version of it had both. It named a constant `intervalTop` and gave it $14.71, which is the MEDIAN token value, not the ceiling; the p90 is $31.25, and with the median standing in for the top the same rule selects 5000 instead of 2000 -- it reversed the direction of a config change. That number has now moved three times on the same 873 calls: an imported k=12 from another corpus, k=12 again through a mislabelled band, and the median through a constant NAME. And it asserts a LOWER BOUND rather than an equality. A higher floor only ever declines so it cannot hurt the agent, and the bands are non-monotonic in cost (2-3k at $14.27 is cheaper than 3-5k at $15.76), which puts the ordering inside the noise of 25-359 calls per band. Equality would pin the literal to a rule fitting that noise. The open-ended top band is skipped explicitly: treating its sentinel as a token count would derive a floor of that size and silently disable the component. Signed-off-by: Osher-Elhadad <Osher.Elhadad@ibm.com>
Review: revert-verified all three fixes, plus two findings the tests do not coverReviewed at Data boundary: every production figure in the description (the 220,933-request / 16-day corpus, the 29,321/29,372 row split, the $3.42 / 704,925-token prefix write, the band economics) is not verifiable within the data boundary — no reviewer here read the service database or any export of it. Those numbers are treated as given; what was checked is the mechanism behind each, against the code. Real run results
Per-package counts that actually RAN (non-race): The filename trap does not recur.
Of the 19 SKIPs, one is new: Revert-verification — each defect restored to its original form
That last one answers the question worth asking of any test that pins a measured number: the floor is genuinely derived, by looping the bands table against Mechanism spot-checks behind the three: FindingsMinor · Go runs deferred functions during a panic. If Traced every consumer: Minor · commit The commit message says the new
So the row is built, retained, and carries the new string. An independent probe test (written, run, deleted) confirmed it: with Net: the string is live in production and has zero test coverage of its content, because the coverage was skipped on a premise that does not hold. Given this PR's own words that this column "has already been mis-analysed twice, so a wrong reason here becomes a wrong finding later," that is the one gap I would close — a Minor · docs · Nit · the "both exits" coverage claim does not hold. Both subtests of Nit · the headline production shape is untested. Request 175582 had Checked and clean
Cross-PR note (#212, #211, #196)Unlike the previous trio, these three do not collide: merged onto |
…c half-state 549714c's rationale for skipping a test on the new Rejection string was wrong: it claimed rec.Component stays "" on this decline path, so Offload's `call.rec.Component != ""` guard drops the row. That premise only holds for the existing unit tests' own `rep := &components.Report{}`. In production, pipeline.go's runOne sets rep.Component = comp.Name() before any component runs, and extract_sweep.go assigns r.rec.Component from rep.Component before this decline branch is reached -- so the row survives, lands in rep.Calls, and the branched Rejection string is exactly what an operator reads on extraction_calls.rejection. Add a test that sets rep.Component the way the pipeline does and asserts the published string, and correct the stale "row is discarded" claim left on the neighboring test's doc comment. Also close a half-state the deferred Skipped-guard (introduced earlier in this branch) made reachable: that defer can run during the same panic unwind that reaches runOne's recover, which sets Reverted without clearing Skipped, so a Report could end up with both true -- which dash/event.go's Mutated derivation and any future "skipped rows" query would misread. Clear Skipped alongside Reverted in the one place all components' panics route through. And add sweep_prefix_cache_write to the counters list in docs/components/extract_llm_sweep.md, which 549714c's own change had left stale. Signed-off-by: Osher-Elhadad <Osher.Elhadad@ibm.com>
|
Addressed the review at pull/211#issuecomment-5558475749. Pushed Verified the finding firstRe-derived the mechanism at this HEAD before changing anything: What changed
Revert-verification (source mutated, never the test)New Rejection test — reverted the branched reason to the pre-PR flat string in FAILED, naming its own subject: Restored the file, rebuilt, reran: PASS. Panic half-state test — removed the new FAILED, naming its own subject: Restored the file, rebuilt, reran: PASS. Ready-checklist
Decided NOT to change, and whyThe review's two remaining "Nit" items (as opposed to the "Minor" items above) are left as-is:
Both are testing-coverage suggestions the review itself marks as lower severity than the two "worth |
What this changes
Three defects found while measuring
extract_llmandextract_llm_sweepover the 16-dayproduction corpus (220,933 requests, 892 model calls). Two are telemetry, one is economics.
Every figure below carries the query or the
file:linebehind it; full working incg-research/results/extractllm-findings.mdand the page atcg-research/artifacts/extract-llm-deep-dive.html.Mechanism claims are read at the deployed commit
3a1b438, not atmain— prod runs aside branch that is 2 commits ahead of and 22 behind
main. All three defects are live onmainas well, which is why they are fixed here rather than merely reported.1.
ExtractSweep.Offloadreportedmutatedfor turns it declinedOffloadhas two return paths and only the tail one setrep.Skipped. The inventory floorreturns early:
Outside the pre-expiry window phase 1 collects no candidates at all, so
len(cands) = 0 < 10,the early return fires, and
dash/event.go'sMutated = !Reverted && !Skippedreadstrue.GateNis a no-op atn <= 0, so those turns recorded neither a gate nor a skip.29,321 of 29,372 production rows read
mutated=1, acted=0, skipped=0:sweep_offeredis emitted before the floor check, so it partitions the two exits cleanly: all8 correctly-skipped rows have it, only 7 of the 29,321 do, and those same 7 are the only ones
with a non-zero
sweep_inventory_below_min. 29,310 + 4 + 7 = 29,321 exactly.No dollar figure is affected —
actedderives fromsaved_grossand is correct. What iswrong is the
mutatedcensus: the component is credited with 29,364 mutations, of which 29,321are a component that declined. Fixed by guarding the outcome once in a
defer, so both exitsand any future one are covered; the duplicated tail check is what went wrong here.
2.
sweep_prefix_cache_read_ZEROcould not see the harm it exists to catchThe counter tested
usage.CacheRead == 0, so a partial hit silenced it however large thewrite. The prefix ask's whole justification is that it reads the agent's cached prefix; when
the entry has gone it writes it instead, at 1.25× fresh on the agent's own model rather than
a tenth of it — which is precisely what
extract_econ.gocited when it rejected prefix reuse.Three production asks did exactly that, for 704,925 opus
cache_writetokens = $3.42 = 73 %of this component's entire spend. Two of the three had read 39,805 tokens of a stable
sub-prefix, so
CacheRead == 0was false and $2.26 of the $3.42 went uncounted:Now counted separately as
sweep_prefix_cache_write, because a zero read and a non-zero writename different failures with different fixes. The existing counter keeps its exact meaning.
Worth recording alongside the fix, since it bears on whether to re-enable the component: on all
three turns the agent's own request also re-created its prefix, so the sweep walked into a
miss rather than causing one. But the trigger guarantees that —
sweeping()fires only when0 < CacheTTLMs − IdleMs <= 60 s, i.e. in the last minute of the entry's life, which is when aprefix re-read is most likely to fail. No window width fixes that; the permission to act and the
need for a live prefix are mutually exclusive by construction.
3.
block_fallbacksaid the wrong thing about which failure it declined onWidening the condition in change 2 also put the
blockFallbackbranch on the partial-hit path, whereit still wrote "the prefix ask read nothing from cache" — false at
CacheRead = 39,805with a260,604-token write. Branched, so the two cases stay distinguishable.
One thing worth stating plainly, and a correction to how this section originally described the
string's reach:
section originally claimed
rec.Componentstays""on this path, soOffloaddiscards the rowon its
call.rec.Component != ""guard, and it shipped only a counters test on that premise. Thatpremise held for the unit test's own
rep := &components.Report{}, but not for production:components/pipeline.go'srunOnesetsReport{Component: comp.Name(), ...}before any componentruns, and
extract_sweep.goassignsr.rec = components.ModelCall{Component: rep.Component, ...}before the
block_fallbackbranch is ever reached. So the row survives, reachesrep.Calls, andthe branched
Rejectionstring is exactly what an operator reads onextraction_calls.rejection—the column this same PR calls out as already mis-analysed twice. Added
TestBlockFallbackDecliningAWritePublishesTheCorrectRejection, which setsrep.Componentthe waythe pipeline does and asserts the exact published string.
block_fallback: truepreviously declined only on azero read and now also declines on any partial hit that wrote. A write on the agent's own prefix
bills at 1.25× fresh on the agent's model rather than a tenth of it, so declining is the point of
the switch — but this is a change to a config-gated brake, not just a counter split.
4.
cg.dbandcg-control.dbsit untracked, and*.dbis not ignoredThe proxy writes its dashboard and control DBs with default names into whatever directory it is
started from, so a proxy run inside a checkout leaves production-shaped tenant data in the working
tree — untracked, but one
git add -Aaway from a repo with three remotes. Both files were 0 byteswith no tables, so nothing leaked this time. Three lines of
.gitignore.5. The floor guard: the measurement, not the literal — and no literal changes
An earlier version of this branch raised
housellm'smin_tokensfrom 3,000 to 5,000. Dropped.The guard that replaces it carries the per-band cost measurement and the per-session replay
multiplier and derives the floor from them, so the next edit has to argue with the data. It asserts
the shipped 3,000 as a lower bound, and it currently passes.
Two corrections are baked in because the first version of the guard had both:
intervalTopand gave it $14.71, which is the MEDIAN token value, not theceiling. The p90 is $31.25. With the median standing in for the top, the same rule selects 5,000
instead of 2,000 — it reversed the direction of a config change. That number has now moved three
times on the same 873 calls: an imported k=12 from another corpus, k=12 again through a mislabelled
band, and the median through a constant's name.
non-monotonic in cost (2–3k at $14.27 is cheaper than 3–5k at $15.76), which puts the ordering
inside the noise of 25–359 calls per band. Equality would have pinned the literal to a rule fitting
that noise.
The open-ended top band is skipped explicitly: treating its sentinel as a token count would derive a
floor of that size and silently disable the component.
6. The deterministic-only arm, as a runnable test
The question "would the free character window have done as well as the paid model leg?" had never
been measured, and it is the one arm that answers it without spending anything: with
model == nil,strategyOrdercollapses to["deterministic"]and no call is issued. Skips withoutCG_H0_DIR, soit costs CI nothing; the doc comment carries the export query and both internal-validity limits.
One gotcha recorded in the source because it cost real time: the first version of this file was
named
..._arm_test.go, which Go reads as the GOARCH filename build constraint. It landed inIgnoredGoFileson amd64 andgo testreported "no tests to run" and exited 0 — a green pass fora test that never executed. Detect that class with
go list -f '{{.IgnoredGoFiles}}' ./..., never with an exit code.Tests
Seven, and each guarding changed logic was confirmed to fail without its fix:
TestSweepDeclinedAtInventoryFloorReportsSkipped— both exits, table-driven. Reverted, itreproduces the production row shape exactly:
gates: map[not_in_pre_expiry_window:1]withSkipped=false, which is request 141575.TestSweepPrefixWriteTripsTheCounterEvenOnAPartialHit— asserts the write counter fires on a39,805-token read with a 260,604-token write, and that the zero-read counter does not, so
the two are not collapsed.
TestBlockFallbackDistinguishesAZeroReadFromAWrite— table-driven over both cases, asserting theright counter fires, the wrong one does not, and a declined ask leaves the transcript untouched.
TestBlockFallbackDecliningAWritePublishesTheCorrectRejection— assertsrep.Callsitself, withrep.Componentset the waypipeline.gosets it in production; see the correction to section 3above.
TestPanicClearsSkippedSetByTheComponentsOwnDefer— a component's own deferredSkipped-guard(the pattern this PR's fix feat: Go context-engineering proxy/library (tree-sitter, TOON, Starlark extractor, config, metrics, real integrations) #1 introduced) can run during the same panic unwind that reaches
runOne'srecover, which setsReverted. FixedrunOneto clearSkippedthere, so aReportnever carries both — closing a half-state fix feat: Go context-engineering proxy/library (tree-sitter, TOON, Starlark extractor, config, metrics, real integrations) #1's own defer made newly reachable.TestHousellmFloorClearsTheBandsThatLoseAtEveryK— passes at the shipped 3,000, and verified tofail at 1,000 with the derived bound of 2,000 named in the message.
TestDeterministicOnlyArmOverCapturedBodies— a measurement harness rather than a guard; skipswithout its corpus.
Also added
sweep_prefix_cache_writeto the counters list indocs/components/extract_llm_sweep.md, which had gone stale for this PR's own change (no codewiring needed —
metrics/metrics.goandproxy/promexport.goalready iterate gates generically).go build ./...,go vet, andgo test ./...are green.Deliberately not in this PR
Five things this investigation measured and is not shipping. Each is in the write-up with its
query.
housellmliteral from 3,000to 5,000 and I committed it. Withdrawn and dropped from the branch. The break-even band it
rested on was mislabelled: solving
$4.755 + (k−1)×$0.3814for the three printed values givesk = 3.80 / 12.00 / 27.11, so the middle figure was not this corpus's median but the 12.0
imported from
docs/components/extract_llm.mdand measured elsewhere. The measured band is$5.82 / $14.71 / $31.25, and at it the change is worth +$1.27 / +$0.13 / −$1.99 — $0.13 at
the median, on a 7 % overshoot well inside the noise of a 70-session median. The rule the guard
encoded now selects 2,000, which the shipped 3,000 already clears. The real exposure is six
tenants overriding
min_tokensto 500, which is a deployment fix.stored in full shows the free window removes 2.56× more tokens for $0.00, and class-gated
routing would avoid $4.51 of $5.02 and 3,619 s. Declined: the window keeps a median 33.1 %
of characters and drops 44.2 % of identifiers against the paid program's 30.8 %. And the
paired corpus excludes the paid leg's only winning size band entirely — max candidate is 6,405
tokens, so the 8–15k band at $4.05/MTok has zero representation — which biases the comparison
toward the free arm. The next measurement is reward and steps, not tokens.
on whether it removed anything: 7 removal turns wrote 3,363,850 agent
cache_writetokensagainst 4 same-idle-band controls' 4,907 — 686× at comparable growth, all ten accepted rows at
≤0.196 cache warmth and all four no-removal warm rows at ≥0.997, and one request that grew by
exactly zero tokens and wrote 592,279.
extract_llmrefuses depth, so the sweep is the onlycomponent editing inside the already-cached region, and a mid-history edit re-hashes everything
after it. Revised net −$19.6 to −$27.2, not the ledger's −$3.60 (attributed, not proven; n=7
vs 4). Its own premise fails too: it fired on a live cache on 13 of 19 requests and on a
genuinely expired one once.
free content predictor pays across the band.
looksLikeFileRead— the predicate the codebasealready has, whose comment calls line-numbered dumps irreducible — is net negative at every
point, because those are the most profitable class the component sees (83 calls, 71.1 %
acceptance, 169,171 tokens saved).
are programs the interpreter could not run, but they are ~six distinct bugs rather than one. The
reply-budget theory is refuted — only 5 of 39 cut-off replies reach 4,000 output tokens
against a 4,096 cap; the median is 859. The two small ones are the
while-loop refusal (8 calls)and taking the first fenced block rather than only a leading one (5 calls;
stripFencesatinternal/extract/extract.go:397strips only a leading fence). Together $0.22, and everyprompt edit re-runs the acceptance corpus by design.
Two defects reported earlier in this investigation that turned out not to exist
Recorded because both were mine and both flattered the conclusion:
saved_usdis gross and nothing nets the component's own spend."dash/query.go:876computes
NetUSD = SavedUSD − LLMCostUSDin the deployed binary, anddash/ui/app.js:2602-2611already flags any component whose amortised and first-removal verdicts disagree in sign — which is
exactly this component's situation, spelled out for the operator. The figure was on the dashboard
the whole time.
every token column and
cost_usdat zero. The upstream never billed them, soEvent.Price'searly return is correct. I priced a "$5.69 correction" by falling through to the fresh-input branch
on rows with no token data; a reviewer independently produced the same error at $0.90. It is a
property of the column —
saved_gross > 0on an unbilled request — not of either of us.Scope note
extract_llm_sweepwas removed from all nine tenant configs on 2026-09-03, so changes 1 and 2 haveno effect on current production traffic. They are shipped because the code is still reachable, and
because change 2 is the instrument anyone would need before deciding whether to re-enable it — a
decision the measurement above says should be no.
Net cash impact of this PR: $0. Its value is that a component reporting a decline as a mutation,
and a tripwire that could not see the harm it was built for, are how the sweep ran for three days
unexamined.