diff --git a/src/controller/config_repl.c b/src/controller/config_repl.c index 43b2f0b4..ba6e8a94 100644 --- a/src/controller/config_repl.c +++ b/src/controller/config_repl.c @@ -2356,19 +2356,50 @@ int ha_stream_wal_to_standby(endpoint_t *ep, const char *wal_path, * never sent on the live broadcast path either * (persist_wal_write_replicated rejects type==WAL_CHECKPOINT with * -EINVAL). Skip it entirely -- do not build/send a catchup entry - * and do not advance prev_streamed_lsn/prev_streamed_term, so the - * NEXT real entry's AppendEntries prev tuple chains to the last - * REAL entry before this gap, exactly matching what a standby that - * never records a checkpoint marker in its own log expects. - * Without this, a standby receiving one gets stuck retrying the - * same LSN forever (the receive-side guard correctly refuses it). */ - if (hdr.type == WAL_CHECKPOINT) { - free(locked_pbuf); - off += (uint32_t)(sizeof(hdr) + hdr.payload_len); - continue; - } + * for it. + * + * bug-1475 (fix): DO fall through to the SAME unconditional + * prev-tracker advance every other scanned entry gets below + * (the "for EVERY scanned entry" logic a few lines down) instead + * of special-casing a skip here. A standby's own current_lsn/ + * durable_floor ALSO advances past this exact LSN the moment it + * independently applies the SAME committed WAL_CONFIG_MARKER (any + * member that commits a marker immediately writes its own local + * checkpoint at the marker's own LSN+1, deterministically the + * SAME lsn on every member that has caught up through the + * marker) -- so the checkpoint's LSN is a real, held position on + * BOTH sides, not a gap. The OLD behavior (never advancing the + * tracker across it) under-counted the sender's prev_log_index by + * one for every checkpoint encountered, permanently diverging it + * from the receiver's own (now correctly co-tracked -- see + * ha_apply_term_entry_via_library's bug-1475 fix) log_len: the + * first post-checkpoint entry would spuriously "succeed" at the + * WRONG index, after which every following entry's prev_log_index + * permanently exceeded the receiver's true log length -- + * ae_reject_logmismatch forever, with the primary re-streaming + * the identical doomed range every heartbeat. Falling through + * here (falling to the same code path as every other entry) + * fixes the divergence at its source. + * + * bug-1475 follow-up: this tracker advance alone was NOT + * sufficient — persist_entry_term(p, checkpoint_lsn) (the term + * this tracker reads for prev_log_term) turned out to be + * TIME-DEPENDENT before a further persist.c fix: it correctly + * read absent (0) right after the checkpoint, but silently + * flipped to WAL_LEGACY_TERM (1) the instant this leader + * appended any LATER real entry (which has already happened by + * the time this streamer runs), because persist.c's term-index + * array growth zero-filled the checkpoint's never-explicitly- + * recorded gap slot and read that zero-fill back as present. A + * receiver that had not yet appended past its own checkpoint + * still (correctly) read 0 for the same LSN, so logOk's + * prev_log_term equality check mismatched (0 != 1) and rejected + * forever. Fixed with a TERM_INDEX_UNSET sentinel in persist.c + * (record_entry_term/entry_term_locked) that keeps a + * never-recorded slot reading absent permanently, independent of + * later growth — see TERM_INDEX_UNSET's comment there. */ - if (hdr.lsn > standby_lsn) { + if (hdr.lsn > standby_lsn && hdr.type != WAL_CHECKPOINT) { wal_catchup_entry_t *entry = calloc(1, sizeof(*entry)); if (!entry) { free(locked_pbuf); diff --git a/src/controller/ha.c b/src/controller/ha.c index 27b2e58b..4c660663 100644 --- a/src/controller/ha.c +++ b/src/controller/ha.c @@ -2996,6 +2996,64 @@ static int ha_apply_term_entry_via_library(ha_state_t *ha, persist_t *p, cluster_t *c, struct endpoint_t *ep, wal_catchup_entry_t *e) { + /* bug-1475 / bug-1466: resync the raft library's log_len from this node's + * OWN recovered/durable WAL tip before consuming the AE, exactly mirroring + * ha_sync_raft_log_from_recovery's boot-time computation (persist_durable_ + * floor), but applied live, JUST-IN-TIME, on this same single AE-receive + * call path — never touching persist.c or adding any new cross-thread + * mutation of ha->raft (ha_apply_wal_catchup_entry / this function already + * own that field on this thread, same as every other s->log_len write in + * the AE-receive path below). + * + * Root cause: persist_write_checkpoint_marker (a LOCAL-only, never- + * replicated WAL_CHECKPOINT entry written by ANY role — primary or + * standby — whenever a committed WAL_CONFIG_MARKER triggers an immediate + * checkpoint) advances persist_t's current_lsn directly, WITHOUT going + * through raft_log_append — so s->log_len silently falls one behind the + * true physical WAL tip for every checkpoint written since the last + * resync (documented gap, bug-1466). Once behind, the very next AE for + * the entry immediately following the checkpoint carries a prev_log_index + * equal to the checkpoint's own LSN (config_repl.c's streamer correctly + * advances its tracker across the skipped checkpoint) — but a stale + * s->log_len makes logOk's `prev_log_index <= s->log_len` bound fail + * forever, permanently wedging this standby's catch-up (every subsequent + * heartbeat re-streams the identical doomed range with zero progress). + * + * persist_durable_floor is a lock-free atomic read of durable_lsn (the + * flusher's own fsync-confirmed watermark, which DOES count a checkpoint's + * consumed LSN slot, same as at boot) — safe to call from any thread. The + * write below (raising ha->raft.log_len) happens on the same thread that + * already owns every other s->log_len mutation in this call chain + * (raft_on_append_entries_request), so no new lock is introduced. + * Monotonic: only ever raises log_len, mirroring + * ha_sync_raft_log_from_recovery exactly. Deliberately does NOT touch the + * term index (on_get_entry_term(checkpoint_lsn) stays 0/absent on every + * member, by design — see persist_write_checkpoint_marker's own comment) + * — recording a synthetic term here would risk a cross-member mismatch + * (each member's checkpoint stamps ITS OWN current term at write time, + * which need not agree with a peer's), whereas leaving it absent keeps + * the logOk equality check (0==0) trivially and SAFELY consistent on + * every member. + * + * bug-1475 follow-up: the "stays absent on every member" claim above only + * holds because persist.c's term index now uses a TERM_INDEX_UNSET + * sentinel to keep a never-explicitly-recorded LSN (like a checkpoint's) + * reading back absent PERMANENTLY. Before that fix, persist.c's array- + * growth zero-fill silently reclassified the checkpoint's gap slot as + * present-with-WAL_LEGACY_TERM the instant any LATER lsn was recorded — + * which happens immediately on the sender (it streams after its own + * later entries exist) but not yet on a receiver that hasn't appended + * past its own checkpoint, so the two sides read DIFFERENT terms for the + * SAME checkpoint LSN and logOk permanently rejected. See + * TERM_INDEX_UNSET's comment (persist.c) and + * test_bug1475_catchup_survives_midstream_checkpoint (test_config_repl.c) + * for the full mechanism and live-instrumentation evidence. */ + if (p) { + uint64_t recovered_tip = persist_durable_floor(p); + if (recovered_tip > ha->raft.log_len) + ha->raft.log_len = recovered_tip; + } + /* Wrap the single entry in an AE container whose TOP-LEVEL fields carry the * prev tuple + term that ha_consume_append_entries reads, with entries[0] * pointing at the entry itself (the same shape repl_send_append_entries / @@ -3488,10 +3546,12 @@ int ha_handle_snapshot_chunk(ha_state_t *ha, persist_t *p, * rather than silently surviving the install. Applies identically to * both a legacy (position-only) and an entity-bearing checkpoint — the * term reconcile is orthogonal to entity content. chunk->checkpoint_term - * == 0 means a legacy sender never stamped the wire field; persist's - * existing legacy-0 -> WAL_LEGACY_TERM convention (applied uniformly at - * read-back by persist_entry_term) already covers that case, so no - * special-casing is needed here. */ + * == 0 is unambiguous and means the checkpoint LSN is genuinely absent + * from the sender's own term index, never "legacy term 0, present" + * (bug-1475 Finding 2 — see persist_reconcile_checkpoint_term's own doc + * comment, persist.h). persist_reconcile_checkpoint_term itself + * special-cases a wire 0 to TERM_INDEX_UNSET before recording, so the + * receiver reads this LSN back as absent too, matching the sender. */ persist_reconcile_checkpoint_term(p, chunk->snapshot_lsn, chunk->checkpoint_term); diff --git a/src/controller/persist.c b/src/controller/persist.c index 8fb18d5b..112e1fbe 100644 --- a/src/controller/persist.c +++ b/src/controller/persist.c @@ -499,14 +499,37 @@ static void* fsync_worker(void* arg) * WAL term adapter (ha-term-safety task 1.3, R1.1/R1.5/R1.6/R1.7/R1.8) * * ------------------------------------------------------------------ */ +/* Sentinel stored in a term_index[] slot that has never been explicitly + * written by record_entry_term — distinct from a genuinely-recorded raw term + * of 0 (a legacy pre-term-safety entry, which maps to WAL_LEGACY_TERM at + * read-back). Reserved so growth (below) can leave a gap slot reading back as + * truly ABSENT forever, not just until the NEXT lsn happens to be recorded + * (bug-1475 follow-up: a WAL_CHECKPOINT slot is deliberately never recorded — + * see persist_write_checkpoint_marker's comment — but before this fix, the + * geometric-growth realloc for ANY later lsn zero-filled the checkpoint's own + * gap slot, and entry_term_locked's raw==0 rule then read that zero-fill back + * as WAL_LEGACY_TERM, not absent — silently and retroactively flipping a + * deliberately-unrecorded LSN's term the instant any later entry was + * appended. Confirmed via live instrumentation: persist_entry_term(checkpoint + * lsn) read back 0 (absent) immediately after the checkpoint, then 1 + * (WAL_LEGACY_TERM) once a later real entry was appended and grew the array + * past it — a time-of-check/time-of-use divergence between the sender (which + * scans/streams AFTER later entries exist) and a receiver that has not yet + * appended past the same checkpoint, causing logOk's prev_log_term equality + * check to spuriously mismatch (0 != 1) and permanently reject catch-up). */ +#define TERM_INDEX_UNSET UINT64_MAX + /* Record an entry's RAW hdr.term at its 1-based LSN in the in-memory per-LSN * term index (R1.5). Grows the index on demand; LSNs replay/append contiguously * so the array is dense (slot i == LSN i+1). Any gap left by a non-contiguous - * LSN (should not happen on the contiguous WAL) is zero-filled by realloc-then- - * memset, which read back as "absent" until/unless written. The raw term - * (including a legacy 0) is stored verbatim; the legacy-0 -> WAL_LEGACY_TERM - * mapping is applied only at READ-BACK (persist_entry_term), keeping "present - * legacy-0" distinguishable from "absent". + * LSN (e.g. a deliberately-skipped WAL_CHECKPOINT slot) is filled with the + * TERM_INDEX_UNSET sentinel by realloc-then-memset, which reads back as + * "absent" PERMANENTLY — regardless of whether a later LSN is subsequently + * recorded and grows term_index_count past it (bug-1475 follow-up; see + * TERM_INDEX_UNSET's comment). The raw term (including a legacy 0) is stored + * verbatim; the legacy-0 -> WAL_LEGACY_TERM mapping is applied only at + * READ-BACK (persist_entry_term), keeping "present legacy-0" distinguishable + * from "absent". * * Callers: the live append path (holds p->lock) and the single-threaded * recovery path (replay_wal — no other thread touches the index before the node @@ -531,8 +554,11 @@ static void record_entry_term(persist_t* p, uint64_t lsn, uint64_t term) "back as absent", lsn, p->term_index_cap, new_cap); return; } - /* Zero-fill the newly grown region so any unwritten slot reads absent. */ - memset(grown + p->term_index_cap, 0, + /* Fill the newly grown region with the UNSET sentinel (all-1s byte + * pattern, so memset can fill it directly) so any never-explicitly- + * written slot reads absent FOREVER, not just until term_index_count + * happens to grow past it (bug-1475 follow-up). */ + memset(grown + p->term_index_cap, 0xFF, (new_cap - p->term_index_cap) * sizeof(uint64_t)); p->term_index = grown; p->term_index_cap = new_cap; @@ -556,6 +582,11 @@ static uint64_t entry_term_locked(const persist_t* p, uint64_t lsn) return 0; if (lsn <= p->term_index_count && p->term_index != NULL) { uint64_t raw = p->term_index[lsn - 1]; + /* bug-1475 follow-up: a slot filled by growth but never explicitly + * recorded (e.g. a skipped WAL_CHECKPOINT lsn) stays absent forever — + * see TERM_INDEX_UNSET. */ + if (raw == TERM_INDEX_UNSET) + return 0; return (raw == 0) ? WAL_LEGACY_TERM : raw; } return 0; @@ -566,8 +597,11 @@ static uint64_t entry_term_locked(const persist_t* p, uint64_t lsn) * the on-disk entries above keep_lsn are removed, keeping the term index * consistent with the WAL: a later persist_entry_term on a truncated LSN must * return 0. The backing allocation is left as-is (only the live count moves); - * the zeroed-on-grow contract means a later re-append at those LSNs overwrites - * cleanly. Caller must hold p->lock. */ + * the TERM_INDEX_UNSET-sentinel-on-grow contract (bug-1475 follow-up — grown + * slots are filled with TERM_INDEX_UNSET, not zero, since this fix) means a + * later re-append at those LSNs still overwrites cleanly: record_entry_term + * always writes the slot explicitly, regardless of what fill value (zero or + * sentinel) it previously held. Caller must hold p->lock. */ static void truncate_term_index_locked(persist_t* p, uint64_t keep_lsn) { if (!p) @@ -624,15 +658,44 @@ uint64_t persist_entry_term_locked(const persist_t* p, uint64_t lsn) * check against this member ever references an LSN below the checkpoint * again (the checkpoint is the new log-start boundary), and the WAL bytes * below it were compacted away, so there is no data to reconstruct a full - * per-LSN history from even if it were needed. */ + * per-LSN history from even if it were needed. + * + * bug-1475 Finding 2 (coordinator review, 2026-07-27/28): checkpoint_term==0 + * on the wire is UNAMBIGUOUS today, not a legacy default to fall back to + * WAL_LEGACY_TERM. ha_snapshot_do_send (ha.c) — the only sender — computes + * this value via persist_entry_term(leader, checkpoint_lsn), whose public + * contract already collapses "absent" and "present raw-0 legacy" into + * DIFFERENT return values (0 vs WAL_LEGACY_TERM respectively — see + * entry_term_locked). A wire value of exactly 0 can therefore only mean + * "this sender's checkpoint LSN is genuinely, permanently absent" (the + * expected, designed state for ANY real checkpoint — persist_write_ + * checkpoint_marker never records a term for its own entry). Before this + * fix, record_entry_term(p, checkpoint_lsn, 0) stored a RAW 0 — an EXPLICIT + * write, not a growth-fill, so it never got the TERM_INDEX_UNSET sentinel — + * and entry_term_locked's legacy-0 rule then read it back as + * WAL_LEGACY_TERM(1) forever, permanently diverging from the sender's own + * permanently-absent(0) value for the SAME LSN: a subsequent AppendEntries + * whose prev_log_index==checkpoint_lsn (the entry immediately following it) + * then mismatched logOk (0 != 1) forever — the identical wedge class + * bug-1475 fixed for WAL-streaming catch-up, reachable instead via + * HA_REPL_SEND_SNAPSHOT (dispatched whenever a standby has fallen too far + * behind for incremental streaming — a live, common path). Recording the + * SAME TERM_INDEX_UNSET sentinel here (instead of raw 0) keeps a genuinely- + * absent checkpoint boundary reading absent on the receiver too, matching + * the sender — while a genuinely non-zero checkpoint_term (a real historical + * term, however it arrived on the wire) is still recorded verbatim and still + * correctly overwrites any stale local term at this LSN, unchanged. */ void persist_reconcile_checkpoint_term(persist_t* p, uint64_t checkpoint_lsn, uint64_t checkpoint_term) { if (!p || checkpoint_lsn == 0) return; + uint64_t stored_term = + (checkpoint_term == 0) ? TERM_INDEX_UNSET : checkpoint_term; + pthread_mutex_lock(&p->lock); - record_entry_term(p, checkpoint_lsn, checkpoint_term); + record_entry_term(p, checkpoint_lsn, stored_term); pthread_mutex_unlock(&p->lock); } diff --git a/src/controller/testsuite/test_config_repl.c b/src/controller/testsuite/test_config_repl.c index 967e9030..ecd044e9 100644 --- a/src/controller/testsuite/test_config_repl.c +++ b/src/controller/testsuite/test_config_repl.c @@ -4476,17 +4476,32 @@ static int capture_all_entries_wal_stream_hook(endpoint_t *ep, xce_request_t *re * checkpoint LSN; the live index must match"), never a logical Raft log * entry, and never sent on the live broadcast path either * (persist_wal_write_replicated rejects type==WAL_CHECKPOINT with -EINVAL). - * A standby receiving one gets stuck retrying the same LSN forever. * * Fixture: LSN [1..5], LSN 3 is a checkpoint marker (consumes a real LSN slot, * exactly like a live checkpoint firing mid-range). Streaming standby_lsn=0, - * committed_lsn=5 must emit exactly 4 real entries (1,2,4,5), never lsn=3, and - * the entry after the gap (lsn=4) must chain prev_log_index=2 (the last REAL - * entry before the gap), not 3. + * committed_lsn=5 must emit exactly 4 real entries (1,2,4,5), never lsn=3. * - * RED before the fix: the streamer builds/sends a catchup_entry for every - * hdr.type in range with no filter, so lsn=3/type=WAL_CHECKPOINT is included - * and lsn=4's prev_log_index is 3. + * bug-1475 (UPDATED, supersedes the original assertion): the entry after the + * gap (lsn=4) must now chain prev_log_index=3 -- the checkpoint's OWN lsn -- + * NOT 2 (the last real entry before it). The original assertion here (prev_ + * log_index=2, "not the skipped marker's lsn=3") encoded the OLD, DEFECTIVE + * design: a receiving standby that has itself already applied the same + * committed WAL_CONFIG_MARKER independently writes its OWN local checkpoint + * at the identical LSN (persist_write_checkpoint_marker runs deterministically + * on every member that applies the marker's commit, not just the sender), so + * the checkpoint's LSN is a real, HELD position on both sides -- not a gap to + * skip past. Never advancing the tracker across it left every subsequent + * prev_log_index permanently one below the receiver's true log length, + * producing a permanent post-checkpoint catch-up stall (ae_reject_logmismatch + * forever, zero progress every heartbeat) -- root-caused and fixed as part of + * bug-1475; see ha_apply_term_entry_via_library's bug-1475 fix (ha.c) for the + * matching receive-side co-tracking half of this fix, and + * test_bug1475_catchup_survives_midstream_checkpoint below for the full + * end-to-end (send+receive) regression proof. + * + * RED before the ORIGINAL bug (pre-existing, already fixed): the streamer + * built/sent a catchup_entry for every hdr.type with no filter at all, so + * lsn=3/type=WAL_CHECKPOINT itself was shipped as a real entry. */ static void test_wal_stream_skips_checkpoint_marker(void) { @@ -4519,15 +4534,20 @@ static void test_wal_stream_skips_checkpoint_marker(void) "no streamed entry may carry entry_type==WAL_CHECKPOINT"); } - /* Entries in order must be lsn 1,2,4,5 with lsn=4's prev_log_index=2 - * (the last real entry before the checkpoint gap, not the marker's lsn 3). */ + /* Entries in order must be lsn 1,2,4,5. */ TEST_ASSERT_EQUAL_UINT64_MESSAGE(1, g_cap_ckpt_lsn[0], "entry 0 must be lsn=1"); TEST_ASSERT_EQUAL_UINT64_MESSAGE(2, g_cap_ckpt_lsn[1], "entry 1 must be lsn=2"); TEST_ASSERT_EQUAL_UINT64_MESSAGE(4, g_cap_ckpt_lsn[2], "entry 2 must be lsn=4 (lsn=3 skipped)"); TEST_ASSERT_EQUAL_UINT64_MESSAGE(5, g_cap_ckpt_lsn[3], "entry 3 must be lsn=5"); - TEST_ASSERT_EQUAL_UINT64_MESSAGE(2, g_cap_ckpt_prev_idx[2], - "lsn=4 must chain prev_log_index=2 (the last real entry before the " - "checkpoint gap), not the skipped marker's lsn=3"); + /* bug-1475: lsn=4 must chain prev_log_index=3 -- the checkpoint's OWN lsn, + * which is a real HELD position on any receiver that independently + * applied the same committed marker -- NOT 2 (the stale, pre-fix value + * that permanently wedged catch-up one entry later; see the updated + * fixture doc comment above and test_bug1475_catchup_survives_ + * midstream_checkpoint for the full send+receive proof). */ + TEST_ASSERT_EQUAL_UINT64_MESSAGE(3, g_cap_ckpt_prev_idx[2], + "bug-1475: lsn=4 must chain prev_log_index=3 (the checkpoint's own " + "lsn, a real held position on both sides), not the stale lsn=2"); xce_wal_stream_request_hook = NULL; @@ -4537,6 +4557,216 @@ static void test_wal_stream_skips_checkpoint_marker(void) printf("test_wal_stream_skips_checkpoint_marker: PASS\n"); } +/* ══════════════════════════════════════════════════════════════════════════ + * bug-1475 — END-TO-END regression: a standby must NOT permanently stall + * catching up across a mid-stream WAL_CHECKPOINT. + * + * This drives all THREE parts of the fix together through the REAL production + * send+receive path — not just the sender's prev_log_index computation + * (already pinned above) in isolation: + * - SEND side (config_repl.c, ha_stream_wal_to_standby): the tracker now + * advances across a skipped WAL_CHECKPOINT instead of freezing one entry + * behind. + * - RECEIVE side (ha.c, ha_apply_term_entry_via_library): JIT-resyncs + * ha->raft.log_len from persist_durable_floor() before consuming each AE + * — mirroring ha_sync_raft_log_from_recovery's own boot-time computation, + * but applied live, on the same single AE-receive call path (no new lock, + * no cross-thread mutation) — so a receiver whose OWN local checkpoint + * write left log_len stale (bug-1466, deliberately NOT fixed at its root + * by this change) still correctly logOk-accepts the checkpoint's own lsn + * as a valid predecessor. + * - TERM-INDEX side (persist.c, record_entry_term/entry_term_locked): + * a THIRD, previously-undiscovered gap found by live instrumentation of + * THIS test after the first two fixes above still left it RED. The first + * two fixes both rely on `persist_entry_term(checkpoint_lsn)` staying + * "absent" (0) FOREVER on every member (documented design intent in both + * comments above and in persist_write_checkpoint_marker's own comment). + * That was false: record_entry_term's geometric-growth realloc zero-filled + * any skipped gap slot (e.g. the checkpoint's own, deliberately-unrecorded + * LSN), and entry_term_locked's `lsn <= term_index_count` presence check + * then read that zero-fill back as WAL_LEGACY_TERM (1), NOT absent (0), + * the INSTANT any LATER lsn was recorded and grew term_index_count past + * the gap — which happens immediately in this test (and in any live + * cluster) once the leader appends its next real entry after the + * checkpoint. This made the checkpoint LSN's "term" a TIME-DEPENDENT + * value: a fresh read right after the checkpoint returned 0 (absent, as + * designed), but the SAME read after a later entry was appended returned + * 1 — so the sender (which streams AFTER its own later entries exist) + * computed prev_log_term=1 for the entry right after the checkpoint, + * while a receiver that had not yet appended anything past its own + * checkpoint still (correctly, per design) read 0 for the same LSN — + * logOk's equality check then spuriously mismatched (0 != 1) and rejected + * forever. Fixed with a TERM_INDEX_UNSET sentinel (UINT64_MAX) that marks + * a never-explicitly-written slot as absent PERMANENTLY, independent of + * later array growth — see TERM_INDEX_UNSET's comment in persist.c for + * the full mechanism. Confirmed via real fprintf instrumentation at the + * streamer, the JIT resync, and raft.c's logOk check (added and removed + * during this investigation) that prev_log_term flipped from 0 to 1 + * exactly at the point lsn=4 was appended, before the persist.c fix; the + * same instrumentation confirmed prev_log_term=0 on both sides and + * log_ok=1 after the fix. + * + * Fixture: a REAL leader persist_t WAL [lsn=1 real, lsn=2 WAL_CHECKPOINT + * (via the real persist_checkpoint()), lsn=3 real, lsn=4 real]. A REAL + * receiver cluster_t independently applies the SAME committed prefix through + * lsn=1 and independently writes its OWN local checkpoint at lsn=2 (exactly + * mirroring persist_write_checkpoint_marker's deterministic per-member + * trigger — every member that applies a committed WAL_CONFIG_MARKER + * checkpoints at the identical LSN, not just the leader). The receiver's + * raft.log_len is left at its STALE, pre-checkpoint value (1) — the exact + * live-write-time gap bug-1466 documents (persist_write_checkpoint_marker + * bypasses raft_log_append, so log_len never advances for a checkpoint on + * its own) — this is the precondition the permanent stall needs. + * + * ha_stream_wal_to_standby streams (standby_lsn=2, committed_lsn=4] and a + * capture-and-replay hook feeds every batch into the REAL + * ha_apply_wal_catchup_entry receive entry point against the receiver — + * exactly the wire hop xce_decode → ha_apply_wal_catchup_entry performs live. + * + * RED (pre-fix, verified live during this investigation by reverting the + * persist.c term-index sentinel fix with the other two parts still in + * place): the receiver + * gets permanently stuck AT OR BEFORE the checkpoint boundary — lsn=3's + * prev_log_index is computed one below where the checkpoint actually left + * the receiver's log, so ha_apply_term_entry_via_library's accept-check + * (persist_entry_term(p, e->lsn) against the ACTUAL write position) never + * matches, no ACK is sent, and every subsequent entry's prev_log_index only + * grows further past the receiver's true (stale) log_len — ae_reject_ + * logmismatch forever, zero progress. A second stream of the IDENTICAL range + * makes IDENTICAL zero progress, proving the wedge is permanent, not a + * transient one-round lag. + * + * GREEN (post-fix): the receiver catches all the way up to lsn=4. + * ══════════════════════════════════════════════════════════════════════════ */ + +/* Bring a node up as a raft FOLLOWER at `term` (mirrors t42_make_leader, + * make_follower in test_term_safety_adapter.c — this file has no standby-role + * helper of its own yet). */ +static void t_bug1475_make_follower(cluster_t *c, uint64_t term, int n_peers) +{ + atomic_store(&c->ha.role, CTRL_STANDBY); + atomic_store(&c->ha.term, term); + ha_init_raft(&c->ha, c, n_peers); + c->ha.raft.term = term; + c->ha.raft.role = RAFT_FOLLOWER; +} + +/* Replay-into-receiver hook: feeds every streamed batch into the REAL + * ha_apply_wal_catchup_entry receive path against g_bug1475_recv, exactly as + * the wire hop (xce_decode) would on a live connection. */ +static cluster_t *g_bug1475_recv = NULL; + +static int bug1475_replay_hook(endpoint_t *ep, xce_request_t *req) +{ + (void)ep; + if (!req || !req->body.walcatchupentrymsg || !g_bug1475_recv) + return 0; + wal_catchup_entry_t *batch = + (wal_catchup_entry_t *)req->body.walcatchupentrymsg; + ha_apply_wal_catchup_entry(&g_bug1475_recv->ha, &g_bug1475_recv->persist, + batch, /*ep*/NULL, g_bug1475_recv); + return 0; +} + +static void test_bug1475_catchup_survives_midstream_checkpoint(void) +{ + char ltmp[256], rtmp[256]; + strcpy(ltmp, "/tmp/xce_cr_b1475_leader_XXXXXX"); + strcpy(rtmp, "/tmp/xce_cr_b1475_recv_XXXXXX"); + TEST_ASSERT_NOT_NULL(mkdtemp(ltmp)); + TEST_ASSERT_NOT_NULL(mkdtemp(rtmp)); + + cluster_t *leader = t42_make_cluster(ltmp); + cluster_t *recv = t42_make_cluster(rtmp); + TEST_ASSERT_NOT_NULL(leader); + TEST_ASSERT_NOT_NULL(recv); + + enum { TERM = 3 }; + t42_make_leader(leader, TERM, /*n_peers=*/3); + t_bug1475_make_follower(recv, TERM, /*n_peers=*/3); + + /* Identical prefix on both members through lsn=1. persist_wal_async is a + * raw WAL write and does not itself update raft.log_len (that only + * happens via ha_primary_log_append/raft_log_append on the real commit + * path) -- both members already correctly hold index 1 (e.g. from a + * prior, successful AE exchange this test does not need to re-simulate), + * so both are seeded here to match. */ + persist_set_term(&leader->persist, TERM); + TEST_ASSERT_EQUAL_INT(0, + persist_wal_async(&leader->persist, WAL_JOB_UPDATE, NULL, 0)); /* lsn=1 */ + leader->ha.raft.log_len = 1; + persist_set_term(&recv->persist, TERM); + TEST_ASSERT_EQUAL_INT(0, + persist_wal_async(&recv->persist, WAL_JOB_UPDATE, NULL, 0)); /* lsn=1 */ + recv->ha.raft.log_len = 1; + + /* Each member independently checkpoints at lsn=2 -- the SAME deterministic + * side effect persist_checkpoint_marker_triggered fires on every member + * that applies a committed WAL_CONFIG_MARKER, not just the leader. Force a + * synchronous flush right after so persist_durable_floor() (which the + * ha.c bug-1475 fix reads) reflects it immediately rather than waiting on + * the background fsync_worker's own timer (cfg.wal_sync_ms=5000). */ + TEST_ASSERT_EQUAL_INT(0, persist_checkpoint(&leader->persist)); /* lsn=2 */ + TEST_ASSERT_EQUAL_INT(0, persist_flush(&leader->persist)); + TEST_ASSERT_EQUAL_INT(0, persist_checkpoint(&recv->persist)); /* lsn=2 */ + TEST_ASSERT_EQUAL_INT(0, persist_flush(&recv->persist)); + + /* bug-1466 (unfixed, deliberately NOT touched by this fix): the checkpoint + * write bypassed raft_log_append on BOTH members, so log_len stayed at 1 + * on both even though current_lsn moved to 3 -- exactly the precondition + * the live permanent stall needs. */ + TEST_ASSERT_EQUAL_UINT64(1, leader->ha.raft.log_len); + TEST_ASSERT_EQUAL_UINT64(1, recv->ha.raft.log_len); + TEST_ASSERT_EQUAL_UINT64(3, (uint64_t)leader->persist.current_lsn); + TEST_ASSERT_EQUAL_UINT64(3, (uint64_t)recv->persist.current_lsn); + + /* Leader appends two more REAL entries after the checkpoint. */ + persist_set_term(&leader->persist, TERM); + TEST_ASSERT_EQUAL_INT(0, + persist_wal_async(&leader->persist, WAL_JOB_UPDATE, NULL, 0)); /* lsn=3 */ + TEST_ASSERT_EQUAL_INT(0, + persist_wal_async(&leader->persist, WAL_JOB_UPDATE, NULL, 0)); /* lsn=4 */ + atomic_store_explicit(&leader->persist.committed_lsn, 4, + memory_order_release); + + /* Drive the REAL catch-up streamer -> REAL receive path. standby_lsn=2: + * this receiver already durably holds through the checkpoint's own lsn. */ + g_bug1475_recv = recv; + xce_wal_stream_request_hook = bug1475_replay_hook; + int rc = ha_stream_wal_to_standby(/*ep=*/NULL, leader->persist.wal_path, + &leader->persist, /*leader_term=*/TERM, + /*standby_lsn=*/2, /*committed_lsn=*/4); + xce_wal_stream_request_hook = NULL; + g_bug1475_recv = NULL; + TEST_ASSERT_EQUAL_INT_MESSAGE(0, rc, "ha_stream_wal_to_standby failed"); + + uint64_t applied = atomic_load_explicit(&recv->ha.applied_lsn, + memory_order_acquire); + TEST_ASSERT_EQUAL_UINT64_MESSAGE(4, applied, + "bug-1475: the standby must catch all the way up to lsn=4 across the " + "mid-stream checkpoint, not stall permanently at/before it"); + TEST_ASSERT_EQUAL_UINT64(4, recv->ha.raft.log_len); + TEST_ASSERT_EQUAL_UINT64(TERM, persist_entry_term(&recv->persist, 4)); + + /* A SECOND identical stream (the real heartbeat-driven retry) must be a + * clean no-op / re-confirmation, never regress applied_lsn -- proving + * this is genuine convergence, not a one-round fluke. */ + g_bug1475_recv = recv; + xce_wal_stream_request_hook = bug1475_replay_hook; + rc = ha_stream_wal_to_standby(/*ep=*/NULL, leader->persist.wal_path, + &leader->persist, /*leader_term=*/TERM, + /*standby_lsn=*/4, /*committed_lsn=*/4); + xce_wal_stream_request_hook = NULL; + g_bug1475_recv = NULL; + TEST_ASSERT_EQUAL_INT(0, rc); + TEST_ASSERT_EQUAL_UINT64(4, atomic_load_explicit(&recv->ha.applied_lsn, + memory_order_acquire)); + + t42_teardown(leader); + t42_teardown(recv); + printf("test_bug1475_catchup_survives_midstream_checkpoint: PASS\n"); +} + /* * bug-1028 — the catch-up streamer must source each streamed entry's term and * the AppendEntries prev_log_term from the AUTHORITATIVE per-LSN term index @@ -4687,6 +4917,219 @@ static void test_snapshot_transfer_two_chunks(void) printf("test_snapshot_transfer_two_chunks: PASS\n"); } +/* ══════════════════════════════════════════════════════════════════════════ + * bug-1475 Finding 2 (coordinator review, 2026-07-27/28): the SAME permanent + * catch-up wedge bug-1475 fixed for WAL-streaming catch-up, reachable + * instead via the SNAPSHOT-INSTALL path (HA_REPL_SEND_SNAPSHOT — dispatched + * whenever a standby has fallen too far behind for incremental streaming, a + * live, common path, not dead code). + * + * ha_snapshot_do_send (ha.c) computes checkpoint_term = persist_entry_term( + * leader, checkpoint_lsn) — which, thanks to bug-1475's TERM_INDEX_UNSET + * fix, is now PERMANENTLY 0 (absent) for any real checkpoint LSN + * (persist_write_checkpoint_marker never records a term for its own entry, + * by design). Before THIS fix, ha_handle_snapshot_chunk's + * persist_reconcile_checkpoint_term(p, checkpoint_lsn, checkpoint_term) + * wrote that 0 RAW into the term index via an EXPLICIT record_entry_term + * call (not a growth-fill) — so entry_term_locked's legacy-0 rule read it + * back as WAL_LEGACY_TERM(1), NOT absent, permanently diverging from the + * leader's own permanently-absent(0) value for the IDENTICAL LSN. A + * subsequent AppendEntries whose prev_log_index==checkpoint_lsn (the entry + * immediately following it) then mismatched logOk (0 != 1) forever. + * + * RED (pre-fix, verified by temporarily reverting persist_reconcile_ + * checkpoint_term's TERM_INDEX_UNSET substitution): the receiver's + * checkpoint-boundary term reads back 1 (WAL_LEGACY_TERM), not 0, and the + * subsequent AppendEntries is rejected — applied_lsn never reaches 3. + * GREEN (post-fix): the receiver's checkpoint-boundary term reads back 0 + * (absent, matching the leader), and the subsequent AppendEntries is + * accepted. + * ══════════════════════════════════════════════════════════════════════════ */ + +static cluster_t *g_bug1475f2_recv = NULL; + +static int bug1475f2_snapshot_replay_hook(endpoint_t *ep, xce_request_t *req) +{ + (void)ep; + if (!req || !req->body.snapshottransfermsg || !g_bug1475f2_recv) + return 0; + snapshot_transfer_t *chunk = + (snapshot_transfer_t *)req->body.snapshottransfermsg; + return ha_handle_snapshot_chunk(&g_bug1475f2_recv->ha, + &g_bug1475f2_recv->persist, + g_bug1475f2_recv->persist.snap_path, + chunk, chunk->raw_payload, + chunk->raw_payload_len); +} + +static void test_bug1475_finding2_snapshot_install_checkpoint_term_absent(void) +{ + char ltmp[256], rtmp[256]; + strcpy(ltmp, "/tmp/xce_cr_b1475f2_leader_XXXXXX"); + strcpy(rtmp, "/tmp/xce_cr_b1475f2_recv_XXXXXX"); + TEST_ASSERT_NOT_NULL(mkdtemp(ltmp)); + TEST_ASSERT_NOT_NULL(mkdtemp(rtmp)); + + cluster_t *leader = t42_make_cluster(ltmp); + cluster_t *recv = t42_make_cluster(rtmp); + TEST_ASSERT_NOT_NULL(leader); + TEST_ASSERT_NOT_NULL(recv); + + extern int (*xce_snapshot_chunk_hook)(endpoint_t *, xce_request_t *); + extern int ha_send_snapshot_to_standby(endpoint_t *, const char *, + uint64_t, uint64_t); + + enum { TERM = 5 }; + t42_make_leader(leader, TERM, /*n_peers=*/3); + t_bug1475_make_follower(recv, TERM, /*n_peers=*/3); + /* ha_handle_snapshot_chunk takes ha->lock directly; t42_make_cluster / + * ha_init_raft never call pthread_mutex_init on it (only the AE-receive + * path is exercised by the OTHER bug-1475 test, which never locks it) — + * initialize it explicitly here rather than relying on a zeroed mutex + * happening to behave like PTHREAD_MUTEX_INITIALIZER. */ + pthread_mutex_init(&recv->ha.lock, NULL); + + /* Leader: a real entry at lsn=1, then a REAL checkpoint at lsn=2 via + * persist_checkpoint -> persist_write_checkpoint_marker (the exact + * production path — not a synthetic marker). + * + * p->checkpoint_lsn is NOT the WAL_CHECKPOINT entry's own physical lsn — + * persist_checkpoint() (the general/periodic form ha_snapshot_do_send + * actually calls) labels the snapshot with last_applied_lsn, read + * immediately AFTER persist_write_checkpoint_marker has already + * consumed the next lsn slot for the checkpoint itself. In a + * continuously-active system checkpoint_lsn is usually one BELOW the + * checkpoint's own physical lsn (the last real entry applied so far); + * Finding 2 requires the specific (real, reachable) quiescent-state + * timing where the apply pump has already walked all the way through + * and landed exactly ON the checkpoint's own lsn (persist_apply_pump_run + * advances last_applied_lsn one lsn at a time, INCLUDING a no-op pass + * over a WAL_CHECKPOINT slot, before this snapshot-send cycle runs) — + * e.g. right after a config upgrade with no immediate follow-up + * activity. Seed that precondition directly (deterministic; the real + * race depends on independent apply-pump timing this test does not + * need to reproduce) so persist_checkpoint()'s OWN checkpoint_lsn + * coincides with the checkpoint entry's own un-recorded lsn — exactly + * the case where persist_entry_term(checkpoint_lsn) reads genuinely + * absent. */ + persist_set_term(&leader->persist, TERM); + TEST_ASSERT_EQUAL_INT(0, + persist_wal_async(&leader->persist, WAL_JOB_UPDATE, NULL, 0)); /* lsn=1 */ + TEST_ASSERT_EQUAL_UINT64(2, (uint64_t)leader->persist.current_lsn); + atomic_store_explicit(&leader->persist.last_applied_lsn, 2, + memory_order_release); + TEST_ASSERT_EQUAL_INT(0, persist_checkpoint(&leader->persist)); /* lsn=2 */ + TEST_ASSERT_EQUAL_INT(0, persist_flush(&leader->persist)); + TEST_ASSERT_EQUAL_UINT64_MESSAGE(2, leader->persist.checkpoint_lsn, + "precondition: checkpoint_lsn must coincide with the checkpoint " + "entry's own physical lsn for this test to exercise Finding 2 " + "(otherwise it would read a real, non-absent term instead)"); + + /* Leader appends one more real entry AFTER the checkpoint — mirrors the + * real timing that exposed Finding 2 (persist_entry_term(checkpoint_lsn) + * read right after the checkpoint vs. after later growth exists). */ + persist_set_term(&leader->persist, TERM); + TEST_ASSERT_EQUAL_INT(0, + persist_wal_async(&leader->persist, WAL_JOB_UPDATE, NULL, 0)); /* lsn=3 */ + + /* Precondition: exactly what ha_snapshot_do_send's real computation + * would read for the wire — genuinely absent (0), permanently, even + * after later growth (TERM_INDEX_UNSET's whole point). */ + uint64_t checkpoint_term = + persist_entry_term(&leader->persist, leader->persist.checkpoint_lsn); + TEST_ASSERT_EQUAL_UINT64_MESSAGE(0, checkpoint_term, + "precondition: a real checkpoint LSN's term reads absent (0) on the " + "sender, even after later entries exist — the exact value " + "ha_snapshot_do_send would put on the wire"); + + /* Drive the REAL snapshot send -> receive path: ha_send_snapshot_to_standby + * chunks the on-disk snapshot file (written by persist_checkpoint above) + * and stamps checkpoint_term on every chunk; the capture-and-replay hook + * feeds each chunk into the REAL ha_handle_snapshot_chunk on the + * receiver, exactly the wire hop a live transfer performs. */ + g_bug1475f2_recv = recv; + xce_snapshot_chunk_hook = bug1475f2_snapshot_replay_hook; + int rc = ha_send_snapshot_to_standby(/*ep=*/NULL, leader->persist.snap_path, + leader->persist.checkpoint_lsn, + checkpoint_term); + xce_snapshot_chunk_hook = NULL; + g_bug1475f2_recv = NULL; + TEST_ASSERT_EQUAL_INT_MESSAGE(0, rc, "ha_send_snapshot_to_standby failed"); + TEST_ASSERT_EQUAL_UINT64(leader->persist.checkpoint_lsn, + recv->persist.checkpoint_lsn); + + /* The receiver must reconcile the checkpoint boundary LSN's term to + * match the leader's — genuinely absent (0), NOT WAL_LEGACY_TERM(1). */ + TEST_ASSERT_EQUAL_UINT64_MESSAGE(0, + persist_entry_term(&recv->persist, leader->persist.checkpoint_lsn), + "bug-1475 Finding 2: the receiver's checkpoint-boundary term must " + "reconcile to absent (0), matching the leader's permanently-absent " + "value for the SAME lsn — NOT get reinterpreted as " + "WAL_LEGACY_TERM(1) by persist_reconcile_checkpoint_term's " + "record_entry_term(..., 0) call"); + + /* Isolate Finding 2's term-index concern from two OTHER, SEPARATE, + * pre-existing (unchanged by this fix) mechanics this test is not about: + * + * 1. ha_handle_snapshot_chunk does not itself resync ha->raft.log_len + * (only ha_apply_term_entry_via_library's JIT resync does, on the + * NEXT AE) — set it directly to the checkpoint's own lsn here, the + * value a real deployment reaches once durable_lsn catches up (or a + * later boot-reseed runs). + * 2. load_snapshot() sets p->current_lsn = stored_lsn (the checkpoint's + * OWN lsn), NOT stored_lsn + 1 — confirmed via direct instrumentation + * (current_lsn read back as 2, matching checkpoint_lsn, immediately + * after this install). persist_wal_write_replicated's forward-gap + * guard (lsn > current_lsn -> EAGAIN) would then reject ANY entry at + * checkpoint_lsn+1 regardless of term, confounding this test's + * specific term question. Whether that current_lsn convention + * correctly bridges into the next live catch-up cycle in production + * is a DIFFERENT, pre-existing question this test does not answer — + * flagged here, not fixed (out of Finding 2's scope: the coordinator's + * review identified a term(0-vs-1) mismatch specifically, not a + * current_lsn contiguity gap). Bypass it directly so only the term + * question is under test. */ + recv->ha.raft.log_len = leader->persist.checkpoint_lsn; + recv->persist.current_lsn = leader->persist.checkpoint_lsn + 1; + + /* Drive a REAL subsequent AppendEntries whose prev_log_index is the + * checkpoint's own LSN — the entry immediately following it. */ + wal_catchup_entry_t sub; + memset(&sub, 0, sizeof(sub)); + sub.lsn = 3; + sub.entry_type = WAL_JOB_UPDATE; + sub.term = TERM; + sub.prev_log_index = leader->persist.checkpoint_lsn; /* == 2 */ + sub.prev_log_term = checkpoint_term; /* == 0, absent */ + sub.leader_current_term = TERM; + + wal_catchup_entry_t *sub_arr[1] = { &sub }; + wal_catchup_entry_t batch; + memset(&batch, 0, sizeof(batch)); + batch.n_entries = 1; + batch.entries = sub_arr; + batch.term = TERM; + batch.prev_log_index = sub.prev_log_index; + batch.prev_log_term = sub.prev_log_term; + + rc = ha_apply_wal_catchup_entry(&recv->ha, &recv->persist, &batch, + /*ep*/NULL, recv); + TEST_ASSERT_EQUAL_INT(0, rc); + + TEST_ASSERT_EQUAL_UINT64_MESSAGE(3, + atomic_load_explicit(&recv->ha.applied_lsn, memory_order_acquire), + "bug-1475 Finding 2: the standby must accept the AppendEntries " + "immediately following the checkpoint boundary after a snapshot " + "install, not permanently reject it (ae_reject_logmismatch) due to " + "a term(0) vs term(1) mismatch at the checkpoint LSN"); + TEST_ASSERT_EQUAL_UINT64(TERM, persist_entry_term(&recv->persist, 3)); + + pthread_mutex_destroy(&recv->ha.lock); + t42_teardown(leader); + t42_teardown(recv); + printf("test_bug1475_finding2_snapshot_install_checkpoint_term_absent: PASS\n"); +} + static void test_snapshot_transfer_small_less_than_one_chunk(void) { char tmpdir[] = "/tmp/xcectest_snaptrans_XXXXXX"; @@ -5964,9 +6407,11 @@ void test_config_repl(void) RUN_TEST(test_wal_stream_partial_batch); RUN_TEST(test_wal_stream_empty_range_no_batches); RUN_TEST(test_wal_stream_skips_checkpoint_marker); + RUN_TEST(test_bug1475_catchup_survives_midstream_checkpoint); /* bug-1475 */ RUN_TEST(test_wal_stream_term_from_index_not_raw_hdr); /* bug-1028 */ /* Task 3.5: snapshot chunk transfer (sender side) */ RUN_TEST(test_snapshot_transfer_two_chunks); + RUN_TEST(test_bug1475_finding2_snapshot_install_checkpoint_term_absent); /* bug-1475 Finding 2 */ RUN_TEST(test_snapshot_transfer_small_less_than_one_chunk); RUN_TEST(test_snapshot_transfer_stops_and_propagates_send_failure); /* Task 3.5c: standby snapshot receive handler */ diff --git a/src/include/persist.h b/src/include/persist.h index 231c293a..103b02b1 100644 --- a/src/include/persist.h +++ b/src/include/persist.h @@ -660,12 +660,18 @@ uint64_t persist_entry_term_locked(const persist_t* p, uint64_t lsn); * checkpoint against this member again, so only the checkpoint LSN's own * term needs reconciling — not the full compacted history below it. * - * `checkpoint_term == 0` means a legacy sender (pre-task-3.2 peer) never - * stamped the wire field; treat that as WAL_LEGACY_TERM per the existing - * legacy-0 convention (record_entry_term stores the raw value verbatim; the - * legacy-0 -> WAL_LEGACY_TERM mapping is applied uniformly at read-back by - * persist_entry_term/entry_term_locked, so this call is consistent with that - * convention without needing to special-case it here). + * `checkpoint_term == 0` is unambiguous and means the checkpoint LSN is + * genuinely/permanently absent from the term index, never "legacy term 0, + * present" (bug-1475 Finding 2: the sole sender, ha_snapshot_do_send, always + * computes this value via persist_entry_term, whose own contract already + * returns the distinct WAL_LEGACY_TERM for any present-but-legacy-0 entry — + * so a wire value of exactly 0 can only mean absent). This call substitutes + * TERM_INDEX_UNSET for a wire 0 before recording, instead of the raw value, + * so entry_term_locked reads the checkpoint LSN back as absent on the + * receiver too, matching the sender — recording the raw 0 here (the old + * behavior) let it read back as WAL_LEGACY_TERM instead, permanently + * diverging from the sender's own absent(0) and wedging the next + * AppendEntries whose prevLogIndex lands on this LSN. * * Takes p->lock internally (callers must NOT already hold it). Safe on a * NULL p or checkpoint_lsn == 0 (no-op). */