From bdee48928f11b3109e43e52d88f9a24cf9e4cc0d Mon Sep 17 00:00:00 2001 From: emozilla Date: Fri, 7 Aug 2026 00:41:58 -0400 Subject: [PATCH] fix(dashboard): derive the stale-schema read probe from SCHEMA_SQL MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit After `hermes update`, the desktop sidebar showed "No sessions yet" until the user's first message. #72424 added sessions.last_activity_at, which list_sessions_rich now selects — but column adds only land through _reconcile_columns() in the writable _init_schema, and read-only opens skip that by design. Every sidebar read path opens state.db read-only, so each poll raised "no such column: s.last_activity_at" until the first prompt's lazy session-row persist forced a writable open and reconciled. A heal for exactly this class already existed (_open_session_db_for_profile probes the read-only handle and does a one-time writable reopen on staleness), but its probe was a hand-written four-column list that never learned last_activity_at — it went stale three days after shipping. And the batched sidebar route (/api/profiles/sessions/sidebar) bypassed the helper entirely, swallowing per-profile failures into an errors array the desktop never surfaces, so the incident produced an empty sidebar with clean logs. The fix removes the maintenance burden instead of paying it once more: - hermes_state_schema.schema_read_probe_statements() derives one `SELECT FROM LIMIT 0` per table from SCHEMA_SQL via the existing _parse_schema_columns() — the same source of truth the writable reconciler diffs against, so any future ADD COLUMN is probed with no list to update. Column references are table-qualified: an unqualified double-quoted identifier that fails to resolve silently degrades to a string literal (SQLite's double-quoted-string misfeature) and would make the probe pass on exactly the store it exists to catch. - web_server splits the heal into a path-level _open_session_db_at_path (semantics unchanged) so the cross-profile session routes can share it; both profiles.py loops and _count_status_active_sessions (the remaining raw read-only sibling) now open through it. The heal stays a helper rather than a SessionDB classmethod on purpose: escalation-to-writable must remain an explicit caller decision — update_cmd.py opens read-only mid-update and must never write. - Exhaustion guard: if the writable heal SUCCEEDS and the re-probe still fails (a schema problem ADD COLUMN cannot express), the store is marked exhausted — warn once, skip the probe, serve reads probe-less — instead of re-running the full writable init on every poll against a possibly live DB. A FAILED writable open (transient lock) is deliberately not recorded, so the next poll retries the heal. - The per-profile swallow sites in profiles.py now also log a deduplicated warning, so a persistent read failure is loud in errors.log even though the response errors array stays invisible to the sidebar. Tests: probe/SCHEMA_SQL coverage invariants (tests/test_schema_read_probe.py), last_activity_at added to the /api/sessions heal parametrize, a sidebar-route heal test reproducing the shipped symptom (errors == [] and the session returned against a store missing the column), and an exhaustion test pinning exactly one writable open. The sidebar and last_activity_at tests fail on main. --- hermes_cli/web_routers/profiles.py | 44 ++++++++-- hermes_cli/web_server.py | 122 ++++++++++++++++++++-------- hermes_state_schema.py | 47 +++++++++++ tests/hermes_cli/test_web_server.py | 107 +++++++++++++++++++++++- tests/test_schema_read_probe.py | 100 +++++++++++++++++++++++ 5 files changed, 380 insertions(+), 40 deletions(-) create mode 100644 tests/test_schema_read_probe.py diff --git a/hermes_cli/web_routers/profiles.py b/hermes_cli/web_routers/profiles.py index 3d72d073c3165..075480f22eacf 100644 --- a/hermes_cli/web_routers/profiles.py +++ b/hermes_cli/web_routers/profiles.py @@ -38,6 +38,25 @@ from hermes_cli.web_models import ( # Same logger the handlers used before extraction (identical logger object). _log = logging.getLogger("hermes_cli.web_server") +# Per-profile session reads report failures in the response's ``errors`` +# array, which the desktop sidebar does not currently surface — during the +# stale-schema incident that made an empty sidebar look healthy while +# /api/sessions (which logs) was the only diagnosable trace. Warn once per +# (profile, message) per process so a persistent failure is loud in +# errors.log without turning every sidebar poll into log spam. +_profile_read_warned: set = set() + + +def _warn_profile_read_error(profile: str, exc: Exception) -> None: + key = (profile, str(exc)) + if key in _profile_read_warned: + return + _profile_read_warned.add(key) + _log.warning( + "profile session read failed for %r (reported only in the response " + "errors array): %s", profile, exc, + ) + sessions_router = APIRouter() router = APIRouter() @@ -47,6 +66,7 @@ _cron_profile_home = late("_cron_profile_home") _disable_unselected_skills = late("_disable_unselected_skills") _fallback_profile_dicts = late("_fallback_profile_dicts") _hub_action_name = late("_hub_action_name") +_open_session_db_at_path = late("_open_session_db_at_path") _profile_setup_command = late("_profile_setup_command") _profile_to_dict = late("_profile_to_dict") _resolve_profile_dir = late("_resolve_profile_dir") @@ -92,7 +112,6 @@ def get_profiles_sessions( if order not in ("created", "recent"): raise HTTPException(status_code=400, detail="order must be one of: created, recent") - from hermes_state import SessionDB from hermes_cli import profiles as profiles_mod targets: List[Tuple[str, Path]] = [] @@ -132,11 +151,17 @@ def get_profiles_sessions( if not db_path.exists(): continue try: - # Read-only: this loop runs on every sidebar refresh, so it must - # never DDL/write-lock another profile's live DB (see SessionDB - # read_only docstring). - db = SessionDB(db_path=db_path, read_only=True) + # Read-only on the healthy path: this loop runs on every sidebar + # refresh, so it must not routinely DDL/write-lock another + # profile's live DB (see SessionDB read_only docstring). The + # helper's stale-schema probe performs a ONE-TIME writable open + # when the store predates a schema addition — the same reconcile + # that profile's own backend runs at startup — because read-only + # opens skip column reconciliation and would otherwise fail here + # on every refresh until something else opened the DB writable. + db = _open_session_db_at_path(db_path, read_only=True) except Exception as exc: + _warn_profile_read_error(name, exc) errors.append({"profile": name, "error": str(exc)}) continue try: @@ -176,6 +201,7 @@ def get_profiles_sessions( s["pinned"] = bool(s.get("pinned")) merged.append(s) except Exception as exc: + _warn_profile_read_error(name, exc) errors.append({"profile": name, "error": str(exc)}) finally: db.close() @@ -226,7 +252,6 @@ def get_profiles_sessions_sidebar( ``min_messages=1`` / ``archived=exclude`` / recency order, matching the desktop's per-slice calls. """ - from hermes_state import SessionDB from hermes_cli import profiles as profiles_mod # cron + messaging are cross-profile; recents is scoped to recents_profile. @@ -290,8 +315,12 @@ def get_profiles_sessions_sidebar( if not db_path.exists(): continue try: - db = SessionDB(db_path=db_path, read_only=True) + # Read-only with the stale-schema heal — same contract as the + # per-slice endpoint above (one-time writable reconcile when the + # store predates a schema addition, plain read-only otherwise). + db = _open_session_db_at_path(db_path, read_only=True) except Exception as exc: + _warn_profile_read_error(name, exc) errors.append({"profile": name, "error": str(exc)}) continue try: @@ -310,6 +339,7 @@ def get_profiles_sessions_sidebar( _tag(_slice(db, exclude=messaging_exclude_list, cap=messaging_cap), name) ) except Exception as exc: + _warn_profile_read_error(name, exc) errors.append({"profile": name, "error": str(exc)}) finally: db.close() diff --git a/hermes_cli/web_server.py b/hermes_cli/web_server.py index 3627f34a0e1c1..7fc50719a3624 100644 --- a/hermes_cli/web_server.py +++ b/hermes_cli/web_server.py @@ -1673,19 +1673,20 @@ def _probe_gateway_health() -> tuple[bool, dict | None]: def _count_status_active_sessions() -> int: """Return the dashboard status active-session count. - This is best-effort status garnish, not a critical path. Use a read-only - connection so /api/status never tries to initialise or migrate state.db - while another Hermes process is writing to it. + This is best-effort status garnish, not a critical path. Opens read-only + (via the shared stale-schema heal, same as every other dashboard read + path) so /api/status never routinely writes to state.db while another + Hermes process is using it. """ - from hermes_state import DEFAULT_DB_PATH, SessionDB + from hermes_state import _default_db_path - # read_only opens require the DB to already exist (see SessionDB.__init__ - # read_only contract) — on a fresh install every /api/status poll would - # otherwise pay an OperationalError until the first session is written. - if not DEFAULT_DB_PATH.exists(): + # The heal helper bootstraps a missing store; this garnish must not — on + # a fresh install /api/status polls would otherwise create state.db + # before the user's first session. + if not Path(_default_db_path()).exists(): return 0 - db = SessionDB(read_only=True) + db = _open_session_db_for_profile(None, read_only=True) try: sessions = db.list_sessions_rich(limit=50, compact_rows=True) now = time.time() @@ -11195,38 +11196,56 @@ from hermes_cli.web_routers.sessions import ( # noqa: E402,F401 — legacy re-e # query raises "no such table: sessions". _session_db_bootstrap_lock = threading.Lock() -# Stale-schema probe for read-only opens: compiled against the newest columns -# the dashboard read paths query. Reads at most one row per table. Read-only -# opens skip _reconcile_columns(), so an older store would otherwise 500 on -# every poll until something opened it writable. -_SESSION_DB_READ_PROBE_SQL = ( - "SELECT (SELECT archived FROM sessions LIMIT 1), " - "(SELECT pinned FROM sessions LIMIT 1), " - "(SELECT active FROM messages LIMIT 1), " - "(SELECT compacted FROM messages LIMIT 1)" -) + +def _session_db_read_probe_statements() -> tuple: + """Stale-schema probes for read-only opens, derived from SCHEMA_SQL. + + Read-only opens skip _reconcile_columns(), so an older store would + otherwise 500 on every poll until something opened it writable. Derived + from the same schema the writable reconciler applies, so any column + added there is probed here automatically — the previous hand-written + probe listed four columns and went stale the first time a new column + (sessions.last_activity_at) shipped, leaving the desktop sidebar empty + after `hermes update` until the first message forced a writable open. + """ + from hermes_state_schema import schema_read_probe_statements + + return schema_read_probe_statements() -def _open_session_db_for_profile(profile: Optional[str], *, read_only: bool): - """Open a SessionDB with an explicit access mode for a profile. +# Stores where a heal WRITABLE OPEN SUCCEEDED and the read probe still +# failed afterwards: the schema problem is one reconciliation cannot fix +# (e.g. a NOT-NULL-without-default column SQLite refuses to ADD). Retrying +# the full writable init on every poll would hammer a live DB for nothing, +# so such stores fall back to the raw read-only open until restart. A +# FAILED writable open (transient lock) is deliberately NOT recorded — +# the next poll retries the heal. +_session_db_heal_exhausted: set = set() - ``profile`` None/empty selects this process's own ``state.db``. A named - profile opens that profile's on-disk store directly. +# Deduplicates the heal-failure warning per store per process, so a +# persistent problem is loud once instead of once per sidebar poll. +_session_db_heal_warned: set = set() + + +def _open_session_db_at_path(db_path: Path, *, read_only: bool): + """Open a SessionDB at an explicit path with an explicit access mode. Writable opens keep the full init and repair path. Read-only opens bootstrap a missing or zero-byte store once, and heal an older or malformed schema through one writable open before reopening read-only. The healthy read path never takes a write lock or requests a checkpoint. + + Scope of the heal: the probe checks every table/column declared in + SCHEMA_SQL (see ``schema_read_probe_statements``), so ANY schema + addition escalates a stale store to a one-time writable open — the same + reconcile the store's own backend runs at startup. Tables created + outside SCHEMA_SQL (telemetry ``tel_*``, FTS shadow tables) are + deliberately outside both the probe and the heal. """ import sqlite3 - from hermes_state import SessionDB, _default_db_path, is_malformed_db_error + from hermes_state import SessionDB, is_malformed_db_error - if profile: - _name, home = _cron_profile_home(profile) - db_path = Path(home) / "state.db" - else: - db_path = Path(_default_db_path()) if not read_only: return SessionDB(db_path=db_path, read_only=False) @@ -11248,9 +11267,10 @@ def _open_session_db_for_profile(profile: Optional[str], *, read_only: bool): # Unit-test fakes may replace SessionDB without exposing a raw # connection. Probe only real connections. conn = getattr(db, "_conn", None) - if conn is not None: + if conn is not None and str(db_path) not in _session_db_heal_exhausted: try: - conn.execute(_SESSION_DB_READ_PROBE_SQL).fetchone() + for statement in _session_db_read_probe_statements(): + conn.execute(statement).fetchone() except BaseException: db.close() raise @@ -11264,7 +11284,45 @@ def _open_session_db_for_profile(profile: Optional[str], *, read_only: bool): if not stale_schema and not is_malformed_db_error(exc): raise SessionDB(db_path=db_path, read_only=False).close() - return _open_probed() + try: + return _open_probed() + except sqlite3.DatabaseError as still_stale: + message = str(still_stale).lower() + if "no such table" not in message and "no such column" not in message: + raise + # The writable open succeeded but the store is STILL behind the + # probe: reconciliation cannot fix this one. Serve reads without + # the probe (queries touching the broken part will still fail, + # everything else works) and stop paying the writable init per + # poll. + _session_db_heal_exhausted.add(str(db_path)) + if str(db_path) not in _session_db_heal_warned: + _session_db_heal_warned.add(str(db_path)) + _log.warning( + "state.db at %s is missing schema that a writable " + "reconcile could not add (%s); read paths may partially " + "fail until the store is repaired", + db_path, + still_stale, + ) + return _open_probed() + + +def _open_session_db_for_profile(profile: Optional[str], *, read_only: bool): + """Open a SessionDB with an explicit access mode for a profile. + + ``profile`` None/empty selects this process's own ``state.db``. A named + profile opens that profile's on-disk store directly. Access-mode + semantics are documented on :func:`_open_session_db_at_path`. + """ + 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) # In-process throttle for the opportunistic auto-archive trigger, keyed by diff --git a/hermes_state_schema.py b/hermes_state_schema.py index 0761a0804ef72..68a888879c2b5 100644 --- a/hermes_state_schema.py +++ b/hermes_state_schema.py @@ -32,6 +32,53 @@ from hermes_state_common import ( # keep that logger identity so log filtering/capture behavior is unchanged. logger = logging.getLogger("hermes_state") +# Cache for schema_read_probe_statements() — parsing SCHEMA_SQL spins up an +# in-memory SQLite database, so derive the statements once per process. +_READ_PROBE_STATEMENTS: Optional[tuple] = None + + +def schema_read_probe_statements() -> tuple: + """SELECT statements that fail iff a live store is behind SCHEMA_SQL. + + Read-only opens skip ``_reconcile_columns()`` by design (no DDL against + another profile's live DB), so a store created before a schema addition + keeps 500ing on read paths until something opens it writable. Callers + that heal on staleness (see ``_open_session_db_at_path`` in + ``hermes_cli/web_server.py``) run these probes right after a read-only + open: any missing table raises "no such table" and any missing column + raises "no such column", both at prepare time. + + Derived from SCHEMA_SQL — the same source of truth the writable + reconciler diffs against — so a column added there is covered here + automatically. A hand-maintained probe list went stale within days of + shipping (it never learned ``sessions.last_activity_at``, so the sidebar + served an empty session list after `hermes update` until the user's + first message forced a writable open). + + Each statement is ``LIMIT 0``: column resolution happens at prepare + time, so the probe reads zero rows. Column references are qualified + with the table name — an unqualified double-quoted identifier that + fails to resolve silently degrades to a string literal (SQLite's + double-quoted-string misfeature), which would make the probe pass on + exactly the stale store it exists to catch. + """ + global _READ_PROBE_STATEMENTS + if _READ_PROBE_STATEMENTS is None: + tables = SessionSchemaMixin._parse_schema_columns(SCHEMA_SQL) + _READ_PROBE_STATEMENTS = tuple( + 'SELECT {} FROM "{}" LIMIT 0'.format( + ", ".join( + '"{}"."{}"'.format( + table.replace('"', '""'), col.replace('"', '""') + ) + for col in cols + ), + table.replace('"', '""'), + ) + for table, cols in sorted(tables.items()) + ) + return _READ_PROBE_STATEMENTS + class SessionSchemaMixin: """See module docstring — mixin for SessionDB (Schema cluster).""" diff --git a/tests/hermes_cli/test_web_server.py b/tests/hermes_cli/test_web_server.py index 462e8881f8e8c..5154fcffbf8c1 100644 --- a/tests/hermes_cli/test_web_server.py +++ b/tests/hermes_cli/test_web_server.py @@ -398,7 +398,9 @@ class TestWebServerEndpoints: assert response.json()["sessions"] == [] assert response.json()["total"] == 0 - @pytest.mark.parametrize("missing_column", ["archived", "pinned"]) + @pytest.mark.parametrize( + "missing_column", ["archived", "pinned", "last_activity_at"] + ) def test_get_sessions_heals_stale_schema_store(self, missing_column): import sqlite3 @@ -434,6 +436,109 @@ class TestWebServerEndpoints: healed.close() assert missing_column in columns + def test_profiles_sidebar_heals_stale_schema_store(self): + """The desktop's batched sidebar route must heal a stale store too. + + The shipped regression (#72424 aftermath): a store predating + ``sessions.last_activity_at`` made every per-profile read raise + "no such column", which this endpoint swallowed into its ``errors`` + array — the desktop rendered "No sessions yet" after `hermes update` + until the user's first message forced a writable open elsewhere. + """ + import sqlite3 + + from hermes_constants import get_hermes_home + from hermes_state import SessionDB + + db_path = get_hermes_home() / "state.db" + seed = SessionDB(db_path=db_path) + try: + seed.create_session("sidebar-stale", source="cli") + seed.append_message( + session_id="sidebar-stale", role="user", content="hi" + ) + finally: + seed.close() + + legacy = sqlite3.connect(str(db_path)) + try: + legacy.execute("ALTER TABLE sessions DROP COLUMN last_activity_at") + legacy.commit() + finally: + legacy.close() + + response = self.client.get("/api/profiles/sessions/sidebar") + + assert response.status_code == 200 + payload = response.json() + assert payload["errors"] == [] + assert [row["id"] for row in payload["recents"]["sessions"]] == [ + "sidebar-stale" + ] + + def test_heal_gives_up_when_reconcile_cannot_fix_the_store(self, monkeypatch): + """A probe failure reconciliation can't cure must not retry forever. + + The writable heal is a full SessionDB init against a possibly-live + DB. If the store is STILL behind the probe afterwards (schema problem + ADD COLUMN can't express), retrying that init on every sidebar poll + would hammer the DB for nothing: serve reads probe-less instead, warn + once, and never pay the writable open for that store again. + """ + from hermes_cli import web_server + from hermes_constants import get_hermes_home + from hermes_state import SessionDB + + db_path = get_hermes_home() / "state.db" + seed = SessionDB(db_path=db_path) + try: + seed.create_session("unfixable", source="cli") + finally: + seed.close() + + # A column no SCHEMA_SQL declares: the heal's writable reconcile + # cannot add it, so the re-probe keeps failing. + monkeypatch.setattr( + web_server, + "_session_db_read_probe_statements", + lambda: ('SELECT "sessions"."not_a_real_column" FROM "sessions" LIMIT 0',), + ) + monkeypatch.setattr(web_server, "_session_db_heal_exhausted", set()) + monkeypatch.setattr(web_server, "_session_db_heal_warned", set()) + + writable_opens = [] + + import hermes_state + + original_init = hermes_state.SessionDB.__init__ + + def counting_init(self, *args, **kwargs): + if not kwargs.get("read_only", False): + writable_opens.append(1) + return original_init(self, *args, **kwargs) + + # web_server imports SessionDB inside the function body, so patching + # the class on hermes_state covers every open the helper makes. + monkeypatch.setattr(hermes_state.SessionDB, "__init__", counting_init) + + # First open: probe fails -> one writable heal -> re-probe fails -> + # exhausted. Still returns a usable read-only handle. + db = web_server._open_session_db_for_profile(None, read_only=True) + try: + assert db.list_sessions_rich(limit=10, compact_rows=True) + finally: + db.close() + assert len(writable_opens) == 1 + assert str(db_path) in web_server._session_db_heal_exhausted + + # Second open: probe skipped, NO further writable opens. + db = web_server._open_session_db_for_profile(None, read_only=True) + try: + assert db.list_sessions_rich(limit=10, compact_rows=True) + finally: + db.close() + assert len(writable_opens) == 1 + def test_get_sessions_zero_byte_store_returns_empty_list(self): from hermes_constants import get_hermes_home diff --git a/tests/test_schema_read_probe.py b/tests/test_schema_read_probe.py new file mode 100644 index 0000000000000..9770a8f050a21 --- /dev/null +++ b/tests/test_schema_read_probe.py @@ -0,0 +1,100 @@ +"""Contract tests for schema_read_probe_statements(). + +Read-only SessionDB opens skip _reconcile_columns() by design, so dashboard +read paths heal stale stores via a probe-then-writable-reopen dance in +``hermes_cli.web_server._open_session_db_at_path``. These tests pin the +probe's contract: it is DERIVED from SCHEMA_SQL (any column added there is +covered automatically — the previous hand-written probe went stale within +days) and it must fail at prepare time on a store missing any declared +column or table. +""" + +import sqlite3 + +import pytest + +from hermes_state_common import DEFERRED_INDEX_SQL, SCHEMA_SQL +from hermes_state_schema import SessionSchemaMixin, schema_read_probe_statements + + +def _fresh_schema_conn() -> sqlite3.Connection: + conn = sqlite3.connect(":memory:") + conn.executescript(SCHEMA_SQL) + conn.executescript(DEFERRED_INDEX_SQL) + return conn + + +class TestSchemaReadProbeStatements: + def test_probes_cover_every_declared_column(self): + """Invariant: every column SCHEMA_SQL declares appears in a probe. + + This is the anti-staleness contract — a column added to SCHEMA_SQL + must be probed without anyone remembering to update a list. + """ + expected = SessionSchemaMixin._parse_schema_columns(SCHEMA_SQL) + statements = schema_read_probe_statements() + by_table = {} + for statement in statements: + for table in expected: + if f'FROM "{table}"' in statement: + by_table[table] = statement + for table, cols in expected.items(): + assert table in by_table, f"no probe statement for table {table}" + for col in cols: + assert f'"{table}"."{col}"' in by_table[table], ( + f"column {table}.{col} declared in SCHEMA_SQL but not probed" + ) + + def test_probes_pass_on_fresh_schema(self): + conn = _fresh_schema_conn() + try: + for statement in schema_read_probe_statements(): + conn.execute(statement).fetchone() + finally: + conn.close() + + def test_probes_fail_on_missing_column(self): + """The shipped regression: a store predating sessions.last_activity_at + + (#72424) passed the old hand-written probe, then 500'd inside + list_sessions_rich on every sidebar poll until the user's first + message forced a writable open. + """ + conn = _fresh_schema_conn() + try: + conn.execute("ALTER TABLE sessions DROP COLUMN last_activity_at") + # The failure must come from the sessions probe naming the exact + # column — not incidentally from some other statement — so a + # probe-generation bug that misassigns columns to tables can't + # sneak through. + sessions_probe = next( + s + for s in schema_read_probe_statements() + if 'FROM "sessions"' in s + ) + with pytest.raises(sqlite3.OperationalError) as excinfo: + conn.execute(sessions_probe) + assert "no such column: sessions.last_activity_at" in str( + excinfo.value + ) + finally: + conn.close() + + def test_probes_fail_on_missing_table(self): + conn = sqlite3.connect(":memory:") + try: + conn.executescript(SCHEMA_SQL) + conn.executescript("DROP TABLE gateway_routing") + gateway_probe = next( + s + for s in schema_read_probe_statements() + if 'FROM "gateway_routing"' in s + ) + with pytest.raises(sqlite3.OperationalError) as excinfo: + conn.execute(gateway_probe) + assert "no such table" in str(excinfo.value).lower() + finally: + conn.close() + + def test_probe_statements_are_cached(self): + assert schema_read_probe_statements() is schema_read_probe_statements()