From 71223ec712ef94c1207ef36faa1a9b754c5d6847 Mon Sep 17 00:00:00 2001 From: Rongsong Shen Date: Tue, 28 Jul 2026 08:47:55 +0000 Subject: [PATCH] docs(config-upgrade-snapshot): re-block task 8.6 on bug-1477 (HA bootstrap retry gap) bug-1472 (the prior blocker, worker-control replication) is fixed and verified (7547a8f1). Rebuilding and re-running --config-upgrade on top of that fix surfaced a new, unrelated defect: a node that takes the skip_election fast path in myapp_run can permanently lose commit_engine_init if its one cluster_init_phase2() attempt races config availability, since none of ha.c's four retry call sites re-attempt for a node that never contests an election. That member then never fires the marker-triggered checkpoint (task 5), leaving it permanently unable to catch up past that LSN (WAL_CHECKPOINT is local-only, non-replicated by design) -- a distinct, permanent wedge from bug-1475's already-fixed transient race. Root-caused via a dedicated debug pass (log/grep/git-blame evidence, logged as bug-1477). Out of config-upgrade-snapshot's boundary -- same pattern as bug-1471/1472/1474 -- so task 8.6 stays blocked until bug-1477 is fixed upstream in HA bootstrap/election. --- .kiro/specs/config-upgrade-snapshot/tasks.md | 2 +- .wolf/buglog.json | 35 ++++++++++++++++++++ .wolf/cerebrum.md | 1 + 3 files changed, 37 insertions(+), 1 deletion(-) diff --git a/.kiro/specs/config-upgrade-snapshot/tasks.md b/.kiro/specs/config-upgrade-snapshot/tasks.md index 2818294d..2ecba1fe 100644 --- a/.kiro/specs/config-upgrade-snapshot/tasks.md +++ b/.kiro/specs/config-upgrade-snapshot/tasks.md @@ -127,7 +127,7 @@ - Observable: the chaotic-upgrade soak run reports zero materialized-state divergence, zero configuration divergence, and correct host admin-status across all members - _Requirements: 4.1, 4.3, 6.1, 6.4_ - _Depends: 7, 8.1, 8.2, 8.3, 8.4_ - - _Blocked: bug-1472 — pre-existing, out-of-spec-boundary HA worker-control replication defect (`worker_from_capnp`, `worker.c:827-856`, introduced 2026-05-08, commit `9b6a91a8`, ~2.5 months before this spec). `WAL_WORKER_CTRL` apply treats "-EEXIST" (target worker already exists) as a benign no-op for ALL hook details — correct for JOIN replay, but wrong for UPDATE/DEAD, where the target already existing is the normal case. Consequence: a host admin-status change (`hostctrl -c`/`-o`) never propagates past the member that directly processed the RPC — completely general, unrelated to config upgrades or checkpoints. Live soak infra + task 8.6's own bug-1468/bug-1469 fixes are committed (959b0cd) and independently reviewed; only the Requirement 6.4 host-admin-status-survival assertion is blocked, on a bug this spec does not own. See `.wolf/buglog.json` bug-1471 (byte-precise diagnosis) and bug-1472 (root cause) for full forensic detail. Unblocks when bug-1472 is fixed by whoever owns worker/HA replication — no further config-upgrade-snapshot work needed once that lands (re-run `run-ha-soak.sh --config-upgrade` to confirm clean PASS)._ + - _Blocked: bug-1477 — pre-existing, out-of-spec-boundary HA bootstrap/election defect (`myapp.c`'s `skip_election` fast path, ~343-425, plus `ha.c`'s unconditional `phase2_done=1` latch across all 4 retry call sites — `raft_cb_become_follower` 2000-2012, `raft_cb_become_leader` 1772-1783, `ha_elect_evaluate_and_signal` 5609-5629/5699-5710; introduced commits `20e59d0b`/`8f0d2d55`, ~1 month before this spec). bug-1472 (the PRIOR blocker on this task, worker-control replication) is now fixed and verified (commit `7547a8f1`); rebuilding and re-running `--config-upgrade` on top of that fix surfaced a NEW, unrelated defect: a node that finds "leader already known" at boot (`skip_election`) makes exactly one `cluster_init_phase2()` attempt, which can lose the race against config becoming available and return `-EINVAL` — and since none of the 4 retry call sites ever fire for a node that never itself contests an election, that node's `commit_engine_init` (and therefore `apply_committed_entry`/`persist_checkpoint_marker_triggered`, config-upgrade-snapshot's own task-5 mechanism) never runs, for the rest of that process's life. The member's config still "activates" cosmetically via the independent `handle_repl_config_push` RPC path, masking the defect until a checkpoint-identity check catches it: that member permanently lacks the marker-triggered checkpoint every other member takes at the same LSN, and since `WAL_CHECKPOINT` is local-only/non-replicated by design, it can never reconstruct one — a permanent `ae_reject_logmismatch` catch-up wedge, distinct from bug-1475's (already-fixed) transient race. Completely general, unrelated to config upgrades specifically — any HA bootstrap timing that lands a node on `skip_election` before its config is available is exposed the same way. See `.wolf/buglog.json` bug-1477 for full forensic detail (log/grep/git-blame evidence, no unit-level repro built — the multi-node startup-stagger timing isn't cleanly unit-testable in isolation). Unblocks when bug-1477 is fixed by whoever owns HA bootstrap/election (add a retry path for a `skip_election` node whose first `cluster_init_phase2` attempt fails, and gate the `phase2_done=1` latch on that call's return value) — no further config-upgrade-snapshot work needed once that lands (re-run `run-ha-soak.sh --config-upgrade` to confirm clean PASS)._ - [x] 8.7 Inject a crash and a leadership change at the two critical upgrade windows - Force a controller crash/restart between a configuration-change marker's commit and that member's own snapshot write becoming durable, and assert materialization resumes correctly from the marker on restart diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 212eb002..3379eabc 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -14156,5 +14156,40 @@ ], "occurrences": 2, "last_seen": "2026-07-28T08:06:00Z" + }, + { + "id": "bug-1477", + "timestamp": "2026-07-28T08:25:00Z", + "error_message": "Live config-upgrade-snapshot task 8.6 soak (run-ha-soak.sh --config-upgrade ~/tmp/xce-ha-configupgrade), run on top of bug-1475's already-fixed and already-built-in commit ce8df990 (confirmed via binary mtime 08:16:27 postdating ce8df990 04:48:53Z and b08e392e 08:13:54Z, plus `strings` matching TERM_INDEX_UNSET/persist_durable_floor), FAILED: \"ctrl-3 has no on-disk checkpoint after the upgrade\". ctrl-1/ctrl-2 both have data/snap/snap-000000000000000b.capnp (51161 bytes, LSN 11 hex = the WAL_CONFIG_MARKER's own lsn); ctrl-3's data/snap/ is completely empty. ctrl-3's log shows a PERMANENT loop (repeats every ~3s/heartbeat for the entire ~3-minute run, never progressing): a bare heartbeat probe at prevIdx=11 succeeds (ae_already_have, match=11), but every walCatchupEntry at prevIdx=12/13/14 is rejected forever with ae_reject_logmismatch. Unlike bug-1475's own signature, this is NOT a transient race that self-heals once durable_lsn catches up -- it never recovers for the rest of the run.", + "file": "src/controller/myapp.c (~line 388-425, the \"leader already known -- skip own election\" fast path and its single guarded cluster_init_phase2 retry, bug-849 lineage); src/controller/ha.c (raft_cb_become_follower ~line 2000-2012, raft_cb_become_leader ~line 1772-1783, ha_elect_evaluate_and_signal ~line 5609-5629/5699-5710 -- all three unconditionally set ha->phase2_done=1 after calling cluster_init_phase2(c) without checking its return value); src/controller/cluster.c (cluster_init_phase2 ~line 1342-1598, the sole call site of commit_engine_init/persist_recover/ha_sync_raft_log_from_recovery); src/controller/persist.c (~line 796-799, on_durable_advance documented as registered ONLY by commit_engine_init)", + "root_cause": "ROOT-CAUSED with byte/log-precise evidence, NOT config-upgrade-snapshot's own defect. ctrl-3 (my_priority=2, the highest-priority-number/most-deferred candidate in the 3-node cluster, per myapp_run's startup-stagger nanosleep) never ran its own raft candidacy for the ENTIRE test: zero occurrences of raft_cb_become_follower/raft_cb_become_leader/\"-> CTRL_STANDBY\" anywhere in ctrl-3.log. Instead, by the time its stagger delay elapsed, ctrl-1 (priority 0) had already voted/established itself, so myapp_run's own \"leader already known\" check (myapp.c ~343-390: voted_for_name set, or raft.term>0, or primary_ctrl_fd>=0) was true, and ctrl-3 took the `goto skip_election` fast path, entirely bypassing ha_start_election_async and therefore every raft-library election callback for the rest of its process lifetime (it only ever GRANTS votes to others afterward -- confirmed via repeated vote_granted/pre_vote_granted RAFT[p2] events with no corresponding become_follower/become_leader). The skip_election fast path (myapp.c ~415-425, bug-849, commit 20e59d0b, 2026-06-21 -- three-plus weeks before config-upgrade-snapshot's first commit 9e68335a) makes exactly ONE, correctly-guarded attempt at cluster_init_phase2(&c) (checks prc, only sets c.ha.phase2_done=1 on success) -- and at 08:18:26,930, that ONE attempt fired before c->myconf->cluster_config was populated (ctrl-3 had no local config file and had not yet received/activated a push), so cluster_init_phase2 returned -EINVAL immediately (cluster.c:1349-1358, before doing ANY of its real work) and the WARN 'cluster_init_phase2 on standby rejoin failed (rc=-22) -- WAL not recovered; falling back to election-path recovery' fired. phase2_done correctly stayed 0 -- but there is NO OTHER retry mechanism anywhere in the codebase for a node that (a) took the skip_election fast path and (b) never subsequently runs its own contested election: the only other three call sites that could retry (raft_cb_become_follower ha.c:2000-2012, raft_cb_become_leader ha.c:1772-1783, ha_elect_evaluate_and_signal's CTRL_PRIMARY/CTRL_STANDBY branches ha.c:5609-5629/5699-5710) never fire for ctrl-3 because it never engages the raft callback machinery at all. (Separately confirmed those three call sites ALSO unconditionally set ha->phase2_done=1 after calling cluster_init_phase2(c) with NO check of its return value -- unlike myapp.c's own careful guard -- a second, adjacent defect of the same class that did not trigger THIS failure only because ctrl-3 never reached them, but would identically strand any node whose FIRST raft-driven role transition happens to race ahead of config load.) Consequence, confirmed via grep: ctrl-3.log has ZERO occurrences of \"commit engine wired\", \"persist_recover\", \"xce_config_init\", or \"create_lost_and_found\" for the entire run (vs. multiple occurrences on ctrl-1/ctrl-2, once per boot/restart/re-election) -- cluster_init_phase2 (and therefore commit_engine_init, cluster.c:1484-1496) NEVER completed on ctrl-3. persist.c:796-799 documents on_durable_advance (the sole wake hook driving persist_apply_pump_run) as registered ONLY inside commit_engine_init -- so without it, persist_apply_pump_run/apply_committed_entry NEVER runs on ctrl-3, for ANY committed LSN, for the whole process lifetime. This means persist_checkpoint_marker_triggered (config-upgrade-snapshot task 5's own WAL_CONFIG_MARKER-triggered checkpoint, apply_committed_entry's WAL_CONFIG_MARKER case) never fires on ctrl-3 -- explaining precisely why its data/snap/ is empty while ctrl-1/ctrl-2 (whose commit engines DID wire) both hold the identical snap-000000000000000b.capnp. ctrl-3's config nonetheless activates cosmetically at 08:18:48,572 via a SEPARATE, independent code path (handle_repl_config_push -> load_primary_config -> config_activate_committed, an RPC push handler that does not touch the commit engine or apply pump at all) -- masking the underlying defect and making the soak's materialized-state/checkpoint assertions the first thing ever to surface it. bug-1475's three-part fix (config_repl.c's tracker-advance-across-WAL_CHECKPOINT, ha.c's JIT persist_durable_floor resync of ha->raft.log_len, persist.c's TERM_INDEX_UNSET sentinel) is necessary and correctly targets its own class of bug (a receiving standby's log_len bookkeeping merely LAGGING behind a checkpoint it DID independently write) but structurally cannot cover this failure: bug-1475's own fix explicitly documents and depends on the invariant 'a standby that independently applied the SAME committed WAL_CONFIG_MARKER writes its OWN local checkpoint at the identical LSN (deterministic per-member trigger)' -- ctrl-3 violates that precondition outright (it never writes the checkpoint AT ALL, not merely late), so the primary's catch-up stream's prev_log_index=12 (the checkpoint's own lsn, per bug-1475's now-correct sender tracking) checks against an entry ctrl-3 genuinely, permanently does not have. ae_reject_logmismatch is therefore a CORRECT rejection of ctrl-3's true log state, not a stale/racy one -- and since a WAL_CHECKPOINT entry is local-only/non-replicated BY DESIGN (persist_write_checkpoint_marker's own doc comment; persist_wal_write_replicated/persist_wal_async both explicitly reject type==WAL_CHECKPOINT), ctrl-3 can NEVER receive lsn=12 over the wire, and can never independently write it either (cluster_init_phase2/commit_engine_init never retries) -- a genuinely permanent, not merely time-bounded, wedge, exactly matching the soak's observed behavior (unlike bug-1475's transient race, this repeated with zero progress for the entire ~3-minute run). git blame confirms both implicated pre-existing defects (myapp.c's skip_election fast path, commit 20e59d0b bug-849 2026-06-21; ha.c's raft-callback phase2_done latch structure, commit 8f0d2d55 task 6.2 raft-library) predate config-upgrade-snapshot's first commit (9e68335a) by roughly a month -- this is a pre-existing HA bootstrap/election gap, NOT something config-upgrade-snapshot's task 5 introduced. Task 5 merely exposed it by creating a new cross-member structural dependency (every member independently checkpointing at a synchronized marker-boundary LSN) that a node whose commit engine/apply pump never wired silently violates. Before config-upgrade-snapshot, the same underlying gap would have left such a node's materialized state (jobmgr/qmgr/workermgr) permanently stale/un-applied with a much less visible failure signature (no crash, no wedge -- just silently wrong query results if that node were ever promoted), plausibly unnoticed by prior soaks that do not assert per-member materialized-state identity.", + "fix": "NOT FIXED -- root-caused only, per explicit instruction (forensic investigation, not a fix task; this defect is squarely OUT OF SCOPE for config-upgrade-snapshot, parallel to bug-1471/1472/1474's routing). Two coordinated repo-fixable gaps, both in pre-existing HA bootstrap/election machinery (ha-config-bootstrap / election-iomgr-refactor / raft-library spec lineage), NOT config-upgrade-snapshot: (1) myapp.c's skip_election fast path (~line 415-425) needs a retry hook for a node that took it and never subsequently runs its own raft candidacy -- e.g. re-attempt cluster_init_phase2 once config_activate_committed/handle_repl_config_push first populates c->myconf->cluster_config on such a node, or arm a bounded retry timer instead of a single one-shot attempt. (2) ha.c's three raft-driven call sites (raft_cb_become_follower ~2000-2012, raft_cb_become_leader ~1772-1783, ha_elect_evaluate_and_signal's two branches ~5609-5629/5699-5710) should check cluster_init_phase2's return value the same way myapp.c's own guarded call already does, only latching ha->phase2_done=1 on success -- so a node whose first raft-driven role-transition callback races ahead of config load gets a genuine later retry instead of being permanently stranded. Recommend filing/handing this to whichever spec owns HA bootstrap/election continuity (ha-config-bootstrap or a new small fix spec), NOT implementing inside config-upgrade-snapshot. config-upgrade-snapshot task 8.6 should be BLOCKED on this new bug (same pattern as bug-1471/1472/1474 before it), not reattempted until fixed upstream.", + "tags": [ + "ha.c", + "myapp.c", + "cluster.c", + "cluster_init_phase2", + "phase2_done", + "commit_engine_init", + "apply_pump_never_wired", + "skip_election", + "bug-849-lineage", + "ae_reject_logmismatch", + "permanent-catchup-wedge", + "config-upgrade-snapshot-task-8.6", + "marker-triggered-checkpoint", + "not-bug-1475", + "bug-1475-fix-verified-good", + "out-of-scope-upstream", + "needs-owner", + "not-fixed" + ], + "related_bugs": [ + "bug-1475", + "bug-1466", + "bug-849" + ], + "occurrences": 1, + "last_seen": "2026-07-28T08:25:00Z" } ] diff --git a/.wolf/cerebrum.md b/.wolf/cerebrum.md index cec89513..c4a6193a 100644 --- a/.wolf/cerebrum.md +++ b/.wolf/cerebrum.md @@ -108,6 +108,7 @@ - (2026-07-10) A chaotic-HA-soak "COMMITTED JOB LOSS" verdict with `committed_divergence=0` and all jobs present at final settlement is a VISIBILITY-LATENCY gap, not a durability violation: the job was legitimately committed by the old primary before it died, but the new leader's post-election `safe_committed_lsn` (computed only from THIS election's granted-voter sample, which can be conservative when a second voter is mid-restart) is lower until fresh quorum reconfirmation — correct Raft Figure-8 safety, not a bug by itself. Per this project's test philosophy (skill xce-test-ha: "a committed job an elected primary cannot list IS a real loss regardless of eventual reappearance") this is still a hard soak FAIL and must be fixed — but ONLY by shrinking the reconfirmation window (e.g. sending the first post-promotion heartbeat immediately), never by unsafely exposing unconfirmed old-term entries early just to make the check pass. - (2026-07-10, bug-1433, controller-invariant-audit) `peer_ctrl_classify` (ha.c ~5935) hardcodes `VTASK_LIVENESS` for EVERY inbound peer-control packet (vote replies, PreVote replies, WAL/config ACKs) — a task class documented as "never admission-gated," i.e. never expected to block. `raft_cb_become_leader` (the raft library's `.on_become_leader` callback) is invoked synchronously from THIS dispatch path whenever a real multi-node winning vote reply arrives — NOT from the separate `VTASK_LIVE_BLOCK`-dispatched election-*start* path (`ha_dispatch_election_start`, which only covers RDHUP-failover/single-node self-grant). Any blocking call added inside `raft_cb_become_leader` (or anything it calls) is reachable on a worker class the design guarantees never blocks — same bug class as bug-1198 (closed by moving `persist_checkpoint`'s snapshot-send fdatasync off VTASK_LIVENESS entirely). Before adding ANY blocking call to the promotion path, trace peer_ctrl_classify's actual dispatch, don't trust an existing nearby comment claiming "already on VTASK_LIVE_BLOCK" — one was WRONG (see bug-1433 in buglog.json for the full trace). `persist_apply_pump_run_sync` still has this residual (bounded `pread`, lower risk than `fdatasync`, not fixed this session — see buglog.json bug-1433 for why it can't simply be removed). - (2026-07-10, bug-1434, controller-invariant-audit) `persist_promotion_advance_committed` and `ha_standby_advance_committed_and_apply` both did an unlocked `load; if(target<=cur) return; store` on `p->committed_lsn` — safe ONLY if truly single-writer, but `raft_cb_become_leader` calls the former BEFORE setting `role = CTRL_PRIMARY` (~170 lines later), so a still-in-flight WAL catch-up entry on another thread can call the latter concurrently during that window — classic lost-update race that can regress `committed_lsn` (monotonicity violation). General lesson: when two independent call sites do "monotonic-max store to a shared atomic, no lock" and you can't prove they're strictly serialized by role/state gating (gating checked AT CALL TIME can still race with a WINDOW where the gate value itself is about to change), use a CAS retry loop (`persist_committed_lsn_advance_atomic`), not a bare load-then-store — it's safe under ANY interleaving with zero lock-ordering risk. +- (2026-07-28, bug-1477) `cluster_init_phase2()` (cluster.c) is the SOLE place that runs `commit_engine_init()` -- which is itself the ONLY place that registers `persist_t`'s `on_durable_advance` wake hook (persist.c:796-799 says so explicitly: "starts unregistered ... the commit engine registers it"). Without that hook, `persist_apply_pump_run`/`apply_committed_entry` NEVER runs on that node, for ANY committed LSN, for its whole process lifetime -- a node can still fully participate in WAL replication/ACK (that path is independent, in ha.c) while never materializing ANY committed state. `cluster_init_phase2` short-circuits with `-EINVAL` (cluster.c:1349-1358) whenever `c->myconf->cluster_config == NULL` (config not loaded yet) -- normal during cold boot -- and its THREE raft-driven callers (`raft_cb_become_follower` ha.c:2000-2012, `raft_cb_become_leader` ha.c:1772-1783, `ha_elect_evaluate_and_signal`'s two branches ha.c:5609-5629/5699-5710) all set `ha->phase2_done=1` UNCONDITIONALLY after calling it, with NO check of its return value -- unlike `myapp.c`'s own `skip_election` fast-path caller (~line 415-425, bug-849 lineage) which correctly gates the latch on success. Worse: a low-priority node (highest `my_priority`, longest startup stagger) that finds "leader already known" on its very first check takes `goto skip_election` and NEVER runs `ha_start_election_async` at all -- so it never reaches ANY of the three raft-callback retry opportunities, ever, for its whole life, if it never later contests its own election. If its one-shot `myapp.c` attempt races ahead of config load, `cluster_init_phase2`/`commit_engine_init` never runs again, PERIOD -- a real, permanent HA-bootstrap gap, predates config-upgrade-snapshot by ~1 month (myapp.c skip_election = commit 20e59d0b 2026-06-21; ha.c raft-callback structure = commit 8f0d2d55 task 6.2), NOT introduced by it. It stayed invisible until config-upgrade-snapshot's task 5 (`persist_checkpoint_marker_triggered`) created a NEW cross-member invariant (every member independently writes a local checkpoint at a synchronized marker-boundary LSN) that a node with a never-wired apply pump silently violates -- surfacing as a PERMANENT (not transient/racy) `ae_reject_logmismatch` catch-up wedge that superficially resembles bug-1475 but is a categorically different, unrecoverable failure (the missing entry is genuinely, permanently absent -- not merely stale bookkeeping) since a WAL_CHECKPOINT entry is local-only/non-replicated by design and can never arrive over the wire to fill the gap. Diagnostic tell: grep the suspect node's log for "commit engine wired" -- if it NEVER appears (vs. multiple times on healthy peers, once per boot/restart/election), the commit engine/apply pump never wired on that node at all. ## Do-Not-Repeat