diff --git a/.kiro/specs/job-array-single-wal-record/spec.json b/.kiro/specs/job-array-single-wal-record/spec.json index 2c201194..26308404 100644 --- a/.kiro/specs/job-array-single-wal-record/spec.json +++ b/.kiro/specs/job-array-single-wal-record/spec.json @@ -1,7 +1,7 @@ { "feature_name": "job-array-single-wal-record", "created_at": "2026-07-09T17:20:00Z", - "updated_at": "2026-07-17T09:47:00Z", + "updated_at": "2026-07-17T10:45:00Z", "language": "en", "phase": "implementation-complete", "approvals": { @@ -23,8 +23,9 @@ "validate_impl": { "decision": "GO", "validated_at": "2026-07-17T09:47:00Z", - "known_limitations": [ - "bug-1445: first-boot promotion-ordering gap -- a node's very first promotion evaluation in a fresh process runs before that node's own first persist_recover()/replay_wal() call, so the Live Apply Resource Fence is invisible to that one specific check. Every promotion evaluation after a process's first one is protected. Out of this spec's persist.c-only boundary; tracked in .wolf/buglog.json, not fixed in this spec." + "known_limitations": [], + "resolved_limitations": [ + "bug-1445 (first-boot promotion-ordering gap) fixed 2026-07-17 in src/controller/ha.c (raft_cb_become_leader), outside this spec's own task list -- see .wolf/buglog.json for full detail. TDD-verified (RED/GREEN) with a dedicated test plus a full controller_unit_test regression pass." ], "prior_decision": { "decision": "GO", diff --git a/.wolf/buglog.json b/.wolf/buglog.json index 3340f0f8..ef26c368 100644 --- a/.wolf/buglog.json +++ b/.wolf/buglog.json @@ -13314,7 +13314,7 @@ "error_message": "A node's very first promotion-eligibility evaluation in a fresh process runs before that node's own first persist_recover()/replay_wal() call, so the Live Apply Resource Fence (job-array-single-wal-record tasks 4.1-4.3, extended to boot replay by task 7.2) is invisible to that one specific check. A node that would otherwise correctly fence itself non-promotable on a resource-exhaustion apply failure during its first-ever boot replay can instead pass its first promotion check looking fully eligible, because the fence flag hasn't been set yet at the point that first gate runs.", "file": "src/controller/ha.c", "root_cause": "ha.c's promotion-gate eligibility check (ha.c:1303-1408) runs before persist_recover()'s first-ever replay_wal() call (ha.c:1427-1439) on a freshly-started process. Every promotion evaluation AFTER a process's first one is correctly protected (persist_apply_resource_fenced() is threaded into both the periodic fence-release check and the election-time check per task 4.3) -- this is a narrow ordering gap specific to the single very-first evaluation of a brand-new process, discovered and documented (not fixed) during job-array-single-wal-record task 7.2's own review, out of that task's persist.c-only file boundary.", - "fix": "NOT FIXED. Root cause and reproduction path already established in tasks.md (job-array-single-wal-record task 7.2 Implementation Notes) and this buglog is the first standalone tracking entry for it -- previously only documented inline in that spec's notes. Suggested shape (per /kiro-validate-impl discussion 2026-07-17): either move the promotion-gate's first evaluation to run after the first replay_wal() completes, or make that one gate call explicitly treat 'has not replayed yet' as non-promotable until the first replay_wal() sets or clears the fence for real. Small, single-call-site ordering fix in ha.c; suggested as a quick TDD fix (not a full Kiro spec) given the narrow scope, but still needs a real fresh-process-boot test plus a live soak given ha.c's HA-critical status.", + "fix": "FIXED and VERIFIED (2026-07-17, src/controller/ha.c). raft_cb_become_leader()'s is_first_boot block now re-checks persist_apply_resource_fenced(&c->persist) immediately after cluster_init_phase2() completes (the call that triggers this process's own first persist_recover()/replay_wal()) -- if that first replay just engaged the fence, promotion is refused (same pattern as the pre-existing refusal branch: WARN log + ha_arm_promotion_fence_timer() + return), instead of falling through to CTRL_PRIMARY on a decision made before that first replay ever ran. Every later election is unaffected -- is_first_boot is false by then, so the earlier eligibility gate (ha.c:1337) already covers it correctly. Scope check: confirmed ha_elect_evaluate_and_signal (the OTHER election path, ha.c ~5030) is dead in production for the promotion outcome -- every live call site of handle_request_vote_reply passes vote_granted=0 (bug-828 already redirected the real grant-recording path to the record-only ha_record_vote_reply, which never signals it) -- so raft_cb_become_leader is confirmed the sole live promotion path and this fix's scope is complete, not partial. TDD: new test test_first_boot_promotion_evaluates_own_first_replay_fence (src/controller/testsuite/test_job_array_replay_fence.c) wires ha_phase2_hook to a stub that calls persist_recover() for real, reproducing production ordering exactly (a never-recovered persist_t entering the election path with ha->phase2_done==0) -- RED-confirmed failing pre-fix at the exact predicted assertion (role_after_election==CTRL_PRIMARY), GREEN-confirmed passing post-fix. Full controller_unit_test binary (bundles every testsuite/test_*.c including test_convergence_verification.c, test_ha_cluster.c, test_p1_integration.c) green: 16/16 tests in this file, 0 regressions cluster-wide.", "tags": [ "job-array-single-wal-record", "ha.c", @@ -13325,12 +13325,12 @@ "persist_recover", "replay_wal", "ordering-bug", - "not-fixed" + "fixed" ], "related_bugs": [ "bug-1443" ], "occurrences": 1, - "last_seen": "2026-07-17T09:47:00Z" + "last_seen": "2026-07-17T10:45:00Z" } ] diff --git a/src/controller/ha.c b/src/controller/ha.c index 4157906d..e56d8fb0 100644 --- a/src/controller/ha.c +++ b/src/controller/ha.c @@ -1436,6 +1436,41 @@ static void raft_cb_become_leader(void *ctx, uint64_t term) cluster_init_phase2(c); #endif ha->phase2_done = 1; + + /* bug-1445 fix: cluster_init_phase2() above just ran this process's + * very FIRST persist_recover()/replay_wal() -- the ONLY thing that + * can engage the Live Apply Resource Fence (job-array-single-wal- + * record tasks 4.1/4.2, extended to boot replay by task 7.2) for + * THIS node. The eligibility gate above (~line 1337) necessarily + * read persist_apply_resource_fenced() as false: a fresh persist_t + * defaults to unfenced (persist_init) and this is the first replay + * that could ever have set it -- so that gate's ELIGIBLE decision + * was made blind to whatever this first replay just did. Re-check + * here, once, right after the only call that could have changed the + * answer: if this node's own first-ever replay just fenced it, + * refuse promotion now instead of falling through to CTRL_PRIMARY + * below on a decision that is now stale. Every later election in + * this process's lifetime is unaffected -- is_first_boot is false + * by then, so the gate above already covers it correctly (this is + * exactly what the sibling test, + * test_replay_wal_engages_fence_on_resource_exhaustion_failure, + * proves). Mirrors the existing refusal branch above verbatim (same + * WARN shape, same ha_arm_promotion_fence_timer() call, same + * unconditional-refuse treatment as apply_divergent/ + * self_restart_pending) rather than inventing a second mechanism. */ + if (c != NULL && persist_apply_resource_fenced(&c->persist)) { + WARN("HA: promotion REFUSED — this node's own first-ever boot " + "replay (cluster_init_phase2, just completed) engaged the " + "Live Apply Resource Fence; the earlier eligibility check " + "in this same election evaluation necessarily missed it " + "(bug-1445) — member stays ALIVE, non-promotable, " + "retrying apply (job-array-single-wal-record Req 9.4/9.5)"); + ha_arm_promotion_fence_timer(ha, c, + persist_recovery_truncated(&c->persist), + persist_durable_floor(&c->persist), + promotion_safe_lsn); + return; + } } /* ha-single-leader-role (Req 1.1): enter CTRL_PRIMARY directly — there is diff --git a/src/controller/testsuite/test_job_array_replay_fence.c b/src/controller/testsuite/test_job_array_replay_fence.c index 9df5a326..979c0dee 100644 --- a/src/controller/testsuite/test_job_array_replay_fence.c +++ b/src/controller/testsuite/test_job_array_replay_fence.c @@ -223,6 +223,22 @@ static int trf_encode_job_submit(uint64_t base_jobid, uint64_t array_size, return 0; } +/* bug-1445 test-only stub: reproduces the REAL production call chain + * (cluster_init_phase2 -> persist_recover -> replay_wal) at the REAL call + * site inside raft_cb_become_leader's is_first_boot block, wired via + * ha_phase2_hook (ha.h:1619) since XCE_TESTING builds skip the real + * cluster_init_phase2() otherwise (ha.c:1431-1433). Deliberately calls ONLY + * persist_recover -- the narrow slice bug-1445 is about -- not the rest of + * cluster_init_phase2's other work (config load etc.), which this test does + * not need. */ +#ifdef XCE_TESTING +static int trf_phase2_hook_calls_persist_recover(void *c) +{ + cluster_t *cc = (cluster_t *)c; + return persist_recover(&cc->persist); +} +#endif + /* ── The test: crash-while-would-be-fenced, restart into a boot replay that * hits the SAME resource-exhaustion condition ────────────────────────────── */ @@ -473,12 +489,181 @@ test_replay_wal_engages_fence_on_resource_exhaustion_failure(void) "PASS\n"); } +/* ── bug-1445: a node's very FIRST-EVER promotion evaluation races its OWN + * first replay ───────────────────────────────────────────────────────────── + * Unlike the sibling test above (which calls persist_recover() BEFORE the + * election path, proving a LATER evaluation is protected), this test leaves + * the persist_t completely un-recovered when raft_cb_become_leader_with_ + * cluster_for_test() is invoked -- ha->phase2_done is fresh (0) and + * ha_phase2_hook is wired to actually call persist_recover(), so + * cluster_init_phase2()'s real call chain runs from INSIDE this SAME + * election evaluation, exactly as it does in production + * (raft_cb_become_leader, ha.c ~1427-1439). This is the exact scenario + * bug-1445 names and the sibling test's own SCOPE NOTE explicitly says it + * does not cover. */ +static void +test_first_boot_promotion_evaluates_own_first_replay_fence(void) +{ + char tmp[256]; + strcpy(tmp, "/tmp/xce_trf_firstboot_XXXXXX"); + TEST_ASSERT_NOT_NULL(mkdtemp(tmp)); + + const uint64_t base_jobid = 981000; + const uint64_t array_size = 5; + const int fail_index = 2; + + job_submit_data_t spec; + memset(&spec, 0, sizeof(spec)); + spec.queue = (char *)"normal"; + spec.user = (char *)"tester"; + spec.mintasks = 1; + spec.maxtasks = 1; + spec.job_name = (char *)"first-boot-fence"; + + uint8_t *payload = NULL; + size_t len = 0; + int enc_rc = trf_encode_job_submit(base_jobid, array_size, &spec, + &payload, &len); + + /* Physically append ONE committed-shape array entry, then tear down + * without ever applying it -- mirrors the sibling test's phase 1, + * simulating a genuinely fresh, never-recovered on-disk WAL. */ + { + persist_config_t cfg1 = persist_config_defaults(); + cfg1.wal_sync_ms = 5000; + persist_t *p1 = calloc(1, sizeof(persist_t)); + TEST_ASSERT_NOT_NULL(p1); + persist_set_workdir(p1, tmp, "ctrl-test"); + TEST_ASSERT_EQUAL_INT(0, persist_init(p1, &cfg1, NULL)); + TEST_ASSERT_EQUAL_INT(0, persist_start(p1)); + TEST_ASSERT_EQUAL_INT(0, + persist_wal_async(p1, WAL_JOB_ARRAY_SUBMIT, payload, + (uint32_t)len)); + TEST_ASSERT_EQUAL_INT(0, persist_flush(p1)); + persist_stop(p1); + persist_fini(p1); + free(p1); + } + + trf_build_cluster(); + + persist_config_t cfg2 = persist_config_defaults(); + cfg2.wal_sync_ms = 5000; + persist_set_workdir(&g_trf_c.persist, tmp, "ctrl-test"); + TEST_ASSERT_EQUAL_INT(0, + persist_init(&g_trf_c.persist, &cfg2, &g_trf_c)); + TEST_ASSERT_EQUAL_INT(0, persist_start(&g_trf_c.persist)); + /* persist_init already defaults recovery_verdict=RECOVER_CLEAN and + * apply_verdict=APPLY_CLEAN (persist.c:613,623) -- set explicitly anyway + * to mirror the sibling test's defensive style, not because a fresh + * persist_t needs it. */ + g_trf_c.persist.recovery_verdict = RECOVER_CLEAN; + + job_array_apply_test_clear_force_fail(); + job_array_apply_test_set_force_fail_at(fail_index); + + /* Precondition: this persist_t has NEVER been recovered -- the fence + * must read clear, exactly the state the real eligibility gate + * (ha.c:1337) sees at a process's very first election. This is the + * blind spot bug-1445 exploits. */ + bool fenced_precondition = persist_apply_resource_fenced(&g_trf_c.persist); + + ha_config_t hcfg = { + .heartbeat_interval_ms = 3000, + .heartbeat_timeout_ms = 10000, + .election_timeout_ms = 2000, + .probe_connect_timeout_ms = 500, + .max_promotion_retries = 5, + }; + TEST_ASSERT_EQUAL_INT(0, ha_init(&g_trf_c.ha, &hcfg, 0)); + g_trf_c.ha.raft_c = &g_trf_c; + g_trf_c.ha.repl = NULL; /* no healthy peer reachable at this level */ + + TEST_ASSERT_EQUAL_INT(0, + delaymgr_init(&g_trf_c.delaymgr, 5, trf_run_delay_task)); + TEST_ASSERT_EQUAL_INT(0, delaymgr_start(&g_trf_c.delaymgr)); + ha_set_promotion_fence_window_ms(60); + + /* The crux of the reproduction: ha->phase2_done is 0 (fresh ha_init + * above), so raft_cb_become_leader's is_first_boot block fires and + * calls this hook -- which calls persist_recover() for real, from + * INSIDE this same election evaluation, racing the gate exactly like + * production. */ + ha_phase2_hook = trf_phase2_hook_calls_persist_recover; + + raft_cb_become_leader_with_cluster_for_test(&g_trf_c, /*term=*/1); + + ha_phase2_hook = NULL; /* restore -- shared process-global test seam */ + + int32_t role_after_election = + atomic_load_explicit(&g_trf_c.ha.role, memory_order_acquire); + int in_catch_up_after_election = + atomic_load_explicit(&g_trf_c.ha.in_catch_up, memory_order_acquire); + bool fenced_after_election = + persist_apply_resource_fenced(&g_trf_c.persist); + uint64_t applied_after_election = + persist_last_applied_lsn(&g_trf_c.persist); + + bool any_element_visible = false; + for (uint64_t i = 0; i < array_size; i++) { + if (trf_find_job(base_jobid + i) != NULL) + any_element_visible = true; + } + + ha_set_promotion_fence_window_ms(0); /* restore default */ + ha_cancel_promotion_fence_timer(&g_trf_c.ha); + delaymgr_stop(&g_trf_c.delaymgr); + delaymgr_fini(&g_trf_c.delaymgr); + ha_fini(&g_trf_c.ha); + + job_array_apply_test_clear_force_fail(); + free(payload); + persist_stop(&g_trf_c.persist); + persist_fini(&g_trf_c.persist); + trf_teardown_cluster(); + + char cmd[512]; + snprintf(cmd, sizeof(cmd), "rm -rf %s", tmp); + if (system(cmd) != 0) + fprintf(stderr, "cleanup warning: rm -rf %s failed\n", tmp); + + /* ── Assertions ───────────────────────────────────────────────────── */ + TEST_ASSERT_EQUAL_INT(0, enc_rc); + TEST_ASSERT_FALSE_MESSAGE(fenced_precondition, + "a never-recovered persist_t must start with the fence CLEAR -- " + "this is the exact blind spot bug-1445 exploits"); + TEST_ASSERT_EQUAL_UINT64_MESSAGE(0, applied_after_election, + "the first-ever replay (triggered from inside the election path) " + "must halt at the failed LSN, same as any other halt-and-fence"); + TEST_ASSERT_TRUE_MESSAGE(fenced_after_election, + "the node's OWN first-ever replay, triggered from inside this SAME " + "election evaluation, must have engaged the Live Apply Resource " + "Fence by the time this call returns"); + TEST_ASSERT_FALSE_MESSAGE(any_element_visible, + "no partial/divergent set of array elements may be constructed " + "(Req 9.6)"); + + TEST_ASSERT_NOT_EQUAL_MESSAGE((int32_t)CTRL_PRIMARY, role_after_election, + "bug-1445: a node whose OWN first-ever replay (racing this SAME " + "election evaluation) engages the Live Apply Resource Fence must " + "be refused promotion -- not silently become CTRL_PRIMARY on a " + "gate decision that was made before that first replay ever ran"); + TEST_ASSERT_EQUAL_INT_MESSAGE(1, in_catch_up_after_election, + "a node refused for this reason must be fenced via the SAME " + "existing in_catch_up mechanism every other refusal reason uses " + "-- no separate mechanism, no drift"); + + printf("test_first_boot_promotion_evaluates_own_first_replay_fence: " + "PASS\n"); +} + #endif /* XCE_TESTING */ void test_job_array_replay_fence(void) { #ifdef XCE_TESTING RUN_TEST(test_replay_wal_engages_fence_on_resource_exhaustion_failure); + RUN_TEST(test_first_boot_promotion_evaluates_own_first_replay_fence); #else printf("test_job_array_replay_fence: skipped (no XCE_TESTING)\n"); #endif