Set fx.StopTimeout inside the container stop grace (closes #134)
All checks were successful
check / check (push) Successful in 3m16s
All checks were successful
check / check (push) Successful in 3m16s
fx defaults the stop timeout to 15s and the Dockerfile sets no STOPSIGNAL or grace override, so Docker's 10s default SIGKILLs the process five seconds before the bound can fire. Everything gated on it — including the "shutdown timed out, goroutines still running" error log that tells an operator a component is wedged — was unreachable in the image this repo produces. Set fx.StopTimeout to 5s: inside the grace with headroom for signal delivery and process exit, and equal to the HTTP server's own drain budget so the first hook can spend its whole budget without the sequence bound truncating it. The option set moves into newApp() so a test can read (*fx.App).StopTimeout() back and pin it against drift; dropping the option makes that test report fx's 15s default. Also fix a latent coin flip in the shared stop-hook waiter. It selected on the drained channel against ctx.Done() with no preamble, and select picks uniformly among ready cases, so a component that drained against an already-expired context reported a timeout about half the time. Not reachable through fx, which re-checks ctx.Err() before each hook, but the helper is shared and a direct caller can reach it. waitDone now settles the drained case in a non-blocking preamble first; the test drives it over 1000 passes, so a restored coin flip cannot pass by luck. README records the timeout and its relationship to the container stop grace: that lowering the grace below it puts SIGKILL back in front of the bound, and that an expired stop context makes fx skip its remaining hooks, so a wedge in the first-stopped component means the database close never runs. Adds the missing internal/lifecycle/ entry to the Package Layout tree.
This commit is contained in:
35
README.md
35
README.md
@@ -1040,6 +1040,8 @@ webhooker/
|
|||||||
│ │ └── webhook.go # Webhook receiver handler
|
│ │ └── webhook.go # Webhook receiver handler
|
||||||
│ ├── healthcheck/
|
│ ├── healthcheck/
|
||||||
│ │ └── healthcheck.go # Health check service (uptime, version)
|
│ │ └── healthcheck.go # Health check service (uptime, version)
|
||||||
|
│ ├── lifecycle/
|
||||||
|
│ │ └── lifecycle.go # Shared stop-hook waiter, bounded by the stop context
|
||||||
│ ├── logger/
|
│ ├── logger/
|
||||||
│ │ └── logger.go # slog setup with TTY detection
|
│ │ └── logger.go # slog setup with TTY detection
|
||||||
│ ├── middleware/
|
│ ├── middleware/
|
||||||
@@ -1165,6 +1167,39 @@ downstream at form-parse time.
|
|||||||
- Container runs as non-root user (UID 1000)
|
- Container runs as non-root user (UID 1000)
|
||||||
- GORM soft deletes on all entities (data preserved for audit)
|
- 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
|
### Docker
|
||||||
|
|
||||||
The Dockerfile uses a multi-stage build:
|
The Dockerfile uses a multi-stage build:
|
||||||
|
|||||||
@@ -2,6 +2,8 @@
|
|||||||
package main
|
package main
|
||||||
|
|
||||||
import (
|
import (
|
||||||
|
"time"
|
||||||
|
|
||||||
"go.uber.org/fx"
|
"go.uber.org/fx"
|
||||||
"sneak.berlin/go/webhooker/internal/config"
|
"sneak.berlin/go/webhooker/internal/config"
|
||||||
"sneak.berlin/go/webhooker/internal/database"
|
"sneak.berlin/go/webhooker/internal/database"
|
||||||
@@ -15,6 +17,17 @@ import (
|
|||||||
"sneak.berlin/go/webhooker/internal/session"
|
"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.
|
// Build-time variables set via -ldflags.
|
||||||
//
|
//
|
||||||
//nolint:gochecknoglobals // Build-time variables injected by the linker.
|
//nolint:gochecknoglobals // Build-time variables injected by the linker.
|
||||||
@@ -27,7 +40,14 @@ func main() {
|
|||||||
globals.Appname = appname
|
globals.Appname = appname
|
||||||
globals.Version = version
|
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(
|
fx.Provide(
|
||||||
globals.New,
|
globals.New,
|
||||||
logger.New,
|
logger.New,
|
||||||
@@ -60,5 +80,5 @@ func main() {
|
|||||||
) {
|
) {
|
||||||
},
|
},
|
||||||
),
|
),
|
||||||
).Run()
|
)
|
||||||
}
|
}
|
||||||
|
|||||||
33
cmd/webhooker/main_test.go
Normal file
33
cmd/webhooker/main_test.go
Normal file
@@ -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)
|
||||||
|
}
|
||||||
21
internal/lifecycle/export_test.go
Normal file
21
internal/lifecycle/export_test.go
Normal file
@@ -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)
|
||||||
|
}
|
||||||
@@ -38,6 +38,29 @@ func WaitForShutdown(
|
|||||||
wg.Wait()
|
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 {
|
select {
|
||||||
case <-done:
|
case <-done:
|
||||||
return nil
|
return nil
|
||||||
|
|||||||
@@ -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) {
|
func TestWaitForShutdown_ContextExpires(t *testing.T) {
|
||||||
t.Parallel()
|
t.Parallel()
|
||||||
|
|
||||||
|
|||||||
Reference in New Issue
Block a user