From a3cce7b97432c20af9702c6a0b3e75954976b079 Mon Sep 17 00:00:00 2001 From: teknium1 <127238744+teknium1@users.noreply.github.com> Date: Fri, 18 Sep 2026 04:17:37 -0700 Subject: [PATCH] fix(gateway): warn when a live gateway's heartbeat goes stale instead of printing `running` MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The reporter's case in #113372 is "not a crash": the process stays alive, `gateway_state.json` keeps saying `running`, and housekeeping, cron and the kanban dispatcher are frozen. Nothing wrote `updated_at` periodically, so the file was a stored status, not a heartbeat, and both `hermes gateway status` and `/api/status` rendered a wedged gateway as healthy (the existing stale arm only fires when the recorded PID is gone). Make the housekeeping tick re-stamp `gateway_state.json` first thing every tick (60 s), so `updated_at` is a heartbeat that stops when the thread — or a chore blocked on the loop — wedges. Readers then warn on `running`/`starting` + stale stamp + live PID: `hermes gateway status` prints `⚠ Gateway heartbeat stale: housekeeping has not refreshed gateway_state.json for N s (event loop or housekeeping wedged; pid X alive)`, `/api/status` carries `gateway_heartbeat_stale_s` (null when healthy) and the sidebar strip shows "Heartbeat stale". Liveness (`gateway_running`, busy/drainable) still keys off the PID, never the stamp. Draining is excluded: shutdown drains the housekeeping thread before the process exits, so its stamp legitimately ages. Invariant tests: the CLI line names the age and the live PID and is silent on a fresh stamp; /api/status sets/clears `gateway_heartbeat_stale_s` the same way. --- apps/desktop/src/types/hermes.ts | 3 ++ gateway/run.py | 7 ++++- gateway/status.py | 17 +++++++++-- hermes_cli/gateway.py | 28 +++++++++++-------- hermes_cli/web_routers/status.py | 15 ++++++++-- .../hermes_cli/test_gateway_runtime_health.py | 22 +++++++++++++++ .../test_web_status_watchdog_surfaces.py | 18 ++++++++++++ web/src/components/SidebarStatusStrip.tsx | 5 ++++ web/src/i18n/en.ts | 1 + web/src/i18n/types.ts | 1 + web/src/lib/api.ts | 4 +++ website/docs/user-guide/messaging/index.md | 7 +++++ 12 files changed, 111 insertions(+), 17 deletions(-) diff --git a/apps/desktop/src/types/hermes.ts b/apps/desktop/src/types/hermes.ts index 64b6af0ad0..b79cf331c3 100644 --- a/apps/desktop/src/types/hermes.ts +++ b/apps/desktop/src/types/hermes.ts @@ -1276,6 +1276,9 @@ export interface StatusResponse { env_path: string gateway_exit_reason: string | null gateway_health_url: string | null + /** Seconds since housekeeping last stamped gateway_state.json; set only when the process is alive + * but the stamp is past the freshness TTL (loop/housekeeping wedged). null when healthy. */ + gateway_heartbeat_stale_s?: number | null gateway_pid: number | null gateway_platforms: Record gateway_running: boolean diff --git a/gateway/run.py b/gateway/run.py index 5b57bf8304..2ed27576d8 100644 --- a/gateway/run.py +++ b/gateway/run.py @@ -4597,7 +4597,12 @@ def _start_gateway_housekeeping( so chores run under any ``CronScheduler`` provider (external scale-to-zero has no 60s loop). Cadences are ticks of ``interval``; inner gates own the real cadence.""" from gateway.run_profile_reconcile import _mcp_config_reconciler - chores: list[tuple[int, str, Any]] = [] + chores: list[tuple[int, str, Any]] = [ + # First every tick: re-stamp ``updated_at`` in gateway_state.json so it is a real heartbeat. + # ``hermes gateway status`` / ``/api/status`` warn when it ages past 2x ``interval`` with the + # PID alive — the thread (or a chore blocked on the loop) wedged (#113372). Runs first so a + # wedged chore stops the NEXT stamp instead of a slow one delaying this tick's. + (1, "Runtime heartbeat", _write_runtime_status_quiet)] if adapters is not None or runner is not None: # Restart-safe cron workers run outside the gateway cgroup and queue their final send for # whichever gateway is live; drained here (not the scheduler tick) so external providers get it too. diff --git a/gateway/status.py b/gateway/status.py index 461e955083..fac4715ac7 100644 --- a/gateway/status.py +++ b/gateway/status.py @@ -909,8 +909,10 @@ def read_runtime_status(path: Optional[Path] = None) -> Optional[dict[str, Any]] return _read_json_file(path or _get_runtime_status_path()) -# Max age of a ``gateway_state.json`` snapshot before its liveness claim is suspect: -# an older record outlived an ungracefully-killed writer (taskkill /F, OOM, power loss). +# Max age of a ``gateway_state.json`` snapshot before its liveness claim is suspect: an older record +# outlived an ungracefully-killed writer (taskkill /F, OOM, power loss) — or, with the PID alive, the +# housekeeping thread that re-stamps ``updated_at`` every tick has wedged (#113372). 2x the 60 s +# housekeeping interval. _RUNTIME_STATUS_STALE_TTL_S = 120 @@ -921,6 +923,15 @@ def runtime_status_is_stale( return not isinstance(record, dict) or _marker_is_stale(record.get("updated_at") or "", ttl_s) +def runtime_status_heartbeat_age_s(record: Optional[dict[str, Any]]) -> Optional[int]: + """Whole seconds since the snapshot's ``updated_at``; None when missing/unparseable (an + unparseable stamp is a stale *file*, not a wedged heartbeat).""" + updated_at = normalize_updated_at(record.get("updated_at")) if isinstance(record, dict) else None + if not updated_at: + return None + return max(0, int((datetime.now(timezone.utc) - datetime.fromisoformat(updated_at)).total_seconds())) + + def runtime_status_pid_is_live(record: Optional[dict[str, Any]]) -> bool: """True when the snapshot's PID is alive and passes the start-time PID-reuse guard.""" return _live_pid_from_record(record) is not None @@ -940,7 +951,7 @@ _DRAINABLE_GATEWAY_STATES = frozenset({"running"}) def derive_gateway_busy(*, gateway_running: bool, gateway_state: Any, active_agents: Any) -> bool: """Busy iff live, ``running``, and ``active_agents > 0`` -- the contract NAS gates on. Liveness - keys off ``gateway_running``, NEVER ``updated_at`` (an idle gateway never advances it).""" + keys off ``gateway_running``, NEVER ``updated_at`` (a stale heartbeat is a health warning, not death).""" if not derive_gateway_drainable(gateway_running=gateway_running, gateway_state=gateway_state): return False return parse_active_agents(active_agents) > 0 diff --git a/hermes_cli/gateway.py b/hermes_cli/gateway.py index fd0038ff65..ab30fcc881 100644 --- a/hermes_cli/gateway.py +++ b/hermes_cli/gateway.py @@ -5091,7 +5091,8 @@ _WATCHDOG_EXIT_REASONS = { def _runtime_health_lines() -> list[str]: """Summarize the latest persisted gateway runtime health state.""" try: - from gateway.status import read_runtime_status, runtime_status_is_stale, runtime_status_pid_is_live + from gateway.status import ( + read_runtime_status, runtime_status_heartbeat_age_s, runtime_status_is_stale, runtime_status_pid_is_live) except Exception: return [] @@ -5109,16 +5110,21 @@ def _runtime_health_lines() -> list[str]: # A live-claiming snapshot can outlive an ungracefully killed gateway (taskkill /F, OOM). Past # the freshness TTL with the recorded PID gone, say so instead of rendering stale live state. - if ( - gateway_state in ("running", "starting", "draining") - and runtime_status_is_stale(state) - and not runtime_status_pid_is_live(state) - ): - lines.append( - f"⚠ Stale gateway_state.json: recorded state '{gateway_state}' but the " - "recorded process is gone (likely an ungraceful shutdown)" - ) - return lines + if gateway_state in ("running", "starting", "draining") and runtime_status_is_stale(state): + if not runtime_status_pid_is_live(state): + lines.append( + f"⚠ Stale gateway_state.json: recorded state '{gateway_state}' but the " + "recorded process is gone (likely an ungraceful shutdown)" + ) + return lines + # PID alive but housekeeping stopped re-stamping the file: the reporter's "not a crash" case + # (#113372) — the process looks 'running' while housekeeping/cron/kanban dispatch are frozen. + age = runtime_status_heartbeat_age_s(state) + if gateway_state != "draining" and age is not None: + lines.append( + f"⚠ Gateway heartbeat stale: housekeeping has not refreshed gateway_state.json for {age} s " + f"(event loop or housekeeping wedged; pid {state.get('pid')} alive) — restart the gateway" + ) if gateway_state == "startup_failed" and exit_reason: lines.append(f"⚠ Last startup issue: {exit_reason}") diff --git a/hermes_cli/web_routers/status.py b/hermes_cli/web_routers/status.py index c8d4adc202..c41a9f1c89 100644 --- a/hermes_cli/web_routers/status.py +++ b/hermes_cli/web_routers/status.py @@ -20,7 +20,8 @@ from starlette.concurrency import run_in_threadpool from fastapi import HTTPException, Request from gateway.status import ( derive_gateway_busy, derive_gateway_drainable, normalize_updated_at, parse_active_agents, - profile_platforms_from_multiplexer, resolve_gateway_liveness, retained_gateway_state) + profile_platforms_from_multiplexer, resolve_gateway_liveness, retained_gateway_state, + runtime_status_heartbeat_age_s, runtime_status_is_stale) from hermes_cli import __version__, __release_date__ from hermes_cli.config import get_config_path, get_env_path from hermes_constants import get_process_hermes_home, profile_name_for_home @@ -293,6 +294,7 @@ async def _resolve_gateway_status(profile_dir: Optional[Path], health_url) -> Di gateway_platforms: dict = {} gateway_exit_reason = None gateway_updated_at = None + gateway_heartbeat_stale_s = None if runtime: gateway_state = runtime.get("gateway_state") if not gateway_running: @@ -304,6 +306,11 @@ async def _resolve_gateway_status(profile_dir: Optional[Path], health_url) -> Di # The health probe confirmed the gateway is alive, but the local runtime status # file may be stale (cross-container): override so the badge is correct. gateway_state = "running" + elif gateway_state in {"running", "starting"} and runtime_status_is_stale(runtime): + # Alive PID, but housekeeping stopped re-stamping the heartbeat: the loop or the + # housekeeping thread wedged while the file still says 'running' (#113372). Same arm + # as ``hermes gateway status`` so the sidebar strip and the CLI agree. + gateway_heartbeat_stale_s = runtime_status_heartbeat_age_s(runtime) gateway_platforms = _project_gateway_platforms( runtime.get("platforms") or {}, configured, gateway_running, gateway_state) gateway_exit_reason = None if gateway_state == "stopped" else runtime.get("exit_reason") @@ -323,6 +330,7 @@ async def _resolve_gateway_status(profile_dir: Optional[Path], health_url) -> Di "runtime": runtime, "gateway_running": gateway_running, "gateway_pid": liveness.pid, "gateway_state": gateway_state, "gateway_platforms": gateway_platforms, "gateway_exit_reason": gateway_exit_reason, "gateway_updated_at": gateway_updated_at, + "gateway_heartbeat_stale_s": gateway_heartbeat_stale_s, "gateway_shared_with": [str(p) for p in served] if isinstance(served, list) else None} @@ -457,7 +465,7 @@ async def get_status(profile: Optional[str] = None): # Busy/drainable (NAS lifecycle-safety gate) derive from the persisted in-flight turn # count + liveness via gateway.status. Liveness keys off gateway_running, NEVER - # gateway_updated_at — a healthy idle gateway never advances that. + # gateway_updated_at — a stale heartbeat is reported separately, not treated as death. active_agents = parse_active_agents((gateway["runtime"] or {}).get("active_agents", 0)) # Off-loop: on a cold Windows install the first import of hermes_cli.gateway blocks # 15-30s (.pyc compilation + Defender), exceeding the desktop handshake's 15s timeout. @@ -472,6 +480,9 @@ async def get_status(profile: Optional[str] = None): "gateway_platforms": gateway["gateway_platforms"], "gateway_exit_reason": gateway["gateway_exit_reason"], "gateway_updated_at": gateway["gateway_updated_at"], + # Seconds since housekeeping last stamped the heartbeat, only when the PID is alive but the + # stamp is past the freshness TTL (loop/housekeeping wedged, #113372); else null. + "gateway_heartbeat_stale_s": gateway["gateway_heartbeat_stale_s"], # Non-null only for a profile served by the shared multiplexer: every profile that process carries. "gateway_shared_with": gateway["gateway_shared_with"], "active_agents": active_agents, diff --git a/tests/hermes_cli/test_gateway_runtime_health.py b/tests/hermes_cli/test_gateway_runtime_health.py index bd17528f85..e5f28e842e 100644 --- a/tests/hermes_cli/test_gateway_runtime_health.py +++ b/tests/hermes_cli/test_gateway_runtime_health.py @@ -64,6 +64,28 @@ def test_runtime_health_lines_include_fatal_platform_and_startup_reason(monkeypa assert "⚠ Last startup issue: telegram conflict" in lines +def test_runtime_health_lines_flag_stale_heartbeat_with_live_pid(monkeypatch): + """'running' + updated_at past the TTL + PID ALIVE is the reporter's 'not a crash' case + (#113372): housekeeping stopped stamping the heartbeat while the file still says running. + Render it as a heartbeat warning naming the age and the live PID; a fresh stamp stays silent.""" + from gateway import status as status_mod + + record = {"gateway_state": "running", "pid": 4242, "start_time": 111, + "updated_at": _iso_age(900), "active_agents": 0, "platforms": {}} + monkeypatch.setattr("gateway.status.read_runtime_status", lambda: record) + monkeypatch.setattr(status_mod, "_pid_exists", lambda pid: True) + monkeypatch.setattr(status_mod, "_get_process_start_time", lambda pid: 111) + + stale = [ln for ln in _runtime_health_lines() if ln.startswith("⚠ Gateway heartbeat stale:")] + assert len(stale) == 1, _runtime_health_lines() + assert 900 <= int(stale[0].split(" for ")[1].split(" s")[0]) <= 930 + assert "pid 4242 alive" in stale[0] + assert not _stale_lines(_runtime_health_lines()) # not the dead-PID contradiction line + + record["updated_at"] = _iso_age(5) + assert not [ln for ln in _runtime_health_lines() if "heartbeat" in ln] + + def test_runtime_health_lines_render_watchdog_degraded_exit(monkeypatch): """A watchdog-stamped ``degraded`` + exit_reason renders as a health line; the startup-time ``degraded`` (retryable platforms queued, no exit_reason) stays silent (#113372).""" diff --git a/tests/hermes_cli/test_web_status_watchdog_surfaces.py b/tests/hermes_cli/test_web_status_watchdog_surfaces.py index 62a43e92c4..890d656378 100644 --- a/tests/hermes_cli/test_web_status_watchdog_surfaces.py +++ b/tests/hermes_cli/test_web_status_watchdog_surfaces.py @@ -1,5 +1,7 @@ """``/api/status`` agrees with ``hermes gateway status`` on the two #113372 shapes: +* PID alive but the heartbeat stamp is past the freshness TTL (loop/housekeeping wedged while + ``gateway_state.json`` still says ``running``) -> ``gateway_heartbeat_stale_s`` is set. * A watchdog hard-exited the process (``degraded`` + watchdog ``exit_reason``, PID gone) -> the retained verdict stays ``degraded`` with its ``gateway_exit_reason`` instead of a bare ``stopped``. """ @@ -30,6 +32,21 @@ def client(monkeypatch): return c +def test_status_reports_stale_heartbeat_when_pid_alive(client, monkeypatch): + record = {"gateway_state": "running", "pid": 1234, "start_time": 111.0, + "updated_at": _iso_age(900), "platforms": {}, "active_agents": 0} + monkeypatch.setattr(_gw_status, "get_running_pid_cached", lambda: 1234) + monkeypatch.setattr(_gw_status, "read_runtime_status", lambda: record) + + data = client.get("/api/status").json() + assert data["gateway_running"] is True + assert data["gateway_state"] == "running" + assert 900 <= data["gateway_heartbeat_stale_s"] <= 930 + + record["updated_at"] = _iso_age(5) + assert client.get("/api/status").json()["gateway_heartbeat_stale_s"] is None + + def test_status_keeps_watchdog_degraded_verdict_and_reason_for_dead_pid(client, monkeypatch): record = {"gateway_state": "degraded", "exit_reason": "loop_liveness_watchdog", "pid": 999_999_999, "start_time": 1.0, "updated_at": _iso_age(30), "platforms": {}} @@ -40,6 +57,7 @@ def test_status_keeps_watchdog_degraded_verdict_and_reason_for_dead_pid(client, assert data["gateway_running"] is False assert data["gateway_state"] == "degraded" assert data["gateway_exit_reason"] == "loop_liveness_watchdog" + assert data["gateway_heartbeat_stale_s"] is None # ``hermes gateway stop`` afterwards records the operator's intent: no longer a current failure. record["desired_state"] = "stopped" diff --git a/web/src/components/SidebarStatusStrip.tsx b/web/src/components/SidebarStatusStrip.tsx index bb748437a6..1390d1e526 100644 --- a/web/src/components/SidebarStatusStrip.tsx +++ b/web/src/components/SidebarStatusStrip.tsx @@ -65,6 +65,11 @@ export function gatewayLine( }, stopped: { label: g.stopped, tone: "text-muted-foreground" }, }; + // Alive but housekeeping stopped stamping the heartbeat: 'Running' would be the lie the + // reporter saw (loop/housekeeping wedged while gateway_state.json still said running). + if (status.gateway_heartbeat_stale_s != null) { + return { label: g.heartbeatStale, tone: "text-destructive" }; + } if (status.gateway_state && byState[status.gateway_state]) { return byState[status.gateway_state]; } diff --git a/web/src/i18n/en.ts b/web/src/i18n/en.ts index e406cc4800..159b8f2080 100644 --- a/web/src/i18n/en.ts +++ b/web/src/i18n/en.ts @@ -67,6 +67,7 @@ export const en: Translations = { gatewayStrip: { degraded: "Degraded", failed: "Start failed", + heartbeatStale: "Heartbeat stale", off: "Off", running: "Running", starting: "Starting", diff --git a/web/src/i18n/types.ts b/web/src/i18n/types.ts index b36496b1d2..517c8a0c2d 100644 --- a/web/src/i18n/types.ts +++ b/web/src/i18n/types.ts @@ -86,6 +86,7 @@ export interface Translations { gatewayStrip: { degraded: string; failed: string; + heartbeatStale: string; off: string; running: string; starting: string; diff --git a/web/src/lib/api.ts b/web/src/lib/api.ts index d65aa11d35..3e0a2716f3 100644 --- a/web/src/lib/api.ts +++ b/web/src/lib/api.ts @@ -1927,6 +1927,10 @@ export interface StatusResponse { env_path: string; gateway_exit_reason: string | null; gateway_health_url: string | null; + /** Seconds since the gateway's housekeeping last stamped gateway_state.json, set only when the + * process is alive but the stamp is past the freshness TTL (loop/housekeeping wedged). + * null when healthy; absent on older backends. */ + gateway_heartbeat_stale_s?: number | null; gateway_pid: number | null; gateway_platforms: Record; gateway_running: boolean; diff --git a/website/docs/user-guide/messaging/index.md b/website/docs/user-guide/messaging/index.md index fd73f54838..6daa98cf99 100644 --- a/website/docs/user-guide/messaging/index.md +++ b/website/docs/user-guide/messaging/index.md @@ -199,6 +199,13 @@ gateway process overwrites it, and the dashboard's gateway badge shows **Degraded** with the same reason. Set `gateway.loop_watchdog: false` in `config.yaml` to disable the watchdog. +Housekeeping also re-stamps `gateway_state.json`'s `updated_at` every tick +(60 s), so it doubles as a heartbeat: when the process is still alive but that +stamp is more than 120 s old, `hermes gateway status` prints +`⚠ Gateway heartbeat stale: housekeeping has not refreshed gateway_state.json +for N s …` and the dashboard badge reads **Heartbeat stale** — the "looks +running but nothing is scheduled" case. Restart the gateway. + ### Optional Linux event-loop watchdog A systemd-managed gateway can opt into process recovery when Python's asyncio