fix(server): Shutdown runs the OnShutdown hooks, and returns, only after the drain on every engine (#703) - #746
Conversation
…ter the drain on every engine (celeris#703) Server.Shutdown ran every hook and returned right after cancelling the listen context, so on epoll and io_uring, whose Engine.Shutdown is a no-op and whose drain runs in Listen, the hooks ran while requests were still being handled, and a direct Shutdown returned before the drain. Every Start* entry point now runs Listen through one helper that closes a listenDone channel, published with the engine, when Listen returns; Shutdown waits for it, bounded by ctx, before it closes the CPU monitor and runs the hooks, and returns ctx's error if ctx is done first. The Start*Context watcher (#692) wakes on the same channel. Also pins the window celeris#728 named (a Shutdown before the watcher's view, then a cancel, must run the hooks once).
…e native engines' Shutdown notes the wait (celeris#703) Comment-only.
…M in the celeris#703 drain-order test At CI's 8 MiB memlock the kernel charges ring memory per UID, so a start right after the previous case, or while another test binary holds rings, can fail with nothing leaked; the first failing-first run on main lost two io_uring cases that way. Same convention as startC714DetachServer: a new server, for up to 10 s, then fail (never skip).
|
Navigate logical layers of code changes, visualize relationships, and explore their blast radius. No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configurationConfiguration used: Repository: goceleris/celeris/.coderabbit.yaml Review profile: CHILL Plan: Advanced Run ID: 📒 Files selected for processing (1)
Included review availability: This review used your included allowance. Your plan provides up to 10 included reviews per hour; 6 remain after this review. 📝 WalkthroughWalkthrough
ChangesShutdown lifecycle
Priority: ➖ Normal Estimated code review effort: 4 (Complex) | ~45 minutes Change: Bug fix · Severity of issue fixed: Medium Merge Risk: ⚪ Minimal · up to The reviewed shutdown ordering has no identified issue that needs resolution before merge; normal checks still apply. Security Architecture ReviewSecurity architecture risk: 🔵 Low · up to The change improves the ordering of request draining and shutdown hooks without establishing a new request-controlled shutdown path. Lifecycle and engine coverage remains incomplete, so the assessment is not minimal risk. Retained concerns Security review detailsSecurity Blast Radius
Trust Boundaries and Controls
Resilience and Maintainability Implications
Hardening Proposals
🚥 Pre-merge checks | ✅ 2 | ❌ 2❌ Failed checks (2 warnings)
✅ Passed checks (2 passed)
Full details: Title checkExplanation The title uses valid Conventional Commit syntax and accurately describes the shutdown ordering change. It references issue Full details: Out of Scope Changes checkExplanation The incremental change adds unrelated startup-failure cleanup in
Comment |
Codecov Report✅ All modified and coverable lines are covered by tests. 📢 Thoughts on this report? Let us know! |
…fter that Shutdown, hooks included; scope the drain's godoc (celeris#703) Round 2 of the #746 review. Once Shutdown waited for Listen, closing listenDone woke the Start call and Shutdown's wait at the same moment, and the hooks ran after Start had returned. A main that exits when Start returns lost its hooks on every engine: epoll and io_uring had run them at t=0 before, and on std Start returned when the drain began. listen now waits for the first direct Shutdown after it closes listenDone, which is all Shutdown waits for, so the two never wait on each other. That is the same contract the Start*Context calls already had for a cancel. The drain's godoc and comments now say what the drain covers. They no longer claim every HTTP/2 stream: std's h2c streams and HTTP/2 streams on async routes are not waited for (celeris#759). They also say that epoll closes connections without flushing (celeris#760). The listenDone comment no longer says std's Listen returns after the drain. Tests: TestStartReturnsOnlyAfterADirectShutdownReturns (fake engine, forced order, also the deadlock check). TestShutdownHooksRunAfterTheDrain now also asserts that Start returns after the hook, and runs h2c cases on the native engines' sync routes.
…, the CPU monitor and the settle re-opener (#737) (#747) Bug: a Start that failed before its engine ran left the caller's listener bound (handshakes into a backlog nothing accepts) and, on a createEngine failure, the CPU monitor's /proc/stat fd open; a Start whose Listen failed or ran after Shutdown leaked the monitor fd and the settle re-opener goroutine (+20 fds per 20 starts on main dccb839). Change (server.go): prepareWithListener closes the supplied listener on a failed start except ErrAlreadyStarted; doPrepare closes the CPU monitor when createEngine fails; the func listenContext returns (deferred by every Start*) also stops the settle re-opener and closes the monitor. Breaking: a failed StartWithListener now closes the listener, as net/http's Serve does. Verification: six new tests fail on main (5 FAIL, 23 of 25 subtests) and pass at head (-count=3, 27/75 PASS); revert arm 5 FAIL, and each of four partial mutants is caught only by its own tests. Root suite merged with #746: 380 PASS / 0 FAIL / 1 SKIP (CI shape). CI green on 3d29a49 (run 36358042411); CodeRabbit: no actionable comments. Follow-ups: #778. Fixes #737
|
Round 2 pushed as |
Merging this PR will improve performance by 11.47%
Performance Changes
Tip Curious why performance improved? Comment Comparing Footnotes
|
Fixes #703
What was wrong
Server.Shutdown's godoc says theOnShutdownhooks fire after the engine "stops accepting new connections and drains in-flight requests". Onepollandio_uringthey did not. TheirEngine.Shutdownis a no-op, and their drain runs inListenonce its context is cancelled;Server.Shutdowncancelled that context and went straight on to the CPU monitor and the hooks, and returned. So on the two default Linux engines:Shutdownran every hook, and returned, while requests were still in their handlers: a program that doessrv.Shutdown(ctx); os.Exit(0)could exit mid-request, and a hook that closes a DB pool ran while handlers still used it;StartWithContext's context ran the hooks at once as well; only theStartcall waited for the drain (fix(server): shut down on every context cancel, and return only after it (celeris#673) #692).stdandadaptivekept the order: theirEngine.Shutdownis the drain.The fix
One wait, in
Server.shutdown, aftercancelListenand before the CPU monitor and the hooks: until the engine'sListenhas returned, bounded byctx. On epoll and io_uring the drain runs inListen:Loop.shutdownandWorker.shutdownclose their connections and join async dispatch beforeListenreturns, so every handler the workers run has returned by then. On std and adaptiveEngine.Shutdownhas already drained (std'sListenreturned when that drain began; adaptive'sEngine.Shutdownwaits for its ownListen). What the drain does not cover is in round 2 below: two kinds of HTTP/2 stream (#759), and epoll's unflushed close (#760).Start*entry point now runsListenthrough one helper,listen, which closes alistenDonechannel whenListenreturns.publishEnginemakes that channel together with the engine, so aShutdownthat loads a non-nil engine always finds it (every published engine is followed by exactly onelisten). It is written beforeengineRef.Storeand read only after a non-nilengineRef.Load, so the atomic orders it.Start*Contextwatcher already joined on a locallistenDone. It now wakes on this same channel, as the issue asked, so there is no second signal.ctxis done first, the hooks still run, with thatctx, andShutdownreturnsctx's error, asstd'shttp.Server.Shutdowndoes when its drain outlives the deadline.listenthen waits for the first directShutdown, so theStart*call it stopped returns after its hooks (below).Shutdown(the wait, the error, what the drain covers, why a handler must not callShutdownand wait for it),Config.ShutdownTimeout(one deadline for the drain and then the hooks), theStart*andOnShutdowngodocs (theStart*call returns after the hooks), and the epoll/io_uringEngine.Shutdownnotes.Not on the request path: only the start and shutdown paths change.
Why the wait for
Listencannot deadlockThe wait graph:
shutdownwaits forlistenDone.listenDoneis closed by theStart*goroutine right aftereng.Listenreturns.eng.Listenreturns once its context is cancelled and its workers have drained, andcancelListencancelled that context before the wait.Listenwaits for nothingShutdownholds or does later. No lock is held across the wait:lifecycleMuandcpuMonMuare released before it.shutdownon theStart*Contextwatcher. The watcher waits forListen, never for theStartcall. TheStartcall waits for the watcher only afterListenhas returned (err := s.listen(...); <-watcherDone). Mutant M3 below makes the wait be on theStartcall's return instead, and the tests catch it: every cancel and direct-Shutdowncase on the context path fails at its 10 s cap, far inside the 30 s budget it would otherwise have waited out.Shutdownand waits for it waits for its own request, untilctxis done. That is also true ofstdtoday, and ofnet/http. The godoc says to call it from another goroutine.The round-2 wait (
Startwaits for the directShutdown) has its own deadlock check in the round-2 section.Round 2 (head
3d2ab72)The review of
76c205cfound two blocking defects. Both are fixed here.1.
Startreturned before the hooks of theShutdownthat stopped it. OnceShutdownwaited forListen, closinglistenDonewoke theStartcall andShutdown's wait at the same moment, and the hooks ran afterStarthad returned. So amainshaped like net/http's lost its hooks on every engine:That includes the session write-behind flush the docs put in
OnShutdown. Measured in a child process with thatmain, a 200 ms hook that writes a marker file and one request held 500 ms, 5 runs per engine (round2/738/run-mainexit.sh, one container):5936dd876c205c(round 1)3d2ab72(this head)Fix: the first direct
Shutdownpublishes adirectShutdownDonechannel underlifecycleMubefore it does anything else, and closes it when it returns.listen(the one path of everyStart*entry point) waits for that channel afterListenhas returned andlistenDoneis closed. AStart*call stopped by a directShutdowntherefore returns only after thatShutdown, hooks included, on every engine. This is the contract theStart*Contextcalls already had for a cancel (#692). TheStart,StartWithListener,StartWithContext,StartWithListenerAndContextandOnShutdowngodocs say so. The last of these says that a hook must not wait for theStart*call to return.It also changes std:
Startused to return as soon asShutdownclosed the listener (net/http'sListenAndServedoes too). It now returns when thatShutdownreturns.Deadlock check for the new wait. Lock order:
lifecycleMuis taken only for the read or write of the channel and is never held across a wait. The waits are:Shutdownwaits forlistenDone, bounded by itsctx.listencloseslistenDone(a deferred close) before it waits fordirectShutdownDone(the earlier defer, so it runs later).ShutdownclosesdirectShutdownDonewhen it returns.The owning
Shutdownnever waits for anything that waits onlisten, so there is no cycle. AShutdownthat finds the watcher's claim waits onwatcherShutdownand owns nodirectShutdownDone. The watcher waits forListen, never for theStartcall. The one cycle left is user-made, a hook that waits forStartto return, and the godoc forbids it. That cycle has the same bound as before: the hook'sctx.Mutant R2 below puts the wait before the close. The new test then fails at its 10 s bound instead of hanging:
the direct Shutdown did not return within 10s of Listen's release: it and the Start call wait on each other.2. The drain does not cover every HTTP/2 stream. The drain does not wait for two kinds of stream:
h2c.NewHandlerhijacks the connection.For the first kind, the hooks run while the handler is still running and the response is lost. Filed as #759, with a repro on main 698bed6 (a handler held 400 ms on a fixed timer, independent of the hook). Joining the pool handlers is the H2 half of graceful shutdown (GOAWAY, then keep the connection's write path running until the streams finish). A plain join would deadlock on a handler blocked on flow control, so that fix is not in this PR. Instead this PR:
Shutdowngodoc, thelistenDonecomment and the body's claims to what the drain covers: every HTTP/1.1 request, and on the native engines every HTTP/2 stream whose handler runs on the worker;TestShutdownHooksRunAfterTheDrain, on the native engines' sync routes (15 cases);The minor findings (the
listenDonecomment was false for std; epoll's drain is "the handlers returned") are fixed in the comments changed here. The rest are in #777. The out-of-scope 4 MiB response stall is filed as #761.Behaviour change
breakinglabel, as on #692 (behaviour, not API):Shutdownnow returns after the drain, not at once, and returnsctx's error if the drain outlivesctx. adaptive now returns that error too; itsEngine.Shutdownused to swallow it.deployment.mdsuggested this on epoll/io_uring) now runs too late on every engine, as it already did on std and adaptive. docs#77 moves the flip to the signal handler.Start*call stopped by a directShutdownreturns only after thatShutdownhas returned, hooks included. On std,Startused to return as soon asShutdownclosed the listener, asListenAndServedoes. A hook that waits for theStart*call to return now waits for itself until itsctxis done.OnShutdown's godoc says not to do that, as it already said for a cancel.Shutdownsynchronously now waits untilctxis done on every engine, as it already did on std.No non-test code in this repository calls
Server.Shutdown: besidesserver.go,git grep -n '\.Shutdown(' -- '*.go' ':!*_test.go'lists only engine-internal calls, socketshutdown(2)calls andvalidation/endpoint.go's ownhttp.Server. The test suites that start and shut down servers pass unchanged (below).Tests
TestShutdownHooksRunAfterTheDrain(Linux,shutdown_drain_order_linux_test.go): the issue's experiment as a real test. It runs real engines (std, epoll, epoll async, io_uring, io_uring async, adaptive; default worker count) in three modes: a directShutdownon aStartWithContextserver, a cancel of that context, and a directShutdownon aStartWithListenerserver, which runsListenoutside the watcher. Round 2 adds the same modes over h2c (prior knowledge) on the five native configs, on a sync route: 33 cases. One request is held in its handler. Each case asks four things. Had the handler finished when the first hook started? Had the hook started before the call that shut the server down returned? Did the client get the whole response? And (round 2) did theStartcall return only after the hook had returned?Startcall returns, or for 200 ms. So aShutdownthat does not wait always reaches its hooks with the handler held, and aStartthat does not wait always returns while the hook is held.TestStartReturnsOnlyAfterADirectShutdownReturns(all OSes, round 2): theStart-return property on a fake engine whoseListenoutlives its cancel until released, forStartand forStartWithContextwith a directShutdown. The order is forced the same way. It is also the deadlock check for the round-2 wait.TestShutdownRunsHooksOnlyAfterListenReturnsandTestShutdownWaitForListenIsBoundedByCtx(all OSes): the round-1 property on the same fake engine, forStart,StartWithContext+ShutdownandStartWithContext+ cancel. They also check that the wait is bounded byctx, that the hooks still run with it, and thatShutdownreturnscontext.DeadlineExceeded.Shutdownnow waits for the fake engine'sListen, so it runs on its own goroutine.TestStartContextWatcherDoesNotRepeatADirectShutdownalso asserts that the hook has not run whileListenis still tearing down. That assertion races under the negative control; the deterministic detector isTestShutdownRunsHooksOnlyAfterListenReturns(Follow-ups from #746: the adapted #692 assertion is not forced, the ctx-bound test's unbounded-wait failure mode, CI runs the drain-order test in one shape #777).TestShutdownBeforeTheWatcherLoadsRunsHooksOnce: the Follow-up from #692: a Shutdown that races Start*Context before the callsBefore load can run OnShutdown hooks twice #728 guard (below).Failing-first (linux/arm64 Docker,
--cpus 4,-race -v; counts are--- PASS/FAIL/SKIPlines only)TestShutdownHooksRunAfterTheDrain's final text, overlaid on main698bed6(it uses only the public API;round2/703/ff-main.sh): 30 of 33 cases FAIL, in both shapes: the CI shape (8 MiB memlock, one io_uring worker) and unconstrained memlock (4 io_uring workers).Startcall returned while the hook was still running. These are the two direct-Shutdownmodes on all 11 engine configs.No SKIP line.
Controls (
round2/703/controls-docker.sh)One container per shape, each arm a copy of the head's tree with one edit to
server.go. The generators areround2/703/make-mutants.py(R) and round 1's703/mutants/make-mutants.py(M), applied to this head; both exit if an anchor drifts. The fake-engine tests also ran natively on darwin (round2/703/darwin-unit.sh).TestShutdownHooksRunAfterTheDrain(33 cases)3d2ab72-count=3: 21/21 PASS. darwin-count=10: 70/70 PASS-count=3: 99/99 PASS. unconstrained-count=2: 66/66 PASSlistendoes not wait for the directShutdown(the round-1 behaviour)TestStartReturnsOnlyAfterADirectShutdownReturns(both subtests), all else PASSShutdowncase on all 11 configs,the Start call returned ... while the OnShutdown hook was still running. The 11 cancel cases pass.listenwaits for theShutdownbefore it closeslistenDone(the deadlock)the direct Shutdown did not return within 10s of Listen's release: it and the Start call wait on each other)Shutdownstarts, not when it returnsListendeletedListenmoved after the hooksShutdownwaits for theStartcallTestStartReturnsOnlyAfterADirectShutdownReturns, #692'sTestADirectShutdownAfterTheWatchersDoesNotRepeatIt)Shutdownandcancelcase on the context path, each at the 10 s cap. The 11StartWithListenercases pass.No SKIP line in any arm. With the fix, all 165 engine cases (99 CI shape + 66 unconstrained) ran in this order: handler returned, hook started, hook returned, then
ShutdownandStartreturned. The client got200 "done"in every case. On epoll, io_uring and adaptive the hook started 0.0-1.5 ms after the handler returned, which it did at 300-310 ms. On std the gap was 227-281 ms, from net/http's idle-connection poll. No start needed the ENOMEM retry.What the test does not cover, measured on this head by
round2/repro/run-repro.sh(not committed), is in #759: on epoll, io_uring and adaptive, an h2c request on an.Async()route gotunexpected EOFwith the hook before the handler, in 6/6 cases; on std the hook came before the h2c handler in 4/4 cases. The same script on this head gives the sync-route h2c cases on the native engines handler-then-hook with200 "done"(6/6).Suites (
round2/scripts/suites.sh,-race -count=1 -v, onego testprocess per arm)Root package. The arms are main
9b670b8(main moved during the run; #765 landed), this head3d2ab72, and a local merge of this head, #747's headfb52752and main9b670b8. All three merge cleanly.9b670b8No test goes from PASS to anything else (
round2/scripts/suite-compare2.py). Every test new in an arm passes. The 12 main tests absent from this PR's arm are the twoTestAdapt*tests #736 added after this branch's base; they pass in the merged arm. The skips are the same in every arm:TestRouteAdaptive_SettleReopenCost(env-gated), and at 8 MiB only the three io_uring subtests ofTestAdaptiveSettledRouteRetime592(#709)../middleware/...(CI shape), main9b670b8vs this head: 1779/0/5 vs 1774/0/5 top-level, and 748 vs 723 subtests PASS. No regressions. The difference is the five tests #734 and #736 added on main after this branch's base. The five skips are the same (allocation tests under-race, andTestMeasureWedgeRate). The suites that start and shut down servers while clients hold connections (websocket, sse, static, session) are unchanged. That includesStart*now waiting for theShutdownthat stopped it.Also:
golangci-lintv2.13 (the repo's config): 0 issues forGOOS=linux. OnGOOS=darwinit reports the same twointernal/deferlingerunused fields as on main.gofmtclean excepttest/benchcmp_ws/bench_test.go, which is the same on main.GOOS=linux GOARCH=amd64/arm64 go vetand test-binary builds are clean (lint/r2-703-3d2ab72.log).3d2ab72: run 36349652266, all 11 jobs green on the first attempt; the root package was ok in 71.9 s at 8 MiB memlock.#728
#728 (a
ShutdownracingStart*Contextbefore the watcher'scallsBeforeload can run the hooks twice) does not hold on main. The snapshot it names existed at #692's review head5a05c2eand was replaced before the merge by thedirectShutdownclaim (a20af40).TestShutdownBeforeTheWatcherLoadsRunsHooksOnceforces the #728 order, and this PR adds it as a guard, since it changes the same path. Measured with-race -count=20per tree (728/verify.sh): the hook ran twice in 20/20 runs at5a05c2eand atf17c04a, and once in 20/20 ata20af40and at maindccb839. At this head it passes 10/10 on darwin and 3/3 in the CI shape (the controls above).Docs
goceleris/docs#77 (round 2 at
5b463a1) makes the graceful-shutdown pages state these rules and their HTTP/2 and epoll exceptions, and settles #738, which is to be closed by hand once both merge. It should merge after this PR. Measuring what the pages should say about the deadline found #753: on std, a cancel's shutdown does not keep toShutdownTimeout. That is pre-existing, the same on main, and not changed here.Evidence
Scripts and logs are in the maintainer's probatorium evidence root,
evidence/lanes-20260927/LIFECYCLE/:round2/, which has703/(controls, failing-first, mutants),repro/(HTTP/2 streams on the shared H2 worker pool are not drained at shutdown: an async-route stream loses its response on epoll, io_uring and adaptive, and std waits for no h2c stream #759, epoll: shutdown closes connections with their pending writes unflushed, so a response larger than the socket buffers loses its tail (no counterpart of io_uring's #595 send drain) #760, epoll/io_uring: an HTTP/1.1 response of 4 MiB or more sends only its headers; the body is dropped and a keep-alive client waits until its own timeout #761),738/(the docs probe),scripts/(suites) andlogs/;703/,728/,ff-main/,03-suites/,04-amd64/,lint/.Every number above is printed by a script there. The cluster row (
_queue/cluster.tsv, lane LIFECYCLE) is re-pinned to3d2ab72: this test on bare metal with many io_uring workers, both arches.