fix(controller): cold start elects in ~1.7 s, not ~10 s; ctrlstatus appliedLsn on the primary (bug-1879, bug-1878)

bug-1879: on a fresh HA cluster the config-holding ctrl-1 started its
term-1 election before its peers ran; connect failures count as "no"
votes (bug-1423), so it lost at once and became a follower with no
leader. ctrl-2/ctrl-3 hold no config and are voters only (by design),
so nothing retried until ctrl-1's 10 s standby liveness timeout: every
cold start had no primary for ~10 s.
- ha_note_leaderless() marks a config-holding node that becomes a
  follower with no leader known; the liveness poll then retries the
  election (PreVote) after HA_LEADERLESS_RETRY_MS = 1 s, doubling up to
  heartbeat_timeout_ms. Primary contact or becoming leader clears it.
- ha_heartbeat_is_fresh() answers "no" while leaderless: last_activity
  then only holds the watchdog's arm time, and the failover gates took
  it for a live primary.
Live cold start: primary 1.7 s after the first node started (was ~10 s).

bug-1878: ctrlstatus_fill() reported ha->applied_lsn for every role, a
standby-only counter a primary never advances, so every primary showed
"appliedLsn: 0". A primary now reports persist->last_applied_lsn. The
controller-status design doc's "already correct in every role" note is
corrected.

Tests: 5 new in test_ha_failover_prevote.c, 1 new in test_ctrlstatus.c
(RED: expected 4900, was 0); controller suite 1256/0. HA soaks:
sequential 6 rounds PASS, chaotic 6 rounds PASS (zero divergence, zero
job loss).

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Rongsong Shen 2026-09-28 07:35:45 +00:00
parent 16b422e303
commit aa7fc65a36
Signed by untrusted user: rshen
GPG key ID: 80533536B0EB651C
6 changed files with 260 additions and 6 deletions

View file

@ -273,7 +273,7 @@ No change to `committedLsn @8` / `committedConfigVersion @7` wire shape — Req
- **Req 10 (committed sourcing):** replace the unconditional reads at `ctrlstatus.c:108–110,130` with the role-branch above:
- `responderRole == CTRL_PRIMARY` → `committedLsn = persist.committed_lsn`, `committedConfigVersion = ha->committed_config_tag` (atomic acquire loads, unchanged).
- else → `committedLsn = ha->last_known_committed_lsn` (atomic acquire), `committedConfigVersion = ha->last_known_committed_config_tag` (plain aligned load).
- `appliedLsn` (`ha->applied_lsn`) is unchanged — it is already correct in every role.
- `appliedLsn` (`ha->applied_lsn`) is unchanged here. **Correction (bug-1878, 2026-09-28):** it is *not* correct in every role — `ha->applied_lsn` is a standby-only counter (replicated WAL received/persisted) that a primary never advances, so every primary reported `appliedLsn: 0`. `ctrlstatus_fill` now reports a primary's apply cursor, `persist->last_applied_lsn` (the last entry applied, never above `committedLsn`); a standby still reports `ha->applied_lsn`.
- **Req 11 (timestamp):** stamp `st->responder_time_ms` from `clock_gettime(CLOCK_REALTIME)` (`tv_sec*1000 + tv_nsec/1e6`) at the top of the snapshot, before/with the other field loads, so it marks the responder's sample moment.
- **Read-only invariant (10.4, 1.2) preserved:** all additions are atomic/aligned loads + a clock read; no HA/persist/config mutation.

View file

@ -175,8 +175,17 @@ void ctrlstatus_fill(cluster_t* c, xce_ctrlstatus_t* st)
atomic_load_explicit(&ha->last_known_committed_config_tag,
memory_order_acquire);
}
st->appliedLsn = atomic_load_explicit(&ha->applied_lsn,
memory_order_acquire);
/* bug-1878: ha->applied_lsn is a standby-only counter (how far
* replicated WAL has been received and persisted); a primary never
* advances it, so every primary reported 0. A primary reports its apply
* cursor instead -- the last entry applied, never above committedLsn. */
if (st->responderRole == (uint8_t)CTRL_PRIMARY) {
st->appliedLsn = atomic_load_explicit(&c->persist.last_applied_lsn,
memory_order_acquire);
} else {
st->appliedLsn = atomic_load_explicit(&ha->applied_lsn,
memory_order_acquire);
}
/* fenced: catch-up OR recovery-unrecoverable (Req 6.3) */
int in_catch_up = atomic_load_explicit(&ha->in_catch_up,

View file

@ -1621,6 +1621,9 @@ loud_fence_no_timer:
static void raft_cb_become_leader(void *ctx, uint64_t term)
{
ha_state_t *ha = (ha_state_t *)ctx;
/* bug-1879: a leader exists (us) -- no leaderless retry pending */
atomic_store_explicit(&ha->leaderless, 0, memory_order_release);
cluster_t *c = ha->raft_c;
/* Cancel any pending election timeout */
@ -2144,12 +2147,34 @@ static void raft_cb_become_leader(void *ctx, uint64_t term)
* calls cluster_init_phase2 on first boot (standbys also need it to
* receive config replication push from the new primary).
*/
static uint64_t ha_monotonic_ms(void)
{
struct timespec ts;
clock_gettime(CLOCK_MONOTONIC, &ts);
return (uint64_t)ts.tv_sec * 1000u + (uint64_t)ts.tv_nsec / 1000000u;
}
/* bug-1879: see ha.h's `leaderless`. Only a node that can lead (holds a
* config) and knows no leader is marked; a config-less node is a voter only
* (ha_start_election_async) and keeps the plain liveness timeout. */
void ha_note_leaderless(ha_state_t *ha, cluster_t *c, int leader_idx)
{
if (!ha || leader_idx >= 0 || !c || !c->myconf
|| c->myconf->config_version_tag == 0)
return;
if (!atomic_exchange_explicit(&ha->leaderless, 1, memory_order_acq_rel))
ha->leaderless_retry_ms = HA_LEADERLESS_RETRY_MS;
}
static void raft_cb_become_follower(void *ctx, uint64_t term, int leader_idx)
{
(void)leader_idx;
ha_state_t *ha = (ha_state_t *)ctx;
cluster_t *c = ha->raft_c;
/* bug-1879: a lost election with no leader known is retried soon, not
* after heartbeat_timeout_ms (armed below) */
ha_note_leaderless(ha, c, leader_idx);
/* Cancel any pending election timeout */
raft_cb_cancel_timeout(ctx);
@ -5423,6 +5448,10 @@ int ha_heartbeat_is_fresh(ha_state_t *ha)
time_t last = ha->last_activity; /* time_t load is atomic on LP64 */
if (last == 0)
return 0; /* no primary message seen yet */
/* bug-1879: while leaderless no primary has been heard from at all --
* last_activity then only holds the watchdog's arm time */
if (atomic_load_explicit(&ha->leaderless, memory_order_acquire))
return 0;
struct timespec now;
clock_gettime(CLOCK_MONOTONIC, &now);
long ms = (long)(now.tv_sec - last) * 1000L;
@ -8993,6 +9022,22 @@ static int liveness_poll_fn(void *arg)
time_t elapsed = (last > 0) ? (now - last) : 0;
uint32_t timeout_s = ha->config.heartbeat_timeout_ms / 1000;
/* bug-1879: a leaderless config-holding node retries the election after
* its (doubling) retry delay instead of the full heartbeat timeout */
if (atomic_load_explicit(&ha->leaderless, memory_order_acquire)) {
uint64_t waited = ha_monotonic_ms() - ha->leaderless_since_ms;
if (waited >= ha->leaderless_retry_ms) {
INFO("HA: no primary known after %lums — retrying the election",
(unsigned long)waited);
ha->leaderless_retry_ms *= 2;
if (ha->leaderless_retry_ms > ha->config.heartbeat_timeout_ms)
ha->leaderless_retry_ms = ha->config.heartbeat_timeout_ms;
ha_dispatch_rdhup_failover(ha, c);
return 0; /* failover (PreVote lost -> re-arm) handles the rest */
}
}
if (last > 0 && (uint32_t)elapsed >= timeout_s) {
/* Silence exceeded timeout — trigger failover */
WARN("HA: liveness poll: no primary activity for %lus (timeout=%us) → failover",
@ -9006,6 +9051,10 @@ static int liveness_poll_fn(void *arg)
if (c && c->delaymgr.running) {
uint32_t poll_ms = ha->config.heartbeat_interval_ms / 2;
if (poll_ms < 100) poll_ms = 100;
/* bug-1879: poll no slower than a pending leaderless retry */
if (atomic_load_explicit(&ha->leaderless, memory_order_acquire)
&& ha->leaderless_retry_ms < poll_ms)
poll_ms = ha->leaderless_retry_ms;
delay_task_ms(&c->delaymgr, (int)poll_ms, 1,
(delay_task_entry_fn_t)liveness_poll_fn, ctx);
}
@ -9079,6 +9128,15 @@ void ha_arm_heartbeat_timeout_vtask(ha_state_t *ha, cluster_t *c)
uint32_t poll_ms = ha->config.heartbeat_interval_ms / 2;
if (poll_ms < 100) poll_ms = 100;
if (atomic_load_explicit(&ha->leaderless, memory_order_acquire)) {
/* bug-1879: no leader known -- poll at the retry delay */
ha->leaderless_since_ms = ha_monotonic_ms();
if (ha->leaderless_retry_ms < poll_ms)
poll_ms = ha->leaderless_retry_ms;
INFO("HA: no primary known yet — election retry in %ums",
ha->leaderless_retry_ms);
}
INFO("HA: standby liveness poll armed (timeout=%ums, poll=%ums)",
ha->config.heartbeat_timeout_ms, poll_ms);
@ -9138,6 +9196,11 @@ void ha_on_heartbeat_received(ha_state_t *ha)
ha->last_activity = ts.tv_sec;
tlog(TLOG_DEBUG3, "HA: heartbeat received — last_activity updated to %ld", (long)ts.tv_sec);
/* bug-1879: a primary exists -- back to the plain liveness timeout */
if (atomic_exchange_explicit(&ha->leaderless, 0, memory_order_acq_rel))
INFO("HA: primary contact — leaderless election retry stopped");
ha->leaderless_retry_ms = HA_LEADERLESS_RETRY_MS;
/* ha-prevote task 4.2 (Req 4.2): a fresh primary heartbeat means the leader
* is alive — a PreVote round started by a transient blip must be ABANDONED.
* Cancel the in-progress round (clear the raft round state + the controller

View file

@ -134,6 +134,9 @@ typedef struct {
#define HA_DEFAULT_HEARTBEAT_INTERVAL_MS 3000
#define HA_DEFAULT_HEARTBEAT_TIMEOUT_MS 10000
#define HA_DEFAULT_ELECTION_TIMEOUT_MS 5000
/* bug-1879: first election retry of a leaderless config-holding node;
* doubles per attempt up to heartbeat_timeout_ms */
#define HA_LEADERLESS_RETRY_MS 1000
#define HA_DEFAULT_PROBE_CONNECT_TIMEOUT_MS 500
/* Log the first connect failure per peer, then every Nth attempt. */
#define HA_CONNECT_LOG_THROTTLE 10
@ -247,6 +250,16 @@ typedef struct {
void *raft_election_timeout_ctx; /* election_timeout_ctx_t* for cancel (task 6.2) */
/* ── New fields added by ha-heartbeat-liveness spec (Task 1.1) ── */
time_t last_activity; /* CLOCK_MONOTONIC seconds of last primary message; 0 = none yet */
/* bug-1879: set (ha_note_leaderless) when this node, able to lead (it
* holds a config), became a follower without knowing any leader -- e.g.
* its first-boot election lost because its peers were not up yet. The
* liveness poll then retries the election after leaderless_retry_ms
* (measured from leaderless_since_ms, CLOCK_MONOTONIC ms; doubling up to
* heartbeat_timeout_ms) instead of the full heartbeat_timeout_ms. The
* first primary contact (ha_on_heartbeat_received) clears it. */
_Atomic int leaderless;
uint32_t leaderless_retry_ms;
uint64_t leaderless_since_ms;
/* ── New fields added by ha-repl-hardening spec (Task 1.4) ──────── */
uint64_t standby_reported_tag[MAX_HA_CANDIDATES]; /* Last config_tag reported by each standby */
uint64_t standby_reported_lsn[MAX_HA_CANDIDATES]; /* Last applied_lsn reported by each standby */
@ -956,6 +969,8 @@ int ha_schedule_phase2_retry(cluster_t *c);
/* bug-1876: cluster_init_phase2()'s "cluster_config not pushed yet" result
* (-EAGAIN) -- the normal cold-boot wait of a standby, retried, not a
* failure; callers log it at INFO, everything else at WARN. */
void ha_note_leaderless(ha_state_t *ha, cluster_t *c, int leader_idx);
static inline int ha_phase2_rc_is_waiting(int rc)
{
return rc == -EAGAIN;

View file

@ -90,6 +90,33 @@ static void cs_teardown_cluster(cluster_t* c)
/* ── tests ──────────────────────────────────────────────────── */
/* bug-1878: a primary never advances ha->applied_lsn (a standby-only
* counter: how far replicated WAL has been received), so ctrlstatus showed
* "committedLsn: 4900 / appliedLsn: 0" on every primary. A primary reports
* its apply cursor, persist->last_applied_lsn (the last entry applied). */
static void test_ctrlstatus_primary_reports_its_apply_cursor(void)
{
cluster_t c;
myconf_t mc;
cs_setup_cluster(&c, &mc);
atomic_store_explicit(&c.ha.role, (int32_t)CTRL_PRIMARY,
memory_order_release);
atomic_store_explicit(&c.ha.applied_lsn, 0, memory_order_release);
atomic_store_explicit(&c.persist.committed_lsn, 4900, memory_order_release);
atomic_store_explicit(&c.persist.last_applied_lsn, 4900,
memory_order_release);
xce_ctrlstatus_t st;
ctrlstatus_fill(&c, &st);
TEST_ASSERT_EQUAL_UINT64(4900, st.committedLsn);
TEST_ASSERT_EQUAL_UINT64(4900, st.appliedLsn);
TEST_ASSERT_TRUE_MESSAGE(st.appliedLsn <= st.committedLsn,
"a primary applies only committed entries");
ctrlstatus_free_fields(&st);
}
/* (a) PRIMARY: responderRole==PRIMARY, primaryName==self, peers/version
* populated; committed/applied/term reflect the atomics. (Req 2.1, 3.1, 3.2,
* 4.1, 4.2, 5.1, 6.1, 6.2, 6.4) */
@ -102,7 +129,9 @@ static void test_ctrlstatus_primary(void)
atomic_store_explicit(&c.ha.role, (int32_t)CTRL_PRIMARY,
memory_order_release);
atomic_store_explicit(&c.ha.term, 7, memory_order_release);
atomic_store_explicit(&c.ha.applied_lsn, 42, memory_order_release);
/* bug-1878: a primary's applied position is persist.last_applied_lsn;
* ha.applied_lsn (standby-only) is left at the 0 a live primary has */
atomic_store_explicit(&c.persist.last_applied_lsn, 41, memory_order_release);
atomic_store_explicit(&c.ha.committed_config_tag, 0xAABBCCDDEE001122ULL,
memory_order_release);
atomic_store_explicit(&c.persist.committed_lsn, 41, memory_order_release);
@ -120,7 +149,7 @@ static void test_ctrlstatus_primary(void)
TEST_ASSERT_NOT_NULL(st.primaryName);
TEST_ASSERT_EQUAL_STRING("ctrlA", st.primaryName);
TEST_ASSERT_EQUAL_UINT64(7, st.term);
TEST_ASSERT_EQUAL_UINT64(42, st.appliedLsn);
TEST_ASSERT_EQUAL_UINT64(41, st.appliedLsn);
TEST_ASSERT_EQUAL_UINT64(41, st.committedLsn);
TEST_ASSERT_EQUAL_UINT64(0xAABBCCDDEE001122ULL, st.configVersion);
TEST_ASSERT_EQUAL_UINT64(0xAABBCCDDEE001122ULL, st.committedConfigVersion);
@ -1098,6 +1127,7 @@ void test_ctrlstatus(void)
UnitySetTestFile(__FILE__);
RUN_TEST(test_ctrlstatus_format_time_ms);
RUN_TEST(test_ctrlstatus_primary);
RUN_TEST(test_ctrlstatus_primary_reports_its_apply_cursor);
RUN_TEST(test_ctrlstatus_standby_known_primary);
RUN_TEST(test_ctrlstatus_unknown_primary);
RUN_TEST(test_ctrlstatus_standby_self_vote_is_unknown);

View file

@ -352,6 +352,138 @@ static void test_config_less_node_does_not_start_prevote(void)
printf("test_config_less_node_does_not_start_prevote: PASS\n");
}
/* ── bug-1879: cold boot / lost election with no leader known ──────────── */
/*
* A config-holding node that loses its first election because its peers are
* not up yet (connect failures count as "no" votes, bug-1423) became a
* follower with nobody to follow, and only the 10 s liveness timeout ever
* retried: every cold start had no primary for ~10 s. Now such a node is
* marked leaderless and the liveness poll retries the election (via PreVote)
* after leaderless_retry_ms, doubling up to heartbeat_timeout_ms.
*/
static uint64_t now_ms(void)
{
struct timespec ts;
clock_gettime(CLOCK_MONOTONIC, &ts);
return (uint64_t)ts.tv_sec * 1000u + (uint64_t)ts.tv_nsec / 1000000u;
}
static void test_leaderless_follower_retries_election_after_short_delay(void)
{
ha_state_t ha;
TEST_ASSERT_EQUAL_INT(0, ha_init(&ha, &g_cfg, 0));
ha_do_demote(&ha);
make_three_node(&ha);
struct timespec ts;
clock_gettime(CLOCK_MONOTONIC, &ts);
ha.last_activity = ts.tv_sec; /* the 6 s timeout is far away */
atomic_store(&ha.leaderless, 1);
ha.leaderless_retry_ms = HA_LEADERLESS_RETRY_MS;
ha.leaderless_since_ms = now_ms() - HA_LEADERLESS_RETRY_MS - 50;
liveness_poll_ctx_t ctx;
memset(&ctx, 0, sizeof(ctx));
ctx.ha = &ha;
atomic_init(&ctx.cancelled, 0);
liveness_poll_fn_test_entry(&ctx);
TEST_ASSERT_EQUAL_INT_MESSAGE(1, ha.raft.pre_vote_in_progress,
"a leaderless config-holding node retries after leaderless_retry_ms");
TEST_ASSERT_EQUAL_UINT32_MESSAGE(2 * HA_LEADERLESS_RETRY_MS,
ha.leaderless_retry_ms, "the next retry waits twice as long");
ha_fini(&ha);
}
static void test_leaderless_retry_waits_for_its_delay(void)
{
ha_state_t ha;
TEST_ASSERT_EQUAL_INT(0, ha_init(&ha, &g_cfg, 0));
ha_do_demote(&ha);
make_three_node(&ha);
struct timespec ts;
clock_gettime(CLOCK_MONOTONIC, &ts);
ha.last_activity = ts.tv_sec;
atomic_store(&ha.leaderless, 1);
ha.leaderless_retry_ms = HA_LEADERLESS_RETRY_MS;
ha.leaderless_since_ms = now_ms() - 100;
liveness_poll_ctx_t ctx;
memset(&ctx, 0, sizeof(ctx));
ctx.ha = &ha;
atomic_init(&ctx.cancelled, 0);
liveness_poll_fn_test_entry(&ctx);
TEST_ASSERT_EQUAL_INT(0, ha.raft.pre_vote_in_progress);
ha_fini(&ha);
}
static void test_leaderless_retry_backoff_is_capped(void)
{
ha_state_t ha;
TEST_ASSERT_EQUAL_INT(0, ha_init(&ha, &g_cfg, 0));
ha_do_demote(&ha);
make_three_node(&ha);
struct timespec ts;
clock_gettime(CLOCK_MONOTONIC, &ts);
ha.last_activity = ts.tv_sec;
atomic_store(&ha.leaderless, 1);
ha.leaderless_retry_ms = g_cfg.heartbeat_timeout_ms;
ha.leaderless_since_ms = now_ms() - g_cfg.heartbeat_timeout_ms - 50;
liveness_poll_ctx_t ctx;
memset(&ctx, 0, sizeof(ctx));
ctx.ha = &ha;
atomic_init(&ctx.cancelled, 0);
liveness_poll_fn_test_entry(&ctx);
TEST_ASSERT_EQUAL_UINT32(g_cfg.heartbeat_timeout_ms, ha.leaderless_retry_ms);
ha_fini(&ha);
}
static void test_primary_contact_clears_leaderless(void)
{
ha_state_t ha;
TEST_ASSERT_EQUAL_INT(0, ha_init(&ha, &g_cfg, 0));
ha_do_demote(&ha);
atomic_store(&ha.leaderless, 1);
ha.leaderless_retry_ms = 4 * HA_LEADERLESS_RETRY_MS;
ha_on_heartbeat_received(&ha);
TEST_ASSERT_EQUAL_INT(0, atomic_load(&ha.leaderless));
TEST_ASSERT_EQUAL_UINT32(HA_LEADERLESS_RETRY_MS, ha.leaderless_retry_ms);
ha_fini(&ha);
}
static void test_only_a_config_holder_without_leader_is_leaderless(void)
{
ha_state_t ha;
cluster_t c;
myconf_t conf;
TEST_ASSERT_EQUAL_INT(0, ha_init(&ha, &g_cfg, 0));
memset(&c, 0, sizeof(c));
memset(&conf, 0, sizeof(conf));
c.myconf = &conf;
conf.config_version_tag = 0; /* voter only */
ha_note_leaderless(&ha, &c, -1);
TEST_ASSERT_EQUAL_INT(0, atomic_load(&ha.leaderless));
conf.config_version_tag = 0x1234; /* can lead, leader known */
ha_note_leaderless(&ha, &c, 1);
TEST_ASSERT_EQUAL_INT(0, atomic_load(&ha.leaderless));
ha_note_leaderless(&ha, &c, -1); /* can lead, no leader */
TEST_ASSERT_EQUAL_INT(1, atomic_load(&ha.leaderless));
TEST_ASSERT_EQUAL_UINT32(HA_LEADERLESS_RETRY_MS, ha.leaderless_retry_ms);
ha_fini(&ha);
}
/* ── Suite entry point ──────────────────────────────────────────────────── */
void test_ha_failover_prevote(void)
@ -367,6 +499,11 @@ void test_ha_failover_prevote(void)
RUN_TEST(test_heartbeat_without_round_is_plain_noop);
RUN_TEST(test_failover_prevote_win_reaches_real_election);
RUN_TEST(test_config_less_node_does_not_start_prevote);
RUN_TEST(test_leaderless_follower_retries_election_after_short_delay);
RUN_TEST(test_leaderless_retry_waits_for_its_delay);
RUN_TEST(test_leaderless_retry_backoff_is_capped);
RUN_TEST(test_primary_contact_clears_leaderless);
RUN_TEST(test_only_a_config_holder_without_leader_is_leaderless);
ha_prevote_rearm_liveness_hook = NULL;
}