From 98560594cf88cc19897852873e27a74be74f5884 Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Thu, 23 Jul 2026 04:16:16 +0000 Subject: [PATCH 1/3] Prove ACL rejection per peer by matching a single log line The four rejection checks were independent greps over the whole log: two npubs, a context and a decision. Together they proved only that node-a mentioned each npub somewhere, rejected somebody on an inbound handshake, and rejected somebody by denylist. Nothing tied a rejection to a named peer, and node-a lists both denied peers as auto_connect peers, so it logs their npubs on the outbound connect path whether or not any rejection ever happened. The actual message was never matched. Replace them with a helper that requires every given string on ONE line, and assert per denied peer: the real message, that peer's npub, and the denylist decision together. Strings match in any order by chaining fixed-string greps over the surviving lines, so the assertion does not depend on how the log formatter orders a message and its fields. A grep over empty input yields the empty string rather than anything a caller could mistake for a match, so an unreadable container times out and fails instead of passing. Two limits are written at the call sites rather than left implied. The decision conjunct discriminates nothing, since the two allowing variants return early and denylist is the only value that can reach that warning. And node-a authorizes before dialing, so it emits a fully formed rejection line for each denied peer on the outbound path; these assertions are satisfiable without the inbound check running at all, and it is the peer-count assertions that would catch that. Verified against the running harness: all three find a real matching line. The defect shape they replace was exercised offline first, with the three strings spread across three lines, where the old checks passed and the new ones fail. --- testing/acl-allowlist/test.sh | 97 +++++++++++++++++++++++++++++------ 1 file changed, 81 insertions(+), 16 deletions(-) diff --git a/testing/acl-allowlist/test.sh b/testing/acl-allowlist/test.sh index f2dff98..1bf9905 100755 --- a/testing/acl-allowlist/test.sh +++ b/testing/acl-allowlist/test.sh @@ -116,27 +116,62 @@ wait_for_peers_exact() { exit 1 } -assert_log_contains() { +# Assert that ONE log line in $container contains every one of the given +# fixed strings. +# +# Single-line matching is the point. Independent whole-log greps for an +# npub and for `decision=denylist match` are jointly satisfied by "this +# npub appears somewhere" plus "somebody was rejected by denylist", which +# is not the property this suite exists to prove. Node-a lists the denied +# peers as auto_connect peers, so it logs their npubs on the outbound +# connect path whether or not a rejection ever happened; the npub has to +# be on the rejection line itself to mean anything. +# +# Strings match in any order, by chaining fixed-string greps over the +# surviving lines, so the assertion does not depend on the order the +# tracing formatter emits a message and its fields in. A grep over empty +# input yields the empty string rather than a value that could satisfy +# the caller, so a container that cannot be read times out and fails +# rather than passing. +# +# Polls rather than reading once: under the XX handshake the +# cross-connection tie-breaker decides which side reaches its ACL check +# first, so an inbound-handshake rejection may not emit until a later +# retry. Same wait-with-timeout shape as wait_for_peers_exact above. +# +# Deliberately NOT registered in check-log-strings.py's SHELL_HELPERS, +# for two reasons, and note that registering it would in fact capture +# nothing: that extractor reads only a helper's FIRST argument and only +# when it is a quoted literal free of `$` (check-log-strings.py:116), +# whereas the first argument here is the unquoted container name +# carrying ${FIPS_CI_NAME_SUFFIX}. Verified by running the extractor +# with this helper added: zero hits. The same is true of the +# `assert_log_contains` this replaced, so nothing left the check's scope. +# +# It should stay out of scope regardless: that check exists for strings +# whose disappearance from src/ would let an assertion silently pass, +# and every string here is a positive requirement, so a missing one +# exhausts the poll and exits 1, which is loud. +assert_log_line_contains_all() { local container="$1" - local pattern="$2" - local timeout="${3:-15}" - local logs + local timeout="$2" + shift 2 - # Poll docker logs instead of one-shot reading: under XX handshake, - # the cross-connection tie-breaker determines which side reaches - # its ACL-check point first, so the inbound-handshake-context - # rejection may not emit until a later retry. Same wait-with-timeout - # shape as wait_for_peers_exact above. + local logs surviving pattern for _ in $(seq 1 "$timeout"); do logs="$(docker logs "$container" 2>&1 | python3 -c 'import re,sys; print(re.sub(r"\x1b\[[0-9;]*m", "", sys.stdin.read()), end="")' || true)" - if printf '%s' "$logs" | grep -F "$pattern" >/dev/null; then - echo "PASS: $container logs contain expected ACL rejection" + surviving="$logs" + for pattern in "$@"; do + surviving="$(printf '%s' "$surviving" | grep -F -- "$pattern" || true)" + done + if [ -n "$surviving" ]; then + echo "PASS: $container has a log line matching all of: $*" return 0 fi sleep 1 done - echo "FAIL: missing log pattern in $container: $pattern (waited ${timeout}s)" >&2 + echo "FAIL: no single log line in $container contains all of: $* (waited ${timeout}s)" >&2 exit 1 } @@ -175,9 +210,39 @@ assert_acl_field fips-acl-container-c${FIPS_CI_NAME_SUFFIX:-} allow_file_entries assert_acl_field fips-acl-container-c${FIPS_CI_NAME_SUFFIX:-} allow_entries "npub1cld9yay0u24davpu6c35l4vldrhzvaq66pcqtg9a0j2cnjrn9rtsxx2pe6 npub1n9lpnv0592cc2ps6nm0ca3qls642vx7yjsv35rkxqzj2vgds52sqgpverl npub1sjlh2c3x9w7kjsqg2ay080n2lff2uvt325vpan33ke34rn8l5jcqawh57m npub1tdwa4vjrjl33pcjdpf2t4p027nl86xrx24g4d3avg4vwvayr3g8qhd84le npub1x5z9rwzzm26q9verutx4aajhf2zw2pyp34c6whhde2zduxqav40qgq36l6 npub1ytrut7gjncn2zfnhn56c0zgftf0w6p99gf6fu8j73hzw5603zglqc9av6c" log "Checking ACL rejection logs" -assert_log_contains fips-acl-container-a${FIPS_CI_NAME_SUFFIX:-} "npub1cld9yay0u24davpu6c35l4vldrhzvaq66pcqtg9a0j2cnjrn9rtsxx2pe6" -assert_log_contains fips-acl-container-a${FIPS_CI_NAME_SUFFIX:-} "npub1n9lpnv0592cc2ps6nm0ca3qls642vx7yjsv35rkxqzj2vgds52sqgpverl" -assert_log_contains fips-acl-container-a${FIPS_CI_NAME_SUFFIX:-} "context=inbound_handshake" -assert_log_contains fips-acl-container-a${FIPS_CI_NAME_SUFFIX:-} "decision=denylist match" +# One assertion per denied peer, each requiring the real message, that +# peer's npub and the denylist decision on the SAME line. The npub being +# on the rejection line is what carries the weight here: node-a rejected +# THIS peer. The `decision=` conjunct adds no discrimination, since +# PeerAclDecision::allowed() returns early for AllowList and DefaultAllow +# (src/node/acl.rs:44-46), so DenyList is the only value that can reach +# that warn! and every rejection line carries it. It is kept because the +# remediation prescribes it and it documents the expected decision. +# +# Residual, recorded rather than hidden: node-a has auto_connect stanzas +# for both denied peers and authorizes before dialing, so it emits a +# fully-formed rejection line for each on the outbound_connect path. +# These two assertions are therefore satisfiable without the inbound ACL +# check running at all. The suite still catches that, because the denied +# peer would then connect and the peer-count assertions above would time +# out; but these two lines alone do not prove the inbound path. +assert_log_line_contains_all fips-acl-container-a${FIPS_CI_NAME_SUFFIX:-} 15 \ + "Rejected peer by ACL" \ + "npub1cld9yay0u24davpu6c35l4vldrhzvaq66pcqtg9a0j2cnjrn9rtsxx2pe6" \ + "decision=denylist match" +assert_log_line_contains_all fips-acl-container-a${FIPS_CI_NAME_SUFFIX:-} 15 \ + "Rejected peer by ACL" \ + "npub1n9lpnv0592cc2ps6nm0ca3qls642vx7yjsv35rkxqzj2vgds52sqgpverl" \ + "decision=denylist match" +# The outsider-initiated path specifically, asserted separately and not +# per-npub. Node-a carries static stanzas for both denied peers, so each +# can be rejected on the outbound_connect path as well and which context +# a given npub lands in is not deterministic (see README). Requiring an +# inbound rejection of a *named* peer would red on scheduling rather than +# on a regression; requiring that one exists at all does not. +assert_log_line_contains_all fips-acl-container-a${FIPS_CI_NAME_SUFFIX:-} 15 \ + "Rejected peer by ACL" \ + "context=inbound_handshake" \ + "decision=denylist match" log "ACL allowlist integration test passed" From 700ac581eeea5d9256d413044ab624d30a01038f Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Thu, 23 Jul 2026 04:16:32 +0000 Subject: [PATCH 2/3] Require a timeout and a drop verdict in the firewall assertions Case (a) sends an unallowed inbound request that the ruleset should drop, and accepted any non-zero curl status as proof. A drop produces no RST, so curl can only hit its deadline and exit 28; connection refused, an unroutable address or a missing listener all fail too, with different codes, and the check counted those as a blocked connection. Require 28 exactly, so the assertion distinguishes silently dropped from failed for some other reason. Confirmed against the harness: the real run returns 28. The baseline check matched `counter packets`, which any counter rule satisfies whatever its verdict, including one that accepts. Require the rendered drop rule instead. The drop-counter read had the same weakness plus a worse one: it took field three of the first line mentioning a counter, which is the packet count only when the line begins with `counter`. On a rule such as `tcp dport 9 counter packets 42 bytes 3000 drop` it printed the port number. That shape is reachable, because the shipped ruleset includes the operator drop-in directory ahead of the trailing default deny and a drop-in may add its own counted drop. Extract by position within the matched text, and take the last match rather than the first, since case (a) falls through to the default deny that the ruleset emits as the final rule. Note in place at the baseline check that it still only proves a counted drop rule exists somewhere in the table, not that it is the trailing one; asserting rule position is a larger change than this warrants. The sample output in the README is updated to the new wording. --- testing/firewall/README.md | 2 +- testing/firewall/test.sh | 53 ++++++++++++++++++++++++++++++++++---- 2 files changed, 49 insertions(+), 6 deletions(-) diff --git a/testing/firewall/README.md b/testing/firewall/README.md index 1da268d..cecd186 100644 --- a/testing/firewall/README.md +++ b/testing/firewall/README.md @@ -84,7 +84,7 @@ PASS: fips-fw-container-b: fips.nft baseline + drop-in loaded === Case (c): ICMPv6 echo-request to firewalled node PASS: (c) ICMPv6 ping node-a → node-b accepted === Case (a): unallowed inbound TCP/8000 from node-a → node-b -PASS: (a) inbound TCP/8000 blocked (curl rc=28) +PASS: (a) inbound TCP/8000 dropped (curl rc=28, timed out as expected) === Case (b): node-b initiates outbound TCP, expects reply via conntrack PASS: (b) outbound from node-b got HTTP 200 via conntrack reply path === Case (d): drop-in allowlisted TCP/22 from node-a → node-b diff --git a/testing/firewall/test.sh b/testing/firewall/test.sh index 449b983..4d942e7 100755 --- a/testing/firewall/test.sh +++ b/testing/firewall/test.sh @@ -124,8 +124,20 @@ assert_baseline_loaded() { listing="$(docker exec "$container" nft list table inet fips)" # Default-deny is achieved via the trailing `counter drop` (chain # policy is `accept` for return-on-non-fips0 to work safely). - if ! printf '%s' "$listing" | grep -q 'counter packets'; then - fail "$container: counter drop rule missing from inet fips" + # Require the verdict, not just the counter: `counter packets` alone + # matches a counter rule with any verdict, including one that accepts. + # nft renders the rule as `counter packets N bytes M drop`. + # + # This checks that a counted drop rule exists somewhere in the table, + # not that it is the baseline's trailing one. A drop-in under + # /etc/fips/fips.d/ contributing its own counted drop would satisfy + # this even with the baseline rule removed. Asserting the rule's + # position is a larger change than this finding calls for; the + # drop-counter check at the end of the run is the one that reads the + # trailing rule specifically. + if ! printf '%s' "$listing" \ + | grep -qE 'counter packets [0-9]+ bytes [0-9]+ drop'; then + fail "$container: trailing 'counter drop' rule missing from inet fips" fi if ! printf '%s' "$listing" | grep -q 'iifname != "fips0" return'; then fail "$container: non-fips0 early return rule missing" @@ -191,7 +203,15 @@ fi # ── (a) Unallowed inbound is dropped ─────────────────────────────────── log "Case (a): unallowed inbound TCP/${UNALLOWED_PORT} from node-a → node-b" # python3 http.server is already listening on :: per entrypoint default mode. -# Use curl --max-time 5 — must time out (exit 28) or otherwise fail. +# +# The rule is a DROP, so the SYN is discarded with no RST and curl must +# hit --max-time and exit 28. Assert exactly that rather than "any +# non-zero rc": a REJECT, a closed port, an unroutable address or a +# missing listener all fail too, with rc 7 or similar, and accepting +# those would let the suite report a blocked connection when nothing was +# ever blocked. Only 28 distinguishes "silently dropped" from "failed for +# some other reason". +CURL_TIMEOUT_RC=28 set +e docker exec "$CONTAINER_A" curl -6 --silent --output /dev/null \ --max-time 5 "http://[${ADDR_B}]:${UNALLOWED_PORT}/" @@ -200,7 +220,10 @@ set -e if [ "$RC" -eq 0 ]; then fail "(a) connection to ${UNALLOWED_PORT} succeeded but should have been DROP'd (rc=0)" fi -pass "(a) inbound TCP/${UNALLOWED_PORT} blocked (curl rc=$RC)" +if [ "$RC" -ne "$CURL_TIMEOUT_RC" ]; then + fail "(a) connection to ${UNALLOWED_PORT} failed with curl rc=$RC, expected $CURL_TIMEOUT_RC (timeout). A DROP produces no RST, so anything else means the connection failed for a reason other than the firewall dropping it" +fi +pass "(a) inbound TCP/${UNALLOWED_PORT} dropped (curl rc=$RC, timed out as expected)" # ── (b) Outbound-initiated flow + conntrack reply ────────────────────── log "Case (b): node-b initiates outbound TCP, expects reply via conntrack" @@ -237,8 +260,28 @@ fi # ── Drop-counter sanity ──────────────────────────────────────────────── log "Drop counter incremented (case a should have ticked it)" +# Scope to a drop rule rather than any counter rule: `/counter packets/` +# alone takes the first counter rule of whatever verdict. +# +# Extract the count by position within the matched text, not by field +# number. `$3` assumes the line starts with `counter`, so on a rule like +# `tcp dport 9 counter packets 42 bytes 3000 drop` it prints the port, +# not the packet count -- a plausible shape, since fips.nft includes +# /etc/fips/fips.d/*.nft ahead of the trailing drop and a drop-in may +# legitimately add its own counted drop. +# +# Take the LAST match, not the first. Case (a) is an unallowed inbound +# that matches no accept rule and falls through to the baseline +# default-deny, which fips.nft emits as the final rule of the chain +# (packaging/common/fips.nft, `counter drop` after the drop-in include). +# A drop-in's own counted drop would otherwise be read instead, and it +# has nothing to do with what case (a) exercised. DROP_PKTS="$(docker exec "$CONTAINER_B" nft list table inet fips \ - | awk '/counter packets/ && !seen { print $3; seen=1 }')" + | awk 'match($0, /counter packets [0-9]+ bytes [0-9]+ drop/) { + line = substr($0, RSTART); sub(/^counter packets /, "", line); + split(line, f, " "); val = f[1] + } + END { if (val != "") print val }')" if [ -z "${DROP_PKTS:-}" ] || [ "$DROP_PKTS" -lt 1 ]; then fail "drop counter is $DROP_PKTS — case (a) should have produced drops" fi From 300deb04761cfc1f28b40ab36b6231fe8cd00a57 Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Thu, 23 Jul 2026 04:16:42 +0000 Subject: [PATCH 3/3] Reject an unanswered show_mappings instead of reading it as zero The mapping-reclaimed check expects zero mappings, and read the count with `r.get('data',{}).get('mappings',[])`. An error response carries no data field, so it parsed to zero and satisfied the check without the gateway having answered at all. The expected value and the failure value were the same number, which is the shape that lets an assertion pass without asking anything. Require the key to exist and be a list, and exit non-zero otherwise, so the existing fallback turns an unanswered or malformed response into a failure. The gateway always emits the key on success, including for an empty set, so a genuine zero still reads as zero; confirmed against the running gateway, where the reclamation check passes. The earlier show_mappings poll shares the parse and is left alone: it waits for a positive two, which no error response can produce. The hazard was already documented there, and this is the call site that was exposed to it. --- testing/static/scripts/gateway-test.sh | 20 ++++++++++++++++++-- 1 file changed, 18 insertions(+), 2 deletions(-) diff --git a/testing/static/scripts/gateway-test.sh b/testing/static/scripts/gateway-test.sh index 1491039..16fc9c2 100755 --- a/testing/static/scripts/gateway-test.sh +++ b/testing/static/scripts/gateway-test.sh @@ -410,10 +410,26 @@ docker exec "$GATEWAY" conntrack -F 2>/dev/null || true echo " Waiting 25s for TTL + grace period to expire (two tick cycles)..." sleep 25 -# Query gateway control socket for mapping count +# Query gateway control socket for mapping count. +# +# The expected value here is zero, so the reader must not be able to +# produce a zero from a failed query: an error response carries no `data` +# field, and `r.get('data',{}).get('mappings',[])` would report that as +# zero mappings and pass this check without the gateway having answered. +# The same hazard is documented at the show_mappings poll above, which is +# safe only because it waits for a positive "2". Require the key to exist +# and exit non-zero if it does not, so the `|| echo "error"` fallback +# fires and the check reds. MAPPING_COUNT=$(docker exec "$GATEWAY" bash -c \ 'echo "{\"command\":\"show_mappings\"}" | nc -U -w1 /run/fips/gateway.sock 2>/dev/null' \ - | python3 -c "import sys,json; r=json.load(sys.stdin); print(len(r.get('data',{}).get('mappings',[])))" 2>/dev/null || echo "error") + | python3 -c " +import sys, json +r = json.load(sys.stdin) +data = r.get('data') +if not isinstance(data, dict) or not isinstance(data.get('mappings'), list): + sys.exit(1) +print(len(data['mappings'])) +" 2>/dev/null || echo "error") if [ "$MAPPING_COUNT" = "0" ]; then check "Mapping reclaimed after TTL+grace" 0 else