From 6315368b013d1598febd88e51ad83994b022e260 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Fri, 19 Jun 2026 16:41:30 +0000 Subject: [PATCH] test(xce-test-e2e-primitives): convert durability soak to exit-code primitives (task 7.1) --- .kiro/specs/xce-test-e2e-primitives/tasks.md | 3 +- src/tools/test-commit-durability.sh | 254 ++++++++++++++----- 2 files changed, 193 insertions(+), 64 deletions(-) diff --git a/.kiro/specs/xce-test-e2e-primitives/tasks.md b/.kiro/specs/xce-test-e2e-primitives/tasks.md index ad361774..8c441691 100644 --- a/.kiro/specs/xce-test-e2e-primitives/tasks.md +++ b/.kiro/specs/xce-test-e2e-primitives/tasks.md @@ -69,7 +69,7 @@ - _Depends: 1.1_ - [ ] 7. Reference E2E driver -- [ ] 7.1 Convert `test-commit-durability.sh` to use the primitives +- [x] 7.1 Convert `test-commit-durability.sh` to use the primitives - Replace the prose-grep + sanitizer-filter logic with piped `xce_test` scripts using `wait-primary`, `jobsub`/`$jobid`, `expect-jobs`/`expect-job`, and `!`-shell-escape for the primary kill/restart; gate each phase on the `xce_test` exit code. Preserve the rolling-kill + zero-loss coverage; add a `!`-driven cold-restart-all + `expect-jobs` step. - Observable: the converted soak runs end-to-end and reports pass/fail via `xce_test` exit codes (no joblist prose parsing); rolling-kill zero-loss coverage is retained; the cold-restart step asserts all committed jobs recover. - _Requirements: 8.1, 8.2, 8.3_ @@ -93,3 +93,4 @@ - 4.1 (bug-786 fixed): `cmd_jobsub` inits local `jobid=0`, prints `jobsubmit ok` + captures `g_last_jobid` ONLY after BOTH gates: `rc>=0` AND `jobid!=0`; else typed error (`E_XCE_NOMASTER/REDIRECT/NOT_READY`/timeout switch via `xce_strerror_r`) + `return <0`. **`$jobid` capture uses `fmt_jobid(g_last_jobid, ..., jobid)` — the FULL jobid, byte-identical to how `cmd_joblist` formats `jobs[i]->jobid`** (NOT `array_jobid()`, which the display-only `ok:` line uses). This is REQUIRED so task 5.3 `expect-job $jobid` matches the joblist column for array jobs. Also moved the error check AFTER the FREEUP block → fixed a pre-existing error-path leak. Live success-path ($jobid==joblist entry) verified by code reading; runtime-verified via soak (7.2). - 5.1: extracted DRY print-free helper `static int joblist_query(const char* find_jobid, int* contains, int print_table)` — single `xcecli_joblist` call + internal free; returns count (>=0) or `<0`; membership via `strcmp(fmt_jobid(buf,...,jobs[i]->jobid), find_jobid)` (SAME full-jobid form as 4.1's `$jobid`). `cmd_joblist` delegates `joblist_query(NULL,NULL,1)` and sets `g_last_jobcount=count` ONLY on success (no fake count on failure). 5.2/5.3 assertion commands call `joblist_query` directly. Live `$jobcount`-after-success needs a controller (soak 7.2). - 5.2/5.3/6.1: `expect-jobs`, `expect-job`, `wait-primary` are all CLIENT-context commands registered in `client_commands[]` (they need `active_ctx` to query jobs) — a script must `client` first. All return `<0` on failure → `preprocess_and_run` fails the session. Implemented directly (no flag macro); RED shown via unknown-command absence. Key invariant across assertions: a FAILED joblist query is an assertion failure (distinct message), NEVER silently "0 jobs"/"absent". `wait-primary`: monotonic `clock_gettime(CLOCK_MONOTONIC)`, default `WAIT_PRIMARY_DEFAULT_MS=30000`, poll `WAIT_PRIMARY_POLL_MS=200`, bounded (no hang) — do NOT run no-arg `wait-primary` against a dead cluster in a test (blocks 30s); pass a small explicit timeout. +- 7.1 (soak conversion): all `xce_test` verdicts now come from the PROCESS EXIT CODE via a single `xce_test_script` chokepoint (sets `ASAN_OPTIONS=detect_leaks=0`). `$jobid` capture uses `echo ACKED_JOBID $jobid` (space-separated — whole-token substitution requires it; a glued `MARK=$jobid` would NOT expand) parsed with `sed`. Multi-line script accumulation must use real `$'\n'`, NOT `$(...)` (command-sub strips trailing newlines → glued tokens). `current_primary`/`node_pid`/`node_role` log helpers retained ONLY for lifecycle (victim selection, strace targeting), never as a verdict. New `run_cold_restart_recovery` phase: `!pkill` all → `!bash start.sh` all → `wait-primary` → `expect-jobs`/`expect-job`. 7.2 (live run on `/xce-deploy-ha`) is the only remaining task — manual env prerequisite (needs a real 3-node cluster). diff --git a/src/tools/test-commit-durability.sh b/src/tools/test-commit-durability.sh index c01a9b22..6d59ccc5 100755 --- a/src/tools/test-commit-durability.sh +++ b/src/tools/test-commit-durability.sh @@ -205,42 +205,70 @@ current_primary() { return 1 } -# Wait until some live node is CTRL_PRIMARY and the other live nodes are not ELECTING. -wait_for_primary() { - local deadline=$(( $(date +%s) + ${1:-40} )) - while [ "$(date +%s)" -lt "$deadline" ]; do - current_primary >/dev/null && return 0 - sleep 1 - done - return 1 -} +# NOTE: serve-readiness ("is the cluster serving yet") is no longer decided by +# polling controller logs. It is now an xce_test exit-code gate via the +# `wait-primary` primitive (see wait_primary_primitive below). The log helpers +# above (node_role / current_primary / node_pid) survive ONLY for node-lifecycle +# decisions the shell still owns: picking which node to SIGKILL and locating a +# node's strace log — never for a pass/fail verdict. -# ── xce_test drivers (piped stdin; readline reads to EOF) ────────────────────── - -# Submit one job; echo the acked JobId (empty on failure). xce_test does its own -# client-side master rotation, so a single invocation rides through a failover. +# ── xce_test primitive drivers (piped stdin; exit code IS the verdict) ───────── # -# Only a well-formed success counts: the output must carry the literal -# "jobsubmit ok: JobId:" AND a canonical 4-field numeric id (0-0--). -# A submit attempted mid-failover can print a malformed id (e.g. "63-15--1-...") -# from an uninitialized jobid struct — that is NOT an ack and must be rejected, -# else the survival check chases a job the cluster never committed. -xce_submit_one() { - local out - out=$(printf 'set masters %s\nclient\njobsub -q %s -u %s -c "sleep 1000"\n' \ - "$MASTERS" "$QUEUE" "$JOBUSER" \ - | timeout 40 "$XCE_TEST" 2>/dev/null) - echo "$out" \ - | grep -oE 'jobsubmit ok: JobId: [0-9]+-[0-9]+-[0-9]+-[0-9]+' \ - | grep -oE '[0-9]+-[0-9]+-[0-9]+-[0-9]+$' \ - | head -1 +# Every cluster interaction now goes through an `xce_test` script whose PROCESS +# EXIT CODE is the pass/fail verdict (xce-test-e2e-primitives Req 1). The shell +# never parses joblist/jobsub prose for a verdict anymore — it pipes a script, +# checks `$?`, and (for jobsub) reads the tool's own authoritative captured id +# off an `echo $jobid` line after the clean-ack gate already passed. +# +# ASAN_OPTIONS=detect_leaks=0 on every invocation: the client has a known +# out-of-scope leak (design.md note); the exit-code verdict is only trustworthy +# with a clean exit, so leak detection must be off for the verdict to be valid. + +# Run a piped xce_test script; return its exit code (the verdict). The script is +# passed on stdin; readline reads to EOF. xce_test does its own client-side +# master rotation, so a single invocation rides through a failover. +xce_test_script() { + local script="$1" + printf '%s' "$script" \ + | ASAN_OPTIONS=detect_leaks=0 timeout 60 "$XCE_TEST" } -# List current JobIds (column 1), one per line. -xce_joblist() { - printf 'set masters %s\nclient\njoblist\n' "$MASTERS" \ - | timeout 40 "$XCE_TEST" 2>/dev/null \ - | grep -oE '^[0-9]+-[0-9]+-[0-9]+-[0-9]+' +# Serve-readiness gate (Req 4): block until a client op succeeds against the +# configured masters (or time out). Replaces the old log-polling wait_for_primary +# for the "is the cluster serving yet" decision. Returns 0 on success. +# Arg: timeout in ms (default 40000). +wait_primary_primitive() { + local timeout_ms="${1:-40000}" + xce_test_script "$(printf 'set masters %s\nclient\nwait-primary %s\n' \ + "$MASTERS" "$timeout_ms")" +} + +# Submit one job; echo the acked JobId (empty on failure). The ack VERDICT is the +# xce_test EXIT CODE (clean ack carrying a valid JobId => exit 0; bug-786 fix +# guarantees `jobsub` never reports "ok" with a malformed/uninitialized id and +# returns non-zero otherwise). On exit 0 we read the id from the `echo $jobid` +# line — that is the TOOL's authoritative captured id (after clean-ack gating), +# NOT a prose-grep of "jobsubmit ok". No more malformed-id grep. +xce_submit_one() { + local out rc id + # `jobsub` sets $jobid only on a clean ack; we then `echo` it on a uniquely + # marked line so the shell captures EXACTLY the tool's authoritative id + # (whatever fmt_jobid form it used — non-array N-N-N-N or array N-N-N-N[i]), + # format-agnostically, instead of re-imposing a brittle id regex. The marker + # and $jobid are SEPARATE whitespace-delimited tokens: $jobid is only + # substituted as a WHOLE token (a `$` glued to other text, e.g. + # `MARK=$jobid`, is NOT expanded), so we keep them apart and echo prints + # both. If the submit did not cleanly ack, jobsub fails -> session non-zero + # -> discard. + out=$(xce_test_script "$(printf 'set masters %s\nclient\njobsub -q %s -u %s -c "sleep 1000"\necho ACKED_JOBID $jobid\n' \ + "$MASTERS" "$QUEUE" "$JOBUSER")") + rc=$? + [ "$rc" -ne 0 ] && return 1 + # Exit 0 == clean ack. Pull the id off the marked line (second field, last + # such line wins). The id is whatever echo emitted after the marker token. + id=$(echo "$out" | sed -n 's/^ACKED_JOBID //p' | tail -1) + [ -z "$id" ] && return 1 + echo "$id" } submit_n() { @@ -251,30 +279,62 @@ submit_n() { echo "$jid" >> "$ACKED_FILE" echo " submitted (acked): $jid" else - yellow " submit returned no JobId (cluster mid-failover) — not counted" + yellow " submit did not cleanly ack (cluster mid-failover) — not counted" fi # Tight burst: keep the freshly-committed tail un-fsync'd when the kill # lands (the ~10ms wal_sync_ms window). No long inter-submit delay. done } -# Assert every acked JobId is still present. Returns 0 if all survive. +# Build ONE xce_test script: `expect-job ` per acked id, gate the WHOLE +# no-loss assertion on the single exit code (Req 5, Req 8.3). No joblist prose +# membership parsing — `expect-job` fails the session (non-zero) on the first +# missing committed id and reports it. Returns 0 iff all acked jobs survive. assert_no_loss() { - local label="$1" present missing=0 jid - present=$(xce_joblist | sort -u) + local label="$1" total script rc + total=$(sort -u "$ACKED_FILE" | grep -c . || true) + + if [ "$total" -eq 0 ]; then + # Nothing acked yet (e.g. baseline before any clean ack) — vacuously OK. + pass "$label: no committed jobs yet (nothing to lose)" + return 0 + fi + + # set masters / client first, then one expect-job per unique acked id. + # Accumulate with explicit $'\n' — command substitution strips trailing + # newlines, so `script+=$(printf ...\n)` would concatenate lines into one + # malformed token. + script="set masters ${MASTERS}"$'\n'"client"$'\n' + local jid while read -r jid; do [ -z "$jid" ] && continue - if ! echo "$present" | grep -qxF "$jid"; then - red " LOST committed job: $jid" - missing=$((missing+1)) - fi + script+="expect-job ${jid}"$'\n' done < <(sort -u "$ACKED_FILE") - local total; total=$(sort -u "$ACKED_FILE" | grep -c .) - if [ "$missing" -eq 0 ]; then + + xce_test_script "$script" + rc=$? + if [ "$rc" -eq 0 ]; then pass "$label: all $total committed jobs present after failover" return 0 else - fail "$label: DATA LOSS — $missing of $total committed jobs vanished (bug-661)" + fail "$label: DATA LOSS — a committed job vanished (bug-661); see expect-job output above" + return 1 + fi +} + +# Assert the cluster currently lists EXACTLY N jobs (Req 5.1/5.2), gated on the +# xce_test exit code. Used by the cold-restart-all recovery phase. Returns 0 iff +# the live count equals N. +assert_job_count() { + local label="$1" expected="$2" rc + xce_test_script "$(printf 'set masters %s\nclient\nexpect-jobs %s\n' \ + "$MASTERS" "$expected")" + rc=$? + if [ "$rc" -eq 0 ]; then + pass "$label: cluster lists exactly $expected jobs" + return 0 + else + fail "$label: job count != $expected after recovery (see expect-jobs output above)" return 1 fi } @@ -290,12 +350,16 @@ run_soak() { bash "$DEPLOY_DIR/scripts/cleanup.sh" >/dev/null 2>&1 || true start_cluster - if ! wait_for_primary 40; then - fail "cluster did not elect an initial primary within 40s" + # Serve-readiness is now an xce_test exit-code gate (Req 4), not log polling: + # wait-primary blocks until a client op succeeds against the masters. + if ! wait_primary_primitive 40000; then + fail "cluster did not become serveable (wait-primary timed out) within 40s" exit 1 fi - sleep 3 - green "Initial primary: $(current_primary)" + # current_primary reads logs ONLY to pick which node to SIGKILL — node + # lifecycle, allowed in the shell. The "is it serving" decision above was + # wait-primary, not log prose. + green "Initial primary (for victim selection): $(current_primary || echo '?')" # Seed a baseline batch so there is committed state before the first kill. echo "" @@ -311,6 +375,7 @@ run_soak() { submit_n "$JOBS_BEFORE_KILL" + # Pick the victim from log role (node lifecycle); fall back to round-robin. victim=$(current_primary || true) [ -z "$victim" ] && victim="${NODES[$(( round % 3 ))]}" vpid=$(node_pid "$victim") @@ -318,32 +383,42 @@ run_soak() { if [ -z "$vpid" ]; then yellow " no live victim found; skipping kill this round" else - # SIGKILL (not SIGSTOP): drop any WAL tail not yet fsync'd by the timer. - echo " SIGKILL primary $victim (pid $vpid) immediately after submit ..." - kill -9 "$vpid" 2>/dev/null || true + # SIGKILL via `!`-shell-escape inside an xce_test script (Req 2): the + # script confirms the cluster is serveable, then escapes to the shell + # to drop the primary. SIGKILL (not SIGSTOP) drops any WAL tail not + # yet fsync'd by the timer. Gate on the xce_test exit code. + echo " SIGKILL primary $victim (pid $vpid) via !kill immediately after submit ..." + if ! xce_test_script "$(printf 'set masters %s\nclient\nwait-primary 5000\n!kill -9 %s\n' \ + "$MASTERS" "$vpid")"; then + yellow " !kill script returned non-zero (kill may still have landed)" + fi fi - # Let the surviving two elect a new primary and serve. - if ! wait_for_primary 40; then - fail "round $round: no new primary elected within 40s after killing $victim" + # Let the surviving two elect a new primary and SERVE again (exit-code gate). + if ! wait_primary_primitive 40000; then + fail "round $round: cluster not serveable within 40s after killing $victim" # keep going to capture the loss signature else - echo " new primary: $(current_primary || echo '?')" + echo " new primary (for next victim): $(current_primary || echo '?')" fi sleep 2 # Submit against the new primary while one node is still down. submit_n "$JOBS_AFTER_KILL" - # Restart the killed node so it rejoins (reproduces hollow-rejoin election). + # Restart the killed node via `!`-shell-escape (Req 2) so it rejoins + # (reproduces hollow-rejoin election). start.sh is the node-lifecycle + # entrypoint; we escape to it from inside an xce_test script. if [ -n "${victim:-}" ]; then - echo " restarting $victim (rejoin) ..." - start_node "$victim" + echo " restarting $victim (rejoin) via !bash start.sh ..." + xce_test_script "$(printf '!VERBOSE=-vvv bash %s %s %s >/dev/null 2>&1 &\n' \ + "$DEPLOY_DIR/scripts/start.sh" "$victim" "$EXTRA_CTRL_ARGS")" \ + || yellow " !bash start.sh returned non-zero" fi - # Let the rejoined node catch up / participate in any re-election. - if ! wait_for_primary 40; then - fail "round $round: cluster lost its primary after $victim rejoined" + # Wait until the cluster serves again after the rejoin (exit-code gate). + if ! wait_primary_primitive 40000; then + fail "round $round: cluster not serveable after $victim rejoined" fi sleep 4 @@ -354,6 +429,56 @@ run_soak() { echo "--- final durability check ---" sleep 2 assert_no_loss "final" || true + + # ── NEW: cold-restart-all + expect-jobs recovery phase (Req 8.3) ────────── + # A full cold stop + cold start of every node, then assert ALL committed + # jobs recover. This exercises the durability/recovery path end-to-end (a + # bug-778-class WAL-replay regression would surface as a count mismatch). + run_cold_restart_recovery +} + +# Full cold restart of the cluster, then assert every acked job survives a +# from-disk recovery. The cold stop/start lifecycle is driven via `!`-shell- +# escape inside xce_test scripts (the task's `!`-driven cold-restart-all path, +# Req 2); the SERVE-readiness gate and the count assertion go through the +# primitives (wait-primary + expect-jobs / expect-job), exit-code-gated. +run_cold_restart_recovery() { + local committed + committed=$(sort -u "$ACKED_FILE" | grep -c . || true) + + echo "" + yellow "=== cold-restart-all recovery: assert $committed committed jobs survive a full restart ===" + + # Cold stop EVERY node via `!`-shell-escape (Req 2): we escape to the shell + # to kill the whole cluster, proving the `!`-driven cold path. + echo " cold stop (!kill all nodes) ..." + xce_test_script "$(printf '!pkill -9 -x xce_controller; sleep 1\n')" \ + || true # pkill exits 1 when nothing matched; harmless here. + sleep 1 + + # Cold start every node from disk via `!bash start.sh` (Req 2). + echo " cold start (!bash start.sh all nodes) ..." + local n + for n in "${NODES[@]}"; do + xce_test_script "$(printf '!VERBOSE=-vvv bash %s %s %s >/dev/null 2>&1 &\n' \ + "$DEPLOY_DIR/scripts/start.sh" "$n" "$EXTRA_CTRL_ARGS")" \ + || yellow " !bash start.sh $n returned non-zero" + sleep 0.5 + done + + # SERVE-readiness after the cold restart (exit-code gate, generous timeout: + # a from-disk recovery + election can take longer than a live failover). + if ! wait_primary_primitive 60000; then + fail "cold-restart: cluster not serveable within 60s after full cold restart" + return 1 + fi + sleep 3 + + # Assert ALL committed jobs recovered after the full cold restart. We check + # both the exact count (expect-jobs) and per-id membership (expect-job), + # each gated on the xce_test exit code — no joblist prose parsing. + assert_job_count "cold-restart" "$committed" || true + assert_no_loss "cold-restart" || true } # ── deterministic mode (timing-independent DURABILITY-GAP proof) ────────────── @@ -475,14 +600,17 @@ run_deterministic() { rm -f "$LOGDIR"/*.strace.log 2>/dev/null || true start_cluster - if ! wait_for_primary 40; then - fail "cluster did not elect an initial primary within 40s" + # Serve-readiness via the exit-code primitive (Req 4), not log polling. The + # log-role current_primary below is used ONLY to locate the strace log of the + # primary to inspect — node lifecycle, allowed in the shell. + if ! wait_primary_primitive 40000; then + fail "cluster did not become serveable (wait-primary timed out) within 40s" exit 1 fi # Generous initial settle so the elected primary fully serves jobsub and its # boot-time fdatasyncs (segment preallocation) are well before any probe window. sleep 6 - green "Initial primary: $(current_primary)" + green "Initial primary (strace target): $(current_primary)" # Repeat the probe several times against the stable primary. Every probe must # be RED on the unfixed build — this is the in-run reproducibility evidence