diff --git a/README.md b/README.md index 570f087..8779d17 100644 --- a/README.md +++ b/README.md @@ -1040,6 +1040,8 @@ webhooker/ │ │ └── webhook.go # Webhook receiver handler │ ├── healthcheck/ │ │ └── healthcheck.go # Health check service (uptime, version) +│ ├── lifecycle/ +│ │ └── lifecycle.go # Shared stop-hook waiter, bounded by the stop context │ ├── logger/ │ │ └── logger.go # slog setup with TTY detection │ ├── middleware/ @@ -1165,6 +1167,39 @@ downstream at form-parse time. - Container runs as non-root user (UID 1000) - GORM soft deletes on all entities (data preserved for audit) +### Shutdown + +On SIGINT or SIGTERM, fx runs the registered stop hooks in reverse +dependency order under a **5 second budget** (`fx.StopTimeout` in +`cmd/webhooker/main.go`). That budget covers the whole sequence, not +each hook: the HTTP server drains first with its own 5 second limit, +then the delivery engine, the reapers, and finally the database +close. + +The value is chosen to sit inside the container stop grace period. +Docker's default `docker stop` grace is 10 seconds and the Dockerfile +sets no `STOPSIGNAL` or grace override, so the process must be gone +before that. fx's own default is 15 seconds, which is past the grace: +the container would be SIGKILLed (exit 137) before the bound could +fire, and nothing that depends on it — including the +`shutdown timed out, goroutines still running` error log that tells +an operator a component is wedged — would ever be reached. + +Two operational consequences follow from bounding the sequence: + +- **A wedged component aborts the rest of the shutdown.** fx checks + the stop context before each remaining hook and returns outright + once it has expired, skipping the hooks it has not reached. If the + first-stopped component consumes the whole budget, the later hooks + never run — **the database close among them**. SQLite is crash-safe, + so this is not corruption, but it is not a clean close either. +- **Lowering the grace below 5 seconds reintroduces the silent + truncation.** `docker stop --time`, Compose's `stop_grace_period`, + or Kubernetes' `terminationGracePeriodSeconds` set under 5 seconds + put SIGKILL back in front of the bound, and the process dies with + no shutdown diagnostics at all. Keep the deployment's grace above + the stop timeout. + ### Docker The Dockerfile uses a multi-stage build: diff --git a/cmd/webhooker/main.go b/cmd/webhooker/main.go index 793f44c..b642059 100644 --- a/cmd/webhooker/main.go +++ b/cmd/webhooker/main.go @@ -2,6 +2,8 @@ package main import ( + "time" + "go.uber.org/fx" "sneak.berlin/go/webhooker/internal/config" "sneak.berlin/go/webhooker/internal/database" @@ -15,6 +17,17 @@ import ( "sneak.berlin/go/webhooker/internal/session" ) +// stopTimeout bounds the whole fx stop sequence. +// +// fx defaults to 15s, which is longer than Docker's 10s default +// stop grace: the container would be SIGKILLed before the bound +// could fire, so nothing bounded by it would ever be observed. +// 5s leaves headroom inside that grace for signal delivery and +// process exit, and matches the HTTP server's own drain budget so +// the first hook can spend its whole budget without the bound +// truncating it. +const stopTimeout = 5 * time.Second + // Build-time variables set via -ldflags. // //nolint:gochecknoglobals // Build-time variables injected by the linker. @@ -27,7 +40,14 @@ func main() { globals.Appname = appname globals.Version = version - fx.New( + newApp().Run() +} + +// newApp builds the application graph. It is separate from main so +// a test can assert the options it carries. +func newApp() *fx.App { + return fx.New( + fx.StopTimeout(stopTimeout), fx.Provide( globals.New, logger.New, @@ -60,5 +80,5 @@ func main() { ) { }, ), - ).Run() + ) } diff --git a/cmd/webhooker/main_test.go b/cmd/webhooker/main_test.go new file mode 100644 index 0000000..3e392d1 --- /dev/null +++ b/cmd/webhooker/main_test.go @@ -0,0 +1,33 @@ +package main + +import ( + "testing" + "time" + + "github.com/stretchr/testify/require" +) + +// dockerStopGrace is Docker's default `docker stop` grace period. +// The Dockerfile sets no STOPSIGNAL or grace override, so this is +// the deadline the container is actually held to, and the fx stop +// timeout has to fit inside it with room for signal delivery and +// process exit. +const dockerStopGrace = 10 * time.Second + +// TestNewApp_StopTimeout pins the fx stop timeout. Without the +// explicit fx.StopTimeout option the app reads fx's 15s +// DefaultTimeout, which exceeds dockerStopGrace: the container is +// SIGKILLed before the bound fires and every shutdown hook bounded +// by it — including the operator-facing timeout log — becomes +// unreachable in the image this repo produces. +// +// fx.New applies options before it executes invokes, so the timeout +// is set whether or not the graph itself can be constructed here. +func TestNewApp_StopTimeout(t *testing.T) { + t.Setenv("DATA_DIR", t.TempDir()) + + got := newApp().StopTimeout() + + require.Equal(t, stopTimeout, got) + require.Less(t, got, dockerStopGrace) +} diff --git a/internal/lifecycle/export_test.go b/internal/lifecycle/export_test.go new file mode 100644 index 0000000..08fd13b --- /dev/null +++ b/internal/lifecycle/export_test.go @@ -0,0 +1,21 @@ +package lifecycle + +import ( + "context" + "log/slog" +) + +// WaitDone exposes waitDone to the external test package. Only the +// unexported waiter can be handed a channel that is already closed +// before the call, which is the state the preamble exists for; +// through WaitForShutdown the waiter goroutine may or may not have +// closed the channel yet, so the case is not reachable +// deterministically from outside. +func WaitDone( + ctx context.Context, + log *slog.Logger, + component string, + done <-chan struct{}, +) error { + return waitDone(ctx, log, component, done) +} diff --git a/internal/lifecycle/lifecycle.go b/internal/lifecycle/lifecycle.go index b538fd6..614305f 100644 --- a/internal/lifecycle/lifecycle.go +++ b/internal/lifecycle/lifecycle.go @@ -38,6 +38,29 @@ func WaitForShutdown( wg.Wait() }() + return waitDone(ctx, log, component, done) +} + +// waitDone waits for done to close, bounded by ctx. +// +// The non-blocking preamble is load-bearing. When the component has +// already drained and ctx has already expired, both cases of the +// bounded select are ready and Go picks between them uniformly at +// random, so a clean shutdown would be reported as a timeout about +// half the time. Draining wins: the goroutines are gone, and there +// is nothing left for the operator to act on. +func waitDone( + ctx context.Context, + log *slog.Logger, + component string, + done <-chan struct{}, +) error { + select { + case <-done: + return nil + default: + } + select { case <-done: return nil diff --git a/internal/lifecycle/lifecycle_test.go b/internal/lifecycle/lifecycle_test.go index ca327e3..db5a7cf 100644 --- a/internal/lifecycle/lifecycle_test.go +++ b/internal/lifecycle/lifecycle_test.go @@ -37,6 +37,57 @@ func TestWaitForShutdown_DrainedGroup(t *testing.T) { ) } +// racePasses is how many times the both-cases-ready race is run. +// Without the preamble each pass is an independent coin flip, so +// the probability of the whole loop passing by luck is 2^-N: at +// this N the test is deterministic in practice, and it involves no +// wall-clock waiting at all. +const racePasses = 1000 + +// TestWaitDone_DrainedBeforeExpiredContext covers the case where a +// component drained cleanly but the stop context had already +// expired. Both select cases are ready, and Go chooses among ready +// cases uniformly at random, so the drained case must be settled by +// the preamble before the bounded select ever runs. +func TestWaitDone_DrainedBeforeExpiredContext(t *testing.T) { + t.Parallel() + + done := make(chan struct{}) + close(done) + + ctx, cancel := context.WithCancel(context.Background()) + cancel() + + for pass := range racePasses { + require.NoErrorf( + t, + lifecycle.WaitDone( + ctx, discardLogger(), "test component", done, + ), + "pass %d reported a timeout for a drained component", + pass, + ) + } +} + +// TestWaitDone_ExpiredContext pins the other side of the preamble: +// an expired context with a component that has not drained is still +// a timeout. +func TestWaitDone_ExpiredContext(t *testing.T) { + t.Parallel() + + ctx, cancel := context.WithCancel(context.Background()) + cancel() + + err := lifecycle.WaitDone( + ctx, discardLogger(), "test component", + make(chan struct{}), + ) + + require.ErrorIs(t, err, context.Canceled) + require.ErrorContains(t, err, "test component") +} + func TestWaitForShutdown_ContextExpires(t *testing.T) { t.Parallel()