diff --git a/hermes_cli/web_routers/_common.py b/hermes_cli/web_routers/_common.py index 1301353f5b..a93974894d 100644 --- a/hermes_cli/web_routers/_common.py +++ b/hermes_cli/web_routers/_common.py @@ -7,7 +7,9 @@ from __future__ import annotations import asyncio import contextlib import logging -from typing import Any, Callable, Optional +import sqlite3 +import time +from typing import Any, Callable, Dict, Optional from fastapi import HTTPException @@ -76,3 +78,39 @@ def require(value: Optional[str], detail: str) -> str: if not stripped: raise HTTPException(status_code=400, detail=detail) return stripped + + +# Corrupt-store reporting for polled read endpoints. The dashboard polls analytics every few +# seconds; a persistently malformed state.db once produced ~520K identical tracebacks in 24 h +# (#96591). One WARNING per store per interval, then debug; the caller gets an explicit status +# instead of a 500. The file is never quarantined or renamed from here — that is `hermes doctor`'s job. +_CORRUPT_STORE_WARN_INTERVAL_S = 300.0 +_corrupt_store_warned_at: Dict[str, float] = {} # {db path: monotonic} + +CORRUPT_STORE_DETAIL = { + "error": "state_db_corrupt", + "message": "state.db corrupt — run `hermes doctor` (then `hermes doctor --fix` or `hermes sessions repair`).", +} + + +@contextlib.contextmanager +def corrupt_store_as_status(db_path): + """Map a corrupt-image ``sqlite3.DatabaseError`` 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 + + try: + yield + except sqlite3.DatabaseError as exc: + if not is_malformed_db_error(exc): + raise + key, now = str(db_path), time.monotonic() + last = _corrupt_store_warned_at.get(key) + 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) + 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 diff --git a/hermes_cli/web_routers/analytics.py b/hermes_cli/web_routers/analytics.py index d3dac5f9bf..77d1131865 100644 --- a/hermes_cli/web_routers/analytics.py +++ b/hermes_cli/web_routers/analytics.py @@ -13,6 +13,7 @@ from fastapi import APIRouter, HTTPException, Query from hermes_cli.config import get_config_path, read_raw_config from hermes_cli.web_deps import late +from hermes_cli.web_routers._common import corrupt_store_as_status from hermes_cli.web_server_profiles import ( _approval_mode_of, _aux_task_summary, _aux_usage_rows, _broadcast_gateway_session_info, _is_other_profile, _merge_aux_into_by_model, ) @@ -22,6 +23,7 @@ router = APIRouter() # Late-bound so a test's monkeypatch on the owning module wins at call time. _open_session_db_for_profile = late("_open_session_db_for_profile", "hermes_cli.web_server_sessions") +_session_db_path_for_profile = late("_session_db_path_for_profile", "hermes_cli.web_server_sessions") _profile_scope = late("_profile_scope", "hermes_cli.web_server_profiles") save_config = late("save_config", "hermes_cli.config") @@ -147,7 +149,8 @@ async def get_usage_analytics( values would force expensive full-history SQL and InsightsEngine work, or produce empty/inverted time windows. The UI only offers 7/30/90-day presets.""" - return await asyncio.to_thread(_get_usage_analytics, days, profile) + with corrupt_store_as_status(_session_db_path_for_profile(profile)): + return await asyncio.to_thread(_get_usage_analytics, days, profile) _USAGE_KEYS = ( @@ -305,4 +308,5 @@ async def get_models_analytics( profile: Optional[str] = None, ): """Return model analytics without blocking the serving event loop.""" - return await asyncio.to_thread(_get_models_analytics, days, profile) + with corrupt_store_as_status(_session_db_path_for_profile(profile)): + return await asyncio.to_thread(_get_models_analytics, days, profile) diff --git a/hermes_cli/web_server_sessions.py b/hermes_cli/web_server_sessions.py index 106288207d..70bfbc914b 100644 --- a/hermes_cli/web_server_sessions.py +++ b/hermes_cli/web_server_sessions.py @@ -180,20 +180,23 @@ def _open_session_db_at_path(db_path: Path, *, read_only: bool): return _open_probed() -def _open_session_db_for_profile(profile: Optional[str], *, read_only: bool): - """Open a SessionDB for ``profile`` (None/empty = this process's own state.db). - - Access-mode semantics: see :func:`_open_session_db_at_path`. - """ +def _session_db_path_for_profile(profile: Optional[str]) -> Path: + """state.db path for ``profile`` (None/empty = this process's own).""" from hermes_cli.web_server_cron import _cron_profile_home from hermes_state import _default_db_path if profile: _name, home = _cron_profile_home(profile) - db_path = Path(home) / "state.db" - else: - db_path = Path(_default_db_path()) - return _open_session_db_at_path(db_path, read_only=read_only) + return Path(home) / "state.db" + return Path(_default_db_path()) + + +def _open_session_db_for_profile(profile: Optional[str], *, read_only: bool): + """Open a SessionDB for ``profile`` (None/empty = this process's own state.db). + + Access-mode semantics: see :func:`_open_session_db_at_path`. + """ + return _open_session_db_at_path(_session_db_path_for_profile(profile), read_only=read_only) # In-process throttle for the opportunistic auto-archive trigger, keyed by diff --git a/tests/hermes_cli/test_web_analytics_corrupt_store.py b/tests/hermes_cli/test_web_analytics_corrupt_store.py new file mode 100644 index 0000000000..d1cd877ed0 --- /dev/null +++ b/tests/hermes_cli/test_web_analytics_corrupt_store.py @@ -0,0 +1,57 @@ +"""A malformed state.db must not turn dashboard analytics polling into a traceback storm (#96591).""" +import logging +import sqlite3 +from pathlib import Path + +import pytest +from fastapi import FastAPI +from fastapi.testclient import TestClient + +from hermes_cli.web_routers import _common, analytics +from hermes_state import SessionDB + + +def _malformed_state_db(home: Path) -> Path: + db_path = home / "state.db" + db = SessionDB(db_path=db_path) + db.create_session("s1", source="cli", model="m") + db.close() + for side in ("-wal", "-shm"): + Path(str(db_path) + side).unlink(missing_ok=True) + with open(db_path, "r+b") as f: + f.seek(100) + f.write(b"\xff" * (4096 - 100)) + with pytest.raises(sqlite3.DatabaseError): + sqlite3.connect(str(db_path)).execute("SELECT count(*) FROM sqlite_master") + return db_path + + +def test_corrupt_store_polls_return_status_and_warn_once_per_interval(tmp_path, monkeypatch, caplog): + monkeypatch.setenv("HERMES_HOME", str(tmp_path)) + import hermes_state + db_path = _malformed_state_db(tmp_path) + monkeypatch.setattr(hermes_state, "_default_db_path", lambda: db_path) + monkeypatch.setattr(_common, "_corrupt_store_warned_at", {}) + app = FastAPI() + app.include_router(analytics.router) + client = TestClient(app) + + with caplog.at_level(logging.DEBUG, logger="hermes_cli.web_server"): + first = client.get("/api/analytics/usage?days=7") + second = client.get("/api/analytics/usage?days=7") + third = client.get("/api/analytics/models?days=7") + for resp in (first, second, third): + assert resp.status_code == 503 + assert resp.json()["detail"]["error"] == "state_db_corrupt" + assert "hermes doctor" in resp.json()["detail"]["message"] + warnings = [r for r in caplog.records if r.levelno >= logging.WARNING] + assert len(warnings) == 1, [r.getMessage() for r in warnings] + assert not any(r.exc_info for r in caplog.records), "no tracebacks for a known corrupt store" + assert db_path.exists() and db_path.stat().st_size > 0, "dashboard must never quarantine the file" + + # The gate re-arms once the interval has elapsed (aged, not slept). + _common._corrupt_store_warned_at[str(db_path)] -= _common._CORRUPT_STORE_WARN_INTERVAL_S + 1 + caplog.clear() + with caplog.at_level(logging.WARNING, logger="hermes_cli.web_server"): + assert client.get("/api/analytics/usage?days=7").status_code == 503 + assert sum(r.levelno >= logging.WARNING for r in caplog.records) == 1