fix(gateway): never print ✓ for a Windows gateway that dies after the liveness poll

The 6s post-spawn liveness poll (#86687) returned on the FIRST
process-table hit, so a gateway created and then killed moments later —
e.g. by the parent shell's Job Object teardown when
CREATE_BREAKAWAY_FROM_JOB is denied — still earned a "✓ Gateway started"
line (#91675 hole a). And no poll can ever observe a death that happens
AFTER the CLI process exits, which is exactly when the Job Object
teardown fires.

Two layers:

1. _wait_for_gateway_ready now treats the first hit as provisional: the
   gateway must stay visible through a 2s confirmation window
   (_confirm_gateway_stable) before it is reported ready; a death during
   confirmation resumes polling until the deadline. Failure output is an
   honest ✗ with the Job Object explanation and the schtasks /Run
   recovery command when a Scheduled Task exists.
2. Start attestation (report-async-death): every ✓ persists
   state/gateway.start-attestation.json with the vouched-for PIDs. The
   next `gateway start`/`gateway status` invocation checks it — if the
   attested PIDs are gone with no clean-exit record in the lifecycle
   ledger, the CLI reports (once) that the previous ✓ was false and
   prints the schtasks recovery hint. `gateway stop` and a clean
   lifecycle-ledger exit clear the marker silently.

Also: when _spawn_detached had to retry without
CREATE_BREAKAWAY_FROM_JOB, the ✓ now carries an explicit "could not
break away from this shell's Job Object" warning, and the post-update
cold-start ✓ (update_cmd) writes the same attestation marker.

Sub-symptom (b) of #91675 (post-update cold-start only resumes the
active profile) is handled separately by PR #99685.

Fixes #91675
This commit is contained in:
Teknium
2026-09-01 09:58:10 -07:00
parent e5e71d8c46
commit e9541d213f
3 changed files with 441 additions and 7 deletions
+241 -7
View File
@@ -59,6 +59,12 @@ _FALLBACK_PATTERNS = re.compile(
)
_ACCESS_DENIED_PATTERN = re.compile(r"(access is denied|acceso denegado)", re.IGNORECASE)
# Set by _spawn_detached() when the breakaway spawn failed and it had to
# retry WITHOUT CREATE_BREAKAWAY_FROM_JOB — meaning the child stays inside
# the parent's Job Object and may be killed when this shell exits (#91675).
# Dict (not bare bool) so the flag is mutable without ``global``.
_LAST_SPAWN_BREAKAWAY_FALLBACK: dict = {"fallback": False}
_TASK_NAME_DEFAULT = "Hermes_Gateway"
_TASK_DESCRIPTION = "Hermes Agent Gateway - Messaging Platform Integration"
_TASK_LOGON_DELAY = "PT30S"
@@ -957,6 +963,7 @@ def _spawn_detached(script_path: Path | None = None) -> int:
stdout=log_fh,
stderr=log_fh,
)
_LAST_SPAWN_BREAKAWAY_FALLBACK["fallback"] = False
except OSError as exc:
# CREATE_BREAKAWAY_FROM_JOB can fail with "access denied" when the
# parent's job object doesn't permit breakaway (some Windows
@@ -984,6 +991,7 @@ def _spawn_detached(script_path: Path | None = None) -> int:
stdout=log_fh,
stderr=log_fh,
)
_LAST_SPAWN_BREAKAWAY_FALLBACK["fallback"] = True
return proc.pid
@@ -1178,33 +1186,249 @@ def install(
raise RuntimeError(f"Windows gateway install failed: {detail}")
def _wait_for_gateway_ready(timeout_s: float = 6.0, interval_s: float = 0.4) -> list[int]:
def _confirm_gateway_stable(
initial_pids: list[int], confirm_s: float, interval_s: float
) -> list[int]:
"""Re-check a freshly detected gateway for ``confirm_s`` seconds.
A single process-table hit only proves the child was *created*, not that
it survived startup — a gateway that crashes moments after spawn (or is
reaped by the parent shell's Job Object, #91675/#84185) passes a
first-hit poll and then dies. Require the gateway to stay visible for
the whole confirmation window before we vouch for it. Returns the last
observed PID list, or ``[]`` if the gateway vanished mid-window.
"""
if confirm_s <= 0:
return initial_pids
from hermes_cli.gateway import find_gateway_pids
pids = initial_pids
confirm_deadline = time.monotonic() + confirm_s
while time.monotonic() < confirm_deadline:
time.sleep(interval_s)
pids = list(find_gateway_pids())
if not pids:
return []
return pids
def _wait_for_gateway_ready(
timeout_s: float = 6.0,
interval_s: float = 0.4,
confirm_s: float = 2.0,
) -> list[int]:
"""Poll for a live gateway process for up to ``timeout_s`` seconds.
Returns the list of PIDs found. Empty list means nothing came up in
time — the caller should surface that to the user as a failed start.
A first process-table hit is treated as *provisional*: the gateway must
then stay visible for ``confirm_s`` more seconds before we report it
ready (see :func:`_confirm_gateway_stable` — a child that dies right
after spawn must not earn a ✓, #91675). If it vanishes during the
confirmation window, polling resumes until the deadline.
Returns the list of PIDs found. Empty list means nothing (stable) came
up in time — the caller should surface that to the user as a failed
start.
"""
from hermes_cli.gateway import find_gateway_pids
deadline = time.time() + timeout_s
while time.time() < deadline:
deadline = time.monotonic() + timeout_s
while time.monotonic() < deadline:
pids = list(find_gateway_pids())
if pids:
return pids
confirmed = _confirm_gateway_stable(pids, confirm_s, interval_s)
if confirmed:
return confirmed
continue # died during confirmation — keep polling until deadline
time.sleep(interval_s)
return []
# ---------------------------------------------------------------------------
# Start attestation — honest reporting for deaths AFTER the liveness poll
# ---------------------------------------------------------------------------
#
# The liveness poll (even with the confirmation window above) cannot observe
# a death that happens after this CLI process exits — the exact #91675
# failure mode, where the parent shell's Job Object tears the gateway down
# on CLI exit. So every ✓ persists a small attestation marker recording
# which PIDs we vouched for. The NEXT gateway CLI invocation checks the
# marker: if those PIDs are gone and the lifecycle ledger shows no clean
# exit for them, the earlier ✓ was a lie and we say so — once — with the
# schtasks recovery hint.
_START_ATTESTATION_RELATIVE = ("state", "gateway.start-attestation.json")
def _start_attestation_path() -> Path:
from hermes_cli.config import get_hermes_home
return Path(get_hermes_home()).joinpath(*_START_ATTESTATION_RELATIVE)
def _write_start_attestation(pids: list[int], via: str) -> None:
"""Persist the PIDs a ✓ vouched for. Best-effort, never raises."""
import json as _json
from datetime import datetime, timezone
try:
path = _start_attestation_path()
path.parent.mkdir(parents=True, exist_ok=True)
payload = {
"pids": [int(p) for p in pids],
"via": via,
"ts": datetime.now(timezone.utc).isoformat(),
}
tmp = path.with_suffix(".json.tmp")
tmp.write_text(_json.dumps(payload), encoding="utf-8")
tmp.replace(path)
except Exception:
logger.debug("Failed to write gateway start attestation", exc_info=True)
def _clear_start_attestation() -> None:
try:
_start_attestation_path().unlink(missing_ok=True)
except OSError:
pass
def _attested_pid_exited_cleanly(pid: int) -> bool:
"""True when the lifecycle ledger shows a clean exit for ``pid``."""
import json as _json
try:
from gateway.lifecycle_ledger import get_lifecycle_sentinel_path
from hermes_cli.config import get_hermes_home
sentinel_path = get_lifecycle_sentinel_path(Path(get_hermes_home()))
data = _json.loads(sentinel_path.read_text(encoding="utf-8"))
except Exception:
return False
return (
isinstance(data, dict)
and data.get("phase") == "exited"
and data.get("pid") == pid
)
def check_start_attestation(current_pids: list[int] | None = None) -> str | None:
"""Surface (once) a gateway that died after a ✓ was printed for it.
Reads the attestation marker left by the last successful-looking start.
Outcomes:
* gateway currently running → the start held (or the service healed it);
clear the marker silently.
* attested PIDs all gone, lifecycle ledger shows a clean exit for one of
them → planned stop; clear silently.
* attested PIDs all gone with NO clean-exit record → the previous ✓ was
false (#91675: parent Job Object teardown killed the child after the
poll). Return a warning string and consume the marker so it prints
exactly once.
Never raises.
"""
import json as _json
try:
path = _start_attestation_path()
data = _json.loads(path.read_text(encoding="utf-8"))
except (OSError, ValueError):
return None
if not isinstance(data, dict):
_clear_start_attestation()
return None
attested = [p for p in data.get("pids", []) if isinstance(p, int)]
if not attested:
_clear_start_attestation()
return None
if current_pids is None:
try:
from hermes_cli.gateway import find_gateway_pids
current_pids = list(find_gateway_pids())
except Exception:
return None
if current_pids:
# Gateway is up — the previous start held, or something restarted it.
_clear_start_attestation()
return None
if any(_attested_pid_exited_cleanly(pid) for pid in attested):
_clear_start_attestation()
return None
_clear_start_attestation()
via = data.get("via") or "direct spawn"
ts = data.get("ts") or "unknown time"
lines = [
f"⚠ The previous gateway start ({via}, {ts}) reported success, but the "
f"process (PID {', '.join(map(str, attested))}) died without a clean "
"shutdown record.",
" This usually means the shell that ran `hermes gateway start` was inside "
"a Windows Job Object that killed the gateway on exit (#91675).",
]
try:
if is_task_registered():
lines.append(
f" Recovery: schtasks /Run /TN {get_task_name()} "
"(Task Scheduler starts the gateway outside any Job Object)"
)
except Exception:
pass
return "\n".join(lines)
def _print_start_attestation_warning() -> None:
"""Print the stale-attestation warning if one is pending. Never raises."""
try:
warning = check_start_attestation()
except Exception:
return
if warning:
print(warning)
def _report_gateway_start(via: str) -> None:
pids = _wait_for_gateway_ready()
if pids:
print(f"✓ Gateway started via {via} (PID: {', '.join(map(str, pids))})")
if _LAST_SPAWN_BREAKAWAY_FALLBACK.get("fallback"):
print(
"⚠ The gateway could not break away from this shell's Job Object; "
"it may be killed when this shell exits."
)
try:
if is_task_registered():
print(
f" If it dies, start it with: schtasks /Run /TN {get_task_name()}"
)
except Exception:
pass
_write_start_attestation(pids, via)
else:
print(f"⚠ Launched gateway via {via}, but no process detected after 6s.")
print(
f"✗ Gateway start via {via} FAILED — no stable gateway process "
"detected within the verification window."
)
print(
" (The process may have been created and then killed — e.g. by a "
"parent Job Object, #91675.)"
)
print(" Check the log for startup errors:")
from hermes_cli.config import get_hermes_home
print(f" type {Path(get_hermes_home())}\\logs\\gateway.log")
print(f" type {Path(get_hermes_home())}\\logs\\gateway-stdio.log")
try:
if is_task_registered():
print(
f" Recovery: schtasks /Run /TN {get_task_name()} "
"(starts the gateway outside any Job Object)"
)
except Exception:
pass
def _print_next_steps() -> None:
@@ -1448,6 +1672,9 @@ def _print_deep_probes() -> None:
def status(deep: bool = False) -> None:
"""Print a status report for the Windows gateway service."""
_assert_windows()
# Surface (once) any gateway that died after a previous start printed ✓
# — the poll can't see deaths that happen after the CLI exits (#91675).
_print_start_attestation_warning()
task_name = get_task_name()
task_installed = is_task_registered()
startup_installed = is_startup_entry_installed()
@@ -1491,6 +1718,9 @@ def status(deep: bool = False) -> None:
def start() -> None:
"""Start the gateway using the canonical detached Windows launch path."""
_assert_windows()
# Report (once) if the LAST start's ✓ turned out to be false — the child
# died after the poll window, e.g. parent Job Object teardown (#91675).
_print_start_attestation_warning()
running_pids = _gateway_pids()
if running_pids:
print(f"✓ Gateway already running (PID: {', '.join(map(str, running_pids))})")
@@ -1629,6 +1859,10 @@ def stop() -> None:
_assert_windows()
from gateway.status import get_running_pid
# A user-initiated stop is a planned death: the attestation from the
# last start must not later be reported as a silent crash (#91675).
_clear_start_attestation()
# Phase 1: ask the running gateway (if any) to drain itself by writing
# the planned-stop marker, then wait briefly for it to exit cleanly.
# On clean exit, sessions land with resume_pending=True and the next
+9
View File
@@ -6753,6 +6753,15 @@ def _cold_start_windows_gateway_after_update() -> bool:
"✓ Gateway started via cold-start after update "
f"(PID: {', '.join(map(str, ready_pids))})"
)
# Persist the PIDs this ✓ vouched for so a death AFTER the updater exits
# (parent Job Object teardown, #91675) is reported by the next CLI
# invocation instead of staying silent. Best-effort.
try:
gateway_windows._write_start_attestation(
ready_pids, "cold-start after update"
)
except Exception:
pass
return True
@@ -0,0 +1,191 @@
"""Tests for the #91675 gateway-start honesty fixes.
Two holes closed by the fix:
1. ``_wait_for_gateway_ready`` returned on the FIRST process-table hit, so a
gateway that spawned and then died moments later (parent Job Object
teardown) still earned a ✓. The poll now requires the gateway to stay
visible for a confirmation window before it is reported ready.
2. A death AFTER the CLI process exits can never be seen by any poll. Every
✓ now persists a start-attestation marker; the next CLI invocation checks
it and reports the silent death (once) unless the lifecycle ledger shows
a clean exit.
All timing knobs are shrunk so no test sleeps longer than ~1s.
"""
import json
import pytest
import hermes_cli.gateway_windows as gateway_windows
# ---------------------------------------------------------------------------
# _wait_for_gateway_ready: confirmation window
# ---------------------------------------------------------------------------
def _install_pid_sequence(monkeypatch, snapshots):
"""find_gateway_pids returns successive snapshots (last one repeats)."""
calls = {"n": 0}
def _fake(*args, **kwargs):
idx = min(calls["n"], len(snapshots) - 1)
calls["n"] += 1
return list(snapshots[idx])
monkeypatch.setattr("hermes_cli.gateway.find_gateway_pids", _fake)
return calls
def test_ready_poll_rejects_gateway_that_dies_during_confirmation(monkeypatch):
"""First-hit-then-dead must NOT be reported ready (#91675 sabotage case).
Pre-fix, the poll returned ``[4242]`` on the first snapshot and the CLI
printed ✓ for a process that was already doomed.
"""
_install_pid_sequence(monkeypatch, [[4242], [], [], []])
monkeypatch.setattr(gateway_windows.time, "sleep", lambda s: None)
pids = gateway_windows._wait_for_gateway_ready(
timeout_s=0.5, interval_s=0.01, confirm_s=0.2
)
assert pids == []
def test_ready_poll_confirms_stable_gateway(monkeypatch):
"""A gateway that stays visible through the confirmation window is ready."""
_install_pid_sequence(monkeypatch, [[4242]])
monkeypatch.setattr(gateway_windows.time, "sleep", lambda s: None)
pids = gateway_windows._wait_for_gateway_ready(
timeout_s=0.5, interval_s=0.01, confirm_s=0.05
)
assert pids == [4242]
def test_ready_poll_recovers_when_gateway_respawns_within_deadline(monkeypatch):
"""Death during confirmation resumes polling; a later stable gateway wins."""
# hit → dead (confirmation fails) → nothing → new stable pid
_install_pid_sequence(monkeypatch, [[1], [], [], [2], [2], [2]])
monkeypatch.setattr(gateway_windows.time, "sleep", lambda s: None)
pids = gateway_windows._wait_for_gateway_ready(
timeout_s=1.0, interval_s=0.01, confirm_s=0.03
)
assert pids == [2]
def test_report_gateway_start_failure_is_loud_not_checkmark(monkeypatch, tmp_path, capsys):
"""No stable gateway ⇒ ✗ failure line, never ✓ (#91675)."""
monkeypatch.setattr(
gateway_windows, "_wait_for_gateway_ready", lambda *a, **k: []
)
monkeypatch.setattr(
"hermes_cli.config.get_hermes_home", lambda: str(tmp_path)
)
monkeypatch.setattr(gateway_windows, "is_task_registered", lambda: True)
monkeypatch.setattr(gateway_windows, "get_task_name", lambda: "Hermes_Gateway_x")
gateway_windows._report_gateway_start("direct spawn (PID 7)")
out = capsys.readouterr().out
assert "✓" not in out
assert "FAILED" in out
assert "schtasks /Run /TN Hermes_Gateway_x" in out
# ---------------------------------------------------------------------------
# Start attestation: report-async-death on the next CLI invocation
# ---------------------------------------------------------------------------
@pytest.fixture
def attest_home(monkeypatch, tmp_path):
monkeypatch.setattr("hermes_cli.config.get_hermes_home", lambda: str(tmp_path))
monkeypatch.setattr(gateway_windows, "is_task_registered", lambda: False)
return tmp_path
def test_success_report_writes_attestation(monkeypatch, attest_home, capsys):
monkeypatch.setattr(
gateway_windows, "_wait_for_gateway_ready", lambda *a, **k: [321]
)
gateway_windows._LAST_SPAWN_BREAKAWAY_FALLBACK["fallback"] = False
gateway_windows._report_gateway_start("direct spawn (PID 321)")
assert "✓" in capsys.readouterr().out
marker = attest_home / "state" / "gateway.start-attestation.json"
data = json.loads(marker.read_text(encoding="utf-8"))
assert data["pids"] == [321]
assert data["via"] == "direct spawn (PID 321)"
def test_attestation_reports_silent_death(attest_home):
"""Attested PIDs gone + no clean-exit record ⇒ warning, marker consumed."""
gateway_windows._write_start_attestation([555], "direct spawn (PID 555)")
warning = gateway_windows.check_start_attestation(current_pids=[])
assert warning is not None
assert "died without a clean shutdown record" in warning
assert "555" in warning
# Consumed: second check is silent.
assert gateway_windows.check_start_attestation(current_pids=[]) is None
def test_attestation_silent_when_gateway_running(attest_home):
gateway_windows._write_start_attestation([555], "direct spawn (PID 555)")
assert gateway_windows.check_start_attestation(current_pids=[555]) is None
# Marker cleared — a later dead scan must not resurrect the warning.
assert gateway_windows.check_start_attestation(current_pids=[]) is None
def test_attestation_silent_after_clean_ledger_exit(attest_home):
"""A clean lifecycle-ledger exit for the attested PID is a planned stop."""
gateway_windows._write_start_attestation([777], "direct spawn (PID 777)")
state = attest_home / "state"
state.mkdir(exist_ok=True)
(state / "gateway.lifecycle.json").write_text(
json.dumps({"phase": "exited", "pid": 777, "exit_reason": "graceful_shutdown"}),
encoding="utf-8",
)
assert gateway_windows.check_start_attestation(current_pids=[]) is None
def test_attestation_warning_includes_schtasks_recovery(monkeypatch, attest_home):
monkeypatch.setattr(gateway_windows, "is_task_registered", lambda: True)
monkeypatch.setattr(
gateway_windows, "get_task_name", lambda: "Hermes_Gateway_arthur_tutor"
)
gateway_windows._write_start_attestation([888], "direct spawn (PID 888)")
warning = gateway_windows.check_start_attestation(current_pids=[])
assert "schtasks /Run /TN Hermes_Gateway_arthur_tutor" in warning
def test_attestation_tolerates_missing_and_garbage_marker(attest_home):
assert gateway_windows.check_start_attestation(current_pids=[]) is None
marker = attest_home / "state" / "gateway.start-attestation.json"
marker.parent.mkdir(exist_ok=True)
marker.write_text("not json", encoding="utf-8")
assert gateway_windows.check_start_attestation(current_pids=[]) is None
marker.write_text(json.dumps({"pids": []}), encoding="utf-8")
assert gateway_windows.check_start_attestation(current_pids=[]) is None
assert not marker.exists()
def test_breakaway_fallback_warns_even_on_success(monkeypatch, attest_home, capsys):
"""When the spawn fell back to no-breakaway, the ✓ carries a Job warning."""
monkeypatch.setattr(
gateway_windows, "_wait_for_gateway_ready", lambda *a, **k: [99]
)
monkeypatch.setattr(gateway_windows, "is_task_registered", lambda: True)
monkeypatch.setattr(gateway_windows, "get_task_name", lambda: "Hermes_Gateway")
gateway_windows._LAST_SPAWN_BREAKAWAY_FALLBACK["fallback"] = True
try:
gateway_windows._report_gateway_start("direct spawn (PID 99)")
finally:
gateway_windows._LAST_SPAWN_BREAKAWAY_FALLBACK["fallback"] = False
out = capsys.readouterr().out
assert "✓" in out
assert "could not break away" in out
assert "schtasks /Run /TN Hermes_Gateway" in out