diff --git a/.claude/skills/xce-test-ha/SKILL.md b/.claude/skills/xce-test-ha/SKILL.md index bb8d2e3..2e4b20c 100644 --- a/.claude/skills/xce-test-ha/SKILL.md +++ b/.claude/skills/xce-test-ha/SKILL.md @@ -56,6 +56,18 @@ XCE_HA_ROUNDS=6 nix develop ./src --command bash "$SKILL_DIR/run-ha-soak.sh" --c XCE_HA_MODE=chaotic XCE_HA_ROUNDS=6 nix develop ./src --command bash "$SKILL_DIR/run-ha-soak.sh" /tmp/ha-chaos ``` +`run-ha-soak.sh` also accepts a **bare-integer positional** as the round count +(matching `/xce-test-ha [rounds] [dir]`): a non-integer positional is the deploy +dir, an integer positional is rounds. So the release-binary short run is: + +```bash +# 2-round chaotic soak on real-fs release binaries (no nix shell needed for the +# release build), positional rounds + dir: +XCE_HA_BIN=$PWD/src/build.release/controller/xce_controller \ +XCE_HA_XT=$PWD/src/build.release/controller/xce_test \ + bash .claude/skills/xce-test-ha/run-ha-soak.sh --chaotic 2 ~/tmp/ha-1p5 +``` + For the **acceptance gate (task 7.2)** run chaotic mode for ≥6 rounds against **real-fs (ext4) release binaries** (point `XCE_HA_BIN` / `XCE_HA_XT` at the release `xce_controller` / `xce_test`). @@ -169,9 +181,13 @@ XCE_HA_ROUNDS=10 XCE_HA_TOP=/tmp/my-ha-run nix develop ./src --command bash "$SK `ctrl-1=localhost:9991, ctrl-2=localhost:9992, ctrl-3=localhost:9993`, using config/certs from `XCE_HA_DATADIR`. 3. **Start** — `scripts/start.sh ctrl-N -vvv` for all three, 0.5s staggered. -4. **Elect** — waits (≤45s) for `raft_cb_become_leader … CTRL_PRIMARY` in any - `logs/ctrl-N.log`, then confirms the client can reach the primary via - `ctrlstatus`. +4. **Elect** — detects the elected primary via a **client probe** (`xce_test` + `wait-primary` + `ctrlstatus`), reading live controller state. Primary, + per-failover term, and convergence are ALL detected through the client path, + never by grepping a controller logfile: the RELEASE build block-buffers its + `--logfile` and flushes only on signal, so a log grep lags reality and would + false-abort ("no primary within Ns") even though a primary is serving (task + 1.3). The client probe is immune to that buffering. 5. **Initial workload** — drives `xce_test`: `set masters … / client / wait-primary / jobsub ×N / joblist (expect-job) / walcompare`. Every acked `JobId` is tracked. @@ -270,7 +286,7 @@ printf 'waldump %s/controller/ctrl-1/data\nquit\n' "$XCE_HA_TOP" \ | Symptom | Cause | Fix | |---|---|---| | `controller binary missing` | not built | `/xce-build controller` | -| `no primary elected within 45s` | cold-start election stalled / port clash | check `logs/ctrl-*.log`; ensure ports 9991-9993 free | +| `no primary elected within ~90s via client probe` | cold-start election stalled / port clash (NOT a log-buffer artifact — detection is client-probe based) | check `logs/ctrl-*.log`; ensure ports 9991-9993 free | | `primary elected in logs but client could not reach it` | client discovery (bug-854 regression) | check `client.c` rotation fix is in the binary | | `a committed job was LOST after failover` | data-safety regression (bug-828 class) | inspect WAL via `waldump`; this is a real FAIL | | driver hangs | a controller wedged; `xtest` 60s timeout should break it | check for stuck `xce_test`/`xce_controller` procs | diff --git a/.claude/skills/xce-test-ha/run-ha-soak.sh b/.claude/skills/xce-test-ha/run-ha-soak.sh index aef3fb1..4dc2f42 100755 --- a/.claude/skills/xce-test-ha/run-ha-soak.sh +++ b/.claude/skills/xce-test-ha/run-ha-soak.sh @@ -10,8 +10,10 @@ # and xce_test runtime libs (openssl etc.) are on the library path. # # Usage: -# run-ha-soak.sh [--chaotic|--sequential] [--selftest] [DEPLOY_DIR] -# DEPLOY_DIR optional deploy directory (positional). Precedence: +# run-ha-soak.sh [--chaotic|--sequential] [--selftest] [ROUNDS] [DEPLOY_DIR] +# ROUNDS optional bare integer (e.g. `2`): kill/restart rounds. +# Precedence: positional integer > $XCE_HA_ROUNDS > default 6. +# DEPLOY_DIR optional deploy directory (non-integer positional). Precedence: # positional arg > $XCE_HA_TOP env > default. Relative paths # are resolved to absolute. # --chaotic overlapping-kill mode: kills land INSIDE election/catch-up @@ -33,17 +35,23 @@ # XCE_HA_WAITMS wait-primary budget (default 30000) set -u -# ── Mode / flag parsing (flags may precede the positional DEPLOY_DIR) ───────── +# ── Mode / flag parsing (flags may precede the positional [ROUNDS] [DEPLOY_DIR]) ─ # `--selftest` short-circuits to the verdict self-test before any cluster setup. +# Positional args match the `/xce-test-ha [rounds] [dir]` convention: a bare +# integer positional is ROUNDS; a non-integer positional is the DEPLOY_DIR. Either +# may be omitted (env/default fills in). This lets `--chaotic 2 ~/tmp/ha` mean +# "2 rounds into ~/tmp/ha", as documented, without a dir of "2". SELF_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" MODE="${XCE_HA_MODE:-sequential}" +ROUNDS_CLI="" # rounds from a bare-integer positional (wins over env/default) ARGS=() while [ $# -gt 0 ]; do case "$1" in --chaotic) MODE="chaotic" ;; --sequential) MODE="sequential" ;; --selftest) exec bash "$SELF_DIR/soak-verdict-selftest.sh" ;; - *) ARGS+=("$1") ;; + *[!0-9]*|'') ARGS+=("$1") ;; # non-integer ⇒ deploy dir + *) ROUNDS_CLI="$1" ;; # bare integer ⇒ rounds esac shift done @@ -73,8 +81,16 @@ BIN="${XCE_HA_BIN:-$REPO/src/xce.build/controller/xce_controller}" XT="${XCE_HA_XT:-$REPO/src/xce.build/controller/xce_test}" DEPLOY="$REPO/src/tools/deploy-ha.sh" -ROUNDS="${XCE_HA_ROUNDS:-6}" -[ "$ROUNDS" -lt 5 ] && ROUNDS=5 +# Rounds precedence: bare-integer positional (ROUNDS_CLI) > $XCE_HA_ROUNDS > 6. +# Default soak floor stays 5; an EXPLICIT small request (CLI or env) is honored +# down to 2 so a short detection/smoke run (task 1.5: `--chaotic 2 `) can +# reach its verdict quickly. Upper bound clamped to 10. +ROUNDS="${ROUNDS_CLI:-${XCE_HA_ROUNDS:-6}}" +if [ -n "$ROUNDS_CLI" ] || [ -n "${XCE_HA_ROUNDS:-}" ]; then + [ "$ROUNDS" -lt 2 ] && ROUNDS=2 # explicit request: honor down to 2 +else + [ "$ROUNDS" -lt 5 ] && ROUNDS=5 # default soak floor +fi [ "$ROUNDS" -gt 10 ] && ROUNDS=10 NJOBS="${XCE_HA_JOBS:-3}" WAITMS="${XCE_HA_WAITMS:-30000}" @@ -133,56 +149,91 @@ xtest() { ASAN_OPTIONS=detect_leaks=0 timeout 60 "$XT" 2>&1; } start_node() { bash "$TOP/scripts/start.sh" "$1" -vvv >/dev/null 2>&1 & } -# The INFO-level promotion marker each elected primary logs (ha.c: raft_cb_ -# become_leader → "HA FSM (raft): → CTRL_PRIMARY (term=N, ...)"). Present even -# without -vvv. We track election by this line + its term, which is the most -# reliable "a new primary was elected" signal (independent of client-side -# discovery). NOTE: the arrow is a UTF-8 "→"; grep with a wildcard to avoid -# encoding pitfalls. -PRIMARY_LOG_RE='HA FSM .raft.: . CTRL_PRIMARY .term=' +# ── Primary / convergence detection: CLIENT PROBE (release-build-log-immune) ── +# The RELEASE controller block-buffers its --logfile and flushes only on a signal +# (task 1.3 finding), so grepping a node's logfile for the CTRL_PRIMARY promotion +# marker LAGS reality and false-aborts ("no primary within Ns") even though a +# primary WAS elected and is serving. All primary + convergence detection here +# therefore goes through the CLIENT path (xce_test `ctrlstatus`), which reads live +# controller state and is unaffected by the buffered logfile. ctrlstatus reports +# Primary, responder role, term, committedLsn and appliedLsn directly. +# +# Note on bug-854 isolation: the old log-grep claimed "server truth, independent +# of client discovery". Under the buffered release logfile that server-side signal +# is simply invisible, so the client probe is the only usable election signal on +# release binaries. The chaotic verdict still isolates bug-854 separately via +# verify_classify/discover_primary (a discovery miss is COUNTED, never a verdict +# fault), so detection moving to the client does not weaken that isolation. -# Highest term any node has announced CTRL_PRIMARY for, across all logs. -latest_primary_term() { - grep -ohE "$PRIMARY_LOG_RE[0-9]+" "$TOP"/logs/*.log 2>/dev/null \ - | grep -oE 'term=[0-9]+' | grep -oE '[0-9]+' | sort -n | tail -1 +# Per-probe wait-primary budget for the POLLING probes — kept short so a poll loop +# stays time-bounded; the authoritative discover_primary still uses full WAITMS. +PROBE_WAITMS="${XCE_HA_PROBE_WAITMS:-2500}" + +# Single client probe of the SERVING primary. wait-primary rotates the any-node +# read onto the primary; echoes " " on success (a +# genuinely elected + serving primary), or nothing with rc!=0 if no primary is +# reachable within PROBE_WAITMS. Log-buffer-immune. +probe_primary() { + local out name term clsn + out="$(printf 'set masters %s\nset myname probe\nclient\nwait-primary %s\nctrlstatus\nquit\n' \ + "$MASTERS" "$PROBE_WAITMS" | xtest)" + name="$(printf '%s\n' "$out" | sed -n 's/^Primary: \(ctrl-[0-9]\)$/\1/p' | head -1)" + [ -n "$name" ] || return 1 + term="$(printf '%s\n' "$out" | sed -n 's/^term: \([0-9][0-9]*\)$/\1/p' | head -1)" + clsn="$(printf '%s\n' "$out" | sed -n 's/^committedLsn: \([0-9][0-9]*\)$/\1/p' | head -1)" + echo "$name ${term:-0} ${clsn:-0}" } -# The node name that most recently logged CTRL_PRIMARY (the elected primary). -# Echoes "ctrl-N" or "" — purely from the logs, no client round-trip. -primary_from_log() { - local n best_term="" best_node="" t - for n in "${NODES[@]}"; do - t="$(grep -oE "$PRIMARY_LOG_RE[0-9]+" "$TOP/logs/$n.log" 2>/dev/null \ - | grep -oE 'term=[0-9]+' | grep -oE '[0-9]+' | sort -n | tail -1)" - [ -z "$t" ] && continue - if [ -z "$best_term" ] || [ "$t" -ge "$best_term" ]; then - best_term="$t"; best_node="$n" - fi - done - echo "$best_node" +# Direct client probe of ONE node (single-master, NO wait-primary so a STANDBY +# answers about ITSELF). Echoes " " +# (role from the "answered by ctrl-N (role)" line), or nothing with rc!=0 if the +# node is unreachable. Used by the convergence check to read each member directly. +node_probe() { + local node="$1" addr out role term clsn alsn fenced + addr="localhost:${PORT[$node]}" + out="$(printf 'set masters %s\nset myname conv\nclient\nctrlstatus\nquit\n' "$addr" | xtest)" + role="$(printf '%s\n' "$out" | sed -n 's/^answered by ctrl-[0-9] (\([a-z-]*\))$/\1/p' | head -1)" + [ -n "$role" ] || return 1 + term="$(printf '%s\n' "$out" | sed -n 's/^term: \([0-9][0-9]*\)$/\1/p' | head -1)" + clsn="$(printf '%s\n' "$out" | sed -n 's/^committedLsn: \([0-9][0-9]*\)$/\1/p' | head -1)" + alsn="$(printf '%s\n' "$out" | sed -n 's/^appliedLsn: \([0-9][0-9]*\)$/\1/p' | head -1)" + fenced="$(printf '%s\n' "$out" | sed -n 's/^fenced: \(.*\)$/\1/p' | head -1)" + echo "$role ${term:-0} ${clsn:-0} ${alsn:-0} ${fenced:-unknown}" } -# Block until a node announces CTRL_PRIMARY at a term STRICTLY GREATER than -# `$1` (the term before the kill), i.e. a genuinely NEW election has happened. -# Echoes the new primary's node name on success; returns non-zero on timeout. +# Highest term the SERVING primary advertises (client probe; replaces the old +# logfile term grep). Empty if no primary is reachable. Name kept for callers. +latest_primary_term() { local i; i="$(probe_primary)" && [ -n "$i" ] && echo "$i" | awk '{print $2}'; } + +# Node name of the current SERVING primary (client probe; replaces the old logfile +# name grep). "ctrl-N" or empty. Name kept for callers. +primary_from_log() { local i; i="$(probe_primary)" && [ -n "$i" ] && echo "$i" | awk '{print $1}'; } + +# Block until the SERVING primary advertises a term STRICTLY GREATER than `$1` +# (the term before the kill) — a genuinely NEW election. Echoes the new primary's +# node name on success; non-zero on timeout. Each probe is PROBE_WAITMS-bounded so +# the loop is time-bounded (~30 × (≤PROBE_WAITMS + 1s) ≈ 90s). wait_for_new_primary() { - local prev_term="${1:-0}" i t node - for i in $(seq 1 45); do - t="$(latest_primary_term)" - if [ -n "$t" ] && [ "$t" -gt "$prev_term" ]; then - node="$(primary_from_log)" - [ -n "$node" ] && { echo "$node"; return 0; } + local prev_term="${1:-0}" i info name term + for i in $(seq 1 30); do + if info="$(probe_primary)"; then + name="$(echo "$info" | awk '{print $1}')" + term="$(echo "$info" | awk '{print $2}')" + if [ -n "$term" ] && [ "$term" -gt "$prev_term" ] && [ -n "$name" ]; then + echo "$name"; return 0 + fi fi sleep 1 done return 1 } -# Wait until SOME node logs CTRL_PRIMARY (cold-start election), up to ~45s. +# Wait until SOME node is a SERVING primary (cold-start / post-failover election), +# up to ~90s. Client probe (log-buffer-immune). wait_for_primary_log() { local i - for i in $(seq 1 45); do - [ -n "$(latest_primary_term)" ] && return 0 + for i in $(seq 1 30); do + probe_primary >/dev/null 2>&1 && return 0 sleep 1 done return 1 @@ -209,41 +260,57 @@ discover_primary() { return 1 } -# Wait until the cluster is FULLY converged: all 3 controllers are alive AND the -# current primary is no longer actively streaming catch-up to any standby. This -# is a HARD precondition before killing the next primary — killing while a just- -# restarted node is still catching up tests an UNSUPPORTED double-fault-within- -# one-reconvergence window (a momentary 2-of-3 with a stale member), not the -# single-failover guarantee. +# True (rc 0) iff every member, probed DIRECTLY via the client, holds a consistent +# committed prefix right now: all 3 reachable, exactly one primary + two standbys, +# none fenced, and each standby's committedLsn has caught up to the primary's. This +# is the client-probe convergence signal that replaces the old "primary stopped +# logging 'stream WAL batches'" heuristic — invisible under the buffered release +# logfile. The primary's appliedLsn may transiently trail its own committedLsn, so +# convergence keys on the committed prefix (committedLsn), not appliedLsn. +cluster_committed_converged() { + local n role term clsn alsn fenced primaries=0 standbys=0 pcommit="" info + declare -A NCOMMIT=() + for n in "${NODES[@]}"; do + info="$(node_probe "$n")" || return 1 # a member is unreachable + read -r role term clsn alsn fenced <<<"$info" + [ "$fenced" = "true" ] && return 1 # a fenced member is not converged + NCOMMIT["$n"]="$clsn" + case "$role" in + primary) primaries=$((primaries + 1)); pcommit="$clsn" ;; + standby) standbys=$((standbys + 1)) ;; + *) return 1 ;; # electing/initializing ⇒ not settled + esac + done + [ "$primaries" -eq 1 ] && [ "$standbys" -eq 2 ] || return 1 + [ -n "$pcommit" ] || return 1 + for n in "${NODES[@]}"; do # every standby caught up to primary + [ "${NCOMMIT[$n]:-0}" -ge "$pcommit" ] || return 1 + done + return 0 +} + +# Wait until the cluster is FULLY converged: all 3 controllers are alive AND every +# member agrees on the committed prefix. This is a HARD precondition before killing +# the next primary — killing while a just-restarted node is still catching up tests +# an UNSUPPORTED double-fault-within-one-reconvergence window (a momentary 2-of-3 +# with a stale member), not the single-failover guarantee. # -# Convergence signal: a lagging standby makes the primary log "stream WAL batches" -# every heartbeat (~3s); once every standby is caught up the primary STOPS -# emitting that line (action becomes HA_REPL_CONVERGED, a no-op). So "no new -# 'stream WAL batches' line on the primary for STABLE_S seconds" == all standbys -# converged. This is robust to the per-term re-emit quirk of the "standby[i] -# converged" transition log (which only fires for a standby that was previously -# NOT converged under the current primary term). Bounded ~90s. +# Convergence is checked via the CLIENT path (cluster_committed_converged): the old +# log-grep of "stream WAL batches" is invisible under the release build's buffered +# logfile. Stable for STABLE_TICKS consecutive probes ⇒ converged. Bounded ~90s. wait_for_full_convergence() { - local i alive primary line_now line_prev stable=0 - local STABLE_TICKS=3 # 3 ticks × 2s = 6s with no new stream line ⇒ converged - line_prev="" - for i in $(seq 1 45); do + local i alive stable=0 + local STABLE_TICKS=2 # 2 consecutive converged probes ⇒ settled + for i in $(seq 1 30); do alive="$(pgrep -c -f -- "xce_controller --myname ctrl-")" if [ "$alive" -lt 3 ]; then stable=0; sleep 2; continue fi - primary="$(primary_from_log)" - [ -z "$primary" ] && { sleep 2; continue; } - # Most recent "stream WAL batches" line in the primary's log (empty if - # the primary has never streamed / has stopped). Compare across ticks: - # if it has not changed for STABLE_TICKS, no catch-up is in flight. - line_now="$(grep -n "stream WAL batches" "$TOP/logs/$primary.log" 2>/dev/null | tail -1)" - if [ "$line_now" = "$line_prev" ]; then + if cluster_committed_converged; then stable=$((stable + 1)) [ "$stable" -ge "$STABLE_TICKS" ] && return 0 else stable=0 - line_prev="$line_now" fi sleep 2 done @@ -572,7 +639,7 @@ done # ── Step 4: confirm a primary was elected ──────────────────────────────────── log "waiting for primary election (cold start ~15s)" -wait_for_primary_log || fail "no primary elected within 45s (check $TOP/logs)" +wait_for_primary_log || fail "no primary elected within ~90s via client probe (check $TOP/logs)" PRIMARY="$(discover_primary)" [ -n "$PRIMARY" ] || fail "primary elected in logs but client could not reach it" record_primary "$PRIMARY" @@ -655,11 +722,11 @@ for round in $(seq 1 "$ROUNDS"); do DOWN="$PRIMARY" sleep 2 - # Step 7: a NEW primary must be elected (CTRL_PRIMARY at a higher term in the - # logs) AND be reachable by the client; then joblist must show no loss. + # Step 7: a NEW primary must be elected (client probe reports a SERVING + # primary at a higher term) AND be reachable; then joblist must show no loss. log "round $round: waiting for new primary (term > $PREV_TERM)" NEWP="$(wait_for_new_primary "$PREV_TERM")" - [ -n "$NEWP" ] || fail "round $round: no new primary elected after kill (no CTRL_PRIMARY term>$PREV_TERM)" + [ -n "$NEWP" ] || fail "round $round: no new primary elected after kill (no serving primary at term>$PREV_TERM)" log "round $round: new primary elected: $NEWP (term=$(latest_primary_term))" record_primary "$NEWP" PRIMARY="$(discover_primary)" diff --git a/.kiro/specs/raft-ha-core-safety/tasks.md b/.kiro/specs/raft-ha-core-safety/tasks.md index 160f87d..e08e862 100644 --- a/.kiro/specs/raft-ha-core-safety/tasks.md +++ b/.kiro/specs/raft-ha-core-safety/tasks.md @@ -31,7 +31,7 @@ - _Requirements: 7.1, 7.4_ - _Boundary: Deterministic Chaotic Harness_ -- [ ] 1.5 Make soak primary-detection robust to the release-build log buffer +- [x] 1.5 Make soak primary-detection robust to the release-build log buffer - Task 1.3 found the release build block-buffers its `--logfile` and flushes only on signal, so the soak's log-grep primary/convergence detection cannot see an elected primary and false-aborts. Switch the soak's primary + convergence detection to a client probe (`ctrlstatus`/`xce_test`) instead of log-grep, so the chaotic soak runs unattended on release binaries. (Only if a client probe is insufficient, fall back to a controller release log-flush change that does not alter production logging semantics.) - Observable completion: `run-ha-soak.sh --chaotic` on the `~/tmp` real-fs path with the `src/build.release` binaries detects the elected primary each round via the client probe and no longer false-aborts on "no primary within Ns"; a short (2-round) run reaches its verdict line - _Requirements: 7.5, 8.3_