hermes-agent/tests/gateway/test_restart_notification.py
Teknium 1dce908930
fix(gateway): shutdown + restart hygiene (drain timeout, false-fatal, success log) (#18761)
* fix(gateway): config.yaml wins over .env for agent/display/timezone settings

Regression from the silent config→env bridge. The bridge at module import
time is correct for max_turns (unconditional overwrite), but every other
agent.*, display.*, timezone, and security bridge key was guarded by
'if X not in os.environ' — so a stale .env entry from an old 'hermes setup'
run would shadow the user's current config.yaml indefinitely.

Symptom: agent.max_turns: 500 in config.yaml, HERMES_MAX_ITERATIONS=60
in .env from an old setup, and the gateway silently capped at 60
iterations per turn. Gateway logs confirmed api_calls never exceeded 60.

Three changes:

1. gateway/run.py: drop the 'not in os.environ' guards for all agent.*,
   display.*, timezone, and security.* bridge keys. config.yaml is now
   authoritative for these settings — same semantics already in place
   for max_turns, terminal.*, and auxiliary.*. Also surface the bridge
   failure (previously 'except Exception: pass') to stderr so operators
   see bridge errors instead of silently falling back to .env.

2. gateway/run.py: INFO-log the resolved max_iterations at gateway
   start so operators can verify the config→env bridge did the right
   thing instead of chasing a phantom budget ceiling.

3. hermes_cli/setup.py: stop writing HERMES_MAX_ITERATIONS to .env in
   the setup wizard. config.yaml is the single source of truth. Also
   clean up any stale .env entry left behind by pre-fix setups.

Regression tests in tests/gateway/test_config_env_bridge_authority.py
guard each config→env key against the 'stale .env shadows config' bug.

* fix(gateway): shutdown + restart hygiene (drain timeout, false-fatal, success log)

Three issues observed in production gateway.log during a rapid restart
chain on 2026-05-02, all fixed here.

1. _send_restart_notification logged unconditional success
   adapter.send() catches provider errors (e.g. Telegram 'Chat not found')
   and returns SendResult(success=False); it never raises. The caller
   ignored the return value and always logged 'Sent restart notification
   to <chat>' at INFO, producing a misleading success line directly
   below the 'Failed to send Telegram message' traceback on every boot.
   Now inspects result.success and logs WARNING with the error otherwise.

2. WhatsApp bridge SIGTERM on shutdown classified as fatal error
   _check_managed_bridge_exit() saw the bridge's returncode -15 (our own
   SIGTERM from disconnect()) and fired the full fatal-error path,
   producing 'ERROR ... WhatsApp bridge process exited unexpectedly' plus
   'Fatal whatsapp adapter error (whatsapp_bridge_exited)' on every
   planned shutdown, immediately before the normal '✓ whatsapp
   disconnected'. Adds a _shutting_down flag that disconnect() sets
   before the terminate, and _check_managed_bridge_exit() returns None
   for returncode in {0, -2, -15} while shutting down. OOM-kill (137)
   and other non-signal exits still hit the fatal path.

3. restart_drain_timeout default 60s → 180s
   On 2026-05-02 01:43:27 a user /restart fired while three agents were
   mid-API-call (82s, 112s, 154s into their turns). The 60s drain budget
   expired and all three were force-interrupted. 180s covers realistic
   in-flight agent turns; users on very-long-reasoning models can still
   raise it further via agent.restart_drain_timeout in config.yaml.
   Existing explicit user values are preserved by deep-merge.

Tests
- tests/gateway/test_restart_notification.py: two new tests assert INFO
  is only logged on SendResult(success=True) and WARNING with the error
  string is logged on SendResult(success=False).
- tests/gateway/test_whatsapp_connect.py: parametrized test for
  returncode in {0, -2, -15} proves shutdown-time exits are suppressed;
  separate test proves returncode 137 (SIGKILL/OOM) still surfaces as
  fatal even when _shutting_down is set.
- _check_managed_bridge_exit() reads _shutting_down via getattr-with-
  default so existing _make_adapter() test helpers that bypass __init__
  (pitfall #17 in AGENTS.md) keep working unmodified.
2026-05-02 02:08:06 -07:00

330 lines
11 KiB
Python

"""Tests for /restart notification — the gateway notifies the requester on comeback."""
import asyncio
import json
from pathlib import Path
from unittest.mock import AsyncMock, MagicMock
import pytest
import gateway.run as gateway_run
from gateway.config import Platform
from gateway.platforms.base import MessageEvent, MessageType
from gateway.session import build_session_key
from tests.gateway.restart_test_helpers import (
make_restart_runner,
make_restart_source,
)
# ── _handle_restart_command writes .restart_notify.json ──────────────────
@pytest.mark.asyncio
async def test_restart_command_writes_notify_file(tmp_path, monkeypatch):
"""When /restart fires, the requester's routing info is persisted to disk."""
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
runner, _adapter = make_restart_runner()
runner.request_restart = MagicMock(return_value=True)
source = make_restart_source(chat_id="42")
event = MessageEvent(
text="/restart",
message_type=MessageType.TEXT,
source=source,
message_id="m1",
)
result = await runner._handle_restart_command(event)
assert "Restarting" in result
notify_path = tmp_path / ".restart_notify.json"
assert notify_path.exists()
data = json.loads(notify_path.read_text())
assert data["platform"] == "telegram"
assert data["chat_id"] == "42"
assert "thread_id" not in data # no thread → omitted
@pytest.mark.asyncio
async def test_restart_command_uses_service_restart_under_systemd(tmp_path, monkeypatch):
"""Under systemd (INVOCATION_ID set), /restart uses via_service=True."""
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
monkeypatch.setenv("INVOCATION_ID", "abc123")
runner, _adapter = make_restart_runner()
runner.request_restart = MagicMock(return_value=True)
source = make_restart_source(chat_id="42")
event = MessageEvent(
text="/restart",
message_type=MessageType.TEXT,
source=source,
message_id="m1",
)
await runner._handle_restart_command(event)
runner.request_restart.assert_called_once_with(detached=False, via_service=True)
@pytest.mark.asyncio
async def test_restart_command_uses_detached_without_systemd(tmp_path, monkeypatch):
"""Without systemd, /restart uses the detached subprocess approach."""
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
monkeypatch.delenv("INVOCATION_ID", raising=False)
runner, _adapter = make_restart_runner()
runner.request_restart = MagicMock(return_value=True)
source = make_restart_source(chat_id="42")
event = MessageEvent(
text="/restart",
message_type=MessageType.TEXT,
source=source,
message_id="m1",
)
await runner._handle_restart_command(event)
runner.request_restart.assert_called_once_with(detached=True, via_service=False)
@pytest.mark.asyncio
async def test_restart_command_preserves_thread_id(tmp_path, monkeypatch):
"""Thread ID is saved when the requester is in a threaded chat."""
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
runner, _adapter = make_restart_runner()
runner.request_restart = MagicMock(return_value=True)
source = make_restart_source(chat_id="99")
source.thread_id = "topic_7"
event = MessageEvent(
text="/restart",
message_type=MessageType.TEXT,
source=source,
message_id="m2",
)
await runner._handle_restart_command(event)
data = json.loads((tmp_path / ".restart_notify.json").read_text())
assert data["thread_id"] == "topic_7"
@pytest.mark.asyncio
async def test_restart_command_uses_atomic_json_writes_for_marker_files(tmp_path, monkeypatch):
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
calls = []
def _fake_atomic_json_write(path, payload, **kwargs):
calls.append((Path(path).name, payload, kwargs))
monkeypatch.setattr(gateway_run, "atomic_json_write", _fake_atomic_json_write)
runner, _adapter = make_restart_runner()
runner.request_restart = MagicMock(return_value=True)
source = make_restart_source(chat_id="42")
event = MessageEvent(
text="/restart",
message_type=MessageType.TEXT,
source=source,
message_id="m1",
)
await runner._handle_restart_command(event)
names = [name for name, _payload, _kwargs in calls]
assert names == [".restart_notify.json", ".restart_last_processed.json"]
assert calls[0][1]["chat_id"] == "42"
assert calls[1][1]["platform"] == "telegram"
# ── _send_restart_notification ───────────────────────────────────────────
@pytest.mark.asyncio
async def test_send_restart_notification_delivers_and_cleans_up(tmp_path, monkeypatch):
"""On startup, the notification is sent and the file is removed."""
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
notify_path = tmp_path / ".restart_notify.json"
notify_path.write_text(json.dumps({
"platform": "telegram",
"chat_id": "42",
}))
runner, adapter = make_restart_runner()
adapter.send = AsyncMock()
await runner._send_restart_notification()
adapter.send.assert_called_once()
call_args = adapter.send.call_args
assert call_args[0][0] == "42" # chat_id
assert "restarted" in call_args[0][1].lower()
assert call_args[1].get("metadata") is None # no thread
assert not notify_path.exists()
@pytest.mark.asyncio
async def test_send_restart_notification_with_thread(tmp_path, monkeypatch):
"""Thread ID is passed as metadata so the message lands in the right topic."""
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
notify_path = tmp_path / ".restart_notify.json"
notify_path.write_text(json.dumps({
"platform": "telegram",
"chat_id": "99",
"thread_id": "topic_7",
}))
runner, adapter = make_restart_runner()
adapter.send = AsyncMock()
await runner._send_restart_notification()
call_args = adapter.send.call_args
assert call_args[1]["metadata"] == {"thread_id": "topic_7"}
assert not notify_path.exists()
@pytest.mark.asyncio
async def test_send_restart_notification_noop_when_no_file(tmp_path, monkeypatch):
"""Nothing happens if there's no pending restart notification."""
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
runner, adapter = make_restart_runner()
adapter.send = AsyncMock()
await runner._send_restart_notification()
adapter.send.assert_not_called()
@pytest.mark.asyncio
async def test_send_restart_notification_skips_when_adapter_missing(tmp_path, monkeypatch):
"""If the requester's platform isn't connected, clean up without crashing."""
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
notify_path = tmp_path / ".restart_notify.json"
notify_path.write_text(json.dumps({
"platform": "discord", # runner only has telegram adapter
"chat_id": "42",
}))
runner, _adapter = make_restart_runner()
await runner._send_restart_notification()
# File cleaned up even though we couldn't send
assert not notify_path.exists()
@pytest.mark.asyncio
async def test_send_restart_notification_cleans_up_on_send_failure(
tmp_path, monkeypatch
):
"""If the adapter.send() raises, the file is still cleaned up."""
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
notify_path = tmp_path / ".restart_notify.json"
notify_path.write_text(json.dumps({
"platform": "telegram",
"chat_id": "42",
}))
runner, adapter = make_restart_runner()
adapter.send = AsyncMock(side_effect=RuntimeError("network down"))
await runner._send_restart_notification()
# File cleaned up even though send raised.
assert not notify_path.exists()
@pytest.mark.asyncio
async def test_send_restart_notification_logs_warning_on_sendresult_failure(
tmp_path, monkeypatch, caplog
):
"""Adapter that returns SendResult(success=False) must log a WARNING, not INFO.
Regression guard: adapter.send() catches provider errors (e.g. Telegram
"Chat not found") and returns SendResult(success=False) rather than
raising. The caller previously ignored the return value and always
logged "Sent restart notification to ..." at INFO — masking real
delivery failures behind a fake success line.
"""
from gateway.platforms.base import SendResult
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
notify_path = tmp_path / ".restart_notify.json"
notify_path.write_text(json.dumps({
"platform": "telegram",
"chat_id": "42",
}))
runner, adapter = make_restart_runner()
adapter.send = AsyncMock(
return_value=SendResult(success=False, error="Chat not found"),
)
with caplog.at_level("DEBUG", logger="gateway.run"):
await runner._send_restart_notification()
success_lines = [
r for r in caplog.records
if r.levelname == "INFO" and "Sent restart notification" in r.getMessage()
]
warning_lines = [
r for r in caplog.records
if r.levelname == "WARNING"
and "was not delivered" in r.getMessage()
and "Chat not found" in r.getMessage()
]
assert not success_lines, (
"Expected no INFO 'Sent restart notification' line when send failed, "
f"got: {[r.getMessage() for r in success_lines]}"
)
assert warning_lines, (
"Expected a WARNING line mentioning the failure; "
f"got records: {[(r.levelname, r.getMessage()) for r in caplog.records]}"
)
# Still cleans up.
assert not notify_path.exists()
@pytest.mark.asyncio
async def test_send_restart_notification_logs_info_on_sendresult_success(
tmp_path, monkeypatch, caplog
):
"""Adapter returning SendResult(success=True) keeps the INFO log line."""
from gateway.platforms.base import SendResult
monkeypatch.setattr(gateway_run, "_hermes_home", tmp_path)
notify_path = tmp_path / ".restart_notify.json"
notify_path.write_text(json.dumps({
"platform": "telegram",
"chat_id": "42",
}))
runner, adapter = make_restart_runner()
adapter.send = AsyncMock(return_value=SendResult(success=True, message_id="m-1"))
with caplog.at_level("DEBUG", logger="gateway.run"):
await runner._send_restart_notification()
success_lines = [
r for r in caplog.records
if r.levelname == "INFO" and "Sent restart notification" in r.getMessage()
]
assert success_lines, (
"Expected INFO 'Sent restart notification' when send succeeded; "
f"got records: {[(r.levelname, r.getMessage()) for r in caplog.records]}"
)
assert not notify_path.exists()