Graceful shutdown is not blocking. #2897
Description
In the website there is an example of how to do a graceful shutdown.
Note that I'm talking about the echo.StartConfig{}.Start() function!
But the example code is terminating the program immediately after an interrupt signal has been received and is not waiting that 5 seconds, so the graceful shutdown is not happening.
I read the source and I think that server.Shutdown(waitShutdownCtx) is causing the server.Serve(listener) to stop listening for new connections and return immediately. So, while that happens, the server.Shutdown(waitShutdownCtx) is still waiting for existing connection to finish, but since that is happening in a goroutine, nothing stops the rest of the code to continue (it is not blocking).
I suggest to rewrite the logic of that code so that the echo.StartConfig{}.Start() function blocks as expected. I mean, the gracefulShutdown() function/goroutine should singnal the parent function that it has done it's job and only then the parent function should return (stop blocking).
I found this commend in the standard net/http library:
// Shutdown gracefully shuts down the server without interrupting any
// active connections. Shutdown works by first closing all open
// listeners, then closing all idle connections, and then waiting
// indefinitely for connections to return to idle and then shut down.
// If the provided context expires before the shutdown is complete,
// Shutdown returns the context's error, otherwise it returns any
// error returned from closing the [Server]'s underlying Listener(s).
//
// When Shutdown is called, [Serve], [ServeTLS], [ListenAndServe], and
// [ListenAndServeTLS] immediately return [ErrServerClosed]. Make sure the
// program doesn't exit and waits instead for Shutdown to return.
So, I expect the echo.StartConfig{}.Start() function to block until the inner server.Shutdown(waitShutdownCtx) returns. Otherwise there is no way to tell when it has returned. 😉 🤷
The example code found in the website:
package main
import (
"context"
"errors"
"net/http"
"os"
"os/signal"
"syscall"
"time"
"github.com/labstack/echo/v5"
)
func main() {
// Setup
e := echo.New()
e.GET("/", func(c *echo.Context) error {
time.Sleep(5 * time.Second)
return c.JSON(http.StatusOK, "OK")
})
ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM)
defer stop()
sc := echo.StartConfig{
Address: ":1323",
GracefulTimeout: 5 * time.Second,
}
if err := sc.Start(ctx, e); err != nil {
e.Logger.Error("failed to start server", "error", err)
}
}Code snippet from file server.go:
func (sc StartConfig) Start(ctx stdContext.Context, h http.Handler) error {
return sc.start(ctx, h)
}
func (sc StartConfig) start(ctx stdContext.Context, h http.Handler) error {
var logger *slog.Logger
if e, ok := h.(*Echo); ok {
logger = e.Logger
} else {
logger = slog.New(slog.NewJSONHandler(os.Stdout, nil))
}
server := http.Server{
Handler: h,
ErrorLog: slog.NewLogLogger(logger.Handler(), slog.LevelError),
// defaults for GoSec rule G112 // https://github.com/securego/gosec
// G112 (CWE-400): Potential Slowloris Attack because ReadHeaderTimeout is not configured in the http.Server
ReadTimeout: 30 * time.Second,
WriteTimeout: 30 * time.Second,
}
listenerNetwork := sc.ListenerNetwork
if listenerNetwork == "" {
listenerNetwork = "tcp"
}
var listener net.Listener
var err error
if sc.TLSConfig != nil {
listener, err = tls.Listen(listenerNetwork, sc.Address, sc.TLSConfig)
} else {
listener, err = net.Listen(listenerNetwork, sc.Address)
}
if err != nil {
return err
}
if sc.ListenerAddrFunc != nil {
sc.ListenerAddrFunc(listener.Addr())
}
if sc.BeforeServeFunc != nil {
if err := sc.BeforeServeFunc(&server); err != nil {
_ = listener.Close()
return err
}
}
if !sc.HideBanner {
bannerText := fmt.Sprintf(banner, Version)
logger.Info(bannerText, "version", Version)
}
if !sc.HidePort {
logger.Info("http(s) server started", "address", listener.Addr().String())
}
if sc.GracefulTimeout >= 0 {
gCtx, cancel := stdContext.WithCancel(ctx) // end goroutine when Serve returns early
defer cancel()
go gracefulShutdown(gCtx, &sc, &server, logger)
}
if err := server.Serve(listener); err != nil && !errors.Is(err, http.ErrServerClosed) {
return err
}
return nil
}
func gracefulShutdown(shutdownCtx stdContext.Context, sc *StartConfig, server *http.Server, logger *slog.Logger) {
<-shutdownCtx.Done() // wait until shutdown context is closed.
// note: is server if closed by other means this method is still run but is good as no-op
timeout := sc.GracefulTimeout
if timeout == 0 {
timeout = 10 * time.Second
}
waitShutdownCtx, cancel := stdContext.WithTimeout(stdContext.Background(), timeout)
defer cancel()
if err := server.Shutdown(waitShutdownCtx); err != nil {
// we end up here when listeners are not shut down within given timeout
if sc.OnShutdownError != nil {
sc.OnShutdownError(err)
return
}
logger.Error("failed to shut down server within given timeout", "error", err)
}
}