chore: sync OpenWolf state (buglog, cerebrum, memory, anatomy)
Records today's session: bug-1386/1389 snapshot pipeline fixes, bug-795 closure, bug-1400/1401 fixes, bug-1396 harness instrumentation, and the raft-apply-decoupling spec-family promotion. Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SDWVNQLKxqTVHh42cH7rV3
This commit is contained in:
parent
13c6e89309
commit
cf3fa9b850
8 changed files with 48260 additions and 2564 deletions
|
|
@ -318,3 +318,39 @@ Task 8 (live 3-node E2E) passed: `/xce-test-ha` 8 rounds, 30 jobs, zero loss, al
|
|||
- XCE thread-role contract (ha-async-io.md, corrected 2026-06-25): iomgr = non-blocking IO + dispatch ONLY (never process inline); delaymgr = trigger-only, NEVER block (it drives heartbeats/election-timeouts — blocking there stalls cluster liveness → spurious failover); vtask pool = bounded blocking ONLY under COMMIT_WAIT_RESERVED admission cap; long blocking IO (reconnect/snapshot/config-push) → dedicated slow lane. This SUPERSEDES the old "delaymgr for blocking ops = Permitted" rule, which was the root cause of the bug-851 chaotic-failover family (delaymgr overloaded as both heartbeat-driver and blocking-sink).
|
||||
- `endpoint_block_tasks(ep)`/`endpoint_unblock_tasks(ep)` (src/lib/netio.c:896-911) set a per-endpoint `ep->busy` flag enforcing SEQUENTIAL processing of messages from the same endpoint. Auto-applied on the VTASK_IO dispatch path (vtaskmgr.c:249 block on start, :66 unblock on completion; vtask_eligible :203 skips a busy endpoint). Use this when strict per-connection message-processing order is required. Caveat: the block is held for the whole task duration — never run long I/O inline in a blocked handler (it queues that peer's later messages, incl. heartbeat ACKs); trigger long I/O to a slow lane and return.
|
||||
- epoll registration in libxce is thread-safe: iomgr_monitor (EPOLL_CTL_ADD), iomgr_unmonitor (DEL), iomgr_update_poll (MOD) all wrap epoll_ctl in mylock_lock(&iomgr->lock) (src/lib/netio.c:1046-1082). So an endpoint's fd can be registered into the iomgr epoll set from ANY thread (connect→register already runs from delaymgr/main, e.g. on_vote_connected). No eventfd/self-pipe "post to iomgr" primitive exists or is needed for fd registration — prepare the endpoint fully before iomgr_monitor (unmonitored fd yields no events → no race).
|
||||
|
||||
## Key Learning (2026-07-02, bug-1381) — the bug-1298 endpoint refcount is the ONLY safe way to hand a borrowed endpoint_t* to another thread
|
||||
Any time code snapshots a raw `endpoint_t*` under `c->ha.lock` (or another owner lock) and then touches it from a DIFFERENT thread after releasing that lock — a spawned `pthread_create` worker, a slow-lane task, anything — it MUST `endpoint_ref()` the ep in the same critical section the pointer is read, with an unconditional matching `endpoint_unref()` on every path that thread can exit (success, send-failure, thread-never-started, alloc-failure before the thread even runs). Without this, a concurrent RDHUP teardown (`handle_endpoint_error` → `zarray_del` → `endpoint_killer` → `endpoint_unref`) can free the ep mid-use. This is the THIRD instance of this exact hazard shape (bug-1197/snapshot-lane, bug-1376/cold-start dispatch, bug-1381/config-push transport fan-out) — when reviewing any NEW code that borrows a standby/vote endpoint across a thread hop, check for this bracket by default, don't wait for a bug report.
|
||||
|
||||
## Do-Not-Repeat (2026-07-02, bug-1381 test approach)
|
||||
When a production send function has no test seam (e.g. `xce_replconfigpush_req_raw` calls real capnp+SSL machinery), don't try to unit-test the real network path — add a small function-pointer hook (`push_thread_send_hook`, same shape as the existing `xce_wal_stream_request_hook`) so a test can park/gate the send and probe invariants (like `endpoint_ref` counts) deterministically. Confirmed via temporary revert (`Expected 2 Was 1`) that the new regression test actually fails without the fix before trusting it as the RED→GREEN gate.
|
||||
|
||||
## Do-Not-Repeat (2026-07-02, re-triggered) — verify xce.build mtime EVERY soak run, not just once
|
||||
Nearly repeated the exact mistake already logged above (2026-06-24 entry): ran two `/xce-test-ha`-style soaks (chaotic PASS, force-snapshot FAIL x2) against `src/xce.build/controller/xce_controller` that was BUILT BEFORE the `g_drive_async_configpush_offload` flag flip — the binary's mtime (04:05) predated the source edit (07:43). The chaotic "PASS" therefore validated old code, not the new flip; the force-snapshot failures are inconclusive noise, not evidence against the change. Root cause: I rebuilt `build.release` (a different meson output dir used for other purposes) and assumed that was what the soak script deploys — it is NOT. `run-ha-soak.sh` / `/xce-test-ha` always deploys from `src/xce.build/controller/{xce_controller,xce_test}` specifically. RULE: before EVERY soak invocation (not just once per session), run `stat -c '%Y %n' src/xce.build/controller/xce_controller src/controller/*.c` (or equivalent) and confirm the binary is newer than every source file it depends on — `ninja -C xce.build controller/xce_controller controller/xce_test` unconditionally right before the soak costs nothing when already up to date (ninja says "no work to do") and is cheap insurance against silently testing stale code.
|
||||
|
||||
## Key Learning (2026-07-02, bug-1386) — a soak PASS/FAIL always needs a flag-OFF control run before blaming the flag
|
||||
Flipped `g_drive_async_configpush_offload` ON after closing its correctness blocker (bug-1381) and got 0/3 force-snapshot soak passes — looked damning. Before reverting-and-declaring-regression, ran the SAME scenario with the flag OFF on the identical freshly-built binary: 1/2 pass, SAME failure signature ("no snapshot install" / "did not reconverge"). That proved the defect was pre-existing (root cause: `ha_send_snapshot_to_standby` in config_repl.c ignores `xce_snapshot_chunk_req_raw`'s return in its chunk loop, silently dropping a chunk on `-ECONNRESET` and still logging "complete") and unrelated to the flag being tested. Lesson: when a soak fails after a flag flip, ALWAYS run an A/B (flag-ON vs flag-OFF) control on the same binary/environment before attributing the failure to the change — a single-arm test can't distinguish "my change broke this" from "this was already flaky." [[project_bug1381_configpush_uaf]]
|
||||
|
||||
## Do-Not-Repeat (2026-07-02) — small soak sample sizes overstate confidence either direction
|
||||
0/3 vs 1/2 is NOT strong evidence of a flag-specific regression (P(0/3 fails | true 50% pass rate) ≈ 12%, well within noise) — but it's also not strong enough to declare "definitely safe, flip it." When a flip's soak sample is this small and the underlying bug is independently reproducible at baseline, the correct call is to REVERT and defer (don't ship on ambiguous evidence) rather than accept either "probably a coincidence" or "probably a regression" without more data. Bar to re-flip: fix the underlying bug (bug-1386) first, THEN re-run enough rounds (the existing 2/3-pass precedent from the 3.1/3.2 flip session) to get a real signal.
|
||||
|
||||
## Key Learning (2026-07-02, bug-1386 FIXED) — a fire-and-forget send-loop must check EVERY iteration's return, not just fread's
|
||||
`ha_send_snapshot_to_standby`'s chunk loop already checked `fread`'s return (`rc = -EIO; break;`) but not the network send call two lines later — an inconsistent half-checked loop is an easy trap: it *looks* like errors are handled because the pattern exists right there, but the actual transport call was left bare. Fix: capture into a per-iteration `send_rc`, `if (send_rc != 0) { rc = send_rc; break; }`, mirroring the existing fread check exactly. When reviewing/writing any chunked-transfer loop, verify *every* fallible call inside the loop body is checked, not just the first one — grep for the pattern once isn't enough, read the whole loop body. Also confirmed: no receive-side timeout/re-request was needed to fully close this — `ha->snapshot_inflight[peer_idx]` already unconditionally clears when the send thread exits (`snapshot_lane_fn`, success or failure), so the next heartbeat's SEND_SNAPSHOT decision naturally retries a peer whose `applied_lsn` never advanced. A silently-lying "success" return was the actual bug, not a missing retry mechanism — fixing the lie let the existing retry cadence do its job. [[project_bug1381_configpush_uaf]]
|
||||
|
||||
## Do-Not-Repeat (2026-07-02) — "the fix is verified" and "the failure mode is gone" are different claims; re-test the FULL scenario, not just the mechanism you fixed
|
||||
Fixed bug-1386 (send-side chunk-drop), confirmed via unit test AND via re-running the exact `--force-snapshot` soak scenario that originally surfaced it. The soak STILL failed — but with a genuinely different signature (sender now correctly reports "complete" for a truly-complete transfer; receiver's `persist_load_snapshot` then rejects the file as corrupted, `rc=-5`). Byte-diffing sender-vs-receiver files proved chunk CONTENT corruption at 64KB boundaries (a capnp encode issue, likely same family as bug-847) — a THIRD, previously-invisible bug that bug-1386's silent-drop bug had been masking/co-occurring with. Logged as bug-1389 (open). Lesson: when a user asks "did the fix solve the problem," don't stop at "the code path I changed now behaves correctly" — re-run the ORIGINAL failing scenario end-to-end. A fixed bug can still leave the outer symptom (soak FAIL) unchanged if a second, previously-undetected bug was co-resident in the same failure path. Report both facts distinctly: "your specific fix works" vs "the scenario now passes" are not the same sentence.
|
||||
|
||||
## Key Learning (2026-07-02, bug-1389 FIXED — corrects the capnp hypothesis below) — snapshot chunk transfer had TWO independent failure classes in the same code path
|
||||
`ha_send_snapshot_to_standby`/`ha_handle_snapshot_chunk`'s OPCode_snapshotTransfer pipeline had two distinct bugs stacked in the same force-snapshot scenario: bug-1386 = chunk DROP (send loop didn't check return, silently truncated); bug-1389 = chunk MISORDERING (full byte count arrives, every chunk's content is byte-for-byte correct, but chunks land at the WRONG FILE POSITION). Both produce a receiver-side failure but via different mechanisms (bug-1386: is_last never arrives, transfer hangs forever; bug-1389: is_last arrives, size check passes, `persist_load_snapshot` rejects the misassembled file with -EIO). **The initial "capnp encode/segment-boundary" hypothesis (below, and in the first version of this entry) was WRONG** — ruled out two ways: (1) an exhaustive trace of the wire framing (8-byte length-prefix, all uint64_t, clean) and the capnp far-pointer resolution (walked byte-exact, correct); (2) a deterministic in-process encode→decode round-trip test at the REAL 65536-byte chunk size (test_wal_wire.c) passed cleanly — proof, not just inspection, that capnp/transport was never the bug. **What actually happened**: the vtask pool dispatches one transfer's chunks to DIFFERENT workers (cpu#0-3 in the log) with no ordering guarantee — a live crc32 log at both send and receive (correlated by snapshot_lsn+chunk_index) proved chunks arrived as `0,1,3,4,2,5,...` with every individual chunk's crc32 matching exactly, while `ha_handle_snapshot_chunk` blindly appended bytes in ARRIVAL order instead of at `chunk->chunk_offset` (a field already on the wire, just unused) — reordered chunks landed at the wrong byte range. Fixed with `pwrite`-at-offset (order-independent) + a chunk-count-vs-expected-total completion tracker (not "this call has is_last") to avoid finalizing before a straggler chunk arrives. **The decisive technique**: live per-chunk crc32 correlation logging at BOTH ends of a transport pipeline, re-run against the real failing scenario — this is what separated "content genuinely corrupted in transit" from "content correct but reassembled in the wrong order," which byte-diffing the final files alone could NOT distinguish (a diff just shows "different at offset X"; only a per-hop hash trail shows WHERE the divergence enters). When a "corruption" bug's symptom is a byte-shift within an otherwise-correct total, always separate "wrong bytes" from "right bytes, wrong position" before hypothesizing a specific encode/transport mechanism — the two have completely different root-cause spaces (protocol/library bug vs. ordering/concurrency bug). `g_drive_async_configpush_offload` re-flipped to DEFAULT ON same day after this fix — soak-validated (6-round chaotic + 3/3 force-snapshot PASS) — raft-drive-async task 3.3 fully landed. [[project_bug1386_snapshot_chunk_drop]]
|
||||
|
||||
## Key Learning (2026-07-02, ha-commit-durability 6.1 closed) — bug-795's cold-restart-all loss was overlayfs, not real; 0/5 on genuine ext4
|
||||
Ran `test-commit-durability.sh` (8 rolling rounds + cold-restart-all) 5 times against a live 3-node cluster deployed to `~/tmp` (confirmed via `mount`/`df -T` to be real ext4 on `/dev/nvme0n1p2`, distinct from the sandbox's overlay `/`) — zero committed-job loss across all 5 cold-restart-all cycles. This closes the long-standing "pending confirmation under simultaneous total outage" caveat on the Commit Durability guarantee (`src/controller/CLAUDE.md`) — it was genuinely an overlayfs `fdatasync` artifact (as suspected since 2026-06-19), not a real durability gap; no production code changed. Confirms [[reference_nonoverlay_fs_soak]]'s `~/tmp` recommendation generalizes beyond HA failover soaks to durability soaks too. One SEPARATE anomaly surfaced (run 5/5): cluster showed 20 committed jobs, harness's own ACKED_FILE tracked only 19 — an EXTRA job, not a missing one, opposite of the bug-795 symptom. Deliberately did NOT chase this to ground (it doesn't match what task 6.1 was investigating, and full root-cause needs a live `joblist` capture at the failure point, which the cluster had already been torn down before I thought to check) — logged as bug-1396 and left open rather than either ignoring it silently or burning more budget on a tangent. When a soak run turns up an anomaly that ISN'T the one you're hunting, the right move is: log it precisely (so it's not lost), don't silently drop it, but also don't let it hijack the current investigation's scope.
|
||||
|
||||
## Key Learning (2026-07-02) — proving a fs-blocker resolved unblocks EVERY task gated on it, not just the one you were investigating
|
||||
Closing ha-commit-durability 6.1 (proving `~/tmp` is real ext4, not overlay) turned out to unblock TWO OTHER unrelated specs' live-validation tasks in one shot: controller-status 6.4 and ha-heartbeat-committed-propagation 4.1 both carried the IDENTICAL `_Blocked: ... this sandbox is overlayfs ... cannot run here_` annotation, referencing the exact same bug-795/overlayfs root cause. Once 6.1 resolved that root cause, both were immediately runnable with zero further investigation — just deploy to `~/tmp` and execute the hand-off recipes already written in their Implementation Notes. Lesson: when closing an environment/infrastructure blocker (not just a code bug), grep ALL specs' tasks.md for the SAME blocking annotation/bug-ID before moving on — a single fix can cascade-unblock several stale "blocked" checkboxes across unrelated specs that all cited the same underlying constraint. Found via `grep -oP '^\s*-\s\[[ ~]\]\s+\d+\.\d+' .kiro/specs/*/tasks.md` to enumerate genuinely-open leaf tasks (excludes cosmetic phase-header lines) across the whole `.kiro/specs/` tree — a fast way to get the REAL remaining-work picture instead of trusting `spec.json`'s `phase` field (which only tracks spec-generation phase, not implementation completion, and was stale/misleading for several fully-done specs in this project).
|
||||
|
||||
## Key Learning (2026-07-02) — job-facing client ops are primary-only by design; verify standby replication via ctrlstatus, not joblist
|
||||
Attempted to validate ha-wal-replication 5.4 ("job appears in joblist on primary AND all standbys") by pointing `xce_test`'s `masters` setting at a single standby only — got `xce_joblist: Unknown error 10014` (`E_XCE_STANDBY`). This is NOT a bug: `ha.c`'s `CTRL_STANDBY` dispatch switch (~line 3501) only allows replication/election/`OPCode_ctrlstatus` opcodes; every job-facing op (`joblist`, `jobsub`, etc.) falls through to `-XCE_ERR_STANDBY` by design — standbys never serve job reads/writes directly, only the client-side failover loop transparently rotates to the primary. Correct way to verify a standby *has* replicated data without going through the primary-only ops: query `ctrlstatus` (explicitly allowed in every role) and compare `committedLsn`/`appliedLsn` across nodes — a match proves the WAL entry replicated and applied, even though you can't `joblist` the standby directly. Confirmed this is intentional, not an oversight, by reading the full `ha_dispatch_gate`-style switch statement rather than assuming a gap. [[project_xce_system_map]]
|
||||
|
||||
## Key Learning (2026-07-02, bug-1401 FIXED) — a generated codec's `free_X(struct*)` vs `free_X_ptr(struct**)` split is easy to get wrong in a hand-written client wrapper
|
||||
`decode_X_ptr()` (capnp-generated) `calloc`s the top-level struct THEN fills its fields; the matching free is `free_X_ptr(&ptr)` (frees fields + the struct + nulls the caller's pointer), NOT `free_X(ptr)` (fields only — the codegen intentionally splits these because `free_X` is also reused on stack-allocated structs, e.g. this project's own `test_ctrlstatus_roundtrip_all_fields` test calls `free_CtrlStatus(&out)` on a stack var, which is correct there but wrong for a heap ptr). `src/include/client.h`'s `xce_free_ctrlstatus(s)` macro used the fields-only variant, leaking `sizeof(xce_ctrlstatus_t)` (120 bytes) on every real `ctrlstatus` call. **Root cause of it going undetected**: every existing ctrlstatus unit test built its `xce_ctrlstatus_t` via the stack-decode helper (`decode_CtrlStatus`) and freed it with the correct raw `free_CtrlStatus(&out)` call directly — none of them ever exercised the actual client-facing `xce_free_ctrlstatus()` macro that real code paths use. **Rule going forward**: whenever a generated codec exposes both a bare `free_X` and a `free_X_ptr`, any hand-written `xce_free_*`/`xcecli_free_*` wrapper macro over it MUST use `free_X_ptr(&(s))` if the value being freed came from a `decode_X_ptr()` heap allocation (check what the corresponding `xce_X(...)` API call's `MOVE_PTR` source was decoded with, not just what looks intuitively "free-shaped"). And: a roundtrip test that exercises only the raw encode/decode/free primitives is NOT a substitute for a test that goes through the actual client macro/wrapper — add at least one regression per free-wrapper that uses the real heap-allocating decode path + the real macro. RED confirmed the exact 120-byte/1-alloc LeakSanitizer signature from the bug report before applying the fix.
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue