From 0ddb206703a08f18bc08b832668329a11e1e340d Mon Sep 17 00:00:00 2001 From: Johnathan Corgan Date: Sat, 19 Sep 2026 02:46:55 +0000 Subject: [PATCH] Re-measure the interop control window after a rekey cutover, and abstain when it stays contaminated Phase 1b detected a rekey cutover inside its quiet control window, printed a warning, and Phase 5b then computed its verdict from the contaminated baseline anyway. A node whose logs could not be read made the cutover comparison error out, and the window was accepted as clean. The window now counts only when the cutover count was read before and after it and did not move. Otherwise Phase 1b waits for the cutovers to settle and re-measures, up to three attempts by default. When no attempt is clean, Phase 5b reports ABSTAIN for every stream instead of a verdict, and the summary says its rekey-loss check did not run. The stress loop counts the reps in which Phase 5b abstained or re-measured, so a run that always abstains cannot pass unnoticed. --- testing/interop/README.md | 11 +++ testing/interop/interop-stress.sh | 22 ++++++ testing/interop/interop-test.sh | 113 ++++++++++++++++++++++++++---- 3 files changed, 132 insertions(+), 14 deletions(-) diff --git a/testing/interop/README.md b/testing/interop/README.md index bd92f467..a481bd0b 100644 --- a/testing/interop/README.md +++ b/testing/interop/README.md @@ -209,6 +209,7 @@ expected and is not by itself a failure, so every other outcome exits 0. | ---------------------------- | ------------------------------------------------- | | `FIPS_INTEROP_NETEM` | tc-netem string applied to each container's eth0, e.g. `"delay 10ms 5ms 25% loss 1%"`. Passed through `interop-stress.sh` to `interop-test.sh`. | | `REKEY_AFTER_SECS` | Rekey interval for generated configs (default 35).| +| `CONTROL_MAX_ATTEMPTS` | Control windows Phase 1b measures before Phase 5b abstains (default 3). | | `FIPS_INTEROP_KEEP_UP` | `1` = leave containers running after the test. The stress loop sets it for every rep and tears down itself. | | `FIPS_INTEROP_KEEP_WORKTREES`| `1` = keep `build-images.sh` worktrees (debug). | | `FIPS_INTEROP_RUNS_DIR` | Root for the three scratch dirs — see [Scratch directory location](#scratch-directory-location). | @@ -255,6 +256,16 @@ The driver runs seven phases: | 5 | All pairs still ping after the second rekey. | | 6 | Per-node / per-pair interop log analysis. | +When data-plane streams are on (`--topology`, or `FIPS_INTEROP_STREAMS`), +Phase 1b measures stream loss over a quiet control window and Phase 5b +compares the loss across the rekey window against it. A control window +counts only if no FMP rekey cutover happened during it and the cutover +count could be read on every node. Otherwise Phase 1b waits for the +cutovers to settle and re-measures, up to `CONTROL_MAX_ATTEMPTS` times (default +3). If no attempt is clean, Phase 5b prints `ABSTAIN` for every stream and +returns no verdict, and the summary says so. The stress loop reports in how +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, diff --git a/testing/interop/interop-stress.sh b/testing/interop/interop-stress.sh index a2629bdf..933da670 100755 --- a/testing/interop/interop-stress.sh +++ b/testing/interop/interop-stress.sh @@ -263,6 +263,11 @@ FAILED_REPS=() # Failed reps whose per-node logs were not all saved. HARVEST_FAILS=0 HARVEST_FAILED_REPS=() +# Phase 5b outcomes over the reps that measured a control window (Phase +# 1b ran): reps that abstained, and reps that re-measured at least once. +STREAM_REPS=0 +ABSTAIN_REPS=0 +REMEASURE_REPS=0 # Per-kind connectivity-failure tallies, summed across all failed reps. MIXED_FAILS=0 SAME_FAILS=0 @@ -283,6 +288,20 @@ for ((rep = 1; rep <= REPS; rep++)); do bash "$DRIVER" "${DRIVER_ARGS[@]}" >"$driver_log" 2>&1 rc=$? + # Tallied for every rep whatever its verdict: abstaining is the absence + # of a verdict rather than a failure, so without this count a run whose + # Phase 5b always abstains would pass unnoticed. + if grep -q '^Phase 1b: ' "$driver_log"; then + STREAM_REPS=$((STREAM_REPS + 1)) + if grep -q '^ ABSTAIN Data-plane continuity' "$driver_log"; then + ABSTAIN_REPS=$((ABSTAIN_REPS + 1)) + echo " Phase 5b abstained (no clean control window)" + fi + if grep -q 'control window attempt .*re-measuring' "$driver_log"; then + REMEASURE_REPS=$((REMEASURE_REPS + 1)) + fi + fi + if [ "$rc" -eq 0 ]; then PASS_COUNT=$((PASS_COUNT + 1)) echo " PASS (exit 0)" @@ -387,6 +406,9 @@ fi if [ "$HARVEST_FAILS" -gt 0 ]; then echo "Harvest : $HARVEST_FAILS failed rep(s) with incomplete per-node logs: ${HARVEST_FAILED_REPS[*]}" fi + if [ "$STREAM_REPS" -gt 0 ]; then + echo "Phase 5b : abstained in $ABSTAIN_REPS of $STREAM_REPS reps; re-measured in $REMEASURE_REPS of $STREAM_REPS reps" + fi echo "" echo "-- Connectivity-failure attribution (summed over failed reps) --" echo " mixed-version : $MIXED_FAILS failure(s) over $MIXED_PAIRS mixed pairs x $REPS reps" diff --git a/testing/interop/interop-test.sh b/testing/interop/interop-test.sh index 3d8e41dd..913518fe 100755 --- a/testing/interop/interop-test.sh +++ b/testing/interop/interop-test.sh @@ -53,6 +53,9 @@ # by --topology; empty = streams off. # STREAM_LOSS_MARGIN_PCT rekey-vs-control loss margin (default 5). # CONTROL_STREAM_SECS quiet control-window length (default 12). +# CONTROL_MAX_ATTEMPTS control windows measured before Phase 5b +# abstains because every one saw a rekey +# cutover or could not be checked (default 3). # MESH_SIZE_WARMUP Phase 7 bloom warmup, from mesh start, before # any estimate counts (default 300). # MESH_SIZE_SETTLE Phase 7 unbroken in-band window a node must @@ -190,6 +193,14 @@ LOG_POLL_INTERVAL=2 # as on mixed ones. STREAM_RATE_HZ=20 CONTROL_STREAM_SECS="${CONTROL_STREAM_SECS:-12}" # quiet pre-rekey window +# A control window that saw a rekey cutover, or whose cutover count could +# not be read, is no baseline. Phase 1b re-measures it, after waiting for +# the cutover count to hold still for CONTROL_QUIET_SECS (at most +# CONTROL_QUIET_MAX) so the retry does not land in the same cluster of +# cutovers, and Phase 5b abstains when no attempt comes out clean. +CONTROL_MAX_ATTEMPTS="${CONTROL_MAX_ATTEMPTS:-3}" +CONTROL_QUIET_SECS=5 +CONTROL_QUIET_MAX=30 # 5% is 12 packets of the 240-packet control window and ~155 of the # ~3100-packet rekey window. On a path losing up to 6% (the range the # v0.4.2 netem runs baselined at, under `loss 2%` over several hops) the @@ -526,6 +537,37 @@ count_log_pattern() { return 0 } +# Count completed FMP initiator rekey cutovers across all node logs. +# +# The pattern is a literal argument so the log-string guard can check it +# against the daemon source. Prints the count, or `unreadable:` with +# status 1 when a node's logs cannot be read. +fmp_cutover_count() { + count_log_pattern 'Rekey cutover complete \(initiator\), K-bit flipped' + return $? +} + +# Wait until the FMP cutover count has held unchanged for +# CONTROL_QUIET_SECS, giving up after CONTROL_QUIET_MAX. An unreadable +# count is treated as a change, so it never counts as quiet. +wait_cutover_quiet() { + local start=$SECONDS still=$SECONDS last cur + last="$(fmp_cutover_count)" || last="unreadable" + while (( SECONDS - still < CONTROL_QUIET_SECS )); do + if (( SECONDS - start >= CONTROL_QUIET_MAX )); then + echo " cutover count still moving after ${CONTROL_QUIET_MAX}s; measuring anyway" + return 1 + fi + sleep 1 + cur="$(fmp_cutover_count)" || cur="unreadable" + if [ "$cur" != "$last" ] || [ "$cur" = "unreadable" ]; then + last="$cur" + still=$SECONDS + fi + done + return 0 +} + # Per-node count of a pattern. count_node_pattern() { local node="$1" pattern="$2" @@ -765,25 +807,52 @@ echo "" # ── Phase 1b: data-plane control window (quiet, pre-rekey) ─────────── # # Measure stream loss over a window with NO rekey cutover, as the control -# baseline for the differential. Validated cutover-free by confirming the -# FMP cutover count did not advance during the window. Then launch the +# baseline for the differential. A window counts only when the FMP cutover +# count was read before and after it and did not advance. A window that +# saw a cutover, or could not be checked, is re-measured up to +# CONTROL_MAX_ATTEMPTS times; if none is clean, Phase 5b abstains rather +# than computing a verdict from a contaminated baseline. Then launch the # rekey-window streams, which run in the background across Phases 2-5 and # are collected/asserted in Phase 5b. -control_contaminated=0 +control_abstain=0 if [ "${#STREAM_PAIRS[@]}" -gt 0 ]; then - echo "Phase 1b: Data-plane control stream (${CONTROL_STREAM_SECS}s quiet window)" - pre_cut="$(count_log_pattern 'Rekey cutover complete \(initiator\), K-bit flipped')" - launch_streams CONTROL "$CONTROL_STREAM_SECS" - collect_streams - post_cut="$(count_log_pattern 'Rekey cutover complete \(initiator\), K-bit flipped')" - if [ "$post_cut" -ne "$pre_cut" ]; then - control_contaminated=1 - echo " WARN a rekey cutover occurred during the control window — control loss may be contaminated" + echo "Phase 1b: Data-plane control stream (${CONTROL_STREAM_SECS}s quiet window, up to ${CONTROL_MAX_ATTEMPTS} attempts)" + control_ok=0 + for ((attempt = 1; attempt <= CONTROL_MAX_ATTEMPTS; attempt++)); do + pre_rc=0 + post_rc=0 + pre_cut="$(fmp_cutover_count)" || pre_rc=$? + launch_streams CONTROL "$CONTROL_STREAM_SECS" + collect_streams + post_cut="$(fmp_cutover_count)" || post_rc=$? + if [ "$pre_rc" -ne 0 ] || ! [[ "$pre_cut" =~ ^[0-9]+$ ]]; then + why="cutover count unreadable ($pre_cut)" + elif [ "$post_rc" -ne 0 ] || ! [[ "$post_cut" =~ ^[0-9]+$ ]]; then + why="cutover count unreadable ($post_cut)" + elif [ "$post_cut" -ne "$pre_cut" ]; then + why="a rekey cutover occurred (+$((post_cut - pre_cut)))" + else + control_ok=1 + echo " control window accepted on attempt $attempt/$CONTROL_MAX_ATTEMPTS" + break + fi + if [ "$attempt" -lt "$CONTROL_MAX_ATTEMPTS" ]; then + echo " control window attempt $attempt/$CONTROL_MAX_ATTEMPTS: $why; re-measuring" + wait_cutover_quiet || true + else + echo " control window attempt $attempt/$CONTROL_MAX_ATTEMPTS: $why" + fi + done + if [ "$control_ok" -eq 0 ]; then + control_abstain=1 + echo " ABSTAIN control window contaminated on all $CONTROL_MAX_ATTEMPTS attempts; Phase 5b will not return a verdict" fi + ctl_note="" + [ "$control_abstain" -eq 1 ] && ctl_note=" (last attempt, contaminated)" for sp in "${STREAM_PAIRS[@]}"; do read -r sf st <<< "$sp" key="$sf->$st" - echo " control $key: tx=${STREAM_TX[CONTROL:$key]:-0} rx=${STREAM_RX[CONTROL:$key]:-0} loss=$(_loss_pct "${STREAM_TX[CONTROL:$key]:-0}" "${STREAM_RX[CONTROL:$key]:-0}")%" + echo " control $key: tx=${STREAM_TX[CONTROL:$key]:-0} rx=${STREAM_RX[CONTROL:$key]:-0} loss=$(_loss_pct "${STREAM_TX[CONTROL:$key]:-0}" "${STREAM_RX[CONTROL:$key]:-0}")%$ctl_note" done echo " Launching rekey-window streams (${REKEY_STREAM_SECS}s, spanning Phases 2-5)" launch_streams REKEY "$REKEY_STREAM_SECS" @@ -863,6 +932,12 @@ if [ "${#STREAM_PAIRS[@]}" -gt 0 ]; then if (k <= c + m) print "PASS"; else print "FAIL" }')" delta="$(awk -v c="$cpct" -v k="$rpct" 'BEGIN{ if(c=="NA"||k=="NA") print "NA"; else printf "%+.1f", k-c }')" + # No clean control window: report the losses for reading, but + # compute no verdict from a contaminated baseline. + if [ "$control_abstain" -eq 1 ]; then + printf ' %-16s %11s %11s %8s %s\n' "$key" "$cpct" "$rpct" "$delta" "ABSTAIN" + continue + fi printf ' %-16s %11s %11s %8s %s\n' "$key" "$cpct" "$rpct" "$delta" "$verdict" if [ "$verdict" = "PASS" ]; then PASSED=$((PASSED + 1)) @@ -871,8 +946,11 @@ if [ "${#STREAM_PAIRS[@]}" -gt 0 ]; then INTEROP_FAILURES+=("[stream] $key ($(hop_label "$sf" "$st")): rekey-window loss ${rpct}% vs control ${cpct}% (+${STREAM_LOSS_MARGIN_PCT}% margin) -> $verdict") fi done - [ "${control_contaminated:-0}" -eq 1 ] && echo " NOTE: control window saw a cutover; differential may understate rekey loss." - phase_result "Data-plane continuity across rekey" + if [ "$control_abstain" -eq 1 ]; then + echo " ABSTAIN Data-plane continuity across rekey: no uncontaminated control window in $CONTROL_MAX_ATTEMPTS attempts" + else + phase_result "Data-plane continuity across rekey" + fi echo "" fi @@ -1078,6 +1156,13 @@ echo "==============================================================" # `${#arr[@]}` cannot be combined with `:-`; count into a plain var. INTEROP_FAILURE_COUNT="${#INTEROP_FAILURES[@]}" +# An abstaining Phase 5b adds no check, so say so: otherwise a green run +# reads as having covered data-plane continuity across rekey. +if [ "${control_abstain:-0}" -eq 1 ]; then + echo "" + echo "NOTE: Phase 5b abstained (control window contaminated); its rekey-loss check did not run." +fi + if [ "$TOTAL_FAILED" -eq 0 ] && [ "$INTEROP_FAILURE_COUNT" -eq 0 ]; then echo "" echo "PASS: all versions interoperate cleanly across the mesh (spec '$SPEC_STR')."