fix(telemetry): both rule arms logged only their hits, so the clear-rate could only read 100% (#3497) #138

Merged
bvandeusen merged 2 commits from dev into main 2026-09-03 07:19:08 -04:00
Owner

write_path_rule reported zero_result_calls: 0 and cleared_threshold: 133/133 — a perfect record no other surface comes near (write_path 421 zeroes of 613, reuse_slot 124/199, auto_inject 114/326). #3311 read that as a measurement, and milestone 333 was scoped on it.

It was an artifact. Both arms called record_retrieval inside a guard on having results — the write-path arm behind if fresh:, the pre-tool arm below if not fresh: return out — so a call that found nothing wrote no row. The statistic was a fact about the shape of the code, true at any threshold whatsoever.

What changed

  • The call log moves out of the guard in both arms. The surfacing log stays in it: nothing was shown, so no surfacing occurred.
  • results=fresh kept deliberately. The note arms pass exclusions into semantic_search_notes, so what they log is already post-exclusion; logging hits here would make this row mean something other than every other row in the same readout.
  • Six regression tests — behavioural for each arm (found nothing; found only what the session already held; searched nothing at all, which must stay silent) plus a structural guard, because this was one level of indentation that appeared independently in two places.
  • test_telemetry_uses_its_own_source had encoded the defect: its assert_called_once passed only because the rule arm skipped its row. Rewritten to assert the source split it was actually about.

The defect bites hardest on the pre-tool arm (#3476), which fires on every Bash call: with no rows at all, a ranker that declined is indistinguishable from a hook that never fired — the silent failure that arm exists to stop.

Why this merges now

The deployed instance is actively writing the contaminated rows that milestone 333 step 4 has to read. Every hour it runs unfixed is analysis window that has to be discarded.

#3311 and the rule_usage module docstring are corrected rather than quietly rewritten — the wrong version stays visible, since the reason to measure the arm survives the correction and is stronger for it.

CI green on dev @ 48804c4 (run 5450, all six jobs).

🤖 Generated with Claude Code

https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ

`write_path_rule` reported `zero_result_calls: 0` and `cleared_threshold: 133/133` — a perfect record no other surface comes near (`write_path` 421 zeroes of 613, `reuse_slot` 124/199, `auto_inject` 114/326). #3311 read that as a measurement, and milestone 333 was scoped on it. It was an artifact. Both arms called `record_retrieval` inside a guard on having results — the write-path arm behind `if fresh:`, the pre-tool arm below `if not fresh: return out` — so a call that found nothing wrote no row. The statistic was a fact about the shape of the code, true at any threshold whatsoever. ## What changed - The **call** log moves out of the guard in both arms. The **surfacing** log stays in it: nothing was shown, so no surfacing occurred. - `results=fresh` kept deliberately. The note arms pass exclusions into `semantic_search_notes`, so what they log is already post-exclusion; logging `hits` here would make this row mean something other than every other row in the same readout. - Six regression tests — behavioural for each arm (found nothing; found only what the session already held; searched nothing at all, which must stay silent) plus a structural guard, because this was one level of indentation that appeared independently in two places. - `test_telemetry_uses_its_own_source` had encoded the defect: its `assert_called_once` passed only because the rule arm skipped its row. Rewritten to assert the source split it was actually about. The defect bites hardest on the pre-tool arm (#3476), which fires on every Bash call: with no rows at all, a ranker that declined is indistinguishable from a hook that never fired — the silent failure that arm exists to stop. ## Why this merges now The deployed instance is actively writing the contaminated rows that milestone 333 step 4 has to read. Every hour it runs unfixed is analysis window that has to be discarded. #3311 and the `rule_usage` module docstring are corrected rather than quietly rewritten — the wrong version stays visible, since the reason to measure the arm survives the correction and is stronger for it. CI green on `dev` @ `48804c4` (run 5450, all six jobs). 🤖 Generated with [Claude Code](https://claude.com/claude-code) https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
bvandeusen added 2 commits 2026-09-03 07:19:03 -04:00
fix(telemetry): both rule arms logged only their hits, so the clear-rate could only read 100% (#3497)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 9s
CI & Build / TypeScript typecheck (push) Successful in 22s
CI & Build / integration (push) Successful in 33s
CI & Build / Python tests (push) Failing after 48s
CI & Build / Build & push image (push) Skipped
154a5de13e
`write_path_rule` reported `zero_result_calls: 0` and `cleared_threshold:
133/133` — a perfect record no other surface comes near (`write_path` 421
zeroes of 613, `reuse_slot` 124/199, `auto_inject` 114/326). #3311 read that
as a measurement and milestone 333 was scoped on it.

It was an artifact. Both arms called `record_retrieval` inside a guard on
having results — the write-path arm behind `if fresh:`, the pre-tool arm
below `if not fresh: return out` — so a call that found nothing wrote no row.
The statistic was a fact about the shape of the code, true at any threshold
whatsoever.

The call log moves out of the guard in both arms. The surfacing log stays in
it: nothing was shown, so no surfacing occurred. `results=fresh` is kept
deliberately — the note arms pass exclusions into `semantic_search_notes`, so
what they log is already post-exclusion, and logging `hits` here would make
this row mean something other than every other row in the same readout.

The defect bites hardest on the pre-tool arm, which fires on every Bash call:
with no rows at all, a ranker that declined is indistinguishable from a hook
that never fired — the silent failure the arm exists to stop.

Tests cover both arms behaviourally (found nothing; found only what the
session already held; searched nothing at all, which must stay silent) plus a
structural guard, because this was one level of indentation and it appeared
independently in two places.

#3311 and the `rule_usage` docstring corrected rather than quietly rewritten.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
fix(tests): the write-path telemetry test asserted the defect, not the split (#3497)
CI & Build / Python lint (push) Successful in 5s
CI & Build / Plugin hooks (push) Successful in 10s
CI & Build / integration (push) Successful in 28s
CI & Build / TypeScript typecheck (push) Successful in 34s
CI & Build / Python tests (push) Successful in 1m8s
CI & Build / Build & push image (push) Successful in 28s
48804c437d
`assert_called_once` held only because the rule arm skipped its retrieval_logs
row when it found nothing. With the arm logging every call, the test now
asserts what it was always about — exactly one `write_path` row, no
`auto_inject`, and the rule arm keeping its own separate source.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_011cPyzNnegXHr5iRMzzy5KJ
bvandeusen merged commit aea7b63b62 into main 2026-09-03 07:19:08 -04:00
Sign in to join this conversation.
No Reviewers
No labels
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: bvandeusen/FabledScribe#138