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
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
`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
This commit is contained in:
@@ -1218,24 +1218,43 @@ async def build_write_path_hint(
|
||||
"does not apply; it is not in this session's loaded set."
|
||||
)
|
||||
rule_ids.append(rule.id)
|
||||
# TWO tables, and the split is not arbitrary. retrieval_logs is one
|
||||
# row per CALL, keyed on the score distribution a threshold is tuned
|
||||
# from. rule_usage_events is one row per RULE per event, which is the
|
||||
# grain "was this hint ever acted on" needs and the grain a JSONB
|
||||
# result_ids array cannot be indexed at.
|
||||
#
|
||||
# This comment used to say rule ids had nowhere to go — that
|
||||
# note_usage_events remaps ids on restore, so a rule id there would
|
||||
# return attached to whatever note took that number. That is still
|
||||
# true of the NOTE table, and it is exactly why rule_usage_events is
|
||||
# its own (milestone 333 step 1). The gap it described is closed.
|
||||
#
|
||||
# THE CALL LOG IS UNCONDITIONAL; THE SURFACING LOG IS NOT, and the
|
||||
# asymmetry is the correction #3497 exists to make. Both used to sit
|
||||
# inside an `if fresh:`, which is how this arm came to report
|
||||
# `zero_result_calls: 0` and `cleared_threshold: 133/133` — not a
|
||||
# perfectly tuned surface but one structurally unable to record its
|
||||
# own misses. #3311 read that artifact as a measurement and a whole
|
||||
# milestone was scoped on it. A call that found nothing is the ONLY
|
||||
# evidence a threshold is set too high, and it is the row every note
|
||||
# surface has always written (write_path: 421 zeroes of 613 calls;
|
||||
# auto_inject: 114 of 326). A SURFACING is different in kind: nothing
|
||||
# was shown, so no such event occurred, and its log stays guarded.
|
||||
#
|
||||
# `results=fresh`, not `hits`: the note arms pass their exclusions
|
||||
# INTO semantic_search_notes, so what they log is already
|
||||
# post-exclusion. semantic_search_rules takes no such parameter and
|
||||
# this filter is where the equivalent happens — logging `hits` would
|
||||
# quietly make this row mean something other than every other row in
|
||||
# the same readout.
|
||||
record_retrieval(
|
||||
user_id=user_id, source="write_path_rule", query=code or path,
|
||||
threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT,
|
||||
project_id=project_id,
|
||||
is_task=None, results=fresh, duration_ms=rule_ms,
|
||||
)
|
||||
if fresh:
|
||||
# TWO tables, and the split is not arbitrary. retrieval_logs is one
|
||||
# row per CALL, keyed on the score distribution a threshold is
|
||||
# tuned from. rule_usage_events is one row per RULE per event,
|
||||
# which is the grain "was this hint ever acted on" needs and the
|
||||
# grain a JSONB result_ids array cannot be indexed at.
|
||||
#
|
||||
# This comment used to say rule ids had nowhere to go — that
|
||||
# note_usage_events remaps ids on restore, so a rule id there would
|
||||
# return attached to whatever note took that number. That is still
|
||||
# true of the NOTE table, and it is exactly why rule_usage_events
|
||||
# is its own (milestone 333 step 1). The gap it described is closed.
|
||||
record_retrieval(
|
||||
user_id=user_id, source="write_path_rule", query=code or path,
|
||||
threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT,
|
||||
project_id=project_id,
|
||||
is_task=None, results=fresh, duration_ms=rule_ms,
|
||||
)
|
||||
# `rule_ids` is `fresh`, i.e. AFTER exclude_rule_ids. A rule the
|
||||
# session already holds was considered and not shown, and counting
|
||||
# it would inflate the denominator with claims the agent never saw
|
||||
@@ -1319,6 +1338,21 @@ async def build_tool_rule_hint(
|
||||
|
||||
already = set(exclude_rule_ids or [])
|
||||
fresh = [(score, rule) for score, rule in hits if rule.id not in already]
|
||||
|
||||
# Logged BEFORE the early return, for the reason spelled out at length
|
||||
# on the write-path arm above: a call that found nothing is the only
|
||||
# evidence a threshold is too high, and an arm that logs only the calls
|
||||
# it liked reports a flawless clear-rate however badly it is tuned.
|
||||
# This arm shipped with the same defect inherited from its sibling, and
|
||||
# it mattered more here — a surface with no rows at all cannot be told
|
||||
# apart from a hook that never fired, which is precisely the silent
|
||||
# failure the arm was built to stop.
|
||||
record_retrieval(
|
||||
user_id=user_id, source="pre_tool_rule", query=query,
|
||||
threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT,
|
||||
project_id=project_id,
|
||||
is_task=None, results=fresh, duration_ms=duration_ms,
|
||||
)
|
||||
if not fresh:
|
||||
return out
|
||||
|
||||
@@ -1335,12 +1369,6 @@ async def build_tool_rule_hint(
|
||||
)
|
||||
rule_ids.append(rule.id)
|
||||
|
||||
record_retrieval(
|
||||
user_id=user_id, source="pre_tool_rule", query=query,
|
||||
threshold=cfg["rule_threshold"], limit=RULEHINT_LIMIT,
|
||||
project_id=project_id,
|
||||
is_task=None, results=fresh, duration_ms=duration_ms,
|
||||
)
|
||||
# RANKED, not ambient: this arm chose what it showed, so a pull can
|
||||
# settle whether the choice was any good. `rule_usage.RANKED_SOURCES`
|
||||
# carries the same name.
|
||||
|
||||
@@ -12,11 +12,23 @@ Two event streams, deliberately independent:
|
||||
|
||||
WHY THIS ARM AND NOT ANOTHER. Every other surface declines most of the time —
|
||||
`write_path` returns nothing on 78% of calls, `reuse_slot` on 79%, auto-inject
|
||||
on 39%. The rule arm has never once returned nothing (#3311). That is either a
|
||||
perfectly tuned surface or a bar it cannot fail to clear, and `retrieval_logs`
|
||||
cannot tell the two apart: it records what the ranker scored, never whether the
|
||||
hint was any use. The ratio these two streams produce is the missing half, and
|
||||
without it any threshold change is a number picked off a histogram.
|
||||
on 39%. The rule arm APPEARED never to have returned nothing (#3311), and this
|
||||
docstring used to put that forward as the puzzle worth measuring: "either a
|
||||
perfectly tuned surface or a bar it cannot fail to clear".
|
||||
|
||||
It was neither, and the correction belongs here rather than being quietly
|
||||
deleted. The arm wrote its `retrieval_logs` row only on calls that FOUND
|
||||
something (#3497), so `zero_result_calls` sat at 0 and `cleared_threshold` at
|
||||
`calls` because of the shape of the code — at any threshold whatsoever. A
|
||||
statistic that could not vary was read as a finding about the corpus. It is the
|
||||
#2663 failure mode one level up: there the broken readout was a zero, here it
|
||||
was a hundred percent, which is far better camouflage.
|
||||
|
||||
The reason to measure this arm survives the correction, and is stronger for it.
|
||||
`retrieval_logs` records what the ranker scored, never whether the hint was any
|
||||
use, so even an honest clear-rate would not settle the question. The ratio these
|
||||
two streams produce is the missing half, and without it any threshold change is
|
||||
a number picked off a histogram.
|
||||
|
||||
Design notes, mirroring `note_usage`:
|
||||
- Writes are fire-and-forget through `background.spawn`, so telemetry never
|
||||
|
||||
Reference in New Issue
Block a user