[eric] system: out-of-loop OS-thread watchdog hard-exits a provably frozen event loop with stack forensics so Electron respawns a working backend (hermes #66892 lift)

backend/apps/health/health.py

@@ -7,7 +7,17 @@ from fastapi import status, HTTPException
 
 @asynccontextmanager
 async def health_lifespan():
-    yield
+    # Out-of-loop liveness backstop (hermes #66892 lift): every other watchdog here is an asyncio
+    # task that a wedged loop can never run; this one is a plain OS thread that hard-exits a
+    # provably frozen backend so Electron's respawn produces a working process. Fails open.
+    import asyncio
+    from backend.apps.system.loop_liveness_watchdog import start_loop_liveness_watchdog
+    p_stop = start_loop_liveness_watchdog(asyncio.get_running_loop())
+    try:
+        yield
+    finally:
+        if p_stop is not None:
+            p_stop.set()
 
 health = SubApp("health", health_lifespan)
 

backend/apps/system/loop_liveness_watchdog.py

@@ -0,0 +1,106 @@
+"""Out-of-loop event-loop liveness watchdog (lifted from hermes-agent
+gateway/shutdown_watchdog.py::start_loop_liveness_watchdog, MIT; their incident #66892: the
+asyncio loop froze and every recovery path needed that same frozen loop, so a wedged-but-alive
+gateway sat as a zombie forever, because supervisors only restart DEAD processes).
+
+Our three watchdog layers (sidecar heartbeat, delegation backstop, wedge unwedger) are all
+asyncio tasks INSIDE the backend loop; if that loop wedges, none of them can fire, and Electron's
+respawn only triggers on process exit. This plain OS thread probes the loop with
+call_soon_threadsafe; three consecutive unanswered probes means the loop is provably frozen, so
+it dumps every thread's stack to a forensics file and hard-exits with the restart code Electron's
+supervisor already backs off on.
+
+Hermes's own rules kept: the watchdog never shares a fate with the loop it watches (daemon OS
+thread), every failure inside the watchdog fails OPEN (returns, never kills), and generous
+strikes so a slow-but-alive loop (sync httpx on the loop is a known 2s block here) never dies."""
+
+import asyncio
+import faulthandler
+import logging
+import os
+import threading
+import time
+from typing import Optional
+
+from typeguard import typechecked
+
+from backend.config.paths import DATA_ROOT
+
+logger = logging.getLogger(__name__)
+
+PROBE_INTERVAL_S = 30.0
+PROBE_TIMEOUT_S = 10.0
+MAX_STRIKES = 3
+# 75 = EX_TEMPFAIL, hermes's "restart me" exit language; Electron respawns any non-zero exit.
+RESTART_EXIT_CODE = 75
+DUMP_PATH = os.path.join(DATA_ROOT, "loop-watchdog-dump.log")
+
+
+@typechecked
+def p_dump_and_exit(strikes: int) -> None:
+    try:
+        logger.critical(f"backend event loop missed {strikes} consecutive liveness probes; dumping stacks and exiting {RESTART_EXIT_CODE} so Electron respawns a working process")
+    except Exception:
+        pass
+    try:
+        with open(DUMP_PATH, "a", encoding="utf-8") as fh:
+            fh.write(f"\n=== loop watchdog fired pid={os.getpid()} t={time.time():.0f} strikes={strikes} ===\n")
+            fh.flush()
+            faulthandler.dump_traceback(file=fh, all_threads=True)
+            fh.write("=== end dump ===\n")
+    except Exception:
+        pass
+    try:
+        faulthandler.dump_traceback(all_threads=True)
+    except Exception:
+        pass
+    os._exit(RESTART_EXIT_CODE)
+
+
+@typechecked
+def start_loop_liveness_watchdog(loop: "asyncio.AbstractEventLoop") -> Optional[threading.Event]:
+    """Arm the watchdog against `loop`. Returns the stop event, or None when arming failed
+    (fail open: a backend without a watchdog beats a backend killed by a broken one)."""
+    stop_event = threading.Event()
+
+    def p_wait_for_probe(probe: threading.Event) -> Optional[bool]:
+        deadline = time.monotonic() + PROBE_TIMEOUT_S
+        while True:
+            if stop_event.is_set():
+                return None
+            remaining = deadline - time.monotonic()
+            if remaining <= 0:
+                return probe.is_set()
+            if probe.wait(timeout=min(remaining, 0.05)):
+                return True
+
+    def p_watchdog() -> None:
+        strikes = 0
+        while not stop_event.wait(timeout=PROBE_INTERVAL_S):
+            probe = threading.Event()
+            try:
+                loop.call_soon_threadsafe(probe.set)
+            except RuntimeError:
+                # A closed loop is a normally exiting process; no backstop needed.
+                return
+            except Exception:
+                logger.debug("loop liveness probe scheduling failed", exc_info=True)
+                return
+            responded = p_wait_for_probe(probe)
+            if responded is None:
+                return
+            if responded:
+                strikes = 0
+                continue
+            strikes += 1
+            logger.warning(f"backend event loop missed liveness probe ({strikes}/{MAX_STRIKES})")
+            if strikes >= MAX_STRIKES and not stop_event.is_set():
+                p_dump_and_exit(strikes)
+                return
+
+    try:
+        threading.Thread(target=p_watchdog, daemon=True, name="loop-liveness-watchdog").start()
+    except Exception:
+        logger.debug("failed to start loop liveness watchdog", exc_info=True)
+        return None
+    return stop_event

backend/tests/test_loop_liveness_watchdog.py

@@ -0,0 +1,87 @@
+"""Pins the out-of-loop watchdog (hermes #66892 lift): a frozen loop is detected and killed with
+forensics; a healthy or merely-slow loop is never touched; arming failures fail open."""
+
+import subprocess
+import sys
+import textwrap
+
+from backend.apps.system import loop_liveness_watchdog as w
+
+
+def p_run_child(code: str, timeout: int = 60) -> subprocess.CompletedProcess:
+    return subprocess.run([sys.executable, "-c", textwrap.dedent(code)], capture_output=True, text=True, timeout=timeout)
+
+
+P_PRELUDE = """
+import asyncio, sys, time
+sys.path.insert(0, ".")
+from backend.apps.system import loop_liveness_watchdog as w
+w.PROBE_INTERVAL_S = 0.3
+w.PROBE_TIMEOUT_S = 0.3
+w.DUMP_PATH = "/tmp/loop_watchdog_test_dump.log"
+"""
+
+
+def test_wedged_loop_is_killed_with_forensics(tmp_path):
+    code = P_PRELUDE + """
+async def main():
+    loop = asyncio.get_running_loop()
+    assert w.start_loop_liveness_watchdog(loop) is not None
+    time.sleep(30)  # wedge the loop with a sync sleep: probes can never run
+
+asyncio.run(main())
+print("SURVIVED")
+"""
+    r = p_run_child(code)
+    assert r.returncode == w.RESTART_EXIT_CODE, f"expected exit {w.RESTART_EXIT_CODE}, got {r.returncode}: {r.stderr[:300]}"
+    assert "SURVIVED" not in r.stdout
+    dump = open("/tmp/loop_watchdog_test_dump.log").read()
+    assert "loop watchdog fired" in dump
+    assert "Thread" in dump, "faulthandler stack dump missing"
+
+
+def test_healthy_loop_never_killed():
+    code = P_PRELUDE + """
+async def main():
+    loop = asyncio.get_running_loop()
+    stop = w.start_loop_liveness_watchdog(loop)
+    await asyncio.sleep(2.5)  # many probe intervals, loop responsive throughout
+    stop.set()
+
+asyncio.run(main())
+print("SURVIVED")
+"""
+    r = p_run_child(code)
+    assert r.returncode == 0 and "SURVIVED" in r.stdout
+
+
+def test_slow_but_alive_loop_survives_single_strikes():
+    """Blocks shorter than MAX_STRIKES consecutive misses must never kill (sync httpx on the loop is a known 2s block)."""
+    code = P_PRELUDE + """
+async def main():
+    loop = asyncio.get_running_loop()
+    stop = w.start_loop_liveness_watchdog(loop)
+    for _ in range(3):
+        time.sleep(0.5)   # one missed probe worth of block
+        await asyncio.sleep(0.7)  # then responsive again: strikes reset
+    stop.set()
+
+asyncio.run(main())
+print("SURVIVED")
+"""
+    r = p_run_child(code)
+    assert r.returncode == 0 and "SURVIVED" in r.stdout
+
+
+def test_closed_loop_ends_watchdog_quietly():
+    code = P_PRELUDE + """
+async def main():
+    loop = asyncio.get_running_loop()
+    w.start_loop_liveness_watchdog(loop)
+
+asyncio.run(main())
+time.sleep(1.2)  # loop closed; watchdog must not fire on a normally exiting process
+print("SURVIVED")
+"""
+    r = p_run_child(code)
+    assert r.returncode == 0 and "SURVIVED" in r.stdout