From a5d5fb898591588088569786d579d337a0b2a1be Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Thu, 1 Oct 2026 03:22:00 +0000 Subject: [PATCH] Make the interop harness report link loss and record what it built build-images.sh resolved each ref with a bare rev-parse, so an annotated tag recorded its tag object's SHA in refs.env and the image label: v0.5.1 showed as 46601931 rather than the commit c5aeef39 that was built. Peel each ref to its commit. The harness asserted connectivity only in its ping phases. Phase 7, the five-minute mesh-size warmup, pinged nothing, so a link lost and re-established there passed the run; the v0.5.2 gate's three link losses all fell in it and were found only by reading the logs. Phase 7 now checks on every poll round, warmup included, that each node still lists all its direct peers, and attributes a lost link to its pair in the failure list. An isolated unreadable peer-list round is counted and tolerated; two in a row, or an unreadable final round, fail the node. The global log checks move to a final phase so they cover the whole run, and the generated config sets handlers::mmp to debug so their "MMP link teardown" pattern can match. The Phase 6 per-pair summary now says the pair was healthy through Phase 6, which is what it observed. Builds before v0.5.2 log a link rekey responder's self-cutover with the same "Rekey cutover complete (initiator)" line an initiator logs, so in a mixed mesh the cutover count cannot show direction. None of its uses needs direction; say so where it is counted and reported, instead of labelling it an initiator count. --- testing/interop/README.md | 22 ++- testing/interop/build-images.sh | 6 +- testing/interop/generate-configs.sh | 5 +- testing/interop/interop-test.sh | 247 +++++++++++++++++++++------- 4 files changed, 208 insertions(+), 72 deletions(-) diff --git a/testing/interop/README.md b/testing/interop/README.md index 2dd5abf2..bb9d5d0a 100644 --- a/testing/interop/README.md +++ b/testing/interop/README.md @@ -123,7 +123,8 @@ per node-spec into `generated-configs/docker-compose.generated.yml`. with its ref + short SHA. 5. Remove the temp worktree (done per-ref so peak disk stays at one worktree). -It also writes `.build/refs.env`, recording each slot's ref and SHA. The +It also writes `.build/refs.env`, recording each slot's ref and the short SHA +of the commit it resolves to (an annotated tag is peeled to its commit). The driver reads it to know which pairs are mixed-version. (If absent, it falls back to the image labels.) @@ -244,19 +245,20 @@ working copy at all. ## How to read the output -The driver runs eight phases (0 to 7), plus 1b and 5b when data-plane +The driver runs nine phases (0 to 8), plus 1b and 5b when data-plane streams are on: | Phase | Check | | ----- | ---------------------------------------------------------------- | | 0 | Bring up the mesh (+ optional netem). | | 1 | All nodes reach N-1 authenticated peers; all directed pairs ping over `fips0` (the definitive FSP-session check). | -| 2 | First FMP rekey cutover completes within the timeout. | +| 2 | First FMP rekey cutover completes within the timeout (the count is role-blind: builds before v0.5.2 log a responder's cutover with the same line). | | 3 | All pairs still ping after the first rekey. | | 4 | Wait out a second rekey cycle. | | 5 | All pairs still ping after the second rekey. | | 6 | Per-node / per-pair interop log analysis. | -| 7 | Every node's mesh-size estimate within ±25% of N after warmup. | +| 7 | Every node's mesh-size estimate within ±25% of N after warmup, and every node lists all its direct peers in every poll round, warmup included (one isolated round in which a node cannot be asked is tolerated). | +| 8 | Whole-run log health (the global negative checks below). | When data-plane streams are on (`--topology`, or `FIPS_INTEROP_STREAMS`), Phase 1b measures stream loss over a quiet control window and Phase 5b @@ -270,12 +272,16 @@ many reps Phase 5b abstained and in how many it re-measured. Phase 6 is the interop-specific part. It reports: -- **Global health** — panics, `ERROR` lines, `unknown FMP version` drops, - link teardowns, decrypt failures, handshake failures, rekey-msg2 failures. - Any non-zero count is broken down per node, attributed to a specific build. - **Rekey machinery exercised** — both FMP and FSP rekey cutovers fired. - **Per-pair interop summary** — each unordered pair, classified - same-version vs MIXED, with whether it stayed healthy through the run. + same-version vs MIXED, with whether it stayed healthy through Phase 6. + +Phase 8 runs the global health checks last, so they cover the whole run, +the Phase 7 warmup included: panics, `ERROR` lines, `unknown FMP version` +drops, link teardowns (`MMP link teardown`, which the generated config +makes visible by setting `fips::node::handlers::mmp` to debug), decrypt +failures, handshake failures, rekey-msg2 failures. Any non-zero count is +broken down per node, attributed to a specific build. The final verdict lists every failure attributed to a specific `x[ref@sha] <-> y[ref@sha]` pair or build, then states the attribution: diff --git a/testing/interop/build-images.sh b/testing/interop/build-images.sh index 9abab1be..9accb0e4 100755 --- a/testing/interop/build-images.sh +++ b/testing/interop/build-images.sh @@ -144,7 +144,9 @@ build_one() { local slot="$1" local ref="$2" local sha - sha="$(git -C "$REPO_ROOT" rev-parse --short "$ref")" + # Peel to the commit: an annotated tag's own name resolves to the tag + # object, which is not what was built. + sha="$(git -C "$REPO_ROOT" rev-parse --short "${ref}^{commit}")" echo "" echo "=== Building slot '$slot' ref='$ref' sha=$sha ===" @@ -224,7 +226,7 @@ MANIFEST="$WORK_BASE/refs.env" for i in 0 1 2; do slot="${SLOTS[$i]}" ref="${REFS[$i]}" - sha="$(git -C "$REPO_ROOT" rev-parse --short "$ref")" + sha="$(git -C "$REPO_ROOT" rev-parse --short "${ref}^{commit}")" upper="$(echo "$slot" | tr '[:lower:]' '[:upper:]')" echo "INTEROP_REF_${upper}=$ref" echo "INTEROP_SHA_${upper}=$sha" diff --git a/testing/interop/generate-configs.sh b/testing/interop/generate-configs.sh index d21266a1..feab1dc2 100755 --- a/testing/interop/generate-configs.sh +++ b/testing/interop/generate-configs.sh @@ -307,7 +307,10 @@ COMPOSE_FILE="$OUT_DIR/docker-compose.generated.yml" echo " - net.ipv6.conf.all.disable_ipv6=0" echo " restart: \"no\"" echo " environment:" - echo " - RUST_LOG=info,fips::node::handlers::rekey=debug,fips::node::handlers::handshake=debug" + # handlers::mmp at debug so the driver's "MMP link teardown" scan, which + # catches a peer removed at any point of the run, can match: the line is + # a debug! in that module. + echo " - RUST_LOG=info,fips::node::handlers::rekey=debug,fips::node::handlers::handshake=debug,fips::node::handlers::mmp=debug" echo "" echo "services:" for nid in "${NODE_IDS[@]}"; do diff --git a/testing/interop/interop-test.sh b/testing/interop/interop-test.sh index 857e4b59..5e10cf19 100755 --- a/testing/interop/interop-test.sh +++ b/testing/interop/interop-test.sh @@ -41,6 +41,11 @@ # Phase 5b), and MESH-SIZE estimate convergence across versions # (Phase 7). # +# A link lost at any point of a run turns it red: the ping phases cover +# Phases 1 to 5, Phase 7 checks every node's direct peers on each poll +# round of its warmup and settle loops, and Phase 8 scans the whole run's +# logs for peer removals and the other global failure signatures. +# # Environment: # FIPS_INTEROP_NETEM tc-netem arg string applied to every container's # eth0, e.g. "delay 10ms 5ms 25% loss 1%". Unset = @@ -537,7 +542,14 @@ count_log_pattern() { return 0 } -# Count completed FMP initiator rekey cutovers across all node logs. +# Count completed FMP rekey cutovers across all node logs. +# +# The line says "(initiator)", but it does not show direction in a mixed +# mesh: builds before v0.5.2 also log it as a responder, on the self-cutover +# one tick after sending msg2. So this counts cutovers of either role, and +# every caller reports it as a role-blind count. None needs direction: the +# control window wants any cutover, and the rekey phases want proof that +# rekeys completed. # # The pattern is a literal argument so the log-string guard can check it # against the daemon source. Prints the count, or `unreadable:` with @@ -597,6 +609,114 @@ mesh_estimate() { || echo null } +# The direct neighbours does not list in `fipsctl show peers`, as +# space-separated node ids (empty when all are listed). Prints `unreadable` +# with status 1 when the node cannot be asked or its answer cannot be +# parsed, so a dead reader is never taken for a full peer list. +missing_peers() { + local n="$1" out listed m missing="" + if ! out="$(docker exec "${CONTAINER[$n]}" fipsctl show peers 2>/dev/null)" \ + || ! listed="$(python3 -c 'import sys,json; print(" ".join(p["npub"] for p in json.load(sys.stdin)["peers"]))' <<<"$out" 2>/dev/null)"; then + echo "unreadable" + return 1 + fi + for m in "${NODES[@]}"; do + pair_is_direct "$n" "$m" || continue + case " $listed " in + *" ${NPUB_OF[$m]} "*) ;; + *) missing+=" $m" ;; + esac + done + echo "${missing# }" + return 0 +} + +# One link-continuity round over every node: record each direct neighbour +# a node has stopped listing, and each node that could not be asked. A +# peer drops out of `show peers` only when its link is removed (a stale +# but live link stays listed), so a miss here is a lost link, not loss +# noise. Phase 7 runs no pings, so without this a link lost during its +# warmup would pass the run. +# +# A node that cannot be asked is a different matter: one failed +# `docker exec` says nothing about its links. An isolated unreadable round +# is counted and reported but tolerated; two in a row, or an unreadable +# final round, fail the node, because then the harness has stopped +# observing it. A link lost and re-established inside the unread gap +# still leaves an "MMP link teardown" line for Phase 8 to find. +declare -A LINK_LOST_AT LINK_LOST_ROUNDS LINK_UNREADABLE LINK_UNREAD_RUN LINK_UNREAD_WORST +LINK_ROUNDS=0 +check_links_round() { + local n m missing at=$(( SECONDS - MESH_UP_AT )) + LINK_ROUNDS=$((LINK_ROUNDS + 1)) + for n in "${NODES[@]}"; do + if ! missing="$(missing_peers "$n")"; then + LINK_UNREADABLE[$n]=$(( ${LINK_UNREADABLE[$n]:-0} + 1 )) + LINK_UNREAD_RUN[$n]=$(( ${LINK_UNREAD_RUN[$n]:-0} + 1 )) + if [ "${LINK_UNREAD_RUN[$n]}" -gt "${LINK_UNREAD_WORST[$n]:-0}" ]; then + LINK_UNREAD_WORST[$n]="${LINK_UNREAD_RUN[$n]}" + fi + echo " UNREADABLE $n: show peers could not be read (${at}s after mesh start)" + continue + fi + LINK_UNREAD_RUN[$n]=0 + for m in $missing; do + if [ -z "${LINK_LOST_AT[$n|$m]:-}" ]; then + LINK_LOST_AT[$n|$m]="$at" + echo " LINK LOST $n no longer lists direct peer $m (${at}s after mesh start)" + fi + LINK_LOST_ROUNDS[$n|$m]=$(( ${LINK_LOST_ROUNDS[$n|$m]:-0} + 1 )) + done + done + return 0 +} + +# Global negative checks — these must be zero on EVERY node regardless +# of version pairing. A non-zero count is attributed to the node and, +# where the count is asymmetric across versions, flagged as interop. +# Every pattern must be live at the level generate-configs.sh sets. +declare -A GLOBAL_PATTERNS=( + ["PANIC|panicked"]="panics" + ["ERROR"]="error-level log lines" + ["unknown FMP version|Unknown FMP version"]="unknown-FMP-version drops" + ["MMP link teardown"]="MMP link teardowns (a peer removed)" + ["Excessive decryption failures"]="excessive-decryption-failure removals" + ["Session AEAD decryption failed"]="FSP AEAD decrypt failures" + ["Rekey msg2 processing failed"]="rekey msg2 failures" + ["Handshake failed|handshake failed"]="handshake failures" +) + +scan_global_patterns() { + local pat desc total n c s u + for pat in "${!GLOBAL_PATTERNS[@]}"; do + desc="${GLOBAL_PATTERNS[$pat]}" + if ! total="$(count_log_pattern "$pat")"; then + echo " FAIL $desc: node logs unreadable ($total), zero not established" + FAILED=$((FAILED + 1)) + INTEROP_FAILURES+=("[log] $desc: node logs unreadable ($total)") + continue + fi + if [ "$total" -eq 0 ]; then + echo " PASS $desc: 0" + PASSED=$((PASSED + 1)) + else + echo " FAIL $desc: $total (expected 0)" + FAILED=$((FAILED + 1)) + # Per-node breakdown so the count can be attributed to a build. + for n in "${NODES[@]}"; do + c="$(count_node_pattern "$n" "$pat")" + if [ "$c" -gt 0 ]; then + s="${SLOT_OF[$n]}" + u="$(echo "$s" | tr '[:lower:]' '[:upper:]')" + echo " $n [$u ${SLOT_REF[$s]}@${SLOT_SHA[$s]}]: $c" + INTEROP_FAILURES+=("[log] node $n ($u ${SLOT_REF[$s]}@${SLOT_SHA[$s]}): $c x '$desc'") + fi + done + fi + done + return 0 +} + # ── Data-plane continuity streams ──────────────────────────────────── # # A sustained ping6 stream over the overlay (.fips) is data-plane @@ -876,7 +996,7 @@ if ! fmp_cutovers="$(count_log_pattern 'Rekey cutover complete \(initiator\), K- FAILED=$((FAILED + 1)) INTEROP_FAILURES+=("[log] FMP rekey cutovers: node logs unreadable ($fmp_cutovers)") elif [ "$fmp_cutovers" -ge 1 ]; then - echo " PASS FMP rekey initiator cutovers: $fmp_cutovers" + echo " PASS FMP rekey cutovers (either role; see fmp_cutover_count): $fmp_cutovers" PASSED=$((PASSED + 1)) else echo " FAIL no FMP rekey cutover observed within ${FIRST_REKEY_TIMEOUT}s" @@ -983,49 +1103,9 @@ PASSED=0; FAILED=0 # at least one cutover before the final assertions. wait_for_log_pattern_count "FSP rekey cutover complete" 1 "$REKEY_SETTLE" || true -# Global negative checks — these must be zero on EVERY node regardless -# of version pairing. A non-zero count is attributed to the node and, -# where the count is asymmetric across versions, flagged as interop. -echo "" -echo " -- Global health (all $NUM_NODES nodes) --" - -declare -A GLOBAL_PATTERNS=( - ["PANIC|panicked"]="panics" - ["ERROR"]="error-level log lines" - ["unknown FMP version|Unknown FMP version"]="unknown-FMP-version drops" - ["MMP link teardown"]="MMP link teardowns" - ["Excessive decryption failures"]="excessive-decryption-failure removals" - ["Session AEAD decryption failed"]="FSP AEAD decrypt failures" - ["Rekey msg2 processing failed"]="rekey msg2 failures" - ["Handshake failed|handshake failed"]="handshake failures" -) - -for pat in "${!GLOBAL_PATTERNS[@]}"; do - desc="${GLOBAL_PATTERNS[$pat]}" - if ! total="$(count_log_pattern "$pat")"; then - echo " FAIL $desc: node logs unreadable ($total), zero not established" - FAILED=$((FAILED + 1)) - INTEROP_FAILURES+=("[log] $desc: node logs unreadable ($total)") - continue - fi - if [ "$total" -eq 0 ]; then - echo " PASS $desc: 0" - PASSED=$((PASSED + 1)) - else - echo " FAIL $desc: $total (expected 0)" - FAILED=$((FAILED + 1)) - # Per-node breakdown so the count can be attributed to a build. - for n in "${NODES[@]}"; do - c="$(count_node_pattern "$n" "$pat")" - if [ "$c" -gt 0 ]; then - s="${SLOT_OF[$n]}" - u="$(echo "$s" | tr '[:lower:]' '[:upper:]')" - echo " $n [$u ${SLOT_REF[$s]}@${SLOT_SHA[$s]}]: $c" - INTEROP_FAILURES+=("[log] node $n ($u ${SLOT_REF[$s]}@${SLOT_SHA[$s]}): $c x '$desc'") - fi - done - fi -done +# The global negative checks (panics, errors, link teardowns, ...) run +# after Phase 7 instead, so they cover the whole run including the +# mesh-size warmup; see Phase 8. # Positive checks — the rekey machinery actually exercised both layers. echo "" @@ -1036,7 +1116,7 @@ if ! fmp_total="$(count_log_pattern 'Rekey cutover complete \(initiator\), K-bit echo " FAIL FMP rekey cutovers: node logs unreadable ($fmp_total), not established" FAILED=$((FAILED + 1)) elif [ "$fmp_total" -ge 1 ]; then - echo " PASS FMP rekey cutovers across mesh: $fmp_total" + echo " PASS FMP rekey cutovers across mesh (either role): $fmp_total" PASSED=$((PASSED + 1)) else echo " FAIL FMP rekey cutovers: $fmp_total (expected >= 1)" @@ -1056,8 +1136,9 @@ else fi # Per-pair summary: classify each unordered pair and report whether it -# stayed healthy through the run. "Healthy" = no connectivity failure -# recorded for either direction of the pair. +# stayed healthy through Phases 1 to 6. "Healthy" = no connectivity +# failure recorded for either direction of the pair. Phase 7's link +# checks and Phase 8's log scan run later and record their own failures. echo "" echo " -- Per-pair interop summary --" for p in "${PAIRS[@]}"; do @@ -1074,10 +1155,10 @@ for p in "${PAIRS[@]}"; do done fi if [ "$pair_failed" -eq 0 ]; then - echo " PASS $kind pair $label: stayed healthy" + echo " PASS $kind pair $label: healthy through Phase 6" PASSED=$((PASSED + 1)) else - echo " FAIL $kind pair $label: connectivity failed during the run" + echo " FAIL $kind pair $label: connectivity failed by Phase 6" FAILED=$((FAILED + 1)) fi done @@ -1109,21 +1190,28 @@ declare -A MS_EST MS_OK MS_INBAND_SINCE ms_accept_after=$(( MESH_UP_AT + MESH_SIZE_WARMUP )) echo " band [$ms_lo, $ms_hi], warmup ends $(( ms_accept_after - SECONDS ))s from now, then ${MESH_SIZE_SETTLE}s settled, poll up to ${MESH_SIZE_TIMEOUT}s beyond that" -# Poll through the warmup as well. Nothing here is asserted on — it is -# the trajectory the phase has never recorded, and it is what an -# undercount that never recovers would show up in. +# Poll through the warmup as well. The estimates are not asserted on here — +# they are the trajectory the phase has never recorded, and what an +# undercount that never recovers would show up in — but every round +# checks that each node still lists all its direct peers. +ms_next_print=$SECONDS while [ "$SECONDS" -lt "$ms_accept_after" ]; do - ms_line="" - for n in "${NODES[@]}"; do - MS_EST[$n]="$(mesh_estimate "$n")" - ms_line+=" $n=${MS_EST[$n]}" - done - echo " warmup, $(( ms_accept_after - SECONDS ))s to go:$ms_line" - sleep 30 + check_links_round + if [ "$SECONDS" -ge "$ms_next_print" ]; then + ms_line="" + for n in "${NODES[@]}"; do + MS_EST[$n]="$(mesh_estimate "$n")" + ms_line+=" $n=${MS_EST[$n]}" + done + echo " warmup, $(( ms_accept_after - SECONDS ))s to go:$ms_line" + ms_next_print=$(( SECONDS + 30 )) + fi + sleep "$MESH_SIZE_POLL" done ms_deadline=$(( SECONDS + MESH_SIZE_SETTLE + MESH_SIZE_TIMEOUT )) while :; do + check_links_round all_ok=1 for n in "${NODES[@]}"; do est="$(mesh_estimate "$n")" @@ -1165,7 +1253,44 @@ done # that the nodes agreed. Print the spread so nobody has to infer it. ms_spread="$(printf '%s\n' "${MS_EST[@]}" | sort -n | awk '/^[0-9]+$/{ if (lo=="") lo=$1; hi=$1 } END{ if (lo=="") print "no numeric estimates"; else if (lo==hi) print "all nodes agree on " lo; else print "nodes disagree: " lo " to " hi }')" echo " NOTE: final estimates — $ms_spread (agreement is reported, not asserted)" -phase_result "Mesh-size estimate convergence" + +# Link continuity across Phase 7, one check per node. +for n in "${NODES[@]}"; do + s="${SLOT_OF[$n]}"; u="$(echo "$s" | tr '[:lower:]' '[:upper:]')" + node_ok=1 + if [ "${LINK_UNREAD_WORST[$n]:-0}" -ge 2 ] || [ "${LINK_UNREAD_RUN[$n]:-0}" -ge 1 ]; then + node_ok=0 + echo " FAIL $n [$u]: show peers unreadable in ${LINK_UNREADABLE[$n]} of $LINK_ROUNDS rounds (longest run ${LINK_UNREAD_WORST[$n]}, final round $([ "${LINK_UNREAD_RUN[$n]:-0}" -ge 1 ] && echo unreadable || echo read)); link continuity not established" + INTEROP_FAILURES+=("[link] node $n ($u ${SLOT_REF[$s]}@${SLOT_SHA[$s]}): show peers unreadable in ${LINK_UNREADABLE[$n]} of $LINK_ROUNDS Phase 7 rounds") + elif [ -n "${LINK_UNREADABLE[$n]:-}" ]; then + echo " NOTE $n [$u]: show peers unreadable in ${LINK_UNREADABLE[$n]} isolated round(s) of $LINK_ROUNDS; tolerated" + fi + for m in "${NODES[@]}"; do + [ -n "${LINK_LOST_AT[$n|$m]:-}" ] || continue + node_ok=0 + echo " FAIL $n [$u]: lost direct peer $m (first ${LINK_LOST_AT[$n|$m]}s after mesh start, missing in ${LINK_LOST_ROUNDS[$n|$m]} of $LINK_ROUNDS rounds)" + # NOTE: keep "$kind pair" contiguous — interop-stress.sh greps it. + INTEROP_FAILURES+=("[link] $(pair_kind "$n" "$m") pair $(pair_label "$n" "$m") [$(hop_label "$n" "$m")]: $n lost $m during Phase 7 (first ${LINK_LOST_AT[$n|$m]}s after mesh start)") + done + if [ "$node_ok" -eq 1 ]; then + echo " PASS $n [$u]: listed every direct peer in every readable round of $LINK_ROUNDS Phase 7 rounds" + PASSED=$((PASSED + 1)) + else + FAILED=$((FAILED + 1)) + fi +done +phase_result "Mesh-size estimate convergence and link continuity" +echo "" + +# ── Phase 8: whole-run log health ──────────────────────────────────── +# +# The global negative checks, run last so they cover every phase. A +# link lost and re-established inside the Phase 7 warmup leaves an +# "MMP link teardown" line even if no poll round caught it missing. +echo "Phase 8: Whole-run log health (all $NUM_NODES nodes)" +PASSED=0; FAILED=0 +scan_global_patterns +phase_result "Whole-run log health" echo "" # ── Summary ──────────────────────────────────────────────────────────