Rongsong Shen
d26ff8870d
The buglog was one 27K-line JSON file whose fields covered only symptom,
root cause and fix, as free text: 2% of entries named the code version a
bug was found on, 12% the build profile, 36% a way to reproduce, and 58% of
the file was OpenWolf hook auto-detections ("Missing guard clause",
"Function not marked async" on .md files).
- .claude/skills/buglog/bug-record.md: the record standard. Eight
sections (Summary as the title, Description, Environment, Reproduction;
Root cause, Fix, Verification, References once fixed), each with the
content it must contain -- e.g. Environment needs the OS, the libc the
failing binary loads (from its ELF interpreter: glibc 2.42 in the nix
shell vs 2.40 on the host), toolchain, build profile and commit.
- .wolf/bugs/<id>.md: 500 records migrated from buglog.json; every field
verified to round-trip. They carry legacy: true and an explicit "not
recorded" where the old log had no such field; component derived from
file paths, severity from keywords (else unknown), fix_commits from
hashes in status_note/fix that git resolves (91 of 463 fixed).
- .wolf/buglog-archive.json: the 710 hook auto-detections, verbatim.
- .wolf/buglog.json is now an index generated from the records, keeping
the fields OpenWolf's hooks and `openwolf bug search` read.
- scripts/buglog.py rewritten: new (template + Environment collected from
the machine and --binary), check, status (refuses a status the record
doesn't support; fixed needs Root cause, Fix, Verification and
--commit hashes git resolves), note, recur, set, show, list, triage,
env, index. 29 unittest cases in scripts/tests/test_buglog.py.
- scripts/git-hooks/pre-commit runs `check --staged`: incomplete staged
records, a legacy record hand-changed to fixed without the fix-time
sections, a new record claiming legacy: true, or a stale index refuse
the commit.
- scripts/gitea-sync.py reads the records: issue body = the record's
sections plus linked fix commits (origin remote, GITEA_COMMIT_REPO to
override), and a body hash so an issue's text is refreshed when the
record changes.
- bug-1866 rewritten to the full standard as the worked example.
Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
5.7 KiB
| id | status | status_updated | status_note | component | severity | timestamp | last_seen | occurrences | files | tags | related | legacy | ||||||||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| bug-1696 | fixed | 2026-09-24 | controller | unknown | 2026-08-25T16:20:00Z | 2026-09-19T09:00:00Z | 2 |
|
|
|
true |
bug-1696: Chaotic HA soak (post-bug-1695-fix) reports committed_job_loss on every round; waldump on ctrl-1's…
Description
Chaotic HA soak (post-bug-1695-fix) reports committed_job_loss on every round; waldump on ctrl-1's live data dir shows the ENTIRE on-disk WAL truncated to a single NOOP entry (entries: 1 submits: 0) despite 21+ jobs previously verified committed; no snapshot exists; log shows ha_compute_safe_committed_lsn=0 immediately before raft_cb_become_leader promotes ctrl-1 to CTRL_PRIMARY at term=2 on its SECOND boot.
Environment
Not recorded (migrated from buglog.json).
Reproduction
Not recorded (migrated from buglog.json).
Root cause
raft_cb_become_leader() computes the promotion WAL-truncation floor (line ~1658-1662: trunc_floor = ha_promotion_truncate_floor(safe_lsn, persist_durable_floor(&c->persist)); persist_truncate_wal_above(&c->persist, trunc_floor)) and evaluates the whole promotion-eligibility gate (durable_floor/truncated/apply_verdict, ~line 1699-1823) BEFORE cluster_init_phase2() -- the ONLY call that invokes persist_recover() for this process's first-ever boot -- which does not run until is_first_boot handling at line ~1873-1899, further down in the SAME function. persist_durable_floor()/persist_recovery_truncated()/persist_apply_verdict() all read fields persist_recover() is responsible for populating from the real on-disk WAL; before that call, a freshly persist_init()'d struct reports durable_lsn=0 (bug-1445's comment at line 1901 already flagged this exact 'gate evaluated blind before recovery' hazard for ONE flag -- persist_apply_resource_fenced -- with a narrow re-check-after-phase2 patch, but the far more consequential durable_floor/truncation-floor computation was never covered by that fix). With durable_floor=0 (bogus, pre-recovery) and safe_lsn=0 (every voter, including self, ALSO advertised its LSN via persist_durable_floor() before its own recovery ran -- myapp.c:324-329, ha_candidate_advertise_lsn), ha_promotion_truncate_floor(0,0)=0 and persist_truncate_wal_above(p, 0) physically ftruncates/unlinks the real on-disk WAL segments down to LSN 0/1 -- destroying committed job data that persist_recover(), had it run FIRST, would have correctly reported as durable and protected via the bug-1060 floor guard. This scenario (a node RESTARTS with real durable data on disk, then immediately WINS its own promotion on that same boot, before its own recovery has run) was unreachable before bug-1695's fix -- previously a restarted node's stale-but-nonzero persisted term made it always skip its own election and defer to a peer, so it never hit is_first_boot-during-become_leader with real data at stake. bug-1695 correctly restored real re-election on restart and, in doing so, newly exposed this pre-existing boot-ordering flaw. A genuine Leader Completeness / bug-1060-guard-defeat, not a test-harness artifact: confirmed via direct waldump on-disk evidence plus source-level trace of the read-before-recover ordering.
Fix
FIXED. Reordered raft_cb_become_leader() (ha.c) so cluster_init_phase2()/persist_recover() (is_first_boot path) runs BEFORE the promotion-eligibility gate and the promotion-truncation-floor computation, so persist_durable_floor()/persist_recovery_truncated()/persist_apply_verdict() always reflect this boot's REAL recovered WAL state before any eligibility/truncation decision reads them. Split the pure vote-derived safe_committed_lsn computation (reads only ha->elect_ctx, safe pre-recovery) from the truncation-floor computation (needs post-recovery persist state) -- the former stays early, the latter moved to run after phase2. Original RED test hypothesis (physical WAL destruction via truncate) was disproven by source tracing (persist_truncate_wal_above's own no-op guard plus persist_init's current_lsn=1 reset make that specific mechanism impossible); the REAL, provable defect was the promotion-eligibility gate wrongly judging a genuinely corrupt/divergent node ELIGIBLE because it read persist_recovery_truncated()/persist_apply_verdict() before recovery ran. New regression test test_first_boot_promotion_refuses_when_own_first_recovery_finds_corruption (CRC-corrupts a real on-disk WAL entry, restarts, promotes) confirmed RED against unfixed code (wrongly became CTRL_PRIMARY despite RECOVER_TRUNCATED) and GREEN against the fix (correctly refused). Full controller unit suite: 1193 tests, 2 pre-existing bug-1561 failures only, 0 new. Live proof: full 10-round --chaotic soak under ASAN (build-asan-1696repro) PASSED (VERDICT mode=chaotic rounds=10 jobs=33 committed_divergence=0 committed_job_loss=0 result=PASS) and full 10-round --sequential soak PASSED (PASS: 10 rounds, 33 jobs submitted, zero job loss; all 3 nodes led (ctrl-1,ctrl-2,ctrl-3)) -- both legs of the audit skill's Step 4 mandate satisfied. Note: the fix's own verification agent died mid-A/B-soak leaving the fix orphaned in a git stash for a period before being discovered and restored; a subsequent independent full soak (this entry) is what actually closes it out.
Verification
Not recorded (migrated from buglog.json).
References
- Related: bug-1695, bug-1060, bug-1445, bug-828, bug-1487