fix(plugin): the ledger that proves a rule was read was being deleted by the compaction that asked about it (#4217)
CI & Build / Python lint (push) Successful in 3s
CI & Build / Plugin hooks (push) Successful in 15s
CI & Build / TypeScript typecheck (push) Successful in 53s
CI & Build / integration (push) Successful in 56s
CI & Build / Python tests (push) Successful in 1m45s
CI & Build / Build & push image (push) Successful in 16s

Milestone 419's acceptance, and it failed the first time it was run — which
is the only reason this commit exists.

THE MEASUREMENT. Ran the step-5 readout against this session's real traffic
instead of a fixture. It reported 19 rules named by an arm and none opened.
That is false: the session had called `get_rule` 45 times. Across six real
sessions on this instance: 208 opens, 3 surviving ledger entries. 1.4%.

THE CAUSE. `.opened.ids` was doing two jobs with opposite lifetimes.

  - "this context HOLDS rule 156" — false after a compaction, and three hooks
    read it to decide whether to stay quiet. Clearing it is correct.
  - "rule 156 WAS OPENED" — which no compaction makes untrue, and which the
    session-end readout is built on.

`scribe_clear_session_ledgers` sweeps every `<sid>*.ids` on SessionStart
source=compact. Right for the first claim, and it was deleting the second.
The TTL did the same thing more quietly: `scribe_rules_live` ages an
exclusion ledger, which is right, and would have eaten the early part of any
long session's evidence too.

So the readout was reporting only the stretch since the last compaction while
reading as though it had reported the session — a statistic that cannot vary
being mistaken for a finding (#3311), which is the shape this whole milestone
exists to stop producing. It ran AT the seam it was blind to.

THE SPLIT. `scribe_rules_append` now writes both: the exclusion ledger it
always wrote, and `<kind>.keep.ids`, an evidence twin that is never aged and
never swept. The readout reads twins; the three `held` readers are untouched.

DERIVED, NOT LISTED, because a list is what broke this before — the comment
above the sweep says so about its own history. Every ledger written through
the appender gets a twin, including the next one somebody adds; a new ledger
is born on the swept side unless its name opts out. `scribe_checkpoint_allowed`
writes its twin explicitly since it bypasses the appender, and there the split
lands right on both sides: the cap counts the swept file, so a compaction
honestly restores the budget to stop an act the context can no longer justify,
while the record that a stop happened stays.

Removed `scribe_ledger_ids`, orphaned by the change — a dead helper beside a
live one is a thing the next reader trusts.

test_session_ledger_clear.py asserted every ledger dies and could not have
caught this: its fixture never created a twin, so the sweep was one glob away
from either mistake with only one of them guarded. Both sides now asserted.
The slippage tests build their ledgers through the real writers rather than
by hand, for the same reason — a fixture that writes the bytes itself keeps
passing after the writer stops.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01821k5B3Ysecp9fNYs92Kuy
This commit is contained in:
2026-09-21 01:04:17 -04:00
co-authored by Claude Opus 5
parent ae773740b4
commit 36b54bff1f
5 changed files with 188 additions and 50 deletions
+1 -1
View File
@@ -1,7 +1,7 @@
{ {
"name": "scribe", "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).", "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": { "author": {
"name": "Bryan Van Deusen" "name": "Bryan Van Deusen"
}, },
+59 -38
View File
@@ -525,37 +525,6 @@ scribe_contract_block() {
return 0 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() { scribe_slippage_lines() {
# $1 state dir, $2 sanitised session id. # $1 state dir, $2 sanitised session id.
@@ -573,10 +542,16 @@ scribe_slippage_lines() {
# skip it. # skip it.
local dir="$1" sid="$2" named opened acted held local dir="$1" sid="$2" named opened acted held
[ -n "$dir" ] && [ -n "$sid" ] || return 0 [ -n "$dir" ] && [ -n "$sid" ] || return 0
named=$(scribe_ledger_ids "$dir/${sid}.rules.ids") # THE TWINS, not the exclusion ledgers. This runs at the compaction, which
opened=$(scribe_ledger_ids "$dir/${sid}.opened.ids") # is the moment the exclusion ledgers are about to be cleared and the moment
acted=$(scribe_ledger_ids "$dir/${sid}.acted.ids") # their TTL has usually already eaten the early part of a long session. A
held=$(scribe_ledger_ids "$dir/${sid}.checkpoint.ids") # 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 [ -n "$named$opened" ] || return 0
local unread unresolved local unread unresolved
@@ -790,10 +765,42 @@ scribe_rules_live() {
# Append surfaced ids, stamped. Reads ids on stdin, one per line — the shape # 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_json_list "$flat" '.rule_ids'` already produces at both call sites.
scribe_rules_append() { 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 local f="$1" now
[ -n "$f" ] || return 0 [ -n "$f" ] || return 0
now=$(date +%s 2>/dev/null) || now=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). # 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 [ "$n" -ge "$_SCRIBE_CHECKPOINT_CAP" ] && return 1
fi fi
printf '%s\n' "$id" >> "$f" 2>/dev/null || return 1 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 return 0
} }
@@ -914,10 +926,19 @@ scribe_held_query() {
SCRIBE_LEDGER_DIRS="scribe-priorart scribe-autoinject" SCRIBE_LEDGER_DIRS="scribe-priorart scribe-autoinject"
scribe_clear_session_ledgers() { 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 [ -n "$sid" ] || return 0
for dir in $SCRIBE_LEDGER_DIRS; do 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 done
return 0 return 0
} }
+7
View File
@@ -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 # 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 # 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. # 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(): def test_the_recorder_is_registered_on_the_get_rule_tool():
+33 -2
View File
@@ -75,8 +75,12 @@ def _swept_dirs() -> set[str]:
return set(line.group(1).split()) return set(line.group(1).split())
def _run_session_start(source: str, tmp: Path) -> Path: 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.""" """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",): for tool in ("bash",):
if shutil.which(tool) is None: if shutil.which(tool) is None:
pytest.skip(f"hook runtime tool {tool!r} not installed") 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") (state / f"s1{suffix}").write_text("42\t1789600000\n")
# Not a ledger: an outage marker that must outlive the clear. # Not a ledger: an outage marker that must outlive the clear.
(tmp / "scribe-priorart" / "s1.unreached").write_text("1\n") (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)} env = {"PATH": os.environ["PATH"], "HOME": str(tmp), "TMPDIR": str(tmp)}
out = subprocess.run( out = subprocess.run(
@@ -226,3 +232,28 @@ def test_the_clear_is_derived_and_not_a_list_of_names():
assert suffix not in block, ( assert suffix not in block, (
f"the clear names {suffix} again — a list, not a convention" 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: `<sid>.<kind>.ids`, which
says what this context HOLDS and must be forgotten here, and
`<sid>.<kind>.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"
)
+88 -9
View File
@@ -64,20 +64,26 @@ def sh(script: str) -> str:
def ledgers(tmp_path, *, named=(), opened=(), acted=(), held=()) -> Path: 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 = tmp_path / "scribe-priorart"
d.mkdir(parents=True, exist_ok=True) d.mkdir(parents=True, exist_ok=True)
now = int(time.time()) script = []
for name, ids in (("rules", named), ("opened", opened), ("acted", acted)): for name, ids in (("rules", named), ("opened", opened), ("acted", acted)):
if ids: if ids:
(d / f"s.{name}.ids").write_text( body = "".join(f"{i}\n" for i in ids)
"".join(f"{i}\t{now}\n" for i in ids) script.append(
f"printf '%s' '{body}' | scribe_rules_append \"{d}/s.{name}.ids\""
) )
if held: for i in held:
# The checkpoint ledger is bare ids — it records that something script.append(f'scribe_checkpoint_allowed "{d}/s.checkpoint.ids" {i} >/dev/null')
# HAPPENED rather than what the context still holds, so it carries no if script:
# stamp and never ages (#4214). sh("\n".join(script))
(d / "s.checkpoint.ids").write_text("".join(f"{i}\n" for i in held))
return d return d
@@ -253,3 +259,76 @@ def test_the_recorder_is_registered_on_the_rule_outcome_tool():
def test_the_recorder_is_shell_valid(): def test_the_recorder_is_shell_valid():
_need("bash") _need("bash")
subprocess.run(["bash", "-n", str(RECORDER)], check=True) 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