fix(xce-test-ha): guard start_node against duplicate launches (bug-1418)
Chaotic mode's run_chaotic_rounds restarts "the previously-downed node" every round unconditionally via start_node(\$DOWN), but a round that skips (no primary to kill) never updates \$DOWN -- so a stale node name reaches start_node again while its own earlier restart is still alive, stacking a second xce_controller on the same --myname/port without ever killing the first. Six stacked ctrl-2 processes were observed by the end of a 10-round run. Fixed inside start_node itself with a pgrep guard, rather than reworking run_chaotic_rounds's DOWN bookkeeping, so every call site is covered: refuse to launch a duplicate if "xce_controller --myname \$1" is already running. Verified: re-ran the identical 10-round --chaotic soak that surfaced this. The guard fired on every skip-round; exactly 3 xce_controller processes alive throughout the entire run. Note: the same soak run still hits a genuine, separate election-liveness stall (a surviving node fenced non-promotable by a real apply-correctness divergence, traced to non-identical duplicate WAL submits for the same jobid) -- filed as bug-1419, not fixed here.
This commit is contained in:
parent
d5122752fe
commit
9b173c9a5e
2 changed files with 70 additions and 5 deletions
|
|
@ -214,6 +214,18 @@ trap cleanup EXIT INT TERM
|
|||
xtest() { ASAN_OPTIONS=detect_leaks=0 timeout 60 "$XT" 2>&1; }
|
||||
|
||||
start_node() {
|
||||
# bug-1418: chaotic mode's DOWN bookkeeping restarts "the previously-downed
|
||||
# node" every round unconditionally — but a round that skips (no primary to
|
||||
# kill) never updates DOWN, so a stale node name can reach here again while
|
||||
# its OWN earlier restart is still alive, stacking a second xce_controller
|
||||
# on the same --myname/port without ever killing the first. Guard here
|
||||
# (not by "fixing" DOWN's bookkeeping) so every call site is covered:
|
||||
# refuse to launch a duplicate if one is already running.
|
||||
if [ -n "$(pgrep -f -- "xce_controller --myname $1 ")" ]; then
|
||||
log "start_node: $1 already running — skipping duplicate launch (bug-1418)"
|
||||
return 0
|
||||
fi
|
||||
|
||||
# Capture each controller's stdout+stderr to a per-node file so a SILENT crash
|
||||
# (segfault/abort to stderr — the --logfile only holds tlog INFO/DEBUG, not a
|
||||
# libc/ASAN crash message) leaves a forensic trace. Appended (>>) so a
|
||||
|
|
|
|||
|
|
@ -12596,16 +12596,69 @@
|
|||
"error_message": "[xce-test-ha --chaotic] rounds 6-10 of a 10-round soak all skip (no primary to kill) after round 5 hit a slow-but-eventually-successful election; ctrl-2 restarted repeatedly without the prior instance ever being killed -- 6 stacked ctrl-2 xce_controller processes observed alive simultaneously by end of run",
|
||||
"file": ".claude/skills/xce-test-ha/run-ha-soak.sh",
|
||||
"root_cause": "run_chaotic_rounds's DOWN variable tracks the node killed THIS round so the NEXT round can restart it. On a round where primary_from_log finds no primary (log \"no primary to kill this round -- skipping\"), the loop continues without ever updating DOWN or killing anything -- but the NEXT round's \"if [ -n \"\" ]\" restart-previously-downed step still fires unconditionally on the stale DOWN value from several rounds back, calling start_node on a node that was never actually killed (or was already restarted in a prior skipped round), stacking a new xce_controller process on top of an already-running one every single skipped round. Discovered incidentally while verifying bug-1417's fix (10-round chaotic soak, unrelated to the vote-index fix itself -- confirmed via git diff that run-ha-soak.sh was untouched this session).",
|
||||
"fix": "NOT FIXED (out of scope for the bug-1417 investigation that surfaced it). Candidate fix: only treat a node as DOWN (eligible for the next round's restart) if this round genuinely killed it; on a skip-round, DOWN should stay whatever it was (already handled -- the bug is that the skip round should also skip minus the restart-if-still-actually-down check), or more robust: before start_node(\"\"), pgrep for an existing xce_controller --myname and skip the restart if one is already running.",
|
||||
"fix": "FIXED (.claude/skills/xce-test-ha/run-ha-soak.sh start_node): added a pgrep guard at the top of start_node -- refuses to launch a duplicate \"xce_controller --myname $1\" if one is already running, logging \"start_node: $1 already running -- skipping duplicate launch (bug-1418)\" and returning 0. Fixed at the single shared call site (start_node itself) rather than trying to correct run_chaotic_rounds's DOWN bookkeeping, so every caller is covered. Verified: re-ran the identical 10-round --chaotic soak that originally surfaced this -- guard fired on every skip-round (7,8,9,10,final-settle), exactly 3 xce_controller processes alive throughout the entire run (confirmed via ps), zero stacking.",
|
||||
"tags": [
|
||||
"xce-test-ha",
|
||||
"chaotic-mode",
|
||||
"harness-bug",
|
||||
"fixed",
|
||||
"restart-bookkeeping",
|
||||
"process-leak"
|
||||
"process-leak",
|
||||
"harness-bug",
|
||||
"xce-test-ha"
|
||||
],
|
||||
"related_bugs": [],
|
||||
"occurrences": 2,
|
||||
"last_seen": "2026-07-07T14:00:00.000Z"
|
||||
},
|
||||
{
|
||||
"id": "bug-1418",
|
||||
"timestamp": "2026-07-07T18:20:00.000Z",
|
||||
"error_message": "[xce-test-ha --chaotic] Round 5 stall: ctrl-1 PreVote stuck at term 9 while ha->raft.term=22+ \u2014 term desync prevents failover progression. ctrl-3 wins Raft election but promotion REFUSED (apply_divergent=1, durable_floor=26 > cluster_hwm=21).",
|
||||
"file": "src/lib/raft/raft.c + src/controller/ha.c",
|
||||
"root_cause": "TWO contributing factors: (1) TERM DESYNC (new bug): raft_on_vote_request step 2 updates s->term (Raft lib) but only fires on_become_follower when was_leader=true. When a standby receives a higher-term RequestVote, s->term advances but ha->term stays stale. ha_start_prevote_async reads ha->term (not ha->raft.term) for its prospective term \u2192 PreVote at stale term 9 \u2192 rejected by peer at term 22+ as stale_term. (2) APPLY DIVERGENCE (feature working as designed): ctrl-3 applied entries 22-26 from ctrl-2 replication before ctrl-2 was killed in chaotic mode. These were never committed by majority \u2192 promotion gate refuses CTRL_PRIMARY with apply_divergent=1. ctrl-3 wins Raft election but never becomes primary, then gets preempted by higher-term RequestVote \u2192 cycle repeats. Combined effect: ctrl-1 can never win PreVote (stale term), ctrl-3 can never become primary (apply-divergence), ctrl-2 is dead \u2192 NO node can become primary \u2192 eternal stall.",
|
||||
"fix": "Part 1 (term desync): ha_start_prevote_async should sync ha->term from ha->raft.term before computing prospective_term. Or raft_on_vote_request should always fire on_become_follower (not just when was_leader) when adopting a higher term. Part 2 (apply-divergence stall): raft-apply-decoupling should handle the case where the only available leader candidate has apply_divergent=1 \u2014 either truncate uncommitted applied entries back to committed prefix, or promote anyway with reconciliation.",
|
||||
"tags": [
|
||||
"ha",
|
||||
"election",
|
||||
"raft",
|
||||
"term-desync",
|
||||
"pre-vote",
|
||||
"apply-divergence",
|
||||
"promotion-gate",
|
||||
"chaotic-failover",
|
||||
"liveness"
|
||||
],
|
||||
"related_bugs": [
|
||||
"bug-1417",
|
||||
"bug-1060"
|
||||
],
|
||||
"occurrences": 1,
|
||||
"last_seen": "2026-07-07T10:20:00.000Z"
|
||||
"last_seen": "2026-07-07T18:20:00.000Z"
|
||||
},
|
||||
{
|
||||
"id": "bug-1419",
|
||||
"timestamp": "2026-07-07T14:00:00.000Z",
|
||||
"error_message": "[xce-test-ha --chaotic] genuine, reproducible election-liveness stall (not the bug-1418 harness process-stacking artifact, which was a separate, now-fixed issue): after 2+ overlapping kills, the surviving 2-node set can permanently deadlock -- neither node can ever become primary again for the rest of the run.",
|
||||
"file": "src/controller/persist.c (apply-correctness verification) + src/controller/ha.c (PreVote freshness gate) + WAL duplicate-submit mechanism (unlocated)",
|
||||
"root_cause": "Direct log/WAL analysis (waldump on the affected node's data dir) during a live repro superseded two prior, less-precise theories filed as bug-1418 (a shell-script process-stacking artifact, unrelated and separately fixed; and an unverified ha->term/ha->raft.term \"term desync\" claim that does not match the code -- raft_begin_pre_vote/ha_start_prevote_async both read s->term == ha->raft.term directly, there is no separate stale-field read on the PreVote path).\n\nACTUAL mechanism observed: waldump on ctrl-3's WAL (the node with the longest/freshest log after the chaotic kill sequence) showed \"duplicate submits: 3 (byte-identical: 0)\" -- the SAME jobid appended to the WAL twice with DIFFERING payloads (different subtime, different CRC), e.g. lsn=13 and lsn=14 both jobid=0-0-1783418222-0 but distinct subtime/PCRC. This is NOT bug-845's mechanism (that fix, landed 2026-06-23, was for byte-IDENTICAL double-hook-registration dupes and is confirmed still working -- these are non-identical). count_jobmgr_entries() legitimately sees these as 2 distinct job-table mutations (or the entity count otherwise fails to match the WAL-replay-derived expectation), so persist_recover()'s post-replay apply-correctness check (task 5.1, Req 8.1/8.2) correctly fires APPLY_DIVERGENT -> the loud, sticky, non-promotable fence (raft-apply-decoupling Req 8.3/8.4) -- this fencing behavior is WORKING AS DESIGNED, not itself a bug.\n\nThe resulting LIVENESS bug: with the fenced node holding the only sufficiently-fresh (longest) log, the other surviving node can never win the PreVote freshness gate against it (correctly, per Raft/PreVote semantics -- it really is behind), while the fenced node itself can win Raft elections (quorum_reached/became_leader observed at terms 27/30/32 in logs) but its own raft_cb_become_leader promotion gate refuses CTRL_PRIMARY every time (apply_divergent=1). With the third node dead (killed by the chaotic driver) and never restarted long enough to catch up, NO node can ever become primary again -- a genuine, reproducible liveness deadlock, distinct from (and downstream of) the WAL duplicate-submit root cause. Confirmed via direct log grep across ctrl-1.log/ctrl-3.log at the exact stall timestamps (09:57:16 divergence detected, repeating \"PreVote DENIED ... reason=freshness\" and \"promotion REFUSED ... apply_divergent=1\" through 10:05+); NOT root-caused via speculation.",
|
||||
"fix": "NOT FIXED. Two separate, layered problems, neither resolved here: (1) the WAL duplicate-non-identical-submit mechanism itself is unlocated -- needs its own investigation (likely a distinct submit-path race from bug-845's already-fixed double-hook-registration, since these pairs are NOT byte-identical; check for a retry/resubmit path that re-stamps subtime on the same client-generated jobid, or a race in the commit-continuation/apply-pump interaction from raft-apply-decoupling that could double-materialize a submit under a specific kill-timing window). (2) Even with (1) fixed, the raft-apply-decoupling promotion-refusal design has a known, currently-unaddressed liveness gap when the ONLY sufficiently-fresh candidate is apply-divergent and the other members cannot catch up (no reconciliation/truncation-then-promote recovery path exists today) -- this needs its own design discussion, not a quick patch, since forcing promotion of a divergent node or truncating its uncommitted-but-locally-applied entries both have real correctness implications.",
|
||||
"tags": [
|
||||
"ha",
|
||||
"election",
|
||||
"raft",
|
||||
"apply-divergence",
|
||||
"promotion-gate",
|
||||
"chaotic-failover",
|
||||
"liveness",
|
||||
"wal-duplicate-submit",
|
||||
"unresolved"
|
||||
],
|
||||
"related_bugs": [
|
||||
"bug-1417",
|
||||
"bug-1060",
|
||||
"bug-845",
|
||||
"bug-1418"
|
||||
],
|
||||
"occurrences": 1,
|
||||
"last_seen": "2026-07-07T14:00:00.000Z"
|
||||
}
|
||||
]
|
||||
Loading…
Add table
Add a link
Reference in a new issue