diff --git a/hermes_state.py b/hermes_state.py index 2bb6c58fd417f..7b6871023868b 100644 --- a/hermes_state.py +++ b/hermes_state.py @@ -3550,9 +3550,10 @@ class SessionDB(SessionSearchMixin, SessionSchemaMixin, SessionPortabilityMixin) cannot corrupt B-tree pages under I/O pressure. PASSIVE does not truncate the WAL file — it stays at its - high-water mark. WAL truncation happens in :meth:`close` - (TRUNCATE) and pre-VACUUM checkpoints, which run infrequently - under controlled conditions. + high-water mark. Explicit checkpoints on the shared ``state.db`` no + longer truncate the WAL; it is bounded by ``journal_size_limit`` and + the writer's natural post-checkpoint reset rather than by a TRUNCATE + at every close or maintenance command. Previous TRUNCATE strategy caused B-tree corruption on large databases (65K+ pages) due to the exclusive-lock I/O pressure @@ -3575,9 +3576,11 @@ class SessionDB(SessionSearchMixin, SessionSchemaMixin, SessionPortabilityMixin) """Close the database connection. Drains queued token deltas first (the background writer needs the - connection). Writable connections then attempt a TRUNCATE WAL - checkpoint so exiting writer processes help shrink the WAL file. - Read-only connections never request a checkpoint. + connection). Writable connections then attempt a PASSIVE WAL + checkpoint (NOT TRUNCATE: transient per-cron-run connections close + many times an hour, and a TRUNCATE fires a full WAL reset that + races the gateway's live writer and tears B-tree pages — issue + #45383). Read-only connections never request a checkpoint. """ self._stop_token_writer() # The atexit hook holds a strong reference to this instance (bound @@ -3601,11 +3604,18 @@ class SessionDB(SessionSearchMixin, SessionSchemaMixin, SessionPortabilityMixin) with self._lock: if self._conn: if not self.read_only: + # PASSIVE, not TRUNCATE. Every cron run_agent opens+closes a + # transient SessionDB, so a TRUNCATE here fires a full WAL + # reset many times/hour, racing the gateway's long-lived + # writer on large WAL databases and tearing hot B-tree + # pages -- the #45383 corruption this class's own periodic + # checkpoint was already made PASSIVE to avoid. TRUNCATE + # belongs only on a sole-opener/quiescent connection. try: - self._conn.execute("PRAGMA wal_checkpoint(TRUNCATE)") + self._conn.execute("PRAGMA wal_checkpoint(PASSIVE)") except Exception as exc: logger.debug( - "WAL checkpoint (TRUNCATE) at close failed: %s", + "WAL checkpoint (PASSIVE) at close failed: %s", exc, ) self._conn.close() @@ -10893,11 +10903,15 @@ class SessionDB(SessionSearchMixin, SessionSchemaMixin, SessionPortabilityMixin) logger.warning("FTS optimize before VACUUM failed: %s", exc) # VACUUM cannot be executed inside a transaction. with self._lock: - # Best-effort WAL checkpoint first, then VACUUM. + # Best-effort WAL checkpoint first, then VACUUM. PASSIVE, not + # TRUNCATE: a manual `hermes sessions vacuum` runs in a transient + # CLI process, and a TRUNCATE reset here would race a live gateway + # writer and tear B-tree pages (#45383). VACUUM folds the WAL back + # itself; journal_size_limit bounds the file. try: - self._conn.execute("PRAGMA wal_checkpoint(TRUNCATE)") + self._conn.execute("PRAGMA wal_checkpoint(PASSIVE)") except Exception as exc: - logger.debug("WAL checkpoint (TRUNCATE) before VACUUM failed: %s", exc) + logger.debug("WAL checkpoint (PASSIVE) before VACUUM failed: %s", exc) self._conn.execute("VACUUM") return optimized diff --git a/hermes_state_search.py b/hermes_state_search.py index 643c7f7398865..b1cf669210fe6 100644 --- a/hermes_state_search.py +++ b/hermes_state_search.py @@ -913,12 +913,17 @@ class SessionSearchMixin: # its own. Callers must therefore NOT size the result by stat()ing # the file; use :meth:`logical_size_bytes`, which is truthful # immediately regardless of readers. + # PASSIVE, not TRUNCATE: optimize-storage runs from a transient CLI + # process; a TRUNCATE reset here would race a live gateway writer + # and tear B-tree pages (#45383). (The TRUNCATE was already refused + # SQLITE_BUSY while the gateway holds a read-mark, per the note + # above; PASSIVE removes the reset attempt entirely.) try: with self._lock: - self._conn.execute("PRAGMA wal_checkpoint(TRUNCATE)") + self._conn.execute("PRAGMA wal_checkpoint(PASSIVE)") except Exception as exc: logger.debug( - "WAL checkpoint (TRUNCATE) after optimize VACUUM failed: %s", + "WAL checkpoint (PASSIVE) after optimize VACUUM failed: %s", exc, ) diff --git a/tests/test_hermes_state.py b/tests/test_hermes_state.py index 725cfde8d0a90..3f051f3da9f3b 100644 --- a/tests/test_hermes_state.py +++ b/tests/test_hermes_state.py @@ -115,7 +115,7 @@ class TestConnectionLifecycle: assert not any("wal_checkpoint" in sql.lower() for sql in executed) - def test_writable_close_retains_truncate_checkpoint(self, tmp_path): + def test_writable_close_uses_passive_checkpoint(self, tmp_path): db_path = tmp_path / "state.db" writable = SessionDB(db_path=db_path) executed = [] @@ -123,10 +123,17 @@ class TestConnectionLifecycle: writable.close() - assert any( + # close() must NOT TRUNCATE: transient per-cron-run connections firing + # full WAL resets race the gateway's live writer and corrupt B-tree + # pages (issue #45383). It uses PASSIVE instead. + assert not any( "pragma wal_checkpoint(truncate)" == " ".join(sql.lower().split()) for sql in executed ) + assert any( + "pragma wal_checkpoint(passive)" == " ".join(sql.lower().split()) + for sql in executed + ) def test_read_only_connection_keeps_fts_search_available(self, tmp_path): db_path = tmp_path / "state.db" diff --git a/tests/test_wal_checkpoint_strategy.py b/tests/test_wal_checkpoint_strategy.py index 880aa4b5cc2d1..7f479934f6d96 100644 --- a/tests/test_wal_checkpoint_strategy.py +++ b/tests/test_wal_checkpoint_strategy.py @@ -1,7 +1,9 @@ """Tests for SessionDB WAL checkpoint strategy (issue #45383). -Verifies that periodic checkpoints use PASSIVE mode (safe for large DBs) -while close() and pre-VACUUM paths still use TRUNCATE. +Verifies that ALL checkpoints on the shared state.db use PASSIVE mode: +periodic, close(), and pre-VACUUM. TRUNCATE fires a full WAL reset, and +transient per-cron-run connections closing many times an hour would race +the live gateway writer and corrupt B-tree pages (#45383). """ import sqlite3 @@ -13,6 +15,21 @@ import pytest from hermes_state import SessionDB +class TrackingConnection: + """sqlite3.Connection proxy that records executed SQL strings.""" + + def __init__(self, conn): + self._conn = conn + self.execute_calls = [] + + def execute(self, sql, *args, **kwargs): + self.execute_calls.append(sql) + return self._conn.execute(sql, *args, **kwargs) + + def __getattr__(self, name): + return getattr(self._conn, name) + + @pytest.fixture() def db(tmp_path): """Create a SessionDB with a temp database file.""" @@ -73,11 +90,13 @@ class TestTryWalCheckpointPassive: db._try_wal_checkpoint() -class TestCloseUsesTruncate: - """close() should still use TRUNCATE to shrink WAL on shutdown.""" +class TestCloseUsesPassive: + """close() must use PASSIVE. Transient per-cron-run SessionDB connections + close many times an hour; a TRUNCATE reset there races the live gateway + writer on the large WAL DB and corrupts B-tree pages (#45383).""" - def test_close_uses_truncate_mode(self, db): - """TRUNCATE at close is safe — no concurrent writers during shutdown.""" + def test_close_uses_passive_mode(self, db): + """close() checkpoints PASSIVE, never TRUNCATE.""" real_conn = db._conn execute_calls = [] @@ -92,12 +111,16 @@ class TestCloseUsesTruncate: db.close() truncate_calls = [c for c in execute_calls if "wal_checkpoint(TRUNCATE)" in c] - assert len(truncate_calls) == 1, ( - f"Expected 1 TRUNCATE checkpoint at close, got {len(truncate_calls)}" + passive_calls = [c for c in execute_calls if "wal_checkpoint(PASSIVE)" in c] + assert len(truncate_calls) == 0, ( + "close() must NOT TRUNCATE (races the live gateway writer, #45383)" + ) + assert len(passive_calls) == 1, ( + f"Expected 1 PASSIVE checkpoint at close, got {len(passive_calls)}" ) def test_close_logs_debug_on_failure(self, db, caplog): - """Failed TRUNCATE at close logs debug (not warning — close is best-effort).""" + """Failed PASSIVE checkpoint at close logs debug (close is best-effort).""" mock_conn = MagicMock() mock_conn.execute.side_effect = sqlite3.OperationalError("database is locked") db._conn = mock_conn @@ -105,11 +128,63 @@ class TestCloseUsesTruncate: with caplog.at_level(logging.DEBUG): db.close() - assert any("WAL checkpoint (TRUNCATE) at close failed" in r.message for r in caplog.records), ( - f"Expected debug log about TRUNCATE failure at close, got: {caplog.text}" + assert any("WAL checkpoint (PASSIVE) at close failed" in r.message for r in caplog.records), ( + f"Expected debug log about PASSIVE failure at close, got: {caplog.text}" ) +class TestVacuumUsesPassive: + """Manual vacuum paths must checkpoint PASSIVE, never TRUNCATE.""" + + def test_vacuum_uses_passive_before_vacuum(self, db): + """SessionDB.vacuum() checkpoints PASSIVE before running VACUUM.""" + real_conn = db._conn + tracking_conn = TrackingConnection(real_conn) + db._conn = tracking_conn + + db.vacuum() + + checkpoint_calls = [ + c for c in tracking_conn.execute_calls if "wal_checkpoint" in c.lower() + ] + truncate_calls = [c for c in checkpoint_calls if "TRUNCATE" in c] + passive_calls = [c for c in checkpoint_calls if "PASSIVE" in c] + vacuum_calls = [ + c for c in tracking_conn.execute_calls if c.strip().upper() == "VACUUM" + ] + assert truncate_calls == [] + assert passive_calls == ["PRAGMA wal_checkpoint(PASSIVE)"] + assert vacuum_calls == ["VACUUM"] + assert tracking_conn.execute_calls.index( + passive_calls[0] + ) < tracking_conn.execute_calls.index(vacuum_calls[0]) + + def test_optimize_storage_uses_passive_after_vacuum(self, db): + """optimize_fts_storage() checkpoints PASSIVE after its VACUUM.""" + real_conn = db._conn + tracking_conn = TrackingConnection(real_conn) + db._conn = tracking_conn + + result = db.optimize_fts_storage(vacuum=True) + + checkpoint_calls = [ + c for c in tracking_conn.execute_calls if "wal_checkpoint" in c.lower() + ] + truncate_calls = [c for c in checkpoint_calls if "TRUNCATE" in c] + passive_calls = [c for c in checkpoint_calls if "PASSIVE" in c] + vacuum_calls = [ + c for c in tracking_conn.execute_calls if c.strip().upper() == "VACUUM" + ] + assert result["ok"] is True + assert result["vacuumed"] is True + assert truncate_calls == [] + assert passive_calls == ["PRAGMA wal_checkpoint(PASSIVE)"] + assert vacuum_calls == ["VACUUM"] + assert tracking_conn.execute_calls.index( + vacuum_calls[0] + ) < tracking_conn.execute_calls.index(passive_calls[0]) + + class TestCheckpointFrequency: """Checkpoint triggers every N writes."""