diff --git a/CHANGELOG.md b/CHANGELOG.md index c7210dd..5ae94ed 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -236,6 +236,32 @@ with v0.3.x peers. ### Fixed +- Spanning-tree state distribution is now eventually-consistent. + Previously every `send_tree_announce_to_all` call site fired only + on a local state-change event (parent switch, self-root promotion, + ancestry change, peer promotion, parent loss). Once a partition + latched — for example, a parent-switch announce lost in transit + via the brief cross-init handshake swap window where one peer's + outbound session is about to become the loser session and the + receiver has no matching decrypt-worker entry — no node's state + changed again, so no node ever re-broadcast. The existing 60-second + `check_periodic_parent_reeval` short-circuited silently on no-change + (it was a re-evaluation, not a re-broadcast), and production-side + healing depended on incidental link churn (NAT keepalive refresh, + MMP timeout, peer re-promotion after a transport blip). The + function now ends with an unconditional `send_tree_announce_to_all` + on the no-change branch, alongside the existing switch and + self-promote arms; receivers coalesce by sequence comparison + (`ParentDeclaration::is_fresher_than`) and short-circuit at the + `if !updated` gate in `handle_tree_announce`, so same-sequence + repeats drop silently with no cascade. The per-peer 500 ms + rate-limiter is well below this 60-second cadence and does not + suppress the heartbeat broadcast. `BASELINE_CONVERGENCE_TIMEOUT` + in `testing/static/scripts/rekey-test.sh` is bumped from 60 to 65 + so any partition healed by the periodic broadcast at T+60 lands + inside the convergence window; `wait_for_full_baseline` early-exits + on PASS, so successful reps see no extra wall-clock. + - `rx_loop` tick-arm stall under convergence-phase mesh pressure is eliminated. Previously, the tick body's per-peer `check_*` loops (heartbeats, bloom announces, MMP reports, tree announces) diff --git a/src/node/tree.rs b/src/node/tree.rs index e560384..81bf188 100644 --- a/src/node/tree.rs +++ b/src/node/tree.rs @@ -501,6 +501,22 @@ impl Node { self.send_tree_announce_to_all().await; let all_peers: Vec = self.peers.keys().copied().collect(); self.bloom_state.mark_all_updates_needed(all_peers); + } else { + // Periodic re-broadcast on no-change: makes TreeAnnounce + // distribution eventually-consistent. Receivers coalesce + // by sequence via ParentDeclaration::is_fresher_than and + // short-circuit at the `if !updated` gate in + // handle_tree_announce; the per-peer 500 ms rate-limiter + // never blocks at this 60 s cadence. Closes the cross-init + // in-flight loss recovery gap where the swap window can + // strand one side's announce on a session-index the other + // side cannot decrypt. + trace!( + seq = self.tree_state.my_declaration().sequence(), + root = %self.tree_state.root(), + "Periodic TreeAnnounce re-broadcast (no state change)" + ); + self.send_tree_announce_to_all().await; } } diff --git a/testing/mesh-lab/README.md b/testing/mesh-lab/README.md index 29cb457..565911a 100644 --- a/testing/mesh-lab/README.md +++ b/testing/mesh-lab/README.md @@ -53,9 +53,9 @@ Initial target set: - `rekey`, `rekey-accept-off`, `rekey-outbound-only` — rekey-suite Phase 5 post-second-rekey connectivity flake class. - `nat-lan` — two-node NAT-traversal handshake-completion flake class. -- `bloom-storm` — chaos scenario; covers the - [ISSUE-2026-0026](../../../prj/fips/issues/ISSUE-2026-0026.md) - `bloom_send_rate` per-node ceiling exceedance class. Note that +- `bloom-storm` — chaos scenario; covers the `bloom_send_rate` + per-node ceiling exceedance class (single node spiking above the + ceiling while peers stay well under). Note that chaos uses its own python sim runner (not docker-compose), so the mesh-lab `compose-resource-limits.yml` and `compose-trace.yml` overrides do not apply to this suite; per-rep evidence comes from @@ -135,6 +135,26 @@ each rep does, set them in the invoking shell: containers; the sidecar fills that gap. Only applies to the `nat-lan` suite; other suites ignore it. +- **`FIPS_MESH_LAB_TRACE_TREE`** — when set to any non-empty value, + layers `compose-trace-tree.yml` over the rekey-family compose stack + to bump `RUST_LOG` to trace level on `fips::node::tree`, + `fips::tree`, `fips::node::handlers::mmp`, and + `fips::node::handlers::handshake`. Distinct from + `FIPS_MESH_LAB_TRACE` (rekey/forwarding/session/encrypted at trace); + targeted at tree-partition race investigation during multi-peer + startup. Mutually exclusive with `FIPS_MESH_LAB_TRACE` in practice — + both env vars layer their overlay, but the second one's per-service + environment replaces the first's. Only applies to the rekey-family + suites. + +- **`FIPS_MESH_LAB_NO_RESOURCE_LIMITS`** — when set to any non-empty + value, omits the `compose-resource-limits.yml` overlay for rekey-family + runs. Default behaviour keeps the overlay engaged so rekey-family lab + reps stay pressure-matched to a GHA `ubuntu-latest` runner. Set this + for unconstrained characterization where the goal is to surface a race + or scheduling artefact rather than reproduce CI pressure. Only applies + to the rekey-family suites; other suites ignore it. + - **`FIPS_MESH_LAB_RUNS_DIR`** — root directory for harness output (the `runs//` tree). When unset, the harness falls back to an in-tree path under `testing/mesh-lab/` and prints a warning diff --git a/testing/mesh-lab/compose-trace-tree.yml b/testing/mesh-lab/compose-trace-tree.yml new file mode 100644 index 0000000..e6a3a20 --- /dev/null +++ b/testing/mesh-lab/compose-trace-tree.yml @@ -0,0 +1,71 @@ +# Compose override that bumps RUST_LOG to trace level on the modules +# relevant to tree-partition / parent-re-eval investigations: +# +# - fips::node::tree — handle_tree_announce, +# evaluate_parent decisions, +# send_tree_announce_to_all +# recipient enumeration +# - fips::node::handlers::mmp — MMP receiver-report processing, +# first-RTT trigger, SRTT updates +# - fips::node::handlers::handshake — peer promotion timing +# (correlate with tree-announce +# broadcast window) +# - fips::tree — TreeState::evaluate_parent +# internal predicate flow +# +# Distinct from compose-trace.yml (rekey-class flake) — that overlay +# pulls in rekey / forwarding / session / encrypted at trace level +# which would drown the tree-convergence signal. This overlay is +# scoped to the tree-partition mechanism only. +# +# Service-name layout matches compose-trace.yml: per-profile services +# named `-` for the three rekey-family profiles. +# All 15 rekey-family services get the same trace RUST_LOG. +# +# Include this override alongside the base compose via: +# docker compose -f testing/static/docker-compose.yml \ +# -f testing/mesh-lab/compose-trace-tree.yml up -d +# +# The run-loop.sh harness includes it automatically when the mesh-lab +# environment variable FIPS_MESH_LAB_TRACE_TREE=1 is set. Mutually +# exclusive with FIPS_MESH_LAB_TRACE — set one or the other, not both. + +x-trace-tree-rust-log: &trace-tree-rust-log + RUST_LOG: "info,fips::node::tree=trace,fips::tree=trace,fips::node::handlers::mmp=trace,fips::node::handlers::handshake=trace" + +services: + # rekey profile + rekey-a: + environment: *trace-tree-rust-log + rekey-b: + environment: *trace-tree-rust-log + rekey-c: + environment: *trace-tree-rust-log + rekey-d: + environment: *trace-tree-rust-log + rekey-e: + environment: *trace-tree-rust-log + + # rekey-accept-off profile + rekey-accept-off-a: + environment: *trace-tree-rust-log + rekey-accept-off-b: + environment: *trace-tree-rust-log + rekey-accept-off-c: + environment: *trace-tree-rust-log + rekey-accept-off-d: + environment: *trace-tree-rust-log + rekey-accept-off-e: + environment: *trace-tree-rust-log + + # rekey-outbound-only profile + rekey-outbound-only-a: + environment: *trace-tree-rust-log + rekey-outbound-only-b: + environment: *trace-tree-rust-log + rekey-outbound-only-c: + environment: *trace-tree-rust-log + rekey-outbound-only-d: + environment: *trace-tree-rust-log + rekey-outbound-only-e: + environment: *trace-tree-rust-log diff --git a/testing/mesh-lab/run-loop.sh b/testing/mesh-lab/run-loop.sh index 27bb405..9fa9487 100755 --- a/testing/mesh-lab/run-loop.sh +++ b/testing/mesh-lab/run-loop.sh @@ -25,6 +25,20 @@ # of the base + resource-limits stack to # bump RUST_LOG to trace on rekey/handshake/ # forwarding/session/encrypted/mmp modules. +# FIPS_MESH_LAB_TRACE_TREE +# when set, layers compose-trace-tree.yml to +# bump RUST_LOG to trace on tree/mmp/handshake +# modules. Targeted at tree-partition race +# investigation during multi-peer startup. +# Mutually exclusive with FIPS_MESH_LAB_TRACE in +# practice — both apply but the second overlay +# replaces the first's per-service environment. +# FIPS_MESH_LAB_NO_RESOURCE_LIMITS +# when set, omits the compose-resource-limits.yml +# overlay for rekey-family runs. Use for +# unconstrained characterization (e.g. surfacing +# a race without GHA-pressure shaping). Does not +# affect other suites. # FIPS_MESH_LAB_RUNS_DIR Root for harness output (runs/ and any # other scratch). When unset, falls back to # an in-tree path under testing/mesh-lab/ @@ -163,6 +177,10 @@ run_rekey_family() { # ubuntu-latest runner imposes. Base compose is unmodified so # ci-local.sh stays unconstrained for day-to-day developer runs. # + # FIPS_MESH_LAB_NO_RESOURCE_LIMITS=1 omits the resource-limits overlay + # for unconstrained characterization runs where the goal is to expose + # a race or scheduling artifact rather than reproduce GHA pressure. + # # Trace-logging override: set FIPS_MESH_LAB_TRACE=1 in the environment # to bump RUST_LOG to trace level on the modules relevant to the # rekey-class flake (rekey, handshake, forwarding, session, encrypted, @@ -170,17 +188,17 @@ run_rekey_family() { # primary failure-moment evidence for mechanism investigation. local compose_args=( -f testing/static/docker-compose.yml - -f testing/mesh-lab/compose-resource-limits.yml - --profile "$compose_profile" ) - if [ -n "${FIPS_MESH_LAB_TRACE:-}" ]; then - compose_args=( - -f testing/static/docker-compose.yml - -f testing/mesh-lab/compose-resource-limits.yml - -f testing/mesh-lab/compose-trace.yml - --profile "$compose_profile" - ) + if [ -z "${FIPS_MESH_LAB_NO_RESOURCE_LIMITS:-}" ]; then + compose_args+=(-f testing/mesh-lab/compose-resource-limits.yml) fi + if [ -n "${FIPS_MESH_LAB_TRACE:-}" ]; then + compose_args+=(-f testing/mesh-lab/compose-trace.yml) + fi + if [ -n "${FIPS_MESH_LAB_TRACE_TREE:-}" ]; then + compose_args+=(-f testing/mesh-lab/compose-trace-tree.yml) + fi + compose_args+=(--profile "$compose_profile") ( cd "$REPO_ROOT" || exit 1 @@ -265,6 +283,34 @@ parse_rekey() { phase6_status="errors-observed" fi + # Phase 1 baseline convergence — captures the failure shape where the + # pre-rekey baseline never reaches 20/20 within the convergence + # timeout. rekey-test.sh prints the line + # Best observed baseline before timeout: N/M passed + # on the timeout path (else-branch) and exits 1 before any later + # phase runs. phase1_status reports `ok` (the if-branch ran a verbose + # ping_all and phase_result), `timeout` (the else-branch fired), or + # `unknown` (neither line scraped, e.g. test never reached Phase 1). + local phase1_status="unknown" + local phase1_passed="" + local phase1_total="" + local phase1_line + phase1_line=$(grep -m1 'Best observed baseline before timeout:' "$log" 2>/dev/null || true) + if [ -n "$phase1_line" ]; then + phase1_status="timeout" + phase1_passed=$(echo "$phase1_line" | grep -oE '[0-9]+/[0-9]+' | head -1 | cut -d/ -f1) + phase1_total=$(echo "$phase1_line" | grep -oE '[0-9]+/[0-9]+' | head -1 | cut -d/ -f2) + elif grep -q '✓ Pre-rekey baseline (all 20 pairs):' "$log" 2>/dev/null; then + phase1_status="ok" + local phase1_ok + phase1_ok=$(grep -m1 '✓ Pre-rekey baseline (all 20 pairs):' "$log" \ + | grep -oE '[0-9]+/[0-9]+' | head -1) + phase1_passed="${phase1_ok%/*}" + phase1_total="${phase1_ok#*/}" + fi + phase1_passed="${phase1_passed:-0}" + phase1_total="${phase1_total:-0}" + # Late FSP K-bit cutover detection — scan node logs for cutover- # complete events occurring within or after the Phase 5 settle # window. The settle window is the 12 s before Phase 5's first @@ -290,14 +336,26 @@ parse_rekey() { --arg pairs "$phase5_failures" \ --arg phase6 "$phase6_status" \ --arg events "$late_fsp_events" \ - '{phase5_failing_pairs: $pairs, phase6_log_analysis: $phase6, late_fsp_events_per_node_tail: $events}' \ + --arg p1_status "$phase1_status" \ + --argjson p1_passed "$phase1_passed" \ + --argjson p1_total "$phase1_total" \ + '{phase5_failing_pairs: $pairs, + phase6_log_analysis: $phase6, + late_fsp_events_per_node_tail: $events, + phase1_status: $p1_status, + phase1_baseline_passed: $p1_passed, + phase1_baseline_total: $p1_total}' \ > "$REP_DIR/signature.json" } -# Heuristic mechanism-match check for the rekey Phase 5 flake class. -# True iff: -# - At least one Phase 5 ping fails -# - Phase 6 log analysis is all-green (no ERROR/PANIC noise) +# Heuristic mechanism-match check for the rekey-family flake classes. +# True iff EITHER: +# - Phase 5 mechanism: at least one Phase 5 ping fails AND Phase 6 log +# analysis is all-green (the post-rekey reconvergence-flake shape) +# - Phase 1 mechanism: Phase 1 baseline timed out with the +# characteristic 12/20 multi-hop-only split (multi-hop routing not +# converging while direct-link forwarding works in the 5-node +# sparse mesh). mechanism_match_rekey() { local REP_DIR="$1" local sig="$REP_DIR/signature.json" @@ -314,14 +372,24 @@ mechanism_match_rekey() { echo "false" return fi - local pairs phase6 + local pairs phase6 p1_status pairs=$(jq -r '.phase5_failing_pairs' "$sig") phase6=$(jq -r '.phase6_log_analysis' "$sig") + p1_status=$(jq -r '.phase1_status' "$sig") if [ -n "$pairs" ] && [ "$phase6" = "all-green" ]; then echo "true" - else - echo "false" + return fi + # Any Phase 1 baseline-convergence timeout — the tree-partition + # surfaces with a variable count of failing multi-hop pairs depending + # on which node misses its parent re-evaluation (e.g., node-c orphan + # → 12/20 PASS, node-b orphan → 14/20). The exact count remains in + # signature.json for cross-rep analysis. + if [ "$p1_status" = "timeout" ]; then + echo "true" + return + fi + echo "false" } run_nat_lan() { @@ -363,7 +431,7 @@ run_nat_lan() { # bumps RUST_LOG to trace on discovery::nostr, transport::udp, # node::lifecycle, handlers::handshake, handlers::forwarding — # the modules covering the cross-init / adoption / handshake - # path that ISSUE-2026-0027 exhibits. Path is repo-relative. + # path that the NAT-traversal flake exhibits. Path is repo-relative. local -a env_args=(FIPS_NAT_SKIP_FINAL_CLEANUP=1) if [ -n "${FIPS_MESH_LAB_TRACE:-}" ]; then env_args+=(FIPS_NAT_EXTRA_COMPOSE=testing/mesh-lab/compose-trace-nat.yml) @@ -603,7 +671,7 @@ mechanism_match_nat_lan() { # on `stats.bloom.sent` deltas over the trailing 30s window of the # 180s run. The flake class tracked here is a single node spiking # above the ceiling while peers stay well under (asymmetric -# distribution), seen on master CI as ISSUE-2026-0026. +# distribution), as seen on master CI. # # Unlike rekey and nat-lan, chaos doesn't use docker-compose — the # python sim runner under `python3 -m sim` owns the container @@ -747,7 +815,7 @@ EOF mechanism_match_bloom_storm() { local REP_DIR="$1" local log="$REP_DIR/test-output.log" - # The ISSUE-2026-0026 mechanism is a bloom_send_rate FAIL with + # The bloom-storm mechanism is a bloom_send_rate FAIL with # at least one named offender (i.e., not the "failed to sample # window endpoints" sub-failure mode, which is harness rather # than mechanism). The asymmetric-distribution check (one node diff --git a/testing/static/scripts/rekey-test.sh b/testing/static/scripts/rekey-test.sh index 46b2d5e..5d79163 100755 --- a/testing/static/scripts/rekey-test.sh +++ b/testing/static/scripts/rekey-test.sh @@ -145,8 +145,14 @@ fi # ── Full test ───────────────────────────────────────────────────────── trap 'echo ""; echo "Test interrupted"; exit 130' INT -# Wait times derived from rekey timer -BASELINE_CONVERGENCE_TIMEOUT=60 +# Wait times derived from rekey timer. +# BASELINE_CONVERGENCE_TIMEOUT must cover one full daemon +# node.tree.reeval_interval_secs (default 60) plus a small margin +# so any partition that only heals via the periodic TreeAnnounce +# re-broadcast lands inside the convergence window. wait_for_full_baseline +# early-exits on PASS, so successful reps are unaffected by the +# extra headroom. +BASELINE_CONVERGENCE_TIMEOUT=65 REKEY_SETTLE=12 # > DRAIN_WINDOW_SECS (10) so post-rekey samples are off the old session # First FMP rekey should follow shortly after the 35s interval once the mesh is # fully converged. Keep this bounded to preserve a meaningful scheduling check