diff --git a/src/scribe/services/plugin_context.py b/src/scribe/services/plugin_context.py index 3ce4dda..a391c63 100644 --- a/src/scribe/services/plugin_context.py +++ b/src/scribe/services/plugin_context.py @@ -1300,7 +1300,7 @@ async def build_write_path_hint( 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, + is_task=None, results=hits, duration_ms=rule_ms, # What the ranker found and this session had already been told. # Without it a zero row cannot say whether the bar was too high or # the reader was simply ahead of it — and only the first is a @@ -1404,7 +1404,7 @@ async def build_tool_rule_hint( 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, + is_task=None, results=hits, duration_ms=duration_ms, # See the sibling arm. It matters more here: this arm fires on every # Bash call, so a long session excludes its way to an all-zero row # and the threshold looks wrong when nothing about it is. diff --git a/tests/test_rule_usage_wiring.py b/tests/test_rule_usage_wiring.py index f985bae..050ca89 100644 --- a/tests/test_rule_usage_wiring.py +++ b/tests/test_rule_usage_wiring.py @@ -772,3 +772,97 @@ async def test_a_shown_hit_is_not_counted_as_suppressed(): assert out["rule_ids"] == [161] assert log.call_args.kwargs["suppressed"] == 1 assert len(log.call_args.kwargs["results"]) == 1 + + +# ── The identity that falsified this milestone (#3668) ───────────────── +# +# `rule_usage.surfaced` == `pre_tool_rule.cleared` + `write_path_rule.cleared`. +# Milestone #379 was scoped on a reconstruction that put ~64% of ranked rule +# surfacings as never reaching `rule_usage_events`. Five steps were planned +# against it. One read of this identity — 17 = 17, then 39 = 39 on a second +# window — falsified the whole thing: the gap was two counters that started +# recording on different days, not a write path dropping rows. +# +# So the identity is not a nice-to-have. It is the cheapest true statement +# available about this pair of tables, and its absence is what let a magnitude +# that merely LOOKED wrong survive a code review and a five-step plan. An +# identity that must hold exactly beats a magnitude that looks wrong. +# +# WHY THE ARM IS THE RIGHT PLACE TO PIN IT, and the readout is not. Inside an +# arm, one `fresh` list feeds both recorders in one function, so the counts +# cannot legitimately differ — at any limit. The readout-level form is weaker +# than it looks: `cleared_threshold` counts CALLS that beat the bar while +# `surfaced` counts RULES, and those coincide only while `RULEHINT_LIMIT` is 1. +# Raise the limit and the readout identity breaks while nothing is wrong. +# `RULEHINT_LIMIT` has already moved once (2 → 1, `2385100`), and that move is +# half of why the original reconstruction misread its own numbers. +# +# Hence three hits below, where production currently returns at most one. The +# test is deliberately in a state the limit does not permit today, because what +# is being pinned is that the two recorders read the same list — not that the +# list happens to be short. + +_THREE_HITS = [ + (0.81, fake_rule(id=156, title="A wait with no deadline is a bug")), + (0.77, fake_rule(id=157, title="A loop re-arms in a finally")), + (0.74, fake_rule(id=161, title="Reach the forge through its MCP tools")), +] + +_ARMS = [("write_path_rule", _run_arm), ("pre_tool_rule", _run_tool_arm)] + + +def _both_ends(log, rec, source): + """What the two recorders said about one call, at the same grain. + + Ids rather than counts. Equal counts drawn from different lists is a real + way for this to break — an off-by-one slice, or one recorder reading `hits` + where the other reads `fresh` in a window where the exclusion happened to + remove as many as it added — and a count comparison would call that agreement. + """ + rows = [c for c in log.call_args_list if c.kwargs.get("source") == source] + assert len(rows) == 1, ( + f"expected exactly one {source} call row, got {len(rows)} — the " + f"identity is per call and cannot be read across several" + ) + logged = [rule.id for _score, rule in rows[0].kwargs["results"]] + surfaced = [ + rid + for c in rec.call_args_list if c.kwargs.get("source") == source + for rid in c.kwargs["rule_ids"] + ] + return logged, surfaced + + +@pytest.mark.parametrize(("source", "run"), _ARMS, ids=["write_path", "pre_tool"]) +@pytest.mark.parametrize( + ("excluded", "expected"), + [([], 3), ([157], 2), ([156, 157, 161], 0)], + ids=["nothing-held", "one-already-held", "all-already-held"], +) +@pytest.mark.asyncio +async def test_both_recorders_report_the_same_rules_for_one_call( + source, run, excluded, expected +): + """One list, two tables, no room to disagree. + + The middle case is the one that discriminates. With nothing excluded both + recorders see the same three rules however wrongly they are wired, so an + arm logging `hits` to the call log and `fresh` to the surfacing log passes + that case and fails this one — and logging `hits` is exactly the divergence + that would manufacture an apparent write loss out of a correct system. + """ + log, rec = MagicMock(), MagicMock() + await run(list(_THREE_HITS), rec, retrieval_log=log, exclude_rule_ids=excluded) + + logged, surfaced = _both_ends(log, rec, source) + assert surfaced == logged, ( + f"{source} told its two tables different stories about one call: the " + f"call log recorded {logged} and the surfacing log recorded {surfaced}. " + f"Both come from `fresh`, in one function, so any difference is a bug " + f"in the wiring — and it is the shape that reads as a lost write when " + f"the two tables are later compared in aggregate (#3668)." + ) + assert len(logged) == expected, ( + "the fixture stopped exercising what it claims to; check the exclusion " + "filter still runs before both recorders" + )