fix(raft-apply-decoupling): kill-mid-fact-stream soak + close bug-1416 boot-time TOCTOU (task 7.2)
Adds --factstream HA soak mode driving real jstart/jfinish/jfail worker-fact traffic against a live 3-node cluster, killing the primary mid-stream and asserting zero committed-state divergence and zero phantom fact reactions. Building this scenario surfaced bug-1416: persist_recover()'s boot-time apply-correctness verification can race the live apply pump and the standby live-replication apply path, both of which mutate the same last_applied_lsn/ job-table state the verification re-reads live -- producing a false APPLY_DIVERGENT that permanently fences an otherwise-healthy node. Fixed with a new persist_t.recovery_complete gate that defers only the in-memory apply (never the durability write or replication ACK) while a recovery pass is in flight, closed from the earliest safe point in myapp_run() so an election- retry candidate can't apply live traffic before persist_recover() ever runs. Round-2 adversarial review independently verified the ACK/durability paths stay ungated, reproduced the myapp.c fix as load-bearing via revert-and- reproduce, and confirmed real-divergence detection still fires. Live 3-node factstream soak: 2/2 rounds PASS, zero APPLY_DIVERGENT across 5 recover calls. controller_unit_test: zero new failures across 23 groups.
This commit is contained in:
parent
5f98d1b0ef
commit
a5e29a6ffa
17 changed files with 74793 additions and 156 deletions
|
|
@ -9,6 +9,11 @@
|
|||
<!-- How the user likes things done. Code style, tools, patterns, communication. -->
|
||||
|
||||
## Key Learnings
|
||||
- (2026-07-04, raft-apply-decoupling task 6.1 round 2 — job-state merge-staleness fix) Round 1's `apply_committed_entry` wired the live pump but left a real corruption: `record_job_fail_fact`/`record_job_update_fact` (job.c) precomputed a FINAL absolute state at RECEIPT time (a scratch-copy merge for FAIL, an inline backstop+PDONE merge for postdone) and baked it into `wal_jobstate_t.state`; under deferred apply, a second fact for the same job (e.g. FINISH) could apply BETWEEN receipt and this fact's own apply, making the baked snapshot stale — a POST_EXEC-stage FAIL received while a job is still `RUN` (FINISH not yet applied) bakes `RUN|EXIT|PERR`, and when FINISH applies first (`DONE`) then FAIL's blind absolute overwrite clobbers it back to `RUN|EXIT|PERR` — DONE silently lost. FIX PATTERN: `wal_jobstate_t._pad` (previously always-zero, unused) is repurposed as a discriminator — `_pad==0` still means "legacy absolute state, safe" (job_ctrl's mark_job_fail/mark_job_update paths, which mutate+capture state synchronously under one lock, no staleness window); a nonzero `_pad` (`WAL_JOB_FAIL_STAGE_FLAG|stage` for FAIL, `WAL_JOB_UPDATE_POSTDONE_MARK` for postdone) marks "recompute at apply time against ACTUAL current state" — `apply_committed_entry` (persist.c) dispatches on this bit per WAL type, calling the REAL `apply_job_fail_transition`/new `apply_job_postdone_transition` (job.c, mirrors the existing guard-core family) instead of `apply_job_update_transition`'s blind overwrite. New low-level `persist_submit_job_fact_ex(p, type, jobid, state, pad)` added as the primitive; `persist_submit_job_fact` becomes a pad=0 thin wrapper — ZERO existing call sites (including ~20 in test_commit_barrier_reply.c) needed touching. GENERAL PATTERN for "wire format has 2 producers, one safe one not": don't change the safe producer's shape — add a discriminator field/flag so the consumer can tell them apart, and make "0"/"absent" mean exactly the old/safe behavior so every existing writer keeps working unchanged.
|
||||
- (2026-07-04, same task) Fixing a wire-format bug INSIDE a task's own scope can break pre-existing tests that assert the wire format directly (not just behavior) — 2 tests in test_commit_barrier_reply.c (`test_guard_forward_update_on_terminal_preserved`, `test_guard_fail_after_finish_preserves_perr_merge`) read the raw on-disk `wal_jobstate_t.state` via a helper (`cbrp_count_jobstate_entries`) and asserted DONE/PDONE/PERR bits directly on it — exactly the field this fix stops populating for FAIL/postdone. These are NOT the "old apply-before-commit ordering" tests task 7.3 owns (a different axis — ordering vs wire-format) — they are a DIRECT, in-scope, mechanical consequence of the wire-format fix itself, so I fixed them here rather than deferring: extended the helper to a `_ex` variant returning `_pad` too (existing helper becomes a thin wrapper, zero other call sites touched — same pattern as persist_submit_job_fact_ex), changed the wire-level assertions to check the new `_pad` marker, and added a direct call to the guard core (`apply_job_fail_transition`/`apply_job_postdone_transition`) on a scratch `job_t` to keep pinning the actual merge semantics the test was written to protect. A 3rd test (`test_fact_state_unchanged_throughout_quorum_loss_outage`) had the identical `st_upd` bit-check for postdone; fixed the same way (already had a `(void)st_fail` precedent in the same file for exactly this "order-dependent, can't check at receipt time" reasoning — extended it to `st_upd`/`pad_upd`). Lesson: when a task's fix legitimately changes what a durable record contains, grep for every DIRECT byte/field-level test assertion on that record (not just behavioral tests) before declaring the regression sweep clean — `grep cbrp_count_jobstate_entries` found them, `--run test_apply_pump` alone would not have.
|
||||
- (2026-07-04, same task) RED-phase verification for a bugfix already merged into the same commit as its own regression test (no separate "before" commit to check out) — reverted the exact 2 production hunks in-place (record_job_fail_fact's scratch-copy computation + apply_committed_entry's WAL_JOB_FAIL case ignoring `_pad`) using Edit, confirmed the new test fails with the EXACT predicted corrupted value (`Expected 264 Was 262` = DONE|PERR vs RUN|EXIT|PERR, byte-for-byte matching the hand-derived bug trace), then restored from a pre-saved `cp` snapshot of the fixed files and `diff`-verified byte-identical restoration before rebuilding GREEN. Combined with the existing longjmp-past-teardown lesson (isolate the new test alone in RUN_TEST via `#if 0` during the revert-and-check step, restore full list after) — both techniques compose cleanly.
|
||||
- (2026-07-04, same task) **Do-not-repeat**: this repo has TWO independently-built `controller_unit_test` binaries — `src/build/controller/controller_unit_test` (correct, incremental, what `ninja -C build` from `src/` updates) and `../build/controller/controller_unit_test` i.e. repo-root `build/` (a STALE separate build tree from an earlier/different session — NOT updated by the `src/`-relative ninja command). Running `../build/controller/controller_unit_test` after rebuilding via `ninja -C build` silently executes stale, unrelated test binaries — symptom observed: a `--run test_apply_pump` invocation printed exactly 3 tests (the pre-round-2 test count) with `PASS` for all, at line numbers that didn't match the current file, right after a successful rebuild that should have produced 4 tests. Always verify with `strings build/controller/controller_unit_test | grep <new_test_name>` (or check `ls -la --full-time` / mtimes) when a test run's output looks suspiciously like an older version of the suite — don't trust "the build succeeded" alone to mean "the binary I'm about to run reflects it." ALWAYS run `./build/controller/controller_unit_test` (relative, from `src/`), never `../build/...`.
|
||||
- (2026-07-04, same task) Observed a rare (~1/50 runs) flake in `test_apply_pump_fail_racing_finish_merges_against_current_state` where the final job state read back as the untouched SEEDED value (job never mutated at all) despite every prior assertion (including `committed_lsn == watermark`) passing — i.e. the covering ACK genuinely advanced `committed_lsn` but the inline (NULL-pool fallback) apply-pump walk apparently didn't mutate the job that pass. Reproduced 1 time in ~55 total runs across 3 batches; the identical ACK+inline-pump trigger mechanism is shared with round-1's already-reviewer-verified `test_apply_pump_kick_applies_committed_burst_in_ascending_lsn_order`, which never flaked in the same sampling — inconclusive whether this is environmental (system load during rapid repeated `nix develop` shell spin-up) or a genuine rare race in `persist_apply_pump_run`/`commit_resolve_pending`'s kick path (both explicitly out of this task's remit, verified-correct by the round-1 reviewer). Flagged in the status report as a CONCERN, not fixed — the fix logic itself (`apply_job_fail_transition`/`apply_job_postdone_transition`/the `_pad` dispatch) is pure and time-independent, so this does not implicate the round-2 correctness fix specifically.
|
||||
- (2026-07-03, raft-apply-decoupling task 1.5) Wrote the concurrency unit tests closing task-group 1: `test_commit_resolve.c` gained 3 new tests (a genuine multi-threaded admission-cap burst using a sampling monitor thread; a mixed majority-ack+timeout burst using a `bounded_pool_setup` helper that DECOUPLES the continuation registry's capacity from the vtaskmgr pool's real worker-thread count so "bounded worker usage" is a meaningful, non-trivial assertion via `pthread_equal`-based distinct-thread counting; and a nice-to-have genuine two-real-thread majority-wins-over-timeout race relying on `commit_advance_locked`'s `pthread_cond_broadcast` to wake the sweep thread early). The demotion- and truncation-triggered burst cases were placed in `test_demotion_convergence.c` and `test_persist_truncate.c` INSTEAD of `test_commit_resolve.c`, reusing those files' existing `dc_setup`/`make_fresh_persist` fixtures rather than duplicating a full `cluster_t` fixture — keeps each file's fixture cohesive; design.md's file-plan wording ("test_commit_resolve.c covers demotion/truncation admission behavior") is better read as describing task-group 1's aggregate coverage, not a literal single-file mandate. IMPORTANT DISCOVERY: bug-1407 (`test_commit_advance_retry_clears_push_before_commit_fence`, test_config_repl.c), which task 1.4's notes closed as "70/70 passing, 3/3 runs", is REOPENED — it now fails 100% of the time (10/10), confirmed on BOTH the task-1.5 working tree AND a `git stash`-clean checkout of the task-1.4 commit with zero task-1.5 changes applied (i.e. genuinely pre-existing on the current tree, not caused by this task's test-only diff). Do not trust a prior task's "CLOSED, N/N runs" bug verdict at face value when validating a later task in the same task-group — always re-run the specific regression yourself before citing it as settled, especially for a concurrency-adjacent flake with no isolated root cause.
|
||||
- (2026-07-03, raft-apply-decoupling task 1.4) Wired demotion + log-truncation to resolve pending commit continuations as FAILED. TWO call sites, TWO different idioms, deliberately: (1) **demotion** — `raft_cb_become_follower`'s existing `if (prior_role == CTRL_PRIMARY && c != NULL)` hook-disable block (ha.c) now also calls the new `commit_resolve_pending_above(&c->commit, 0, -XCE_ERR_STANDBY)` directly — ha.c is already a direct consumer of commit.c's public API elsewhere (commit_set_writable_lsn etc.), so a direct call is idiomatic there; lsn_floor=0 means "all pending" (a demoted node can never commit ANYTHING it had pending — there is no partial-floor case, unlike truncation). (2) **truncation** — used the SAME inversion-of-control pattern as the existing durable-advance wake (`persist_set_durable_cb`/`on_durable_advance`) rather than calling commit.c from ha.c/persist.c's 3 real truncate call sites (`raft_cb_become_leader`'s post-election truncate, `ha_cb_truncate_from_stub`'s conflict-reconcile, `ha_demotion_convergence_fn`'s post-demotion truncate) individually: added `persist_set_truncate_cb`/`on_truncate`/`truncate_cb_ctx` to persist_t, registered by `commit_engine_init` (`commit_on_truncate` → `commit_resolve_pending_above(ce, cutoff_lsn, -ENOENT)`), fired ONCE from the single shared `persist_truncate_wal_above` wrapper (never `truncate_wal_above_locked`, which runs under `p->lock` — the callback must fire AFTER `pthread_mutex_unlock(&p->lock)`, checked via `after < before` on `current_lsn`, mirroring the flusher's `after > before` durable-advance guard EXACTLY) — this is DRY (one wiring point catches all 3 real+future truncate callers) and preserves the documented "persist.c never depends on commit.c" direction. `-XCE_ERR_STANDBY` (demotion) and `-ENOENT` (truncation) reuse the exact rc vocabulary `test_commit_resolve.c`'s task-1.2 author had already picked in `test_commit_resolve_delivers_failed_outcome_for_{demotion,truncation}` — do not invent new codes when an existing test file has already established the vocabulary for a not-yet-wired scenario. New commit.c/h function `commit_resolve_pending_above(ce, lsn_floor, rc)`: snapshot-then-resolve under `ce->lock` (mirrors `commit_resolve_pending`'s shape exactly), resolves every `lsn > lsn_floor`, exactly-once via `commit_resolve`'s own idempotent slot-clear.
|
||||
- (2026-07-03, RED-verification hazard with Unity + threaded fixtures — reusable gotcha) Proving a genuinely-RED test in THIS harness by temporarily reverting production code and running the WHOLE test group (`--run <group>`) can HANG the process, even though the identical group passes cleanly once GREEN. Root cause: Unity's `TEST_ASSERT_*` macros `longjmp` out of the failing test function on the FIRST failed assertion, which SKIPS any teardown code written after that assertion in the same function (e.g. `dc_teardown()` at the end of a test in test_demotion_convergence.c) — so a thread-owning fixture (a `commit_engine_t` with its task-1.3 sweep thread, a persist flusher thread) is never joined/freed. The NEXT `RUN_TEST` in the same process then calls the SAME group's `setup()` which does `memset(&fixture, 0, sizeof(fixture))` on a struct a live orphaned thread still references — corrupting a mutex/cond mid-use and hanging (observed: 0% CPU, process alive, no output, indefinitely). FIX for RED verification (not a product bug — never manifests in GREEN, since teardown runs normally when assertions pass): temporarily edit the suite's `RUN_TEST` list down to JUST the one new test (wrap the rest in `#if 0`/`#endif`), rebuild, confirm the single isolated failure, then revert the RUN_TEST list back before restoring the production fix. Reusable rule: whenever a fixture under test owns a background thread AND you need to prove RED via a real (not calling-the-helper-directly) test, isolate that ONE test in the group during the revert-and-check step — do not run the full group against reverted production code.
|
||||
|
|
@ -88,6 +93,7 @@
|
|||
- (2026-06-13) OPERATIONAL: controller meson test wrapper ROUTINELY hits its 300s timeout under load (barrier commit-deadline waits) — `Timeout: 1` is NOT a failure. Authoritative green = direct binary `src/xce.build/controller/controller_unit_test` (EXIT 0, every group "N Tests 0 Failures"). A pre-existing ~153KB suite-wide LSan leak is SUPPRESSED by `ASAN_OPTIONS=detect_leaks=0` at controller/meson.build:163 — LSan exit=1 only appears on a RAW direct-binary run without that env; baseline, reproduces at pre-spec commits, not a per-change regression.
|
||||
- (2026-06-14, reserve-lsn-0 / bug-543 FIX) LSN 0 is now RESERVED as the none/empty sentinel — `persist_init()` sets `current_lsn = 1` on a fresh store (persist.c, the ONLY fresh-init site; recovery overwrites from snapshot/WAL tip). First-ever WAL entry (promotion NOOP) is lsn 1. This was a ONE-LINE production change + a comment block; everything downstream ALREADY treated 0 as "none/empty" and lsn>=1 as real, so NO change was needed in commit.c (highest_appended_lsn `current_lsn>0?-1:0`, commit_submit rejects lsn 0, wait_done writable_lsn==0=gate-off), the streamer (`hdr.lsn>standby_lsn`: 1>0=true now streams the first entry → no hole), ha.c own-term gate (noop_lsn=current_lsn-1=1, writable_lsn=1 effective), or the wire/capnp format. The pre-alloc zero-region sentinel `hdr.lsn==0 && type==0 && payload_len==0` (persist.c:874, config_repl.c:1580, truncate:1666) is STRENGTHENED — no real entry is ever lsn 0. Segment naming follows current_lsn at open time, so the first segment is `seg-...001.wal` (not 000); recovery/truncate scan by sscanf, no hard-coded seg-000 assumption.
|
||||
- (2026-06-14, reserve-lsn-0 TEST FALLOUT) Base-shift broke tests that did a "priming append so the entry lands at LSN >= 1" — that priming was ONLY to escape the old lsn-0 special-case and is now redundant. Fix = REMOVE the priming append so the real entry lands at lsn 1 (test_commit_engine tests 32/34, test_commit_barrier_rollout fact-hook, test_commit_barrier_reply cbrp_setup, test_p2_integration single_node) OR bump a hard-coded `current_lsn==1` assertion to `==2` if the priming must stay (test_egress_filter ef_setup). The ENGINE-LESS walAck path only "worked" via `repl_wait_majority_ack`'s `entry_lsn==0 → return 0` hatch (repl.c:437); with the first entry now lsn 1 it routes to `commit_submit(ce=NULL)` → -EINVAL, so engine-less commit tests MUST wire a commit engine (test_p2_integration test 9: added commit_engine_init(n_peers=3) + repl_set_commit_engine + commit_engine_fini). Tests asserting RELATIVE lsn (lsn_before+1, current_lsn>0, h1.lsn>h0.lsn) or byte-offset truncation math are base-shift-immune.
|
||||
- (2026-07-03, raft-apply-decoupling task 3.3) `test_commit_barrier_reply.c`'s `cbrp_setup` fixture wires job submission's commit continuations through a SEPARATE standalone `commit_engine_t g_hce` (via `commit_engine_init(&g_hce, &g_hc.persist, ...)` + `repl_set_commit_engine`), NOT through `cluster_t`'s own embedded `c->commit` field. This matters because `raft_cb_become_follower`'s demotion branch (ha.c:1395) calls `commit_resolve_pending_above(&c->commit, 0, -XCE_ERR_STANDBY)` — i.e. it operates on `c->commit`, the field `g_hce` deliberately bypasses. So `raft_cb_become_follower_with_cluster_for_test(&g_hc, term)` CANNOT be used to force a job-submission continuation FAILED in this file's harness — it would touch the wrong (never-initialized, all-zero) engine. `persist_truncate_wal_above(&g_hc.persist, cutoff)` has no such problem: `persist_set_truncate_cb` is wired directly by `commit_engine_init` onto whichever engine you pass it (here, `g_hce`), so truncation is the ONLY viable way to force a deterministic, explicit non-timeout FAILED outcome (`-ENOENT`) for a job-submit continuation in this specific fixture. Added 4 tests exercising this (single + repeated truncation-forced FAILED, repeated timeout-forced FAILED, array mixed-outcome) — all GREEN on first run (no bug found; task 3.2's failure-path guarantee holds). Generic demotion-resolve-continuations-FAILED behavior already has its own dedicated coverage in `test_demotion_convergence.c` (task 1.4/1.5), which uses `ha_promote_to_primary` + the cluster-aware `_for_test` seam against a REAL `c->commit`-shaped fixture — reuse THAT file, not this one, for anything demotion-specific.
|
||||
- (2026-06-13, kiro-impl process) A RED-only test pin is only valid if its OWN impl task can turn it green via the SAME seam the test drives. Misfires caught in review: boot-replay pin RED on an lsn-0 `replay_wal` skip artifact; hooks pin via the `c==NULL` raft shim where `ha_register_persist_hooks(&c->hooksys)` can never run (re-point to the real-cluster `ha_promote_to_primary` seam). Deleting machinery → DELETE the machinery-subject tests (design "no shims, rewritten or deleted not stubbed"), never add file-local no-op stubs. Unity runner prints the PREVIOUS passing test's file:line as a stale prefix on FAIL lines → attribute failures by test NAME.
|
||||
|
||||
## Do-Not-Repeat
|
||||
|
|
@ -369,3 +375,51 @@ Swept 7 old "not yet fixed" buglog entries (846, 847, 855, 1096, 1147, 1198, 130
|
|||
|
||||
## Key Learning (2026-07-03, bug-847 investigation) — trace the actual library mechanism before trusting a plausible-sounding root-cause hypothesis
|
||||
A prior investigation (and a fresh subagent re-investigation) both converged on "the encoder captures a capnp segment pointer once outside a loop and reuses it stale across iterations" as bug-847's root cause — plausible-sounding, cites real code (`cs = capn_root(&c).seg;` before a `for` loop in `xce_wal_batch_encode_raw`, src/lib/request.c). Tracing the ACTUAL c-capnproto library (`new_object`/`new_data`/`write_ptr`/`capn_setp` in the vendored `capn.c`) showed this is a non-issue by design: `new_object` always re-resolves and re-tags `.seg` on segment overflow regardless of what stale segment pointer was passed in, and `write_ptr`/`capn_setp` correctly emit far/double-far pointers whenever the source and target objects land in different segments. The theory was never tested against the library source, only against the observed symptom — and the observed symptom (RED test failure) turned out to no longer reproduce at all once actually run. Lesson: a hypothesis that "sounds mechanistically right" and cites real line numbers is not the same as a verified root cause — for a data-loss bug specifically, always run the existing/write a NEW regression test before accepting a hypothesis, even one two independent investigations agreed on.
|
||||
|
||||
## Key Learning (2026-07-04, raft-apply-decoupling task 5.3) — `recovery_unrecoverable`'s clear path is LIVE-catch-up-only, not recovery-driven; apply_divergent has no live self-heal yet
|
||||
`persist_clear_recovery_unrecoverable()` (persist.c) has ZERO call sites inside persist.c itself — its only two callers are in ha.c (`promotion_fence_timeout_fn` ~ha.c:867, and the promotion-eligibility gate ~ha.c:1115), both gated on STRUCTURAL getters (`persist_recovery_truncated`/`persist_durable_floor` vs cluster HWM) that can genuinely change while a process stays up (a fenced standby keeps receiving replicated WAL from a healthy peer). `persist_recover()`'s own APPLY_CLEAN branch never calls the clear function — a second, later `persist_recover()` call reaching APPLY_CLEAN does NOT auto-clear a sticky flag set by an earlier APPLY_DIVERGENT verdict on the same object. This is correct by design (task 5.2's decision table fences apply_divergent unconditionally specifically because more WAL bytes/catch-up can't prove a local apply-dispatch defect is fixed) but means: today, the apply_divergent-triggered fence has no LIVE self-heal analogue to the structural fence's catch-up-timer release — it only "clears" via a full process restart into a fresh `persist_t` (persist_init defaults `recovery_unrecoverable=false`) that then replays cleanly. Task 6 (ordered apply pump) is where a live re-verification analogue would need to be built if ever wanted. Don't assume "the fence auto-clears like the structural one" for this trigger without checking which mechanism (live re-check vs restart) actually applies.
|
||||
|
||||
## Key Learning (2026-07-04, raft-apply-decoupling task 5.3 round-2, CLOSED) — the trigger-agnostic sticky-fence bug: fix the guard on BOTH live-clear call sites, not just one
|
||||
Round-1 review found a CRITICAL gap: `persist_recovery_unrecoverable` is a bare boolean with no provenance about WHY it was set — task 5.2 added `apply_divergent` as a new trigger reusing the existing sticky flag, but the flag's two pre-existing LIVE clear call sites (`promotion_fence_timeout_fn` ha.c:~867, and `raft_cb_become_leader`'s promotion-eligibility gate ha.c:~1109) both only ever checked STRUCTURAL conditions (`persist_recovery_truncated`/`persist_durable_floor` vs HWM) — never the apply verdict. Since a WAL can be structurally perfectly healthy (not truncated, durable_floor>=HWM) while the local apply-dispatch path is still defective (APPLY_DIVERGENT — the two are orthogonal by construction), the structural timer would eventually observe "healthy" and silently clear an apply-divergence fence, letting a genuinely divergent node get promoted on its NEXT election. FIX (additive, ~30 lines, both call sites in ha.c): added `bool apply_divergent = persist_apply_verdict(&c->persist) == APPLY_DIVERGENT;` at each site and ANDed `!apply_divergent` into the existing enclosing `if` condition that gates the clear (`if (!truncated && !below_hwm && !apply_divergent)` in the timer; `if (gate==ELIGIBLE && !unrecoverable && !apply_divergent)` in the promotion gate). **Key design insight**: gating just the bare `persist_clear_recovery_unrecoverable(...)` call-statement itself is NOT sufficient at the become_leader site — the safety-critical action there is falling through to `CTRL_PRIMARY` promotion, not the clear call (which in production can only be reached when `unrecoverable` already reads false); you must extend the ENCLOSING branch condition that also gates promotion, or the fix is a no-op that still promotes a divergent node while merely skipping a redundant flag-clear. Added to `promotion_fence_timeout_fn`'s guard anyway (timer site) since it DOES flip true→false there and is the actually-exploitable half. Since `apply_verdict` is only ever recomputed by `persist_recover()` (boot-time-once, single call site `cluster.c:1451`), this guard means an apply-divergent fence can now ONLY clear via a full process restart that replays cleanly — never a live timer/gate. Regression test `test_promotion_fence_apply_divergent_survives_structural_catchup` (test_commit_durability.c) mirrors `test_promotion_fence_released_on_catchup`'s exact harness/timing, differing only in also forcing `c->persist.apply_verdict = APPLY_DIVERGENT` + `recovery_unrecoverable=true` up front — confirmed RED (fence wrongly cleared) against the pre-fix code, GREEN after. All 3 required suites pass with 0 regressions: test_commit_durability 39/39, test_apply_correctness_verification 11/11, test_ha_core_safety 28/28. [[project_bug1060_leader_completeness]]
|
||||
|
||||
## Do-Not-Repeat (2026-07-04, sticky-flag-with-multiple-triggers pattern)
|
||||
When a shared sticky/latching flag gains a NEW trigger reason (reusing an existing mechanism, as instructed by a design doc's "don't build a new mechanism" guidance), always audit EVERY existing call site that CLEARS or CHECKS that flag for whether it silently assumes the OLD trigger's semantics (e.g. "clearable once structural conditions are healthy"). A flag with no provenance field is only as safe as the least-restrictive clear site — adding a new, stricter-to-clear trigger without updating every clearer creates exactly this class of bug. Grep for all callers of the clear function FIRST (`grep -n "persist_clear_recovery_unrecoverable" src/controller/ha.c` found exactly 2, matching the reviewer's claim precisely) rather than trusting a blast-radius/paraphrased caller count.
|
||||
|
||||
## Key Learning (2026-07-04, raft-apply-decoupling task 5.3 round-3, CLOSED) — a logically-correct guard with a green suite can still have zero coverage; prove it by reverting the guard, not by reading the code
|
||||
Round-2's `!apply_divergent` conjunct at the `raft_cb_become_leader` promotion-eligibility gate (ha.c:1130) was independently verified LOGICALLY correct twice, yet reverting ONLY that conjunct left all 298 pre-existing tests green — no test ever drove a node that was simultaneously (a) structurally ELIGIBLE (`ha_promotion_gate_decision` genuinely returns `RECOVER_DECISION_ELIGIBLE`), (b) NOT sticky-fenced (`persist_recovery_unrecoverable()==false`), AND (c) `apply_verdict==APPLY_DIVERGENT`. Closed by adding `test_promotion_refused_when_apply_divergent_even_if_eligible` to `test_convergence_verification.c`, reusing `test_promotion_registers_standbys_when_peer_set`'s exact `cv_setup` fixture (n_peers=2, n_standbys=0, appended_lsn=0 — this fixture is PROVEN to reach genuine ELIGIBLE because that sibling test's own assertion, `repl_active_standby_count==2` after promotion, is unreachable unless the gate let promotion through) and forcing only `c->persist.apply_verdict = APPLY_DIVERGENT` before calling `raft_cb_become_leader_with_cluster_for_test`. RED→GREEN confirmed by temporarily deleting the `&& !apply_divergent` conjunct in-place, rebuilding, observing exactly 1 failure (the new test, on the promotion-refused assertion), then restoring and reconfirming 0 failures. Full 13-group / 299-test regression (all files touching `raft_cb_become_leader`) stayed green throughout. **Lesson**: "the reviewer traced the boolean logic and it's correct" and "a regression test exists that would catch a revert of this exact line" are different claims — always close a coverage gap by demonstrating the RED failure, not by re-reading the code once more. **Environment note**: contrary to a round-2 flag about a possible openssl/flake.nix issue in this worktree, `nix develop --command bash -c "ninja -C ../build ..."` from `src/` built cleanly with no header-path problems — that concern did not reproduce here.
|
||||
|
||||
## Key Learning (2026-07-04, raft-apply-decoupling task 6.1, CLOSED) — the "detail-filter" fix for a dual-origin hook detail is a trap; use call-provenance instead
|
||||
Hazard 1 (task 4.1's double-append warning) named `HOOK_DETAIL_JOB_UPDATE` as the risky detail once `apply_committed_entry()` goes live, and the obvious-sounding fix is "early-return `persist_job_hook_fun` when `detail == HOOK_DETAIL_JOB_UPDATE`". That fix is WRONG: `job_ctrl`'s SIGCONT/SIGSTOP path (`mark_job_update`, job.c:498/508) fires the IDENTICAL detail for its own still-legitimate live append, and a detail-based filter would silently break job-suspend/resume durability with zero test failure to catch it (no existing test exercises job_ctrl's WAL append in isolation). The correct fix is a call-PROVENANCE guard: a `_Thread_local bool t_apply_seam_notifying` set only around `apply_committed_entry()`'s own `xce_run_hooks()` calls, checked by `persist_job_hook_fun`/`persist_queue_hook_fun`/`persist_worker_hook_fun`. Thread-local (not a shared `persist_t` field) because a shared flag races across the apply-pump thread and any concurrent live command thread touching a DIFFERENT job. Lesson: when a hook detail is dual-origin (one AFTER_EVENT firing point that both a legacy live-command path and a new apply-seam path share), filtering on the detail value is never safe — filter on which CALL STACK is asking.
|
||||
|
||||
## Key Learning (2026-07-04, raft-apply-decoupling task 6.1) — commit_resolve_pending is the ONE choke point for ALL SIX committed_lsn-advance paths; wiring a new trigger only into ha.c's on_commit_advanced silently starves single-node/self-quorum clusters
|
||||
design.md's File Structure Plan says to wire the live apply pump from ha.c's `on_commit_advanced` callback. That callback is fed by exactly ONE of the six commit.c-internal paths that can move `committed_lsn` (durable-advance, self-quorum `commit_submit`, ack-driven `commit_on_ack`, the writable-lsn gate, the raft-library commit-index feed, membership change) — task 1.2 already discovered and consolidated all six into `commit_resolve_pending()`. Wiring the apply-pump kick ONLY into ha.c would leave 5 of 6 paths never triggering it — concretely, most unit-test fixtures (n_peers<=1 self-quorum, no raft library wired) would NEVER see the pump fire. Wired the kick into `commit_resolve_pending()` itself instead (one new line, `persist_apply_pump_kick(ce->p, ce->pool)`, after its existing resolve loop) — a documented, deliberate deviation from design.md's literal text, justified by this discovery. Lesson: when a design doc names ONE integration point for "whenever X changes," check whether X actually has multiple internal advance paths before trusting that single named point is complete — grep for every writer of the field.
|
||||
|
||||
## Do-Not-Repeat (2026-07-04, raft-apply-decoupling task 6.1) — a retry-until-caught-up drain loop MUST distinguish "no more work" from "the same failed work is still there"
|
||||
`apply_pump_drain()`'s first version cleared the scheduled flag, rechecked `last_applied_lsn+1 <= committed_lsn`, and reclaimed+looped if true — without checking whether the PRECEDING `persist_apply_pump_run()` call actually made progress. When a WAL read genuinely fails (e.g. a test fixture advances `committed_lsn` without real WAL bytes on disk for that LSN), `last_applied_lsn` never advances, so the recheck ALWAYS sees identical unresolved work and reclaims the flag forever — an unbounded tight busy-loop (18.5M+ log lines before a 90s timeout killed the process in `test_demotion_convergence`). Fixed by checking the walk's return code immediately: a negative rc returns without rechecking or reclaiming, so a genuinely new future kick (a distinct commit-advance event) is what retries, never the drain loop's own tail. Lesson: any "loop until caught up, recheck before exiting to avoid a lost wakeup" idiom (task 1.3's precedent) MUST also handle "the loop body failed and made zero progress" as a THIRD outcome, distinct from both "caught up" and "genuinely more work" — otherwise the recheck-for-lost-wakeup safety mechanism itself becomes an infinite-retry hazard the moment the underlying operation can fail.
|
||||
|
||||
## Key Learning (2026-07-04, raft-apply-decoupling task 6.1) — Hazard 2 (merge-staleness) is real, immediately exploitable under ordinary traffic, and requires a wire-format change; it was escalated as BLOCKED, not silently shipped
|
||||
Traced `apply_job_start_transition` (`job->job.state = JOB_STAT_RUN`, a full overwrite to a FIXED constant, discarding any other bits) and confirmed different job-state fact types need genuinely different apply semantics: START overwrites-to-fixed-value, FINISH/FAIL/UPDATE are guard-then-set, RESUME needs to CLEAR a bit (not just OR one in). A naive fix (change the shared `apply_job_update_transition` core from overwrite to OR-merge) would silently break RESUME's clear semantics on both replay and any live re-apply — trading one correctness bug for another. Since the wire format (`wal_jobstate_t{jobid,state}`) carries ONLY the final computed value, not which bits a given fact intends to set vs. clear vs. leave alone, no in-boundary fix exists without either (a) a wire-format change (delta/mask encoding) or (b) a receipt-time per-job serialization gate (a much bigger architectural change, arguably violating Req 11.4's "no per-fact synchronous barrier"). Escalated as a BLOCKED-severity, carried-forward finding in task 6.1's status report rather than either ignoring it or shipping a wrong compensating fix — mirrors task 4.1's own precedent of carrying forward a documented, unfixed hazard to the next task rather than guessing at scope it doesn't own.
|
||||
|
||||
## Key Learning (2026-07-04, raft-apply-decoupling task 6.2 round 2, bug-1415 FIXED) — self-heal a late registration by checking the already-applied watermark; reproduce the multi-vcpu race in a test by forcing the interleaving with a poll-barrier, not a sleep
|
||||
Fixed via the self-healing option this same entry's original write-up proposed: `persist_register_pending_apply()` (persist.c) now checks `lsn <= persist_last_applied_lsn(p)` BEFORE linking onto `pending_applies`; if the walk already passed `lsn`, it fires `on_applied(ctx, lsn)` immediately, synchronously, on the CALLER's thread instead of orphaning a registration nothing will ever revisit. Proving this deterministically required a genuinely new test-fixture pattern for this codebase: `vtaskmgr_init()` alone starts NOTHING (no dispatcher, no vcpu threads) — only `vtaskmgr_start()` spawns them, so `test_commit_admission_pool.c`'s existing pool fixture (admission-accounting only) is NOT sufficient for a test that needs real concurrent vtask execution; you must call both. To force the specific bad interleaving (apply-pump wins) deterministically rather than relying on a timing-guessed `usleep()`, the test's stand-in commit-continuation callback blocks in a poll loop on `persist_last_applied_lsn(p) < lsn` BEFORE calling `persist_register_pending_apply()` — this is a genuine barrier tied to the actual race predicate (not a sleep guess), so it reproduces the exact interleaving on every run once a real multi-vcpu pool is wired via `commit_set_pool`. New test `test_apply_pump_late_pending_apply_registration_self_heals` (test_apply_pump.c) is the ONE test in this entire spec that wires a real pool; every other fixture deliberately keeps `ce->pool == NULL` and must stay that way (verified via full regression sweep: zero new failures, only the 2 pre-existing task-7.3-owned `test_commit_barrier_reply.c` failures persist unchanged). [[project_raft_commit_safety_done]]
|
||||
|
||||
## Key Learning (2026-07-04, raft-apply-decoupling task 6.2, historical — original bug-1415 finding, now fixed above) — two vtask dispatches enqueued back-to-back from the same function have NO completion-order guarantee once a real (n_vcpus>1) pool is wired
|
||||
Wired `persist_apply_pump_run()` to consume task 3.2's hand-off (`persist_take_pending_apply()` immediately after each entry's `apply_committed_entry()` + `last_applied_lsn` advance, then invoke the returned continuation) and made `jobsubmit_apply_complete` actually send the batch's success reply (`RequestReply_data_jobid`, gated on `actx->replied` the same way `jobsubmit_reply_failure_once` already gates the failure reply — added a `jobsubmit_reply_success_once` sibling and a `jobid` field on `jobsubmit_async_ctx_t`). While tracing correctness end-to-end, found (not fixed — out of this task's boundary, which is scoped to `persist_apply_pump_run`'s loop only) that `commit_resolve_pending()` (commit.c) enqueues TWO independent `VTASK_LIVE_BLOCK` tasks back-to-back onto the SAME `vtaskmgr_t` pool: first each ready continuation's dispatch (which, for a job submit, calls `persist_register_pending_apply()`), then `persist_apply_pump_kick()`'s own walk task. `vtaskmgr.c`'s dispatcher (`vdispatcher_entry`/`pick_idle_vcpu`) hands queued tasks to whichever of `n_vcpus` worker threads is next idle — with more than one idle vcpu, two tasks enqueued in that order can run on two DIFFERENT threads with no guarantee the first-enqueued one finishes first. If the apply-pump task wins, it applies the entry and advances `last_applied_lsn` past it BEFORE the registration exists; the registration then lands for an lsn the walk will never revisit (it only ever walks `[last_applied_lsn+1..]` forward) — a silently, permanently orphaned reply. **This is invisible in every test in this entire spec** because every fixture (`tap_setup`, `cbrp_setup`, etc.) deliberately never calls `commit_set_pool`, so `ce->pool` stays NULL and `dispatch_continuation`/`persist_apply_pump_kick` both fall back to running INLINE, synchronously, in enqueue order — a single-threaded test can never observe a multi-worker race that only exists when a pool is actually wired. Logged as bug-1415 (not fixed) with two candidate fixes (make the pump-kick wait for its batch's continuation dispatches to finish first, or make `persist_register_pending_apply()` self-heal by checking `lsn <= persist_last_applied_lsn()` and firing inline immediately if so) — flag for whoever builds a real multi-vcpu regression test (task 6.3/6.4 or a fast-follow) to close it. **Lesson**: "the test fixture never wires a pool" is a load-bearing fact worth stating explicitly whenever reasoning about ordering between two `vtask_enq_classified` calls — pool-less inline fallback silently converts an async multi-threaded dispatch into a same-thread synchronous one, which can hide a real race for an entire task's worth of otherwise-thorough tests. [[project_raft_commit_safety_done]]
|
||||
|
||||
## Key Learning (2026-07-05, raft-apply-decoupling task 6.3) — a test spy for a hook-fan-out reaction must mirror the REAL routing table, not the idealized one
|
||||
`apply_committed_entry()` fires every job-state fact via the generic `HOOK_DETAIL_JOB_UPDATE` only (never the type-specific `HOOK_DETAIL_JOB_START/_EXIT/_FAIL/_RUSAGE_UPDATE` — a documented wire-format deviation since task 2.2, persist.h's doc comment). Consequence for test-writing: `sched_job_start_fun`/`sched_job_exit_fun`/`sched_job_fail_fun` (sched.c) and their apiserver.c equivalents are structurally UNREACHABLE for any live-applied fact. A reaction spy registered for the type-specific details would silently test a code path that can never fire in production — passing vacuously, catching nothing. The correct spy listens ONLY for `HOOK_DETAIL_JOB_NEW` (submit) and `HOOK_DETAIL_JOB_UPDATE` (every fact type), since that is the only pair actually reachable. Verified this file's tests are NOT vacuous by temporarily reintroducing the pre-task-4.1 eager receipt-time mutation+notify bug in `on_job_start` (job.c) — both new integration tests failed immediately (double-append from the reintroduced live-notify racing `persist_job_hook_fun`'s durable-append guard), confirmed clean revert (`git diff` empty), then GREEN again, 30/30 stable reruns.
|
||||
|
||||
## Do-Not-Repeat (2026-07-05) — `TEST_ASSERT_EQUAL_INT_MESSAGE` requires 3 args; a bare 2-arg call is a compile error, not a silent no-message pass
|
||||
Caught immediately by the build (gcc: "macro requires 3 arguments, but only 2 given"), not by review — worth remembering `TEST_ASSERT_EQUAL_INT` (no `_MESSAGE` suffix) is the correct macro when no custom message is needed, in this Unity-based C test harness.
|
||||
|
||||
## Key Learning (2026-07-05, raft-apply-decoupling task 7.2) — xce_test's `worker` REPL context was missing jstart/jfail; libxce already had the full wire API
|
||||
`src/lib/client.c` already implements the ENTIRE worker-fact wire API (`xcecli_notify_jobstart/_jobfail/_jobstop/_jobresume/_jobchkpt/_jobpostdone`, alongside the pre-existing `_jobfinish`) — but `testsuite/test.c`'s `worker_commands[]` table only ever exposed `jfinish` as a REPL command. Added `jstart`/`jfail` (mirroring `jfinish`'s exact getopt/parse_jobid/SET_ERROR shape) to unlock a synthetic-but-real-wire-protocol worker-fact stream for the new `--factstream` HA soak scenario, without needing a real `xcecd_worker` + scheduler dispatch handshake — `on_job_start`/`on_job_fail` (job.c) only require the job to already exist in jobmgr (i.e. be submitted), not to have been dispatched, so this is genuinely the SAME production receipt→commit→apply path a real worker would drive, just skipping actual OS-process execution (irrelevant to raft-apply-decoupling's apply-ordering concern). **Do-not-repeat**: `cmd_jobfinish` never reset `optind = 1` — harmless for every EXISTING caller (always invoked at most once per xce_test process) but a REAL bug once a script calls `jfinish` repeatedly in one session (as the factstream scenario does): getopt's static `optind` carries over from whatever position the PRIOR command's parse left it at, silently causing the 2nd+ call to skip its own `-j`/`-c` flags. Fixed by adding `optind = 1` to `cmd_jobfinish` (matching the majority convention most other `cmd_` handlers already follow) — any new REPL command that might be invoked repeatedly in one script MUST reset `optind` itself; don't assume the previous command's handler already did it for you.
|
||||
|
||||
## Key Learning (2026-07-05, raft-apply-decoupling task 7.2) — waldump only decoded jobid for WAL_JOB_SUBMIT; extended it to the flat wal_jobstate_t fact types
|
||||
`testsuite/waldump.c` only ever decoded `jobid`/`state` for `WAL_JOB_SUBMIT` (capnp Job schema) — every fact type (`WAL_JOB_START/FINISH/FAIL/STOP/RESUME/UPDATE/RUSAGE/CKPT/PREASON`, all sharing the flat native-endian `wal_jobstate_t{jobid,state,_pad}` struct, wal_types.h) printed as `jobid=?`. Added `wal_type_is_jobstate()`/`decode_jobstate_info()` (a bounds-checked `memcpy`, not a parser — same triviality as the struct itself) so these types now print `jobid=<fmt> state=0x%x pad=0x%x` too, letting a caller grep waldump output per-jobid per-fact-type across nodes. This is what makes the factstream scenario's phantom-fact cross-check possible (grep -F "JOB_START" + "jobid=$jid " per node). Generically useful beyond this task: any future "did fact X actually commit for job Y" question can now be answered offline via waldump alone.
|
||||
|
||||
## Key Learning (2026-07-05, raft-apply-decoupling task 7.2) — `job_state_str`'s if/else-if priority ordering (RUN checked before EXIT) HIDES bits from the pretty-printed state string
|
||||
`apply_job_fail_transition` (job.c) merges `JOB_STAT_EXIT|JOB_STAT_PERR` onto the job's CURRENT state via `|=` — it does NOT clear `JOB_STAT_RUN`. So a job that receives a POST_EXEC-stage FAIL WITHOUT a prior FINISH (a legitimate worker-report ordering — "died without ever reporting finish") ends up with `state_raw = RUN(0x2)|EXIT(0x4)|PERR(0x100) = 0x106`, genuinely correct per the merge semantics — but `job_state_str()`'s `if (RUN) return "RUN"` check fires FIRST and never reaches the `EXIT` branch, so `jobinfo`/`joblist` print "RUN", silently hiding that the fail was actually applied. Confirmed via a live standalone probe (3-node cluster, `jstart`+`jfail` with no `jfinish`): `state: RUN` / raw `0x106`. This is a pre-existing, minor, likely-harmless-until-now display quirk (not introduced by raft-apply-decoupling — `apply_job_fail_transition` is an unmodified lift from the original `mark_job_fail`), NOT fixed (out of task 7.2's boundary), but it DOES matter for any script-level check that infers "did a terminal fact apply" from the pretty string — the factstream phantom-check was written against `state:` first and produced a false negative (silently failed to check for a committed JOB_FAIL backing a RUN-displayed job) until switched to a new `state_raw: 0x%x` field added to `print_jobinfo()` (test.c) and bitwise-AND'd against the real `JOB_STAT_*` constants. **Do-not-repeat**: never infer "which facts applied" from a job's pretty-printed state string in this codebase — always use `state_raw` (or the raw bits directly) since the string's priority-ordering can mask co-set bits.
|
||||
|
||||
## Key Learning (2026-07-05, bug-1416, raft-apply-decoupling task 7.2) — cluster_init_phase2's persist_recover() apply-correctness verification can false-positive APPLY_DIVERGENT when a returning node's recovery vtask races a compressed catch-up replication burst — FIXED round 2
|
||||
Found live, reproduced 10/10 times, building the `--factstream` kill-mid-fact-stream HA soak scenario. `cluster_init_phase2()` (cluster.c) calls `cluster_open_listener()` (accepts network I/O, including replicated/catch-up WAL writes) BEFORE `persist_recover()` (the task-5.1 boot-time apply-correctness verification, Req 8.1/8.2) — and `persist_recover()` itself fires from a vtask, not synchronously. `persist_verify_apply_correctness()`'s LIVE reads of `p->last_applied_lsn` and `count_jobmgr_entries()` can race two live mutation paths (the apply pump, `persist_apply_pump_run`/`persist_apply_pump_kick`; and the standby live-replication apply path, `ha_apply_single_entry`/`ha_apply_term_entry_via_library` in ha.c) that write those SAME values concurrently, producing a DIVERGENT verdict on a node that has NOT actually diverged. **FIXED (round 2, review remediation)**: new `_Atomic bool persist_t.recovery_complete` gate (persist.h/persist.c). `persist_apply_pump_kick()` no-ops while closed; `ha_apply_single_entry`/`ha_apply_term_entry_via_library` skip ONLY the in-memory `apply_wal_entry()` call while closed (durability write + ACK + applied_lsn advance stay ungated — mirrors bug-1043's durability/materialization decoupling). `persist_recover()` closes it at entry, reopens it + issues one deliberate catch-up kick before returning. **Round-2-of-the-fix gap, found via live verification, not just code review**: this alone was NOT enough — a node stuck retrying its own election as a losing/timing-out candidate can receive and durably APPLY live-replicated entries via the ungated (`persist_init` default=true) path for tens of seconds BEFORE `cluster_init_phase2()` ever calls `persist_recover()` for the first time, reproducing the identical false-DIVERGENT symptom through an earlier entry point `persist_recover()`'s own bracket can't see. Closed with `persist_mark_recovery_pending(&c.persist)` in `myapp_run()` (myapp.c), called right after `persist_init()`/`persist_start()` succeed and BEFORE `ha_start_election_async()`/`cluster_run()` can process any network traffic — closing the gate from the true earliest safe moment. `persist_init()`'s default stays TRUE so none of this spec's ~20 unit-test fixtures that construct a `persist_t` directly (bypassing `myapp_run`) are affected. Verified: live 3-node `--factstream` soak (2 rounds, kill+restart both) now PASSes clean, zero `APPLY_DIVERGENT` across 5 `persist_recover()` calls; broader `controller_unit_test` sweep (23 groups) shows zero new failures; real-divergence detection re-confirmed intact via the 3 dedicated `test_apply_correctness_verification.c` divergence tests. **Do-not-repeat lesson**: when gating a live path behind a "recovery in progress" flag, the flag's OWN bracket around the recovery function itself is not sufficient if OTHER code paths (election retry, live replication) can mutate the same state BEFORE that function is ever first called — the gate must close at the EARLIEST point in the real process lifecycle traffic could possibly begin, not just around the specific function whose output it protects.
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue