…bservability + reboot-parity proof (#142)
* fix(gateway): auto-surface a self-initiated restart that was drain-interrupted (restart_consumed_interrupted)
A turn whose last act fires safe-restart.py sets _session_initiated_restart, so
on shutdown the F1/F2 cascade-breaker stamps restart_consumed — deliberately
EXCLUDED from _AUTO_RESUME_REASONS to break the restart->resume->restart cascade.
But if that same turn was ALSO still running when the 180s drain timed out
(genuinely interrupted in-flight work), it fell in a seam: the cascade guard
suppressed the auto-wake AND #136 preserve-and-prompt never got to surface it,
so the session stayed silent until the next inbound message (observed live
2026-06-30 20:30 — Apollo's Discord turn preserved but not surfaced).
Fix (restart-only; reboot is unaffected — proven): a new resume_reason
restart_consumed_interrupted, stamped when a self-initiated restart is marked at
the POST-DRAIN-TIMEOUT site (interrupted=True) rather than the pre-drain
speculative site. It IS in _AUTO_RESUME_REASONS (so startup auto-resume
proactively surfaces the interrupted work, surface-and-wait, no tool replay),
but still records the F2 replay-mark, so a genuine restart->resume->restart loop
is still bounded and suspended at threshold within the 300s window.
- _resume_reason_for_shutdown_mark gains interrupted kwarg; _self_initiated
helper also treats an entry already carrying restart_consumed[_interrupted] as
self-initiated.
- Only the post-timeout mark site passes interrupted=True (the pre-drain
speculative mark, which is cleared on graceful finish, stays interrupted=False).
- _resume_reason_phrase maps the new reason to 'a gateway restart'.
Reboot parity (Task C, proof-not-code): a self-initiated REBOOT never sets
_session_initiated_restart (the detector matches literal safe-restart.py, not
safe-reboot.py; reboot-watcher writes no breadcrumb), so it marks shutdown_timeout
(already auto-resumes). Reboot inherits #136/#137 preservation via the shared
SIGTERM spine unchanged.
Tests: 7 cascade unit tests + 1 integration call-site gate (real stop() through
the drain-timeout branch) + 2 reboot-parity tests. The integration test is
MUTATION-PROVEN: flipping the post-timeout site to interrupted=False turns it RED.
Change-detector allow-list test converted to an additive-invariant assertion.
Spec: plans/2026-07-01_restart-reboot-continuity-observability-SPEC.md (pass-3
APPROVE, all RCs folded).
* feat(gateway): PHASE= observability for the shutdown mark + boot-resume decisions
Task B (spec 2026-07-01 restart-reboot-continuity). The gateway shutdown spine
already logs phase TIMINGS ('Shutdown phase: drain done at +Xs', #140's
'Executor drain:', 'Auto-resume skipped') — that existing 'Auto-resume skipped'
line is what let us diagnose the 20:30 seam. This adds the two per-session
DECISION points that were invisible:
- PHASE=shutdown_mark key=... reason=... interrupted=... replay_marked=... marked=...
at _mark_resume_pending_for_shutdown — makes the restart_consumed vs
restart_consumed_interrupted vs shutdown_timeout choice observable per session.
- PHASE=boot_resume_scheduled key=... reason=... platform=...
when a session is proactively resumed at boot (surface-and-wait).
Both use the module logger at INFO (INV-3/D-8: no fsync, no rollover in the hot
path — logging must never eat the 180s drain budget) and carry session key +
flags ONLY, never transcript content (INV-6).
Tests: PHASE-line-emitted, no-content-leak (INV-6), and a slow/blocking-handler
latency gate (D-8 — proves the mark path doesn't fan out or block). Watcher-side
PHASE= markers (safe-restart watcher.py, safe-reboot reboot-watcher.py) ship in
the skills tree.
* fix(gateway): address Opus code-review — real INV-6/INV-3 gates, no overclaim
Opus code-review BLOCKed the first cut: two invariant tests passed vacuously.
Fixed both to be genuine gates, plus the required-changes:
- INV-6 (no transcript content): the test was a TAUTOLOGY — it declared a SECRET
marker but never seeded it where the PHASE logger could reach it, so the
assertion was true by construction. Now seeds the sentinel into the transcript
(append_to_transcript), _pending_messages, and the running-agent object, then
asserts it never appears in any PHASE= line. MUTATION-PROVEN: adding msg=%s to
the log line turns it RED.
- INV-3 (fail-open / non-blocking): the old test over-claimed 'non-blocking' with
a bound its own docstring admitted didn't prove it. Replaced with an honest
single-emit + FAIL-OPEN gate, and made the CODE genuinely fail-open (both PHASE
logs wrapped in try/except so a raising/broken sink can't abort the resume-mark
— losing the mark = losing the interrupted work). Dropped the overclaiming code
comment (handler blocking is a gateway-logging-config concern, not this site's).
- RC#3: added a direct reason-UPGRADE test (mark clean restart_consumed → mark
interrupted → upgraded to restart_consumed_interrupted) so the overwrite can't
silently regress if mark_resume_pending ever gains idempotency.
- Residual #31 (reason drift): added a test proving a self-restart reason does NOT
leak into a later unrelated shutdown (clear_resume_pending nulls resume_reason +
the post-turn gate pops _session_initiated_restart → back to shutdown_timeout).
- Test hygiene: the logger-level test now restores the prior level in finally.
- Maintainability: promoted the 4-site magic literal to a named module constant
_REASON_RESTART_CONSUMED_INTERRUPTED.
199 passed / 1 skipped.
* fix(gateway): code-review-2 follow-ups — WARNING-level audit breadcrumb + restart_consumed constant
Code-review pass-2 = APPROVE WITH CHANGES (0 blockers; both prior fake-gate
BLOCKERs certified genuinely resolved). Two non-blocking RCs landed:
- (SRE) PHASE breadcrumbs were logger.info → lost when a deployment runs
gateway.run at WARNING+, exactly while diagnosing a bad restart. Made the mark
log LEVEL-AWARE: an INTERRUPTED or replay-marked mark (the diagnostic case) and
the boot_resume_scheduled breadcrumb now log at WARNING (survive a raised
threshold, matching the sibling drain-timeout warning); a routine clean mark
stays INFO so normal shutdowns don't spam WARNING.
- (Maintainability) promoted the clean-sibling literal 'restart_consumed' to a
named constant _REASON_RESTART_CONSUMED alongside its twin
_REASON_RESTART_CONSUMED_INTERRUPTED, so the cascade-guard pair moves together.
Residual #31 (reason drift) verified against the PRODUCTION path:
_apply_post_turn_resume_gate (called post-turn at the run loop) pops
_session_initiated_restart AND calls clear_resume_pending (nulls resume_reason) —
so the drift the test proves absent cannot ship.
Tests: WARNING-level-survives + clean-stays-INFO + caplog-propagation-pin.
209 passed / 1 skipped.
---------
Co-authored-by: Apollo <apollo@ang.ventures>
Symptom
Restarting the gateway occasionally left it "down but not exited" for ~2.5 minutes (measured: a 149s blackout on one restart), during which launchd/systemd could not relaunch it — the old process was still alive, so the supervisor wouldn't spawn a new one. Most restarts are sub-second; this is intermittent.
Root cause (measured, not theorized)
From
gateway-exit-diag.logfor the slow restart:asyncio.run.returnedat T+0 — async teardown done in ~6s (adapters disconnected, SessionDB closed, sessions persisted)atexit.hookat T+149s — the interpreter hung for 2.5 min after the loop returnedThe gateway runs each agent turn on a
ThreadPoolExecutor(gateway/run.py). In CPython, those workers aredaemon=False, andconcurrent.futuresregisters anatexithook that joins every worker thread before the interpreter can exit. If an agent turn was still executing in a worker at SIGTERM, the process blocked at interpreter finalization until that in-flight turn completed. Verified empirically on 3.11.15:ThreadPoolExecutorworkerdaemon=False,concurrent.futures.thread._python_exitatexit-join present.Across 185 recorded shutdowns the hang fired once (149s); every other exit was sub-second — it needs a worker mid-blocking-call at the SIGTERM instant.
gateway/run.py::main()already force-exits for exactly this reason (_exit_after_graceful_shutdown), but production runs viahermes_cli/gateway.py::run_gateway(), which lacked the backstop.Fix
Apply the same graceful-teardown-then-hard-exit pattern to the production path, plus diagnostics.
hermes_cli/gateway.py:run_gateway()force-exits via a new_force_process_exit()at both the clean (0) and failure (1) tails, afterstart_gateway()'s graceful teardown. Nothing of value is lost — the graceful work already ran; we hard-exit the husk. The helper flushes stdio and logs any lingering non-daemon threads (greppableforce-exit: lingering non-daemon ...) so the next stall is diagnosable at a glance. Wrapped in a helper so tests neutralizeos._exit.gateway/run.py:_shutdown_executor()now does a bounded drain (_executor_drain_timeout(), default 8s,HERMES_GATEWAY_EXECUTOR_DRAIN_TIMEOUToverride) and logs in-flight worker count + drain time (Executor drain: N worker(s) in-flight ... drained in Xs/clean in Xs). A wedged worker no longer blocks here; the CLI backstop finalizes it.Tests (RED→GREEN verified)
test_run_gateway_force_exits_zero_after_clean_shutdown/..._exits_nonzero_when_start_gateway_reports_failure— force-exit fires with the right code (fail on old fall-through/sys.exit).test_force_process_exit_calls_os_exit_and_flushes— flushes stdio, callsos._exit(code).test_shutdown_executor_bounded_by_drain_timeout—_shutdown_executorreturns within budget even when a worker blocks 5s (RED-proven: unbounded variant blocks 4.97s and fails).Existing
run_gateway()end-to-end tests updated to neutralize the new force-exit (shared_install_fake_gateway_runhelper stubs_force_process_exit), mirroring the existingtests/gateway/test_gateway_process_exit.pypattern formain().