Clamp the HTTP drain by the tail-hook reserve (closes #170)
check / check (push) Waiting to run
check / check (push) Waiting to run
The server's stop hook bounded the drain by ShutdownTimeout alone, so once the archive sweeper or retention reaper had spent part of the fx stop budget, a request held open could use up the reserve and fx skipped every hook after the server, the database close included. The drain now gets the shorter of ShutdownTimeout and what is left less TailHookReserve, the clamp the Sentry flush already has. The headroom test also sweeps the time earlier hooks spent and checks that a drain on the full budget gets all of ShutdownTimeout. A new test, run on synctest's clock, holds a request open over net.Pipe against a stop context with only the reserve left. The README and the reserve's comment say how the reserve is derived and what a slow sweeper now costs. Model: opus-5-5
This commit is contained in:
@@ -3245,9 +3245,9 @@ each hook. The order, read off the fx stop-hook log:
|
||||
|
||||
1. `ArchiveSweeper`
|
||||
2. `RetentionReaper`
|
||||
3. `server` — the HTTP drain, bounded separately by
|
||||
`server.ShutdownTimeout` (**3 seconds**), then a Sentry flush if
|
||||
`SENTRY_DSN` is set
|
||||
3. `server` — the HTTP drain, bounded by `server.ShutdownTimeout`
|
||||
(**3 seconds**) and by what the hooks before it left, then a Sentry
|
||||
flush if `SENTRY_DSN` is set
|
||||
4. `delivery.Engine` — waits for its workers, then closes the archive
|
||||
databases
|
||||
5. `healthcheck`
|
||||
@@ -3267,23 +3267,30 @@ exhaust the sequence budget at the instant it finished, and every
|
||||
later hook — the delivery engine, the healthcheck, the webhook DB
|
||||
manager and the database close — would be skipped in exactly the
|
||||
case where the drain mattered. 3 seconds leaves 2 seconds
|
||||
(`server.TailHookReserve`) for the tail, which is far more than the
|
||||
microseconds it needs.
|
||||
(`server.TailHookReserve`) for the tail. The reserve is that
|
||||
remainder, not a figure sized to the tail, which takes about a
|
||||
millisecond.
|
||||
|
||||
That reserve belongs to the tail hooks, not to the server hook, and
|
||||
the Sentry flush is what could take it: it runs after the drain
|
||||
**inside the same hook**, and `sentry.Flush` takes a bare duration
|
||||
and honours no context, so an unreachable Sentry endpoint would add
|
||||
its own timeout on top of a full-length drain and consume the whole
|
||||
sequence budget by itself. It is therefore clamped to whatever is
|
||||
left on the stop context minus the reserve, and skipped when that
|
||||
leaves too little to be worth attempting — so a full-length drain
|
||||
means Sentry events are dropped rather than the database close being
|
||||
skipped.
|
||||
the server hook could take it in two ways. The hooks before it may
|
||||
already have spent part of the budget, so a full 3-second drain
|
||||
would come out of the reserve; the drain is therefore also bounded
|
||||
by whatever is left on the stop context minus the reserve. And the
|
||||
Sentry flush runs after the drain **inside the same hook**, and
|
||||
`sentry.Flush` takes a bare duration and honours no context, so an
|
||||
unreachable Sentry endpoint would add its own timeout on top of a
|
||||
full-length drain and consume the whole sequence budget by itself.
|
||||
It is clamped the same way, and skipped when that leaves too little
|
||||
to be worth attempting — so a full-length drain means Sentry events
|
||||
are dropped rather than the database close being skipped.
|
||||
|
||||
This does not make the database close unconditional: a wedged
|
||||
`ArchiveSweeper` or `RetentionReaper` still runs first and can
|
||||
consume the whole budget on its own.
|
||||
This does not make the database close unconditional. A slow
|
||||
`ArchiveSweeper` or `RetentionReaper` is enough to cut the shutdown
|
||||
short, not only one that consumes the whole budget: what they spend
|
||||
comes out of the drain first, so after 2 seconds of theirs a request
|
||||
still in flight gets 1 second to finish, and after 3 it gets none.
|
||||
Past 3 seconds they spend the reserve itself, and one that takes the
|
||||
whole budget skips every hook after it, the database close included.
|
||||
|
||||
The value is chosen to sit inside the container stop grace period.
|
||||
Docker's default `docker stop` grace is 10 seconds and the Dockerfile
|
||||
|
||||
@@ -38,17 +38,19 @@ import (
|
||||
// hook that used the whole budget would exhaust it at that instant,
|
||||
// and fx would skip every hook after the server — the delivery
|
||||
// engine, the healthcheck, the webhook DB manager and the database
|
||||
// close. That hook is the 3s HTTP drain plus the Sentry flush that
|
||||
// follows it in the same hook, so the flush is clamped to the stop
|
||||
// close. That hook is the HTTP drain plus the Sentry flush that
|
||||
// follows it in the same hook, and each is clamped to the stop
|
||||
// context's remaining time less server.TailHookReserve rather than
|
||||
// running for its own fixed 2s; the reserve is what the tail hooks
|
||||
// live on, and they are microsecond-scale in normal operation.
|
||||
// running for its own fixed 3s and 2s; the reserve is what the tail
|
||||
// hooks live on, and they are microsecond-scale in normal operation.
|
||||
// TestStopTimeout_LeavesHeadroomForTailHooks pins the arithmetic
|
||||
// across every drain length.
|
||||
// across every drain length and every amount of budget the hooks
|
||||
// before the server may already have spent.
|
||||
//
|
||||
// This does not make the database close unconditional: the
|
||||
// ArchiveSweeper and RetentionReaper hooks run before the server
|
||||
// and can still consume the whole budget on their own.
|
||||
// ArchiveSweeper and RetentionReaper hooks run before the server.
|
||||
// What they spend comes out of the drain first, but past 3s it comes
|
||||
// out of the reserve, and they can consume the whole budget.
|
||||
const stopTimeout = 5 * time.Second
|
||||
|
||||
// exitUsage is the status for a command line this binary cannot make
|
||||
|
||||
@@ -252,22 +252,40 @@ const tailHeadroom = 2 * time.Second
|
||||
// can produce, since a shorter drain leaves the flush more room and
|
||||
// the worst case is not necessarily at either extreme.
|
||||
//
|
||||
// Shrinking either budget, or unbounding the flush again, must fail
|
||||
// here rather than silently recreating a hook that swallows the
|
||||
// whole sequence.
|
||||
// Nor does the hook start on a full budget: the ArchiveSweeper and
|
||||
// RetentionReaper hooks run before it, and whatever they spent is
|
||||
// gone. The outer sweep walks every amount they can spend. Once they
|
||||
// have eaten into the headroom themselves, the hook must spend
|
||||
// nothing of what is left. A drain that starts on the full budget
|
||||
// must still get all of ShutdownTimeout, so a smaller stopTimeout
|
||||
// cannot silently shorten every drain.
|
||||
//
|
||||
// Shrinking either budget, or unbounding the drain or the flush
|
||||
// again, must fail here rather than silently recreating a hook that
|
||||
// swallows the whole sequence.
|
||||
func TestStopTimeout_LeavesHeadroomForTailHooks(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
require.Less(t, server.ShutdownTimeout, stopTimeout)
|
||||
require.Equal(
|
||||
t, server.ShutdownTimeout, server.DrainBudget(stopTimeout),
|
||||
"a drain that starts on the full stop budget is cut short",
|
||||
)
|
||||
|
||||
const step = 10 * time.Millisecond
|
||||
|
||||
for drain := time.Duration(0); drain <= server.ShutdownTimeout; drain += step {
|
||||
hook := drain + server.SentryFlushBudget(stopTimeout-drain)
|
||||
for spent := time.Duration(0); spent <= stopTimeout; spent += step {
|
||||
remaining := stopTimeout - spent
|
||||
longest := max(server.DrainBudget(remaining), 0)
|
||||
|
||||
require.LessOrEqual(
|
||||
t, hook+tailHeadroom, stopTimeout,
|
||||
"a %s drain leaves the tail hooks short", drain,
|
||||
)
|
||||
for drain := time.Duration(0); drain <= longest; drain += step {
|
||||
hook := drain + server.SentryFlushBudget(remaining-drain)
|
||||
|
||||
require.GreaterOrEqual(
|
||||
t, remaining-hook, min(remaining, tailHeadroom),
|
||||
"a %s drain after %s of earlier hooks leaves "+
|
||||
"the tail hooks short", drain, spent,
|
||||
)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@@ -1,6 +1,8 @@
|
||||
package server
|
||||
|
||||
import (
|
||||
"context"
|
||||
"log/slog"
|
||||
"net/http"
|
||||
"testing"
|
||||
|
||||
@@ -37,6 +39,14 @@ func SentryClientOptionsForTest(
|
||||
return sentryClientOptions(dsn, release)
|
||||
}
|
||||
|
||||
// CleanShutdownForTest runs the server's stop hook, cleanShutdown,
|
||||
// against hs: a server the test started itself, so it can hold a
|
||||
// request open across the drain. Sentry is off.
|
||||
func CleanShutdownForTest(ctx context.Context, hs *http.Server) {
|
||||
s := &Server{log: slog.New(slog.DiscardHandler), httpServer: hs}
|
||||
s.cleanShutdown(ctx)
|
||||
}
|
||||
|
||||
// newServerForTest builds a Server through New, as the application
|
||||
// does, on a lifecycle that is never started: the hooks New adds to
|
||||
// it never run, so nothing listens.
|
||||
|
||||
@@ -39,6 +39,12 @@ const (
|
||||
// refuses to spend, leaving it for the hooks that run after the
|
||||
// server: the delivery engine, the healthcheck, the webhook DB
|
||||
// manager and the database close.
|
||||
//
|
||||
// Its value is not tuned to those hooks, which take about a
|
||||
// millisecond between them. It is what the 5s fx stop timeout in
|
||||
// cmd/webhooker leaves after a full ShutdownTimeout drain, so a
|
||||
// drain that starts on a full budget still gets all of
|
||||
// ShutdownTimeout.
|
||||
TailHookReserve = 2 * time.Second
|
||||
|
||||
// sentryFlushTimeout is the longest wait for Sentry to flush
|
||||
@@ -59,6 +65,16 @@ const (
|
||||
// key off it, and a zero exit would read as a deliberate stop.
|
||||
const StartupFailureExitCode = 1
|
||||
|
||||
// DrainBudget reports how long the HTTP drain may wait for in-flight
|
||||
// requests when remaining is the time left on the fx stop context as
|
||||
// the server's stop hook starts. The hooks before the server can
|
||||
// already have spent part of the budget, so the drain takes its time
|
||||
// out of what they left, never out of TailHookReserve. Zero or less
|
||||
// means no wait at all.
|
||||
func DrainBudget(remaining time.Duration) time.Duration {
|
||||
return min(ShutdownTimeout, remaining-TailHookReserve)
|
||||
}
|
||||
|
||||
// SentryFlushBudget reports how long the Sentry flush may run when
|
||||
// remaining is the time left on the fx stop context after the HTTP
|
||||
// drain. sentry.Flush takes a bare duration and honours no context,
|
||||
@@ -261,10 +277,17 @@ func (s *Server) cleanupForExit() {
|
||||
s.log.Info("cleaning up")
|
||||
}
|
||||
|
||||
// cleanShutdown drains the HTTP server and flushes Sentry inside what
|
||||
// is left of the fx stop budget. A context carrying no deadline — a
|
||||
// caller outside the fx lifecycle — gets the full ShutdownTimeout.
|
||||
func (s *Server) cleanShutdown(ctx context.Context) {
|
||||
ctxShutdown, shutdownCancel := context.WithTimeout(
|
||||
ctx, ShutdownTimeout,
|
||||
)
|
||||
drain := ShutdownTimeout
|
||||
|
||||
if deadline, ok := ctx.Deadline(); ok {
|
||||
drain = DrainBudget(time.Until(deadline))
|
||||
}
|
||||
|
||||
ctxShutdown, shutdownCancel := context.WithTimeout(ctx, drain)
|
||||
defer shutdownCancel()
|
||||
|
||||
err := s.httpServer.Shutdown(ctxShutdown)
|
||||
|
||||
@@ -1,13 +1,148 @@
|
||||
package server_test
|
||||
|
||||
import (
|
||||
"context"
|
||||
"net"
|
||||
"net/http"
|
||||
"testing"
|
||||
"testing/synctest"
|
||||
"time"
|
||||
|
||||
"github.com/stretchr/testify/require"
|
||||
"sneak.berlin/go/webhooker/internal/server"
|
||||
)
|
||||
|
||||
// TestDrainBudget covers the clamp that keeps the HTTP drain from
|
||||
// spending the tail hooks' share of the fx stop budget when the hooks
|
||||
// before the server have already used part of it.
|
||||
func TestDrainBudget(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
tests := []struct {
|
||||
name string
|
||||
remaining time.Duration
|
||||
want time.Duration
|
||||
}{
|
||||
{
|
||||
name: "only the reserve is left",
|
||||
remaining: server.TailHookReserve,
|
||||
want: 0,
|
||||
},
|
||||
{
|
||||
name: "earlier hooks spent part of the budget",
|
||||
remaining: server.TailHookReserve + time.Second,
|
||||
want: time.Second,
|
||||
},
|
||||
{
|
||||
name: "capped at the nominal timeout",
|
||||
remaining: time.Hour,
|
||||
want: server.ShutdownTimeout,
|
||||
},
|
||||
}
|
||||
|
||||
for _, tt := range tests {
|
||||
t.Run(tt.name, func(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
require.Equal(t, tt.want, server.DrainBudget(tt.remaining))
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
// TestCleanShutdown_LeavesTailHookReserve stops the server with a
|
||||
// request still in flight, after the hooks before it have spent all
|
||||
// of the stop budget but TailHookReserve. The drain must give up at
|
||||
// once rather than wait for the request: what is left belongs to the
|
||||
// hooks after the server, the database close among them. A drain
|
||||
// bounded only by ShutdownTimeout waits until the stop context
|
||||
// expires, and fx then skips those hooks.
|
||||
//
|
||||
// The test runs in a synctest bubble, whose clock moves only while
|
||||
// every goroutine in it is blocked, so a drain that gives up at once
|
||||
// leaves the stop context unexpired however slow the host is. The
|
||||
// request travels over net.Pipe because a goroutine waiting on a
|
||||
// real socket would stop that clock from moving at all.
|
||||
func TestCleanShutdown_LeavesTailHookReserve(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
synctest.Test(t, func(t *testing.T) {
|
||||
entered := make(chan struct{})
|
||||
release := make(chan struct{})
|
||||
|
||||
hs := &http.Server{
|
||||
Handler: http.HandlerFunc(
|
||||
func(http.ResponseWriter, *http.Request) {
|
||||
close(entered)
|
||||
<-release
|
||||
},
|
||||
),
|
||||
ReadHeaderTimeout: time.Second,
|
||||
}
|
||||
|
||||
srvConn, cliConn := net.Pipe()
|
||||
|
||||
listener := pipeListener{
|
||||
conns: make(chan net.Conn, 1),
|
||||
closed: make(chan struct{}),
|
||||
}
|
||||
listener.conns <- srvConn
|
||||
|
||||
go func() { _ = hs.Serve(listener) }()
|
||||
|
||||
// Cleanups run last first: the handler returns, then closing
|
||||
// the client end ends the server's write of the response.
|
||||
t.Cleanup(func() { _ = cliConn.Close() })
|
||||
t.Cleanup(func() { close(release) })
|
||||
|
||||
_, err := cliConn.Write(
|
||||
[]byte("GET / HTTP/1.1\r\nHost: webhooker.test\r\n\r\n"),
|
||||
)
|
||||
require.NoError(t, err)
|
||||
|
||||
<-entered
|
||||
|
||||
stopCtx, cancel := context.WithTimeout(
|
||||
t.Context(), server.TailHookReserve,
|
||||
)
|
||||
defer cancel()
|
||||
|
||||
server.CleanShutdownForTest(stopCtx, hs)
|
||||
|
||||
require.NoError(
|
||||
t, stopCtx.Err(), "the drain spent the tail hooks' reserve",
|
||||
)
|
||||
})
|
||||
}
|
||||
|
||||
// pipeListener is the net.Listener http.Server.Serve needs to serve
|
||||
// the server end of a net.Pipe: Accept returns that one connection,
|
||||
// then waits until Close, as a real listener with no more clients
|
||||
// does.
|
||||
type pipeListener struct {
|
||||
conns chan net.Conn
|
||||
closed chan struct{}
|
||||
}
|
||||
|
||||
func (l pipeListener) Accept() (net.Conn, error) {
|
||||
select {
|
||||
case conn := <-l.conns:
|
||||
return conn, nil
|
||||
case <-l.closed:
|
||||
return nil, net.ErrClosed
|
||||
}
|
||||
}
|
||||
|
||||
func (l pipeListener) Close() error {
|
||||
close(l.closed)
|
||||
|
||||
return nil
|
||||
}
|
||||
|
||||
// Addr is never called by http.Server.Serve.
|
||||
func (pipeListener) Addr() net.Addr {
|
||||
return nil
|
||||
}
|
||||
|
||||
// TestSentryFlushBudget covers the clamp that keeps the Sentry flush
|
||||
// from spending the tail hooks' share of the fx stop budget.
|
||||
// sentry.Flush ignores the stop context, so without the clamp a
|
||||
|
||||
Reference in New Issue
Block a user