Bug in listing 7.5 (graceful server shutdown)

[joergjo]

The sample will only work as intended if the server is shutdown within ~30 seconds after launching, because the context's deadline is set directly at server launch. Running the sample and waiting for > 30 seconds before hitting CTRL+C produces

2022/10/02 14:32:45 I started processing the request
^C2022/10/02 14:32:47 Got signal: interrupt. Server shutting down.
2022/10/02 14:32:47 Waiting for shutdown to complete...
2022/10/02 14:32:47 Error during shutdown: context deadline exceeded
2022/10/02 14:32:47 http: Server closed

The deadline to shutdown the server has been reached, but not because the clean shutdown took too long, but because the deadline was already exceeded when s.Shutdown(ctx) was called.

To fix this, context.WithTimeout() should be called in the shutdown function:

func shutdown(ctx context.Context, s *http.Server, waitForShutdownCompletion chan struct{}) {
	sigch := make(chan os.Signal, 1)
	signal.Notify(sigch, syscall.SIGINT, syscall.SIGTERM)
	sig := <-sigch
	log.Printf("Got signal: %v. Server shutting down.", sig)

	childCtx, cancel := context.WithTimeout(ctx, 30*time.Second)
	defer cancel()

	if err := s.Shutdown(childCtx); err != nil {
		log.Printf("Error during shutdown: %v", err)
	}
	waitForShutdownCompletion <- struct{}{}
}

func main() {
	listenAddr := os.Getenv("LISTEN_ADDR")
	if len(listenAddr) == 0 {
		listenAddr = ":8080"
	}

	waitForShutdownCompletion := make(chan struct{})

	mux := http.NewServeMux()
	mux.HandleFunc("/api/users/", handleUserAPI)

	s := http.Server{
		Addr:         listenAddr,
		Handler:      mux,
		ReadTimeout:  5 * time.Second,
		WriteTimeout: 5 * time.Second,
	}

	go shutdown(context.Background(), &s, waitForShutdownCompletion)

	err := s.ListenAndServe()
	log.Println("Waiting for shutdown to complete...")
	<-waitForShutdownCompletion
	log.Fatal(err)
}

[amitsaha]

Thanks @joergjo - correct catch indeed.

[amitsaha]

This is interesting indeed. I wonder how you managed to catch it? Was it just your knowledge of how the WithTimeout() works - i.e. by setting a deadline?

[joergjo]

This is interesting indeed. I wonder how you managed to catch it? Was it just your knowledge of how the WithTimeout() works - i.e. by setting a deadline?

As far as I remember, I ran the server and for whatever reason had it running long enough to exceed the deadline. I have tried various graceful shutdown techniques when building Go servers, so on second glance that context seemed misplaced.

[amitsaha]

Thanks a lot for filing the issue and bringing this to my attention, fixed in master, will create a new release now.