diff --git a/.claude/skills/xce-test-ha/run-ha-soak.sh b/.claude/skills/xce-test-ha/run-ha-soak.sh index a679bc18..d4b0ae46 100755 --- a/.claude/skills/xce-test-ha/run-ha-soak.sh +++ b/.claude/skills/xce-test-ha/run-ha-soak.sh @@ -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 diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 8c758cf9..e619b82d 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -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" } ] \ No newline at end of file