From d82cc782843fbd6c23146f1619334dbbcbbc6473 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Sat, 20 Jun 2026 01:27:38 +0000 Subject: [PATCH] =?UTF-8?q?test(xce-test-e2e-primitives):=20harden=20durab?= =?UTF-8?q?ility=20soak=20=E2=80=94=20separate=20liveness=20from=20durabil?= =?UTF-8?q?ity,=20no=20false=20bug-661=20cascades?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Conflation fix: gate every kill + durability assertion on cluster health (3 nodes up + serving + rejoin settle); assert_no_loss probes serveability first and reports INCONCLUSIVE (not DATA LOSS) when unserveable; confirm-settle re-check distinguishes catch-up lag from persistent loss; post-kill election SLA configurable (60s default). DATA LOSS now reported ONLY for a job persistently absent from a SERVING cluster. --- .kiro/specs/xce-test-e2e-primitives/tasks.md | 1 + src/tools/test-commit-durability.sh | 106 +++++++++++++++++-- 2 files changed, 97 insertions(+), 10 deletions(-) diff --git a/.kiro/specs/xce-test-e2e-primitives/tasks.md b/.kiro/specs/xce-test-e2e-primitives/tasks.md index 3ddea4c..4453c5b 100644 --- a/.kiro/specs/xce-test-e2e-primitives/tasks.md +++ b/.kiro/specs/xce-test-e2e-primitives/tasks.md @@ -95,4 +95,5 @@ - 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). +- 7.1 SOAK ROBUSTNESS HARDENING (post-merge, prompted by a 10-round live run that produced 18 mostly-FALSE "DATA LOSS — bug-661" lines): the converted soak CONFLATED liveness with durability — once a round's `wait-primary` failed (cluster transiently unserveable), it STILL ran `assert_no_loss`, so every `expect-job` "not found" was mislabeled DATA LOSS, cascading. Root cause of the unavailability: killing the next primary before the previous round's restarted node had REJOINED → drops the live set to 1 node (no quorum). Fix (all in `src/tools/test-commit-durability.sh`): (1) `wait_cluster_healthy` gate (all 3 node PIDs up + a primary serves + rejoin settle) BEFORE each kill and before each durability assertion — never SIGKILL into a degraded cluster; (2) `assert_no_loss` PROBES serveability first → `inconc()` INCONCLUSIVE (distinct verdict, not DATA LOSS) when the cluster isn't serving; (3) a confirm-settle re-check so a momentary post-failover catch-up lag is not mislabeled a permanent loss — DATA LOSS is reported ONLY for a job PERSISTENTLY absent from a SERVING cluster; (4) post-kill election SLA `ELECT_TIMEOUT_MS` default 60s, liveness failures labeled distinctly; (5) `INCONC` tally in the final verdict. RESULT: zero false cascades; durability vs liveness cleanly separated. A durability soak must NEVER cry bug-661 when it merely cannot reach a primary — that conflation makes the whole soak untrustworthy. - 7.2 LIVE RUN OUTCOME (ran 3 live soaks on a sandbox 3-node cluster): the converted soak works end-to-end with the exit-code verdict; rolling-kill zero-loss PASSES every round. TWO findings: (A) IN-SCOPE/FIXED — bug-786's 4.1 gate was insufficient (stale non-zero reply id `63-15--1-1015808` slipped past `jobid != 0`); strengthened to `jobid == jobsubmit.jobid` (commit 8609976), garbage now rejected loud. Root cause is upstream libxce (`xcectx.c handle_sub_reply` leaves `ctx->reply.u.jobid` stale on a non-jobid reply; `xceapi.c:309` copies it when status>=0) — the test client defends itself per Req 7.3 without touching libxce (boundary). (B) UPSTREAM/OUT-OF-SCOPE — cold-restart-all (kill ALL 3 + restart) NON-DETERMINISTICALLY loses a committed job (passed run #2, FAILED run #3: baseline job `0-0-...332-0` survived all rolling rounds then vanished after full restart; recovery logs show WAL `truncate`). This is a controller commit-durability race under total-cluster-outage — owned by `ha-commit-durability`, surfaced (correctly) by this spec's new soak step. Sandbox is overlayfs, NOT the task's required "real fsync-able fs"; confirm on real hw + route to ha-commit-durability owner. DO NOT patch this in the test spec. diff --git a/src/tools/test-commit-durability.sh b/src/tools/test-commit-durability.sh index 6d59ccc..fa35973 100755 --- a/src/tools/test-commit-durability.sh +++ b/src/tools/test-commit-durability.sh @@ -125,12 +125,19 @@ ACKED_FILE="$(mktemp "$WORKTREE/.xce-durability-acked.XXXXXX")" PASS=0 FAIL=0 +INCONC=0 # durability could not be assessed (cluster not serving) — NOT data loss green() { printf '\033[32m%s\033[0m\n' "$*"; } red() { printf '\033[31m%s\033[0m\n' "$*"; } yellow() { printf '\033[33m%s\033[0m\n' "$*"; } pass() { green " PASS: $*"; PASS=$((PASS+1)); } fail() { red " FAIL: $*"; FAIL=$((FAIL+1)); } +# A LIVENESS/AVAILABILITY failure is a real fault, but it is NOT a bug-661 +# durability violation — keep it a distinct verdict so it is never mislabeled +# "DATA LOSS". inconc() = durability inconclusive (cluster unreachable), reported +# but kept separate from both PASS and DATA-LOSS so one outage does not cascade +# into a pile of false "committed job vanished" lines. +inconc() { yellow " INCONCLUSIVE: $*"; INCONC=$((INCONC+1)); } cleanup_exit() { rm -f "$ACKED_FILE"; kill_cluster 2>/dev/null || true; } trap cleanup_exit EXIT @@ -243,6 +250,30 @@ wait_primary_primitive() { "$MASTERS" "$timeout_ms")" } +# Cluster HEALTH gate (NOT just "a primary serves"): every node process is back +# up (lifecycle via node_pid) AND a client op succeeds (wait-primary). This is +# the precondition for (a) killing the next primary — so we never SIGKILL down to +# a single node and induce a self-inflicted quorum loss the test then misreports +# as bug-661 — and (b) trusting a durability assertion. A rejoined node that has +# not finished catching up is the usual cause of the next round losing quorum, so +# we also settle briefly once all three are up. Returns 0 iff healthy in time. +# Args: . +wait_cluster_healthy() { + local timeout_s="${1:-45}" deadline n alive + deadline=$(( $(date +%s) + timeout_s )) + while [ "$(date +%s)" -lt "$deadline" ]; do + alive=0 + for n in "${NODES[@]}"; do [ -n "$(node_pid "$n")" ] && alive=$((alive+1)); done + if [ "$alive" -eq "${#NODES[@]}" ] \ + && wait_primary_primitive 5000 >/dev/null 2>&1; then + sleep "${REJOIN_SETTLE_S:-5}" # let the rejoined node finish catch-up + return 0 + fi + sleep 1 + done + return 1 +} + # 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 @@ -300,6 +331,16 @@ assert_no_loss() { return 0 fi + # DURABILITY IS ONLY ASSERTABLE AGAINST A SERVING PRIMARY. If the cluster is + # not serveable, `expect-job not found` cannot tell a genuinely lost job + # from a merely-unreachable primary — reporting "DATA LOSS / bug-661" there is + # a FALSE verdict. Probe first; if the cluster is down, the result is + # INCONCLUSIVE (a liveness problem the caller already flags), NOT data loss. + if ! wait_primary_primitive "${SERVE_PROBE_MS:-20000}" >/dev/null 2>&1; then + inconc "$label: cluster not serving — durability NOT assessed (liveness failure, not data loss)" + return 2 + 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 @@ -316,8 +357,25 @@ assert_no_loss() { if [ "$rc" -eq 0 ]; then pass "$label: all $total committed jobs present after failover" return 0 + fi + + # First check failed — a committed job is missing from a serving primary. To + # avoid mislabeling a momentary post-failover CATCH-UP LAG (a just-elected + # primary still applying replicated entries) as a permanent loss, CONFIRM the + # absence: settle, re-confirm the cluster is healthy, and re-run the check. + # bug-661's invariant is that an acked job stays visible — a job still absent + # after a generous settle is a genuine durability violation; one that + # reappears was transient catch-up, not loss. + yellow " $label: a committed job is missing — confirming (could be catch-up lag) ..." + sleep "${LOSS_CONFIRM_SETTLE_S:-8}" + wait_cluster_healthy 30 || true + xce_test_script "$script" + rc=$? + if [ "$rc" -eq 0 ]; then + pass "$label: all $total committed jobs present after a catch-up settle (transient lag, not loss)" + return 0 else - fail "$label: DATA LOSS — a committed job vanished (bug-661); see expect-job output above" + fail "$label: DATA LOSS — a committed job is PERSISTENTLY absent from a SERVING cluster after a confirm settle (bug-661); see expect-job output above" return 1 fi } @@ -373,6 +431,18 @@ run_soak() { echo "" echo "--- round $round/$ROUNDS ---" + # Only kill into a HEALTHY cluster (all 3 nodes up + serving). Killing the + # current primary while the previous round's restarted node has not yet + # rejoined would drop the live set to ONE node (no quorum) — a + # self-inflicted availability loss the soak must not cause, and must never + # misreport as durability loss. If the cluster never gets healthy, that is + # a real LIVENESS failure (recorded once); skip this round's kill+assert + # rather than cascading false DATA-LOSS lines. + if ! wait_cluster_healthy 60; then + fail "round $round: cluster not healthy (3 nodes up + serving) before kill — LIVENESS failure, not data loss" + continue + fi + submit_n "$JOBS_BEFORE_KILL" # Pick the victim from log role (node lifecycle); fall back to round-robin. @@ -394,10 +464,12 @@ run_soak() { fi fi - # 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 + # Let the surviving two elect a new primary and SERVE again (exit-code + # gate). Post-kill election SLA = ELECT_TIMEOUT_MS (default 60s; a loaded + # sandbox can run slow — this is a LIVENESS bound, not a durability one). + if ! wait_primary_primitive "${ELECT_TIMEOUT_MS:-60000}"; then + fail "round $round: cluster not serveable after killing $victim (>$(( ${ELECT_TIMEOUT_MS:-60000} / 1000 ))s) — LIVENESS failure, not data loss" + # keep going; assert_no_loss self-gates and reports INCONCLUSIVE, not loss else echo " new primary (for next victim): $(current_primary || echo '?')" fi @@ -416,11 +488,15 @@ run_soak() { || yellow " !bash start.sh returned non-zero" fi - # 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" + # Wait until the cluster is fully HEALTHY again (rejoined node back up + + # serving + caught up) before asserting durability — so the verdict + # reflects a real cluster, not a mid-recovery transient. If it never + # returns to health that is a LIVENESS failure (recorded distinctly); + # assert_no_loss then self-detects the non-serving state as INCONCLUSIVE + # rather than crying DATA LOSS. + if ! wait_cluster_healthy 60; then + fail "round $round: cluster did not return to healthy (3 up + serving) after $victim rejoined — LIVENESS failure, not data loss" fi - sleep 4 assert_no_loss "round $round" || true done @@ -647,7 +723,17 @@ fi echo "" echo "=========================" echo "Mode: $MODE" -echo "Results: ${PASS} passed, ${FAIL} failed" +echo "Results: ${PASS} passed, ${FAIL} failed, ${INCONC} inconclusive" echo "Acked jobs total: $(sort -u "$ACKED_FILE" | grep -c .)" +if [ "${INCONC:-0}" -gt 0 ]; then + yellow "NOTE: ${INCONC} durability check(s) were INCONCLUSIVE because the cluster" + yellow " was not serving at the time — a LIVENESS/availability problem, NOT a" + yellow " bug-661 durability loss. 'FAIL' counts genuine faults only: a DATA LOSS" + yellow " is reported solely when a committed job is absent from a SERVING cluster." +fi echo "=========================" +# Exit non-zero on any genuine fault (real DATA LOSS on a serving cluster, or a +# cluster that never returned to health). Inconclusive durability checks do NOT +# by themselves fail the run, but a liveness failure that produced them is itself +# recorded as a FAIL above. [ "$FAIL" -eq 0 ] && exit 0 || exit 1