wdgzyjx/myxce
1
0
Fork 0
forked from lei.chen/myxce
Code Pull requests Activity

test(raft-ha-core-safety): client-probe soak primary-detection (task 1.5)

Browse source 
Release build block-buffers --logfile (flush on signal only), so log-grep
primary/convergence detection false-aborted. Replace all log-grep detection
with client probes (xce_test ctrlstatus): probe_primary/node_probe/
cluster_committed_converged. Both modes use shared helpers; 1.2 verdict
self-test 17/17 intact; bug-854 isolation preserved. Live release-binary
runs reach the verdict (chaotic re-confirms committed_divergence=3 / job
loss 0; sequential PASS). No production code touched. Phase 1 complete.
This commit is contained in:
Rongsong Shen 2026-06-27 10:12:50 +00:00
parent dc50924833
commit 07f08e58f5
3 changed files with 159 additions and 76 deletions
Download patch file Download diff file Expand all files Collapse all files

24
.claude/skills/xce-test-ha/SKILL.md
View file

@ -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 |

209
.claude/skills/xce-test-ha/run-ha-soak.sh
View file

@ -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 <dir>`) 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 "<ctrl-N> <term> <committedLsn>" 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> <term> <committedLsn> <appliedLsn> <fenced>"
# (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)"