2182f51d7c
"database is locked (another Hermes process held the state.db write lock for over 60s)" identified the victim only. The open-descriptor scan cannot single out the writer because every Hermes process (gateway, CLI sessions, worktree agents, cron) has the DB open, so an operator hit repeatedly by session_persistence_failed:locked had nothing to act on. SQLite's unix VFS takes fcntl byte-range locks whose offset encodes the lock kind (state.db-shm byte 120 = WAL write, 121 = checkpoint; the pending-byte page on state.db = PENDING/RESERVED), and the kernel exports them with the owning pid in /proc/locks. hermes_state_lockowners reads that table at the moment the patience budget runs out and logs one WARNING per write-class holder with describe_holder_pid()'s argv summary, for both the transcript write path and open+init lock patience. The holder stays out of the exception text on purpose: classify_persistence_error() buckets by phrase and a holder argv such as a worktree named fix-corrupt-db would flip the bucket. Docs: the Write Contention section still described attempt-counted retries (_WRITE_MAX_RETRIES = 15); updated to the time budgets in force and the new log line.
120 lines
4.5 KiB
Python
120 lines
4.5 KiB
Python
"""Who holds the SQLite write lock on state.db right now (Linux ``/proc/locks``).
|
|
|
|
The "database is locked for over Ns" failure names the victim but not the holder, and the
|
|
open-descriptor scan (``hermes_state_holders``) cannot tell a reader from the one writer: every
|
|
Hermes process has the DB open. SQLite's unix VFS takes ``fcntl`` byte-range locks whose offsets
|
|
encode the lock kind, and the kernel exports them with the owning pid, so the holder can be named
|
|
at the moment the deadline passes.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
import logging
|
|
import os
|
|
import sys
|
|
from pathlib import Path
|
|
from typing import Dict, List, Tuple
|
|
|
|
logger = logging.getLogger(__name__)
|
|
|
|
# sqlite/src/os_unix.c: UNIX_SHM_BASE = (22 + SQLITE_SHM_NLOCK) * 4 = 120; WAL lock i sits at BASE + i.
|
|
_SHM_LOCK_NAMES = {
|
|
120: "WAL write",
|
|
121: "WAL checkpoint",
|
|
122: "WAL recover",
|
|
128: "shm dead-man switch",
|
|
}
|
|
# Rollback-journal / exclusive locks on the main file live in the pending-byte page (1 GiB).
|
|
_PENDING_BYTE = 0x40000000
|
|
_MAIN_LOCK_NAMES = {
|
|
_PENDING_BYTE: "PENDING",
|
|
_PENDING_BYTE + 1: "RESERVED",
|
|
}
|
|
|
|
|
|
def _describe_range(sidecar: str, start: int, end: int) -> str:
|
|
if sidecar == "-shm":
|
|
if start in _SHM_LOCK_NAMES and end == start:
|
|
return _SHM_LOCK_NAMES[start]
|
|
if 123 <= start <= 127 and end == start:
|
|
return f"WAL read slot {start - 123}"
|
|
return f"shm bytes {start}-{end}"
|
|
if start == end and start in _MAIN_LOCK_NAMES:
|
|
return _MAIN_LOCK_NAMES[start]
|
|
if start == _PENDING_BYTE + 2:
|
|
return "SHARED range"
|
|
return f"db bytes {start}-{end}"
|
|
|
|
|
|
def parse_proc_locks(text: str, inodes: Dict[Tuple[int, int], str]) -> List[Tuple[int, str, str]]:
|
|
"""``(pid, lock kind, sidecar)`` for every WRITE lock on one of ``inodes``.
|
|
|
|
``inodes`` maps ``(st_dev, st_ino)`` to ``""`` (main file), ``"-wal"`` or ``"-shm"``. Read locks
|
|
are dropped: they never block a writer in WAL mode. An OFD lock is reported with pid ``-1``
|
|
(the kernel does not export its owner).
|
|
"""
|
|
found: List[Tuple[int, str, str]] = []
|
|
for line in text.splitlines():
|
|
fields = line.split()
|
|
# "N: POSIX ADVISORY WRITE <pid> MAJ:MIN:INO <start> <end|EOF>"; a blocked waiter is "N: -> POSIX ...".
|
|
if len(fields) < 8 or fields[1] == "->":
|
|
continue
|
|
_, _kind, _cls, access, pid_s, ident, start_s, end_s = fields[:8]
|
|
if access != "WRITE":
|
|
continue
|
|
try:
|
|
major_s, minor_s, ino_s = ident.split(":")
|
|
dev = os.makedev(int(major_s, 16), int(minor_s, 16))
|
|
key = (dev, int(ino_s))
|
|
pid = int(pid_s)
|
|
start = int(start_s)
|
|
end = start if end_s == "EOF" else int(end_s)
|
|
except ValueError:
|
|
continue
|
|
sidecar = inodes.get(key)
|
|
if sidecar is None:
|
|
continue
|
|
found.append((pid, _describe_range(sidecar, start, end), sidecar))
|
|
return found
|
|
|
|
|
|
def state_db_write_lock_holders(db_path) -> List[str]:
|
|
"""Operator-facing lines naming the processes that hold a write-class lock on ``db_path``.
|
|
|
|
Empty when nothing is held or the platform has no ``/proc/locks``.
|
|
"""
|
|
if not sys.platform.startswith("linux"):
|
|
return []
|
|
base = os.path.realpath(os.fspath(db_path))
|
|
inodes: Dict[Tuple[int, int], str] = {}
|
|
for sidecar in ("", "-wal", "-shm"):
|
|
try:
|
|
st = os.stat(base + sidecar)
|
|
except OSError:
|
|
continue
|
|
inodes[(st.st_dev, st.st_ino)] = sidecar
|
|
try:
|
|
with open("/proc/locks", encoding="ascii", errors="replace") as handle:
|
|
text = handle.read()
|
|
except OSError:
|
|
return []
|
|
from hermes_state_holders import describe_holder_pid
|
|
|
|
lines = []
|
|
for pid, kind, sidecar in parse_proc_locks(text, inodes):
|
|
who = describe_holder_pid(pid) if pid > 0 else "OFD lock, owner pid not exported by the kernel"
|
|
lines.append(f"{who} holds {kind} lock on {Path(base + sidecar).name}")
|
|
return lines
|
|
|
|
|
|
def log_write_lock_holders(db_path, patience_s: float) -> None:
|
|
"""One WARNING naming the write-lock holders at the moment a writer gave up waiting."""
|
|
holders = state_db_write_lock_holders(db_path)
|
|
if holders:
|
|
detail = " | ".join(holders)
|
|
else:
|
|
detail = "no write-class lock held at the deadline (the holder released just before it)"
|
|
logger.warning(
|
|
"state.db write lock unavailable for %.0fs (%s): %s", patience_s, Path(db_path).name, detail
|
|
)
|