fix(controller): debounce RDHUP-triggered failover — stop the term-escalation storm (bug-1310, task 5.10b)

A dead primary's control fd RDHUPs faster than an election settles. The 5.6 guard only drops an RDHUP while the role is instantaneously CTRL_ELECTING/ prevote; an RDHUP landing in the gap after a lost election (role briefly back to CTRL_STANDBY) re-triggers a fresh ha_begin_failover -> PreVote -> real election (term++). One bump per RDHUP -> unbounded escalation under a sustained cadence (observed round 4: 48 begin_failovers, terms 6->24, round overran the harness window). Fix: ha_state_t.last_failover_ms (atomic) stamped at ha_begin_failover; ha_on_primary_ctrl_fd_rdhup drops an RDHUP within 2*election_timeout_ms of the last trigger (closes the dead fd, returns) so the election's own jittered retry (5.7) runs without the external RDHUP cadence adding term bumps. First trigger never debounced; genuine loss still fails over, at most once per window. Validation: unit-proven — test_rdhup_within_cooldown_is_debounced (recent last_failover -> stays CTRL_STANDBY) vs test_rdhup_single_node_reaches_primary (last_failover=0 -> CTRL_PRIMARY) is a differential proof. Soak: 10/10 elect, terms 4->14 bounded, begin_failover 14/14/12 (was 48), committed_job_loss=0, no regression. The stochastic storm did not recur this run (debounce fired 0x), so soak-reproduction of the storm is still pending; the mechanism rests on the unit test. Election suites green (rdhup 8/0, prevote 12/0, core_safety 24/0, election 28/0, failover_prevote 6/0). Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01JDYFbrgyDHbvNYcxApKhrX
2026-07-01 01:32:27 +00:00 · 2026-07-01 01:32:27 +00:00 · 0d70d5e412
commit 0d70d5e412
parent cc80e65288
5 changed files with 175 additions and 1 deletions
--- a/.kiro/specs/raft-ha-core-safety/tasks.md
+++ b/.kiro/specs/raft-ha-core-safety/tasks.md
@ -172,7 +172,8 @@
  - _Boundary: Commit durability (raft-apply-decoupling item #1). Full canonical inversion (async keystone + apply_committed_entry seam + facts + restart validation) = the follow-on ha spec._
  - _Depends: 5.8_

- [ ] 5.10 Residual soak FAILs after 5.9 (NOT job loss) — divergence lag + election-escalation tail
+- [ ] 5.10 Residual soak FAILs after 5.9 (NOT job loss) — divergence lag [5.10a, OPEN] + election-escalation tail [5.10b, FIX LANDED]
+  - _5.10b DONE (bug-1310, commit pending): RDHUP failover DEBOUNCE. Root cause = a dead primary's fd RDHUPs faster than an election settles; the 5.6 point-in-time guard misses RDHUPs that land after a lost election (role briefly back to STANDBY) → term++ per RDHUP (48 begin_failovers, terms 6→24). Fix: ha_state_t.last_failover_ms stamped at ha_begin_failover; ha_on_primary_ctrl_fd_rdhup drops an RDHUP within 2×election_timeout of the last trigger. Unit-proven (test_rdhup_within_cooldown_is_debounced); soak 10/10 elect, terms 4→14 bounded, begin_failover 14/14/12 (was 48), no regression — but the stochastic storm did not recur this run (debounce fired 0×), so soak-reproduction of the storm is still pending. 5.10a (divergence catch-up lag) remains OPEN below._
  - _(a) committed_divergence>0 from the just-restarted node's catch-up LAG (walcompare `present=2`: entry on the 2 live nodes, not yet backfilled on the restarted one). Transient, settles; NOT lost data. Closed by entity-bearing snapshots / the full raft-apply-decoupling apply seam (EXTERNAL — ha-commit-durability / ha-convergence-recovery). (b) Election-escalation TAIL: under an adversarial overlap (kill inside a split-vote window) a round can still stall + ladder terms (observed round-4 term 6→25 before electing) despite 5.7's jitter — liveness held (elected next round) but degraded. Harden: cap/dampen term escalation or widen the jitter under repeated same-round failovers._
  - Observable completion: a 10-round chaotic soak verdict is committed_divergence=0 with no per-round election stall — the green 7.2 gate
  - _Requirements: 4.1, 4.3, 6.1, 6.2, 6.3_
--- a/.wolf/buglog.json
+++ b/.wolf/buglog.json
@ -21809,6 +21809,76 @@
      "related_bugs": [],
      "occurrences": 1,
      "last_seen": "2026-07-01T00:42:13.591Z"
+    },
+    {
+      "id": "bug-1314",
+      "timestamp": "2026-07-01T01:24:37.398Z",
+      "error_message": "Missing error handling in unknown",
+      "file": "src/controller/ha.c",
+      "root_cause": "Code path had no error handling — exceptions would propagate uncaught",
+      "fix": "Added try/catch block",
+      "tags": [
+        "auto-detected",
+        "error-handling",
+        "c"
+      ],
+      "related_bugs": [],
+      "occurrences": 1,
+      "last_seen": "2026-07-01T01:24:37.398Z"
+    },
+    {
+      "id": "bug-1315",
+      "timestamp": "2026-07-01T01:26:38.341Z",
+      "error_message": "Wrong reference: unistd should be time",
+      "file": "src/controller/testsuite/test_ha_rdhup_integration.c",
+      "root_cause": "Used \"unistd\" instead of \"time\"",
+      "fix": "Changed unistd → time",
+      "tags": [
+        "auto-detected",
+        "wrong-reference",
+        "c"
+      ],
+      "related_bugs": [],
+      "occurrences": 1,
+      "last_seen": "2026-07-01T01:26:38.341Z"
+    },
+    {
+      "id": "bug-1310",
+      "timestamp": "2026-06-30T18:40:00Z",
+      "error_message": "chaotic soak round-4 election-escalation storm: terms laddered 6->24 (~18 bumps), 48 begin_failovers, round overran the harness window",
+      "file": "src/controller/ha.c (ha_on_primary_ctrl_fd_rdhup)",
+      "root_cause": "A dead primary's control fd RDHUPs faster than an election settles. The 5.6 guard only drops an RDHUP while role is INSTANTANEOUSLY CTRL_ELECTING/prevote; an RDHUP landing in the gap after a lost election (role briefly back to CTRL_STANDBY) re-triggers a fresh ha_begin_failover -> PreVote(won) -> real election(term++). One term bump per RDHUP -> unbounded escalation under a sustained cadence. NOT RNG (seed is /dev/urandom).",
+      "fix": "5.10b RDHUP failover DEBOUNCE: ha_state_t.last_failover_ms (atomic) stamped at ha_begin_failover; ha_on_primary_ctrl_fd_rdhup drops an RDHUP within 2*election_timeout_ms of the last trigger (closes the dead fd, returns) so the election's own jittered retry (5.7) runs without the external RDHUP cadence adding term bumps. First trigger never debounced; genuine loss still fails over, at most once per window. Unit-proven: test_rdhup_within_cooldown_is_debounced (recent last_failover -> stays CTRL_STANDBY) vs test_rdhup_single_node_reaches_primary (last_failover=0 -> CTRL_PRIMARY) = differential proof. Soak: 10/10 elect, terms 4->14 bounded, begin_failover 14/14/12 (was 48), no regression — but the stochastic storm did NOT recur this run (debounce fired 0x), so end-to-end storm suppression is unit-proven, not yet soak-reproduced.",
+      "tags": [
+        "election-liveness",
+        "rdhup",
+        "term-escalation",
+        "debounce",
+        "5.10b",
+        "raft"
+      ],
+      "related_bugs": [
+        "bug-1296",
+        "bug-1306"
+      ],
+      "occurrences": 1,
+      "last_seen": "2026-06-30T18:40:00Z"
+    },
+    {
+      "id": "bug-1317",
+      "timestamp": "2026-07-01T01:32:08.631Z",
+      "error_message": "Missing error handling in unknown",
+      "file": ".kiro/specs/raft-ha-core-safety/tasks.md",
+      "root_cause": "Code path had no error handling — exceptions would propagate uncaught",
+      "fix": "Added try/catch block",
+      "tags": [
+        "auto-detected",
+        "error-handling",
+        "md"
+      ],
+      "related_bugs": [],
+      "occurrences": 1,
+      "last_seen": "2026-07-01T01:32:08.631Z"
    }
  ]
 }
--- a/src/controller/ha.c
+++ b/src/controller/ha.c
@ -6725,9 +6725,22 @@ static int ha_failover_stagger_fn(void *arg)
    return 0;
 }

+/* CLOCK_MONOTONIC milliseconds — for the RDHUP failover debounce (5.10b). */
+static uint64_t ha_mono_ms(void)
+{
+    struct timespec ts;
+    clock_gettime(CLOCK_MONOTONIC, &ts);
+    return (uint64_t)ts.tv_sec * 1000u + (uint64_t)(ts.tv_nsec / 1000000L);
+}
+
 void ha_begin_failover(ha_state_t *ha, cluster_t *c)
 {
    if (!ha) return;
+    /* Stamp the failover-trigger time so a rapid RDHUP cadence from a dead
+     * primary's fd cannot re-trigger a fresh failover on every event (5.10b
+     * debounce in ha_on_primary_ctrl_fd_rdhup). Any trigger source (RDHUP or the
+     * deferred heartbeat-timeout stagger) records here. */
+    atomic_store_explicit(&ha->last_failover_ms, ha_mono_ms(), memory_order_release);
    INFO("HA: beginning failover via PreVote (no truncate / no term bump until "
         "PreVote wins) — staying CTRL_STANDBY");

@ -6790,6 +6803,38 @@ void ha_on_primary_ctrl_fd_rdhup(ha_state_t *ha, cluster_t *c)
        }
    }

+    /* raft-ha-core-safety 5.10b: RDHUP failover DEBOUNCE. The 5.6 guard above
+     * only catches an RDHUP while the role is INSTANTANEOUSLY CTRL_ELECTING /
+     * pre_vote_in_progress. But a dead primary's fd RDHUPs faster than an
+     * election settles, and each RDHUP that lands in the gap AFTER a real
+     * election loses (role briefly back at CTRL_STANDDBY before the next attempt)
+     * re-triggers a fresh failover → a term bump per RDHUP (observed: 48
+     * begin_failovers, terms 6→24 in one round; research.md §"5.10b DEEPER").
+     * Suppress an RDHUP-triggered failover for up to 2× the election timeout
+     * after the last trigger — long enough to cover the jittered [T,2T] election
+     * watchdog (5.7) so the election's OWN retry runs without the external RDHUP
+     * cadence piling on extra term bumps. A genuinely-dead primary is still
+     * failed over — at most once per window, not once per RDHUP. First trigger
+     * (last_failover_ms == 0) is never debounced. */
+    {
+        uint64_t now_ms = ha_mono_ms();
+        uint64_t last   = atomic_load_explicit(&ha->last_failover_ms,
+                                               memory_order_acquire);
+        uint64_t cooldown_ms = 2u * (uint64_t)ha->config.election_timeout_ms;
+        if (last != 0 && now_ms >= last && (now_ms - last) < cooldown_ms) {
+            if (ha->primary_ctrl_fd >= 0) {
+                close(ha->primary_ctrl_fd);
+                ha->primary_ctrl_fd = -1;
+            }
+            INFO("HA: primary_ctrl_fd RDHUP within failover cooldown (%lums since "
+                 "last trigger, cooldown=%lums) — debouncing, not restarting "
+                 "failover (5.10b: a sustained RDHUP cadence must not ladder the "
+                 "term; the in-flight election's own jittered retry handles it)",
+                 (unsigned long)(now_ms - last), (unsigned long)cooldown_ms);
+            return;
+        }
+    }
+
    /* Cancel the liveness poll task first (Req 5.4): prevents a concurrent
     * poll fn from triggering a second failover call after EPOLLRDHUP fires. */
    ha_disarm_heartbeat_timeout_vtask(ha);
--- a/src/controller/ha.h
+++ b/src/controller/ha.h
@ -160,6 +160,7 @@ typedef struct {
    /* watchdog_stop / watchdog_thread deleted — replaced by ha_arm_heartbeat_timeout_vtask */
    void            *ssl_ctx;           /* SSL_CTX* cast; avoids pulling openssl headers here */
    uint64_t         jitter_seed;       /* xorshift64 PRNG state for election jitter */
+    _Atomic uint64_t last_failover_ms;  /* CLOCK_MONOTONIC ms of last failover trigger; RDHUP debounce (5.10b) */
    zarray_t        *standby_endpoints; /* connected standby controller endpoints for config push */
    /* ── New fields added by ha-config-bootstrap spec ──────── */
    uint64_t         voted_for_term;                  /* Req 9: term of last granted vote */
--- a/src/controller/testsuite/test_ha_rdhup_integration.c
+++ b/src/controller/testsuite/test_ha_rdhup_integration.c
@ -23,6 +23,7 @@
 #include <stdlib.h>
 #include <string.h>
 #include <sys/socket.h>
+#include <time.h>
 #include <unistd.h>

 #include <unity/unity.h>
@ -586,9 +587,65 @@ static void test_rdhup_candidate_advertises_freshness_floor_not_stale_committed(

 /* ── Suite entry point ──────────────────────────────────────────────────── */

+/* ═══════════════════════════════════════════════════════════════════════════
+ * 5.10b: an RDHUP arriving within the failover cooldown of a prior trigger must
+ * be DEBOUNCED — no fresh failover/election, no term ladder. The round-4 soak
+ * storm (48 begin_failovers, terms 6→24) came from a dead primary's fd RDHUPing
+ * faster than an election settles; each RDHUP that landed after a lost election
+ * (role briefly back at CTRL_STANDBY) re-triggered a failover. The single-node
+ * fixture normally reaches CTRL_PRIMARY on RDHUP (see
+ * test_rdhup_single_node_reaches_primary — that PASS is the "not within
+ * cooldown → still elects" pin). With a RECENT last_failover_ms and a stale
+ * heartbeat (so the 5.2 alive-suppression does not fire), the node must stay
+ * CTRL_STANDBY. Pre-fix (no debounce) this reached CTRL_PRIMARY → RED.
+ * ═════════════════════════════════════════════════════════════════════════ */
+static void test_rdhup_within_cooldown_is_debounced(void)
+{
+    install_stubs();
+
+    cluster_t c;
+    myconf_t  myconf;
+    make_cluster(&c, &myconf, "ctrl-a");
+    myconf.peers_cfg.candidates_count = 1; /* single node → would self-elect */
+
+    TEST_ASSERT_EQUAL_INT(0, ha_init(&c.ha, &g_cfg, 0));
+    ha_do_demote(&c.ha);
+    c.ha.phase2_done   = 1;
+    c.ha.n_peers       = 0;
+    c.ha.last_activity = 0; /* stale heartbeat → 5.2 alive-suppression will NOT fire */
+
+    g_rdhup_state.c        = &c;
+    ha_rdhup_election_hook = rdhup_election_drives_evaluate;
+
+    /* A failover was triggered "just now" → this RDHUP is within the cooldown. */
+    struct timespec ts;
+    clock_gettime(CLOCK_MONOTONIC, &ts);
+    uint64_t now_ms = (uint64_t)ts.tv_sec * 1000u + (uint64_t)(ts.tv_nsec / 1000000L);
+    atomic_store_explicit(&c.ha.last_failover_ms, now_ms, memory_order_release);
+
+    int sv[2];
+    TEST_ASSERT_EQUAL_INT(0, socketpair(AF_UNIX, SOCK_STREAM, 0, sv));
+    c.ha.primary_ctrl_fd = sv[0];
+
+    ha_on_primary_ctrl_fd_rdhup(&c.ha, &c);
+    close(sv[1]);
+
+    int role = (int)atomic_load_explicit(&c.ha.role, memory_order_acquire);
+    TEST_ASSERT_EQUAL_INT_MESSAGE((int)CTRL_STANDBY, role,
+        "an RDHUP within the failover cooldown must be debounced — no fresh "
+        "failover; node stays CTRL_STANDBY (5.10b RDHUP storm)");
+    TEST_ASSERT_EQUAL_INT_MESSAGE(-1, c.ha.primary_ctrl_fd,
+        "the debounced RDHUP must still close the dead primary_ctrl_fd");
+
+    clear_stubs();
+    ha_fini(&c.ha);
+    printf("test_rdhup_within_cooldown_is_debounced: PASS\n");
+}
+
 void test_ha_rdhup_integration(void)
 {
    RUN_TEST(test_rdhup_candidate_advertises_freshness_floor_not_stale_committed);
+    RUN_TEST(test_rdhup_within_cooldown_is_debounced);
    RUN_TEST(test_rdhup_full_path_reaches_primary);
    /* ack-driven promotion test deleted (ha-single-leader-role 4.1:
     * ack-driven promotion machinery removed, no shim) */