diff --git a/agent/turn_explainers.py b/agent/turn_explainers.py index 8d78279a31a84..487566a66fc8e 100644 --- a/agent/turn_explainers.py +++ b/agent/turn_explainers.py @@ -120,19 +120,23 @@ "pending_messages/pending-*.json." ), "deleted_wal": ( - "the turn was stopped because a live Hermes process held a retired " - "state.db-wal generation after its pathname was deleted or " + "Hermes paused saving this chat because another Hermes process replaced " + "its session database. Nothing is lost. Click Recover / run " + "`hermes {profile_arg}doctor --fix`.\n\n" + "Operator runbook: the turn was stopped because a live Hermes process held a " + "retired state.db-wal generation after its pathname was deleted or " "replaced. Stop the gateway, dashboard, and cron writers; " "do not overwrite the current state.db or delete its sidecars. " "Check the logs for whether Hermes captured the retired generation, " "then read the adjacent state.db.retired-wal-*/manifest.json. If " "manifest.main.mode is `copied`, inspect that artifact with `hermes " - "sessions recover --source " + "{profile_arg}sessions recover --source " "--inspect-only` before deciding whether its committed frames belong " "on the current database. A `header_only` artifact is forensic and " "does not contain a copied state.db to inspect. Unwritten messages " "were diverted to sessions/.jsonl and, on the gateway, " - "pending_messages/pending-*.json." + "pending_messages/pending-*.json.\n" + "Recovery guide: https://hermes.nousresearch.com/docs/user-guide/session-storage-recovery" ), "corrupt": ( "the turn was stopped because the state database " @@ -328,7 +332,7 @@ def _format_turn_completion_explanation( body = _PERSISTENCE_CAUSE_EXPLANATIONS.get( persistence_cause or "unknown", _PERSISTENCE_DEFAULT_EXPLANATION ) - if persistence_cause in ("corrupt", "fts_index"): + if persistence_cause in ("corrupt", "fts_index", "deleted_wal"): # Copy-pasteable, so name the store that actually failed and pin the profile: # a multi-profile backend (Desktop serve) hosts sessions whose state.db is NOT # the process default, and a bare `hermes` follows active_profile (#105887). diff --git a/apps/desktop/src/api/system.ts b/apps/desktop/src/api/system.ts index ba2e0bbccaf17..aea0ee106835e 100644 --- a/apps/desktop/src/api/system.ts +++ b/apps/desktop/src/api/system.ts @@ -241,8 +241,8 @@ export function getGhAuthStatus(refresh = false): Promise<{ available: boolean; // getActionStatus(). // --------------------------------------------------------------------------- -export function runDoctor(): Promise { - return hermesApi({ path: '/api/ops/doctor', method: 'POST', body: {} }) +export function runDoctor(fix = false): Promise { + return hermesApi({ path: '/api/ops/doctor', method: 'POST', body: { fix } }) } export function runSecurityAudit(): Promise { diff --git a/apps/desktop/src/app/command-center/maintenance.tsx b/apps/desktop/src/app/command-center/maintenance.tsx index d603bfc7fdd19..c48e3d77769d9 100644 --- a/apps/desktop/src/app/command-center/maintenance.tsx +++ b/apps/desktop/src/app/command-center/maintenance.tsx @@ -206,6 +206,12 @@ export function MaintenancePanel() { label={mm.doctor} onRun={() => void launch(mm.doctor, runDoctor)} /> + void launch('Doctor (--fix)', () => runDoctor(true))} + /> { + void runDoctor(true) + .then(() => { + notify({ + kind: 'success', + title: 'Recovery started', + message: 'Hermes doctor is repairing database access in the background.' + }) + }) + .catch((err: unknown) => { + notify({ + kind: 'error', + title: 'Recovery failed to start', + message: err instanceof Error ? err.message : String(err) + }) + }) + } + } + }) + } + if (isActiveEvent) { setTurnStartedAt(null) diff --git a/apps/desktop/src/app/session/hooks/use-message-stream/terminal-error-frame.test.tsx b/apps/desktop/src/app/session/hooks/use-message-stream/terminal-error-frame.test.tsx index 8ecefe8e09022..7d3d4ecc2631c 100644 --- a/apps/desktop/src/app/session/hooks/use-message-stream/terminal-error-frame.test.tsx +++ b/apps/desktop/src/app/session/hooks/use-message-stream/terminal-error-frame.test.tsx @@ -112,4 +112,20 @@ describe('terminal error message.complete frames', () => { expect(bubble?.error).toBe('kaput') expect(bubble?.errorSurface).toBeUndefined() }) + + it('handles terminal error with deleted_wal failure_reason and preserves failure state', async () => { + mountStream() + await start() + await delta('…') + + await completeWithError({ + text: 'Hermes paused saving this chat', + error: 'session storage could not be written', + failure_reason: 'session_persistence_failed:deleted_wal' + }) + + const bubble = lastAssistant() + expect(bubble?.error).toBe('session storage could not be written') + expect(getState().busy).toBe(false) + }) }) diff --git a/hermes_cli/doctor_state.py b/hermes_cli/doctor_state.py index 6702cd54ad27c..b44ca55a0868a 100644 --- a/hermes_cli/doctor_state.py +++ b/hermes_cli/doctor_state.py @@ -3,7 +3,9 @@ from __future__ import annotations +import os import subprocess +import time from pathlib import Path from hermes_cli.doctor_report import ( Finding, _fail_and_issue, _section, check_bool, check_info, check_ok, check_warn, doctor_check, ensure_dir, @@ -11,6 +13,9 @@ ) from hermes_cli.sizefmt import format_bytes as _human_bytes from hermes_state_common import FTS_STORAGE_VERSION +import logging + +logger = logging.getLogger("hermes_cli.doctor") def _honcho_is_configured_for_doctor() -> bool: @@ -203,8 +208,227 @@ def _repair_state_db(f: Finding, should_fix: bool, state_db_path: Path, kind: st f.fixed += 1 +def _find_retired_wal_capture(db_path: Path, pid: int, wal_identity: Optional[tuple] = None) -> Optional[Path]: + """Find an existing retired-wal capture directory matching pid and wal_identity.""" + retired_dirs = sorted(db_path.parent.glob(f"{db_path.name}.retired-wal-*")) + for d in reversed(retired_dirs): + manifest_file = d / "manifest.json" + if not manifest_file.is_file(): + continue + try: + import json + m = json.loads(manifest_file.read_text(encoding="utf-8")) + if m.get("pid") == pid: + if wal_identity is None: + return d + captured_ident = tuple(m.get("wal", {}).get("identity") or ()) + if captured_ident == tuple(wal_identity): + return d + except Exception: + continue + return None + + +def _report_retired_dirs_info(retired_dirs: List[Path], profile_arg: str) -> None: + """Report latest retired WAL capture with mode-aware guidance (header_only vs copied).""" + if not retired_dirs: + return + latest = retired_dirs[-1] + manifest_file = latest / "manifest.json" + mode = "unknown" + if manifest_file.exists(): + import json + try: + m = json.loads(manifest_file.read_text(encoding="utf-8")) + mode = m.get("main", {}).get("mode", "unknown") + except Exception: + pass + if mode == "copied": + check_info( + f"Retired WAL capture preserved at {latest.name} (mode: copied; " + f"inspect with 'hermes {profile_arg}sessions recover --source {latest / 'state.db'} --inspect-only')" + ) + else: + check_info( + f"Retired WAL capture preserved at {latest.name} (mode: {mode}; " + f"forensic artifact only — inspect {latest / 'manifest.json'})" + ) + + +def _recover_retired_wal(f: Finding, should_fix: bool, state_db_path: Path, _DHH: str) -> bool: + """Detect and remediate processes holding unlinked or retired WAL generations.""" + from hermes_state_dbfile import iter_deleted_sqlite_sidecar_holders + from hermes_constants import profile_cli_selector + + holders = iter_deleted_sqlite_sidecar_holders(state_db_path) + retired_dirs = sorted(state_db_path.parent.glob(f"{state_db_path.name}.retired-wal-*")) + profile_arg = profile_cli_selector() + + if not holders: + _report_retired_dirs_info(retired_dirs, profile_arg) + return False + + current_pid = os.getpid() + pids = sorted({pid for pid, _ in holders if pid > 0 and pid != current_pid}) + pids_desc = ", ".join(f"PID {p}" for p in pids) + check_warn( + f"{_DHH}/state.db has {len(pids)} process(es) holding an unlinked or retired WAL generation", + f"({pids_desc})", + ) + + if not should_fix: + f.issues.append( + f"state.db has {len(pids)} process(es) holding a retired WAL generation ({pids_desc}) — " + f"run 'hermes {profile_arg}doctor --fix' to stop conflicting processes and reopen cleanly" + ) + return True + + from gateway.status import terminate_pid, get_process_start_time, _start_times_agree + from hermes_state_holders import _read_proc_argv + from hermes_state_dbfile import ( + iter_deleted_sqlite_sidecar_holder_descriptors, + capture_external_retired_wal_generation, + ) + + cmd_descs = {pid: (" ".join(_read_proc_argv(pid))[:60] if _read_proc_argv(pid) else f"PID {pid}") for pid in pids} + + # Precondition 1: Process Identity Witness + # Capture start time while fd/holder is observed; refuse if unavailable. + witness_start_times: Dict[int, int] = {} + failed_pids: List[Tuple[int, str]] = [] + for pid in pids: + st = get_process_start_time(pid) + if st is None: + failed_pids.append((pid, f"{cmd_descs.get(pid, f'PID {pid}')} (refusing to signal: start-time identity unavailable)")) + else: + witness_start_times[pid] = st + + # Precondition 2: Exact-Generation Preservation + # Ensure this PID's exact orphaned WAL inode has a durable capture BEFORE sending any signal. + holder_descriptors = { + r["pid"]: r for r in iter_deleted_sqlite_sidecar_holder_descriptors(state_db_path) + if r.get("suffix") == "-wal" and r.get("identity") + } + preserved_pids = set() + for pid in list(witness_start_times.keys()): + wal_ident = holder_descriptors.get(pid, {}).get("identity") + existing_capture = _find_retired_wal_capture(state_db_path, pid, wal_ident) + if existing_capture: + preserved_pids.add(pid) + continue + fd_path = holder_descriptors.get(pid, {}).get("fd_path") + if fd_path and wal_ident: + try: + capture_external_retired_wal_generation(state_db_path, pid=pid, fd_path=fd_path, wal_identity=wal_ident) + preserved_pids.add(pid) + continue + except Exception as exc: + logger.debug("Failed external capture of WAL for PID %s: %s", pid, exc) + failed_pids.append((pid, f"{cmd_descs.get(pid, f'PID {pid}')} (refusing to signal: unlinked WAL generation {wal_ident} has no durable capture)")) + + target_pids = [p for p in witness_start_times.keys() if p in preserved_pids] + + # Bounded parallel termination with identity revalidation + failed_initial = {} + active_pids = set() + for pid in target_pids: + cur_start = get_process_start_time(pid) + if cur_start is None or not _start_times_agree(cur_start, witness_start_times[pid]): + # Holder exited or was recycled before TERM: no signal to replacement + continue + active_pids.add(pid) + try: + terminate_pid(pid, force=False, expected_start_time=witness_start_times[pid]) + except Exception as exc: + failed_initial[pid] = exc + + def _is_running(p: int) -> bool: + try: + os.kill(p, 0) + return True + except OSError: + return False + + for _ in range(20): + if not active_pids: + break + active_pids = {p for p in active_pids if _is_running(p)} + if active_pids: + time.sleep(0.1) + + if active_pids: + for pid in list(active_pids): + cur_start = get_process_start_time(pid) + if cur_start is None or not _start_times_agree(cur_start, witness_start_times[pid]): + # PID was recycled between TERM and KILL: refuse KILL + active_pids.discard(pid) + continue + try: + terminate_pid(pid, force=True, expected_start_time=witness_start_times[pid]) + except Exception: + pass + for _ in range(10): + if not active_pids: + break + active_pids = {p for p in active_pids if _is_running(p)} + if active_pids: + time.sleep(0.1) + + still_held = {h[0] for h in iter_deleted_sqlite_sidecar_holders(state_db_path) if h[0] != current_pid} + stopped_pids = [] + for p in target_pids: + cmd = cmd_descs.get(p, f"PID {p}") + if p in active_pids or (p in failed_initial and p in still_held): + err = f" ({failed_initial[p]})" if p in failed_initial else "" + failed_pids.append((p, f"{cmd}{err}")) + else: + stopped_pids.append((p, cmd)) + + if stopped_pids: + check_ok( + f"Stopped {len(stopped_pids)} process(es) holding retired WAL", + f"({', '.join(str(p) for p, _ in stopped_pids)})", + ) + f.fixed += 1 + + if failed_pids: + check_warn( + f"Could not stop {len(failed_pids)} process(es) holding retired WAL", + f"({', '.join(f'{p}: {c}' for p, c in failed_pids)})", + ) + f.manual_issues.append( + f"Could not automatically stop {len(failed_pids)} process(es) holding retired WAL: " + f"{', '.join(f'PID {p} ({c})' for p, c in failed_pids)} — stop them manually and reopen" + ) + + remaining = [h for h in iter_deleted_sqlite_sidecar_holders(state_db_path) if h[0] > 0 and h[0] != current_pid] + if not remaining: + try: + check_ok(f"{_DHH}/state.db reopened successfully ({_session_count(state_db_path)} sessions)") + pending_spool = state_db_path.parent / "pending_messages" + if pending_spool.exists(): + spooled_files = list(pending_spool.glob("pending-*.json")) + if spooled_files: + check_info( + f"{len(spooled_files)} pending message spool file(s) preserved in {pending_spool.name}/ " + "for gateway ingestion" + ) + except Exception as e: + check_warn(f"{_DHH}/state.db reopened but health check reported: {e}") + + refreshed_retired_dirs = sorted(state_db_path.parent.glob(f"{state_db_path.name}.retired-wal-*")) + _report_retired_dirs_info(refreshed_retired_dirs, profile_arg) + + return True + + def _state_db_health(f: Finding, should_fix: bool, state_db_path: Path, _DHH: str) -> None: """Session count + FTS write-health probe; malformed-schema path when even COUNT(*) fails.""" + from hermes_state_dbfile import iter_deleted_sqlite_sidecar_holders + if iter_deleted_sqlite_sidecar_holders(state_db_path): + _recover_retired_wal(f, should_fix, state_db_path, _DHH) + return + try: check_ok(f"{_DHH}/state.db exists ({_session_count(state_db_path)} sessions)") # COUNT(*) succeeds even when the FTS index is corrupt and every write fails through the triggers; @@ -222,6 +446,10 @@ def _state_db_health(f: Finding, should_fix: bool, state_db_path: Path, _DHH: st _repair_state_db(f, should_fix, state_db_path, "fts") except Exception as e: from hermes_state import is_malformed_db_error + from hermes_state_errors import DeletedWalGenerationError + if isinstance(e, DeletedWalGenerationError) or "deleted state.db-wal" in str(e): + _recover_retired_wal(f, should_fix, state_db_path, _DHH) + return if not is_malformed_db_error(e): return check_warn(f"{_DHH}/state.db exists but has issues: {e}") # sqlite_master itself is malformed (e.g. duplicate messages_fts): every statement fails before it runs, @@ -253,22 +481,37 @@ def _state_db_wal(f: Finding, should_fix: bool, state_db_path: Path) -> None: with warn_on_error(""): size = wal_size() if size > 50 * 1024 * 1024: # 50 MB - check_warn(f"WAL file is large ({size // (1024*1024)} MB)", "(may indicate missed checkpoints)") + from hermes_state_holders import live_writer_holds_db + from hermes_state_repair import _connect_repair_durable + is_held = live_writer_holds_db(state_db_path, connect_repair_durable=_connect_repair_durable) if not should_fix: - return f.issues.append("Large WAL file — run 'hermes doctor --fix' to checkpoint") + if is_held: + check_warn( + f"WAL file is large ({size // (1024*1024)} MB)", + "(normal while Desktop/gateway are running; only checkpoint with them stopped)", + ) + return f.issues.append( + f"Large WAL file ({size // (1024*1024)} MB) — normal while Desktop/gateway are " + "running; stop them first before checkpointing with 'hermes doctor --fix'" + ) + check_warn( + f"WAL file is large ({size // (1024*1024)} MB)", + "(may indicate missed checkpoints; only checkpoint with Desktop/gateway stopped)", + ) + return f.issues.append( + "Large WAL file — run 'hermes doctor --fix' to checkpoint (ensure Desktop/gateway are stopped)" + ) # Checkpoint-lock premise (#40177): a bare connect runs WAL recovery and the checkpoint joins the # live WAL — under a running gateway that second-writer handling corrupts state.db. Skip instead. - from hermes_state_holders import live_writer_holds_db - from hermes_state_repair import _connect_repair_durable - if live_writer_holds_db(state_db_path, connect_repair_durable=_connect_repair_durable): + if is_held: # Honest disjunction (gate C1): a True here means "held OR # unprovable" — the DatabaseError lane fires when SQLite # cannot open the file at all, with nobody holding it. Never # assert a live writer as fact. check_warn("WAL checkpoint skipped: cannot prove state.db is quiet", - "(a live writer holds it, or it is unreadable — stop the profile's gateway " - "and re-run 'hermes doctor --fix')") - return f.issues.append("Large WAL file — cannot prove state.db is quiet (stop the profile's " + "(a live writer holds it, or it is unreadable — stop Desktop and the profile's gateway " + "first, then re-run 'hermes doctor --fix')") + return f.issues.append("Large WAL file — cannot prove state.db is quiet (stop Desktop and the profile's " "gateway first, then re-run 'hermes doctor --fix' to checkpoint)") import contextlib import sqlite3 diff --git a/hermes_cli/web_models.py b/hermes_cli/web_models.py index 208e4730e18c5..8707e0bb56685 100644 --- a/hermes_cli/web_models.py +++ b/hermes_cli/web_models.py @@ -8,6 +8,10 @@ from pydantic import BaseModel, SecretStr, StrictBool, field_validator +class DoctorRequest(BaseModel): + fix: bool = False + + class ConfigUpdate(BaseModel): config: dict profile: Optional[str] = None diff --git a/hermes_cli/web_routers/_common.py b/hermes_cli/web_routers/_common.py index a93974894defd..b8e27f5ea17c9 100644 --- a/hermes_cli/web_routers/_common.py +++ b/hermes_cli/web_routers/_common.py @@ -95,22 +95,33 @@ def require(value: Optional[str], detail: str) -> str: @contextlib.contextmanager def corrupt_store_as_status(db_path): - """Map a corrupt-image ``sqlite3.DatabaseError`` from a state.db read to a 503 status + """Map a corrupt-image ``sqlite3.DatabaseError`` or ``StateDbReplacedError`` from a state.db read to a 503 status payload, warning once per store per :data:`_CORRUPT_STORE_WARN_INTERVAL_S`. Busy/locked and every other error propagate unchanged.""" - from hermes_state_errors import is_malformed_db_error + from hermes_state_errors import is_malformed_db_error, StateDbReplacedError, DeletedWalGenerationError try: yield - except sqlite3.DatabaseError as exc: - if not is_malformed_db_error(exc): + except (sqlite3.DatabaseError, StateDbReplacedError) as exc: + if isinstance(exc, sqlite3.DatabaseError) and not is_malformed_db_error(exc): raise key, now = str(db_path), time.monotonic() last = _corrupt_store_warned_at.get(key) + detail = dict(CORRUPT_STORE_DETAIL) + if isinstance(exc, DeletedWalGenerationError): + detail = { + "error": "deleted_wal", + "message": "state.db replaced underneath with deleted WAL generation — click Recover or run `hermes doctor --fix`.", + } + elif isinstance(exc, StateDbReplacedError): + detail = { + "error": "state_db_replaced", + "message": "state.db replaced underneath — click Recover or run `hermes doctor --fix`.", + } if last is None or now - last >= _CORRUPT_STORE_WARN_INTERVAL_S: _corrupt_store_warned_at[key] = now - log.warning("state.db at %s is corrupt (%s); dashboard reads return a status payload until it is " - "repaired — run `hermes doctor`", db_path, exc) + log.warning("state.db at %s has error (%s); dashboard reads return a status payload until it is " + "repaired — run `hermes doctor --fix`", db_path, exc) else: - log.debug("state.db at %s still corrupt: %s", db_path, exc) - raise HTTPException(status_code=503, detail={**CORRUPT_STORE_DETAIL, "path": key}) from exc + log.debug("state.db at %s still has error: %s", db_path, exc) + raise HTTPException(status_code=503, detail={**detail, "path": key}) from exc diff --git a/hermes_cli/web_routers/ops.py b/hermes_cli/web_routers/ops.py index 728bd4b4de68e..644721d09342a 100644 --- a/hermes_cli/web_routers/ops.py +++ b/hermes_cli/web_routers/ops.py @@ -26,7 +26,7 @@ from hermes_cli.web_server_gateway import _restart_gateway_after from hermes_cli.web_server_memory import _normalize_memory_provider_name, _require_memory_provider_ready from hermes_cli.web_models import ( - BackupRequest, CredentialPoolAdd, HookCreate, HookDelete, ImportRequest, MemoryProviderSelect, + BackupRequest, CredentialPoolAdd, DoctorRequest, HookCreate, HookDelete, ImportRequest, MemoryProviderSelect, MemoryReset, PairingApprove, PairingRevoke, WebhookCreate, WebhookEnabledToggle, ) from hermes_cli.web_routers._common import _CONFIG_MUTATION_LOCK, http_failure, spawn_profile_action @@ -501,8 +501,11 @@ async def reset_memory(body: MemoryReset): @router.post("/api/ops/doctor") -async def run_doctor(): - return _spawn_action(["doctor"], "doctor", log_msg="Failed to spawn doctor", prefix="Failed to run doctor") +async def run_doctor(body: Optional[DoctorRequest] = None): + args = ["doctor"] + if body and body.fix: + args.append("--fix") + return _spawn_action(args, "doctor", log_msg="Failed to spawn doctor", prefix="Failed to run doctor") @router.post("/api/ops/security-audit") diff --git a/hermes_state_dbfile.py b/hermes_state_dbfile.py index a65c8f900e21c..00cfbaf8393da 100644 --- a/hermes_state_dbfile.py +++ b/hermes_state_dbfile.py @@ -184,24 +184,41 @@ def _iter_proc_fd_targets(): yield int(pid_str), os.readlink(fd_path), fd_path -def iter_deleted_sqlite_sidecar_holders(db_path) -> List[Tuple[int, str]]: - """Return processes holding an unlinked ``state.db-wal`` / ``-shm``. Linux-only; ``[]`` - elsewhere (Windows cannot unlink a held sidecar, macOS has no `` (deleted)`` suffix). - Includes this process: on the open/write refuse path the in-process writer holding the orphan - inode must not mint a replacement WAL (``_foreign_state_db_holders`` skips this PID).""" +def iter_deleted_sqlite_sidecar_holder_descriptors(db_path) -> List[Dict[str, Any]]: + """Return detailed descriptor records for processes holding an unlinked ``state.db-wal`` / ``-shm``. + Linux-only; ``[]`` elsewhere. + Each dict contains: ``{"pid": int, "target": str, "fd_path": str, "identity": Tuple[int, int], "suffix": str}``.""" if not sys.platform.startswith("linux"): return [] - holders: List[Tuple[int, str]] = [] + records: List[Dict[str, Any]] = [] watched = _watched_sqlite_sidecar_paths(db_path) try: for pid, target, fd_path in _iter_proc_fd_targets(): canonical = _canonical_sqlite_path(target) if (" (deleted)" in target and canonical in watched and _fd_is_truly_unlinked(fd_path, watched[canonical])): - holders.append((pid, target)) + ident = None + with contextlib.suppress(OSError): + st = os.stat(fd_path) + ident = (st.st_dev, st.st_ino) + records.append({ + "pid": pid, + "target": target, + "fd_path": fd_path, + "identity": ident, + "suffix": "-wal" if canonical.endswith("-wal") else "-shm", + }) except Exception as exc: - logger.debug("deleted-WAL holder scan failed for %s: %s", db_path, exc) - return holders + logger.debug("deleted-WAL holder descriptor scan failed for %s: %s", db_path, exc) + return records + + +def iter_deleted_sqlite_sidecar_holders(db_path) -> List[Tuple[int, str]]: + """Return processes holding an unlinked ``state.db-wal`` / ``-shm``. Linux-only; ``[]`` + elsewhere (Windows cannot unlink a held sidecar, macOS has no `` (deleted)`` suffix). + Includes this process: on the open/write refuse path the in-process writer holding the orphan + inode must not mint a replacement WAL (``_foreign_state_db_holders`` skips this PID).""" + return [(r["pid"], r["target"]) for r in iter_deleted_sqlite_sidecar_holder_descriptors(db_path)] def refuse_deleted_wal_generation(db_path) -> None: @@ -422,6 +439,82 @@ def capture_retired_wal_generation( return final +def capture_external_retired_wal_generation( + db_path, *, pid: int, fd_path: str, wal_identity: tuple, trigger: str = "doctor_recovery" +) -> Path: + """Durably capture an unlinked WAL generation held open by another process (from /proc//fd/).""" + db_path = Path(db_path) + if not wal_identity: + raise RetiredGenerationCaptureError(f"no recorded WAL generation identity for {db_path}") + try: + wal_fd = os.open(fd_path, os.O_RDONLY) + except OSError as exc: + raise RetiredGenerationCaptureError(f"cannot open descriptor at {fd_path}: {exc}") from exc + try: + st = os.fstat(wal_fd) + if (st.st_dev, st.st_ino) != tuple(wal_identity): + raise RetiredGenerationCaptureError( + f"descriptor at {fd_path} identity {(st.st_dev, st.st_ino)} does not match expected {wal_identity}" + ) + wal_size = st.st_size + + stem = f"{db_path.name}{RETIRED_GENERATION_DIR_SUFFIX}{time.strftime('%Y%m%d-%H%M%S', time.gmtime())}-{pid}" + final = db_path.with_name(stem) + n = 0 + while final.exists() or final.with_name(final.name + ".partial").exists(): + n += 1 + final = db_path.with_name(f"{stem}-{n}") + staging = final.with_name(final.name + ".partial") + try: + staging.mkdir(parents=True, exist_ok=False) + manifest: Dict[str, Any] = { + "version": RETIRED_GENERATION_MANIFEST_VERSION, + "database": str(db_path), + "trigger": trigger, + "pid": pid, + "captured_at": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()), + "python": sys.version.split()[0], + "sqlite": sqlite3.sqlite_version, + "wal": {"identity": list(wal_identity), + **_copy_descriptor(wal_fd, staging / (db_path.name + "-wal"), size=wal_size)}, + "shm": None, + "path_generation_at_capture": { + suffix: list(ident) for suffix, ident in _stat_sqlite_sidecar_identity(db_path).items()}, + "note": ("Frames in the captured WAL were committed by the retired generation. Whether they " + "belong on top of the main file now at the path is an operator decision; inspect " + "the copied image with `hermes sessions recover --inspect-only` first."), + } + if db_path.exists(): + header = _pread_db_range(db_path, 0, _SQLITE_HEADER_BYTES) + if header is not None: + main_size = os.stat(db_path).st_size + main: Dict[str, Any] = {"identity": list(_stat_db_file_identity(db_path) or ()) or None, + "size": main_size, "header": _parse_sqlite_header(header)} + if main_size <= RETIRED_GENERATION_MAIN_IMAGE_MAX_BYTES: + main.update(mode="copied", **_copy_main_image(db_path, staging / db_path.name, size=main_size)) + else: + header_file = staging / (db_path.name + ".header") + header_file.write_bytes(header) + _fsync_path(header_file) + main.update(mode="header_only", file=header_file.name, bytes=len(header)) + manifest["main"] = main + else: + manifest["main"] = {"mode": "missing", "size": 0, "identity": None} + else: + manifest["main"] = {"mode": "missing", "size": 0, "identity": None} + from utils import atomic_json_write + atomic_json_write(staging / RETIRED_GENERATION_MANIFEST, manifest, sort_keys=True) + _fsync_path(staging) + os.replace(staging, final) + _fsync_path(final.parent) + return final + except Exception: + shutil.rmtree(staging, ignore_errors=True) + raise + finally: + os.close(wal_fd) + + def _connect_tracked_db(path, tracking_path=None, **kwargs): """``sqlite3.connect`` that registers the open fd so byte-level probes of a live file are refused (an ``open()``/``close()`` would cancel every POSIX lock, even a running VACUUM's diff --git a/tests/agent/test_turn_completion_explainer.py b/tests/agent/test_turn_completion_explainer.py index 160bc18dc0d67..2a238a1b3a89a 100644 --- a/tests/agent/test_turn_completion_explainer.py +++ b/tests/agent/test_turn_completion_explainer.py @@ -211,12 +211,18 @@ def test_deleted_wal_cause_is_enumerated_and_points_to_retired_capture(): "session_persistence_failed", "deleted_wal" ).lower() assert "deleted_wal" in PERSISTENCE_ERROR_CAUSES + # First line (human-facing) + assert "hermes paused saving this chat because another hermes process replaced its session database" in out + assert "click recover / run" in out + assert "doctor --fix" in out + # Operator runbook and artifacts assert "retired-wal-*/manifest.json" in out assert "manifest.main.mode" in out assert "sessions recover" in out and "--inspect-only" in out assert "header_only" in out and "does not contain a copied state.db" in out assert "check the logs for whether" in out assert "restore the intended state.db" not in out + assert "session-storage-recovery" in out def test_explanation_persistence_unknown_cause_is_neutral(): diff --git a/tests/hermes_cli/test_doctor_deleted_wal_recovery.py b/tests/hermes_cli/test_doctor_deleted_wal_recovery.py new file mode 100644 index 0000000000000..569c2583cb0df --- /dev/null +++ b/tests/hermes_cli/test_doctor_deleted_wal_recovery.py @@ -0,0 +1,426 @@ +"""Tests for hermes doctor in-product recovery of deleted-WAL sidecar holders and retired generations (#110054).""" + +from __future__ import annotations + +import json +import sqlite3 +from pathlib import Path +from unittest.mock import patch + +import pytest + +from hermes_cli.doctor_report import Finding +import hermes_cli.doctor_state as doctor_state +from hermes_state_errors import DeletedWalGenerationError + + +def test_doctor_flags_deleted_wal_holders_dry_run(tmp_path, monkeypatch): + """When processes hold unlinked/retired WAL sidecars, doctor flags them and suggests --fix.""" + db = tmp_path / "state.db" + db.touch() + + # Mock 2 processes holding deleted sidecars + mock_holders = [(12345, str(tmp_path / "state.db-wal (deleted)")), (67890, str(tmp_path / "state.db-shm (deleted)"))] + monkeypatch.setattr(doctor_state, "iter_deleted_sqlite_sidecar_holders", lambda _p: mock_holders, raising=False) + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", lambda _p: mock_holders) + + finding = Finding() + handled = doctor_state._recover_retired_wal(finding, should_fix=False, state_db_path=db, _DHH="~/.hermes") + + assert handled is True + assert finding.fixed == 0 + assert len(finding.issues) == 1 + issue = finding.issues[0] + assert "holding a retired WAL generation" in issue + assert "12345" in issue and "67890" in issue + assert "doctor --fix" in issue + + +def test_doctor_fix_stops_holders_and_reopens(tmp_path, monkeypatch): + """With --fix, doctor stops the holding processes and reopens state.db cleanly.""" + db = tmp_path / "state.db" + conn = sqlite3.connect(str(db)) + conn.execute("CREATE TABLE sessions(id TEXT PRIMARY KEY, title TEXT)") + conn.execute("INSERT INTO sessions VALUES ('s1', 'title')") + conn.commit() + conn.close() + + # Create durable capture artifact satisfying precondition 2 + capture_dir = tmp_path / "state.db.retired-wal-20260913-11111" + capture_dir.mkdir() + (capture_dir / "manifest.json").write_text(json.dumps({"pid": 11111, "main": {"mode": "copied"}}), encoding="utf-8") + + mock_holders = [(11111, str(tmp_path / "state.db-wal (deleted)"))] + calls = [] + dead_pids = set() + + def fake_terminate(pid, force=False, **kwargs): + calls.append((pid, force, kwargs.get("expected_start_time"))) + dead_pids.add(pid) + state["holders"].clear() + + # After termination, holders become empty + state = {"holders": list(mock_holders)} + def fake_iter_holders(_p): + return state["holders"] + + def fake_kill(pid, sig): + if pid in dead_pids: + raise ProcessLookupError("No such process") + return None + + monkeypatch.setattr("gateway.status.terminate_pid", fake_terminate) + monkeypatch.setattr("gateway.status.get_process_start_time", lambda pid: 12345 if pid not in dead_pids else None) + monkeypatch.setattr("gateway.status._start_times_agree", lambda cur, exp: cur == exp) + monkeypatch.setattr(doctor_state, "iter_deleted_sqlite_sidecar_holders", fake_iter_holders, raising=False) + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", fake_iter_holders) + monkeypatch.setattr("hermes_state_holders._read_proc_argv", lambda _p: ["hermes", "gateway", "run"]) + monkeypatch.setattr("os.kill", fake_kill) + + finding = Finding() + handled = doctor_state._recover_retired_wal(finding, should_fix=True, state_db_path=db, _DHH="~/.hermes") + + assert handled is True + assert finding.fixed == 1 + assert len(calls) >= 1 + assert calls[0][0] == 11111 + assert calls[0][2] == 12345 # expected_start_time passed + assert len(finding.manual_issues) == 0 + + +def test_doctor_fix_reports_manual_issue_when_stop_fails(tmp_path, monkeypatch): + """When a holder cannot be stopped (permission or zombie), doctor records it with PID and cmdline.""" + db = tmp_path / "state.db" + db.touch() + + capture_dir = tmp_path / "state.db.retired-wal-20260913-99999" + capture_dir.mkdir() + (capture_dir / "manifest.json").write_text(json.dumps({"pid": 99999, "main": {"mode": "copied"}}), encoding="utf-8") + + mock_holders = [(99999, str(tmp_path / "state.db-wal (deleted)"))] + + def fake_terminate_fail(pid, **kwargs): + raise PermissionError("Operation not permitted") + + monkeypatch.setattr("gateway.status.terminate_pid", fake_terminate_fail) + monkeypatch.setattr("gateway.status.get_process_start_time", lambda pid: 54321) + monkeypatch.setattr("gateway.status._start_times_agree", lambda cur, exp: cur == exp) + monkeypatch.setattr(doctor_state, "iter_deleted_sqlite_sidecar_holders", lambda _p: mock_holders, raising=False) + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", lambda _p: mock_holders) + monkeypatch.setattr("hermes_state_holders._read_proc_argv", lambda _p: ["/usr/bin/python", "daemon.py"]) + + finding = Finding() + handled = doctor_state._recover_retired_wal(finding, should_fix=True, state_db_path=db, _DHH="~/.hermes") + + assert handled is True + assert finding.fixed == 0 + assert len(finding.manual_issues) == 1 + manual = finding.manual_issues[0] + assert "99999" in manual + assert "daemon.py" in manual + assert "stop them manually" in manual + + +def test_doctor_identity_unavailable_fails_closed(tmp_path, monkeypatch): + """When start-time fingerprint cannot be established, doctor refuses to signal and reports manual issue.""" + db = tmp_path / "state.db" + db.touch() + + capture_dir = tmp_path / "state.db.retired-wal-20260913-77777" + capture_dir.mkdir() + (capture_dir / "manifest.json").write_text(json.dumps({"pid": 77777, "main": {"mode": "copied"}}), encoding="utf-8") + + mock_holders = [(77777, str(tmp_path / "state.db-wal (deleted)"))] + signals_sent = [] + + monkeypatch.setattr("gateway.status.terminate_pid", lambda pid, **kw: signals_sent.append(pid)) + monkeypatch.setattr("gateway.status.get_process_start_time", lambda pid: None) # Unavailable + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", lambda _p: mock_holders) + monkeypatch.setattr("hermes_state_holders._read_proc_argv", lambda _p: ["worker.py"]) + + finding = Finding() + handled = doctor_state._recover_retired_wal(finding, should_fix=True, state_db_path=db, _DHH="~/.hermes") + + assert handled is True + assert len(signals_sent) == 0 # No signal sent + assert finding.fixed == 0 + assert any("start-time identity unavailable" in issue for issue in finding.manual_issues) + + +def test_doctor_unlinked_wal_no_capture_fails_closed(tmp_path, monkeypatch): + """When an unlinked WAL generation has no durable capture, doctor refuses to signal the owner.""" + db = tmp_path / "state.db" + db.touch() + + mock_holders = [(88888, str(tmp_path / "state.db-wal (deleted)"))] + signals_sent = [] + + monkeypatch.setattr("gateway.status.terminate_pid", lambda pid, **kw: signals_sent.append(pid)) + monkeypatch.setattr("gateway.status.get_process_start_time", lambda pid: 8888) + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", lambda _p: mock_holders) + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holder_descriptors", lambda _p: [ + {"pid": 88888, "target": str(tmp_path / "state.db-wal (deleted)"), "fd_path": "/proc/88888/fd/3", + "identity": (1, 2), "suffix": "-wal"} + ]) + monkeypatch.setattr("hermes_state_holders._read_proc_argv", lambda _p: ["worker.py"]) + + finding = Finding() + handled = doctor_state._recover_retired_wal(finding, should_fix=True, state_db_path=db, _DHH="~/.hermes") + + assert handled is True + assert len(signals_sent) == 0 # Refused to signal because no capture exists + assert finding.fixed == 0 + assert any("has no durable capture" in issue for issue in finding.manual_issues) + + +def test_doctor_holder_exits_before_term_no_signal_to_replacement(tmp_path, monkeypatch): + """When a holder exits before TERM, doctor detects identity drift and sends no signal to replacement.""" + db = tmp_path / "state.db" + db.touch() + + capture_dir = tmp_path / "state.db.retired-wal-20260913-66666" + capture_dir.mkdir() + (capture_dir / "manifest.json").write_text(json.dumps({"pid": 66666, "main": {"mode": "copied"}}), encoding="utf-8") + + mock_holders = [(66666, str(tmp_path / "state.db-wal (deleted)"))] + signals_sent = [] + + # Witness sees start time 100, but immediately before TERM the process exited and start time is None + start_times = {66666: [100, None]} + def fake_start_time(pid): + vals = start_times.get(pid, [100]) + return vals.pop(0) if len(vals) > 1 else vals[0] + + monkeypatch.setattr("gateway.status.terminate_pid", lambda pid, **kw: signals_sent.append(pid)) + monkeypatch.setattr("gateway.status.get_process_start_time", fake_start_time) + monkeypatch.setattr("gateway.status._start_times_agree", lambda cur, exp: cur == exp) + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", lambda _p: mock_holders) + monkeypatch.setattr("hermes_state_holders._read_proc_argv", lambda _p: ["worker.py"]) + + finding = Finding() + handled = doctor_state._recover_retired_wal(finding, should_fix=True, state_db_path=db, _DHH="~/.hermes") + + assert handled is True + assert len(signals_sent) == 0 # No signal sent to replacement! + + +def test_doctor_pid_recycled_between_term_and_kill_no_kill(tmp_path, monkeypatch): + """When PID is recycled between TERM and KILL, doctor detects identity mismatch and refuses SIGKILL.""" + db = tmp_path / "state.db" + db.touch() + + capture_dir = tmp_path / "state.db.retired-wal-20260913-44444" + capture_dir.mkdir() + (capture_dir / "manifest.json").write_text(json.dumps({"pid": 44444, "main": {"mode": "copied"}}), encoding="utf-8") + + mock_holders = [(44444, str(tmp_path / "state.db-wal (deleted)"))] + signals_sent = [] + + # Start time was 200 during witness & TERM, but before KILL PID was recycled to a process with start time 999 + call_count = {"val": 0} + def fake_start_time(pid): + call_count["val"] += 1 + if call_count["val"] <= 2: + return 200 + return 999 # Recycled PID + + def fake_terminate(pid, force=False, **kw): + signals_sent.append((pid, force)) + + monkeypatch.setattr("gateway.status.terminate_pid", fake_terminate) + monkeypatch.setattr("gateway.status.get_process_start_time", fake_start_time) + monkeypatch.setattr("gateway.status._start_times_agree", lambda cur, exp: cur == exp) + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", lambda _p: mock_holders) + monkeypatch.setattr("hermes_state_holders._read_proc_argv", lambda _p: ["worker.py"]) + monkeypatch.setattr("os.kill", lambda pid, sig: None) # Reports process still alive + + finding = Finding() + handled = doctor_state._recover_retired_wal(finding, should_fix=True, state_db_path=db, _DHH="~/.hermes") + + assert handled is True + # TERM was sent (force=False), but force-kill (force=True) was REFUSED because start time changed to 999! + assert any(sig[1] is False for sig in signals_sent) + assert not any(sig[1] is True for sig in signals_sent) + + +def test_doctor_header_only_mode_guidance(tmp_path, monkeypatch): + """When retired WAL capture is header_only, guidance states forensic only and does not advertise nonexistent state.db.""" + db = tmp_path / "state.db" + db.touch() + + artifact_dir = tmp_path / "state.db.retired-wal-20260913T120000Z-9999" + artifact_dir.mkdir() + manifest = { + "manifest_version": 1, + "main": {"mode": "header_only", "file": "state.db.header", "bytes": 100}, + "wal": {"file": "state.db-wal", "bytes": 512}, + } + (artifact_dir / "manifest.json").write_text(json.dumps(manifest), encoding="utf-8") + + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", lambda _p: []) + + finding = Finding() + infos = [] + monkeypatch.setattr(doctor_state, "check_info", lambda text: infos.append(text)) + + doctor_state._recover_retired_wal(finding, should_fix=False, state_db_path=db, _DHH="~/.hermes") + + # Verify guidance states forensic artifact only and references manifest.json, NOT sessions recover state.db + assert any("mode: header_only" in msg for msg in infos) + assert any("forensic artifact only" in msg for msg in infos) + assert not any("sessions recover --source" in msg for msg in infos) + + +def test_state_db_health_catches_deleted_wal_error(tmp_path, monkeypatch): + """When _session_count raises DeletedWalGenerationError, health check delegates to recovery.""" + db = tmp_path / "state.db" + db.touch() + + def fake_session_count(_p): + raise DeletedWalGenerationError("FATAL: a live process holds a deleted state.db-wal") + + monkeypatch.setattr(doctor_state, "_session_count", fake_session_count) + mock_holders = [(5555, str(tmp_path / "state.db-wal (deleted)"))] + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", lambda _p: mock_holders) + + finding = Finding() + doctor_state._state_db_health(finding, should_fix=False, state_db_path=db, _DHH="~/.hermes") + + assert len(finding.issues) == 1 + assert "5555" in finding.issues[0] + assert "doctor --fix" in finding.issues[0] + + +def test_doctor_surfaces_retired_wal_capture_artifacts(tmp_path, monkeypatch): + """When retired-wal captures exist beside state.db, doctor inspects and reports them.""" + db = tmp_path / "state.db" + db.touch() + + # Create a retired-wal artifact directory + artifact_dir = tmp_path / "state.db.retired-wal-20260913T120000Z-4321" + artifact_dir.mkdir() + manifest = { + "manifest_version": 1, + "main": {"mode": "copied", "bytes": 1024}, + "wal": {"file": "state.db-wal", "bytes": 512}, + } + (artifact_dir / "manifest.json").write_text(json.dumps(manifest), encoding="utf-8") + + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", lambda _p: []) + + finding = Finding() + infos = [] + monkeypatch.setattr(doctor_state, "check_info", lambda text: infos.append(text)) + + doctor_state._recover_retired_wal(finding, should_fix=False, state_db_path=db, _DHH="~/.hermes") + + assert any("state.db.retired-wal-" in msg for msg in infos) + assert any("mode: copied" in msg for msg in infos) + assert any("sessions recover" in msg for msg in infos) + + +@pytest.mark.asyncio +async def test_ops_run_doctor_supports_fix_param(monkeypatch): + """POST /api/ops/doctor forwards --fix to _spawn_action when fix=True.""" + from hermes_cli.web_models import DoctorRequest + from hermes_cli.web_routers.ops import run_doctor + + spawned = [] + monkeypatch.setattr("hermes_cli.web_routers.ops._spawn_action", lambda args, name, **kwargs: spawned.append((args, name))) + + # Without fix + await run_doctor(None) + assert spawned[-1] == (["doctor"], "doctor") + + await run_doctor(DoctorRequest(fix=False)) + assert spawned[-1] == (["doctor"], "doctor") + + # With fix=True + await run_doctor(DoctorRequest(fix=True)) + assert spawned[-1] == (["doctor", "--fix"], "doctor") + + +def test_doctor_excludes_current_pid_and_reports_pending_spool(tmp_path, monkeypatch): + """Doctor never attempts to terminate its own PID, and reports pending spool files upon reopening.""" + import os + db = tmp_path / "state.db" + conn = sqlite3.connect(str(db)) + conn.execute("CREATE TABLE sessions(id TEXT PRIMARY KEY)") + conn.commit() + conn.close() + + spool = tmp_path / "pending_messages" + spool.mkdir() + (spool / "pending-123.json").write_text("{}", encoding="utf-8") + + capture_dir = tmp_path / "state.db.retired-wal-20260913-22222" + capture_dir.mkdir() + (capture_dir / "manifest.json").write_text(json.dumps({"pid": 22222, "main": {"mode": "copied"}}), encoding="utf-8") + + current_pid = os.getpid() + mock_holders = [ + (current_pid, str(tmp_path / "state.db-wal (deleted)")), + (22222, str(tmp_path / "state.db-wal (deleted)")), + ] + + terminated = [] + dead_pids = set() + + def fake_terminate(pid, force=False, **kwargs): + terminated.append((pid, force)) + dead_pids.add(pid) + state["holders"] = [(current_pid, str(tmp_path / "state.db-wal (deleted)"))] + + state = {"holders": list(mock_holders)} + def fake_iter_holders(_p): + return [h for h in state["holders"] if h[0] not in dead_pids] + + def fake_kill(pid, sig): + if pid in dead_pids: + raise ProcessLookupError("No such process") + return None + + monkeypatch.setattr("gateway.status.terminate_pid", fake_terminate) + monkeypatch.setattr("gateway.status.get_process_start_time", lambda pid: 2222) + monkeypatch.setattr("gateway.status._start_times_agree", lambda cur, exp: cur == exp) + monkeypatch.setattr("hermes_state_dbfile.iter_deleted_sqlite_sidecar_holders", fake_iter_holders) + monkeypatch.setattr("hermes_state_holders._read_proc_argv", lambda _p: ["hermes", "worker"]) + monkeypatch.setattr("os.kill", fake_kill) + + infos = [] + monkeypatch.setattr(doctor_state, "check_info", lambda text: infos.append(text)) + + finding = Finding() + handled = doctor_state._recover_retired_wal(finding, should_fix=True, state_db_path=db, _DHH="~/.hermes") + + assert handled is True + # current_pid was excluded from termination + assert all(pid != current_pid for pid, _ in terminated) + assert 22222 in [pid for pid, _ in terminated] + # Spool file was surfaced + assert any("pending message spool file(s) preserved" in msg for msg in infos) + + +def test_corrupt_store_as_status_handles_deleted_wal_and_replaced_errors(tmp_path): + """corrupt_store_as_status maps DeletedWalGenerationError and StateDbReplacedError to 503 HTTPException.""" + from fastapi import HTTPException + from hermes_cli.web_routers._common import corrupt_store_as_status + from hermes_state_errors import DeletedWalGenerationError, StateDbReplacedError + + db = tmp_path / "state.db" + + # Test DeletedWalGenerationError -> 503 with error: deleted_wal + with pytest.raises(HTTPException) as exc_info: + with corrupt_store_as_status(db): + raise DeletedWalGenerationError("deleted wal generation") + assert exc_info.value.status_code == 503 + assert exc_info.value.detail["error"] == "deleted_wal" + assert "doctor --fix" in exc_info.value.detail["message"] + + # Test StateDbReplacedError -> 503 with error: state_db_replaced + with pytest.raises(HTTPException) as exc_info: + with corrupt_store_as_status(db): + raise StateDbReplacedError("database replaced") + assert exc_info.value.status_code == 503 + assert exc_info.value.detail["error"] == "state_db_replaced" + assert "doctor --fix" in exc_info.value.detail["message"] diff --git a/tests/hermes_cli/test_doctor_wal_holder_guard.py b/tests/hermes_cli/test_doctor_wal_holder_guard.py index f08e685861142..f88ddff74b6a2 100644 --- a/tests/hermes_cli/test_doctor_wal_holder_guard.py +++ b/tests/hermes_cli/test_doctor_wal_holder_guard.py @@ -49,3 +49,39 @@ def test_wal_checkpoint_skipped_while_live_writer_holds_db(tmp_path): assert finding.fixed == 0 assert any("gateway" in issue for issue in finding.issues) + + +def test_wal_warning_qualifies_live_writer_in_dry_run(tmp_path): + """When a live writer holds the DB and should_fix=False, the warning clarifies that large + WAL is normal while running, and does not emit the bare 'run hermes doctor --fix' recommendation.""" + db = tmp_path / "state.db" + setup = sqlite3.connect(str(db)) + try: + setup.execute("CREATE TABLE t(x)") + setup.execute("PRAGMA journal_mode=WAL") + setup.execute("INSERT INTO t VALUES (1)") + setup.commit() + finally: + setup.close() + holder = sqlite3.connect(str(db)) + holder.execute("SELECT count(*) FROM t").fetchone() + try: + wal = Path(f"{db}-wal") + assert wal.exists() + with open(wal, "ab") as handle: + handle.truncate(51 * 1024 * 1024) + finding = Finding() + _state_db_wal(finding, False, db) + finally: + try: + holder.close() + except Exception: + pass + + assert finding.fixed == 0 + assert len(finding.issues) == 1 + issue = finding.issues[0] + assert "normal while Desktop/gateway are running" in issue + assert "stop them first before checkpointing" in issue + # Must NOT emit the bare nudge without stopping instructions + assert issue != "Large WAL file — run 'hermes doctor --fix' to checkpoint" diff --git a/website/docs/developer-guide/state-db-recovery.md b/website/docs/developer-guide/state-db-recovery.md index 7a7af15bd6c39..ecbbce58a5a3c 100644 --- a/website/docs/developer-guide/state-db-recovery.md +++ b/website/docs/developer-guide/state-db-recovery.md @@ -105,3 +105,12 @@ The marker query should return no row, the expected FTS triggers should be present, and canonical row counts must not decrease. If repair fails, preserve both the live database and the reported backup; never delete canonical rows to make a derived-index error disappear. + +## Deleted-WAL and generation guard recovery + +When a database replacement occurs underneath a running process, SQLite triggers `DeletedWalGenerationError`. Hermes halts further writes on the obsolete descriptor, preserves uncommitted turns in `sessions/.jsonl`, captures retired WAL files into `state.db.retired-wal-*/`, and surfaces in-product recovery options. + +`hermes doctor --fix` automatically identifies and stops processes holding deleted sidecars before re-opening `state.db`. + +For user-facing and desktop recovery workflows, see [Session Storage Recovery](../user-guide/session-storage-recovery.md). + diff --git a/website/docs/user-guide/session-storage-recovery.md b/website/docs/user-guide/session-storage-recovery.md new file mode 100644 index 0000000000000..e14dcee6473c4 --- /dev/null +++ b/website/docs/user-guide/session-storage-recovery.md @@ -0,0 +1,100 @@ +--- +sidebar_position: 8 +title: "Session Storage Recovery" +description: "Recovering session storage and resolving database lockouts after deleted-WAL generation guards fire" +--- + +# Session Storage Recovery + +Hermes Agent isolates and protects your conversation history in `~/.hermes/state.db`. If an external event replaces the SQLite database underneath a running process (for example, during an automated update, backup restore, or disk synchronization), SQLite's write-ahead log (WAL) generation check trips. + +When this occurs, Hermes halts active writes on that handle to prevent database corruption, buffers unsaved messages locally, and surfaces in-product recovery options. + +--- + +## The Deleted-WAL Guard + +### Why the Guard Trips + +SQLite WAL mode associates an active database handle with a specific WAL generation number. If: +1. Another Hermes process, update script, or restore command replaces `state.db`, +2. An orphaned process holds an old WAL lock descriptor, or +3. A background task rolls over database sidecars, + +the running process detects a generation mismatch (`DeletedWalGenerationError`). Rather than writing pages into an orphaned WAL that could corrupt the active database, Hermes engages a strict write quarantine. + +### Zero Data Loss Invariant + +When the deleted-WAL guard fires: +- **No data is discarded.** Any in-flight turns or pending transcript updates that cannot be committed to SQLite are automatically spooled to plain JSONL files under `~/.hermes/sessions/.jsonl` and the `~/.hermes/pending_messages/` spool. +- **Sidecar evidence is captured.** The replaced WAL and its shm sidecars are preserved in timestamped capture directories: `~/.hermes/state.db.retired-wal--/` along with a `manifest.json`. +- **Pre-update backups remain intact.** Any pre-update emergency backups (`~/.hermes/state.db.pre-update-emergency-*.bak`) remain available in your Hermes home directory. + +--- + +## In-Product Recovery + +### Desktop App (One-Click Recovery) + +When Hermes detects a `deleted_wal` persistence failure during a chat turn, Desktop displays a notification banner: + +> **Hermes paused saving this chat** because another Hermes process replaced its session database. Nothing is lost. + +Click the **Recover** action button directly in the banner. + +Desktop triggers an authenticated repair request to `/api/ops/doctor` with `fix: true`. Hermes: +1. Detects and gracefully terminates any lingering background holders or orphaned gateway processes holding the old WAL descriptor. +2. Re-verifies `state.db` health, FTS5 triggers, and metadata markers. +3. Restores database write readiness so your conversation resumes saving seamlessly. + +You can also trigger this repair at any time from **Command Center → Maintenance → Run doctor --fix**. + +--- + +### Command Line (`hermes doctor --fix`) + +If you are using the CLI or a headless server, resolve the condition using `hermes doctor`: + +```bash +# 1. Check database state and identify conflicting processes +hermes doctor + +# 2. Automatically stop orphaned holders and recover access +hermes doctor --fix +``` + +#### What `hermes doctor --fix` Does: +- **Detects Holders:** Identifies any running processes (`hermes gateway`, GUI backends, or subagents) holding deleted SQLite sidecars (`iter_deleted_sqlite_sidecar_holders`). +- **Terminates Orphaned Holders:** Safely sends termination signals to stale PIDs to release file descriptor locks. +- **Re-opens & Re-checks:** Re-opens `SessionDB` to confirm standard WAL access and validates FTS5 index integrity. +- **Surfaces Artifacts:** If retired WAL captures exist, doctor prints the exact inspection command: + ```bash + hermes sessions recover --source ~/.hermes/state.db.retired-wal-/state.db-wal --inspect-only + ``` + +--- + +## Inspecting and Restoring Captured Artifacts + +If you want to review transactions captured in a retired WAL directory before archiving them: + +```bash +# Inspect contents without modifying your main state.db +hermes sessions recover \ + --source "$HOME/.hermes/state.db.retired-wal-20260913-120000-1234/state.db-wal" \ + --inspect-only + +# Recover records into a separate database file +hermes sessions recover \ + --source "$HOME/.hermes/state.db.retired-wal-20260913-120000-1234/state.db-wal" \ + --output "$HOME/recovered-sessions.db" +``` + +Once verified, you may delete the `state.db.retired-wal-*` directory to free up disk space. + +--- + +## Related Documentation + +- [Sessions Guide](./sessions.md) — Managing sessions, titles, resumes, and compression. +- [State DB Developer Guide](../developer-guide/state-db-recovery.md) — Internal recovery mechanics and FTS repair details. diff --git a/website/docs/user-guide/sessions.md b/website/docs/user-guide/sessions.md index e17fc4964e6de..77e1c62f10a2a 100644 --- a/website/docs/user-guide/sessions.md +++ b/website/docs/user-guide/sessions.md @@ -980,3 +980,13 @@ hermes sessions prune --older-than 30 --yes :::tip Auto-prune is **on by default**: ended sessions that have been inactive for `sessions.retention_days` (default 90) are removed at startup, and active sessions are never touched (see [Automatic Cleanup](#automatic-cleanup) above). Session history powers `session_search` recall across past conversations, so if you want to keep every ended session forever, set `sessions.auto_prune: false` in `config.yaml`, or raise `retention_days`. With auto-prune off, `hermes sessions prune` remains available for one-off cleanup (observed failure mode without any pruning: a 384 MB `state.db` with ~1000 sessions slowing down FTS5 inserts and `/resume` listing). ::: + +### Storage Health and Recovery + +If Hermes detects database replacement, orphaned locks, or SQLite generation errors while saving a conversation, active writes pause to prevent corruption and messages are spooled safely to disk without data loss. + +- In the Desktop app, a notification banner appears with a one-click **Recover** button to repair the database connection immediately. +- In CLI or headless environments, run `hermes doctor --fix` to safely stop orphaned holders and restore database access. + +For full recovery instructions, artifact inspection, and troubleshooting, see [Session Storage Recovery](./session-storage-recovery.md). + diff --git a/website/sidebars.ts b/website/sidebars.ts index 7951d983d8660..072f6350390c6 100644 --- a/website/sidebars.ts +++ b/website/sidebars.ts @@ -52,6 +52,7 @@ const sidebars: SidebarsConfig = { ], }, 'user-guide/sessions', + 'user-guide/session-storage-recovery', 'user-guide/profiles', 'user-guide/profile-distributions', 'user-guide/multi-profile-gateways',