feat(776): every hook reports that it fired, and the report is measured #795

Merged

timothy merged 14 commits from feat/776-hook-fire-log into main 2026-08-14 21:11:05 +02:00

Conversation 1 Commits 14 Files Changed 20

+2529 -20

14 Commits

Author	SHA1	Message	Date
timothyandClaude Opus 5	ba2b162238	docs(776): restore two inventory sections the rebase resolution dropped ... Rebasing onto #798 conflicted in docs/guard-inventory.md at every commit that touched it, and resolving those by taking the accumulated side silently dropped two prose sections: the WITHDRAWN note for the generalised redirect-order guard, and the paragraph recording that test_hook_fire_log.py asserts two clauses with a separate executed mutation for each. Counts, rows and the inventory test were all green without them — which is the point worth recording. A conflict resolution that satisfies every mechanical check can still lose the reasoning, because the checks count rows and the prose carries the WHY. Caught by grepping the merged file for the content the branch was supposed to add, rather than trusting green. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:56:37 +02:00
timothyandClaude Opus 5	5f62140a52	fix(776): the BOM guard was fail-open on Linux — xxd is not installed there ... CI red on `Script tests (pytest)`, three failures, and the first is a real guard defect that six review rounds on macOS could not see. `pretooluse-bom-guard.sh` detects a BOM with `head -c3 | xxd -p`. `xxd` ships with vim and is ABSENT on the Linux CI runner (verified on the runner host), so the substitution yields empty, never equals efbbbf, and the guard passes 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 and byte-identical on both platforms. It surfaced only because #776's non-vacuity assertion demands that hook actually reach a decision. The environment was a sampled population too — every review round ran where xxd exists. The other two failures were my tests being platform-specific: - Linux prints a bare `Terminated` job-control notice where macOS prints `Terminated: 15 sleep 5`; the exemption regex required a trailing colon or space and so did not match. - The locale matrix used en_US.UTF-8, which is not installed on the runner, so bash itself warned and the assertion was measuring the absent locale rather than the export fix. Unavailable locales are skipped with that reason stated. And the stripper test is reframed. It compared the stripped hook against the merge base, which asserted two unrelated things — that the stripper is exact, and that no hook was edited for any other reason. The second went red the moment a hook had a real defect fixed. It now asserts the property that actually protects the A/B control: every line removed is a preamble line and none is added. Mutation-checked — widening the stripper to eat `set -` lines turns it red. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:58 +02:00
timothyandClaude Opus 5	1a2b5758be	docs(776): pin the signal matrix to a sha and its reproduction ... Independent re-measurement confirmed all twelve cells (five repeats each, unanimous), that HEAD matches the control everywhere, and that the group-kill test is blind to the trapped sink — the last with a positive control, patching the trapped re-raise back to `exit 0` to watch the same test go red. The table now names the sha it measured rather than a round number, and carries the command that produces it. Third version of this paragraph; the first was fabricated and the second inverted, both because a number was written without the means to re-derive it. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:58 +02:00
timothyandClaude Opus 5	7d27690185	docs(776): my correction to the fabricated measurement was itself inverted ... Round 6 found a Blocker, and it is in the decision record rather than the code: the paragraph written LAST round to correct a fabricated measurement contains an inverted one. Same mistake, one round later, in the artifact written to fix it — and by the same route, taking a review summary without re-measuring. Claimed: the round-3 trapped sink "returned rc 0 on SIGINT where the control returns -2". Measured myself, 12 cells ({group,pid} x {TERM,INT,HUP} x {control, round-3, HEAD}): pid + INT: control 0 round-3 -2 HEAD 0 Exactly inverted. 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. The record now prints the matrix instead of asserting a conclusion about it. A second false claim in the same paragraph, also removed: that the test's exit-status assertion "catches the SIGINT case". It does not. 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 pins the transparency of the code that ships; it is not evidence any earlier version was worse, and the record now says so. Also this round: - The job-notice exemption in the signal A/B hides a line that NAMES the sink's path on a guard's stderr (bash attributing its own message to the executing line). That is a real if small leak and the exemption conceals it. Accepted rather than fixed — it cannot be suppressed while the sink does any work at exit — but stated plainly instead of left as "bash's notice, harmless". - docs/guard-inventory.md records the withdrawn redirect-order guard and, more importantly, what the surviving exec-only guard does NOT cover. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:58 +02:00
timothyandClaude Opus 5	f729c962b3	fix(776): the 256KB cap reintroduced the defect it was added beside ... Round 6. One High, and it is round 5's own fix: bounding the payload scan to 256KB to make it fast reintroduced the truncating read that round 5 had just removed. A payload whose filler pushes session_id past the cap returns nothing, the record files under `unknown-session`, and that fire reads as NEVER HAVING HAPPENED. My nested-field test could not see it — its identities sit before only 1000 bytes of filler. The cap is now a fast path with an unbounded fallback, so it is an optimisation rather than a correctness dependency. Verified with identity 400KB deep. Also this round: - The field helper was defined inside a function and so was globally scoped under a short generic name, able to collide with a hook's own function. Namespaced and unset after use. - WITHDRAWN: the generalised redirect-order guard. Four iterations, each fixing a false positive or negative the last introduced, and review then constructed more of both. Deleted rather than patched a fifth time, per the withdrawal precedent in docs/guard-inventory.md — a weak detector is itself the symptom-keyed mistake. The narrower exec-only guard is retained: a sound match on a fixed keyword, covering every case that has actually occurred. - The signal A/B compared only status and timing and DISCARDED stdout/stderr. It now compares both, which surfaced a real difference: on a group kill with a live child, bash prints a job-control notice the control does not. Isolated to "the exit handler does work, so the shell lives ~50ms longer" — inherent to the sink's purpose. Exempted narrowly, by the signal word only, and documented as a measured limit rather than papered over. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:57 +02:00
timothyandClaude Opus 5	d3bc13fd5c	docs(776): re-verify the 5.4 measurement against the shipped sink ... The table was measured against an early version of the sink and the classifier changed materially afterwards, so the numbers were a claim about code that no longer existed. Repeated against the final implementation: identical decisions for all five Claude hooks a Bash/Write session reaches. States what the repeat did NOT cover — the Agent pair and the four git hooks are carried over from the original run — rather than implying the whole table was re-measured. Refs: #776 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:57 +02:00
timothyandClaude Opus 5	bd40c962cf	fix(776): the locale fix was inert, and my withdrawal rationale was fabricated ... Round 5, two independent reviews. Two findings, one technical and one about honesty, and the second is the more important. THE RATIONALE. The round-4 commit and the decision record state as measured fact that trapping signals made a hook take 30s to die where it took 1s. That came from a review finding I accepted without re-measuring. It is wrong. Measured A/B: signal the pid control 4.01s trapped 4.12s signal the group control 0.002s trapped 0.054s The stall is bash deferring a fatal signal until its foreground command finishes, and it happens identically with NO trap — the control stalls too. The trap cost ~0.1s, not 29s. The withdrawal still stands, but on its real grounds: three silent permissive-direction defects in three rounds for a sub-millisecond rescue window, and the trapped sink STILL returned rc 0 on SIGINT where the control returns -2. The record now carries the correction rather than the fabrication, because a decision record with an invented measurement reads as checked and talks the next reader out of checking. The test that was supposed to enforce this was itself vacuous: it signalled the pid, so both sides took the full sleep and the timing assertion could distinguish nothing. It signals the process group now — the supervisor shape, and the only one where the assertion can see anything. THE LOCALE FIX WAS INERT. `local LC_ALL=C` does not export, so the child sed/tr never saw it. It read as fixed only because this author's shell sets LANG alone; with an inherited LC_CTYPE (macOS Terminal, ssh SendEnv, sudo env_keep) LC_CTYPE outranks the exported LANG=C and the symptom returns in full — a real deny filed as `output`, records under `unknown-session` with empty event and tool, and `illegal byte sequence` at the harness. `local -x` now, verified end-to-end across four locale environments, and the test is parametrised over them because a single ambient locale tests one row of the matrix. Also this round: - Removing the 64KB cap ARMED a latent bug rather than fixing one: a greedy `.*` over a single-line payload takes the LAST match, so a nested session_id inside a tool_response outranked the top-level one and filed the whole invocation under the wrong session. The cap had been accidentally protecting the right answer. First-match extraction now, bounded at 256KB where the bound is no longer load-bearing (3 unbounded scans cost 1.5s on a 20MB payload). - A present-but-empty decision value was laundered to `output`. - The redirect-order guard excluded operators preceded by a digit, so it was blind to `exec 0<` — the exact line it was written for. Mutation-checked both ways now: clean on the real file, red when the original bug is reintroduced verbatim. Its limits are stated in the docstring rather than implied. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:57 +02:00
timothyandClaude Opus 5	ad636132b7	fix(776): withdraw the signal trap rather than fix it a fourth time ... Round 4, two independent reviews. No Blocker, but the signal trap produced its third defect in three rounds and the fourth finding settles it: bash does not run a trap handler until the current foreground command completes. Measured, same hook, SIGTERM to the pid: uninstrumented dies in 1s, instrumented in 30s. A TERM-then-KILL supervisor therefore gets no flush AT ALL plus a 29s stall — strictly worse than untrapped, on the exact path the trap existed for. So it is withdrawn, not patched again. What that loses is enumerated in the decision record (a killed hook's exit record, its already-printed stdout, its temp files) rather than waved past. The invariant that replaces it is stronger and is asserted as an A/B: under a signal, instrumented and uninstrumented are indistinguishable in BOTH exit status and time to die. The timing half is what the trap broke, and no assertion about output could have caught it. Also fixed this round: - A signalled hook was RECORDED as code=0 decision=pass, because `local sig=...` clobbers `$?` before the flush can read it. git blocked correctly while the log said the killed guard passed. Moot now the trap is gone, but it is why the signal tests assert the record and not only the process status. - The classifier's sed/tr were locale-aware, so one 0xE9 byte in a deny reason printed `illegal byte sequence` at the harness AND filed a real deny as `output`. LC_ALL=C. - Payload fields were read from a 64KB 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. Unbounded now. - `cat <&4 2>/dev/null` and `cat > "$sin" 2>/dev/null`: the SAME left-to-right redirect hazard, at two more commands. The previous guard grepped only `exec`, so it walked past both — the class was named, not removed. test_no_redirection_in_the_sink_PRECEDES_its_stderr_redirect now covers any command, exempting `2>&1` (which is correct precisely because it comes after). - `deny2`/`deny_now` extracted as `output` rather than `unrecognized`; an inherited ETV_HOOK_FIRE_FLUSHED=1 disabled reporting entirely; unclassified output plus a failing exit hid the failure as `output`; NUL bytes were dropped and warned about on stderr. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:57 +02:00
timothyandClaude Opus 5	830939b4ff	docs(776): record the round-3 lesson — the fix was worse than the defect ... Three review rounds, and every round found the previous round's FIX had introduced something beside its target. That is the transferable finding, not any individual bug, so it goes in the record rather than only in a commit message. Also names the pattern that cost two of those rounds: a fix that reads as applied while changing nothing (a scrubber that permits the very characters it was added to remove), and a rule restated in a comment three times instead of enforced once by a test. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:57 +02:00
timothyandClaude Opus 5	b9f031f52a	fix(776): a signal must not become consent ... Round 3, from two independent re-reviews of the round-2 fix commit. The fix for the lost-output-on-SIGTERM defect introduced a worse one than the defect. The signal handler ended in `exit "$?"`, and `$?` at signal time is the status of whatever command was running — normally 0 for a guard still gathering evidence. Measured on the real guard, `prepush-donewhen.sh` SIGTERMed mid-curl with an unticked Done-when box: uninstrumented rc=-15 git ABORTS the push instrumented rc=0 git PUSHES to main That converts a killed guard into consent, in the permissive direction, in the hook that protects `main`. The handler now flushes, restores the default disposition and re-raises the signal, so the process dies the way it would have died. test_output_survives_a_SIGTERM could not see it: it asserts stdout content, never reads the return code, and drives a capture-mode hook so no exit-code guard is ever signalled. Also from this round: - The flush ran TWICE on the signal path (signal handler, then EXIT trap), writing two contradictory exit records for one invocation — a real decision then a phantom no-op — so the report mis-histogrammed the very case the trap was added for. It is idempotent now. - `exec 4<&- 2>/dev/null`: the round-1 blocker pattern again, eight lines below the comment forbidding it. Rather than fix the third instance and wait for a fourth, test_no_exec_in_the_sink_carries_a_STDERR_REDIRECT now enforces it. - The log write leaked `Operation not permitted` to stderr on an unwritable log, because `>> "$file" 2>/dev/null` opens the file BEFORE redirecting stderr. The fail-open test used a path that dies at mkdir and never reached this. - Classification: an unrecognised value is no longer lowercased into a valid decision, exit 2 now dominates a printed `allow` (it is the harness's block channel, and reporting a permit for a refused call is the one direction this log must never be wrong in), and a non-zero exit no longer annotates a real decision with an invented `+error`. - Classification and replay read the same bytes; they disagreed when a hook used fd 4, so the harness saw `deny` while the log recorded `no-op`. - The stderr normaliser rewrote `line N:` globally, collapsing genuinely different diagnostics; it is anchored to the script-path prefix now. - docs 5.4 claimed the two zero rows were "trigger did not fire", justified by unit tests that invoke the scripts directly and therefore prove nothing about harness dispatch. It now separates what is established from what is not, and stops contradicting its own decision record. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:57 +02:00
timothyandClaude Opus 5	183df2bb3d	fix(776): the instrumentation was silencing every hook's stderr ... Round 2, from two independent cold reviews. The headline defect was found by the test the reviews prompted rather than by the reviews themselves: exec 0<"$sin" 2>/dev/null reads as "suppress errors from this redirection". It is not. `exec` with redirections and no command applies them to the shell PERMANENTLY, so this sent each hook's ENTIRE stderr to /dev/null. Every husky guard's user-facing output is stderr — the H6 "push to main BLOCKED" message, the BOM guard's remediation text, the missing-trailer message — so the guards went on blocking correctly while telling the human nothing about why. Invisible to the original A/B, which compared only stdout and exit status. The finding that exposed it was ranked Low ("the A/B ignores stderr"). Also fixed, each with an executed proof: - The fd restore sat inside the same conditional as the replay, and the replay read the PATH, so an unlinked-but-open scratch file meant a swallowed `deny` at exit 0. Restore is now unconditional and the replay reads through a held fd, which survives unlink. - A SIGTERMed hook lost output it had already printed (52 bytes -> 0). Bash runs no EXIT trap for an untrapped fatal signal; INT/TERM/HUP are trapped now. - The classifier misreported an uppercase decision as prose, read the bare word additionalContext in free text as a decision, and let a non-zero exit ERASE a decision the hook really printed. - The session id reached the log FILENAME unscrubbed. The first fix reused the record scrubber, which deliberately keeps `/` and `.`, so `../../escaped` went through untouched: passing a value through a scrub is not the same as passing it through the right scrub. - Preamble line 1 could abort a `set -e` hook, turning a fail-open guard fail-closed; and a missing sink printed `command not found` to stderr. The big one is test quality. `test_instrumentation_changes_NOTHING_the_harness_ can_see` was 160/165 empty-vs-empty and 165/165 exit-0-vs-exit-0, so deleting the whole replay left it green for four hooks, two of which issue `deny`. Three places claimed the matrix reached every deciding branch, including the decision record. It now constructs the missing cases — a foreign worktree marker, a BOM `.cs` in an *ersatztv*-named repo, stubbed memory_pressure, a real bare remote for the three pre-push guards, a stub Gitea for prepush-donewhen — and test_the_AB_is_not_VACUOUS_for_any_hook fails unless each hook has a case where the control side actually says something. Running pytest also wrote 115 synthetic fires into the production log, so the report described the test suite while looking like a record of real sessions. scripts/tests/conftest.py isolates every test; verified live, a full suite run now leaves the real log untouched. Refs: #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:57 +02:00
timothyandClaude Opus 5	773151be14	docs(776): re-derive 773 section 5.4 from measurement, not inference ... Section 5.4 said we cannot tell whether our own hooks fire, and could only count filename mentions in settings dumps. It now carries a per-hook table with the decision each hook reached: 11 of 13 confirmed firing, including a real deny from pretooluse-bash-guard blocking an ETV_UPDATE_GOLDENS probe, which is what distinguishes "this guard ran" from "this guard is present". The two zeroes are named as the not-exercised kind rather than presented as a verdict — nav-guard needs a live browser and merge-consent needs a real merge, and manufacturing a merge to watch the merge guard is worse than the gap. Refs: #776 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:57 +02:00
timothyandClaude Opus 5	fc65b5fbe3	docs(776,784): state the hazard, not the author's timeline ... Applies ersatztv#784's who-benefits test to this change's own prose: if only the author's timeline explains why a sentence is there, it is narrative. Three comments said "the first version of this did X" where the reader only needs the hazard and the reason nothing downstream would catch it. One of the three turned into a real correction rather than a reword. The byte-exactness test was justified as "the A/B does not cover this", which is sharper and also true: the A/B compares the two halves against each other, so a wrapper that truncated BOTH would pass it. Only comparing against the literal expected bytes catches that. Refs: #776 Refs: #784 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:57 +02:00
timothyandClaude Opus 5	56ed794ff7	feat(776): every hook reports that it fired, and the report is measured ... In this harness version only `Stop` hooks emit a structured transcript record. `PreToolUse` and `PostToolUse` hooks leave no durable execution trace — which is every guard this repo relies on. #773 §5.4 could therefore only count filename mentions in settings dumps, i.e. inference, so a silently broken hook looked identical to a working one indefinitely. Each hook now sources one shared sink, `scripts/hook-fire-log.sh`, and records a `fire` record on entry and an `exit` record carrying its status and decision. The decision is parsed from the bytes the hook actually emitted rather than declared by the author: Claude hooks always exit 0 and decide by printing JSON, so stdout is diverted and replayed; git hooks decide by exit code and stream their output, so theirs is left alone. That avoided ~40 edits inside pretooluse-merge-consent and records what the harness sees rather than what the author meant. The instrumentation sits in the stdin/stdout path of the most authoritative guards in the repo, so transparency is the load-bearing claim, not coverage: test_instrumentation_changes_NOTHING_the_harness_can_see drives every hook with and without it over a payload matrix reaching each hook's deciding branch, and demands byte-equal stdout and equal exit status. It shipped with two defects that only that shape catches — `out=$(cat f)` stripping a trailing newline, and an unconditional stdin slurp that hangs on a TTY and would have frozen every interactive `git commit`. Both are now pinned, the second through a real pty. fixes #776 Decisions-Edit: yes Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>	2026-08-14 18:52:20 +02:00