Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
36 changes: 25 additions & 11 deletions hermes_state.py
Original file line number Diff line number Diff line change
Expand Up @@ -3300,9 +3300,10 @@ def _try_wal_checkpoint(self) -> None:
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
Expand All @@ -3325,9 +3326,11 @@ def close(self):
"""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
Expand Down Expand Up @@ -3356,11 +3359,18 @@ def close(self):
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()
Expand Down Expand Up @@ -10262,11 +10272,15 @@ def vacuum(self) -> int:
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

Expand Down
9 changes: 7 additions & 2 deletions hermes_state_search.py
Original file line number Diff line number Diff line change
Expand Up @@ -912,12 +912,17 @@ def _pause(chunk_seconds: float) -> None:
# 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,
)

Expand Down
11 changes: 9 additions & 2 deletions tests/test_hermes_state.py
Original file line number Diff line number Diff line change
Expand Up @@ -115,18 +115,25 @@ def test_read_only_close_never_requests_wal_checkpoint(self, tmp_path):

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 = []
writable._conn.set_trace_callback(executed.append)

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"
Expand Down
97 changes: 86 additions & 11 deletions tests/test_wal_checkpoint_strategy.py
Original file line number Diff line number Diff line change
@@ -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
Expand All @@ -13,6 +15,21 @@
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."""
Expand Down Expand Up @@ -73,11 +90,13 @@ def test_checkpoint_returns_result_on_success(self, db):
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 = []

Expand All @@ -92,24 +111,80 @@ def tracking_execute(sql, *args, **kwargs):
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

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."""

Expand Down
Loading