From 232948a36907578b943f3b81d8a628014a8bb700 Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Mon, 8 Jun 2026 11:49:23 -0400 Subject: [PATCH 01/11] fix(kanban): re-probe DB health on a TTL instead of caching it for the process lifetime MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The integrity probe in `_guard_existing_db_is_healthy` was skipped for the entire process lifetime once a path entered `_INITIALIZED_PATHS`. That set conflates two different facts: "schema is migrated" (genuinely once per process) and "the DB is healthy" (which can change *after* first connect). Consequence is a corruption *amplification* loop. When the main DB file is torn — e.g. an interrupted WAL checkpoint under WSL2 / abrupt VM stop — a long-lived writer (kanban worker, gateway) that first connected while healthy never re-checks. It keeps opening and checkpointing the damaged file, compounding the damage on every cycle and producing a fresh content-addressed `.corrupt..bak` each time, while new/cold connects correctly fail closed. Observed in the wild: ~20 distinct quarantine copies (~150 MB) generated in ~10 minutes from a single initial torn write, with the board unusable (every kanban API 409) until the live DB was restored by hand. Fix: track health separately from schema-init, with a short TTL. - `_LAST_HEALTH_OK: dict[str, float]` records the monotonic time of the last "ok" probe; the full probe is skipped only within `_HEALTH_CHECK_TTL_SECONDS` (30s). The cheap header check in `connect()` still runs on every connect. - A successful probe records the stamp; a failed probe evicts it before raising, so subsequent connects keep failing closed. - `_LAST_HEALTH_OK` is cleared alongside the existing `_INITIALIZED_PATHS` evictions (board delete, init_db). Because workers open a fresh connection per operation (`connect_closing`), the next operation after the TTL elapses fails closed instead of writing — capping the blast radius to ~one TTL window rather than "until the process exits". Adds a regression test covering record-on-ok, skip-within-TTL, and re-probe-and-fail-closed-after-TTL. Co-Authored-By: Claude Opus 4.8 (1M context) --- hermes_cli/kanban_db.py | 22 +++++++++++++++- tests/hermes_cli/test_kanban_db.py | 41 ++++++++++++++++++++++++++++++ 2 files changed, 62 insertions(+), 1 deletion(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index 39c434d4021d9..d44539fb57cd8 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -813,6 +813,7 @@ def remove_board(slug: str, *, archive: bool = True) -> dict: # an empty sqlite file via mkdir(exist_ok=True); the cache entry must be # dropped first so the schema init pass re-runs on that fresh file. _INITIALIZED_PATHS.discard(str((d / "kanban.db").resolve())) + _LAST_HEALTH_OK.pop(str((d / "kanban.db").resolve()), None) if archive: archive_root = boards_root() / "_archived" @@ -1282,6 +1283,15 @@ class Event: # --------------------------------------------------------------------------- _INITIALIZED_PATHS: set[str] = set() +# Health (PRAGMA integrity_check) is a *separate* concern from "schema is +# migrated": a DB that was healthy at first connect can be corrupted later +# (e.g. a torn write from an interrupted checkpoint). Caching health for the +# whole process lifetime lets a long-lived writer keep opening and +# checkpointing an already-corrupt file, compounding the damage on every cycle +# while new/cold connects correctly fail closed. Re-probe on a short TTL so a +# writer notices post-init corruption within one window instead of never. +_LAST_HEALTH_OK: dict[str, float] = {} +_HEALTH_CHECK_TTL_SECONDS = 30.0 _INIT_LOCK = threading.RLock() _SQLITE_HEADER = b"SQLite format 3\x00" DEFAULT_BUSY_TIMEOUT_MS = 120_000 @@ -1657,7 +1667,12 @@ def _guard_existing_db_is_healthy(path: Path) -> None: return except OSError: return - if str(resolved) in _INITIALIZED_PATHS: + # Re-probe periodically rather than trusting a one-shot lifetime cache: + # corruption can develop after first connect, and a writer that never + # re-checks will keep amplifying it. The cheap header check in connect() + # still runs on every connect; this bounds the *full* integrity probe. + last_ok = _LAST_HEALTH_OK.get(str(resolved)) + if last_ok is not None and (time.monotonic() - last_ok) < _HEALTH_CHECK_TTL_SECONDS: return reason: Optional[str] = None try: @@ -1674,7 +1689,11 @@ def _guard_existing_db_is_healthy(path: Path) -> None: except sqlite3.DatabaseError as exc: reason = f"sqlite refused to open file: {exc}" if reason is None: + _LAST_HEALTH_OK[str(resolved)] = time.monotonic() return + # Damaged: force the next connect to re-probe instead of honoring a stale + # "ok" timestamp, then fail closed. + _LAST_HEALTH_OK.pop(str(resolved), None) backup = _backup_corrupt_db(resolved) raise KanbanDbCorruptError(resolved, backup, reason) @@ -1845,6 +1864,7 @@ def init_db( # schema + migration pass unconditionally. with _INIT_LOCK: _INITIALIZED_PATHS.discard(resolved) + _LAST_HEALTH_OK.pop(resolved, None) with contextlib.closing(connect(path)): pass return path diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index 25ed7223129f5..22ec9acb44934 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4370,6 +4370,47 @@ def test_repeated_corrupt_open_reuses_single_backup(tmp_path): assert second_backup.exists() +def test_health_guard_honors_ttl_cache_then_reprobes(tmp_path, monkeypatch): + """Health is cached for a bounded TTL, not the whole process lifetime. + + Regression for the corruption *amplification* loop: the integrity probe + used to be skipped permanently once a path was in ``_INITIALIZED_PATHS``, + so a long-lived writer that first connected while healthy never + re-checked. When the file was later torn (e.g. an interrupted checkpoint), + that writer kept opening and checkpointing the damaged DB, compounding the + corruption on every cycle while only new/cold connects failed closed. + With a TTL'd health cache the writer re-probes and fails closed within one + window instead of never. + """ + db_path = tmp_path / "kanban.db" + resolved = str(db_path.resolve()) + fake_now = [1000.0] + monkeypatch.setattr(kb.time, "monotonic", lambda: fake_now[0]) + + # Fresh, healthy DB. The first guard call probes and records an "ok" stamp. + kb._INITIALIZED_PATHS.discard(resolved) + kb._LAST_HEALTH_OK.pop(resolved, None) + kb.init_db(db_path=db_path) + kb._guard_existing_db_is_healthy(db_path) + assert kb._LAST_HEALTH_OK.get(resolved) == 1000.0 + + # The file is torn after the healthy probe (external event). + _write_corrupt_db(db_path) + + # Within the TTL the cached "ok" is honored — guard skips the probe and + # does not raise (bounded blast radius, not a permanent blind spot). + fake_now[0] = 1000.0 + kb._HEALTH_CHECK_TTL_SECONDS - 1 + kb._guard_existing_db_is_healthy(db_path) + + # Once the TTL elapses the guard re-probes, detects the damage, and fails + # closed — and evicts the stale stamp so subsequent connects keep failing + # closed instead of honoring a now-wrong "ok". + fake_now[0] = 1000.0 + kb._HEALTH_CHECK_TTL_SECONDS + 1 + with pytest.raises(kb.KanbanDbCorruptError): + kb._guard_existing_db_is_healthy(db_path) + assert resolved not in kb._LAST_HEALTH_OK + + def test_locked_healthy_db_does_not_classify_as_corrupt(tmp_path, monkeypatch): """A transient lock during the probe must not produce a .corrupt backup and must not be reported as :class:`KanbanDbCorruptError`. Raw sqlite From 17d15bd01b1c78a54c90daca0fcdd041403602be Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Tue, 9 Jun 2026 12:53:21 -0400 Subject: [PATCH 02/11] fix(kanban): confirm corruption across N probes before quarantining A single PRAGMA integrity_check failure under concurrent writers on a no-FUA disk (WSL2 virtual disk) can be a transient mid-checkpoint read, not real corruption. The read/write guard probe was treating any one non-ok result as definitive, producing spurious .corrupt.bak storms of a healthy, progressing board (~45 copies in 20 min observed live) and failing worker connects closed for no reason. Require _HEALTH_CONFIRM_ATTEMPTS consecutive non-ok probes (brief backoff between) before quarantining. Real corruption reproduces on every probe; a transient torn read clears on retry. Healthy path still costs one probe. Co-Authored-By: Claude Opus 4.8 --- hermes_cli/kanban_db.py | 58 +++++++++++++++++++++++------- tests/hermes_cli/test_kanban_db.py | 48 +++++++++++++++++++++++++ 2 files changed, 94 insertions(+), 12 deletions(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index d44539fb57cd8..a37ee02a0c91c 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -1292,6 +1292,17 @@ class Event: # writer notices post-init corruption within one window instead of never. _LAST_HEALTH_OK: dict[str, float] = {} _HEALTH_CHECK_TTL_SECONDS = 30.0 +# A single non-ok integrity_check is NOT trusted as corruption: under concurrent +# writers on a weak-durability FS (WSL2 virtual disk reports no DPO/FUA), a +# read/write probe can transiently read a mid-checkpoint page as malformed even +# though the DB is fine and the very next read is clean. Empirically a swarm of +# workers produced ~45 spurious .corrupt.bak of a *healthy*, progressing board +# in 20 min. Real corruption reproduces on every probe; a transient torn read +# does not. So require N consecutive non-ok probes (with a brief backoff) before +# quarantining + failing closed. Only the suspected-corrupt path pays this cost; +# a healthy DB returns after the first ok probe. +_HEALTH_CONFIRM_ATTEMPTS = 3 +_HEALTH_CONFIRM_BACKOFF_SECONDS = 0.1 _INIT_LOCK = threading.RLock() _SQLITE_HEADER = b"SQLite format 3\x00" DEFAULT_BUSY_TIMEOUT_MS = 120_000 @@ -1674,28 +1685,51 @@ def _guard_existing_db_is_healthy(path: Path) -> None: last_ok = _LAST_HEALTH_OK.get(str(resolved)) if last_ok is not None and (time.monotonic() - last_ok) < _HEALTH_CHECK_TTL_SECONDS: return + # Confirm before quarantining: a lone non-ok result is often a transient + # mid-checkpoint read on a no-FUA disk, not real corruption. Only declare + # the DB damaged if it fails every probe in a row; a single clean probe + # means it was a transient and the DB is healthy. ``OperationalError`` + # (lock/busy) still propagates raw from the first occurrence — never a + # quarantine. The healthy path costs exactly one probe (first ok → return). reason: Optional[str] = None + for attempt in range(_HEALTH_CONFIRM_ATTEMPTS): + reason = _run_integrity_probe(resolved) + if reason is None: + break + if attempt + 1 < _HEALTH_CONFIRM_ATTEMPTS: + time.sleep(_HEALTH_CONFIRM_BACKOFF_SECONDS) + if reason is None: + _LAST_HEALTH_OK[str(resolved)] = time.monotonic() + return + # Confirmed damaged across every probe: force the next connect to re-probe + # instead of honoring a stale "ok" timestamp, then fail closed. + _LAST_HEALTH_OK.pop(str(resolved), None) + backup = _backup_corrupt_db(resolved) + raise KanbanDbCorruptError(resolved, backup, reason) + + +def _run_integrity_probe(resolved: Path) -> Optional[str]: + """One ``PRAGMA integrity_check`` pass. Returns ``None`` if healthy, else a + short reason string describing why it looked corrupt. + + Opens read/write so SQLite can replay a healthy WAL/hot-journal before the + check (a pure read-only open would flag a recoverable DB as corrupt). + ``sqlite3.OperationalError`` (lock/busy/transient IO) is re-raised, never + classified as corruption — the caller lets it propagate. + """ try: probe = _sqlite_connect(resolved) try: row = probe.execute("PRAGMA integrity_check").fetchone() finally: probe.close() - if not row or (row[0] or "").lower() != "ok": - reason = f"integrity_check returned {row[0] if row else ''!r}" except sqlite3.OperationalError: - # Lock contention, busy, transient IO — not corruption. Let it propagate. raise except sqlite3.DatabaseError as exc: - reason = f"sqlite refused to open file: {exc}" - if reason is None: - _LAST_HEALTH_OK[str(resolved)] = time.monotonic() - return - # Damaged: force the next connect to re-probe instead of honoring a stale - # "ok" timestamp, then fail closed. - _LAST_HEALTH_OK.pop(str(resolved), None) - backup = _backup_corrupt_db(resolved) - raise KanbanDbCorruptError(resolved, backup, reason) + return f"sqlite refused to open file: {exc}" + if not row or (row[0] or "").lower() != "ok": + return f"integrity_check returned {row[0] if row else ''!r}" + return None def connect( diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index 22ec9acb44934..4fe2117781d58 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4411,6 +4411,54 @@ def test_health_guard_honors_ttl_cache_then_reprobes(tmp_path, monkeypatch): assert resolved not in kb._LAST_HEALTH_OK +def test_health_guard_ignores_transient_single_probe_failure(tmp_path, monkeypatch): + """A lone non-ok integrity probe must NOT quarantine a healthy DB. + + Regression for the spurious-``.corrupt.bak`` storm: under concurrent + writers on a no-FUA disk a read/write probe can transiently read a + mid-checkpoint page as malformed while the DB is fine. Observed live as + ~45 quarantine copies of a *healthy, progressing* board in 20 min. The + guard now requires every probe in a row to fail; a single clean probe + means the DB is healthy and nothing is quarantined. + """ + db_path = tmp_path / "kanban.db" + resolved = str(db_path.resolve()) + kb.init_db(db_path=db_path) + kb._INITIALIZED_PATHS.discard(resolved) + kb._LAST_HEALTH_OK.pop(resolved, None) + monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) + + # First two probes flag corruption, the third comes back clean → transient. + probes = iter(["integrity_check returned 'malformed'", + "integrity_check returned 'malformed'", + None]) + monkeypatch.setattr(kb, "_run_integrity_probe", lambda _p: next(probes)) + + kb._guard_existing_db_is_healthy(db_path) # must not raise + assert kb._LAST_HEALTH_OK.get(resolved) is not None + assert not list(tmp_path.glob("*.corrupt.*.bak")) # nothing quarantined + + +def test_health_guard_quarantines_persistent_corruption(tmp_path, monkeypatch): + """Corruption that reproduces on *every* probe is still quarantined and + fails closed — the confirmation loop must not mask real damage.""" + db_path = tmp_path / "kanban.db" + resolved = str(db_path.resolve()) + kb.init_db(db_path=db_path) + kb._INITIALIZED_PATHS.discard(resolved) + kb._LAST_HEALTH_OK.pop(resolved, None) + monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) + monkeypatch.setattr( + kb, "_run_integrity_probe", + lambda _p: "integrity_check returned 'malformed'", + ) + + with pytest.raises(kb.KanbanDbCorruptError): + kb._guard_existing_db_is_healthy(db_path) + assert resolved not in kb._LAST_HEALTH_OK + assert list(tmp_path.glob("*.corrupt.*.bak")) # quarantine happened + + def test_locked_healthy_db_does_not_classify_as_corrupt(tmp_path, monkeypatch): """A transient lock during the probe must not produce a .corrupt backup and must not be reported as :class:`KanbanDbCorruptError`. Raw sqlite From 4bd070b250c593abfbd183a8b455d8c01e1f858e Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Tue, 9 Jun 2026 17:36:08 -0400 Subject: [PATCH 03/11] fix(kanban): classify all-IOERR integrity failures as transient I/O, not corruption MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit PRAGMA integrity_check racing a concurrent WAL checkpoint reports 'unable to get the page. error code=522' (SQLITE_IOERR_SHORT_READ) — the read failed, the content is not malformed. Under sustained worker load that race outlives the N-probe confirmation loop, so the guard still quarantined a healthy, progressing board (observed live: 3 .corrupt.bak of an 'ok' DB in 90s, every failure line an IOERR). When every confirming probe fails and the report contains only IOERR-family unreadable-page lines (plus the 'never used' noise that follows from unvisited pages), raise sqlite3.OperationalError like the lock/busy case instead of quarantining + failing closed. Any content- damage line, non-IOERR code, or unexpected shape still quarantines. Co-Authored-By: Claude Opus 4.8 --- hermes_cli/kanban_db.py | 69 ++++++++++++++++++++++++- tests/hermes_cli/test_kanban_db.py | 81 ++++++++++++++++++++++++++++++ 2 files changed, 148 insertions(+), 2 deletions(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index a37ee02a0c91c..b6d97dd1d68d6 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -70,6 +70,7 @@ from __future__ import annotations +import ast import contextlib import hashlib import json @@ -1303,6 +1304,24 @@ class Event: # a healthy DB returns after the first ok probe. _HEALTH_CONFIRM_ATTEMPTS = 3 _HEALTH_CONFIRM_BACKOFF_SECONDS = 0.1 +# ``PRAGMA integrity_check`` can fail without the database being malformed: +# when the probe races a concurrent WAL checkpoint (a swarm of workers on the +# dispatch board), page reads come back as SQLITE_IOERR_SHORT_READ (522) — +# "unable to get the page. error code=522" — i.e. *the read failed*, not *the +# content is bad*. Under sustained load that race can outlive the whole +# confirmation loop, so quarantining on it copies a healthy board into a +# ``.corrupt.bak`` (observed live: 3 quarantines of an ``ok``, progressing DB +# in 90s, every failure line an IOERR). Classify an all-IOERR failure as +# transient I/O and surface it like a lock/busy error instead of corruption. +_SQLITE_IOERR_PRIMARY = 10 # low byte of extended IOERR codes (522 = SHORT_READ) +# Lines integrity_check emits when pages are unreadable (not malformed): +# the per-database header, the unreadable-page report itself, and the +# "never used" accounting noise that follows from pages it could not visit. +_TRANSIENT_IO_REPORT_LINE = re.compile( + r"^(?:\*\*\* in database .+ \*\*\*" + r"|.*: unable to get the page\. error code=\d+" + r"|Page \d+: never used)$" +) _INIT_LOCK = threading.RLock() _SQLITE_HEADER = b"SQLite format 3\x00" DEFAULT_BUSY_TIMEOUT_MS = 120_000 @@ -1701,13 +1720,59 @@ def _guard_existing_db_is_healthy(path: Path) -> None: if reason is None: _LAST_HEALTH_OK[str(resolved)] = time.monotonic() return - # Confirmed damaged across every probe: force the next connect to re-probe - # instead of honoring a stale "ok" timestamp, then fail closed. + # Non-ok on every probe: force the next connect to re-probe instead of + # honoring a stale "ok" timestamp. _LAST_HEALTH_OK.pop(str(resolved), None) + # An all-IOERR failure means the probe could not *read* the file (e.g. a + # checkpoint-truncate race that outlived the confirmation loop), not that + # the content is malformed. Surface it like the lock/busy case — a raw + # transient error, no quarantine copy, no fail-closed corruption state. + if _integrity_failure_is_transient_io(reason): + raise sqlite3.OperationalError( + f"kanban integrity probe could not read {resolved} after " + f"{_HEALTH_CONFIRM_ATTEMPTS} attempts (SQLITE_IOERR-family, e.g. " + f"SHORT_READ racing a checkpoint — transient I/O, not corruption): " + f"{reason}" + ) + # Confirmed damaged across every probe: quarantine and fail closed. backup = _backup_corrupt_db(resolved) raise KanbanDbCorruptError(resolved, backup, reason) +def _integrity_failure_is_transient_io(reason: str) -> bool: + """True when a confirmed non-ok integrity result describes only unreadable + pages (SQLITE_IOERR family, e.g. 522 SHORT_READ) rather than malformed + content. + + Real corruption reports content damage ("btree page N is malformed", + "row N missing from index", ...) with no I/O error code; a probe racing a + concurrent WAL checkpoint reports "unable to get the page. error code=5xx" + plus the "never used" noise that follows from pages it could not visit. + Strict on purpose: any line that is not provably I/O noise, or any error + code outside the IOERR family, classifies as corruption so the guard still + fails closed on genuine damage. + """ + prefix = "integrity_check returned " + if not reason.startswith(prefix): + return False + # _run_integrity_probe embeds the raw integrity_check row via !r; recover + # the original (possibly multi-line) text from its repr. + try: + text = ast.literal_eval(reason[len(prefix):]) + except (ValueError, SyntaxError): + return False + if not isinstance(text, str): + return False + codes = [int(c) for c in re.findall(r"unable to get the page\. error code=(\d+)", text)] + if not codes or any((code & 0xFF) != _SQLITE_IOERR_PRIMARY for code in codes): + return False + return all( + _TRANSIENT_IO_REPORT_LINE.match(line.strip()) + for line in text.splitlines() + if line.strip() + ) + + def _run_integrity_probe(resolved: Path) -> Optional[str]: """One ``PRAGMA integrity_check`` pass. Returns ``None`` if healthy, else a short reason string describing why it looked corrupt. diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index 4fe2117781d58..a53ddba14659b 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4459,6 +4459,87 @@ def test_health_guard_quarantines_persistent_corruption(tmp_path, monkeypatch): assert list(tmp_path.glob("*.corrupt.*.bak")) # quarantine happened +# Real-world shape of an integrity_check racing a concurrent WAL checkpoint: +# every failure is an unreadable page (SQLITE_IOERR_SHORT_READ = 522), plus +# the "never used" accounting noise from pages the check could not visit. +_SHORT_READ_INTEGRITY_TEXT = ( + "*** in database main ***\n" + "Tree 8 page 2053: unable to get the page. error code=522\n" + "Tree 22 page 22: unable to get the page. error code=522\n" + "Page 93: never used\n" + "Page 94: never used" +) + + +def test_health_guard_persistent_short_read_raises_operational_not_quarantine( + tmp_path, monkeypatch, +): + """An integrity failure that is *only* unreadable pages (IOERR family, + e.g. 522 SHORT_READ) must not quarantine, even when it outlives the whole + confirmation loop. + + Regression for the post-confirm-loop quarantine storm: under sustained + worker load the probe⇄checkpoint race persisted across all + ``_HEALTH_CONFIRM_ATTEMPTS`` probes, so a healthy, progressing board was + still copied to ``.corrupt.bak`` and connects failed closed. The read + failing is not the content being malformed — surface it like the + lock/busy case (raw ``OperationalError``), no backup, and evict the + health stamp so the next connect re-probes. + """ + db_path = tmp_path / "kanban.db" + resolved = str(db_path.resolve()) + kb.init_db(db_path=db_path) + kb._INITIALIZED_PATHS.discard(resolved) + kb._LAST_HEALTH_OK.pop(resolved, None) + monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) + monkeypatch.setattr( + kb, "_run_integrity_probe", + lambda _p: f"integrity_check returned {_SHORT_READ_INTEGRITY_TEXT!r}", + ) + + with pytest.raises(sqlite3.OperationalError): + kb._guard_existing_db_is_healthy(db_path) + assert resolved not in kb._LAST_HEALTH_OK + assert not list(tmp_path.glob("*.corrupt.*.bak")) # nothing quarantined + + +def test_integrity_failure_transient_io_classifier(): + """Only all-IOERR reports classify as transient; anything mentioning + content damage, a non-IOERR code, or an unexpected line stays corruption.""" + wrap = lambda text: f"integrity_check returned {text!r}" + + # The real-world short-read storm shape → transient. + assert kb._integrity_failure_is_transient_io(wrap(_SHORT_READ_INTEGRITY_TEXT)) + # Extended IOERR codes other than SHORT_READ (low byte 10) also qualify. + assert kb._integrity_failure_is_transient_io( + wrap("Tree 2 page 9: unable to get the page. error code=266") + ) + + # Genuine content damage → corruption, fail closed. + assert not kb._integrity_failure_is_transient_io(wrap("malformed")) + assert not kb._integrity_failure_is_transient_io( + wrap("*** in database main ***\nbtree page 5 is malformed") + ) + # IOERR lines mixed with content damage → corruption. + assert not kb._integrity_failure_is_transient_io( + wrap( + "Tree 8 page 2053: unable to get the page. error code=522\n" + "row 7 missing from index idx_tasks_status" + ) + ) + # Non-IOERR error code → corruption. + assert not kb._integrity_failure_is_transient_io( + wrap("Tree 8 page 2053: unable to get the page. error code=11") + ) + # Other reason shapes (refused open, no row) → not transient. + assert not kb._integrity_failure_is_transient_io( + "sqlite refused to open file: file is not a database" + ) + assert not kb._integrity_failure_is_transient_io( + "integrity_check returned " + ) + + def test_locked_healthy_db_does_not_classify_as_corrupt(tmp_path, monkeypatch): """A transient lock during the probe must not produce a .corrupt backup and must not be reported as :class:`KanbanDbCorruptError`. Raw sqlite From ad18f0fd7a41e05ddc373b2ca179424a40e06533 Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Tue, 9 Jun 2026 17:47:42 -0400 Subject: [PATCH 04/11] fix(kanban): give a read-only probe the last word before quarantining MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Under checkpoint contention the read/write integrity probe can fail with a hard SQLITE_CORRUPT ('database disk image is malformed') on open/first-read that clears on the very next read — the r/w probe participates in WAL recovery, so it races concurrent checkpoints in ways a reader does not. That string is identical to real damage, so it cannot be pattern-matched as transient (unlike the all-IOERR case). Observed live: quarantines of an integrity_check=ok board minutes apart, with the N-probe confirmation loop and IOERR classifier active. When the confirmation loop exhausts and the failure is not classified transient-I/O, run PRAGMA integrity_check over a mode=ro connection as the final arbiter: a read-only view takes snapshot semantics, stays out of recovery/checkpointing, and (empirically, a day of 5-minute read-only cron probes plus every manual check) has never false-positived. ro says ok -> raise OperationalError like the lock/busy path, no quarantine; ro confirms damage (which real corruption always does) -> quarantine and fail closed as before. Lock/busy during the ro probe counts as undecided, never as evidence. Co-Authored-By: Claude Opus 4.8 --- hermes_cli/kanban_db.py | 52 +++++++++++++++++++++++++-- tests/hermes_cli/test_kanban_db.py | 57 ++++++++++++++++++++++++++---- 2 files changed, 101 insertions(+), 8 deletions(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index b6d97dd1d68d6..941300e9c1340 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -1734,9 +1734,57 @@ def _guard_existing_db_is_healthy(path: Path) -> None: f"SHORT_READ racing a checkpoint — transient I/O, not corruption): " f"{reason}" ) - # Confirmed damaged across every probe: quarantine and fail closed. + # Last word goes to a READ-ONLY probe. The read/write probe participates + # in WAL recovery/checkpointing, so under concurrent writers the same + # race can also surface as a hard SQLITE_CORRUPT ("database disk image + # is malformed") on open/first-read that clears on the very next read — + # a string indistinguishable from real damage, so it cannot be + # pattern-matched as transient. A read-only connection takes a snapshot + # view and stays out of recovery entirely; empirically it has never + # false-positived on a healthy board that the r/w probe was busy + # quarantining. Only damage the ro probe *confirms* is quarantined. + ro_reason = _readonly_integrity_verdict(resolved) + if ro_reason is None: + raise sqlite3.OperationalError( + f"kanban integrity probe failed {_HEALTH_CONFIRM_ATTEMPTS}x on " + f"{resolved} but a read-only integrity_check passed — transient " + f"probe/checkpoint race, not corruption: {reason}" + ) + # Confirmed damaged by the read-only arbiter too: quarantine, fail closed. backup = _backup_corrupt_db(resolved) - raise KanbanDbCorruptError(resolved, backup, reason) + raise KanbanDbCorruptError( + resolved, backup, f"{reason} (read-only verification: {ro_reason})" + ) + + +def _readonly_integrity_verdict(resolved: Path) -> Optional[str]: + """Arbiter probe for the about-to-quarantine path: ``PRAGMA + integrity_check`` over a read-only (``mode=ro``) connection. + + Returns ``None`` when the DB is healthy **or** the verdict is + undecidable (lock/busy/cannot-open-readonly) — quarantine requires + positive evidence of damage, and an undecided probe just means the next + connect re-probes (the "ok" stamp was already evicted). Returns a short + reason string only when the read-only view itself reports damage, which + real corruption always does and the probe⇄checkpoint race never does. + """ + try: + probe = sqlite3.connect( + f"{resolved.as_uri()}?mode=ro", + uri=True, + timeout=_resolve_busy_timeout_ms() / 1000.0, + ) + try: + row = probe.execute("PRAGMA integrity_check").fetchone() + finally: + probe.close() + except sqlite3.OperationalError: + return None # undecided — never quarantine without evidence + except sqlite3.DatabaseError as exc: + return f"read-only open failed: {exc}" + if not row or (row[0] or "").lower() != "ok": + return f"integrity_check returned {row[0] if row else ''!r}" + return None def _integrity_failure_is_transient_io(reason: str) -> bool: diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index a53ddba14659b..efb53b64f447d 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4440,23 +4440,68 @@ def test_health_guard_ignores_transient_single_probe_failure(tmp_path, monkeypat def test_health_guard_quarantines_persistent_corruption(tmp_path, monkeypatch): - """Corruption that reproduces on *every* probe is still quarantined and - fails closed — the confirmation loop must not mask real damage.""" + """Corruption that reproduces on *every* probe — and that the read-only + arbiter confirms — is still quarantined and fails closed. The + confirmation loop and the arbiter must not mask real damage.""" db_path = tmp_path / "kanban.db" resolved = str(db_path.resolve()) - kb.init_db(db_path=db_path) + # Genuinely malformed file: valid header, damaged pages — the shape the + # guard targets. The read-only arbiter sees the same damage and confirms. + _write_corrupt_db(db_path) + kb._INITIALIZED_PATHS.discard(resolved) + kb._LAST_HEALTH_OK.pop(resolved, None) + monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) + + with pytest.raises(kb.KanbanDbCorruptError) as exc_info: + kb._guard_existing_db_is_healthy(db_path) + assert "read-only verification" in str(exc_info.value) + assert resolved not in kb._LAST_HEALTH_OK + assert list(tmp_path.glob("*.corrupt.*.bak")) # quarantine happened + + +def test_health_guard_spurious_malformed_overruled_by_readonly_arbiter( + tmp_path, monkeypatch, +): + """A persistent r/w probe failure on a *healthy* file must not quarantine. + + Regression for the second spurious-quarantine shape: under checkpoint + contention the r/w probe can fail with a hard SQLITE_CORRUPT ("database + disk image is malformed") on open/first-read that clears on the next + read. That string is identical to real damage, so it cannot be + pattern-matched as transient — instead the read-only arbiter (which + stays out of WAL recovery and has never false-positived) gets the last + word: it reads the healthy file, says ok, and the guard surfaces a raw + ``OperationalError`` with no quarantine copy. + """ + db_path = tmp_path / "kanban.db" + resolved = str(db_path.resolve()) + kb.init_db(db_path=db_path) # healthy on disk kb._INITIALIZED_PATHS.discard(resolved) kb._LAST_HEALTH_OK.pop(resolved, None) monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) + # The r/w probe persistently reports the hard-corrupt open failure. monkeypatch.setattr( kb, "_run_integrity_probe", - lambda _p: "integrity_check returned 'malformed'", + lambda _p: "sqlite refused to open file: database disk image is malformed", ) - with pytest.raises(kb.KanbanDbCorruptError): + with pytest.raises(sqlite3.OperationalError, match="read-only integrity_check passed"): kb._guard_existing_db_is_healthy(db_path) assert resolved not in kb._LAST_HEALTH_OK - assert list(tmp_path.glob("*.corrupt.*.bak")) # quarantine happened + assert not list(tmp_path.glob("*.corrupt.*.bak")) # nothing quarantined + + +def test_readonly_integrity_verdict(tmp_path): + """Arbiter semantics: healthy → None (no quarantine), damaged → reason + string (positive evidence, quarantine proceeds).""" + healthy = tmp_path / "healthy.db" + kb.init_db(db_path=healthy) + assert kb._readonly_integrity_verdict(healthy.resolve()) is None + + damaged = tmp_path / "damaged.db" + _write_corrupt_db(damaged) + verdict = kb._readonly_integrity_verdict(damaged.resolve()) + assert verdict is not None # Real-world shape of an integrity_check racing a concurrent WAL checkpoint: From a8219e52dd500ce795dd305413bdf3983aa93f83 Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Tue, 9 Jun 2026 18:10:24 -0400 Subject: [PATCH 05/11] fix(kanban): require corruption verdicts to persist for seconds, not milliseconds MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The read-only arbiter also false-positived in production: it samples at the hottest possible moment — immediately after every r/w probe failed — and even a read-only open can transiently report SQLITE_CORRUPT there. The quarantined copy itself later checked out integrity_check=ok, as did the live board (which kept progressing throughout). The discriminator that has held across every observed failure shape is persistence: real corruption is permanent, while probe⇄checkpoint contention clears within a second or two. So stretch the decision window from ~300ms to multi-second: - confirmation loop: 4 attempts with exponential backoff (0.15/0.45/ 1.35s, ~2s total) - read-only arbiter: damage verdict must repeat across 3 attempts spaced 1s apart; a single clean or undecided read anywhere in the window means transient (OperationalError, no quarantine) - transient outcomes now log a warning so contention episodes stay visible without minting quarantine copies Only the suspected-corrupt path ever sleeps; a healthy DB still costs exactly one probe. Co-Authored-By: Claude Opus 4.8 --- hermes_cli/kanban_db.py | 68 +++++++++++++++++++++++------- tests/hermes_cli/test_kanban_db.py | 33 +++++++++++++++ 2 files changed, 86 insertions(+), 15 deletions(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index 941300e9c1340..ce602c65f7386 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -1302,8 +1302,23 @@ class Event: # does not. So require N consecutive non-ok probes (with a brief backoff) before # quarantining + failing closed. Only the suspected-corrupt path pays this cost; # a healthy DB returns after the first ok probe. -_HEALTH_CONFIRM_ATTEMPTS = 3 -_HEALTH_CONFIRM_BACKOFF_SECONDS = 0.1 +_HEALTH_CONFIRM_ATTEMPTS = 4 +# Exponential: 0.15s, 0.45s, 1.35s between attempts (~2s total). Real +# corruption is *permanent* — it still fails after seconds. The probe⇄ +# checkpoint contention that produces every observed false positive clears +# within a second or two (each quarantined copy later checked out ok and the +# next connect succeeded), so a sub-second confirmation window cannot +# distinguish the two; a multi-second one can. Only the suspected-corrupt +# path ever sleeps. +_HEALTH_CONFIRM_BACKOFF_SECONDS = 0.15 +_HEALTH_CONFIRM_BACKOFF_FACTOR = 3.0 +# The read-only arbiter gets the same persistence treatment: it samples at +# the *hottest* possible moment (immediately after every r/w probe failed), +# where even a read-only open can transiently report SQLITE_CORRUPT. Require +# the damage verdict to repeat across spaced attempts; any single clean or +# undecided read means transient. +_ARBITER_CONFIRM_ATTEMPTS = 3 +_ARBITER_BACKOFF_SECONDS = 1.0 # ``PRAGMA integrity_check`` can fail without the database being malformed: # when the probe races a concurrent WAL checkpoint (a swarm of workers on the # dispatch board), page reads come back as SQLITE_IOERR_SHORT_READ (522) — @@ -1716,7 +1731,10 @@ def _guard_existing_db_is_healthy(path: Path) -> None: if reason is None: break if attempt + 1 < _HEALTH_CONFIRM_ATTEMPTS: - time.sleep(_HEALTH_CONFIRM_BACKOFF_SECONDS) + time.sleep( + _HEALTH_CONFIRM_BACKOFF_SECONDS + * (_HEALTH_CONFIRM_BACKOFF_FACTOR ** attempt) + ) if reason is None: _LAST_HEALTH_OK[str(resolved)] = time.monotonic() return @@ -1728,32 +1746,52 @@ def _guard_existing_db_is_healthy(path: Path) -> None: # the content is malformed. Surface it like the lock/busy case — a raw # transient error, no quarantine copy, no fail-closed corruption state. if _integrity_failure_is_transient_io(reason): + _log.warning( + "kanban health probe: transient IOERR-family failure on %s " + "(checkpoint race, no quarantine): %s", resolved, reason, + ) raise sqlite3.OperationalError( f"kanban integrity probe could not read {resolved} after " f"{_HEALTH_CONFIRM_ATTEMPTS} attempts (SQLITE_IOERR-family, e.g. " f"SHORT_READ racing a checkpoint — transient I/O, not corruption): " f"{reason}" ) - # Last word goes to a READ-ONLY probe. The read/write probe participates - # in WAL recovery/checkpointing, so under concurrent writers the same - # race can also surface as a hard SQLITE_CORRUPT ("database disk image - # is malformed") on open/first-read that clears on the very next read — - # a string indistinguishable from real damage, so it cannot be - # pattern-matched as transient. A read-only connection takes a snapshot - # view and stays out of recovery entirely; empirically it has never - # false-positived on a healthy board that the r/w probe was busy - # quarantining. Only damage the ro probe *confirms* is quarantined. - ro_reason = _readonly_integrity_verdict(resolved) + # Last word goes to a READ-ONLY probe, and the damage verdict must + # PERSIST. The read/write probe participates in WAL recovery/ + # checkpointing, so under concurrent writers the race can surface as a + # hard SQLITE_CORRUPT ("database disk image is malformed") that clears + # on the next read — indistinguishable by string from real damage. A + # read-only connection avoids recovery, but it samples at the hottest + # possible moment (every r/w probe just failed), where even ro opens + # have been observed to transiently report SQLITE_CORRUPT on a healthy + # board. Real corruption is permanent; contention clears in seconds. So + # quarantine only if every spaced ro attempt independently confirms + # damage — one clean or undecided read means transient. + ro_reason: Optional[str] = None + for attempt in range(_ARBITER_CONFIRM_ATTEMPTS): + ro_reason = _readonly_integrity_verdict(resolved) + if ro_reason is None: + break + if attempt + 1 < _ARBITER_CONFIRM_ATTEMPTS: + time.sleep(_ARBITER_BACKOFF_SECONDS) if ro_reason is None: + _log.warning( + "kanban health probe: r/w probe failed %dx on %s but read-only " + "verification passed (probe/checkpoint race, no quarantine): %s", + _HEALTH_CONFIRM_ATTEMPTS, resolved, reason, + ) raise sqlite3.OperationalError( f"kanban integrity probe failed {_HEALTH_CONFIRM_ATTEMPTS}x on " f"{resolved} but a read-only integrity_check passed — transient " f"probe/checkpoint race, not corruption: {reason}" ) - # Confirmed damaged by the read-only arbiter too: quarantine, fail closed. + # Damage confirmed by every read-only arbiter attempt over a multi-second + # window: this is the permanent kind. Quarantine and fail closed. backup = _backup_corrupt_db(resolved) raise KanbanDbCorruptError( - resolved, backup, f"{reason} (read-only verification: {ro_reason})" + resolved, + backup, + f"{reason} (read-only verification x{_ARBITER_CONFIRM_ATTEMPTS}: {ro_reason})", ) diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index efb53b64f447d..e79008d34c0ae 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4491,6 +4491,39 @@ def test_health_guard_spurious_malformed_overruled_by_readonly_arbiter( assert not list(tmp_path.glob("*.corrupt.*.bak")) # nothing quarantined +def test_health_guard_flickering_arbiter_verdict_is_transient(tmp_path, monkeypatch): + """A damage verdict that does not PERSIST across the arbiter's spaced + attempts must not quarantine. + + Regression for the third spurious-quarantine shape: the arbiter samples + at the hottest possible moment — immediately after every r/w probe + failed — and even a read-only open was observed to transiently report + SQLITE_CORRUPT there (the quarantined copy itself later checked out + ``ok``). Real corruption is permanent: it reports damage on every + attempt, seconds apart. One clean read anywhere in the window means + transient — raw ``OperationalError``, nothing quarantined. + """ + db_path = tmp_path / "kanban.db" + resolved = str(db_path.resolve()) + kb.init_db(db_path=db_path) + kb._INITIALIZED_PATHS.discard(resolved) + kb._LAST_HEALTH_OK.pop(resolved, None) + monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) + monkeypatch.setattr( + kb, "_run_integrity_probe", + lambda _p: "sqlite refused to open file: database disk image is malformed", + ) + # First arbiter read still hits the contention window; the second is clean. + verdicts = iter(["read-only open failed: database disk image is malformed", + None]) + monkeypatch.setattr(kb, "_readonly_integrity_verdict", lambda _p: next(verdicts)) + + with pytest.raises(sqlite3.OperationalError, match="read-only integrity_check passed"): + kb._guard_existing_db_is_healthy(db_path) + assert resolved not in kb._LAST_HEALTH_OK + assert not list(tmp_path.glob("*.corrupt.*.bak")) # nothing quarantined + + def test_readonly_integrity_verdict(tmp_path): """Arbiter semantics: healthy → None (no quarantine), damaged → reason string (positive evidence, quarantine proceeds).""" From 7c217a09111d510e7303328afe38183087452448 Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Tue, 9 Jun 2026 19:01:27 -0400 Subject: [PATCH 06/11] fix(kanban): probe DB health read-only-first and drop the read/write probe MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The guard's scheduled integrity probe opened the DB read/write so SQLite could replay a hot WAL before checking. Under concurrent writers on a weak-durability FS that probe false-positived four distinct ways (single torn read, persistent IOERR storm, hard SQLITE_CORRUPT at open that cleared on the next read, and even the hottest-moment ro arbiter) — each needing its own countermeasure layered on top of the last. Meanwhile a read-only probe at a *random* moment (which is what a TTL expiry is) never produced a false positive across the same period. Invert the design instead of adding a fifth countermeasure: - The TTL probe is now READ-ONLY (mode=ro): it stays out of WAL recovery/checkpointing, cannot tear anything, and does not contend with writers. The only read/write open left is the real connection. - Tri-state verdict: ok → stamp and return. undecided (lock/busy, a hot WAL a ro connection cannot recover, or an all-IOERR report) → fail OPEN without stamping — no error, no quarantine; the next connect re-probes, and the connection itself surfaces real damage anyway (cell_size_check=ON, write_txn page-count invariant). damage → must persist across every spaced probe in a multi-second window before quarantining: real corruption is permanent, contention clears in seconds. - Callers no longer see spurious OperationalError from suspected-transient episodes; those are logged warnings now. This subsumes the confirm-N read/write loop and the separate read-only arbiter while keeping the IOERR-family classifier (now used to mark a ro report undecided) and the TTL re-probe that stops corruption amplification. The suite gets faster too: the quarantine path pays one ~3s persistence window instead of confirm-loop + arbiter. Co-Authored-By: Claude Opus 4.8 --- hermes_cli/kanban_db.py | 256 +++++++++++++---------------- tests/hermes_cli/test_kanban_db.py | 157 +++++++++--------- 2 files changed, 187 insertions(+), 226 deletions(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index ce602c65f7386..fb36079a389d9 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -1293,32 +1293,27 @@ class Event: # writer notices post-init corruption within one window instead of never. _LAST_HEALTH_OK: dict[str, float] = {} _HEALTH_CHECK_TTL_SECONDS = 30.0 -# A single non-ok integrity_check is NOT trusted as corruption: under concurrent -# writers on a weak-durability FS (WSL2 virtual disk reports no DPO/FUA), a -# read/write probe can transiently read a mid-checkpoint page as malformed even -# though the DB is fine and the very next read is clean. Empirically a swarm of -# workers produced ~45 spurious .corrupt.bak of a *healthy*, progressing board -# in 20 min. Real corruption reproduces on every probe; a transient torn read -# does not. So require N consecutive non-ok probes (with a brief backoff) before -# quarantining + failing closed. Only the suspected-corrupt path pays this cost; -# a healthy DB returns after the first ok probe. -_HEALTH_CONFIRM_ATTEMPTS = 4 -# Exponential: 0.15s, 0.45s, 1.35s between attempts (~2s total). Real -# corruption is *permanent* — it still fails after seconds. The probe⇄ -# checkpoint contention that produces every observed false positive clears -# within a second or two (each quarantined copy later checked out ok and the -# next connect succeeded), so a sub-second confirmation window cannot -# distinguish the two; a multi-second one can. Only the suspected-corrupt -# path ever sleeps. -_HEALTH_CONFIRM_BACKOFF_SECONDS = 0.15 -_HEALTH_CONFIRM_BACKOFF_FACTOR = 3.0 -# The read-only arbiter gets the same persistence treatment: it samples at -# the *hottest* possible moment (immediately after every r/w probe failed), -# where even a read-only open can transiently report SQLITE_CORRUPT. Require -# the damage verdict to repeat across spaced attempts; any single clean or -# undecided read means transient. -_ARBITER_CONFIRM_ATTEMPTS = 3 -_ARBITER_BACKOFF_SECONDS = 1.0 +# The scheduled probe is READ-ONLY. A read/write integrity probe participates +# in WAL recovery/checkpointing, and under concurrent writers on a +# weak-durability FS (WSL2 virtual disk reports no DPO/FUA) it false-positived +# four distinct ways in production: a transient mid-checkpoint page read as +# malformed (~45 spurious .corrupt.bak of a *healthy*, progressing board in +# 20 min), an all-IOERR SHORT_READ storm that outlived a multi-probe +# confirmation loop, a hard SQLITE_CORRUPT at open that cleared on the very +# next read, and even a read-only arbiter sampled at the hottest possible +# moment (right after those r/w failures). A read-only probe at a *random* +# moment — which is what a TTL expiry is — never produced a false positive +# across the same period. So the guard probes ro-first and only ever opens +# read/write for the real connection. +# +# A damage verdict still must PERSIST before quarantining: real corruption is +# permanent, while probe⇄checkpoint contention clears in seconds. Require +# every spaced probe in a multi-second window to independently report damage; +# one clean or undecided read anywhere in the window means transient — log it +# and fail open (no error, no quarantine). Only the suspected-corrupt path +# ever sleeps; a healthy DB returns after the first ok probe. +_HEALTH_CONFIRM_ATTEMPTS = 4 # total spaced ro probes that must all report damage +_HEALTH_CONFIRM_SPACING_SECONDS = 1.0 # ``PRAGMA integrity_check`` can fail without the database being malformed: # when the probe races a concurrent WAL checkpoint (a swarm of workers on the # dispatch board), page reads come back as SQLITE_IOERR_SHORT_READ (522) — @@ -1677,21 +1672,33 @@ def _backup_corrupt_db(path: Path) -> Optional[Path]: def _guard_existing_db_is_healthy(path: Path) -> None: - """Run ``PRAGMA integrity_check`` on an existing non-empty DB file. - - Opens the probe in read/write mode so SQLite can recover or - checkpoint a healthy WAL/hot-journal DB before we declare it - corrupt. If the file is malformed, copy it (and any WAL/SHM - sidecars) to a timestamped backup and raise - :class:`KanbanDbCorruptError` so callers cannot silently recreate - the schema on top of a damaged DB. - - Transient lock/busy errors (``sqlite3.OperationalError``) are NOT - treated as corruption; they propagate raw so the caller sees a - normal lock failure and no spurious ``.corrupt`` backup is made. - - No-op for missing files, zero-byte files (treated as fresh), and - paths already proven healthy this process (cache hit). + """Verify an existing non-empty DB file via READ-ONLY integrity probes. + + The probe never opens the file read/write: a r/w ``integrity_check`` + participates in WAL recovery/checkpointing and false-positived four + distinct ways under concurrent writers on a weak-durability FS (see the + constants block above). The real connection that :func:`connect` opens + right after this guard is the only r/w open. + + Verdicts: + + * **ok** — stamp the TTL cache and return. + * **undecided** (lock/busy, hot WAL a ro connection cannot recover, + all-IOERR read failure) — fail OPEN without stamping: no error, no + quarantine; the next connect past the absent stamp re-probes. + Quarantine requires positive evidence of damage, and the connection + about to open will surface real problems itself (``cell_size_check`` + is ON and ``write_txn`` checks the page-count invariant post-commit). + * **damage** — must PERSIST: every spaced probe across a multi-second + window has to independently report damage. Real corruption is + permanent; probe⇄checkpoint contention clears in seconds. Only then + copy the file (and WAL/SHM sidecars) to a quarantine backup and raise + :class:`KanbanDbCorruptError` so callers cannot silently recreate the + schema on top of a damaged DB. A verdict that flickers clean mid-window + is logged and fails open. + + No-op for missing files, zero-byte files (treated as fresh), and paths + proven healthy within the TTL (cache hit). Path-trust note: ``path`` arrives via :func:`connect`, which itself resolves it from an explicit ``db_path`` argument, the @@ -1719,92 +1726,70 @@ def _guard_existing_db_is_healthy(path: Path) -> None: last_ok = _LAST_HEALTH_OK.get(str(resolved)) if last_ok is not None and (time.monotonic() - last_ok) < _HEALTH_CHECK_TTL_SECONDS: return - # Confirm before quarantining: a lone non-ok result is often a transient - # mid-checkpoint read on a no-FUA disk, not real corruption. Only declare - # the DB damaged if it fails every probe in a row; a single clean probe - # means it was a transient and the DB is healthy. ``OperationalError`` - # (lock/busy) still propagates raw from the first occurrence — never a - # quarantine. The healthy path costs exactly one probe (first ok → return). - reason: Optional[str] = None - for attempt in range(_HEALTH_CONFIRM_ATTEMPTS): - reason = _run_integrity_probe(resolved) - if reason is None: - break - if attempt + 1 < _HEALTH_CONFIRM_ATTEMPTS: - time.sleep( - _HEALTH_CONFIRM_BACKOFF_SECONDS - * (_HEALTH_CONFIRM_BACKOFF_FACTOR ** attempt) - ) - if reason is None: + verdict, reason = _readonly_probe(resolved) + if verdict == _RO_OK: _LAST_HEALTH_OK[str(resolved)] = time.monotonic() return - # Non-ok on every probe: force the next connect to re-probe instead of - # honoring a stale "ok" timestamp. + if verdict == _RO_UNDECIDED: + # No evidence either way. Fail open WITHOUT stamping so the next + # connect re-probes once the contention clears. + if reason: + _log.warning( + "kanban health probe: undecided read-only verdict on %s " + "(transient I/O, no quarantine): %s", resolved, reason, + ) + return + # Damage reported once. Force later connects to re-probe instead of + # honoring a stale "ok" stamp, then require the verdict to persist. _LAST_HEALTH_OK.pop(str(resolved), None) - # An all-IOERR failure means the probe could not *read* the file (e.g. a - # checkpoint-truncate race that outlived the confirmation loop), not that - # the content is malformed. Surface it like the lock/busy case — a raw - # transient error, no quarantine copy, no fail-closed corruption state. - if _integrity_failure_is_transient_io(reason): - _log.warning( - "kanban health probe: transient IOERR-family failure on %s " - "(checkpoint race, no quarantine): %s", resolved, reason, - ) - raise sqlite3.OperationalError( - f"kanban integrity probe could not read {resolved} after " - f"{_HEALTH_CONFIRM_ATTEMPTS} attempts (SQLITE_IOERR-family, e.g. " - f"SHORT_READ racing a checkpoint — transient I/O, not corruption): " - f"{reason}" - ) - # Last word goes to a READ-ONLY probe, and the damage verdict must - # PERSIST. The read/write probe participates in WAL recovery/ - # checkpointing, so under concurrent writers the race can surface as a - # hard SQLITE_CORRUPT ("database disk image is malformed") that clears - # on the next read — indistinguishable by string from real damage. A - # read-only connection avoids recovery, but it samples at the hottest - # possible moment (every r/w probe just failed), where even ro opens - # have been observed to transiently report SQLITE_CORRUPT on a healthy - # board. Real corruption is permanent; contention clears in seconds. So - # quarantine only if every spaced ro attempt independently confirms - # damage — one clean or undecided read means transient. - ro_reason: Optional[str] = None - for attempt in range(_ARBITER_CONFIRM_ATTEMPTS): - ro_reason = _readonly_integrity_verdict(resolved) - if ro_reason is None: - break - if attempt + 1 < _ARBITER_CONFIRM_ATTEMPTS: - time.sleep(_ARBITER_BACKOFF_SECONDS) - if ro_reason is None: - _log.warning( - "kanban health probe: r/w probe failed %dx on %s but read-only " - "verification passed (probe/checkpoint race, no quarantine): %s", - _HEALTH_CONFIRM_ATTEMPTS, resolved, reason, - ) - raise sqlite3.OperationalError( - f"kanban integrity probe failed {_HEALTH_CONFIRM_ATTEMPTS}x on " - f"{resolved} but a read-only integrity_check passed — transient " - f"probe/checkpoint race, not corruption: {reason}" - ) - # Damage confirmed by every read-only arbiter attempt over a multi-second + confirmed = reason + for _attempt in range(_HEALTH_CONFIRM_ATTEMPTS - 1): + time.sleep(_HEALTH_CONFIRM_SPACING_SECONDS) + verdict, confirmed = _readonly_probe(resolved) + if verdict == _RO_OK: + _log.warning( + "kanban health probe: damage verdict on %s did not persist " + "(first probe: %s) — transient contention, no quarantine", + resolved, reason, + ) + _LAST_HEALTH_OK[str(resolved)] = time.monotonic() + return + if verdict == _RO_UNDECIDED: + _log.warning( + "kanban health probe: damage verdict on %s went undecided " + "(first probe: %s; later: %s) — transient contention, " + "no quarantine", resolved, reason, confirmed or "", + ) + return + # Damage confirmed by every spaced read-only probe over a multi-second # window: this is the permanent kind. Quarantine and fail closed. backup = _backup_corrupt_db(resolved) raise KanbanDbCorruptError( resolved, backup, - f"{reason} (read-only verification x{_ARBITER_CONFIRM_ATTEMPTS}: {ro_reason})", + f"{reason} (read-only verification x{_HEALTH_CONFIRM_ATTEMPTS}: {confirmed})", ) -def _readonly_integrity_verdict(resolved: Path) -> Optional[str]: - """Arbiter probe for the about-to-quarantine path: ``PRAGMA - integrity_check`` over a read-only (``mode=ro``) connection. +_RO_OK = "ok" +_RO_UNDECIDED = "undecided" +_RO_DAMAGE = "damage" + + +def _readonly_probe(resolved: Path) -> tuple[str, Optional[str]]: + """One ``PRAGMA integrity_check`` over a read-only (``mode=ro``) connection. - Returns ``None`` when the DB is healthy **or** the verdict is - undecidable (lock/busy/cannot-open-readonly) — quarantine requires - positive evidence of damage, and an undecided probe just means the next - connect re-probes (the "ok" stamp was already evicted). Returns a short - reason string only when the read-only view itself reports damage, which - real corruption always does and the probe⇄checkpoint race never does. + Returns ``(verdict, reason)`` where verdict is :data:`_RO_OK` (healthy), + :data:`_RO_UNDECIDED` (no verdict either way: lock/busy, a hot WAL that a + read-only connection cannot recover, or an all-IOERR report such as 522 + SHORT_READ racing a checkpoint — *the read failed*, not *the content is + bad*), or :data:`_RO_DAMAGE` (the read-only view itself reports malformed + content, which real corruption always does and the probe⇄checkpoint race + never does persistently). + + Read-only on purpose: it stays out of WAL recovery/checkpointing, so it + cannot tear anything and does not contend with concurrent writers the way + a read/write probe does. """ try: probe = sqlite3.connect( @@ -1817,12 +1802,15 @@ def _readonly_integrity_verdict(resolved: Path) -> Optional[str]: finally: probe.close() except sqlite3.OperationalError: - return None # undecided — never quarantine without evidence + return (_RO_UNDECIDED, None) except sqlite3.DatabaseError as exc: - return f"read-only open failed: {exc}" + return (_RO_DAMAGE, f"read-only open failed: {exc}") if not row or (row[0] or "").lower() != "ok": - return f"integrity_check returned {row[0] if row else ''!r}" - return None + reason = f"integrity_check returned {row[0] if row else ''!r}" + if _integrity_failure_is_transient_io(reason): + return (_RO_UNDECIDED, reason) + return (_RO_DAMAGE, reason) + return (_RO_OK, None) def _integrity_failure_is_transient_io(reason: str) -> bool: @@ -1841,7 +1829,7 @@ def _integrity_failure_is_transient_io(reason: str) -> bool: prefix = "integrity_check returned " if not reason.startswith(prefix): return False - # _run_integrity_probe embeds the raw integrity_check row via !r; recover + # _readonly_probe embeds the raw integrity_check row via !r; recover # the original (possibly multi-line) text from its repr. try: text = ast.literal_eval(reason[len(prefix):]) @@ -1859,30 +1847,6 @@ def _integrity_failure_is_transient_io(reason: str) -> bool: ) -def _run_integrity_probe(resolved: Path) -> Optional[str]: - """One ``PRAGMA integrity_check`` pass. Returns ``None`` if healthy, else a - short reason string describing why it looked corrupt. - - Opens read/write so SQLite can replay a healthy WAL/hot-journal before the - check (a pure read-only open would flag a recoverable DB as corrupt). - ``sqlite3.OperationalError`` (lock/busy/transient IO) is re-raised, never - classified as corruption — the caller lets it propagate. - """ - try: - probe = _sqlite_connect(resolved) - try: - row = probe.execute("PRAGMA integrity_check").fetchone() - finally: - probe.close() - except sqlite3.OperationalError: - raise - except sqlite3.DatabaseError as exc: - return f"sqlite refused to open file: {exc}" - if not row or (row[0] or "").lower() != "ok": - return f"integrity_check returned {row[0] if row else ''!r}" - return None - - def connect( db_path: Optional[Path] = None, *, @@ -1945,8 +1909,8 @@ def connect( # and other invalid-header cases without opening a sqlite connection. _validate_sqlite_header(path) # Full integrity probe — catches corruption past the header (malformed - # pages, broken internal metadata). Cached per-path after first success - # via _INITIALIZED_PATHS so it only runs once per process per path. + # pages, broken internal metadata). Read-only, and rate-limited by the + # TTL'd _LAST_HEALTH_OK stamp so it runs at most once per TTL window. _guard_existing_db_is_healthy(path) resolved = str(path.resolve()) conn = _sqlite_connect(path) diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index e79008d34c0ae..a4db1dabf61de 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4411,15 +4411,16 @@ def test_health_guard_honors_ttl_cache_then_reprobes(tmp_path, monkeypatch): assert resolved not in kb._LAST_HEALTH_OK -def test_health_guard_ignores_transient_single_probe_failure(tmp_path, monkeypatch): - """A lone non-ok integrity probe must NOT quarantine a healthy DB. - - Regression for the spurious-``.corrupt.bak`` storm: under concurrent - writers on a no-FUA disk a read/write probe can transiently read a - mid-checkpoint page as malformed while the DB is fine. Observed live as - ~45 quarantine copies of a *healthy, progressing* board in 20 min. The - guard now requires every probe in a row to fail; a single clean probe - means the DB is healthy and nothing is quarantined. +def test_health_guard_flickering_damage_fails_open_no_quarantine(tmp_path, monkeypatch): + """A damage verdict that does not PERSIST across spaced probes must not + quarantine — and must not error the caller. + + Regression for the spurious-``.corrupt.bak`` storms: probe⇄checkpoint + contention can make an integrity probe transiently report damage on a + healthy, progressing board (observed live as ~45 quarantine copies in + 20 min). Real corruption is permanent; one clean read anywhere in the + confirmation window means transient. The guard fails OPEN (no exception) + and stamps the health cache from the clean read. """ db_path = tmp_path / "kanban.db" resolved = str(db_path.resolve()) @@ -4428,11 +4429,13 @@ def test_health_guard_ignores_transient_single_probe_failure(tmp_path, monkeypat kb._LAST_HEALTH_OK.pop(resolved, None) monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) - # First two probes flag corruption, the third comes back clean → transient. - probes = iter(["integrity_check returned 'malformed'", - "integrity_check returned 'malformed'", - None]) - monkeypatch.setattr(kb, "_run_integrity_probe", lambda _p: next(probes)) + # First two probes flag damage, the third comes back clean → transient. + probes = iter([ + (kb._RO_DAMAGE, "integrity_check returned 'malformed'"), + (kb._RO_DAMAGE, "integrity_check returned 'malformed'"), + (kb._RO_OK, None), + ]) + monkeypatch.setattr(kb, "_readonly_probe", lambda _p: next(probes)) kb._guard_existing_db_is_healthy(db_path) # must not raise assert kb._LAST_HEALTH_OK.get(resolved) is not None @@ -4459,49 +4462,33 @@ def test_health_guard_quarantines_persistent_corruption(tmp_path, monkeypatch): assert list(tmp_path.glob("*.corrupt.*.bak")) # quarantine happened -def test_health_guard_spurious_malformed_overruled_by_readonly_arbiter( - tmp_path, monkeypatch, -): - """A persistent r/w probe failure on a *healthy* file must not quarantine. - - Regression for the second spurious-quarantine shape: under checkpoint - contention the r/w probe can fail with a hard SQLITE_CORRUPT ("database - disk image is malformed") on open/first-read that clears on the next - read. That string is identical to real damage, so it cannot be - pattern-matched as transient — instead the read-only arbiter (which - stays out of WAL recovery and has never false-positived) gets the last - word: it reads the healthy file, says ok, and the guard surfaces a raw - ``OperationalError`` with no quarantine copy. +def test_health_guard_undecided_probe_fails_open_without_stamp(tmp_path, monkeypatch): + """An undecided probe (lock/busy, hot WAL, unreadable pages) must fail + OPEN: no exception, no quarantine — but also no health stamp, so the + next connect re-probes once contention clears. Quarantine (and blocking + the caller at all) requires positive evidence of damage. """ db_path = tmp_path / "kanban.db" resolved = str(db_path.resolve()) - kb.init_db(db_path=db_path) # healthy on disk + kb.init_db(db_path=db_path) kb._INITIALIZED_PATHS.discard(resolved) kb._LAST_HEALTH_OK.pop(resolved, None) - monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) - # The r/w probe persistently reports the hard-corrupt open failure. - monkeypatch.setattr( - kb, "_run_integrity_probe", - lambda _p: "sqlite refused to open file: database disk image is malformed", - ) + monkeypatch.setattr(kb, "_readonly_probe", lambda _p: (kb._RO_UNDECIDED, None)) - with pytest.raises(sqlite3.OperationalError, match="read-only integrity_check passed"): - kb._guard_existing_db_is_healthy(db_path) - assert resolved not in kb._LAST_HEALTH_OK + kb._guard_existing_db_is_healthy(db_path) # must not raise + assert resolved not in kb._LAST_HEALTH_OK # no stamp without evidence assert not list(tmp_path.glob("*.corrupt.*.bak")) # nothing quarantined -def test_health_guard_flickering_arbiter_verdict_is_transient(tmp_path, monkeypatch): - """A damage verdict that does not PERSIST across the arbiter's spaced - attempts must not quarantine. +def test_health_guard_damage_going_undecided_is_transient(tmp_path, monkeypatch): + """A damage verdict that degrades to undecided mid-window must not + quarantine and must not stamp. - Regression for the third spurious-quarantine shape: the arbiter samples - at the hottest possible moment — immediately after every r/w probe - failed — and even a read-only open was observed to transiently report - SQLITE_CORRUPT there (the quarantined copy itself later checked out - ``ok``). Real corruption is permanent: it reports damage on every - attempt, seconds apart. One clean read anywhere in the window means - transient — raw ``OperationalError``, nothing quarantined. + Regression for the hottest-moment sampling shape: a probe taken right + after another probe reported damage was observed to transiently report + SQLITE_CORRUPT on a healthy board (the quarantined copy itself later + checked out ``ok``). Real corruption reports damage on every attempt, + seconds apart; anything less is contention. """ db_path = tmp_path / "kanban.db" resolved = str(db_path.resolve()) @@ -4509,32 +4496,35 @@ def test_health_guard_flickering_arbiter_verdict_is_transient(tmp_path, monkeypa kb._INITIALIZED_PATHS.discard(resolved) kb._LAST_HEALTH_OK.pop(resolved, None) monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) - monkeypatch.setattr( - kb, "_run_integrity_probe", - lambda _p: "sqlite refused to open file: database disk image is malformed", - ) - # First arbiter read still hits the contention window; the second is clean. - verdicts = iter(["read-only open failed: database disk image is malformed", - None]) - monkeypatch.setattr(kb, "_readonly_integrity_verdict", lambda _p: next(verdicts)) + probes = iter([ + (kb._RO_DAMAGE, "read-only open failed: database disk image is malformed"), + (kb._RO_UNDECIDED, None), + ]) + monkeypatch.setattr(kb, "_readonly_probe", lambda _p: next(probes)) - with pytest.raises(sqlite3.OperationalError, match="read-only integrity_check passed"): - kb._guard_existing_db_is_healthy(db_path) + kb._guard_existing_db_is_healthy(db_path) # must not raise assert resolved not in kb._LAST_HEALTH_OK assert not list(tmp_path.glob("*.corrupt.*.bak")) # nothing quarantined -def test_readonly_integrity_verdict(tmp_path): - """Arbiter semantics: healthy → None (no quarantine), damaged → reason - string (positive evidence, quarantine proceeds).""" +def test_readonly_probe_verdicts(tmp_path, monkeypatch): + """Probe semantics: healthy → ok, damaged → damage (positive evidence), + lock/busy → undecided (never evidence).""" healthy = tmp_path / "healthy.db" kb.init_db(db_path=healthy) - assert kb._readonly_integrity_verdict(healthy.resolve()) is None + assert kb._readonly_probe(healthy.resolve()) == (kb._RO_OK, None) damaged = tmp_path / "damaged.db" _write_corrupt_db(damaged) - verdict = kb._readonly_integrity_verdict(damaged.resolve()) - assert verdict is not None + verdict, reason = kb._readonly_probe(damaged.resolve()) + assert verdict == kb._RO_DAMAGE + assert reason is not None + + def locked_connect(*_a, **_k): + raise sqlite3.OperationalError("database is locked") + + monkeypatch.setattr(kb.sqlite3, "connect", locked_connect) + assert kb._readonly_probe(healthy.resolve()) == (kb._RO_UNDECIDED, None) # Real-world shape of an integrity_check racing a concurrent WAL checkpoint: @@ -4549,34 +4539,41 @@ def test_readonly_integrity_verdict(tmp_path): ) -def test_health_guard_persistent_short_read_raises_operational_not_quarantine( +def test_health_guard_short_read_report_is_undecided_not_quarantine( tmp_path, monkeypatch, ): - """An integrity failure that is *only* unreadable pages (IOERR family, - e.g. 522 SHORT_READ) must not quarantine, even when it outlives the whole - confirmation loop. - - Regression for the post-confirm-loop quarantine storm: under sustained - worker load the probe⇄checkpoint race persisted across all - ``_HEALTH_CONFIRM_ATTEMPTS`` probes, so a healthy, progressing board was - still copied to ``.corrupt.bak`` and connects failed closed. The read - failing is not the content being malformed — surface it like the - lock/busy case (raw ``OperationalError``), no backup, and evict the - health stamp so the next connect re-probes. + """An integrity report that is *only* unreadable pages (IOERR family, + e.g. 522 SHORT_READ) classifies as undecided: fail open, no quarantine, + no health stamp. + + Regression for the quarantine storm under sustained worker load: the + probe⇄checkpoint race makes page reads fail (the read failed — the + content is not malformed), and a healthy, progressing board was copied + to ``.corrupt.bak`` with connects failing closed. Exercises the real + ``_readonly_probe`` → ``_integrity_failure_is_transient_io`` path via a + stubbed connection that returns the observed SHORT_READ report. """ db_path = tmp_path / "kanban.db" resolved = str(db_path.resolve()) kb.init_db(db_path=db_path) kb._INITIALIZED_PATHS.discard(resolved) kb._LAST_HEALTH_OK.pop(resolved, None) - monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) + + class _ShortReadConn: + def execute(self, _sql): + return self + + def fetchone(self): + return (_SHORT_READ_INTEGRITY_TEXT,) + + def close(self): + pass + monkeypatch.setattr( - kb, "_run_integrity_probe", - lambda _p: f"integrity_check returned {_SHORT_READ_INTEGRITY_TEXT!r}", + kb.sqlite3, "connect", lambda *_a, **_k: _ShortReadConn() ) - with pytest.raises(sqlite3.OperationalError): - kb._guard_existing_db_is_healthy(db_path) + kb._guard_existing_db_is_healthy(db_path) # must not raise assert resolved not in kb._LAST_HEALTH_OK assert not list(tmp_path.glob("*.corrupt.*.bak")) # nothing quarantined From a59e6e0df103b954ebcfd49ad13a3fb22dcd664a Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Tue, 9 Jun 2026 19:01:52 -0400 Subject: [PATCH 07/11] fix(kanban): raise wal_autocheckpoint from 100 to 1000 MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Every checkpoint rewrites main-DB pages — exactly the torn-write window on a weak-durability FS (WSL2 virtual disk: write cache enabled, no DPO/FUA), and the contention window integrity probes race against. 100 forced a checkpoint roughly every ~400KB written, i.e. near-constant churn under a dispatcher swarm on an event-heavy board; that churn is what every observed spurious-corruption shape raced against. 1000 (the SQLite default, now asserted explicitly) means ~10x fewer checkpoint events. Durability is unchanged: synchronous=FULL still fsyncs the WAL at commit, so a crash replays from the WAL regardless of when the last checkpoint ran. Co-Authored-By: Claude Opus 4.8 --- hermes_cli/kanban_db.py | 10 +++++++++- tests/hermes_cli/test_kanban_db.py | 11 ++++++++--- 2 files changed, 17 insertions(+), 4 deletions(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index fb36079a389d9..7a59571ee2e66 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -1929,7 +1929,15 @@ def connect( # FULL (was NORMAL): fsync before each checkpoint to narrow the # crash window that can leave a b-tree page header torn. conn.execute("PRAGMA synchronous=FULL") - conn.execute("PRAGMA wal_autocheckpoint=100") + # 1000 (SQLite default; was 100): every checkpoint rewrites + # main-DB pages, which is exactly the torn-write window on a + # weak-durability FS — and the contention window the health + # probes race against. 100 forced a checkpoint roughly every + # ~400KB written, i.e. near-constant churn under a worker + # swarm. Fewer, larger checkpoints shrink both windows; the + # WAL staying a few MB longer costs nothing (synchronous=FULL + # fsyncs the WAL at commit, so durability is unchanged). + conn.execute("PRAGMA wal_autocheckpoint=1000") conn.execute("PRAGMA foreign_keys=ON") # Zero freed pages so a later torn write cannot expose stale # cell content; persisted in the DB header for new DBs. diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index a4db1dabf61de..9d85341d6ee18 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4951,13 +4951,18 @@ def counting_check(c): conn.close() -def test_connect_sets_wal_autocheckpoint_100(tmp_path): - """connect() sets wal_autocheckpoint to 100.""" +def test_connect_sets_wal_autocheckpoint_1000(tmp_path): + """connect() sets wal_autocheckpoint to 1000 (the SQLite default, + asserted explicitly): every checkpoint rewrites main-DB pages — the + torn-write window on a weak-durability FS and the contention window + integrity probes race against. 100 forced near-constant checkpoint + churn under a worker swarm; durability is unchanged because + synchronous=FULL fsyncs the WAL at commit.""" from hermes_cli.kanban_db import connect db = tmp_path / "test.db" conn = connect(db_path=db) val = conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] - assert val == 100 + assert val == 1000 conn.close() From baaa8fdee38b8ca1b76caa7e726e9639f94572dd Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Tue, 14 Jul 2026 11:21:27 -0400 Subject: [PATCH 08/11] fix(kanban): re-probe health and raise wal_autocheckpoint on connect fast path MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit connect()'s _INITIALIZED_PATHS fast path (the #36644 no-cross-process-lock optimization) returned before _guard_existing_db_is_healthy() and set wal_autocheckpoint=100. So the TTL health re-probe and the 1000-page checkpoint setting only ever applied to the first-open init path — a long-lived writer (the gateway dispatcher) took the fast path on every tick and thus never re-probed and checkpointed ~10x more often than intended, exactly the amplification the TTL guard and the raise to 1000 were meant to stop. Wire the bounded health check into the fast path: call the read-only, TTL-gated guard before the r/w open (a dict lookup on a cache hit; it takes no cross-process lock, so it does not reintroduce the #36644 stall), and set wal_autocheckpoint=1000 there too so both paths match. Adds two end-to-end connect() regressions: the fast path re-probes after TTL expiry (and fails closed on persistent damage), and wal_autocheckpoint is 1000 on both the init and already-initialized paths. Both fail without the change. Addresses maintainer review on NousResearch/hermes-agent#41795. Co-Authored-By: Claude Opus 4.8 (1M context) --- hermes_cli/kanban_db.py | 18 ++++++- tests/hermes_cli/test_kanban_db.py | 86 ++++++++++++++++++++++++++++++ 2 files changed, 103 insertions(+), 1 deletion(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index 7a59571ee2e66..b0a547d992e5a 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -1888,6 +1888,17 @@ def connect( # connection with WAL/pragmas under the cheap in-process _INIT_LOCK. resolved = str(path.resolve()) if resolved in _INITIALIZED_PATHS: + # Skipping the cross-process init lock does NOT mean skipping the health + # check. Health is a separate concern from "already initialized": a DB + # that was healthy at first-open can be torn later (e.g. an interrupted + # checkpoint), and a long-lived writer that only ever took this fast + # path would keep opening and checkpointing the damaged file forever — + # the amplification loop the TTL guard exists to stop. The guard is + # read-only and takes no cross-process lock, so it does not reintroduce + # the #36644 stall this fast path exists to avoid; on a TTL cache hit it + # is a dict lookup. Run it before the r/w open so a confirmed-damage + # verdict quarantines and raises with no connection to unwind. + _guard_existing_db_is_healthy(path) conn = _sqlite_connect(path) try: conn.row_factory = sqlite3.Row @@ -1895,7 +1906,12 @@ def connect( from hermes_state import apply_wal_with_fallback apply_wal_with_fallback(conn, db_label=f"kanban.db ({path.name})") conn.execute("PRAGMA synchronous=FULL") - conn.execute("PRAGMA wal_autocheckpoint=100") + # 1000 (SQLite default; was 100) on this path too: steady-state + # connects are the common case for a long-lived writer, so the + # checkpoint cadence here matters as much as on the init path. + # See the matching note in the init path below for the full + # torn-write / contention-window rationale. + conn.execute("PRAGMA wal_autocheckpoint=1000") conn.execute("PRAGMA foreign_keys=ON") conn.execute("PRAGMA secure_delete=ON") conn.execute("PRAGMA cell_size_check=ON") diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index 9d85341d6ee18..66bcb028b5b04 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4966,6 +4966,92 @@ def test_connect_sets_wal_autocheckpoint_1000(tmp_path): conn.close() +def test_connect_sets_wal_autocheckpoint_1000_on_both_paths(tmp_path): + """wal_autocheckpoint must be 1000 on BOTH connect() paths. + + Regression: the ``_INITIALIZED_PATHS`` fast path (the steady-state connect + a long-lived writer takes on every tick after first-open) used to leave the + setting at 100 while only the first-open init path was raised to 1000. That + silently reintroduced ~10x more checkpoint churn on the common path — the + exact torn-write / probe-contention window the raise to 1000 was meant to + shrink. Assert both the init connect and a subsequent fast-path connect. + """ + db = tmp_path / "kanban.db" + resolved = str(db.resolve()) + kb._INITIALIZED_PATHS.discard(resolved) + + # First connect: slow/init path. Populates _INITIALIZED_PATHS. + conn = kb.connect(db_path=db) + assert resolved in kb._INITIALIZED_PATHS # next connect takes the fast path + assert conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] == 1000 + conn.close() + + # Second connect: fast path (already initialized). + conn = kb.connect(db_path=db) + assert conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] == 1000 + conn.close() + + +def test_connect_fast_path_reprobes_health_after_ttl(tmp_path, monkeypatch): + """A post-init connect() re-probes health on the TTL — end to end. + + Regression for the fast-path blind spot: connect() returns early for a path + already in ``_INITIALIZED_PATHS`` (the #36644 no-cross-process-lock + optimization). If that early return skips the health guard entirely, a + long-lived writer that first connected while healthy would keep opening and + checkpointing a later-torn DB *forever* — the amplification loop the TTL + guard exists to stop, reintroduced on the hot path. This drives the whole + thing through ``connect()`` (not the guard in isolation) and asserts: within + the TTL the fast path does not re-probe (bounded cost), past the TTL it does + re-probe exactly once, and a persistent-damage verdict fails the connect + closed instead of opening + checkpointing the file. + """ + db_path = tmp_path / "kanban.db" + resolved = str(db_path.resolve()) + fake_now = [1000.0] + monkeypatch.setattr(kb.time, "monotonic", lambda: fake_now[0]) + monkeypatch.setattr(kb.time, "sleep", lambda *_a, **_k: None) + + kb._INITIALIZED_PATHS.discard(resolved) + kb._LAST_HEALTH_OK.pop(resolved, None) + + # Init, then a second (fast-path) connect while healthy stamps the TTL + # cache from the fast path's own guard call. + kb.connect(db_path=db_path).close() + assert resolved in kb._INITIALIZED_PATHS + kb.connect(db_path=db_path).close() # fast path, healthy → stamps "ok" + assert kb._LAST_HEALTH_OK.get(resolved) == 1000.0 + + # Spy on the probe to prove the fast path actually consults it rather than + # skipping health for the whole process lifetime. + calls = [] + real_probe = kb._readonly_probe + monkeypatch.setattr( + kb, "_readonly_probe", lambda p: (calls.append(p), real_probe(p))[1] + ) + + # Within the TTL: cache hit, no re-probe. + fake_now[0] = 1000.0 + kb._HEALTH_CHECK_TTL_SECONDS - 1 + kb.connect(db_path=db_path).close() + assert calls == [] + + # Past the TTL: the fast path re-probes (exactly once for this connect). + fake_now[0] = 1000.0 + kb._HEALTH_CHECK_TTL_SECONDS + 1 + kb.connect(db_path=db_path).close() + assert len(calls) == 1 + + # And when that re-probe reports persistent damage, the fast path fails + # closed rather than opening + checkpointing the file. + fake_now[0] = 1000.0 + 2 * kb._HEALTH_CHECK_TTL_SECONDS + 2 + monkeypatch.setattr( + kb, "_readonly_probe", + lambda _p: (kb._RO_DAMAGE, "integrity_check returned 'malformed'"), + ) + with pytest.raises(kb.KanbanDbCorruptError): + kb.connect(db_path=db_path) + assert resolved not in kb._LAST_HEALTH_OK + + def test_write_txn_check_reads_correct_header_fields(tmp_path): """Synthetic DB file with mismatched header page_count triggers the check.""" import struct From adaf10ec1c21f0768c02911148eed8f71e50bdc2 Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Wed, 15 Jul 2026 17:21:14 -0400 Subject: [PATCH 09/11] fix(kanban): keep the 100-page checkpoint pacemaker on the connect fast path Local stopgap, not pushed to PR #41795. Raising the fast path to 1000 (d228f239b, deployed 2026-07-15 11:27) removed the long-lived writers' small-checkpoint pacemaker: gateway/webui steady-state connects set the effective WAL ceiling for the whole fleet, and at 1000 pages checkpoints became ~4MB writebacks 10x rarer. On this WSL2 no-FUA vhdx each writeback is the torn-write window: three real index-count corruptions on task_events followed within six hours, on a board that ran a month clean at 100 and at 6x lighter load than its heaviest clean day (2026-07-13, 7634 events). Keep the init path at 1000 and the fast-path health guard as-is; only the steady-state autocheckpoint returns to 100. The read-only-first guard fails open on contention, so small-checkpoint churn no longer mints probe FPs. Co-Authored-By: Claude Fable 5 --- hermes_cli/kanban_db.py | 21 +++++++++++++++------ tests/hermes_cli/test_kanban_db.py | 27 ++++++++++++++++----------- 2 files changed, 31 insertions(+), 17 deletions(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index b0a547d992e5a..32af6dda88eb7 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -1906,12 +1906,21 @@ def connect( from hermes_state import apply_wal_with_fallback apply_wal_with_fallback(conn, db_label=f"kanban.db ({path.name})") conn.execute("PRAGMA synchronous=FULL") - # 1000 (SQLite default; was 100) on this path too: steady-state - # connects are the common case for a long-lived writer, so the - # checkpoint cadence here matters as much as on the init path. - # See the matching note in the init path below for the full - # torn-write / contention-window rationale. - conn.execute("PRAGMA wal_autocheckpoint=1000") + # 100 on the steady-state path, NOT 1000 like the init path + # below. Long-lived writers (gateway dispatcher, webui) take + # this path on every tick, so their threshold sets the + # effective WAL ceiling for the whole fleet: any of their + # commits past ~100 pages checkpoints ~400KB. At 1000 the + # writeback grows to ~4MB bursts 10x rarer — and on a + # weak-durability FS (WSL2 vhdx, no FUA) each burst is the + # torn-write window. Field data 2026-07-15: raising this to + # 1000 preceded three real index-tear corruptions within + # hours on a board that had run a month clean at 100, at 6x + # LIGHTER load than its heaviest clean day. The FP-contention + # rationale for 1000 no longer applies here: the read-only + # first guard fails open on contention, so frequent small + # checkpoints cost nothing but keep the torn window small. + conn.execute("PRAGMA wal_autocheckpoint=100") conn.execute("PRAGMA foreign_keys=ON") conn.execute("PRAGMA secure_delete=ON") conn.execute("PRAGMA cell_size_check=ON") diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index 66bcb028b5b04..b4f562303222a 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4966,15 +4966,20 @@ def test_connect_sets_wal_autocheckpoint_1000(tmp_path): conn.close() -def test_connect_sets_wal_autocheckpoint_1000_on_both_paths(tmp_path): - """wal_autocheckpoint must be 1000 on BOTH connect() paths. - - Regression: the ``_INITIALIZED_PATHS`` fast path (the steady-state connect - a long-lived writer takes on every tick after first-open) used to leave the - setting at 100 while only the first-open init path was raised to 1000. That - silently reintroduced ~10x more checkpoint churn on the common path — the - exact torn-write / probe-contention window the raise to 1000 was meant to - shrink. Assert both the init connect and a subsequent fast-path connect. +def test_connect_sets_wal_autocheckpoint_100_on_fast_path(tmp_path): + """wal_autocheckpoint is 1000 on the init path but 100 on the fast path. + + The steady-state fast path is what long-lived writers (gateway dispatcher, + webui) take on every tick, so their threshold sets the effective WAL + ceiling for every process sharing the board: any of their commits past + ~100 pages checkpoints ~400KB. Raising the fast path to 1000 (2026-07-15) + made checkpoints ~4MB bursts 10x rarer, and on a weak-durability FS (WSL2 + vhdx) each burst is the torn-write window — three real index-tear + corruptions followed within hours on a board that had run a month clean + at 100, at far lighter load. The read-only-first guard fails open on + contention, so the small-checkpoint churn no longer causes probe false + positives. Assert the init connect keeps 1000 and a subsequent fast-path + connect drops to 100. """ db = tmp_path / "kanban.db" resolved = str(db.resolve()) @@ -4986,9 +4991,9 @@ def test_connect_sets_wal_autocheckpoint_1000_on_both_paths(tmp_path): assert conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] == 1000 conn.close() - # Second connect: fast path (already initialized). + # Second connect: fast path (already initialized) — the pacemaker. conn = kb.connect(db_path=db) - assert conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] == 1000 + assert conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] == 100 conn.close() From 21c9f1081364171266f639e1d1680715f7746157 Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Thu, 16 Jul 2026 20:19:15 -0400 Subject: [PATCH 10/11] fix(kanban): quarantine forensics + reconcile wal_autocheckpoint=100 on both connect paths - _backup_corrupt_db captures WAL/SHM bytes BEFORE the main-file hash+copy pass (every 2026-07-15 quarantine recorded a 0-byte WAL because sidecars were copied last; the WAL is the primary forensic artifact) - confirmed quarantines append incident context (full integrity report, MemAvailable, / and /mnt/c free space, fd holders + cmdlines) to /quarantine-forensics.jsonl - init path now matches the fast path at wal_autocheckpoint=100 and both folk-theory comments are replaced: the value is a labeled precaution, not a root-cause fix (analysis: ~/kanban-db-investigation/REVIEW.md) Co-Authored-By: Claude Fable 5 --- hermes_cli/kanban_db.py | 194 ++++++++++++++++++++++++----- tests/hermes_cli/test_kanban_db.py | 43 +++---- 2 files changed, 186 insertions(+), 51 deletions(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index 32af6dda88eb7..5569605d5e779 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -1640,6 +1640,26 @@ def _backup_corrupt_db(path: Path) -> Optional[Path]: resolved = path.resolve() parent = resolved.parent base_name = resolved.name # basename only + # Capture WAL/SHM bytes FIRST, before the multi-MB hash+copy pass over the + # main file. Every 2026-07-15 quarantine recorded a 0-byte WAL because the + # sidecars were copied last — by then a checkpoint/truncate had already + # emptied them. The WAL is the primary forensic artifact for + # index-vs-table damage; grab its bytes at T0 and write them out once the + # content-addressed backup name is known. Size-capped so a pathological + # WAL cannot balloon memory (falls back to a late copy2 in that case). + sidecar_bytes: dict[str, Optional[bytes]] = {} + _SIDECAR_CAPTURE_MAX = 256 * 1024 * 1024 + for suffix in ("-wal", "-shm"): + sidecar = parent / (base_name + suffix) + try: + if sidecar.parent != parent or not sidecar.exists(): + continue + if sidecar.stat().st_size > _SIDECAR_CAPTURE_MAX: + sidecar_bytes[suffix] = None # marker: copy late instead + else: + sidecar_bytes[suffix] = sidecar.read_bytes() + except OSError: + continue digest = hashlib.sha256() try: with resolved.open("rb") as handle: @@ -1657,20 +1677,138 @@ def _backup_corrupt_db(path: Path) -> Optional[Path]: shutil.copy2(resolved, candidate) except OSError: return None - for suffix in ("-wal", "-shm"): - sidecar = parent / (base_name + suffix) - if sidecar.parent != parent or not sidecar.exists(): - continue + for suffix, data in sidecar_bytes.items(): sidecar_backup = parent / (candidate.name + suffix) if sidecar_backup.parent != parent or sidecar_backup.exists(): continue try: - shutil.copy2(sidecar, sidecar_backup) + if data is not None: + sidecar_backup.write_bytes(data) + else: + # Oversized sidecar: late direct copy is better than nothing. + shutil.copy2(parent / (base_name + suffix), sidecar_backup) except OSError: pass return candidate +def _statvfs_free_mb(mount: str) -> Optional[int]: + """Free MB on a filesystem, or None if unavailable (e.g. no /mnt/c).""" + try: + st = os.statvfs(mount) + return int(st.f_bavail * st.f_frsize // (1024 * 1024)) + except OSError: + return None + + +def _mem_available_mb() -> Optional[int]: + try: + for line in Path("/proc/meminfo").read_text().splitlines(): + if line.startswith("MemAvailable:"): + return int(line.split()[1]) // 1024 + except (OSError, ValueError, IndexError): + pass + return None + + +def _collect_db_holders(target: Path, limit: int = 32) -> list[dict[str, Any]]: + """Best-effort /proc scan for processes holding an fd on the DB or its + sidecars. Answers "who was still writing?" at quarantine time — the + 2026-07-15 17:04 double-quarantine proved open holders keep committing to + a condemned file after new connects start failing closed. + """ + needle = str(target) + holders: list[dict[str, Any]] = [] + me = os.getpid() + proc_root = Path("/proc") + if not proc_root.is_dir(): + return holders + for proc in proc_root.iterdir(): + if len(holders) >= limit: + break + if not proc.name.isdigit() or int(proc.name) == me: + continue + try: + fds = list((proc / "fd").iterdir()) + except OSError: + continue + for fd in fds: + try: + fd_target = os.readlink(fd) + except OSError: + continue + if fd_target.startswith(needle): + try: + cmdline = ( + (proc / "cmdline").read_bytes() + .replace(b"\x00", b" ").decode(errors="replace").strip() + ) + except OSError: + cmdline = "?" + holders.append({"pid": int(proc.name), "cmdline": cmdline[:300]}) + break + return holders + + +def _integrity_report_lines(resolved: Path, limit: int = 20) -> list[str]: + """Up to ``limit`` lines of integrity_check output over a fresh ro + connection (the guard's probes only keep the first row).""" + try: + conn = sqlite3.connect( + f"{resolved.as_uri()}?mode=ro", uri=True, timeout=5, + ) + try: + rows = conn.execute(f"PRAGMA integrity_check({int(limit)})").fetchall() + finally: + conn.close() + except sqlite3.Error as exc: + return [f""] + lines: list[str] = [] + for row in rows: + lines.extend(str(row[0]).splitlines()) + return lines[:limit] + + +def _write_quarantine_forensics( + resolved: Path, reason: str, backup: Optional[Path], +) -> None: + """Append one JSON line of incident context next to the board. + + The 2026-07-15 incident was undiagnosable after the fact: WAL sizes, + memory/disk pressure, and the set of live writers were all gone by the + time a human looked. Capture them at the only moment they exist — the + confirmed-damage verdict. Best-effort by design: forensics must never + turn a quarantine into a crash. + """ + try: + def _size(p: Path) -> Optional[int]: + try: + return p.stat().st_size if p.exists() else None + except OSError: + return None + + record = { + "ts": time.strftime("%Y-%m-%dT%H:%M:%S%z"), + "db": str(resolved), + "reason": reason, + "backup": str(backup) if backup is not None else None, + "db_bytes": _size(resolved), + "wal_bytes": _size(resolved.with_name(resolved.name + "-wal")), + "shm_bytes": _size(resolved.with_name(resolved.name + "-shm")), + "mem_available_mb": _mem_available_mb(), + "free_mb": {"/": _statvfs_free_mb("/"), "/mnt/c": _statvfs_free_mb("/mnt/c")}, + "holders": _collect_db_holders(resolved), + "integrity": _integrity_report_lines(resolved), + "pid": os.getpid(), + "argv": sys.argv[:6], + } + out = resolved.parent / "quarantine-forensics.jsonl" + with out.open("a", encoding="utf-8") as fh: + fh.write(json.dumps(record, ensure_ascii=False) + "\n") + except Exception: + _log.exception("quarantine forensics capture failed (non-fatal)") + + def _guard_existing_db_is_healthy(path: Path) -> None: """Verify an existing non-empty DB file via READ-ONLY integrity probes. @@ -1764,6 +1902,11 @@ def _guard_existing_db_is_healthy(path: Path) -> None: # Damage confirmed by every spaced read-only probe over a multi-second # window: this is the permanent kind. Quarantine and fail closed. backup = _backup_corrupt_db(resolved) + _write_quarantine_forensics( + resolved, + f"{reason} (read-only verification x{_HEALTH_CONFIRM_ATTEMPTS}: {confirmed})", + backup, + ) raise KanbanDbCorruptError( resolved, backup, @@ -1906,20 +2049,19 @@ def connect( from hermes_state import apply_wal_with_fallback apply_wal_with_fallback(conn, db_label=f"kanban.db ({path.name})") conn.execute("PRAGMA synchronous=FULL") - # 100 on the steady-state path, NOT 1000 like the init path - # below. Long-lived writers (gateway dispatcher, webui) take - # this path on every tick, so their threshold sets the - # effective WAL ceiling for the whole fleet: any of their - # commits past ~100 pages checkpoints ~400KB. At 1000 the - # writeback grows to ~4MB bursts 10x rarer — and on a - # weak-durability FS (WSL2 vhdx, no FUA) each burst is the - # torn-write window. Field data 2026-07-15: raising this to - # 1000 preceded three real index-tear corruptions within - # hours on a board that had run a month clean at 100, at 6x - # LIGHTER load than its heaviest clean day. The FP-contention - # rationale for 1000 no longer applies here: the read-only - # first guard fails open on contention, so frequent small - # checkpoints cost nothing but keep the torn window small. + # 100, matching the init path below — the two call sites MUST + # agree (they shipped contradictory values + theories for a + # day; wal_autocheckpoint is per-connection, so a mixed fleet + # makes any field observation uninterpretable). This value is + # a labeled PRECAUTION, not a root-cause fix: the 2026-07-15 + # corruptions were index-ahead-of-table damage with an EMPTY + # WAL, which no checkpoint-burst-size mechanism explains, and + # in this fleet checkpoint cadence is dominated by + # last-connection-close checkpoints (short-lived CLI/webui + # connections), not by this threshold. Do not "fix" this to + # 1000 (or defend 100) on the strength of any earlier comment + # here — both prior theories failed direct testing. Full + # analysis: ~/kanban-db-investigation/REVIEW.md. conn.execute("PRAGMA wal_autocheckpoint=100") conn.execute("PRAGMA foreign_keys=ON") conn.execute("PRAGMA secure_delete=ON") @@ -1954,15 +2096,11 @@ def connect( # FULL (was NORMAL): fsync before each checkpoint to narrow the # crash window that can leave a b-tree page header torn. conn.execute("PRAGMA synchronous=FULL") - # 1000 (SQLite default; was 100): every checkpoint rewrites - # main-DB pages, which is exactly the torn-write window on a - # weak-durability FS — and the contention window the health - # probes race against. 100 forced a checkpoint roughly every - # ~400KB written, i.e. near-constant churn under a worker - # swarm. Fewer, larger checkpoints shrink both windows; the - # WAL staying a few MB longer costs nothing (synchronous=FULL - # fsyncs the WAL at commit, so durability is unchanged). - conn.execute("PRAGMA wal_autocheckpoint=1000") + # 100, matching the fast path above — keep the call sites in + # agreement. Labeled precaution, not a root-cause fix; see the + # fast-path comment and ~/kanban-db-investigation/REVIEW.md + # before changing either value. + conn.execute("PRAGMA wal_autocheckpoint=100") conn.execute("PRAGMA foreign_keys=ON") # Zero freed pages so a later torn write cannot expose stale # cell content; persisted in the DB header for new DBs. diff --git a/tests/hermes_cli/test_kanban_db.py b/tests/hermes_cli/test_kanban_db.py index b4f562303222a..46e0d3a30f6a4 100644 --- a/tests/hermes_cli/test_kanban_db.py +++ b/tests/hermes_cli/test_kanban_db.py @@ -4951,35 +4951,32 @@ def counting_check(c): conn.close() -def test_connect_sets_wal_autocheckpoint_1000(tmp_path): - """connect() sets wal_autocheckpoint to 1000 (the SQLite default, - asserted explicitly): every checkpoint rewrites main-DB pages — the - torn-write window on a weak-durability FS and the contention window - integrity probes race against. 100 forced near-constant checkpoint - churn under a worker swarm; durability is unchanged because - synchronous=FULL fsyncs the WAL at commit.""" +def test_connect_sets_wal_autocheckpoint_100(tmp_path): + """connect() sets wal_autocheckpoint=100 on the init path. + + 100 is a labeled precaution while the 2026-07-15 corruption root cause is + unproven — not a mechanism-backed fix (both prior theories failed direct + testing; see ~/kanban-db-investigation/REVIEW.md). What this test actually + protects is the DECISION, whatever the value: change it deliberately, in + both call sites at once, never as a drive-by.""" from hermes_cli.kanban_db import connect db = tmp_path / "test.db" conn = connect(db_path=db) val = conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] - assert val == 1000 + assert val == 100 conn.close() def test_connect_sets_wal_autocheckpoint_100_on_fast_path(tmp_path): - """wal_autocheckpoint is 1000 on the init path but 100 on the fast path. - - The steady-state fast path is what long-lived writers (gateway dispatcher, - webui) take on every tick, so their threshold sets the effective WAL - ceiling for every process sharing the board: any of their commits past - ~100 pages checkpoints ~400KB. Raising the fast path to 1000 (2026-07-15) - made checkpoints ~4MB bursts 10x rarer, and on a weak-durability FS (WSL2 - vhdx) each burst is the torn-write window — three real index-tear - corruptions followed within hours on a board that had run a month clean - at 100, at far lighter load. The read-only-first guard fails open on - contention, so the small-checkpoint churn no longer causes probe false - positives. Assert the init connect keeps 1000 and a subsequent fast-path - connect drops to 100. + """wal_autocheckpoint is 100 on BOTH connect paths. + + The two call sites briefly shipped different values (fast 100 / init + 1000) with contradictory justifying comments. Because the pragma is + per-connection, a mixed fleet makes any field observation about the value + uninterpretable — every new process's first connect takes the init path, + while long-lived writers (gateway dispatcher, webui) re-connect on the + fast path. Assert both paths agree so a future change has to touch both + deliberately. """ db = tmp_path / "kanban.db" resolved = str(db.resolve()) @@ -4988,10 +4985,10 @@ def test_connect_sets_wal_autocheckpoint_100_on_fast_path(tmp_path): # First connect: slow/init path. Populates _INITIALIZED_PATHS. conn = kb.connect(db_path=db) assert resolved in kb._INITIALIZED_PATHS # next connect takes the fast path - assert conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] == 1000 + assert conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] == 100 conn.close() - # Second connect: fast path (already initialized) — the pacemaker. + # Second connect: fast path (already initialized) — must match. conn = kb.connect(db_path=db) assert conn.execute("PRAGMA wal_autocheckpoint").fetchone()[0] == 100 conn.close() From 5fcf6d41c2cd22811768086cfdc4e80b3ee88f57 Mon Sep 17 00:00:00 2001 From: jamesraddock Date: Thu, 16 Jul 2026 22:47:52 -0400 Subject: [PATCH 11/11] fix(kanban): skip the migration backfill write-txn when there is nothing to backfill _migrate_add_optional_columns runs on every process's first connect, and its unconditional BEGIN IMMEDIATE was one leg of a reproducible corruption trigger: health probe + fresh rw connection + early write transaction, under process churn at wal_autocheckpoint=1000, corrupts a live board in under a minute (churn harness, ~830 real connect processes per 150s run; see the reproduction matrix posted on PR #41795). Probe with a plain SELECT first and only open the write transaction when a legacy running-task row actually needs a task_runs backfill. The re-SELECT inside the transaction is unchanged, so a row appearing between probe and txn is still handled; legacy rows can only pre-exist anyway (new claims always set current_run_id). Validated: the harness arms that corrupted before (all1000, migrateonly) run clean with this change; kanban_db suite 240/240. Co-Authored-By: Claude Fable 5 --- hermes_cli/kanban_db.py | 98 ++++++++++++++++++++++++----------------- 1 file changed, 57 insertions(+), 41 deletions(-) diff --git a/hermes_cli/kanban_db.py b/hermes_cli/kanban_db.py index 5569605d5e779..7c86aa6f6bbd8 100644 --- a/hermes_cli/kanban_db.py +++ b/hermes_cli/kanban_db.py @@ -2379,48 +2379,64 @@ def _migrate_add_optional_columns(conn: sqlite3.Connection) -> None: "SELECT name FROM sqlite_master WHERE type='table' AND name='task_runs'" ).fetchone() is not None if runs_exist: - with write_txn(conn): - inflight = conn.execute( - "SELECT id, assignee, claim_lock, claim_expires, worker_pid, " - " max_runtime_seconds, last_heartbeat_at, started_at " - "FROM tasks " - "WHERE status = 'running' AND current_run_id IS NULL" - ).fetchall() - for row in inflight: - started = row["started_at"] or int(time.time()) - cur = conn.execute( - """ - INSERT INTO task_runs ( - task_id, profile, status, - claim_lock, claim_expires, worker_pid, - max_runtime_seconds, last_heartbeat_at, - started_at - ) VALUES (?, ?, 'running', ?, ?, ?, ?, ?, ?) - """, - ( - row["id"], row["assignee"], row["claim_lock"], - row["claim_expires"], row["worker_pid"], - row["max_runtime_seconds"], row["last_heartbeat_at"], - started, - ), - ) - # CAS: only install the pointer if nothing else claimed - # the task between our SELECT and here (shouldn't happen - # under the write_txn, but belt-and-suspenders). If the - # CAS fails we've got an orphan run_row — mark it - # reclaimed so it doesn't look in-flight. - upd = conn.execute( - "UPDATE tasks SET current_run_id = ? " - "WHERE id = ? AND current_run_id IS NULL", - (cur.lastrowid, row["id"]), - ) - if upd.rowcount != 1: - conn.execute( - "UPDATE task_runs SET status = 'reclaimed', " - " outcome = 'reclaimed', ended_at = ? " - "WHERE id = ?", - (int(time.time()), cur.lastrowid), + # Probe BEFORE opening the write transaction, and skip it entirely + # when there is nothing to backfill — the overwhelmingly common + # case. This function runs on every process's first connect, and a + # per-start ``BEGIN IMMEDIATE`` here is one leg of a reproduced + # corruption trigger (health-probe + fresh rw connection + early + # write_txn under process churn at wal_autocheckpoint=1000 corrupts + # the board; see the reproduction matrix posted on PR #41795). The + # re-SELECT inside the transaction below stays, so a task that + # turns 'running' between probe and txn is still handled correctly + # — legacy rows can only pre-exist anyway (new claims always set + # current_run_id). + needs_backfill = conn.execute( + "SELECT 1 FROM tasks " + "WHERE status = 'running' AND current_run_id IS NULL LIMIT 1" + ).fetchone() is not None + if needs_backfill: + with write_txn(conn): + inflight = conn.execute( + "SELECT id, assignee, claim_lock, claim_expires, worker_pid, " + " max_runtime_seconds, last_heartbeat_at, started_at " + "FROM tasks " + "WHERE status = 'running' AND current_run_id IS NULL" + ).fetchall() + for row in inflight: + started = row["started_at"] or int(time.time()) + cur = conn.execute( + """ + INSERT INTO task_runs ( + task_id, profile, status, + claim_lock, claim_expires, worker_pid, + max_runtime_seconds, last_heartbeat_at, + started_at + ) VALUES (?, ?, 'running', ?, ?, ?, ?, ?, ?) + """, + ( + row["id"], row["assignee"], row["claim_lock"], + row["claim_expires"], row["worker_pid"], + row["max_runtime_seconds"], row["last_heartbeat_at"], + started, + ), ) + # CAS: only install the pointer if nothing else claimed + # the task between our SELECT and here (shouldn't happen + # under the write_txn, but belt-and-suspenders). If the + # CAS fails we've got an orphan run_row — mark it + # reclaimed so it doesn't look in-flight. + upd = conn.execute( + "UPDATE tasks SET current_run_id = ? " + "WHERE id = ? AND current_run_id IS NULL", + (cur.lastrowid, row["id"]), + ) + if upd.rowcount != 1: + conn.execute( + "UPDATE task_runs SET status = 'reclaimed', " + " outcome = 'reclaimed', ended_at = ? " + "WHERE id = ?", + (int(time.time()), cur.lastrowid), + ) # One-shot event-kind rename pass. The old names ("ready", "priority", # "spawn_auto_blocked") still worked but were awkward on the wire;