Skip to content
Merged
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
9 changes: 5 additions & 4 deletions hermes_state.py
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,7 @@
_DELETED_WAL_GENERATION_MSG, _DISK_IO_ERROR_MARKER, _STATE_DB_CORRUPT_MSG, _STATE_DB_GENERATION_KEY,
_STATE_DB_REPLACED_MSG, DeletedWalGenerationError, SessionCompressionInProgressError, StateDbCorruptError,
StateDbReplacedError, _is_no_more_rows, classify_persistence_error, is_malformed_db_error,
is_malformed_schema_error,
is_malformed_schema_error, is_sqlite_lock_error,
)
from hermes_state_guard import (
_STATE_DB_GUARD_BYPASS_ENV, _in_test_context, _is_production_state_db, _real_platform_state_root,
Expand Down Expand Up @@ -711,6 +711,8 @@ def _open_read_only(self) -> None:
# SQLITE_IOERR to a mode=ro reader (it can't do the -shm recovery the read
# needs). Closes in milliseconds: retry a bounded number of times before
# classifying the store as failed (#100436; see _READ_ONLY_IOERR_RETRY_ATTEMPTS).
# A lock is NOT retried here: the connection already waited _READ_BUSY_TIMEOUT_S,
# and a retry would multiply that wait on blocking callers (TUI, `hermes status`).
transient = _DISK_IO_ERROR_MARKER in str(ioerr).lower()
if attempt >= _READ_ONLY_IOERR_RETRY_ATTEMPTS or not transient:
raise
Expand Down Expand Up @@ -801,8 +803,7 @@ def _connect_and_init_with_lock_patience(self) -> None:
self._connect_and_init()
return
except sqlite3.OperationalError as exc:
err = str(exc).lower()
if "locked" not in err and "busy" not in err:
if not is_sqlite_lock_error(exc):
raise
self._close_connection_quietly(self._conn)
now = time.monotonic()
Expand Down Expand Up @@ -1041,7 +1042,7 @@ def _execute_write(
continue
err_msg = str(exc).lower()
if isinstance(exc, sqlite3.OperationalError):
if "locked" in err_msg or "busy" in err_msg:
if is_sqlite_lock_error(exc):
if self._sleep_before_write_retry(deadline, patience_s):
continue
# Say what actually happened, not disk/permission damage. The holder goes to
Expand Down
28 changes: 26 additions & 2 deletions hermes_state_errors.py
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,28 @@ def is_malformed_db_error(exc: BaseException) -> bool:
)


# Lock contention by result code. SQLite keeps SQLITE_BUSY when FTS5's xConnect loses the race
# on its %_config read but replaces the text with "vtable constructor failed: messages_fts",
# so a phrase match read a busy store as a hard failure.
_SQLITE_LOCK_CODES = (sqlite3.SQLITE_BUSY, sqlite3.SQLITE_LOCKED)


def _sqlite_primary_code(exc_or_str) -> "int | None":
"""Primary result code (extended codes keep it in the low byte); None when unknown."""
code = getattr(exc_or_str, "sqlite_errorcode", None)
return code & 0xFF if isinstance(code, int) else None


def is_sqlite_lock_error(exc_or_str) -> bool:
"""SQLITE_BUSY / SQLITE_LOCKED: wait and retry, never treat as damage. A known result code
decides; only without one (our own re-raised messages, RPC-wrapped strings) does the text."""
code = _sqlite_primary_code(exc_or_str)
if code is not None:
return code in _SQLITE_LOCK_CODES
text = str(exc_or_str).lower()
return "locked" in text or "busy" in text


def _is_no_more_rows(exc: sqlite3.Error) -> bool:
"""Transient engine error on contended WAL appends (retries like locked/busy);
message-scoped because some builds raise it as InterfaceError."""
Expand All @@ -43,8 +65,8 @@ def _is_no_more_rows(exc: sqlite3.Error) -> bool:
def is_transient_sqlite_error(exc: BaseException) -> bool:
""""Busy right now", not "damaged": one predicate so retry and the HTTP
503-vs-500 split cannot drift apart."""
return isinstance(exc, sqlite3.OperationalError) and any(
marker in str(exc).lower() for marker in _TRANSIENT_SQLITE_MARKERS
return isinstance(exc, sqlite3.OperationalError) and (
is_sqlite_lock_error(exc) or any(marker in str(exc).lower() for marker in _TRANSIENT_SQLITE_MARKERS)
)


Expand Down Expand Up @@ -263,6 +285,8 @@ def classify_persistence_error(exc_or_str) -> str:
# naming messages_fts*) is index damage, never whole-file corruption (#97794).
if is_fts_scoped_corruption_error(exc_or_str):
return "fts_index"
if _sqlite_primary_code(exc_or_str) in _SQLITE_LOCK_CODES:
return "locked"
text = str(exc_or_str).lower()
for markers, cause in _PERSISTENCE_CAUSE_BY_PHRASE:
if any(marker in text for marker in markers):
Expand Down
5 changes: 3 additions & 2 deletions hermes_state_holders.py
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,8 @@
from pathlib import Path
from typing import Callable, List, Optional, Sequence, Set, Tuple

from hermes_state_errors import is_sqlite_lock_error

try: # Hard dependency, but tolerate scaffold-phase imports before pip install.
import psutil
except ImportError: # pragma: no cover - stripped/scaffold installs only
Expand Down Expand Up @@ -536,8 +538,7 @@ def live_writer_holds_db(
probe.execute("ROLLBACK")
return False
except sqlite3.OperationalError as exc:
lowered = str(exc).lower()
return "locked" in lowered or "busy" in lowered
return is_sqlite_lock_error(exc)
except sqlite3.DatabaseError:
# Malformed/unreadable with no holder on the scan: nobody else has it open, so repair may run.
return False
Expand Down
3 changes: 2 additions & 1 deletion hermes_state_schema.py
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@
)
from hermes_state_fts import _drop_orphan_fts_shadow_tables
from hermes_state_holders import _read_proc_argv
from hermes_state_errors import is_sqlite_lock_error

# Pre-split logger identity so log filtering/capture is unchanged.
logger = logging.getLogger("hermes_state")
Expand Down Expand Up @@ -767,7 +768,7 @@ def _reconcile_columns(self, cursor: sqlite3.Cursor) -> None:
# A sibling process won the ADD race; store is correct.
logger.debug("reconcile %s.%s: %s", table_name, col_name, exc)
continue
if "locked" in message or "busy" in message:
if is_sqlite_lock_error(exc):
# Swallowing lock contention left the store half-reconciled ("no such
# column" on every read). Re-raise so the lock-patience wrapper retries init.
raise
Expand Down
3 changes: 2 additions & 1 deletion hermes_state_wal.py
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@
from typing import Any, Dict, Optional

from hermes_cli.sqlite_runtime import is_sqlite_wal_reset_vulnerable as _is_sqlite_wal_reset_vulnerable
from hermes_state_errors import is_sqlite_lock_error

# Log-record parity with the origin module (caplog tests pin "hermes_state").
logger = logging.getLogger("hermes_state")
Expand Down Expand Up @@ -451,7 +452,7 @@ def _apply_delete_for_wal_reset_bug(conn: sqlite3.Connection, *, db_label: str,
except sqlite3.OperationalError as exc:
if require_delete:
raise
if "locked" in str(exc).lower() or "busy" in str(exc).lower():
if is_sqlite_lock_error(exc):
# A concurrent opener appeared between probe and flip: leave the mode as is.
_log_wal_reset_bug_once(db_label, kept_wal=True, indeterminate=True)
return current or "delete"
Expand Down
83 changes: 83 additions & 0 deletions tests/hermes_state/test_write_lock_patience.py
Original file line number Diff line number Diff line change
Expand Up @@ -148,3 +148,86 @@ def test_open_propagates_non_lock_errors_immediately(self, tmp_path):
SessionDB(db_path=bad_path)
# Must fail well before a full patience window (loose bound).
assert time.monotonic() - t0 < 15.0


def _use_delete_journal_mode(monkeypatch, tmp_path):
home = tmp_path / "hermes-home"
home.mkdir()
(home / "config.yaml").write_text("database:\n journal_mode: delete\n", encoding="utf-8")
monkeypatch.setenv("HERMES_HOME", str(home))


def _hold_exclusive(db_path, hold_s, started_evt):
"""DELETE mode: only EXCLUSIVE shuts readers out (a sibling's commit or VACUUM)."""
conn = sqlite3.connect(str(db_path), timeout=1.0, isolation_level=None)
try:
conn.execute("BEGIN EXCLUSIVE")
started_evt.set()
time.sleep(hold_s)
conn.execute("COMMIT")
finally:
conn.close()


@pytest.mark.parametrize("read_only", [False, True], ids=["writer", "read_only"])
def test_open_waits_out_lock_lost_inside_fts_constructor(tmp_path, monkeypatch, read_only):
"""A DELETE-mode sibling taking the lock between schema load and the messages_fts probe
makes SQLite report SQLITE_BUSY as "vtable constructor failed: messages_fts" (FTS5's
xConnect reads %_config). The open must wait that out like any other lock, not fail."""
_use_delete_journal_mode(monkeypatch, tmp_path)
db_path = tmp_path / "state.db"
seed = SessionDB(db_path=db_path)
assert not seed._wal_active
seed.create_session("s", "cli")
seed.append_message(session_id="s", role="user", content="needle")
seed.close()

started = threading.Event()
holder = threading.Thread(target=_hold_exclusive, args=(db_path, 2.5, started))
real_probe = SessionDB._fts_table_probe

def probe_after_sibling_takes_lock(self, cursor, table_name):
if table_name == "messages_fts" and not holder.is_alive() and not started.is_set():
cursor.execute("SELECT count(*) FROM sqlite_master").fetchall() # schema cached
holder.start()
assert started.wait(5.0)
return real_probe(self, cursor, table_name)

monkeypatch.setattr(SessionDB, "_fts_table_probe", probe_after_sibling_takes_lock)
try:
db = SessionDB(db_path=db_path, read_only=read_only)
finally:
if started.is_set():
holder.join(timeout=10.0)
try:
assert started.is_set(), "the lock race was never placed"
assert db._fts_enabled is True
assert [m["content"] for m in db.get_messages("s")] == ["needle"]
finally:
db.close()


def test_lock_lost_inside_fts_constructor_classifies_as_busy(tmp_path):
"""When patience does run out, the same error must read as "busy" (HTTP 503, "locked"
guidance), not as an internal error: SQLite keeps SQLITE_BUSY but not the wording."""
from hermes_state_errors import classify_persistence_error, is_transient_sqlite_error

db_path = tmp_path / "fts.db"
setup = sqlite3.connect(str(db_path))
setup.execute("PRAGMA journal_mode=DELETE")
setup.execute("CREATE VIRTUAL TABLE messages_fts USING fts5(content)")
setup.commit()
setup.close()
reader = sqlite3.connect(str(db_path), timeout=0.05)
holder = sqlite3.connect(str(db_path), isolation_level=None)
try:
reader.execute("SELECT count(*) FROM sqlite_master").fetchall()
holder.execute("BEGIN EXCLUSIVE")
with pytest.raises(sqlite3.OperationalError) as excinfo:
reader.execute("SELECT * FROM messages_fts LIMIT 0").fetchall()
finally:
holder.close()
reader.close()
assert "vtable constructor failed" in str(excinfo.value)
assert is_transient_sqlite_error(excinfo.value)
assert classify_persistence_error(excinfo.value) == "locked"
9 changes: 9 additions & 0 deletions website/docs/developer-guide/session-storage.md
Original file line number Diff line number Diff line change
Expand Up @@ -327,6 +327,15 @@ PENDING/RESERVED/SHARED). The open-descriptor scan cannot make this distinction
because every Hermes process has the DB open. Look for that line in
`~/.hermes/logs/errors.log` next to the `database is locked` failure.

Lock contention is recognised by SQLite result code (`SQLITE_BUSY` /
`SQLITE_LOCKED`, `hermes_state_errors.is_sqlite_lock_error`), not by message
text. In rollback-journal (`delete`) mode a lock lost inside FTS5's table
constructor arrives as `SQLITE_BUSY` with the text `vtable constructor failed:
messages_fts`; it is treated like `database is locked`. Opening a writable
`SessionDB` waits up to `_WRITE_PATIENCE_S`; a read-only open waits its
`_READ_BUSY_TIMEOUT_S` (5 s) read budget once. If the lock outlasts that, the dashboard
answers 503 (busy), not 500.


## Common Operations

Expand Down
Loading