diff --git a/plugin/.claude-plugin/plugin.json b/plugin/.claude-plugin/plugin.json index bf28a89..f90277a 100644 --- a/plugin/.claude-plugin/plugin.json +++ b/plugin/.claude-plugin/plugin.json @@ -1,7 +1,7 @@ { "name": "scribe", "description": "Scribe for Claude Code: connects the scribe MCP server, adds the hooks that deliver live project state and relevant records at the right moment, ships the shared client-neutral Scribe skills (using-scribe, writing-plans, reporting-back, systematic-debugging, verification, brainstorming, reusing-code, shape-accounting), and syncs your saved Scribe Processes as skills (/scribe:sync).", - "version": "2026.09.21.0452", + "version": "2026.09.21.0503", "author": { "name": "Bryan Van Deusen" }, diff --git a/plugin/hooks/scribe_defs.sh b/plugin/hooks/scribe_defs.sh index fbd570d..02ed033 100644 --- a/plugin/hooks/scribe_defs.sh +++ b/plugin/hooks/scribe_defs.sh @@ -525,37 +525,6 @@ scribe_contract_block() { return 0 } -# ── The session slippage readout (#4216, milestone 419) ─────────────────── -# -# WHAT IT ANSWERS, AND WHY IT CANNOT BE ASKED OF THE SERVER. Which rules fired -# this session, which changed an action, which did not. `rule_usage_events` -# carries no session column — it is per user over a window — so a -# session-scoped answer has to be assembled where a session is a thing that -# exists. That is here, from ledgers four hooks already write: -# -# .rules.ids an arm NAMED the rule (a teaser was shown) -# .opened.ids the session called get_rule (#4100, an observed event) -# .acted.ids the session called rule_outcome (#4216) -# .checkpoint.ids the rule HELD an act (#4214, the strongest) -# -# EVERY LINE IS AN OBSERVED TOOL CALL. Nothing here asks the model what it -# followed — milestone 386 ruled that out, and rightly: a model asked "did you -# apply rule 156?" will say yes. These four files record what HAPPENED. -# -# THE SUBTRACTIONS ARE THE POINT. Named-minus-opened is the arm talking to -# nobody; opened-minus-acted is the milestone's whole subject, a rule read and -# then indistinguishable from one that worked. Neither is an accusation — a -# rule may be read and correctly judged not to apply — which is why the lines -# below ask for the leftovers to be CARRIED, not explained. -scribe_ledger_ids() { - # Live ids from one ledger as space-separated words, for set arithmetic. - # Aged through scribe_rules_live so a rule named two hours ago does not read - # as something this context still holds; a bare-id ledger (the checkpoint - # one) simply has no stamps and survives the ageing unchanged. - local f="$1" - [ -n "$f" ] && [ -f "$f" ] || return 0 - scribe_rules_live "$f" | tr ',' ' ' -} scribe_slippage_lines() { # $1 state dir, $2 sanitised session id. @@ -573,10 +542,16 @@ scribe_slippage_lines() { # skip it. local dir="$1" sid="$2" named opened acted held [ -n "$dir" ] && [ -n "$sid" ] || return 0 - named=$(scribe_ledger_ids "$dir/${sid}.rules.ids") - opened=$(scribe_ledger_ids "$dir/${sid}.opened.ids") - acted=$(scribe_ledger_ids "$dir/${sid}.acted.ids") - held=$(scribe_ledger_ids "$dir/${sid}.checkpoint.ids") + # THE TWINS, not the exclusion ledgers. This runs at the compaction, which + # is the moment the exclusion ledgers are about to be cleared and the moment + # their TTL has usually already eaten the early part of a long session. A + # readout built on them would report only the last stretch of the session + # and read as though it had reported all of it — the #3311 shape, and the + # one this milestone exists to stop producing. + named=$(scribe_ledger_kept "$dir/${sid}.rules.keep.ids") + opened=$(scribe_ledger_kept "$dir/${sid}.opened.keep.ids") + acted=$(scribe_ledger_kept "$dir/${sid}.acted.keep.ids") + held=$(scribe_ledger_kept "$dir/${sid}.checkpoint.keep.ids") [ -n "$named$opened" ] || return 0 local unread unresolved @@ -790,10 +765,42 @@ scribe_rules_live() { # Append surfaced ids, stamped. Reads ids on stdin, one per line — the shape # `scribe_json_list "$flat" '.rule_ids'` already produces at both call sites. scribe_rules_append() { + # Writes TWO files, and the second one is the point (#4217). + # + # `$f` is an EXCLUSION ledger: it answers "does this context already hold + # this?", so it is aged by TTL and swept at every compaction — after a + # compaction the agent genuinely does not hold what it was shown, and + # forgetting is correct. Three hooks depend on exactly that. + # + # The twin is an EVIDENCE ledger: it answers "did this happen?", which no + # compaction can make untrue. It is never aged and never swept. + # + # These are opposite lifetimes and `.opened.ids` was serving both, which is + # how a session with 45 `get_rule` calls came to report none: the compaction + # cleared the ledger that was also the record. Measured across six sessions + # on this instance — 208 opens, 3 surviving — before the split. + # + # DERIVED HERE rather than listed at the call sites, because a list is what + # broke this before (see `scribe_clear_session_ledgers`). Every ledger + # written through this function gets its twin, including the next one + # somebody adds. The cost is a second small file per ledger per session. local f="$1" now [ -n "$f" ] || return 0 now=$(date +%s 2>/dev/null) || now=0 - awk -v ts="$now" 'NF { print $1 "\t" ts }' >> "$f" 2>/dev/null || true + awk -v ts="$now" -v keep="${f%.ids}.keep.ids" ' + NF { line = $1 "\t" ts; print line; print line >> keep } + ' >> "$f" 2>/dev/null || true +} + +scribe_ledger_kept() { + # Ids from an EVIDENCE twin: deduped, order preserved, NOT aged. A rule + # opened two hours ago was still opened, so the TTL that keeps an exclusion + # ledger honest would here delete the finding. + local f="$1" + [ -n "$f" ] && [ -f "$f" ] || return 0 + awk -F'\t' '$1 != "" && !seen[$1]++ { + out = out (out == "" ? "" : " ") $1 + } END { if (out != "") print out }' "$f" 2>/dev/null || true } # The OPENED ledger's contribution to a rule arm's query string (#4100). @@ -853,6 +860,11 @@ scribe_checkpoint_allowed() { [ "$n" -ge "$_SCRIBE_CHECKPOINT_CAP" ] && return 1 fi printf '%s\n' "$id" >> "$f" 2>/dev/null || return 1 + # The evidence twin, beside the cap rather than instead of it. `$f` is swept + # at a compaction and SHOULD be: after one, this context has not read the + # rule, so the budget to stop an act on it is honestly fresh. That a stop + # already happened is a different claim, and it stays true. + printf '%s\n' "$id" >> "${f%.ids}.keep.ids" 2>/dev/null || true return 0 } @@ -914,10 +926,19 @@ scribe_held_query() { SCRIBE_LEDGER_DIRS="scribe-priorart scribe-autoinject" scribe_clear_session_ledgers() { - local sid="$1" dir + # SPARES `*.keep.ids`, which are evidence rather than exclusions — see + # `scribe_rules_append`. Everything else still goes: the convention is + # unchanged and still covers a ledger added tomorrow, which is what the + # block above insists on. The twin opts OUT by its name, so a new ledger is + # born on the swept side unless somebody says otherwise. + local sid="$1" dir f [ -n "$sid" ] || return 0 for dir in $SCRIBE_LEDGER_DIRS; do - rm -f "${TMPDIR:-/tmp}/$dir/$sid"*.ids 2>/dev/null || true + for f in "${TMPDIR:-/tmp}/$dir/$sid"*.ids; do + [ -f "$f" ] || continue + case "$f" in *.keep.ids) continue ;; esac + rm -f "$f" 2>/dev/null || true + done done return 0 } diff --git a/tests/test_rule_opened_ledger.py b/tests/test_rule_opened_ledger.py index 1d33bab..a06c97b 100644 --- a/tests/test_rule_opened_ledger.py +++ b/tests/test_rule_opened_ledger.py @@ -138,6 +138,13 @@ def test_an_event_with_nothing_usable_records_nothing_and_still_exits_zero(event # What a compaction clears — including `.opened.ids`, whose claim is the one # that would be worst to get wrong — is asserted against the running hook in # tests/test_session_ledger_clear.py, so there is one home for it. +# +# Since #4217 the recorder writes TWO files and only this one is cleared. +# `.opened.ids` says "this context holds rule 156", which a compaction makes +# false, and three hooks read it to decide whether to stay quiet. Its twin +# `.opened.keep.ids` says "rule 156 was opened", which a compaction does not +# touch, and the session-end readout is built on that. The split is tested +# where the sweep is. def test_the_recorder_is_registered_on_the_get_rule_tool(): diff --git a/tests/test_session_ledger_clear.py b/tests/test_session_ledger_clear.py index b24dd49..7bbba52 100644 --- a/tests/test_session_ledger_clear.py +++ b/tests/test_session_ledger_clear.py @@ -75,8 +75,12 @@ def _swept_dirs() -> set[str]: return set(line.group(1).split()) -def _run_session_start(source: str, tmp: Path) -> Path: - """Run the SessionStart hook for real, with the ledger directories filled.""" +def _run_session_start(source: str, tmp: Path, extra: list[str] | None = None) -> Path: + """Run the SessionStart hook for real, with the ledger directories filled. + + `extra` names further files to plant in `scribe-priorart` — used to put + an evidence twin in front of the sweep. + """ for tool in ("bash",): if shutil.which(tool) is None: pytest.skip(f"hook runtime tool {tool!r} not installed") @@ -88,6 +92,8 @@ def _run_session_start(source: str, tmp: Path) -> Path: (state / f"s1{suffix}").write_text("42\t1789600000\n") # Not a ledger: an outage marker that must outlive the clear. (tmp / "scribe-priorart" / "s1.unreached").write_text("1\n") + for name in extra or (): + (tmp / "scribe-priorart" / name).write_text("42\t1789600000\n") env = {"PATH": os.environ["PATH"], "HOME": str(tmp), "TMPDIR": str(tmp)} out = subprocess.run( @@ -226,3 +232,28 @@ def test_the_clear_is_derived_and_not_a_list_of_names(): assert suffix not in block, ( f"the clear names {suffix} again — a list, not a convention" ) + + +def test_the_evidence_twin_is_not_swept_with_them(tmp_path): + """The second thing that survives, and for the `.unreached` reason (#4217). + + `scribe_rules_append` writes each ledger twice: `..ids`, which + says what this context HOLDS and must be forgotten here, and + `..keep.ids`, which says what HAPPENED and no compaction makes + untrue. The session-end readout is built on the second, and it runs AT the + compaction — so a sweep that took both would leave the readout reporting + only the stretch since the last one, while reading as though it had + reported the session. + + Measured before the split, on the instance this was built on: six sessions, + 208 `get_rule` calls, 3 surviving ledger entries. + + The test above asserts every exclusion ledger dies; this asserts its twin + does not. Neither is complete alone, and the sweep is one glob away from + either mistake. + """ + root = _run_session_start("compact", tmp_path, extra=["s1.rules.keep.ids"]) + assert (root / "scribe-priorart" / "s1.rules.keep.ids").exists(), ( + "the evidence twin was swept with the exclusion ledgers — the readout " + "at this seam now reports a session it cannot see" + ) diff --git a/tests/test_session_slippage_readout.py b/tests/test_session_slippage_readout.py index 40a5580..73b656d 100644 --- a/tests/test_session_slippage_readout.py +++ b/tests/test_session_slippage_readout.py @@ -64,20 +64,26 @@ def sh(script: str) -> str: def ledgers(tmp_path, *, named=(), opened=(), acted=(), held=()) -> Path: - """The four ledgers, written the way the hooks write them.""" + """The four ledgers, written THROUGH THE REAL WRITERS. + + Not hand-rolled files: `scribe_rules_append` is what creates the evidence + twin these read from, so a fixture that wrote the bytes itself would keep + passing if the twin stopped being written — which is the whole defect + #4217 found. + """ d = tmp_path / "scribe-priorart" d.mkdir(parents=True, exist_ok=True) - now = int(time.time()) + script = [] for name, ids in (("rules", named), ("opened", opened), ("acted", acted)): if ids: - (d / f"s.{name}.ids").write_text( - "".join(f"{i}\t{now}\n" for i in ids) + body = "".join(f"{i}\n" for i in ids) + script.append( + f"printf '%s' '{body}' | scribe_rules_append \"{d}/s.{name}.ids\"" ) - if held: - # The checkpoint ledger is bare ids — it records that something - # HAPPENED rather than what the context still holds, so it carries no - # stamp and never ages (#4214). - (d / "s.checkpoint.ids").write_text("".join(f"{i}\n" for i in held)) + for i in held: + script.append(f'scribe_checkpoint_allowed "{d}/s.checkpoint.ids" {i} >/dev/null') + if script: + sh("\n".join(script)) return d @@ -253,3 +259,76 @@ def test_the_recorder_is_registered_on_the_rule_outcome_tool(): def test_the_recorder_is_shell_valid(): _need("bash") subprocess.run(["bash", "-n", str(RECORDER)], check=True) + + +# ── Evidence outlives the compaction; exclusions do not (#4217) ──────────── +# +# THE DEFECT THIS PINS, measured before it was fixed: across six sessions on +# the instance this was built on, 208 `get_rule` calls produced 3 surviving +# ledger entries. `.opened.ids` was doing two jobs with opposite lifetimes — +# "this context holds the rule" (must be forgotten at a compaction, and three +# hooks depend on that) and "this was opened" (which no compaction makes +# untrue). The sweep, correct for the first, was deleting the second. + +def test_the_readout_is_unchanged_by_the_sweep(tmp_path): + """The readout runs AT the compaction. If the sweep took its inputs it + would report only the last stretch of a session and read as though it had + reported all of it.""" + d = ledgers(tmp_path, named=[9, 34, 156], opened=[9, 156], acted=[156], held=[156]) + before = readout(d) + sh(f'TMPDIR="{tmp_path}" scribe_clear_session_ledgers s') + assert readout(d) == before + assert "READ WITH NO OUTCOME RECORDED: 9" in readout(d) + + +def test_the_sweep_still_clears_what_the_context_no_longer_holds(tmp_path): + """The other half, and it must keep working: after a compaction the agent + genuinely does not hold what it was shown, so an arm that stayed quiet on + the strength of the old ledger would be silent about a rule the context + has lost.""" + d = ledgers(tmp_path, named=[9], opened=[9]) + sh(f'TMPDIR="{tmp_path}" scribe_clear_session_ledgers s') + assert not (d / "s.rules.ids").exists() + assert not (d / "s.opened.ids").exists() + assert (d / "s.opened.keep.ids").exists() + + +def test_the_evidence_twin_is_not_aged_out(tmp_path): + """An exclusion ledger ages by TTL, and should: a rule named two hours ago + is not in this context. A rule OPENED two hours ago was still opened.""" + d = tmp_path / "scribe-priorart" + d.mkdir(parents=True, exist_ok=True) + stale = int(time.time()) - 99999 + (d / "s.opened.keep.ids").write_text(f"9\t{stale}\n") + (d / "s.rules.keep.ids").write_text(f"9\t{stale}\n") + assert "read: 9" in readout(d) + + +def test_every_ledger_written_through_the_appender_gets_a_twin(tmp_path): + """Derived in one place rather than listed at the call sites — a list is + what broke this before, and the next ledger somebody adds should be born + on the right side without anyone remembering to say so.""" + d = tmp_path / "scribe-priorart" + d.mkdir(parents=True, exist_ok=True) + sh(f"""printf '7\n' | scribe_rules_append "{d}/s.brandnew.ids" """) + assert (d / "s.brandnew.keep.ids").read_text().startswith("7\t") + sh(f'TMPDIR="{tmp_path}" scribe_clear_session_ledgers s') + assert (d / "s.brandnew.keep.ids").exists() + + +def test_a_checkpoint_budget_is_restored_by_a_compaction(tmp_path): + """The cap counts the SWEPT file on purpose. After a compaction this + context has not read the rule, so the budget to stop an act on it is + honestly fresh — while the record that a stop already happened stays.""" + d = tmp_path / "scribe-priorart" + d.mkdir(parents=True, exist_ok=True) + f = d / "s.checkpoint.ids" + sh(f'scribe_checkpoint_allowed "{f}" 156 >/dev/null') + r = subprocess.run( + ["bash", "-c", f'. "{DEFS}"\nscribe_checkpoint_allowed "{f}" 156'], + capture_output=True, text=True, timeout=30, + ) + assert r.returncode != 0, "a rule does not get to stop the same session twice" + sh(f'TMPDIR="{tmp_path}" scribe_clear_session_ledgers s') + sh(f'scribe_checkpoint_allowed "{f}" 156 >/dev/null') + assert (d / "s.checkpoint.keep.ids").read_text().count("156") == 2