`hermes update` printed "draining (up to 1875s)..." and then nothing for up to 30 minutes while the gateway's in-band restart waited on in-flight work (agent.restart_after_turn_timeout). Neither the updater nor the gateway log said WHAT was being waited on, so a single long cron job read as a hung update. Gateway side: GatewayShutdownMixin._describe_active_work() enumerates each unit the restart wait holds for — chat turns (session key, model, current tool, elapsed), cron jobs (job id, elapsed, and the restart-safe external worker pid when the run was handed off; cron/scheduler now records that pid next to the running id), api/deferred runs by count. It is written to gateway_state.json as `active_work` while the state is `draining` (cleared otherwise) and appended to the 30s "Restart deferred" log line. CLI side: hermes_cli/update_cmd_drain_report.py reads `active_work` and prints a progress block every 30s during the SIGUSR1 exit wait — the holder(s), their pids, elapsed time, seconds left before the forced restart, and the config knob that caps the wait. Wired into the systemd, launchd and manual gateway restart paths of `hermes update` and into `hermes gateway restart`; `hermes gateway status` lists the same units while draining. A pre-fix gateway (no `active_work` field) gets an explicit "gateway did not report" line rather than silence. Live A/B (real gateway, 90s no-agent cron job in flight, SIGUSR1 from the caller): base = 79s of silence, no `active_work` in the state file; head = the job named with pid/elapsed/remaining every interval, log line carries the same detail.
113 lines
5.0 KiB
Python
113 lines
5.0 KiB
Python
"""Name what a draining gateway is waiting on while ``hermes update`` blocks on it.
|
|
|
|
The gateway's in-band restart (SIGUSR1 → ``request_restart``) defers ``stop()`` until in-flight
|
|
work finishes, capped by ``agent.restart_after_turn_timeout`` (30 min by default). From the
|
|
updater's side that was a bare "draining (up to 1875s)..." followed by silence, which reads as a
|
|
hung update. The gateway publishes each unit it is holding for in ``gateway_state.json``
|
|
(``active_work``, written by ``GatewayShutdownMixin._describe_active_work``); this module turns
|
|
that into progress lines.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
import time
|
|
from pathlib import Path
|
|
from typing import Callable, Optional
|
|
|
|
# Progress cadence: the gateway refreshes ``active_work`` every 30s; printing faster only repeats it.
|
|
DRAIN_REPORT_INTERVAL_S = 30.0
|
|
|
|
|
|
def _fmt_elapsed(seconds: object) -> str:
|
|
try:
|
|
total = int(float(seconds)) # type: ignore[arg-type]
|
|
except (TypeError, ValueError):
|
|
return "?"
|
|
return f"{total // 60}m{total % 60:02d}s" if total >= 60 else f"{total}s"
|
|
|
|
|
|
def _cron_job_name(job_id: str, home: Optional[Path]) -> Optional[str]:
|
|
"""``name`` from the profile's ``jobs.json`` (None when unreadable — the id alone still identifies it)."""
|
|
try:
|
|
from hermes_constants import reset_hermes_home_override, set_hermes_home_override
|
|
from cron.jobs import load_jobs
|
|
|
|
token = set_hermes_home_override(home) if home else None
|
|
try:
|
|
for job in load_jobs():
|
|
if str(job.get("id")) == job_id:
|
|
return str(job.get("name") or "") or None
|
|
finally:
|
|
if token is not None:
|
|
reset_hermes_home_override(token)
|
|
except Exception:
|
|
return None
|
|
return None
|
|
|
|
|
|
def describe_active_work_unit(unit: dict, home: Optional[Path] = None) -> str:
|
|
"""One human line for one ``active_work`` entry; unknown shapes degrade to their ``kind``."""
|
|
kind = str(unit.get("kind") or "work")
|
|
pid = unit.get("pid")
|
|
pid_part = f" pid {pid}" if pid else ""
|
|
elapsed = unit.get("elapsed_s")
|
|
elapsed_part = f", running {_fmt_elapsed(elapsed)}" if elapsed is not None else ""
|
|
if kind == "cron":
|
|
job_id = str(unit.get("job_id") or "?")
|
|
name = _cron_job_name(job_id, home)
|
|
label = f"cron job {job_id}" + (f" ({name})" if name else "")
|
|
where = f" in external worker{pid_part}" if unit.get("external") else f" in-process{pid_part}"
|
|
return f"{label}{where}{elapsed_part}"
|
|
if kind == "chat":
|
|
session = str(unit.get("session") or "?")
|
|
model = unit.get("model")
|
|
tool = unit.get("current_tool")
|
|
detail = ", ".join(p for p in (f"model {model}" if model else "", f"tool {tool}" if tool else "") if p)
|
|
return f"chat turn {session}{pid_part}{elapsed_part}" + (f" [{detail}]" if detail else "")
|
|
return f"{kind} run{pid_part}{elapsed_part}"
|
|
|
|
|
|
def read_active_work(home: Optional[Path] = None) -> Optional[list]:
|
|
"""``active_work`` as the gateway last published it, or None (old gateway / not draining / unreadable)."""
|
|
try:
|
|
from gateway.status import read_runtime_status
|
|
|
|
record = read_runtime_status(home / "gateway_state.json" if home else None) or {}
|
|
work = record.get("active_work")
|
|
return list(work) if isinstance(work, list) else None
|
|
except Exception:
|
|
return None
|
|
|
|
|
|
def format_drain_report(work: Optional[list], *, remaining_s: float, home: Optional[Path] = None) -> str:
|
|
"""Multi-line progress block: what the gateway is waiting on plus how to stop waiting."""
|
|
lines = [f" ⏳ still draining — {int(max(remaining_s, 0))}s left before the forced restart"]
|
|
if work is None:
|
|
lines.append(" (gateway did not report what it is waiting on — pre-update gateway or unreadable state file)")
|
|
elif not work:
|
|
lines.append(" (no active work reported; the gateway should exit momentarily)")
|
|
else:
|
|
lines.append(f" waiting on {len(work)} active work unit(s):")
|
|
lines.extend(f" • {describe_active_work_unit(u, home)}" for u in work)
|
|
lines.append(" finish or kill the work above to release the drain now; "
|
|
"agent.restart_after_turn_timeout in config.yaml caps this wait")
|
|
return "\n".join(lines)
|
|
|
|
|
|
def drain_progress_reporter(home: Optional[Path] = None, *, budget_s: float,
|
|
interval_s: float = DRAIN_REPORT_INTERVAL_S,
|
|
emit: Callable[[str], None] = print) -> Callable[[], None]:
|
|
"""Return a zero-arg callback for ``_wait_for_pid_exit(on_progress=...)`` that prints the drain
|
|
report every ``interval_s`` while the wait is in progress."""
|
|
started = time.monotonic()
|
|
state = {"last": started}
|
|
|
|
def _tick() -> None:
|
|
now = time.monotonic()
|
|
if now - state["last"] < interval_s:
|
|
return
|
|
state["last"] = now
|
|
emit(format_drain_report(read_active_work(home), remaining_s=budget_s - (now - started), home=home))
|
|
|
|
return _tick
|