fix(gateway): startup-liveness watchdog for pre-event-loop deadlocks (OOF-298)

[shannonsands]

Problem (OOF-298)

A hosted gateway (hermes-doubleam-2568) deadlocked at startup, before the asyncio event loop came alive: all 3 threads parked in futex_wait_queue, zero lines written to gateway.log, /health returning 000 — for ~30 hours.

Two compounding failures:

1. s6 saw a live PID and never respawned it. Service supervisors only restart dead processes; a wedged-but-alive startup sits as a zombie until manual s6-svc -r.
2. Stale gateway_state.json from the previous process told every status surface the gateway was "draining", sending triage down the wrong path (initially suspected a stuck NS-570 drain — the epoch check was actually working correctly).

Every existing liveness backstop assumes startup succeeded:

• the loop-liveness watchdog (Gateway event loop freezes silently — Telegram CLOSE-WAIT socket deadlocks all async tasks #69089) is armed by GatewayRunner._start_loop_liveness_guards — inside the running loop's startup path;
• the shutdown watchdog (Gateway event loop froze during SIGTERM drain — zombie process for 26h (KeepAlive can't detect it) #66892) arms at stop();
• the loop heartbeat file is written by an asyncio task.

None of them can fire when the process wedges before the loop exists.

Fix

New gateway/startup_watchdog.py: a plain daemon OS thread, armed at process entry, disarmed the moment the event loop is confirmed live (the exact point where the existing loop-liveness watchdog takes over — no coverage gap, no overlap).

If startup neither reaches that milestone nor exits within the deadline (default 300s), the watchdog:

1. dumps all-thread stacks via faulthandler (same diagnostic pattern as the loop watchdog),
2. appends a JSON metadata record to logs/gateway-startup-watchdog.log,
3. records the exit in the NS-608 lifecycle ledger (reason=startup_liveness_watchdog) so the next boot classifies it correctly instead of reporting an unclean SIGKILL/OOM death,
4. os._exit(75) (GATEWAY_SERVICE_RESTART_EXIT_CODE) so s6/systemd/launchd revive the process.

Arm/disarm sites

• Arm: gateway.run.main() and hermes_cli.gateway.run_gateway() (the hermes gateway run path hosted instances use) — in both cases after the --replace/conflict guards, so a replace-loser exiting early never arms one.
• Disarm: GatewayRunner right after _start_loop_liveness_guards(loop) — including when the loop guards are config-disabled, since the startup watchdog only covers the pre-loop window.

Deadline rationale

A healthy startup reaches the disarm point in seconds. The slowest legitimate pre-loop work is MCP tool discovery (internally bounded at 120s), so 300s leaves comfortable headroom. Platform adapter connects — which can genuinely take minutes (WhatsApp pairing, npm cold installs) — happen after the disarm point and are never covered.

Config surface

Env-only, deliberately: HERMES_STARTUP_WATCHDOG=0 to disable, HERMES_STARTUP_WATCHDOG_TIMEOUT_S to tune (floor-clamped to 30s). The watchdog must arm before config.yaml is loaded — a wedge during config parsing is exactly in scope — so it cannot depend on config for its own enablement.

Everything is best-effort: a watchdog failure never affects the startup it observes.

Tests

tests/gateway/test_startup_watchdog.py — 29 tests: config resolution (env override/clamp/garbage), arm/disarm idempotency + re-arm, disable knob, fire path with a captured _exit seam (restart exit code, dump record contents, lifecycle-ledger mark_exited call), dump-write failure swallowing.

29 passed (new suite)
38 passed, 3 skipped (test_runner_startup_failures, test_gateway, test_gateway_run_hard_exit)
10 passed, 1 skipped (test_shutdown_watchdog, test_lifecycle_ledger)
ruff clean

Linear

Fixes OOF-298. Related: NS-608 (lifecycle ledger this builds on), OOF-39 (NAS-side stale-health twin, merged).

[shannonsands]

Pushed f09df10c5d addressing all review findings:

P1 — slow-but-legitimate startups (large state.db migrations) could restart-loop. The watchdog now checks process-wide CPU time (time.process_time()) when the deadline expires: continuous CPU consumption = live migration → deadline extended with a warning log per extension. The OOF-298 deadlock class (all threads parked in futex waits) accrues ~zero CPU and still fires on schedule. Documented limitation: a spinning busy-wait deadlock reads as progress — the observed incident class is parked threads.

P1 — import-time deadlocks uncovered. Implementation moved to a stdlib-only top-level module (hermes_startup_watchdog); hermes_cli/main.py arms it via an argv fast-path (gateway + run in argv) before the heavy module-level import graph. gateway/startup_watchdog remains as a re-export shim. Import-lightness is treated as a correctness property (enforced by an AST test): at fire time the wedged main thread may hold the import lock, so the fire path performs no imports on its own thread — the lifecycle-ledger write runs on a bounded-join (5s) helper thread and os._exit happens regardless.

P2 — disarm/fire race. The handle now has an explicit lock-guarded state machine (armed → disarmed | firing); whichever transition takes the lock first wins. Regression test forces the exact interleaving (disarm landing after deadline expiry but before the fire transition) by blocking inside the CPU probe.

P2 — uncovered entry points. cli.py --gateway and scripts/hermes-gateway now arm before importing the gateway graph; hermes_cli/gateway.py::run_gateway() keeps an idempotent backstop arm for programmatic callers.

P2 — respawn-storm backoff. The storm breaker's intentional backoff sleep (~zero CPU, indistinguishable from a parked deadlock) now calls kick_startup_watchdog(extra_s=backoff) before sleeping.

Also: faulthandler stacks are additionally written to logs/gateway-startup-watchdog.log (stderr may be absent on detached runs); the disarm site moved inside the loop-confirmed branch in gateway/run.py; hermes_startup_watchdog added to py-modules; SERVICE_RESTART_EXIT_CODE duplicated in the stdlib-only module with a parity test against gateway.restart.

Tests: 38 passing in tests/gateway/test_startup_watchdog.py; adjacent suites (shutdown watchdog, lifecycle ledger, runner startup failures, CLI gateway, s6 dispatch, status) all green; ruff clean.

[andrexibiza]

Reviewed exact head f09df10c5de9313bbc4b12048777dcd2d8535d52 against the PR's pre-loop liveness contract, all nine changed files, the stdlib-only arm/fire path, the race/progress tests, current hosted checks, the existing author follow-up, and the adjacent gateway-liveness / restart / state-repair work.

The architectural seam is right: a pre-event-loop watchdog must be owned by an OS thread that is armed before the heavy gateway import graph and disarmed exactly when the existing loop-liveness guard becomes authoritative. The follow-up at this head also closes several real holes in the first version: the import-light top-level module, explicit armed -> disarmed | firing state transition, legacy entry-point coverage, and explicit kick around the respawn-storm backoff are all good changes.

I would not merge this head yet. I found two remaining class-level blockers in the proof that a watchdog fire both (a) cannot itself wedge and (b) distinguishes the watched startup from unrelated process activity.

1. The hard-exit path still depends on blocking logging/filesystem work before os._exit

The PR correctly identifies one critical failure mode: at fire time the main thread may be wedged while holding the import lock, so _mark_lifecycle_exit() is moved to a helper thread with a bounded 5s join and the watchdog promises to reach os._exit regardless.

But _fire() still performs several other potentially blocking operations synchronously on the watchdog thread before _exit:

logger.critical(...)
_write_dump_record(...)             # mkdir + open + write + json
faulthandler.dump_traceback(...)
with open(dump_path, "a", ...) as fh:
    faulthandler.dump_traceback(file=fh, ...)
...
self._exit(self.exit_code)

That leaves the same structural hole through different locks/resources. Python logging acquires handler locks; a wedged thread can already own one. The dump path can sit on slow/broken/full storage, and mkdir/open/write have no deadline. Even the exception handlers call logger.debug, so a logging-lock stall is not escapable by the current try/except structure.

For this watchdog, diagnostics are best-effort; respawn is the invariant. Once the state transition to firing wins, there must be an independent bounded path to the hard exit that does not depend on application logging, filesystem completion, or an application-owned lock.

Required fix: either arm a separate hard-exit deadline before attempting diagnostics, or move all diagnostic/log/file work to bounded daemon helpers and keep the firing thread's route to os._exit(75) free of blocking application facilities. A low-level/pre-opened diagnostic fd is preferable to ordinary logging on the critical path. Please add an adversarial witness that holds a logging handler lock (and ideally one that blocks the dump writer) while the deadline fires and proves the exit seam is still reached within a strict bound.

This is the same reason the import work was moved off-thread; the fix needs to close the whole "watchdog depends on the wedged process's locks/I/O" class, not only the import-lock instance.

2. time.process_time() proves process activity, not startup progress

The slow-start protection currently uses process-wide CPU time:

last_cpu = time.process_time()
...
if cpu - last_cpu >= 1.0:
    self._deadline = time.monotonic() + self.timeout_s
    continue

and the extension is unbounded. This can fail in both directions:

• False negative: the startup/main thread can be parked while some unrelated daemon/native thread burns >=1s CPU per 300s window. The watchdog then extends forever even though the owner it is supposed to supervise made zero progress.
• False positive: legitimate pre-loop recovery can be I/O-bound rather than CPU-bound. The state-repair family is already full of large-copy / fsync / near-full-volume cases; a multi-GB forensic backup or scratch-copy phase can spend a long wall-clock interval waiting on storage while accruing little process CPU. That shape can be killed as a "deadlock" despite being the exact slow-recovery class this follow-up is trying to exempt.

The current tests only synthesize +10s of aggregate CPU as "alive" and 0s as "dead"; they do not prove ownership.

Required fix: bind extensions to the startup phase that owns the wait. The strongest shape is an explicit startup progress/lease signal around known bounded-but-long synchronous phases (DB migration/repair/backup), rather than aggregate process CPU. If CPU remains as a fallback signal, it should at least be bounded (extension count / absolute lifetime) and should not be sufficient on its own to prove the startup thread is making progress.

Please add both adversarial directions: (1) main/startup parked + unrelated CPU burner still fires, and (2) an explicitly-owned long I/O-bound startup phase gets a lease/kick and does not fire.

Interlocks / other side of the shape

• #69089 is complementary, not duplicate: it owns the post-loop freeze class. This PR should hand off exactly when the loop guard is authoritative, as the current disarm placement intends.
• #89134 by @sycamoregroupltd is the adjacent steady-state tolerance change: it makes the post-loop watchdog less eager during legitimate reconnect stalls. If both land, preserve the clean ownership handoff rather than letting either watchdog compensate for the other's window.
• #89088 by @jackulau is complementary restart-storm control. #89750 creates a new autonomous exit-75 restart source, so the system-level invariant is still "detect a wedge without creating a restart amplifier." The explicit kick_startup_watchdog() around the existing storm-breaker sleep is correct and should survive composition.
• #89073 by @the3asic, #88425 (salvaging @jirathip-k's #88224 work), and the state-repair line are the important other side of the CPU heuristic: long pre-loop state recovery includes storage-bound phases, not only CPU-heavy schema transforms.
• #78586 remains outside this PR's scope: that report has an event loop object but the scheduled adapter/connect work stops progressing. This PR deliberately disarms once the loop is live; it should not claim to close that post-handoff class.

CI / current-main state

At this exact head, Docker and Nix are green. The main CI workflow concluded failure but GitHub returned zero jobs, so there is no executed exact-head CI matrix to treat as a code failure or as proof. Current main has also advanced materially since this branch's line (Git compare shows 93 main commits beyond the branch merge-base, including gateway/main entry-path changes). Rebase after the fixes and rerun the actual exact-head matrix.

Re-review gate for me: hard-exit path is independently bounded from logging/filesystem/import/application locks; startup-progress evidence is owner/phase-scoped rather than process-CPU-only (with both adversarial witnesses); the #69089/#89134 handoff stays exact; then fresh exact-head CI after rebasing current main.

[egilewski]

too large to review safely

This PR changes 586 production lines before tests and docs. Please split it or add a focused justification if it should stay together.

Signed: GPT-5.6-luna-high in Codex

[shannonsands]

Pushed b6f1f2c242 addressing both class-level blockers from @andrexibiza's review, rebased onto current main (213 commits; clean rebase, all wiring verified intact).

Blocker 1 — hard-exit path could block on logging/FS before os._exit

_fire() now starts an exit-escort daemon thread before any forensics run. The escort is deliberately free of log handlers, filesystem access, module loads, and any lock shared with application code — its only dependencies are a monotonic sleep, an Event check, and the exit seam. If the forensic path (logger.critical, dump record, faulthandler, lifecycle ledger) wedges, the escort hard-exits with the restart code after _FIRE_EXIT_BOUND_S (10s). If forensics complete normally, _fire_done is set and the escort stands down (no double-exit).

Adversarial tests (TestBoundedExit):

• test_exits_even_when_logging_lock_is_held — acquires the logging handler lock before the deadline expires so logger.critical blocks forever; asserts the exit seam is still reached.
• test_exits_even_when_dump_write_hangs — hangs the dump-record write (full/hung disk); same assertion.
• test_escort_stands_down_when_fire_completes — no double-exit on the normal path.
• test_escort_uses_no_logging_or_filesystem — structural guarantee on the escort body.

Blocker 2 — process_time() proves process activity, not startup progress

New authoritative signal: phase-owned progress leases via report_startup_progress(expected_s, phase=...) (stdlib-only, never raises, no-op when unarmed). Long synchronous startup phases declare an honest worst case and renew to prove continued liveness; per-call duration is clamped to _MAX_LEASE_S (15 min) so a buggy caller can't silence the watchdog forever. Wired into the known-slow phases: _init_schema + the version-gated data-migration chain (hermes_state_schema.py) and repair_state_db_schema (hermes_state.py).

CPU progress is demoted to a bounded fallback: extensions capped at _MAX_CPU_EXTENSIONS (3 → 20 min max at the default timeout), after which the watchdog fires regardless. A current lease outranks the cap.

Adversarial tests in both directions (TestProgressLease, TestCpuProgressExtension):

• False-positive arm: zero-CPU I/O-bound phase with a lease survives (test_lease_prevents_firing_with_zero_cpu); expired lease no longer protects (test_expired_lease_no_longer_protects).
• False-negative arm: perpetual unrelated CPU noise gets exactly _MAX_CPU_EXTENSIONS extensions then fires (test_cpu_extensions_are_capped).
• Lease-vs-cap priority, clamping, garbage-input safety, dump-record forensics (lease_count/last_lease_phase now recorded), and wiring contracts on the state.db call sites.

Validation: 52/52 watchdog tests, 69 passed/1 skipped across watchdog + shutdown-watchdog + lifecycle-ledger + runner-startup suites, 237 passed/2 skipped on tests/test_hermes_state.py (touched by the lease wiring), ruff clean — all re-run post-rebase on the exact head.

---

@egilewski on size: the production-line count is dominated by structure earlier review rounds explicitly required — the stdlib-only top-level module (so it can arm before the heavy import graph), the gateway/ re-export shim, and arm/disarm wiring across all five entry points (hermes_cli/main.py argv fast-path, hermes_cli/gateway.py, cli.py --gateway, scripts/hermes-gateway, gateway/run.py disarm). Splitting the escort or the lease mechanism into follow-up PRs would ship an intermediate watchdog with known false-fire (restart-loops on slow migrations) and wedged-fire-path modes — the exact defect classes the last two reviews flagged as blocking. The mechanism is only safe as a unit; I'd rather keep it together. Happy to walk through any specific region.

[shannonsands]

Rebased onto current main (418 commits, 2 conflicts in gateway/run.py — additive: main added process-identity registration, our branch added watchdog arm in the same region; kept both with their own try/except blocks).

Rebased head 5b793fb75c. Validation against current main:

• 52/52 watchdog tests pass
• 17/17 adjacent gateway suites (shutdown_watchdog, lifecycle_ledger, runner_startup_failures) pass
• ruff clean across 4 touched files

CI re-triggering on the new head now.

[shannonsands]

CI slice 9/12 failed on tests/cli/test_cli_force_redraw.py::TestFocusRegainRedraw::test_focus_regain_redraw_is_rate_limited — pre-existing flake, unrelated to this PR:

• Empty diff on test_cli_force_redraw.py vs origin/main — this branch never touches it.
• Root cause: _schedule_focus_regain_redraw gates on now - last < min_interval with last sentinel 0.0 via getattr. time.monotonic() is seconds-since-boot; on a freshly-booted GH Actions VM (monotonic() < 60.0), even the first call early-returns → test sees zero redraws. Intermittent by runner boot time.
• Passes 6/6 locally; previous head's full matrix was green.
• Pushed empty commit 0b1eec1a80 to retrigger CI.

Suggest a follow-up fix in the test (or cli.py): initialize the rate-limit sentinel to a negative sentinel (last = getattr(self, "_last_focus_regain_redraw", -1.0)) so the first call always fires regardless of host boot epoch. Happy to fold that in separately if useful — keeping this PR scoped to the watchdog.

[kshitijk4poor]

Salvaged onto current main via #92316 — the three substantive commits cherry-picked with authorship preserved (rebase merge armed; the two empty CI-retrigger commits were dropped).

Follow-ups on top per house policy (.env is for secrets; config.yaml is the behavioral surface): gateway.startup_watchdog / startup_watchdog_timeout_seconds registered in config defaults and applied to the LIVE handle in run_gateway (the argv fast-path arms before config can load, so bridging env alone left the knobs dead — disarm on disable, disarm+re-arm on a config timeout); and the argv sniff tightened to the adjacent "gateway run" token pair. The phase-owned progress leases and the stdlib-only constraint were both kept exactly as designed. Thanks @shannonsands!