diff --git a/modules/caddyhttp/app.go b/modules/caddyhttp/app.go index 3f2da4e64..04d614823 100644 --- a/modules/caddyhttp/app.go +++ b/modules/caddyhttp/app.go @@ -716,6 +716,10 @@ func (w stdlibLogRouter) Write(p []byte) (int, error) { // Stop gracefully shuts down the HTTP server. func (app *App) Stop() error { + return app.stop(caddy.Exiting()) +} + +func (app *App) stop(exiting bool) error { ctx := context.Background() // see if any listeners in our config will be closing or if they are continuing @@ -747,11 +751,18 @@ func (app *App) Stop() error { } // enforce grace period if configured + var finishedShutdown sync.WaitGroup if app.GracePeriod > 0 { var cancel context.CancelFunc timeout := time.Duration(app.GracePeriod) ctx, cancel = context.WithTimeoutCause(ctx, timeout, fmt.Errorf("server graceful shutdown %ds timeout", int(timeout.Seconds()))) - defer cancel() + defer func() { + // A reload must leave the grace period alive while its requests finish. + go func() { + finishedShutdown.Wait() + cancel() + }() + }() app.logger.Info("servers shutting down; grace period initiated", zap.Duration("duration", timeout)) } else { app.logger.Info("servers shutting down with eternal grace period") @@ -765,7 +776,7 @@ func (app *App) Stop() error { // old servers are no longer accepting new connections // (* the scheduler might still pause them right before // calling Shutdown(), but it's unlikely) - var startedShutdown, finishedShutdown sync.WaitGroup + var startedShutdown sync.WaitGroup // these will run in goroutines stopServer := func(server *Server) { @@ -829,6 +840,14 @@ func (app *App) Stop() error { go stopH3Server(server) } + shutdownDone := make(chan struct{}) + pendingServerShutdowns.Store(shutdownDone, struct{}{}) + go func() { + finishedShutdown.Wait() + close(shutdownDone) + pendingServerShutdowns.Delete(shutdownDone) + }() + // block until all the goroutines have been run by the scheduler; // this means that they have likely called Shutdown() by now startedShutdown.Wait() @@ -840,8 +859,19 @@ func (app *App) Stop() error { // if the process isn't exiting (but note that frequent config // reloads with long grace periods for a sustained length of time // may deplete resources) - if caddy.Exiting() { + if exiting { finishedShutdown.Wait() + + // Responses from earlier configurations must finish before the process exits. + pendingServerShutdowns.Range(func(done, _ any) bool { + select { + case <-done.(chan struct{}): + return true + case <-ctx.Done(): + app.logger.Error("waiting for previous server shutdowns", zap.Error(context.Cause(ctx))) + return false + } + }) } // run stop callbacks now that the server shutdowns are complete @@ -910,6 +940,9 @@ const ( defaultWriteIdleTimeout = caddy.Duration(time.Minute) ) +// Reloads outlive their app, so termination must track shutdowns across configurations. +var pendingServerShutdowns sync.Map + // Interface guards var ( _ caddy.App = (*App)(nil) diff --git a/modules/caddyhttp/app_test.go b/modules/caddyhttp/app_test.go index f97b4cca7..b1819d24d 100644 --- a/modules/caddyhttp/app_test.go +++ b/modules/caddyhttp/app_test.go @@ -15,13 +15,134 @@ package caddyhttp import ( + "context" + "fmt" + "io" + "net/http" + "net/http/httptest" + "sync" "testing" + "time" + + "github.com/caddyserver/caddy/v2" "go.uber.org/zap" "go.uber.org/zap/zapcore" "go.uber.org/zap/zaptest/observer" ) +func TestStopWaitsForPreviousConfiguration(t *testing.T) { + for _, http2 := range []bool{false, true} { + for _, grace := range []time.Duration{0, 5 * time.Second} { + t.Run(fmt.Sprintf("http2=%t/grace=%s", http2, grace), func(t *testing.T) { + previous, response, release := appWithPendingResponse(t, http2) + previous.GracePeriod = caddy.Duration(grace) + if err := previous.stop(false); err != nil { + t.Fatal(err) + } + + current := &App{logger: zap.NewNop()} + stopped := make(chan error, 1) + go func() { stopped <- current.stop(true) }() + select { + case err := <-stopped: + t.Fatalf("termination returned while the previous response was active: %v", err) + case <-time.After(50 * time.Millisecond): + } + + release() + body, err := io.ReadAll(response.Body) + if err != nil { + t.Fatal(err) + } + if string(body) != "before\nafter\n" { + t.Fatalf("unexpected response body: %q", body) + } + select { + case err := <-stopped: + if err != nil { + t.Fatal(err) + } + case <-time.After(2 * time.Second): + t.Fatal("termination did not finish after the previous response completed") + } + }) + } + } +} + +func TestStopPreviousConfigurationGracePeriod(t *testing.T) { + previous, response, release := appWithPendingResponse(t, false) + if err := previous.stop(false); err != nil { + t.Fatal(err) + } + + current := &App{GracePeriod: caddy.Duration(50 * time.Millisecond), logger: zap.NewNop()} + stopped := make(chan error, 1) + start := time.Now() + go func() { stopped <- current.stop(true) }() + select { + case err := <-stopped: + if err != nil { + t.Fatal(err) + } + case <-time.After(2 * time.Second): + t.Fatal("termination ignored its grace period while waiting for the previous configuration") + } + if elapsed := time.Since(start); elapsed < time.Duration(current.GracePeriod) { + t.Errorf("termination returned after %s, before its grace period expired", elapsed) + } + + release() + if _, err := io.Copy(io.Discard, response.Body); err != nil { + t.Fatal(err) + } +} + +func appWithPendingResponse(t *testing.T, http2 bool) (*App, *http.Response, func()) { + t.Helper() + + released := make(chan struct{}) + release := sync.OnceFunc(func() { close(released) }) + server := httptest.NewUnstartedServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + fmt.Fprintln(w, "before") + http.NewResponseController(w).Flush() + select { + case <-released: + fmt.Fprintln(w, "after") + case <-r.Context().Done(): + } + })) + server.EnableHTTP2 = http2 + server.StartTLS() + t.Cleanup(server.Close) + t.Cleanup(release) + + request, err := http.NewRequestWithContext(t.Context(), http.MethodGet, server.URL, nil) + if err != nil { + t.Fatal(err) + } + response, err := server.Client().Do(request) + if err != nil { + t.Fatal(err) + } + t.Cleanup(func() { response.Body.Close() }) + if http2 && response.ProtoMajor != 2 { + t.Fatalf("expected HTTP/2, got %s", response.Proto) + } + app := &App{ + Servers: map[string]*Server{"test": {server: server.Config}}, + logger: zap.NewNop(), + } + t.Cleanup(func() { + release() + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) + defer cancel() + server.Config.Shutdown(ctx) + }) + return app, response, release +} + // TestServerErrorLoggerLevels verifies that recovered net/http handler panics // written to http.Server.ErrorLog surface at ERROR level (so they're visible // at the default log level), while other standard library server messages stay