Compare commits
1 Commits
cc5836d1f9
...
c568441dc6
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
c568441dc6 |
76
README.md
76
README.md
@@ -1147,6 +1147,8 @@ webhooker/
|
||||
│ │ ├── archive_sweeper.go # Periodic pruning of idle archives
|
||||
│ │ ├── url_mask.go # Strips credentials from *url.Error
|
||||
│ │ └── ssrf.go # SSRF prevention (IP validation, safe HTTP transport)
|
||||
│ ├── lifecycle/
|
||||
│ │ └── lifecycle.go # Shared fx start/stop hook helpers
|
||||
│ ├── handlers/
|
||||
│ │ ├── handlers.go # Base handler struct, JSON helpers, template rendering
|
||||
│ │ ├── auth.go # Login, logout handlers
|
||||
@@ -1158,8 +1160,6 @@ 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/
|
||||
@@ -1319,78 +1319,6 @@ rather than global: **LoginRateLimit** on `/pages/login`,
|
||||
- GORM soft deletes on every entity that carries `BaseModel`, which is
|
||||
all of them but `Setting` (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 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
|
||||
4. `delivery.Engine`
|
||||
5. `healthcheck`
|
||||
6. `WebhookDBManager`
|
||||
7. the database close
|
||||
|
||||
The two components that can realistically hold the budget run
|
||||
first: a retention sweep or an archive prune caught mid-tick each
|
||||
waits on its `WaitGroup` bounded by the stop context, so a wedge
|
||||
there consumes the 5 seconds before the HTTP server hook is ever
|
||||
entered. The hooks after the server are microsecond-scale in normal
|
||||
operation.
|
||||
|
||||
The HTTP drain budget is deliberately **shorter** than the sequence
|
||||
budget. Were the two equal, a drain that used its whole budget would
|
||||
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.
|
||||
|
||||
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.
|
||||
|
||||
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.
|
||||
|
||||
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.
|
||||
|
||||
### Linting
|
||||
|
||||
golangci-lint never runs on the host. `script/lint` builds
|
||||
|
||||
@@ -2,8 +2,6 @@
|
||||
package main
|
||||
|
||||
import (
|
||||
"time"
|
||||
|
||||
"go.uber.org/fx"
|
||||
"sneak.berlin/go/webhooker/internal/config"
|
||||
"sneak.berlin/go/webhooker/internal/database"
|
||||
@@ -17,33 +15,6 @@ import (
|
||||
"sneak.berlin/go/webhooker/internal/session"
|
||||
)
|
||||
|
||||
// stopTimeout bounds the whole fx stop sequence, not each hook.
|
||||
//
|
||||
// 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; the observed wedge case already exits at ~5.3s,
|
||||
// so a larger bound would trade a rare skipped database close for
|
||||
// a more common hard kill.
|
||||
//
|
||||
// The server's stop hook must fit inside it with room to spare: a
|
||||
// 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
|
||||
// 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.
|
||||
// TestStopTimeout_LeavesHeadroomForTailHooks pins the arithmetic
|
||||
// across every drain length.
|
||||
//
|
||||
// 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.
|
||||
const stopTimeout = 5 * time.Second
|
||||
|
||||
// Build-time variables set via -ldflags.
|
||||
//
|
||||
//nolint:gochecknoglobals // Build-time variables injected by the linker.
|
||||
@@ -56,14 +27,7 @@ func main() {
|
||||
globals.Appname = appname
|
||||
globals.Version = version
|
||||
|
||||
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.New(
|
||||
fx.Provide(
|
||||
globals.New,
|
||||
logger.New,
|
||||
@@ -96,5 +60,5 @@ func newApp() *fx.App {
|
||||
) {
|
||||
},
|
||||
),
|
||||
)
|
||||
).Run()
|
||||
}
|
||||
|
||||
@@ -1,75 +0,0 @@
|
||||
package main
|
||||
|
||||
import (
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/stretchr/testify/require"
|
||||
"sneak.berlin/go/webhooker/internal/server"
|
||||
)
|
||||
|
||||
// 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)
|
||||
}
|
||||
|
||||
// tailHeadroom is the slack the fx stop budget must keep beyond the
|
||||
// server stop hook. The hooks that run after the server — the
|
||||
// delivery engine, the healthcheck, the webhook DB manager and the
|
||||
// database close — are microsecond-scale in normal operation, so
|
||||
// this is generous for them.
|
||||
const tailHeadroom = 2 * time.Second
|
||||
|
||||
// TestStopTimeout_LeavesHeadroomForTailHooks pins the relationship
|
||||
// between the server's stop hook and the fx stop budget. fx bounds
|
||||
// the whole stop sequence, and returns without running its
|
||||
// remaining hooks once the stop context has expired. If the hook
|
||||
// could use the entire budget, every later hook — the database close
|
||||
// included — would be skipped in exactly the case where the drain
|
||||
// mattered.
|
||||
//
|
||||
// The hook is not just the HTTP drain: a Sentry flush follows it in
|
||||
// the same hook, and sentry.Flush honours no context, so both halves
|
||||
// have to be counted. The sweep walks every drain length the hook
|
||||
// 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.
|
||||
func TestStopTimeout_LeavesHeadroomForTailHooks(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
require.Less(t, server.ShutdownTimeout, stopTimeout)
|
||||
|
||||
const step = 10 * time.Millisecond
|
||||
|
||||
for drain := time.Duration(0); drain <= server.ShutdownTimeout; drain += step {
|
||||
hook := drain + server.SentryFlushBudget(stopTimeout-drain)
|
||||
|
||||
require.LessOrEqual(
|
||||
t, hook+tailHeadroom, stopTimeout,
|
||||
"a %s drain leaves the tail hooks short", drain,
|
||||
)
|
||||
}
|
||||
}
|
||||
@@ -1,21 +0,0 @@
|
||||
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,29 +38,6 @@ 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
|
||||
|
||||
@@ -37,57 +37,6 @@ 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()
|
||||
|
||||
|
||||
@@ -24,48 +24,15 @@ import (
|
||||
)
|
||||
|
||||
const (
|
||||
// ShutdownTimeout is the maximum time to wait for the HTTP
|
||||
// shutdownTimeout is the maximum time to wait for the HTTP
|
||||
// server to finish in-flight requests during shutdown.
|
||||
//
|
||||
// It must stay strictly below the fx stop timeout in
|
||||
// cmd/webhooker, which bounds the whole stop sequence: a drain
|
||||
// that used the entire sequence budget would leave nothing for
|
||||
// the hooks that run after the server, including the database
|
||||
// close. It is exported so that relationship can be tested.
|
||||
ShutdownTimeout = 3 * time.Second
|
||||
shutdownTimeout = 5 * time.Second
|
||||
|
||||
// TailHookReserve is the share of the fx stop budget this hook
|
||||
// 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.
|
||||
TailHookReserve = 2 * time.Second
|
||||
|
||||
// sentryFlushTimeout is the longest wait for Sentry to flush
|
||||
// pending events during shutdown, before the remaining stop
|
||||
// budget is taken into account.
|
||||
// sentryFlushTimeout is the maximum time to wait for Sentry
|
||||
// to flush pending events during shutdown.
|
||||
sentryFlushTimeout = 2 * time.Second
|
||||
|
||||
// minSentryFlush is the shortest flush worth attempting. Below
|
||||
// it the remaining budget goes to the tail hooks instead.
|
||||
minSentryFlush = 250 * time.Millisecond
|
||||
)
|
||||
|
||||
// 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,
|
||||
// so this clamp is the only thing keeping a stalled flush from
|
||||
// spending the tail hooks' share of the budget on top of a
|
||||
// full-length drain. TailHookReserve is held back, and anything
|
||||
// under minSentryFlush is skipped rather than attempted uselessly.
|
||||
func SentryFlushBudget(remaining time.Duration) time.Duration {
|
||||
budget := min(remaining-TailHookReserve, sentryFlushTimeout)
|
||||
if budget < minSentryFlush {
|
||||
return 0
|
||||
}
|
||||
|
||||
return budget
|
||||
}
|
||||
|
||||
//nolint:revive // ServerParams is a standard fx naming convention.
|
||||
type ServerParams struct {
|
||||
fx.In
|
||||
@@ -197,7 +164,7 @@ func (s *Server) cleanShutdown(ctx context.Context) {
|
||||
s.exitCode = 0
|
||||
|
||||
ctxShutdown, shutdownCancel := context.WithTimeout(
|
||||
ctx, ShutdownTimeout,
|
||||
ctx, shutdownTimeout,
|
||||
)
|
||||
defer shutdownCancel()
|
||||
|
||||
@@ -211,31 +178,10 @@ func (s *Server) cleanShutdown(ctx context.Context) {
|
||||
s.cleanupForExit()
|
||||
|
||||
if s.sentryEnabled {
|
||||
s.flushSentry(ctx)
|
||||
sentry.Flush(sentryFlushTimeout)
|
||||
}
|
||||
}
|
||||
|
||||
// flushSentry drains Sentry's queue inside what is left of the fx
|
||||
// stop budget. A context carrying no deadline — a caller outside the
|
||||
// fx lifecycle — gets the full timeout.
|
||||
func (s *Server) flushSentry(ctx context.Context) {
|
||||
flush := sentryFlushTimeout
|
||||
|
||||
if deadline, ok := ctx.Deadline(); ok {
|
||||
flush = SentryFlushBudget(time.Until(deadline))
|
||||
}
|
||||
|
||||
if flush <= 0 {
|
||||
s.log.Warn(
|
||||
"skipping sentry flush, stop budget exhausted",
|
||||
)
|
||||
|
||||
return
|
||||
}
|
||||
|
||||
sentry.Flush(flush)
|
||||
}
|
||||
|
||||
func (s *Server) configure() {
|
||||
// identify ourselves in the logs
|
||||
s.params.Logger.Identify()
|
||||
|
||||
@@ -1,59 +0,0 @@
|
||||
package server_test
|
||||
|
||||
import (
|
||||
"testing"
|
||||
"time"
|
||||
|
||||
"github.com/stretchr/testify/require"
|
||||
"sneak.berlin/go/webhooker/internal/server"
|
||||
)
|
||||
|
||||
// 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
|
||||
// stalled flush adds its whole timeout on top of the HTTP drain.
|
||||
func TestSentryFlushBudget(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
tests := []struct {
|
||||
name string
|
||||
remaining time.Duration
|
||||
want time.Duration
|
||||
}{
|
||||
{
|
||||
name: "full drain leaves only the reserve",
|
||||
remaining: server.TailHookReserve,
|
||||
want: 0,
|
||||
},
|
||||
{
|
||||
name: "expired budget",
|
||||
remaining: -time.Second,
|
||||
want: 0,
|
||||
},
|
||||
{
|
||||
name: "sliver above the reserve is not worth it",
|
||||
remaining: server.TailHookReserve + 10*time.Millisecond,
|
||||
want: 0,
|
||||
},
|
||||
{
|
||||
name: "partial flush when some room is left",
|
||||
remaining: server.TailHookReserve + time.Second,
|
||||
want: time.Second,
|
||||
},
|
||||
{
|
||||
name: "capped at the nominal timeout",
|
||||
remaining: time.Hour,
|
||||
want: 2 * time.Second,
|
||||
},
|
||||
}
|
||||
|
||||
for _, tt := range tests {
|
||||
t.Run(tt.name, func(t *testing.T) {
|
||||
t.Parallel()
|
||||
|
||||
require.Equal(
|
||||
t, tt.want, server.SentryFlushBudget(tt.remaining),
|
||||
)
|
||||
})
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user