diff --git a/CHANGELOG.md b/CHANGELOG.md index 5579bbc..5ea60c1 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -34,6 +34,44 @@ which records not just what changed but what each drill run proved. ### Fixed +- **`box-firewall` could hand a UFW host the no-UFW firewall, ~2% of the + time** (#102) — filed as an intermittent test flake (`test/cli.sh`'s + fresh-UFW block going four-assertions-red on an unmodified `main`, + measured here at 5 failing runs in 40), it was not one. The branch that + decides the host's entire firewall stance read + `ufw status | grep -q "Status: active"`, and `Status: active` is the FIRST + line ufw prints: `grep -q` matches it and exits immediately, closing the + pipe while ufw is still writing the rest of the table, so ufw dies of + SIGPIPE. `grep` returned 0, but under this script's `set -o pipefail` the + PIPELINE returns 141 — the `if` reads false and a host with UFW plainly + active takes the nft-fallback branch, never building the DNS carve-out its + persisted rules depend on. A pure scheduling race, isolated at ~2% per + invocation (`PIPESTATUS` = `141 0`; a draining reader flakes 0/2000, a + reader whose match is on the last line flakes 0/2000). Real ufw is a + slower, longer writer than the test shim, so production had no reason to + be safer. `ufw status` is now read ONCE into a variable and matched with + `[[ ]]` — no reader, no race — and the stale-rule scan reads that same + snapshot, so the branch decision and the converge loop can no longer + disagree. **`host/teardown-host.sh` carried the same live defect** and is + fixed with it: that file does set `pipefail` (line 12), so its UFW + crumb-removal branch could read a plainly-active UFW as inactive and skip + silently, leaving stale `boxnet`/`claudenet` rules on a host the operator + was told is clean — and its numbered-delete loop had the same early-exit + reader as its condition, so it could end while rules remained. Both now + read captures. The sibling calls in `drill/wipe.sh` and `drill/doctor.sh` + are the same shape but set only `set -u`, so the SIGPIPE is discarded + there and the branch holds — latent, not live, until either gains + `pipefail`. +- **A missing firewall log now diagnoses itself** (#102) — the four greps + reading `$WFW/*.log` used to fail together with empty output when the + driving run took the wrong branch, a signature that looks specific and + says nothing (#102 was filed reading it as "the log is not written"; + the log existed, the mutations did not, and that distinction *was* the + diagnosis). `test/cli.sh` now asserts the precondition explicitly before + the content greps and, on failure, prints the contents of `$WFW`, the log + itself, and the stderr of the run that should have written it. It also + keeps `an agreeing UFW host deletes nothing` honest: that check asserts an + absence, which a run that did nothing at all passes for the wrong reason. - **`box grant` provisions an `incus-admin` member instead of refusing them** (#99) — the refusal read "they already have the admin tier; there is nothing tighter to grant", which is true about *permission* and silent @@ -108,6 +146,7 @@ which records not just what changed but what each drill run proved. opens as them, and dropping `incus-admin` leaves them in their own project with no re-grant. + ## 0.7.0 — 2026-07-19 ### Added diff --git a/host/box-firewall.sh b/host/box-firewall.sh index d7959bf..0d85579 100644 --- a/host/box-firewall.sh +++ b/host/box-firewall.sh @@ -19,7 +19,35 @@ NET=boxnet # ('|| true': under pipefail an absent bridge would kill the script here.) GW="$(ip -4 -o addr show dev "$NET" 2>/dev/null | awk '{ split($4, a, "/"); print a[1]; exit }' || true)" -if command -v ufw >/dev/null && ufw status 2>/dev/null | grep -q "Status: active"; then +# Read `ufw status` ONCE, into a variable, instead of piping it at a matcher. +# The pipe it replaces — `ufw status | grep -q "Status: active"` — was a latent +# branch-flipper, and the branch it flips is the whole firewall. "Status: +# active" is the FIRST line ufw prints, so `grep -q` matches it and exits +# immediately, closing the read end while ufw is still writing the rest of the +# table; ufw then dies of SIGPIPE (141). `grep` reported 0, but under the +# `set -o pipefail` at the top of this file the PIPELINE reports 141, so the +# `if` reads false and a host with UFW plainly active takes the no-UFW branch +# below — installing the nft fallback table and never building the DNS +# carve-out its persisted rules are counting on. It is a pure scheduling race +# between two processes, which is the worst possible property for a decision +# this load-bearing: measured at ~2% per invocation under test/cli.sh's shims +# (#102, where it surfaced as an intermittent four-assertions-red test and got +# read as flakiness for exactly as long as it was cheaper to re-run than to +# diagnose). Real ufw is a Python program with a slower, longer write than the +# shim's single printf, so there is no reason to think production is safer. +# A variable has no reader that can exit early, so the race cannot exist. +# The capture doubles as the snapshot the converge loop below reads, so the +# branch decision and the stale-rule scan are made against the same text +# rather than two reads that could disagree across an intervening change. +# ('|| true': ufw exits non-zero when it cannot read its config, and under +# pipefail+errexit that would kill the script instead of falling through to +# the nft branch, which is the correct answer for "ufw is not usable here".) +UFW_STATUS="" +if command -v ufw >/dev/null; then + UFW_STATUS="$(ufw status 2>/dev/null || true)" +fi + +if [[ "$UFW_STATUS" == *"Status: active"* ]]; then if [ -z "$GW" ]; then echo "box-firewall: $NET has no address yet — UFW DNS carve-out left as-is (no rule beats a wrong one; the persisted rules survive boots, and setup-host or a service restart converges them once the bridge is addressed)" >&2 else @@ -32,7 +60,9 @@ if command -v ufw >/dev/null && ufw status 2>/dev/null | grep -q "Status: active # anywhere else, then ensure the live set: ufw skips a rule that already # exists, so the re-run is a no-op and a fresh host gets exactly the # rules it always did. - for stale in $(ufw status | awk -v net="$NET" -v gw="$GW" ' + # Scanned off the same $UFW_STATUS snapshot the branch was decided from — + # see the capture above for why this is not a second `ufw status` call. + for stale in $(printf '%s\n' "$UFW_STATUS" | awk -v net="$NET" -v gw="$GW" ' $2 ~ /^53\// && $3 == "on" && $4 == net && $1 != gw { print $1 }' | sort -u); do ufw delete allow in on "$NET" to "$stale" port 53 proto tcp || true ufw delete allow in on "$NET" to "$stale" port 53 proto udp || true diff --git a/host/teardown-host.sh b/host/teardown-host.sh index 4a3d5d3..b957ed0 100755 --- a/host/teardown-host.sh +++ b/host/teardown-host.sh @@ -57,10 +57,37 @@ sudo systemctl daemon-reload # Firewall crumbs — UFW rules mentioning either network (numbers shift after # each delete, so re-scan and remove the first match until none remain) -if command -v ufw >/dev/null && sudo ufw status 2>/dev/null | grep -q "Status: active"; then +# Every ufw read is CAPTURED before it is matched, never piped into a reader +# that can exit early — the same discipline box-firewall.sh now uses, and for +# the same measured reason (#102). This file sets `pipefail` (line 12), so +# `ufw status | grep -q "Status: active"` returns the WRITER's exit: grep +# matches on the first line ufw prints, closes the pipe, ufw takes SIGPIPE, +# and the pipeline yields 141. A plainly-active UFW then reads as inactive +# and this entire block silently skips, leaving stale boxnet/claudenet rules +# on a host the operator was told is clean. It is a branch condition, so +# errexit never fires — there is no error to see, which is exactly why it +# went unnoticed here while the same shape was being measured next door. +# +# The numbered loop had the same defect for a different reason: its condition +# was also an early-exit reader, so it could end while rules remained. It now +# reads one capture per iteration and breaks on absence — the re-scan is still +# per-delete (numbers shift after each removal), just no longer racing. +ufw_status="" +if command -v ufw >/dev/null; then + # '|| true': ufw exits non-zero when it cannot read its config, and under + # pipefail+errexit that would kill a teardown instead of correctly deciding + # "no usable ufw here, nothing to clean". + ufw_status="$(sudo ufw status 2>/dev/null || true)" +fi + +if [[ "$ufw_status" == *"Status: active"* ]]; then for net in boxnet claudenet; do - while sudo ufw status numbered | grep -q "on $net"; do - n="$(sudo ufw status numbered | grep -m1 "on $net" | sed -E 's/^\[ *([0-9]+)\].*/\1/')" + while :; do + numbered="$(sudo ufw status numbered 2>/dev/null || true)" + line="$(printf '%s\n' "$numbered" | grep -m1 "on $net" || true)" + [ -n "$line" ] || break + n="$(printf '%s\n' "$line" | sed -E 's/^\[ *([0-9]+)\].*/\1/')" + [ -n "$n" ] || break sudo ufw --force delete "$n" done done diff --git a/test/cli.sh b/test/cli.sh index e4f38c5..a0ac95c 100644 --- a/test/cli.sh +++ b/test/cli.sh @@ -1255,10 +1255,57 @@ SHIM chmod +x "$UFWSHIM/ufw" "$FWSHIM/nft" "$FWSHIM/sysctl" "$FWSHIM/iptables" runfw() { # runfw [VAR=val ...] — the real box-firewall, under shims - local mode="$1" p; shift + local mode="$1" p rc=0; shift p="$FWSHIM:$SHIMDIR:$PATH" [ "$mode" = ufw ] && p="$UFWSHIM:$p" - env PATH="$p" "$@" bash "$ROOT/host/box-firewall.sh" + # Stderr is captured to a file AND re-emitted, rather than only passed + # through. The driving `check` swallows the output of a run that passes, so + # when a later grep over the log fails there is nothing left to read — which + # is precisely the hole #102 fell into. Keeping a copy on disk lets + # fwlog_ready below show what the run actually said. Overwritten per call by + # design: every fwlog_ready sits immediately after its own runfw, so "the + # last run" is always the run being diagnosed. + env PATH="$p" "$@" bash "$ROOT/host/box-firewall.sh" 2>"$WFW/last-run.err" || rc=$? + cat "$WFW/last-run.err" >&2 + return "$rc" +} + +# fwlog_ready — the shimmed ufw actually logged mutations to . +# +# Why this exists (#102): every grep in the blocks below reads a log written by +# the shimmed ufw during the driving `runfw` check. When something stops the +# UFW branch of box-firewall.sh from running at all, that log is missing — or, +# as it turned out, present but holding nothing except the `ufw status` probe. +# The greps then fail four-at-a-time with empty output: a signature that looks +# alarmingly specific and carries no information whatsoever. #102 was filed +# reading it as "the log is not written", which was a reasonable inference from +# four blank failures and was also wrong; the file was there, the mutations +# were not, and that distinction is the entire diagnosis. So assert the +# precondition explicitly, before the content greps, and on failure print what +# IS in $WFW, what the log itself holds, and what the run wrote to stderr. The +# fix below should mean this never fires — it is here for the next cause, not +# this one, and its whole job is to hand over the evidence instead of making +# the next person re-derive it from a re-run loop. +fwlog_ready() { + local log="$1" muts + if [ -f "$log" ]; then + muts="$(grep -vc "^ufw status" "$log")" + [ "$muts" -gt 0 ] && return 0 + echo "DIAGNOSIS: $log exists but logs no ufw MUTATION (only 'ufw status')." + echo " => box-firewall.sh took its no-UFW branch; the UFW carve-out never ran." + else + echo "DIAGNOSIS: $log does not exist — the shimmed ufw was never invoked." + fi + echo " \$WFW ($WFW) holds:" + # shellcheck disable=SC2012 # a human-read diagnostic dump, not parsed: `ls -la` + # shows sizes and mtimes, which is the whole point here (a zero-byte log and a + # log that was never created are different failures). $WFW is our own mktemp -d. + ls -la "$WFW" 2>&1 | sed 's/^/ /' + echo " contents of $(basename "$log"):" + { [ -f "$log" ] && cat "$log" || echo "(absent)"; } 2>&1 | sed 's/^/ /' + echo " stderr of the run that should have written it:" + { [ -s "$WFW/last-run.err" ] && cat "$WFW/last-run.err" || echo "(empty)"; } 2>&1 | sed 's/^/ /' + return 1 } # Canned `ufw status` tables, modeled on the real output shape. @@ -1287,6 +1334,7 @@ BX89='5: boxnet inet 10.89.0.1/24 scope global boxnet' # 10.88's carve-out — the stale allows go, the live gateway's land. check "box-firewall: a remapped bridge CONVERGES the UFW carve-out" 0 "" \ runfw ufw FAKE_IP4_BOXNET="$BX89" FAKE_UFW_STATUS="$U_OLDGW" FAKE_UFW_LOG="$WFW/remap.log" +check "box-firewall: ...the run logged ufw mutations at all" 0 "" fwlog_ready "$WFW/remap.log" check "box-firewall: ...the stale tcp allow is deleted" 0 "" \ grep -qF 'ufw delete allow in on boxnet to 10.88.0.1 port 53 proto tcp' "$WFW/remap.log" check "box-firewall: ...and the stale udp allow" 0 "" \ @@ -1302,12 +1350,17 @@ check "box-firewall: ...the live gateway's rules are never deleted" 1 "" \ # (ufw itself skips the re-adds as existing rules). check "box-firewall: an agreeing UFW host deletes nothing" 0 "" \ runfw ufw FAKE_IP4_BOXNET="$BX89" FAKE_UFW_STATUS="$U_LIVEGW" FAKE_UFW_LOG="$WFW/agree.log" +# This one matters more than it looks: "no delete was issued" is an ASSERT-ABSENT +# check, so a run that issued nothing at all passes it for the wrong reason. +# fwlog_ready is what keeps the absence meaningful. +check "box-firewall: ...the run logged ufw mutations at all" 0 "" fwlog_ready "$WFW/agree.log" check "box-firewall: ...no delete was issued" 1 "" grep -qF ' delete ' "$WFW/agree.log" # The fresh host: no boxnet rules yet — exactly the five historical commands, # aimed at the live gateway, and nothing else (unchanged behavior). check "box-firewall: a fresh UFW host runs clean" 0 "" \ runfw ufw FAKE_IP4_BOXNET="$BX88" FAKE_UFW_STATUS="$U_FRESH" FAKE_UFW_LOG="$WFW/fresh.log" +check "box-firewall: ...the run logged ufw mutations at all" 0 "" fwlog_ready "$WFW/fresh.log" check "box-firewall: ...the deny lands" 0 "" \ grep -qF 'ufw insert 1 deny in on boxnet' "$WFW/fresh.log" check "box-firewall: ...the DNS allows aim at the live gateway" 0 "" \ @@ -1642,6 +1695,27 @@ check "teardown-host: honors --yes/BOX_YES (CI runs it unattended)" 0 "" \ grep -qF 'BOX_YES' "$ROOT/host/teardown-host.sh" check "teardown-host: points at box uninstall when done" 0 "" \ grep -qF "box uninstall" "$ROOT/host/teardown-host.sh" + +# #102's race, in the one other file that sets pipefail. A daemon-free run +# cannot exercise a UFW teardown, so the shape is pinned instead: no `ufw +# status` may be piped into an early-exit reader here, because under this +# file's pipefail the reader's match closes the pipe, ufw takes SIGPIPE, and +# the branch silently reads false — skipping crumb removal on a host the +# operator was told is clean. Both directions: the racing shape absent, the +# capture present. +# Comment lines are stripped before matching: the fix's own commentary quotes +# the racing shape to explain it, and a pin that cannot tell prose from code +# would fail on the very comment documenting why it exists. +# shellcheck disable=SC2016 # "$1" is the subshell's positional, passed below +check "teardown-host: no 'ufw status' piped into an early-exit reader" 0 "" \ + bash -c 'grep -vE "^[[:space:]]*#" "$1" | grep -qE "ufw status[^|]*\| *grep" && exit 1; exit 0' \ + _ "$ROOT/host/teardown-host.sh" +# shellcheck disable=SC2016 # the $-strings are literals in the target file +check "teardown-host: the UFW branch reads a captured snapshot" 0 "" \ + grep -qF 'if [[ "$ufw_status" == *"Status: active"* ]]; then' "$ROOT/host/teardown-host.sh" +# shellcheck disable=SC2016 # ditto +check "teardown-host: the numbered-delete loop breaks on absence, not on a pipe" 0 "" \ + grep -qF '[ -n "$line" ] || break' "$ROOT/host/teardown-host.sh" check "drill: reads the installed tree through current/" 0 "" \ grep -qF '.local/share/box/current/VERSION' "$ROOT/drill/drill.sh"