feat(776): every hook reports that it fired, and the report is measured (#795)
Build ErsatzTV Image / Delimiter ban (release path) (push) Successful in 25s
Build ErsatzTV Image / Build & test (.NET) (push) Successful in 9m14s
Build ErsatzTV Image / EF migration integrity (SQLite + MySql) (push) Successful in 6m37s
Build ErsatzTV Image / Functional E2E (curl + UI contracts) (push) Successful in 6m16s
Build ErsatzTV Image / API docs in sync (OpenAPI + endpoint index) (push) Skipped
Build ErsatzTV Image / Formatting (changed .cs conform to .editorconfig) (push) Skipped
Build ErsatzTV Image / Build & push image (amd64) (push) Successful in 4m19s

Co-authored-by: Timothy <timothy@noreply.gitea.tblindustries.be>
This commit was merged in pull request #795.
This commit is contained in:
2026-08-14 19:11:05 +00:00
committed by timothy
parent 84165ab755
commit 499dd348ab
20 changed files with 2529 additions and 20 deletions
+1
View File
@@ -196,6 +196,7 @@ the link for rationale. Superseded/retired history lives in `archive/`. Regenera
| `testing.enumerating-guard-identity-not-position` | A guard that cross-checks a hand-reviewed registry against call sites discovered across the whole repo must key each entry on properties INTRINSIC to the site — file, kind, and the value source text — and never on its absolute line or column. A registry keyed on position is a function of every other file in the repo, so a branch that never touches the guard can invalidate it; and because each PR is green against its own base, that failure is structurally invisible pre-merge and lands on `main` after review and after the merge gate. Dropping the position keeps every mutation the guard exists for — a NEW site, a REMOVED site and a CHANGED value each still fail, since each changes the identity multiset — and costs exactly ONE case, which must be stated rather than implied: a SAME-IDENTITY SUBSTITUTION within one file (delete a registered site, add a different unreviewed one with the same kind and value token, net-zero count) now passes. A REPORTED failure still prints the discovered line:column, because identity and diagnostics need not share a format. Comparison stays a MULTISET count rather than set membership, so two sites in one file sharing an identity must be discovered exactly that many times and a third occurrence still fails. A SCANNER test that asserts real AST positions against FIXED inline fixtures is the opposite case and keeps its line/column identity — it has no churn, because its input does not move. | 2026-07-27 | [link](records/testing/enumerating-guard-identity-not-position.md) |
| `testing.guard-derives-population-from-source` | A guard that asserts a COMPLETENESS property enumerates its population from a machine-readable authoritative source — the enum, the generated OpenAPI document, the parsed workflow YAML, the provider list — and asserts SET EQUALITY in BOTH directions against it. It may not narrow that population with a filter, a `Where`, a `grep` or an early `continue` before the assertion, because a filter cannot see the member that is MISSING: the member whose absence is the defect is precisely the one the predicate excludes. A hand-written literal list of members is the same defect in slower motion — a filter frozen at authoring time, correct on the day it was written and unable to report the day it stopped being. Two boundaries bound the rule rather than weaken it. FIRST, filtering to select the SUBJECT of a PER-MEMBER property is legitimate and is not this defect: the excluded members satisfy the property vacuously, so the filtered walk and the whole walk assert the same thing (`ToolCatalogTests.Every_Query_Parameter_Should_Be_A_Declared_Property` filters to tools that declare query parameters, and a tool declaring none has nothing to check). The defect is filtering the population before a COMPLETENESS claim, which is what makes an absent member unrepresentable (#757 filtered on `QueryParameters is {Count: > 0}` and so could not see a tool that should have declared one and did not). SECOND, a population of VALUES always has an external authoritative source and this rule applies directly; a population of SITES IN CODE has no such list, needs find-all-references tooling, and is tracked separately in #777 — do not stretch a set-equality assertion over it. Distinguish the guard SCOPE (which subsystems it covers — a reviewed policy choice, legitimately hand-written) from the guard POPULATION (the members inside that scope — always derived). When the scope itself MIRRORS an authoritative source, the mirror needs its own equality check or a dated staleness marker, or the guard is complete within a scope that has silently gone stale. The canonical worked example in this repo is `ToolCatalogTests.Every_Tool_Should_Declare_Exactly_Its_OpenApi_Query_Parameters`; the canonical residual gap is `MARKED_JOBS` in `scripts/tests/test_ci_dropped_step_guard.py`. | 2026-08-13 | [link](records/testing/guard-derives-population-from-source.md) |
| `testing.guard-ships-with-mutation-proof` | A guard is not considered tested because a test involving it passes. It ships with a MUTATION PROOF: remove or disarm THAT GUARD'S CLAUSE ALONE, and a NAMED test must go red. ONE NAMED EXCEPTION, with its limits, because the rule degenerates without it: where the guard IS a test (a checker enforcing a repo invariant, with no separate script behind it), disarming it makes it ABSENT rather than red, so the proof is the contrapositive — INTRODUCE THE DEFECT THE GUARD EXISTS TO CATCH into an isolated copy of the guarded artifact, and the named test must go red. That is a mutation of the guarded SYSTEM rather than of the assertion, and it is admissible ONLY for checker-guards and ONLY when the mutation was executed and witnessed. It is NOT a licence to grade an ordinary script-guard MUTATION for having a bad-input test: feeding a script an input its clause rejects is BEHAVIOUR-ONLY, which is what three rows were regraded for. A file-level grade under this exception covers the clause its cited case actually mutates, not every assertion that later lands in the same file; clause-level grading is tracked in #790. Three things this excludes, each of which has already shipped here as a green suite over a dead check. FIRST, a behavioural test — one that feeds the guard a good input and a bad input and checks it passes and fails — proves the guard REACTS, never that it is LOAD-BEARING; #685 had two guards on one condition where deleting either left the whole suite green while every behavioural test passed. SECOND, mutating the WHOLE FILE does not count (#510): a whole-file revert cannot show that a test reaches a particular clause, so the mutation must target the clause. THIRD, the guard being WIRED is not the guard RUNNING — #631's suite was invoked by no CI job, #751's step was dropped by the runner and the job reported success in 6s against a normal 14-17s, and #719's new logic was never connected to stdin. Every guard also carries an ANTI-VACUITY assertion, because the characteristic failure of a completeness check is reporting that it proved everything while its population was empty. Mechanical enforcement is possible for the BOOKKEEPING and not for the JUDGEMENT, and the split is the decision: `docs/guard-inventory.md` lists every guard file with its Kind, its Proof class (`MUTATION`/`BEHAVIOUR-ONLY`/`NONE`) and a `file::function` ref, and `scripts/tests/test_guard_inventory.py` derives the guard population from the filesystem and the call sites, asserts SET EQUALITY against the rows, and resolves every claimed ref to a real `def`. So a new guard cannot ship unclassified and a renamed test cannot leave a row silently claiming coverage. What stays with review, and is stated rather than papered over: nothing checks that a row claiming `MUTATION` is telling the truth. | 2026-08-13 | [link](records/testing/guard-ships-with-mutation-proof.md) |
| `testing.hook-reports-its-own-execution` | Every script in `.claude/hooks/` sources `scripts/hook-fire-log.sh` and calls `etv_hook_fire_begin <its-own-name> <label> <capture\|stream>` as its FIRST act, before anything reads stdin. Two records are appended per invocation — a `fire` record on entry and an `exit` record carrying the exit status and the decision — to a session-scoped JSONL log. THE DECISION IS READ FROM WHAT THE HOOK ACTUALLY EMITTED, never declared by the hook author: Claude Code hooks (`capture` mode) always exit 0 and communicate by PRINTING JSON, so their stdout is diverted and replayed, and the recorded decision is parsed from those bytes; git hooks (`stream` mode) decide by EXIT CODE and their stdout is live progress text a human is watching, so it is not diverted and the decision is the status. That split is not a tuning knob — capturing a slow pre-push hook's output would hold it back until the end and read as a hang, and inferring a git hook's decision from absent JSON would put the report back into the guessing business this record exists to end. The population is DERIVED from `.claude/hooks/*.sh` by `scripts/tests/test_hook_fire_log.py`, so a new hook is uninstrumented-and-red rather than silently unobserved, and the report lists every hook that EXISTS rather than every hook that appears in the log — a report built from the log alone can only show hooks that fired, which makes the never-fired hook, the one finding worth having, invisible. THE INSTRUMENTATION MUST BE INVISIBLE TO THE HARNESS, and this is the load-bearing half: it sits in the stdin and stdout path of the most authoritative guards in the repo, so a differential test drives EVERY hook with and without it over a payload matrix and demands byte-equal stdout and equal exit status. It fails OPEN in exactly one direction — if the log cannot be written the hook behaves exactly as before — because observability that breaks a guard is worse than the blindness it replaces. Two mechanical traps are pinned by tests rather than left to care: stdout must be replayed from the FILE, since `out=$(cat f)` strips trailing newlines and delivers a guard's JSON one byte short with no parser anywhere to complain; and stdin must never be slurped when it is a TTY, because an interactive `git commit` hands its hooks a terminal and `cat` would block forever, hanging the commit the instrumentation was added to observe. | 2026-08-14 | [link](records/testing/hook-reports-its-own-execution.md) |
| `testing.live-e2e-prepush-timing` | Run live-E2E via `scripts/e2e-local.sh` before pushing a write-path or UI change, and exercise download endpoints with curl, never a browser tab. | 2026-07-21 | [link](records/testing/live-e2e-prepush-timing.md) |
| `testing.playwright-mcp-download-and-recovery` | In Playwright-MCP E2E, fetch file-download endpoints with curl — never a browser tab or `window.open` — and if browser tools stall repeatedly, `pkill -f ms-playwright-mcp` and drive a fresh session. | 2026-07-21 | [link](records/testing/playwright-mcp-download-and-recovery.md) |
| `testing.scripted-playout-golden-deferred` | The `PlayoutBuildGoldenTests` in-memory golden net covers Sequential (YAML) as of #381. Scripted's *end-to-end pipeline* is excluded — `ScriptedPlayoutBuilder` runs a user-authored external program that drives the engine over HTTP loopback, which the in-memory harness can't pin — so that full-pipeline (integration) harness is deferred to #563. But the scheduling *behavior* those scripts drive lives entirely in the in-process `SchedulingEngine` (the `ScriptedScheduleController` is a 1:1 pass-through to it), which IS directly unit/golden-testable; the earlier "Scripted is un-golden-able by construction" framing overstated the constraint by conflating transport with engine. #395 extracts that shared switch to `ContentEnumeratorBuilder` and adds a direct regression net (`ContentEnumeratorBuilderTests`) over it. | 2026-07-22 | [link](records/testing/scripted-playout-golden-deferred.md) |
@@ -0,0 +1,223 @@
---
key: testing.hook-reports-its-own-execution
title: '2026-08-14 — every hook records that it fired and what it decided, through one shared sink (#776)'
status: active
since: '2026-08-14'
supersedes: none
superseded-by: none
rule: 'Every script in `.claude/hooks/` sources `scripts/hook-fire-log.sh` and calls `etv_hook_fire_begin <its-own-name> <label> <capture|stream>` as its FIRST act, before anything reads stdin. Two records are appended per invocation — a `fire` record on entry and an `exit` record carrying the exit status and the decision — to a session-scoped JSONL log. THE DECISION IS READ FROM WHAT THE HOOK ACTUALLY EMITTED, never declared by the hook author: Claude Code hooks (`capture` mode) always exit 0 and communicate by PRINTING JSON, so their stdout is diverted and replayed, and the recorded decision is parsed from those bytes; git hooks (`stream` mode) decide by EXIT CODE and their stdout is live progress text a human is watching, so it is not diverted and the decision is the status. That split is not a tuning knob — capturing a slow pre-push hook''s output would hold it back until the end and read as a hang, and inferring a git hook''s decision from absent JSON would put the report back into the guessing business this record exists to end. The population is DERIVED from `.claude/hooks/*.sh` by `scripts/tests/test_hook_fire_log.py`, so a new hook is uninstrumented-and-red rather than silently unobserved, and the report lists every hook that EXISTS rather than every hook that appears in the log — a report built from the log alone can only show hooks that fired, which makes the never-fired hook, the one finding worth having, invisible. THE INSTRUMENTATION MUST BE INVISIBLE TO THE HARNESS, and this is the load-bearing half: it sits in the stdin and stdout path of the most authoritative guards in the repo, so a differential test drives EVERY hook with and without it over a payload matrix and demands byte-equal stdout and equal exit status. It fails OPEN in exactly one direction — if the log cannot be written the hook behaves exactly as before — because observability that breaks a guard is worse than the blindness it replaces. Two mechanical traps are pinned by tests rather than left to care: stdout must be replayed from the FILE, since `out=$(cat f)` strips trailing newlines and delivers a guard''s JSON one byte short with no parser anywhere to complain; and stdin must never be slurped when it is a TTY, because an interactive `git commit` hands its hooks a terminal and `cat` would block forever, hanging the commit the instrumentation was added to observe.'
signals: 'hook fire log · did this hook actually fire · PreToolUse leaves no transcript record · make the system report it rather than infer it · capture vs stream mode · byte-equal stdout differential · fail-open observability · never slurp a tty · derived hook population · never-fired row · paths: `scripts/hook-fire-log.sh`, `scripts/tests/test_hook_fire_log.py`, `docs/guard-inventory.md`, `docs/defect-shapes-773.md` · issues: #776, #773, #775, #774, #756, #751, #719, #685, #631'
mechanics: 'Read side: `scripts/hook-fire-log.sh report [--all|--json|--dir D|--session S]`. Logs default to `$HOME/.cache/ersatztv/hook-fire/<session-id>.jsonl`, outside the repo, overridable with `ETV_HOOK_FIRE_LOG_DIR`; `ETV_HOOK_FIRE_DISABLE=1` turns recording off without editing a hook. The session id comes from the payload''s `.session_id`, because this harness version does not export one to hooks. Records carry no tool arguments — only hook, label, event, tool name, phase, status and decision — so the log is not a second copy of the transcript.'
---
**The blind spot this closes.** In this harness version only `Stop` hooks emit a structured
transcript record. `PreToolUse` and `PostToolUse` hooks — which is *every* guard this repo actually
relies on: merge consent, worktree ownership, BOM, agent model and RAM, the golden-file ban — leave
no durable execution trace at all. When #773 tried to measure whether they fire, the only available
signal was **filename mentions in settings dumps and prior audits**, which is not evidence of
execution. So the guards carrying the most authority were the ones whose execution could only be
inferred, and a silently broken hook would have looked identical to a working one indefinitely.
That is Family B (the check never ran) applied to the hook layer itself, and this project has
already paid for it twice one layer down: #751's guard that reported success in 6 seconds having run
nothing, and #756's fail-open twin that 30 green tests could not see. #756's standing lesson is the
whole of this record — **make the system report it rather than infer it**.
**Why the decision is parsed from the emitted bytes rather than declared.** The obvious design has
each decision site announce itself. `pretooluse-merge-consent.sh` alone reaches its output through a
`decide` helper from roughly forty call sites, so that design is forty edits in the most
load-bearing guard in the repo, and it records **what the author meant** — which is the inference
being abolished, reintroduced one layer up. Capturing what the hook printed records what the
*harness* sees. It cannot drift from the decision because it **is** the decision, and it needed no
edit to any decision site.
**The risk this takes on, stated plainly.** Reading stdin before the hook and diverting its stdout
puts this code directly in the path of every guard. Get it wrong and a `deny` is swallowed while the
log cheerfully reports the guard firing — strictly worse than the blindness it replaces, and
undetectable from the outside for the same reason the original gap was. So the proof obligation is
not a unit test of the sink: a wrapper can be perfect alone and lethal in context.
`test_instrumentation_changes_NOTHING_the_harness_can_see` runs every hook in both forms and
compares stdout bytes, stderr bytes and exit status.
**A differential test is only as good as the cases it drives, and this one had to be measured rather
than asserted.** A hook that emits nothing and exits 0 makes the comparison `("", 0) == ("", 0)`,
which passes on a wrapper that discards everything. Measured on the first version of the matrix: 160
of 165 comparisons were empty-against-empty and 165 of 165 compared exit 0 against exit 0, so
deleting the entire replay left the test green for four hooks, two of which issue `deny`. The three
places that claimed the matrix "reaches each hook's deciding branch" — including this record — were
simply wrong. The structure that replaces the claim:
- a broad, cheap payload matrix, which reaches the deciding branch of a few hooks;
- `positives()`, which CONSTRUCTS the rest — a sibling worktree carrying a foreign owner marker, an
`*ersatztv*`-named repo with a staged BOM `.cs`, `memory_pressure` stubbed at 5% and 15%, a real
bare remote so the three pre-push guards can be driven to a genuine block, and a stub Gitea so
`prepush-donewhen` is exercised rather than exempted;
- `test_the_AB_is_not_VACUOUS_for_any_hook`, which fails unless each hook has at least one case
where the control side emits output or exits non-zero.
One hook is exempt and the exemption is stated rather than assumed: `posttooluse-worktree-marker.sh`
emits nothing and exits 0 by design — its entire output is a marker file — so its transparency is
asserted on that file instead.
**Five defects this shipped with, all found by cold review or by the tests it prompted.** Recorded
because each was invisible to every other check, and because the ranking is instructive: the worst
one was surfaced by a finding ranked *Low*.
| Defect | Why nothing else would catch it | Pinned by |
|---|---|---|
| `exec 0<"$sin" 2>/dev/null` sent the hook's **entire stderr** to /dev/null for its whole life — `exec` with no command redirects the shell permanently. Every husky guard's user-facing output is stderr, so guards blocked while explaining nothing | the A/B compared only stdout and exit status | `test_stderr_is_NOT_silenced` |
| The fd restore lived inside the same conditional as the replay, and the replay read the PATH — so an unlinked-but-open scratch file meant a swallowed `deny` and an exit 0 | needs `mktemp` stubbed or the file removed mid-run | `test_output_SURVIVES_a_vanished_stdout_tempfile` |
| `sed`/`tr` in the classifier are locale-aware, so one 0xE9 byte in a `permissionDecisionReason` printed `illegal byte sequence` AT THE HARNESS and filed a real `deny` as `output` | no test put a non-UTF-8 byte in a decision | `LC_ALL=C`, plus the stderr comparison in the A/B |
| Payload fields were read from a `head -c 65536` prefix, so a large `tool_response` pushed `session_id` past the cap and those fires filed under `unknown-session` — reading as NEVER FIRED in the report | a truncating read is a sampling error, and no fixture was over 64 KB | fields now read from the file, unbounded |
| `out=$(cat f)` strips trailing newlines, so a hook's JSON reached the harness one byte short | every JSON parser accepts it; only a byte comparison objects | `test_stdout_is_replayed_BYTE_EXACT` |
| An unconditional stdin slurp blocks forever on a TTY, hanging every interactive `git commit` | the pipe-fed tests cannot reach a tty; needs a real pty | `test_a_TTY_stdin_is_not_slurped` |
**One mechanism was WITHDRAWN rather than fixed, and it is recorded here because the next reader
will otherwise re-add it.** A `trap … INT TERM HUP` was added so a hook killed by the harness
timeout would not lose output it had already printed. It produced a defect in each of three
consecutive rounds — a handler ending in `exit "$?"` that turned a signal into consent and let a
push reach `main`; a `local sig=…` that clobbered `$?` so a killed guard was *recorded* as having
passed; and a second signal mid-flush that discarded the output entirely.
**A correction, because the first version of this record justified the withdrawal with a number that
is wrong.** It claimed, as measured fact, that trapping made a hook take 30 s to die where it had
taken 1 s. That came from a review finding accepted without re-measuring, and the A/B refutes it:
signalling the pid gives control **4.01 s** and trapped **4.12 s**; signalling the process group
gives control **0.002 s** and trapped **0.054 s**. The stall is bash deferring a fatal signal until
its foreground command finishes, and it happens **identically without any trap** — the control
stalls too. The trap cost ~0.1 s, not 29 s. Recorded rather than quietly fixed, because a decision
record carrying a fabricated measurement is worse than one carrying none: it reads as checked and
talks the next reader out of checking.
**A second correction, in the same paragraph as the first.** The replacement rationale asserted that
the round-3 sink "returned rc 0 on SIGINT where the uninstrumented control returns 2". That is
**inverted**, and it was again taken from a review summary without re-measuring — the identical
mistake, one round later, in the artifact written to correct it. The measured 12-cell matrix
({group, pid} × {TERM, INT, HUP} × {control, round-3 trapped, HEAD}):
| | TERM | INT | HUP |
|---|---|---|---|
| group kill — control / trapped (`6f006a1b7`) / HEAD | 15 / 15 / 15 | 2 / 2 / 2 | 1 / 1 / 1 |
| pid kill — control / trapped (`6f006a1b7`) / HEAD | 15 / 15 / 15 | **0 / 2 / 0** | 1 / 1 / 1 |
Reproduce: spawn a `stream`-mode hook that prints a decision then `sleep`s, in its own session;
signal 1 s in with `os.killpg` or `os.kill`; read the wait status. Independently re-measured, five
repeats per cell, every cell unanimous, stdout byte-identical in all runs — and the "would not have
caught round 3" claim carries its own positive control: patching the trapped handler's re-raise back
to `exit 0` turns the same test red on all three signals.
So the trapped sink returned **2 where the control returns 0** — a real transparency violation, but
in the *restrictive* direction, which also makes "the consent bug survived" the wrong
characterisation. **HEAD matches the control in all twelve cells.** And the claim that the
exit-status assertion "catches the SIGINT case" is false as written: the test signals the process
group, and in every group cell the trapped sink is indistinguishable, so it would not have caught
round 3 at all. The test asserts the transparency of the current code, which is what it is for; it
is not evidence that the trap was bad.
**What actually justifies the withdrawal**, with the two false reasons removed. Three defects in
three rounds, each real and measured at the time — a handler that turned a signal into consent and
let a push reach `main`, a `local` that clobbered the status so a killed guard was recorded as
passing, and a nested signal that discarded the output. One measured transparency violation that
survived the fixes (pid + SIGINT, above). And a rescue window that is sub-millisecond, because every
capture-mode hook prints its decision and exits immediately. Machinery needing a signal-to-status
map, an idempotent flush, correct re-raise semantics and `BASHPID` handling, to rescue that window,
is not worth its failure modes.
What is lost by withdrawing it, enumerated rather than waved past, because
`process.enumerate-workaround-behaviors-before-deleting` exists for precisely this move:
| Behaviour the trap provided | Status now |
|---|---|
| A killed hook's `exit` record | **LOST.** This is why `report` counts `fire` records, not `exit` records — a hook that fired and was killed still shows as having fired |
| Stdout a killed hook had already printed | **LOST**, and near-unreachable: every capture-mode hook prints its decision and exits immediately, a sub-millisecond window |
| Cleanup of the two temp files on a kill | **LOST**, bounded by `$TMPDIR` cleanup |
| Idempotent flush (`ETV_HOOK_FIRE_FLUSHED`) | **RETAINED** — cheap, and the failure it prevents is silent |
The invariant that replaces the rescue is asserted directly: **under a signal, an instrumented hook
is indistinguishable from an uninstrumented one** — compared on exit status, stdout, stderr and time
to die. It **signals the process group, not the pid**, and that is not a detail: bash defers a fatal
signal until its foreground command finishes, so signalling the pid alone makes both sides take the
full sleep and the timing assertion distinguishes nothing.
Its limit, stated because the alternative is a coverage claim that is not true: **the group-kill
arrangement makes the test blind to the round-3 trapped sink**, which passes every assertion there.
The divergence that sink actually had is a pid-kill one (the table above). This test pins the
transparency of the code that ships; it is not a proof that any earlier version was worse.
**A SECOND withdrawal, on the same reasoning.** A `test_no_redirection_in_the_sink_PRECEDES_its_stderr_redirect`
generalised the `exec … 2>/dev/null` rule to any command by pattern-matching shell source. It went
through four iterations, each fixing a false positive or a false negative the last had introduced —
`>/dev/null 2>&1` flagged wrongly, then operators preceded by a digit (`exec 0<`) missed entirely,
then multi-command lines flagged wrongly — and cold review then constructed more of both
(`[[ "$x" < "$y" ]] 2>/dev/null`, a line continuation, a `>` inside a quoted string). It is deleted
rather than patched a fifth time, following the precedent in `docs/guard-inventory.md`: a weak
detector is itself the symptom-keyed mistake, and another regex patch adds confidence without
soundness. The narrower `test_no_exec_in_the_sink_carries_a_STDERR_REDIRECT` is retained — it is a
sound match on a fixed keyword and covers the dangerous subset, which is every case that has
actually occurred.
**One transparency limit, measured and stated rather than papered over.** On a group kill with a
live foreground child, bash prints its own job-control notice (`Terminated: 15 sleep 5`) that an
uninstrumented hook does not. Isolated: sourcing the sink alone does not produce it, and a no-op
`EXIT` trap does not either — doing ANY work at exit keeps the shell alive the ~50 ms bash needs to
print, and doing work at exit is the sink's entire purpose. The A/B exempts exactly that notice and
nothing else.
**The exemption is doing real work and the honest reading is uncomfortable**, so it is stated
plainly: one observed form of the notice is
`…/scripts/hook-fire-log.sh: line 109: <pid> Hangup: 1 sleep 25` — bash attributing its own
message to whichever line of the sink was executing, which means the instrumentation's path appears
on a guard's stderr where an uninstrumented hook emits nothing. That is a genuine, if small, leak,
and the exemption hides it. It is accepted rather than fixed because it cannot be suppressed while
the sink does any work at exit, and it costs one line in a run that is already being killed.
**CI found what six review rounds on one platform could not, and it was a live guard defect.** The
non-vacuity assertion demands that `pretooluse-bom-guard.sh` reach a `deny`. On the Linux runner it
could not, because the guard detects a BOM with `xxd -p` — and **`xxd` ships with vim and is absent
there**, so the command substitution yielded empty, never matched, and the guard passed every BOM
silently. It has been fail-open on any host without vim for its whole life. `od -A n -t x1 -N 3` is
POSIX, byte-identical on both platforms, and is what it uses now.
Two things follow. The defect was invisible to every round of review because all of them ran on
macOS, where `xxd` exists — **the environment was a sampled population too**, and the only reason it
surfaced is that a test asserted the guard must actually decide something. And two of the three CI
failures were my *tests* being platform-specific (a bare `Terminated` job notice where macOS prints
`Terminated: 15 sleep 5`; locales that do not exist on the runner, so bash warned and the
assertion measured the missing locale rather than the fix). A test suite is code, and it inherits
the same blind spot as the code it checks.
**The generalisable lesson is about the fixing, not the bugs.** This took three review rounds, and
every round found that the previous round's *fix* had introduced something beside its target. The
signal fix is the sharpest case: it corrected a lost log line and, in doing so, turned a killed
`main`-protection guard into a rubber stamp. The rule this repo already has —
`process.consistency-fix-new-code-scrutiny`, a fix is new code and gets reviewed as new code —
applies with full force to instrumentation, because the fix and the thing it instruments occupy the
same execution path.
Two of those fixes read as done and were not, which is the more useful pattern to recognise. The
path-traversal hardening reused the record scrubber, which deliberately permits `/` and `.`, so
`../../escaped` passed through untouched: **passing a value through a scrub is not the same as
passing it through the right scrub.** And `exec … 2>/dev/null` was fixed twice and reintroduced a
third time, eight lines below the comment forbidding it — which is why
`test_no_exec_in_the_sink_carries_a_STDERR_REDIRECT` now enforces the rule instead of restating it.
Enumerating instances loses to removing the class, and the third instance is what proves it.
One measurement note, since it cost a round of confusion: a shared `TMPDIR` between the two halves
of the differential let the control's one-shot throttle marker suppress the instrumented run, so the
test reported a swallowed decision that never happened. A differential whose halves share mutable
state stops measuring the difference and measures the state.
**What the first measurement immediately produced**, which is the argument for the whole thing. A
live run recorded `pretooluse-agent-model` firing on an `Agent` dispatch and deciding `no-op` where
`ask` was expected. Under the old regime that would have been an unanswerable suspicion. Instead the
question was settled by dumping the real payload: the dispatch carried `model: haiku`, so `no-op`
was correct and there was no bug. Note what did *not* happen — no argument from the hook's source
about what it "must" do, which this repo's record says has been wrong repeatedly. One printed line
settled it in one run.
**The limit, stated rather than implied.** A zero in the report means *not observed in this window*,
which is two different findings wearing one number: a hook that is broken, and a hook whose trigger
genuinely did not occur. The report says so in its own footer rather than presenting a zero as a
verdict. `pretooluse-nav-guard` and `pretooluse-merge-consent` are the standing examples — neither
can be exercised without either a browser session or a real merge, so their zeroes are expected and
distinguishing them stays a human judgement.
+85 -16
View File
@@ -474,23 +474,92 @@ and 5,102 `Read` calls over the same corpus, so the search was demonstrably capa
evidence in transcripts (`husky - dotnet format found whitespace/BOM issues`, `husky - commit message
missing Co-Authored-By trailer`, `husky - refusing to commit root-level screenshot(s)`).
### 5.4 We cannot currently tell whether our own hooks fire
Wiring was the strongest claim available for the hook rows when this table was written. It is no
longer the ceiling — §5.4 is now measured — so read the hook rows against
`scripts/hook-fire-log.sh report`, not against this paragraph.
The most consequential Part 2 finding, and it was volunteered by the inventory as a limit on its own
evidence. In this harness version only **`Stop`** hooks emit a structured record
(`stop_hook_summary`/`hookInfos`). `PreToolUse` and `PostToolUse` hooks — which is *every* guard that
matters here: merge consent, worktree, BOM, agent model/RAM — leave **no durable execution trace**.
What the audit could count for those hooks was filename mentions in settings dumps and prior audits,
which is not proof of execution. Only `design-sync-reminder.sh`'s Stop path and the three husky
message strings quoted in §5.3 are confirmed fires; the `.claude/hooks/` scripts are confirmed
*wired*, which is a different claim.
### 5.4 Whether our own hooks fire — now measured (#776 closed this)
So the guards this repo relies on most are exactly the ones whose execution we cannot observe. That
is Family B (the check never ran) applied to the hook layer itself, and this project has already
paid for it twice at the CI layer — #751's guard that reported success in 6s having run nothing, and
#756's fail-open twin. The standing lesson from #756 applies unchanged: **make the system report it
rather than infer it.** A one-line append to a session-scoped log from each hook would convert every
row in that table from inference to measurement, and it is cheap.
**The finding as originally recorded.** In this harness version only `Stop` hooks emit a structured
record (`stop_hook_summary`/`hookInfos`). `PreToolUse` and `PostToolUse` hooks — which is *every*
guard that matters here: merge consent, worktree, BOM, agent model/RAM — leave no durable execution
trace. What this audit could count for those hooks was filename mentions in settings dumps, which is
not evidence of execution. So the guards this repo relies on most were exactly the ones whose
execution could only be inferred: Family B (the check never ran) applied to the hook layer itself,
after this project had already paid for it twice at the CI layer (#751, #756).
**What replaced the inference.** Every hook now records its own execution through one shared sink,
`scripts/hook-fire-log.sh` (`testing.hook-reports-its-own-execution`): a `fire` record on entry and
an `exit` record carrying the status and the decision, where **the decision is parsed from the bytes
the hook actually emitted** rather than declared by its author. Read it with
`scripts/hook-fire-log.sh report [--all]`.
**Measured 2026-08-14** — a scripted headless session (a plain Bash call, a Bash call carrying
`ETV_UPDATE_GOLDENS=1`, a `Write` to a SPA file, and one `Agent` dispatch) plus a real `git commit`
and a `git push --dry-run` in a worktree. Snapshot boundary: this is one deliberately-constructed
window, not a corpus statistic.
| Hook | Event | Fires | Decisions observed |
|---|---|---|---|
| `pretooluse-bash-guard` | PreToolUse/Bash | 2 | `deny` 1, `no-op` 1 |
| `pretooluse-bom-guard` | PreToolUse/Bash | 2 | `no-op` 2 |
| `pretooluse-worktree-guard` | PreToolUse/Bash | 2 | `no-op` 2 |
| `posttooluse-worktree-marker` | PostToolUse/Bash | 1 | `no-op` 1 |
| `design-sync-reminder` | PreToolUse/Write + Stop | 4 | `context` 1, `block` 1, `no-op` 2 |
| `pretooluse-agent-model` | PreToolUse/Agent | 2 | `no-op` 2 |
| `pretooluse-agent-ram` | PreToolUse/Agent | 2 | `no-op` 2 |
| `decisions-guard` | git pre-commit | 2 | `pass` 2 |
| `prepush-clean-worktree-check` | git pre-push | 1 | `pass` 1 |
| `prepush-donewhen` | git pre-push | 1 | `pass` 1 |
| `prepush-rebase-check` | git pre-push | 1 | `pass` 1 |
| `pretooluse-nav-guard` | PreToolUse/navigate | **0** | not exercised — needs a live browser session |
| `pretooluse-merge-consent` | PreToolUse/PR write | **0** | not exercised — needs a real merge attempt |
**11 of 13 hooks are confirmed firing, with the decision each reached.** The `deny` row is the load-
bearing one: `pretooluse-bash-guard` did not merely run, it *blocked* the `ETV_UPDATE_GOLDENS=1`
probe, so at least one guard in this set is demonstrably live rather than merely present.
**Re-verified against the shipped implementation.** The table was first measured against an early
version of the sink, and the classifier changed materially afterwards, so the run was repeated
against the final code: `pretooluse-bash-guard` `deny`+`no-op`, `pretooluse-bom-guard` and
`pretooluse-worktree-guard` `no-op`, `posttooluse-worktree-marker` `no-op`, `design-sync-reminder`
`context`+`block`+`no-op` — identical decisions. The repeat run exercised the five Claude hooks a
Bash/Write session reaches; the `Agent` pair and the four git hooks are carried over from the
original run and were not re-measured.
**Reproducing this table.** It is a constructed window, not a corpus statistic, and it is not
reproducible from a reader's own `report` output — running the test suite alone would not produce
it, and before `scripts/tests/conftest.py` landed, running the suite actively polluted the default
log with synthetic fires. To re-derive: point `ETV_HOOK_FIRE_LOG_DIR` at an empty directory, run a
headless session exercising the four tool paths above, then a `git commit` and a
`git push --dry-run`, and read `scripts/hook-fire-log.sh report --all --dir <that directory>`.
**A zero is two findings wearing one number** — a hook that is broken, and a hook whose trigger did
not occur — and the report says so rather than presenting a zero as a verdict.
For the two zeroes here, what is established and what is not, kept apart deliberately.
**Established:** both script bodies work. `pretooluse-nav-guard` and `pretooluse-merge-consent` are
each driven to their deciding branch in `scripts/tests/test_hook_fire_log.py` — a `deny` on an
`/iptv/` URL and an `ask` on a merge call — emitting the correct decision with the instrumentation
in place. **Not established:** that the harness would dispatch to them. Those tests invoke the
scripts directly, so they bypass registration and matcher dispatch entirely; a typo in
`.claude/settings.json`, a settings file that never loaded, or a matcher that does not match would
leave both tests green while the production zero still meant broken wiring. A working script is a
necessary condition, not the finding.
So these two zeroes remain genuinely ambiguous, and neither can be resolved without the thing that
resolves it: a live browser session, or a real merge attempt. Manufacturing a merge to observe the
merge guard is a worse idea than the gap it would close. Distinguishing the two meanings of zero
stays a human judgement — `testing.hook-reports-its-own-execution` says so, and an earlier draft of
this paragraph quietly contradicted it by treating "the script works" as "the wiring works".
**The measurement earned its keep on its first run.** `pretooluse-agent-model` was recorded deciding
`no-op` on an `Agent` dispatch where `ask` was expected. Previously that would have been an
unanswerable suspicion about a guard nobody could observe; instead the real payload was dumped and
it carried `model: haiku`, so `no-op` was correct and there was no defect. The general form is the
standing #756 lesson — **make the system report it rather than infer it** — and note what it
displaced: an argument from the hook's source about what it "must" do, which is the reasoning shape
§3 measures going wrong repeatedly.
### 5.5 Tools we do *not* have that would address a named class
@@ -533,7 +602,7 @@ This issue is analysis; it spawns implementation rather than doing it.
|---|---|---|---|
| #774 | **A** — a guard derives its population from the authoritative source and asserts set equality | Family A, 27 records (39%) | high |
| #775 | **B** — every guard ships a mutation proof: delete that guard alone, see red | Family B, 9 records (13%) | high |
| #776 | Make hooks report that they fired — PreToolUse/PostToolUse execution is unobservable | the whole hook layer | high |
| #776 | Make hooks report that they fired — PreToolUse/PostToolUse execution is unobservable | the whole hook layer | high **DONE**, §5.4 is measured |
| #777 | `csharp-lsp` and `typescript-lsp` are broken; the "workflow agents must use csharp-lsp" note is stale | partial mitigation for Family A | medium |
| #778 | **D** — pin a version or use compare-and-set for read-then-write against live remote state | Family D, 5 records | medium |
| #779 | **F + G** — test the deny path with the production config value; assert full-replace field lists | fail-open + destructive-replace, ~8 records | medium |
+23 -4
View File
@@ -101,6 +101,7 @@ all.
| `scripts/e2e-functional.sh` | the Functional E2E job, on a failed HTTP contract assertion | GUARD | NONE | — |
| `scripts/e2e-local.sh` | nothing (boots a local instance) | TOOLING | NONE | — |
| `scripts/e2e-ui.sh` | nothing (drives the Playwright flows) | TOOLING | NONE | — |
| `scripts/hook-fire-log.sh` | nothing (records that each hook fired, and reports it) | TOOLING | NONE | — |
| `scripts/jq-preflight.sh` | the `script-tests` job, on a jq version change | GUARD | BEHAVIOUR-ONLY | `test_jq_preflight.py::test_below_the_floor_is_LOUD` |
| `scripts/post-review-verdict.sh` | nothing (writes the verdict status) | GUARD | BEHAVIOUR-ONLY | `test_post_review_verdict.py::test_never_retargets_the_verdict_at_the_new_head` |
| `scripts/pr-changed-files.sh` | the verdict exemption, on an incomplete enumeration | GUARD | BEHAVIOUR-ONLY | `test_pr_changed_files.py::test_a_SHORT_page_does_not_end_the_enumeration` |
@@ -114,6 +115,7 @@ all.
| `scripts/tests/test_decisions_lib.py` | the `script-tests` job | PROOF | NONE | — |
| `scripts/tests/test_decisions_validate.py` | the `script-tests` job | PROOF | NONE | — |
| `scripts/tests/test_guard_inventory.py` | the `script-tests` job, on an unclassified guard or a stale proof ref | GUARD | MUTATION | `test_guard_inventory.py::test_the_inventory_covers_exactly_the_guards_that_exist` |
| `scripts/tests/test_hook_fire_log.py` | the `script-tests` job, on a hook that stops reporting that it fired, or whose reporting changes what the harness sees | GUARD | MUTATION | `test_hook_fire_log.py::test_a_hook_that_LOSES_its_instrumentation_is_DETECTED` |
| `scripts/tests/test_jq_preflight.py` | the `script-tests` job | PROOF | NONE | — |
| `scripts/tests/test_merge_consent_base_change.py` | the `script-tests` job | PROOF | NONE | — |
| `scripts/tests/test_merge_consent_exemption.py` | the `script-tests` job | PROOF | NONE | — |
@@ -124,7 +126,7 @@ all.
## What the numbers say
31 guards, 4 tooling scripts, 13 proof files. **5 guards carry a mutation proof; 6 are
32 guards, 5 tooling scripts, 13 proof files. **6 guards carry a mutation proof; 6 are
behaviour-only; 20 have none.** These figures are asserted against the table by
`test_the_summary_counts_match_the_table` — they were wrong in the first draft (28/4/6/3/19 against
a table holding 27/5/6/3/18), because a hand-maintained summary of a table is a second copy of it,
@@ -171,14 +173,31 @@ dangerous direction — a token that a reviewer means as `BLOCKED` silently read
approval, which writes a green `review-verdict/h10`. A token added to one script and not the other
is untested by either, which is the whole of #788.
**A guard was WITHDRAWN from `test_hook_fire_log.py` after four iterations**, recorded here because
this is where a future session will look for it. A `test_no_redirection_in_the_sink_PRECEDES_its_stderr_redirect`
generalised the `exec … 2>/dev/null` rule to any command by pattern-matching shell source. Each
iteration fixed a false positive or false negative the previous one introduced — `>/dev/null 2>&1`
flagged wrongly, then operators preceded by a digit (`exec 0<`) missed entirely, then multi-command
lines flagged wrongly — and cold review then constructed more of both (`[[ "$x" < "$y" ]] 2>/dev/null`,
a backslash continuation, a `>` inside a quoted string). Deleted rather than patched a fifth time,
on the same reasoning as the vocabulary-parity withdrawal above.
**`test_hook_fire_log.py` asserts TWO clauses
**That unproven set carries no number here on purpose.** It restated the count, drifted the moment
the BOM guard was regraded, and `test_the_summary_counts_match_the_table` cannot see it — the parser
checks the formatted summary sentence and nothing else. A second hand-maintained copy of a number is
the duplication family this file argues against, so the copy is removed rather than corrected: the
set is every `PreToolUse` hook except merge-consent and the BOM guard, and the count is in the
summary above. It is also the population #776 found we
cannot even observe firing. A guard that is neither proven nor observable is an assertion about the
past.
summary above.
**They are now observable but still unproven, and the two words carry different weight.** Observable:
every hook records its own execution through `scripts/hook-fire-log.sh`, so "did this hook fire, and
what did it decide" is a measurement — run `scripts/hook-fire-log.sh report` (#776). Unproven:
nobody has demonstrated any of them is load-bearing, which is what #785 tracks. Observability tells
you a guard ran; only a mutation tells you it would have caught anything. The BOM guard is the case
that shows why the distinction matters — it was firing on every commit the whole time it was
fail-open.
The gaps are not uniform in cost, and the ranking that matters is *what a silent failure would let
through*, not test count: