From d60e6c0abe68c12a8c5422a6e7900432b1b02a62 Mon Sep 17 00:00:00 2001 From: Emi Griffith Date: Fri, 24 Jul 2026 20:52:41 -0700 Subject: [PATCH] web/worker: add a process-level liveness heartbeat ProdWebContainerSilent and ProdWorkerContainerSilent alert on Docker container-stdout volume, which isn't a valid liveness signal for either role: web's real access logging lives in the file-tailed app-json source, not stdout, and worker's stdout is unconditionally dropped by Alloy's own relabel rule. Both fired for hours against a healthy prod. Give web and worker a real audit.log_heartbeat() beat, same pattern the subscription notifier already uses, tagged daemon=ROLE and unguarded across every uvicorn worker/replica (a beat is a single local file append, nothing like the notifier's leader-election cost). Observability alert rules to consume this land separately. --- backend/docker-compose.test.yml | 1 + backend/tests/conftest.py | 1 + backend/tests/web/test_heartbeat.py | 91 +++++++++++++++++++++++++++++ backend/web/app.py | 35 +++++++++++ 4 files changed, 128 insertions(+) create mode 100644 backend/tests/web/test_heartbeat.py diff --git a/backend/docker-compose.test.yml b/backend/docker-compose.test.yml index d110466..2b1addb 100644 --- a/backend/docker-compose.test.yml +++ b/backend/docker-compose.test.yml @@ -33,6 +33,7 @@ services: THERMOGRAPH_FRONTEND_BASE_INTERNAL: http://127.0.0.1:1 THERMOGRAPH_BASE: "/" THERMOGRAPH_ENABLE_NOTIFIER: "0" + THERMOGRAPH_ENABLE_HEARTBEAT: "0" PORT: "8137" WORKERS: "1" ports: diff --git a/backend/tests/conftest.py b/backend/tests/conftest.py index fb76f4f..f4f92fb 100644 --- a/backend/tests/conftest.py +++ b/backend/tests/conftest.py @@ -28,6 +28,7 @@ _TMP = tempfile.mkdtemp(prefix="thermograph-tests-") # start the background notifier thread during tests. Set before db is imported. os.environ.setdefault("THERMOGRAPH_ACCOUNTS_DB", os.path.join(_TMP, "accounts.sqlite")) os.environ.setdefault("THERMOGRAPH_ENABLE_NOTIFIER", "0") +os.environ.setdefault("THERMOGRAPH_ENABLE_HEARTBEAT", "0") # web/app.py (repo-split Stage 4) fails loud at import if this is unset -- tests # never actually hit a frontend-owned path through the live proxy (that's # frontend_ssr/tests' job), so an unreachable placeholder is fine here. diff --git a/backend/tests/web/test_heartbeat.py b/backend/tests/web/test_heartbeat.py new file mode 100644 index 0000000..d65bd19 --- /dev/null +++ b/backend/tests/web/test_heartbeat.py @@ -0,0 +1,91 @@ +"""Process-level liveness heartbeat for web/worker (app.py _heartbeat_loop / +_start_heartbeat) — the fix for ProdWebContainerSilent / ProdWorkerContainerSilent +false-firing on container-stdout silence that isn't a real liveness signal for +either role.""" +import json +import time + +import pytest +from fastapi.testclient import TestClient + +from core import audit +from web import app as appmod + + +@pytest.fixture(autouse=True) +def _reset_heartbeat_thread(): + # _HEARTBEAT_THREAD is a module-level singleton guard (mirrors notify.py's own + # _STOP/_THREAD pattern) -- reset it around every test so one test starting the + # thread doesn't leave _start_heartbeat() a no-op for the next. + appmod._HEARTBEAT_STOP.clear() + appmod._HEARTBEAT_THREAD = None + yield + appmod._HEARTBEAT_STOP.set() + appmod._HEARTBEAT_THREAD = None + + +@pytest.mark.parametrize("role", ["web", "worker", "all"]) +def test_heartbeat_loop_tags_the_beat_with_role(monkeypatch, role): + monkeypatch.setattr(appmod, "ROLE", role) + calls = [] + monkeypatch.setattr(audit, "log_heartbeat", lambda daemon, interval_s: calls.append((daemon, interval_s))) + monkeypatch.setattr(appmod.metrics, "record_heartbeat", lambda daemon, interval_s: None) + + # Setting the stop event first means .wait() returns True immediately, so the + # loop beats exactly once (the pre-loop beat) and exits without blocking. + appmod._HEARTBEAT_STOP.set() + appmod._heartbeat_loop() + + assert calls == [(role, appmod.HEARTBEAT_INTERVAL)] + + +def test_start_heartbeat_respects_the_disable_flag(monkeypatch): + monkeypatch.setenv("THERMOGRAPH_ENABLE_HEARTBEAT", "0") + started = [] + monkeypatch.setattr(appmod.threading, "Thread", lambda **kw: started.append(kw)) + + appmod._start_heartbeat() + + assert appmod._HEARTBEAT_THREAD is None + assert started == [] + + +def test_start_heartbeat_is_idempotent(monkeypatch): + monkeypatch.delenv("THERMOGRAPH_ENABLE_HEARTBEAT", raising=False) + starts = [] + + class _FakeThread: + def __init__(self, **kw): + starts.append(kw) + + def start(self): + pass + + monkeypatch.setattr(appmod.threading, "Thread", _FakeThread) + + appmod._start_heartbeat() + appmod._start_heartbeat() + + # A second call is a no-op once a thread handle already exists -- mirrors + # notify.start()'s own idempotency, so a double-entry into the lifespan + # (or a stray manual call) can't spawn a second beat loop. + assert len(starts) == 1 + + +def test_app_boot_emits_a_heartbeat_within_one_interval(monkeypatch, tmp_path): + monkeypatch.setattr(appmod, "ROLE", "web") + monkeypatch.setattr(appmod, "HEARTBEAT_INTERVAL", 0.01) + monkeypatch.setattr(audit, "HEARTBEAT_DIR", str(tmp_path)) + monkeypatch.delenv("THERMOGRAPH_ENABLE_HEARTBEAT", raising=False) + + with TestClient(appmod.app): + # The pre-loop beat fires synchronously on thread start; a short sleep is + # just slack for the thread to actually get scheduled. The loop itself + # keeps running on HEARTBEAT_INTERVAL until lifespan shutdown sets the + # stop event, so there's nothing to join here. + time.sleep(0.2) + + files = list(tmp_path.glob("heartbeat-*.jsonl")) + assert files, "expected a heartbeat-*.jsonl file to be written during app lifespan" + lines = [json.loads(line) for line in files[0].read_text().splitlines() if line] + assert any(rec["daemon"] == "web" and rec["tag"] == "heartbeat" for rec in lines) diff --git a/backend/web/app.py b/backend/web/app.py index 5949033..cbec4ae 100644 --- a/backend/web/app.py +++ b/backend/web/app.py @@ -154,6 +154,39 @@ def _should_run_notifier() -> bool: return ROLE in ("worker", "all") and singleton.claim_leader() +_HEARTBEAT_STOP = threading.Event() +_HEARTBEAT_THREAD: threading.Thread | None = None +HEARTBEAT_INTERVAL = float(os.environ.get("THERMOGRAPH_HEARTBEAT_INTERVAL", "300")) # 5 min + + +def _heartbeat_loop() -> None: + metrics.record_heartbeat(ROLE, HEARTBEAT_INTERVAL) + audit.log_heartbeat(ROLE, HEARTBEAT_INTERVAL) + while not _HEARTBEAT_STOP.wait(HEARTBEAT_INTERVAL): + metrics.record_heartbeat(ROLE, HEARTBEAT_INTERVAL) + audit.log_heartbeat(ROLE, HEARTBEAT_INTERVAL) + + +def _start_heartbeat() -> None: + """Process-level liveness beat, tagged daemon=ROLE, independent of whether this + process also runs the notifier. web's and worker's own stdout is near-silent by + design (real logging goes to the app-json file source; worker's Docker/stdout + stream is dropped entirely by Alloy), so container-log-silence alerting can't + tell a live process from a dead one for either role — this heartbeat is the + signal observability actually alerts on instead. Deliberately unguarded across + every uvicorn worker process and every autoscaled replica: a beat is a single + local file append (no upstream quota, no DB, no lock), so duplicate beats are + harmless, and only the process actually being dead stops them — see + _should_run_notifier's leader election for the contrasting case where + duplication would be a real cost.""" + global _HEARTBEAT_THREAD + if os.environ.get("THERMOGRAPH_ENABLE_HEARTBEAT", "1") == "0" or _HEARTBEAT_THREAD is not None: + return + _HEARTBEAT_STOP.clear() + _HEARTBEAT_THREAD = threading.Thread(target=_heartbeat_loop, name=f"heartbeat-{ROLE}", daemon=True) + _HEARTBEAT_THREAD.start() + + @contextlib.asynccontextmanager async def _lifespan(app): # Warm the local place-name index (/suggest's typo tolerance) in the @@ -167,6 +200,7 @@ async def _lifespan(app): await db.create_db_and_tables() places.start_loading() threading.Thread(target=_neighbor_warmer, name="neighbor-warmer", daemon=True).start() + _start_heartbeat() # Background subscription evaluator. Its periodic sweep fetches upstream on a timer # (not per request), so with multiple workers — or multiple *hosts* under Swarm — # it must run in exactly one: elect a leader (see singleton.claim_leader, which @@ -189,6 +223,7 @@ async def _lifespan(app): yield audit.log_activity("app.stop", {"role": ROLE, "pid": os.getpid()}) notify.stop() + _HEARTBEAT_STOP.set() await _frontend_client.aclose()