The shutdown grace that never ran

· 14 min read
Contents

The net/http documentation spends two sentences on the trap, in the comment on Server.Shutdown:

// When Shutdown is called, [Serve], [ServeTLS], [ListenAndServe], and
// [ListenAndServeTLS] immediately return [ErrServerClosed]. Make sure the
// program doesn't exit and waits instead for Shutdown to return.

My LAN proxy for local models did the other thing. It started Shutdown in a goroutine with a five-second budget, let ListenAndServe return, and returned from main. Until v0.3.0, every restart cut every stream going through it within milliseconds of the SIGTERM, logged nothing about the requests it cut, and exited with status 0. The proxy needs a restart after every config edit, and its streams are coding agents' turns against models on two GPU boxes, which can run for minutes.

Fixing that took a real drain, socket activation, a KillMode I'd never set, a panic during shutdown, and a lock that refused the proxy's own config, in that order. It was phase 0, the first batch of fixes after a design review, and it went through five review passes of its own.

Five seconds that never started#

The v0.2.2 main, from the idle-stop loop to the end:

go handler.RunIdle(ctx, idle, 30*time.Second)
go handler.RunSSE(ctx)
// No read/write timeouts: prompts take minutes and responses stream for as long as generation runs.
srv := &http.Server{Addr: cfg.Listen, Handler: handler, ReadHeaderTimeout: 10 * time.Second, IdleTimeout: 2 * time.Minute}
go func() {
	<-ctx.Done()
	shutdown, cancel := context.WithTimeout(context.Background(), 5*time.Second)
	defer cancel()
	_ = srv.Shutdown(shutdown)
}()
log.Printf("llm-router-proxy %s listening on %s (%d hosts)", version, cfg.Listen, len(cfg.Hosts))
if err := srv.ListenAndServe(); err != nil && !errors.Is(err, http.ErrServerClosed) {
	log.Fatal(err)
}

The goroutine is correct on its own. It calls Shutdown, which closes the listener and would happily wait five seconds for running requests. But the moment it does, ListenAndServe returns ErrServerClosed, the if swallows that as the normal case, and main returns. The process ends with the goroutine still inside Shutdown and its five seconds barely begun.

A toy server with the same main pattern and one 20-event stream, sent SIGTERM three seconds in:

$ ./run.sh before
server exited 0.004 s after SIGTERM, rc=0
curl rc=18
events received: 3 of 20
--- server log
2026/10/25 13:31:31 listening on 127.0.0.1:18481

Four milliseconds, curl's exit code 18 for a transfer cut short, and a server log with nothing after the start line. Status 0, too. I'd give it this year's award for following orders: told to return, it returned, and reported success as it left.

The same server with a done channel that main waits on after ListenAndServe returns, so the five seconds actually run:

$ ./run.sh after5
server exited 5.004 s after SIGTERM, rc=0
curl rc=18
events received: 8 of 20
--- server log
2026/10/25 13:59:34 listening on 127.0.0.1:18481
2026/10/25 13:59:43 drain time over: context deadline exceeded
2026/10/25 13:59:43 drained, exiting

Now the grace happens, and at the end of it Shutdown gives up and the stream is cut anyway, eight events in. Five seconds was never going to cover a coding agent's turn. With thirty:

$ ./run.sh after
server exited 17.390 s after SIGTERM, rc=0
curl rc=0
events received: 20 of 20
--- server log
2026/10/25 13:31:35 listening on 127.0.0.1:18481
2026/10/25 13:31:55 stream finished
2026/10/25 13:31:55 drained, exiting

It exits when the stream ends, seventeen seconds later. v0.3.0 waits the same way, for up to two minutes (-drain), then closes whatever is still running and gives the cut handlers two seconds to log it. Two minutes, though, during which nothing new gets in: Shutdown works, its own comment says, "by first closing all open listeners". A client that connects mid-drain is refused, and so is everyone else until the new process has bound the port.

Let systemd hold the port#

Socket activation moves the listening socket out of the process. A .socket unit binds the address, and the service gets a duplicate as file descriptor 3, which is what the service manager hands every socket-activated daemon. The manager keeps its own copy open the whole time. From sd_listen_fds(3):

Note that the file descriptors received by daemons are duplicates of the file descriptors the service manager originally allocated and bound and of which it continuously keeps a copy (except if Accept=yes is used). […] Also note that if a daemon is restarted (and its associated sockets are not) it will receive file descriptors to the very same sockets as the earlier invocations, thus all socket options applied then will still apply.

When the old process closes its duplicate, the socket itself stays open. Connections that arrive during the drain wait in the kernel's accept queue until the new process calls accept on the very same socket. The proxy's side of it is a few lines: take fd 3 when LISTEN_PID names this process (and refuse to start unless LISTEN_FDS is exactly one), otherwise bind the address as before, and do it before anything else starts:

func listenerFrom(addr string, fd uintptr, getenv func(string) string) (net.Listener, bool, error) {
	if getenv("LISTEN_PID") == strconv.Itoa(os.Getpid()) {
		if n := getenv("LISTEN_FDS"); n != "1" {
			return nil, false, fmt.Errorf("systemd passed %q sockets, want 1 (one ListenStream in llm-router-proxy.socket)", n)
		}
		f := os.NewFile(fd, "systemd-socket")
		ln, err := net.FileListener(f) // dups the fd
		f.Close()
		return ln, true, err
	}
	ln, err := net.Listen("tcp", addr)
	return ln, false, err
}

The phase-0 review ran the restart on a throwaway copy of the units, on 127.0.0.1 against a fake GPU box: a 40-event stream (A), systemctl --user restart five seconds in, a GET /v1/models (B) two seconds into the drain and a new stream (C) a second after that.

00:55:55.708 A start
00:56:00.712 restart begins
00:56:02.718 B start (GET /v1/models during drain)
00:56:03.730 C start (new stream during drain)
00:56:35.740 A ended
00:56:36.097 restart returned rc=0
B http=200 connect=0.000145 total=33.391385
00:57:16.142 all done

Stream A got all 40 events and its [DONE] from the old process. B connected in 0.15 ms, waited out the drain in the queue and got its 200 33.4 seconds later, from the new process. Stream C, started during the drain, waited in the same queue and got all 40 events from the new process.

B's 200 was 163 bytes long. The full model list is 877. The new process had started answering before it had read the boxes' rosters over ssh, so its list held only the running engine's model, and a queued request for a model on another engine would have got a 404. The fix reads the rosters before the first accept (the connections wait in the queue anyway), and in the fifth pass the same mid-drain request got all 877 bytes.

KillMode=control-group signals the children too#

The proxy doesn't only forward requests. When a request names a model on an engine that isn't running, it stops one llama.cpp build on that box and starts another, over ssh, through a small agent mode of the same binary (why it waits for running streams first). Those ssh calls are child processes of the proxy, in the service's cgroup.

The first cut of the new service unit set no KillMode, so it ran with the default, and systemd.kill(5) is precise about what that means: "If set to control-group, all remaining processes in the control group of this unit will be killed on unit stop". The first signal is SIGTERM, and it goes to every one of them at once. The review's test: a request that needs a 20-second engine start through a fake ssh, then systemctl --user stop four seconds in:

00:58:21.584 request fk-m2 (needs a switch)
00:58:25.588 systemctl stop
00:58:25.601 stop returned rc=0
00:58:25.602 client done: {"error":{"code":424,"message":"model fk-m2: switching host fk to engine e2 failed: host fk: agent start: exit status 143: Terminated                 sleep 1","type":"model_unavailable"}}  http=424 total=4.006381

Exit status 143 is 128 plus SIGTERM's 15. The drain was there to let that request finish. Its ssh child was killed at the start of the stop, and the request got a 424 after four seconds. On a real box, the start it had asked for would have gone on there, unobserved. With KillMode=mixed, SIGTERM goes to the main process only, and whatever is left in the cgroup gets SIGKILL after the main process has exited. Same test:

01:25:55.828 request fk-m2 (needs a switch)
01:25:59.831 systemctl stop
01:26:58.105 stop returned rc=0
01:26:58.106 client done: 3}  data: {"n":24}  data: {"n":25}  data: {"n":26}  data: {"n":27}  data: {"n":28}  data: {"n":29}  data: {"n":30}  data: {"n":31}  data: {"n":32}  data: {"n":33}  data: {"n":34}  data: {"n":35}  data: {"n":36}  data: {"n":37}  data: {"n":38}  data: {"n":39}  data: [DONE]   http=200 total=62.094388

The stop took 58 seconds, and the client got its whole stream (the log line keeps only the last 300 bytes of it). The engine units on the GPU boxes had learned the same lesson in a 90-second stop: there, the whole-cgroup SIGTERM and a wrapper script's trap reached llama-server twice.

The units as they went out in v0.3.0, llm-router-proxy.socket first, then llm-router-proxy.service:

[Unit]
Description=llm-router-proxy socket: held across restarts, so new connections wait while the old process drains

[Socket]
# Filled in from the live config's "listen" by `make install-unit`.
ListenStream=@LISTEN@
# Binds the wired address even before the network is up at boot.
FreeBind=true

[Install]
WantedBy=sockets.target

[Unit]
Description=llm-router-proxy: LAN endpoint for the GPU hosts (listen from ~/.config/llm-router-proxy/hosts.json)
# The port is held by llm-router-proxy.socket (socket activation), so a restart refuses no connection.
# Wants, not Requires: if the socket cannot bind, the proxy binds the address itself and Restart retries.
Wants=llm-router-proxy.socket
After=llm-router-proxy.socket

[Service]
ExecStart=%h/.local/bin/llm-router-proxy -config %h/.config/llm-router-proxy/hosts.json
Restart=on-failure
RestartSec=5
# SIGTERM to the proxy only: its ssh calls (an engine switch in flight) finish during the drain; whatever is
# left is killed after the proxy exits.
KillMode=mixed
# On stop the proxy lets running requests finish for up to -drain (2 min), gives cut handlers 2 s, then waits up
# to 60 s for an idle stop in progress: 182 s at most.
TimeoutStopSec=200

[Install]
WantedBy=default.target

Wants= rather than Requires= came out of the same review: with Requires=, a socket that can't bind (a stray process on the port at boot) fails the service as a dependency, and nothing ever retries.

"Stop the service" stopped meaning stop#

The project's notes had a rule for smoke runs, a second copy of the proxy started by hand against the real config: stop the service first, because two proxies would both switch the same engines on the same boxes. With socket activation, stopping the service leaves the socket listening, and the next connection to it starts the service again. The proxy's status page refreshes itself every five seconds. Coding agents poll. A smoke run done by the old rule would have had company within seconds.

The rule now stops the socket and the service together. The proxy also takes a lock for each GPU box it manages and refuses to start when another instance holds one. The lock went through four versions. The first was keyed on the config file's path, and a copy of the config elsewhere sailed past it. The second was keyed on the set of ssh targets, and a config with only one of the boxes sailed past that. The third took one lock per target, and brought the last bug in this post.

A WaitGroup that panicked on the way out#

Draining requests wasn't the only thing a stop had to wait for. After fifteen idle minutes the proxy stops its own engine on a box, so a benchmark can have the GPU back, and an idle stop cut halfway would leave the box and the proxy's view of it out of step. So the shutdown path got a sync.WaitGroup: every idle stop does Add(1) and Done(), and the stop waits for it. The third pass found what happens when there are two boxes:

=== RUN   TestP0revTwoIdleStopsAtShutdown
    p0rev3_test.go:36: host a up true
    p0rev3_test.go:36: host b up true
2026/10/25 01:44:19 host a: idle 1m0s, engine stopped
panic: sync: WaitGroup is reused before previous Wait has returned

goroutine 42 [running]:
sync.(*WaitGroup).Wait(0x17a8918b2970)
	~/.local/opt/go/src/sync/waitgroup.go:213 +0xf4
llm-router-proxy/internal/proxy.(*Proxy).WaitIdleStops.func1()
	~/work/go/llm-router-proxy/agent-work/2026-10-25-phase0-review/src3/internal/proxy/proxy.go:478 +0x28
created by llm-router-proxy/internal/proxy.(*Proxy).WaitIdleStops in goroutine 41
	~/work/go/llm-router-proxy/agent-work/2026-10-25-phase0-review/src3/internal/proxy/proxy.go:478 +0x7d
FAIL	llm-router-proxy/internal/proxy	0.061s
FAIL

The idle loop visits the boxes one after another and didn't look at the shutdown context between them. It finished the first box's stop, which Wait was waiting for, and then started the second box's: an Add from zero, after a Wait had begun. The sync documentation forbids exactly that ("If a WaitGroup is reused to wait for several independent sets of events, new Add calls must happen after all previous Wait calls have returned"), and sync checks for it as the woken Wait returns. The repro test panicked on its first iteration, three runs out of three.

It wasn't a contrived case, either. After a quiet restart, every box's last activity is the restart time, so they all come due in the same pass fifteen minutes later; a restart during that pass's first stop is all it takes. The fix gives the idle loop a context check and the proxy a closing flag, set under the same mutex the Add now happens under:

if ctx.Err() != nil { // shutting down: no new stop
	return
}
unlock := p.sw.Lock(host) // not while a switch runs
p.mu.Lock()
a := p.act[host]
stop := !p.closing && a.inflight == 0 && !a.stopped && p.now().Sub(a.last) >= d
a.switching = stop // nothing new is routed to the engine being stopped
if stop {
	p.stopping.Add(1) // under mu and before closing: WaitIdleStops never sees an Add during its Wait
}
p.mu.Unlock()

The lock that refused its own config#

The per-box lock is a file in the runtime directory, named after a hash of the box's ssh target, held with flock:

for _, target := range sshTargets {
	sum := sha256.Sum256([]byte(target))
	path := filepath.Join(dir, fmt.Sprintf("llm-router-proxy-%x.lock", sum[:6]))
	f, err := os.OpenFile(path, os.O_CREATE|os.O_RDWR, 0o600)
	if err != nil {
		held.Close()
		return nil, err
	}
	if err := syscall.Flock(int(f.Fd()), syscall.LOCK_EX|syscall.LOCK_NB); err != nil {
		f.Close()
		held.Close()
		return nil, fmt.Errorf("another llm-router-proxy manages %s (lock %s)", target, path)
	}
	held = append(held, f)
}

The fourth pass fed it two configs that -check accepts. One had two hosts without engines and without ssh, which the config allows for a box the proxy only forwards to. Both targets were the empty string, so both hosts mapped to llm-router-proxy-e3b0c44298fc.lock, the first six bytes of SHA-256 of nothing at all. The other had two engine hosts on the same ssh target. Either way, the second flock in the same process failed, because flock(2) treats each open as its own lock holder: "An attempt to lock the file using one of these file descriptors may be denied by a lock that the calling process has already placed via another file descriptor." The proxy reported that another llm-router-proxy managed the box, with two spaces where the empty target's name should have been, and exited 1. Under systemd that's a restart loop, right after make install-unit's config check had passed. The live config has two hosts with two different targets, so it never hit this. The fix locks only the hosts whose engines the proxy manages, each target once.

The fifth pass found nothing left but a few low-severity leftovers. The deploy that installed all of it, at 02:04:50 that night, couldn't use the drain: the process that received that SIGTERM was v0.2.2, which exits on the spot. It cut every running stream, all zero of them. The last chat request had ended at 23:55:51, and the 3090's engine had been idle-stopped at 00:10:57. Since then the unit's TimeoutStopSec=200 covers the rest. Two minutes of drain, two seconds for cut requests to log themselves, up to a minute for an idle stop in flight, and eighteen seconds that belong to nobody.

Filed under: go, systemd, linux, proxy, concurrency

Sources#