6krrt/plans/router-unreachable-signal-investigation.md

Router going unreachable under systemctl — investigation & hardening plan

Status: done -- docs/incidents.md

Started 2026-08-29, after the dispatcher went unreachable three times in one session (opencode: ConnectionError ... Connection refused, and the TUI showing the same). systemctl --user status reported active (running) every time — the process never exited, it just stopped accepting connections. Findings ranked by what's confirmed vs. still open.

---

What's confirmed

• Each time, journalctl --user -u llm-router.service shows the uvicorn process itself logging INFO: Shutting down / INFO: Waiting for connections to close. (CTRL+C to force quit) — this is uvicorn's own signal handler firing, i.e. the process received SIGTERM (or SIGINT).
• In every occurrence there is no preceding Stopping Local LLM model router... line from systemd[862]. That line is systemd's own, unconditional announcement that it is running a stop job — it appears before the two known-good causes (systemctl stop, systemctl restart, including the ones this session ran deliberately, which do show it). Its absence means the signal did not arrive through systemctl.
• Because systemd never opened a stop job for these, TimeoutStopUSec (10s, systemd's default) never applied, and Restart=on-failure never fired — that only triggers when the main process exits, and it never did. The unit sat in active (running) indefinitely, fully invisible to systemd's own health tracking, while curl localhost:8080/health and ss -ltnp (no listener on 8080) showed it was actually dead to clients.
• GET /admin/api/restart-service was never hit — its access-log line (POST /api/restart-service) does not appear in the journal around any of the incidents, and that endpoint calls systemctl --user restart (admin.py:691) which — like the manual restarts — would produce the "Stopping" line. Ruled out.
• Not a suspend/resume cycle (journalctl around each incident has no suspend|resume|sleep|lid entries) and not systemd-oomd (disabled on this host, and RSS was ~100-140MB — nowhere near OOM territory).
• Once hung, the process has ~10 open sockets it's waiting to drain (/proc/<pid>/fd) and its listening socket is already closed — consistent with _decision_event_stream() (dispatcher.py:1396-1415), the /events/decisions SSE generator, which is an unconditional while True loop that only exits when the client disconnects. It sends a heartbeat every SSE_HEARTBEAT_SECONDS = 15, so it never looks "stuck" to uvicorn — it's actively working, just working forever. Any TUI or admin-dashboard tab left open holds one of these connections open across a restart attempt.
• Fix applied for the symptom, already shipped (commit b9220ed): ExecStart now passes --timeout-graceful-shutdown 5 (deploy/llm-router.service, mirrored to ~/.config/systemd/user/llm-router.service). This caps uvicorn's own drain wait at 5s independent of whether systemd is tracking a stop job, so a bare SIGTERM now converges to a clean exit instead of hanging forever. Verified live: the process restarted under this flag has picked it up (confirmed via ps -o cmd showing the flag on the running command).

What's still open: who sends the signal

The symptom (hangs forever) is fixed. The trigger (something delivers SIGTERM outside of systemctl) is not identified, and will keep firing every 10-20 minutes based on tonight's timeline (21:36, 21:49, 22:08, 22:23, 01:42, 01:58 — irregular, not matching either systemd timer's schedule: llm-router-poller.timer is 2h, llm-router-seed.timer is 6h).

H1 — Manual kill/pkill/process manager in another pane

Two of the six restarts tonight (22:23:07, 01:42:16) exactly match systemctl --user restart llm-router.service in this pane's ~/.zsh_history. The other four don't appear in this pane's history, but there are two other active tmux panes (pts/2, pts/3, an opencode session) whose shell history hasn't necessarily flushed to disk yet. A pkill -f uvicorn, an htop/btop kill keystroke, or a kill <pid> typed while cleaning up a stale process in one of those panes would produce exactly this signature: signal delivered, no systemd stop job.

How to confirm, without more guessing: auditctl is present on this host but needs sudo, which isn't passwordless here. One-time setup (run this yourself, since it needs your password):

sudo auditctl -a always,exit -F arch=b64 -S kill -F a1=15 -k routerkill
sudo auditctl -a always,exit -F arch=b64 -S tgkill -F a2=15 -k routerkill

Then after the next hang:

sudo ausearch -k routerkill -i | tail -40

This resolves the exact calling PID, command, and parent PID for every SIGTERM (a1=15/a2=15 is the signal-number filter) sent anywhere on the system — it will name the culprit on the next occurrence, whether it's a shell, a TUI keybinding, or something else entirely.

H2 — In-process signal provenance (fallback if you'd rather not touch audit)

If auditctl is unwanted, the alternative is to have dispatcher.py itself report who signaled it. Python's signal.signal() handler doesn't expose the sender, but signal.sigwaitinfo() does (si_pid, si_uid) when the signal is blocked from the default async handler and waited on synchronously. This would mean overriding uvicorn's own SIGTERM handling — a real change to shutdown behavior, not just an observation — so it's a fallback, not the first move. Concretely: block SIGTERM in the main thread at startup (signal.pthread_sigmask), spawn a daemon thread that blocks on signal.sigwaitinfo([signal.SIGTERM]), logs si_pid/si_uid, resolves /proc/<si_pid>/comm and /proc/<si_pid>/cmdline, and then re-raises SIGTERM to itself so uvicorn's normal shutdown still runs. Only worth building if H1's auditctl approach is blocked (e.g. no sudo access at all).

H3 — A systemd timer or path unit we haven't found

Checked and ruled out: only llm-router-poller.timer (2h) and llm-router-seed.timer (6h) reference this unit family (systemctl --user list-timers), and neither's schedule lines up with any incident tonight. No path units exist under ~/.config/systemd/user/*.path. Not revisiting unless H1 comes back negative.

H4 — opencode or its plugins

Checked deploy/opencode-plugin/router-outcome.js (the only opencode plugin touching this router) — it only does fetch(ROUTER + "/outcome"), no process management, no signals. The oh-my-openagent lsp-daemon processes (304864, 502927) are unrelated node processes with no visibility into this service. No code path here sends a signal. Ruled out unless new evidence surfaces.

Recommended next step

Run the two auditctl commands under H1 once (needs your sudo password — type it interactively in one of your panes, not through me). Leave them running; they're cheap (kill/tgkill syscalls are rare in the ambient workload of this box). Next time the router drops, sudo ausearch -k routerkill -i names the sender in one shot, which turns four remaining hypotheses into zero. Everything else in this doc is instrumentation for if that comes back empty.

Status: armed 2026-08-29 ~02:05 EDT, then immediately caught a live occurrence at 02:06:49-54. Result was a false lead, but an instructive one:

type=SYSCALL msg=audit(08/29/2026 02:06:54.260:103) : arch=x86_64
syscall=tgkill success=yes exit=0 a0=0x81d9a a1=0x81d9a a2=SIGTERM ...
ppid=862 pid=531866 ... comm=uvicorn exe=/usr/bin/python3.14 key=routerkill

a0/a1 both decode to 531866 — the process's own PID. This is not an external actor. It's uvicorn's own shutdown machinery (.venv/.../uvicorn/server.py:315-338, capture_signals()): its custom SIGTERM handler only sets flags, so after graceful shutdown completes it deliberately re-delivers the same signal to itself via signal.raise_signal() so the process actually terminates the normal way. Confirmed by timing: "Shutting down" first logged at 02:06:49; this self-raise is at 02:06:54 — exactly --timeout-graceful-shutdown 5 later. This self-raise happens at the end of every signal-triggered shutdown, including ordinary systemctl restarts, so on its own it proves nothing about the trigger.

The real question is what delivered the original SIGTERM at 02:06:49. Searched the full window (-ts 02:00:40 -te 02:08:00, both kill and tgkill, system-wide) and found only the one self-raise record — no external kill/tgkill syscall anywhere in that window. So the original delivery didn't go through either of those two syscalls. Extended the watch to the other three ways Linux can deliver a signal:

sudo auditctl -a always,exit -F arch=b64 -S pidfd_send_signal -F a1=15 -k routerkill
sudo auditctl -a always,exit -F arch=b64 -S rt_sigqueueinfo -F a1=15 -k routerkill
sudo auditctl -a always,exit -F arch=b64 -S rt_tgsigqueueinfo -F a2=15 -k routerkill

pidfd_send_signal is the leading suspect — it's the modern, race-free signal syscall some tools (and some systemd internals) now prefer over the classic kill/tgkill, and it wouldn't have matched either of the first two rules. Next occurrence: search all five keys, not just two, and specifically look for a record before the self-raise (which will always be ~5s after the "Shutting down" log line and should now be treated as noise, not signal).

Status: all 5 rules armed 2026-08-29 ~02:13 EDT (confirmed via sudo auditctl -l). A silent occurrence at 02:12:33 (self-healed by Restart=always before anyone noticed — Shutting down at 02:12:33, back up at 02:12:43) landed 25 seconds before the 3 new rules were added (CONFIG_CHANGE records at 02:13:04), so it's an incomplete but useful data point: sudo ausearch -k routerkill -i for that window shows plenty of unrelated kill traffic (a timeout 5 curl test artifact at 02:10:50; a Chrome thread pool killing its own subprocesses at 02:12:23, none of them targeting the router's PID) and the expected self-raise at 02:12:38 (target 532910, confirming which MainPID this crash belonged to) — but no kill/tgkill record anywhere delivering to 532910/0x821ae itself. So the original delivery for this occurrence definitely didn't use either of the first two watched syscalls, which is exactly what the pidfd_send_signal hypothesis predicts. That rule (plus the two rt_*sigqueueinfo ones) simply wasn't armed yet for this one. Waiting on the next occurrence now that all 5 are live.

When it happens: sudo ausearch -k routerkill -i and look for a record targeting the router's PID that is not ~5s after the "Shutting down" log line (that offset is always the harmless uvicorn self-raise) and not comm=uvicorn — that's the real sender.

Interim mitigation shipped regardless of root cause: Restart=on-failure → Restart=always in llm-router.service (both the live unit and deploy/llm-router.service). Systemd's on-failure policy explicitly excludes clean termination by SIGTERM/SIGINT from auto-restart (its assumption: SIGTERM means someone deliberately asked it to stop). That assumption was wrong for these events, and combined with the graceful- shutdown-timeout fix (the process now exits cleanly instead of hanging), it meant every occurrence left the service inactive (dead) until a human noticed and restarted it by hand. Restart=always self-heals within RestartSec=5s for any termination except an explicit systemctl stop, which systemd still honors correctly regardless of the Restart= policy.