RomanNum3ral
/
hermes-agent
mirror of https://github.com/NousResearch/hermes-agent.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

fix(state): PASSIVE not TRUNCATE for all state.db checkpoints (#45383) 

SessionDB.close() ran `PRAGMA wal_checkpoint(TRUNCATE)`. Every cron
run_agent opens and closes its own transient SessionDB, so on a busy
fleet this fired a full WAL reset many times an hour, racing the
gateway's long-lived writer on a large WAL database and tearing hot
B-tree pages -- structurally the same corruption this module's own
periodic checkpoint was already switched to PASSIVE to avoid (#45383).
Only close() and two manual-maintenance paths still used TRUNCATE.

Route every checkpoint on the shared state.db through PASSIVE:
  - close()                    (hermes_state.py)
  - pre-VACUUM in vacuum()     (hermes_state.py)
  - post-optimize-storage      (hermes_state_search.py)

PASSIVE never resets/truncates the WAL and never takes the exclusive
checkpoint lock, so it cannot lose a transient closer's race with the
live writer. The WAL is instead bounded by `journal_size_limit` and the
writer's natural post-checkpoint reset. TRUNCATE belongs only on a
sole-opener/quiescent connection (e.g. offline maintenance); this change
does not try to detect that -- PASSIVE is the safe default.

Diagnosed as the root cause of three state.db B-tree corruptions in
2026-08: damage localized to the hottest-written pages (gateway_routing
and the sessions indexes), with whole zero-filled pages still live and
off the freelist -- the checkpoint/reset-race signature, not disk or
application SQL.

Tests: tests/test_wal_checkpoint_strategy.py now asserts PASSIVE at
close(), before vacuum(), and after optimize_fts_storage() VACUUM;
tests/test_hermes_state.py asserts close() likewise. Focused run:
226 passed.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
lkz-de 2026-08-12 05:33:42 +02:00 committed by Teknium
parent aec7fb3ce6
commit ba80f3b86d
4 changed files with 127 additions and 26 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

36
hermes_state.py
View File

@ -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

9
hermes_state_search.py
View File

@ -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,
)

11
tests/test_hermes_state.py
View File

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

97
tests/test_wal_checkpoint_strategy.py
View File

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