diff --git a/.kiro/specs/raft-ha-core-safety/research.md b/.kiro/specs/raft-ha-core-safety/research.md index 736362a..b6151bb 100644 --- a/.kiro/specs/raft-ha-core-safety/research.md +++ b/.kiro/specs/raft-ha-core-safety/research.md @@ -128,3 +128,77 @@ Three critical issues raised and folded into design.md (GO): 3. **Hypothesis-validation risk.** RED gate (7.1) must reproduce the *live* `walcompare` divergence and bisect to a seam before synthetic `(term,lsn)` injection counts; baseline 21e26a1 already retired live term-0 (ha-term-safety 3.4), so the term-blind path may not be the live trigger. Contingency: if soak still diverges after Path-2 closure, re-classify via `walcompare (term,lsn,pcrc)` and add a fix task — do not mark R1/R8 done on green unit tests alone. Updated: §Deterministic Chaotic Harness, Testing E2E + RED-first. Verdict: **GO** (unconditional after edits). Architecture unchanged; refinements were bounded contract clarifications. + +--- + +# Task 1.3 — Live divergence reproduction & bisect + +_Generated by the task-1.3 investigation subagent (REPRODUCE + CLASSIFY + BISECT). Evidence-backed; no production code changed. Real-fs (ext4) `~/tmp`, non-ASAN release binaries `src/build.release/controller/{xce_controller,xce_test}` (built 08:48 this day)._ + +## TL;DR / VERDICT + +**The design's primary "term-blind catch-up bypass" hypothesis is REFUTED for the reproduced live committed divergence.** The divergent committed entry has the **CORRECT term**, was ingested **through** the single library reconcile seam (`ae_append` → `on_persist_entry`), and the LSN-only idempotency no-op was **not** the mechanism. The real defect is **payload loss on cross-term catch-up**: a committed `JOB_SUBMIT` entry is persisted on the catching-up member with `payload_len=0` (empty body) while its `(term, lsn)` are correct. It is a sibling of the bug-795/828/1060 committed-prefix-loss family, located in the **catch-up replication payload path**, not in the `(term,lsn)`/idempotency-guard seam Phase 2 currently targets. + +## Commands run & reproduction status + +- Two `--chaotic` soak attempts via `run-ha-soak.sh` (rounds=6, `XCE_HA_BIN/XT` → release binaries, dir `~/tmp/ha-1p3`) **both aborted at cold-start** with `FAIL: no primary elected within 45s`. A `--sequential` attempt failed identically. +- **This cold-start "election stall" is a HARNESS/LOG-BUFFER ARTIFACT, not a consensus stall.** Evidence: in every aborted run a primary WAS elected on time (e.g. `ctrl-1 → CTRL_PRIMARY (term=2)` logged ~15s after start, `quorum_reached`), yet `wait_for_primary_log` never tripped. All three nodes' last log line is the identical cleanup-kill timestamp (= start+45s): the 08:48 release build **block-buffers its `--logfile` and only flushes on signal**, so the harness's log-grep primary detection (`latest_primary_term`) cannot observe progress live. The OLD binaries used by the prior passing sequential soaks (`~/tmp/xce-soak-{rel,bl}.log`, 02:56/03:01) did not have this buffering behaviour. The client (`ctrlstatus`) path is unaffected. +- **Reproduced cleanly** by driving the cluster with a client-based (log-buffer-immune) driver (`scratchpad/drive.sh`, fresh deploy `~/tmp/ha19`, sequential kill→restart→re-elect, 6 rounds). Committed-prefix divergence appeared by round 1 and persisted: round 1 LSN 8 (present=2), round 2 LSN 8 (present=2), **round 3 LSN 9 (present=3 — all members hold it but disagree)**. Driver wedged at round 4 on a transient quorum loss; the frozen WAL dirs were classified directly. + +## walcompare --report classification (frozen `~/tmp/ha19`, `--committed 25`) + +Decisive divergence — **committed LSN 9, class=committed, compared=3, present=3** (every member holds the entry; they disagree on payload): + +``` +WALCMP_DIVERGENCE lsn=9 class=committed compared=3 present=3 + member 0 (ctrl-1): term=3 pcrc=00000000 <-- MINORITY / divergent + member 1 (ctrl-2): term=3 pcrc=512dc5b5 <-- majority + member 2 (ctrl-3): term=3 pcrc=512dc5b5 <-- majority +``` + +Same pattern at committed LSN 10 (ctrl-1 pcrc=0 vs majority 06e88dac) and LSN 11 (ctrl-1 pcrc=0 vs majority fea75587). **Term is identical (3) across all three members; only the payload-CRC diverges.** (ctrl-3 additionally shows `status=MISSING` for LSN 12-19 — a separate catch-up-lag/convergence gap from the round-4 quorum loss, bug-1042 family, not the payload defect.) + +Raw `waldump` confirms the payload loss, not a term mismatch: + +``` +ctrl-1 (divergent): 9 | 3 | JOB_SUBMIT | PLEN=0 | 00000000 | jobid=? +ctrl-2/ctrl-3 (maj): 9 | 3 | JOB_SUBMIT | PLEN=3560 | 512dc5b5 | jobid=0-0-1782550813-0 ... +``` + +The origin is intact — both majority members hold the full 3560-byte body with a decodable jobid; **ctrl-1 lost the payload bytes during catch-up while keeping the correct type (JOB_SUBMIT) and term (3).** + +## Bisect — the concrete ingest path + +ctrl-1's `--logfile` (fully flushed post-kill) traces exactly how it acquired the divergent entries: + +1. ctrl-1 was the term-1 cold-start primary (wrote LSN 1-7), killed round 1, **restarted round 2** (`persist_recover done — recovered durable_floor=7 current_lsn=8`). It then needed LSN 8-onward. +2. `09:00:13` — term-3 leader ctrl-3 streamed catch-up `op 37 walCatchupEntry`, but starting at `prevIdx=8` (entry 9) while ctrl-1 only held up to 7 → library `ae_reject_logmismatch`, `ha_consume_append_entries … success=0`. Nothing written. (ctrl-3 then died — round 2 failover.) +3. `09:00:26` — new term-4 leader ctrl-2 streamed `op 37 walCatchupEntry` from `prevIdx=7`. The **library accepted and APPENDED**: `RAFT[p0] term=4 event=ae_append`, `ha_consume_append_entries … prevIdx=7 n=1 → success=1 match=8`, then match=9, 10, 11, 12. These were **fresh appends through the reconcile seam (`on_persist_entry`)**, not idempotent no-ops (current_lsn was 8 immediately prior). LSN 9-11 landed with `payload_len=0`. +4. In the SAME catch-up, LSN 13-15 (stored term=4, the streaming leader's OWN term) landed with FULL payloads. **Signature: same-term catch-up preserves payload; cross-term catch-up of prior-term entries (stored term 3 streamed under leader term 4) drops it.** + +Code-path mapping (read at the research anchors): +- Receiver `ha_consume_append_entries` (ha.c:2410-2440) copies the body **unconditionally** (`if (payload && plen>0) memcpy(...)`, ha.c:2438) from `e->raw_payload`/`e->raw_payload_len`. So the empty body **arrived empty on the wire** → the loss is SEND-side / source-side, not in the seam's persist. +- Both documented send paths nominally read the payload: batch streamer `ha_stream_wal_to_standby` (config_repl.c:2154-2161, `pread` when `hdr.payload_len>0`, and sets `entry->term = persist_entry_term(...)` + `entry->leader_current_term = leader_term`, config_repl.c:2130-2151) and the single-entry `on_send_append_entries` → `ha_read_wal_entry_at` (ha.c:1611-1640). Neither *statically* drops a cross-term payload — so the loss is either (a) the streaming leader (ctrl-2) **itself held an empty copy at stream time** and the full payload was reconciled into ctrl-2's WAL only later (a transitive empty-propagation across the failover chain), or (b) the wire encode/decode of the body for these messages. Distinguishing (a) vs (b) requires one instrumented run capturing per-entry `payload_len` at the leader's send and at the receiver's `on_persist_entry` for a cross-term LSN — see "Implied next work". + +## Why the term-blind hypothesis is refuted here + +- Predicted by design.md ROOT CAUSE: `entry->term==0` → `ha_apply_single_entry` (ha.c:2097) → `persist_wal_write_replicated` DIRECT, **wrong term** (standby's `p->term`), idempotency no-op of the later correct entry. +- Observed: the entry's **term is correct (3)**, it was ingested via `ha_apply_term_entry_via_library` → `ha_consume_append_entries` → `on_persist_entry` (the term-carrying LIBRARY seam, `event=ae_append`), and the catch-up was a **fresh append** (no idempotency-guard no-op involved). The streamer stamps a non-zero term (config_repl.c:2141), so the `term==0` → `ha_apply_single_entry` branch (ha.c:2253/2291 gate `sub->term != 0`) is not taken for these entries. + +## VERDICT + +- **Term-blind catch-up bypass (wrong-term + LSN-only idempotency no-op): REFUTED** as the trigger of the reproduced live committed divergence. +- **Actual trigger: payload-loss on cross-term catch-up** — committed `JOB_SUBMIT` entries persisted with `payload_len=0` (term/type correct) on a member that catches up prior-term entries from a higher-term leader; the divergence is a **payload-CRC mismatch at an identical `(term,lsn)`**, in the committed prefix. A member carrying this can (and in round 3 did) become primary, so it is a silent committed-state corruption in the bug-795/828/1060 family. + +## Implied next work (steers Phase 2) + +1. **Re-scope the Phase-2 fix away from the term-stamp/idempotency seam.** Collapsing Path-2 into Path-1 (design D3/D1) will NOT fix this divergence — the entry already goes through Path-1 with the correct term. The fix must target the **catch-up payload source-of-truth**: add an instrumented capture of `payload_len` at `ha_stream_wal_to_standby`/`on_send_append_entries` (send) and `on_persist_entry` (receive) for cross-term LSNs to prove send-side empty vs transitive-empty, then fix whichever drops/propagates the empty body. +2. **Harden the persist conflict guard to be `(term,lsn,payload)`-aware**, not term-only: a committed `(term,lsn)` whose payload-CRC disagrees with the quorum must be detected/repaired (or the member fenced), since term-only reconcile is blind to this class. +3. **Fix the divergence detector / RED gate to assert payload-CRC at committed LSN even when terms match** (it already does via `pcrc`; keep `walcompare --report (term,lsn,pcrc)` as the canonical RED classifier — it caught this). +4. **R6/Harness defect (secondary):** the release build's log buffering defeats `run-ha-soak.sh`'s log-based `wait_for_primary_log`/`primary_from_log` primary detection (false "election stall"). The chaotic acceptance gate (R8) needs client-based (`ctrlstatus`) primary detection, or the controller must line-buffer/flush its INFO log, before the soak can run unattended on release binaries. + +## Evidence artifacts (under ~/tmp, ephemeral) + +- `~/tmp/ha19/` — frozen 3-member deploy with the reproduced LSN 9/10/11 payload divergence (`controller/ctrl-{1,2,3}/data`, `logs/ctrl-1.log`). +- `~/tmp/ha19-drive.log` — driver round-by-round output (divergence first seen round 1). +- `~/tmp/ha-1p3-run{1,2}.log`, `~/tmp/ha-1p3-seq.log` — the cold-start log-buffer "stall" runs. diff --git a/.kiro/specs/raft-ha-core-safety/tasks.md b/.kiro/specs/raft-ha-core-safety/tasks.md index 45339af..17b87fe 100644 --- a/.kiro/specs/raft-ha-core-safety/tasks.md +++ b/.kiro/specs/raft-ha-core-safety/tasks.md @@ -19,7 +19,7 @@ - _Requirements: 7.5, 8.4_ - _Boundary: Acceptance Soak Gate, Deterministic Chaotic Harness_ -- [ ] 1.3 Reproduce and classify the live divergence, then bisect to a seam +- [x] 1.3 Reproduce and classify the live divergence, then bisect to a seam - Run the chaotic soak to capture the actual `walcompare` committed-prefix divergence (RED), classify it via `(term, lsn, pcrc)` (which member, which term, committed vs uncommitted), and bisect it to the concrete ingest path; confirm or refute the term-blind-bypass hypothesis - Observable completion: a recorded RED divergence with member/term/lsn classification and the identified seam, written to `research.md`; the hypothesis is confirmed or a new trigger is named before any fix - _Requirements: 7.1, 1.1_