In this article we explre how to build a server in go that has Logging, tracing heath check and Graceful shutdowns from scratch with the standard library.

Aug 13, 2024

Kevin Kelche

The Ultimate Go HTTP Server Tutorial: Logging, Tracing, and More

In this tutorial, you’ll learn how to build a robust and production-ready HTTP server in Go. We’ll start with a simple “Hello, World!” server and gradually add features like logging, tracing, health checks, and graceful shutdown. By the end, you’ll have a solid foundation for building scalable and reliable web services in Go.

We’ll be using only the standard library, so you won’t need any external dependencies. The Go version used in this tutorial is the new Go 1.22.0, that introduces some new features in the net/http package. Let’s get started!

The Barebones “Hello, World!” Server

Let’s start with the simplest possible HTTP server in Go:

package main

import (
  "fmt"
  "net/http"
)

func handler(w http.ResponseWriter, r *http.Request) {
  fmt.Fprintf(w, "Hello, World!\n")
}

func main() {
  http.HandleFunc("GET /", handler)
  http.ListenAndServe(":8080", nil)
}

This basic server listens on port 8080 and responds with “Hello, World!” to any request. Let’s break it down:

The handler function is called for each incoming request. It takes two parameters:
- w http.ResponseWriter: An interface to write the response.
- r *http.Request: A struct containing information about the incoming request.
In the main function:
- http.HandleFunc("GET /", handler) registers our handler function to handle all the GET requests (the “GET /” path). In the older versions of you Go you had to use http.HandleFunc("/", handler) to register the handler for all the requests. After that you had to check the request method and the request path inside the handler function.
- http.ListenAndServe(":8080", nil) starts the server on port 8080.

By running your application and calling the server with curl -X GET http://localhost:8080 you should see the response Hello, World!.

$ go run main.go

$ curl -X GET http://localhost:8080
> Hello, World!

While this server works, it’s very basic. In a production environment, we’d want more features for better observability and robustness.

Adding Logging

Logging is crucial for understanding what’s happening in your server. It helps with debugging, monitoring, and auditing. Let’s add some basic logging:

package main

import (
  "fmt"
  "log"
  "net/http"
  "os"
)

func handler(w http.ResponseWriter, r *http.Request) {
  fmt.Fprintf(w, "Hello, World!\n")
}

func main() {
  logger := log.New(os.Stdout, "http: ", log.LstdFlags)
  http.HandleFunc("/", handler)
  logger.Println("Server is starting...")
  err := http.ListenAndServe(":8080", nil)
  if err != nil {
    logger.Fatal("ListenAndServe: ", err)
  }
}

Here’s what’s new:

We import the log package for logging and os to write logs to standard output.
We create a custom logger with log.New():
- os.Stdout directs logs to standard output. You can also write logs to other destinations like files or databases.
- "http: " is a prefix for our log messages.
- log.LstdFlags includes the date and time in each log entry.
We log when the server starts and if there’s an error while starting.

This simple logging setup will help you track when your server starts and stops, and catch any startup errors.

Logging Request Details

Now, let’s enhance our logging to capture details about each request:

func handler(w http.ResponseWriter, r *http.Request) {
  logger = log.New(os.Stdout, "http: ", log.LstdFlags)
  logger.Printf("Received request: %s %s from %s", r.Method, r.URL.Path, r.RemoteAddr)
  fmt.Fprintf(w, "Hello, World!\n")
}

This addition will log the HTTP method, URL path, and client IP address for each request. Here’s what each part means:

r.Method: The HTTP method (GET, POST, PUT, etc.)
r.URL.Path: The path part of the URL
r.RemoteAddr: The IP address of the client making the request

Logging these details can help you understand traffic patterns, identify potential issues, and debug problems when they occur. In prod you can create a logger package that will be used in all your handlers. That is not in the scope of this tutorial.

If you know run the app and call the server with curl -X GET http://localhost:8080, you should see the request details in the logs:

$ go run main.go

$ curl -X GET http://localhost:8080

> http: 2024/08/13 14:11:56 Received request: GET /, from [::1]:45440

Adding a Health Check Endpoint

A health check endpoint is essential for monitoring the server’s status, especially in containerized or microservices environments:

...
func healthCheck(w http.ResponseWriter, r *http.Request) {
  w.WriteHeader(http.StatusNoContent)
}

func main() {
  
  http.HandleFunc("GET /", handler)
  http.HandleFunc("GET /healthz", healthCheck)
  logger = log.New(os.Stdout, "http: ", log.LstdFlags)
  logger.Println("Server is starting...")
  logger.Println("Server is ready to handle requests at :8080")

  err := http.ListenAndServe(":8080", nil)

  if err != nil {
    logger.Fatal("ListenAndServe: ", err)
  }
}

This adds a GET /healthz endpoint that returns a 204 No Content status. Here’s why this is useful:

It provides a simple way for external systems (like Kubernetes) to check if your server is running.
The 204 status means “everything is OK, but I have nothing to say” - perfect for a health check.
By convention, many systems use /healthz as the health check endpoint.

In more complex applications, you might want your health check to verify database connections, check memory usage, or perform other system checks before reporting as healthy.

To test this end point start your server and run curl -v http://localhost:8080/healthz:

$ go run main.go

*   Trying 127.0.0.1:8080...
* Connected to localhost (127.0.0.1) port 8080 (#0)
> GET /healthz HTTP/1.1
> Host: localhost:8080
> User-Agent: curl/7.81.0
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 204 No Content
< Date: Tue, 13 Aug 2024 15:36:42 GMT
< 
* Connection #0 to host localhost left intact

Implementing Graceful Shutdown

Graceful shutdown allows your server to finish processing ongoing requests before stopping. This is crucial for maintaining data integrity and providing a good user experience.

func main() {

  http.HandleFunc("GET /", handler)
  http.HandleFunc("GET /healthz", healthCheck)

  logger := log.New(os.Stdout, "http: ", log.LstdFlags)
  logger.Println("Server is starting...")
  logger.Println("Server is ready to handle requests at :8080")

  err := http.ListenAndServe(":8080", nil)
  if err != nil {
    logger.Fatal("ListenAndServe: ", err)
  }

  server := &http.Server{
    Addr:         ":8080",
    Handler:      nil,
    ReadTimeout:  5 * time.Second,
    WriteTimeout: 10 * time.Second,
    IdleTimeout:  15 * time.Second,
  }

  done := make(chan bool)
  quit := make(chan os.Signal, 1)
  signal.Notify(quit, syscall.SIGINT, syscall.SIGTERM)

  go func() {
    <-quit
    logger.Println("Server is shutting down...")

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

    server.SetKeepAlivesEnabled(false)
    if err := server.Shutdown(ctx); err != nil {
      logger.Fatalf("Could not gracefully shutdown the server: %v\n", err)
    }
    close(done)
  }()

  logger.Println("Server is ready to handle requests at :8080")
  if err := server.ListenAndServe(); err != nil && err != http.ErrServerClosed {
    logger.Fatalf("Could not listen on :8080: %v\n", err)
  }

  <-done
  logger.Println("Server stopped")
}

This setup is more complex, but it’s worth understanding:

We create an http.Server instance with custom timeouts for reading, writing, and idling.
We set up a done channel to signal when the server has stopped.
We create a quit channel to listen for SIGINT and SIGTERM signals (e.g., from Ctrl+C or a container orchestrator).
We start a goroutine to listen for these signals and gracefully shut down the server when they’re received.
We call server.ListenAndServe() to start the server. This will block until the server is shut down.
We wait for the done signal to indicate that the server has stopped.

We are using channels to communicate between the main goroutine and the signal handling goroutine. We have also introduced some new packages like context, os, and syscall to handle the graceful shutdown. The context package is used to manage the lifecycle of the shutdown process. We use the os package to handle signals, and the syscall package to define the signals we want to listen for.

Now, when you stop the server with Ctrl+C, it will wait for ongoing requests to complete before shutting down. This ensures that no data is lost and that users don’t experience any interruptions.

$ go run main.go
http: 2024/08/13 19:31:37 Server starting at port 8080 ...
^C2024/08/13 19:31:44 Server is shutting down ....
http: 2024/08/13 19:31:44 Server stopped

Adding Tracing

Request tracing helps in debugging and monitoring by allowing you to follow a request through your system.

To add tracing we’ll introduce the concept of middleware in Go. You can think of middleware as a layer that wraps around your HTTP handler to add extra functionality. We’ll create two middleware functions: one for tracing requests and another for logging request details.

//imports 
...
type key int

const (
  requestIDKey key = 0
)

func tracing(nextReuestID func() string) func(http.Handler) http.Handler {
  return func(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
      requestID := r.Header.Get("X-Request-Id")
      if requestID == "" {
        requestID = nextReuestID()
      }
      ctx := context.WithValue(r.Context(), requestIDKey, requestID)
      w.Header().Set("X-Request-Id", requestID)
      next.ServeHTTP(w, r.WithContext(ctx))
    })
  }
}

func logging(logger *log.Logger) func(http.Handler) http.Handler {
  return func(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
      defer func() {
        requestID, ok := r.Context().Value(requestIDKey).(string)
        if !ok {
          requestID = "unknown"
        }

        logger.Println(requestID, r.Method, r.URL.Path, r.RemoteAddr, r.UserAgent())
      }()
      next.ServeHTTP(w, r)
    })
  }
}

func main() {
  http.HandleFunc("GET /", handler)
  http.HandleFunc("GET /healthz", heathCheck)
  logger := log.New(os.Stdout, "http: ", log.LstdFlags)

  nextRequestID := func() string {
    return strconv.FormatInt(time.Now().UnixNano(), 10)
  }
  server := &http.Server{
    Addr:         ":8080",
    Handler:      tracing(nextRequestID)(logging(logger)(http.DefaultServeMux)),
    ReadTimeout:  5 * time.Second,
    WriteTimeout: 10 * time.Second,
    IdleTimeout:  15 * time.Second,
  }

  done := make(chan bool)
  quit := make(chan os.Signal, 1)
  signal.Notify(quit, syscall.SIGINT, syscall.SIGTERM)

  go func() {
    <-quit
    log.Println("Server is shutting down ....")
    ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second)

    defer cancel()
    server.SetKeepAlivesEnabled(false)
    if err := server.Shutdown(ctx); err != nil {
      logger.Fatalf("Could not gracefully shutdown the server %+v\n", err)
    }
    close(done)
  }()

  logger.Println("Server starting at port 8080 ...")

  if err := server.ListenAndServe(); err != nil && err != http.ErrServerClosed {
    logger.Fatalf("Could not listen on :8080 %+v\n", err)
  }

  <-done
  logger.Println("Server stopped")
}

The tracing and logging functions are middleware functions that wrap around the default HTTP handler. Here’s what they do:

tracing: Adds a unique request ID to each request. If the request already has an ID (from a previous middleware), it uses that. Otherwise, it generates a new ID.
logging: Logs request details, including the request ID, method, path, client IP address, and user agent. It uses the request ID generated by the tracing middleware.
In the main function:
- We create a nextRequestID function that generates a unique request ID based on the current time.
- We wrap the default HTTP handler with the tracing and logging middleware functions.
- We pass the wrapped handler to the http.Server instance.
- We update the Handler in the http.Server to use the wrapped handler.

Now, when you run the server and make a request, you should see the request details logged with a unique request ID:

http: 2024/08/13 20:35:37 Server starting at port 8080 ...
http: 2024/08/13 20:35:47 Received request: GET /, from 127.0.0.1:35094
http: 2024/08/13 20:35:47 1723570547992347359 GET / 127.0.0.1:35094 curl/7.81.0
http: 2024/08/13 20:35:59 Received request: GET /, from 127.0.0.1:41502
http: 2024/08/13 20:35:59 1723570559989523626 GET / 127.0.0.1:41502 curl/7.81.0
http: 2024/08/13 20:36:05 1723570565000852585 GET /healthz 127.0.0.1:41504 curl/7.81.0
http: 2024/08/13 20:36:11 1723570571838457788 GET /healthz 127.0.0.1:56856 curl/7.81.0

In production, you can use a more sophisticated tracing system like OpenTelemetry or Jaeger to track requests across multiple services. These systems provide detailed insights into request latency, error rates, and service dependencies.

Updating the Health Check

Finally, let’s make our health check more meaningful by allowing it to reflect the server’s true state:

...
var healthy int32

func healthCheck(w http.ResponseWriter, r *http.Request) {
  if atomic.LoadInt32(&healthy) == 1 {
    w.WriteHeader(http.StatusNoContent)
    return
  }
  w.WriteHeader(http.StatusServiceUnavailable)
}

func main() {
  // ... (previous code)

  // Set server to healthy
  atomic.StoreInt32(&healthy, 1)

  go func() {
    <-quit
    logger.Println("Server is shutting down...")
    atomic.StoreInt32(&healthy, 0)
    // ... (rest of shutdown code)
  }()

  // ... (rest of main function)
}

This update allows the server to report its health status accurately, even during shutdown. Here’s what’s happening:

We use an atomic integer to track the server’s health status.
The healthCheck checks this status and returns either 204 (healthy) or 503 (unhealthy).
We set the server to healthy when it starts.
During shutdown, we set the server to unhealthy before beginning the shutdown process.

This approach ensures that your health check accurately reflects whether the server is ready to accept new requests, which is crucial for proper load balancing and orchestration in distributed systems.

Conclusion

The compiled code can be found here.

Congratulations! You’ve now built a robust and observably awesome Go HTTP server. This server includes essential features that make it production-ready:

Comprehensive logging for debugging and monitoring
Request tracing for tracking requests through your system
A configurable health check endpoint for integration with orchestration systems
Graceful shutdown to ensure in-flight requests are completed

These features will make your server more reliable, easier to debug, and simpler to monitor in production environments. As you continue to develop your Go skills, consider adding more advanced features like:

Metrics collection and reporting (e.g., with Prometheus - we’ll cover this in a future tutorial)
Rate limiting to protect your server from overload
Authentication and authorization for secure access
Database connection pooling for efficient resource use
Caching mechanisms to improve performance

Just remember: building a production-ready server is an iterative process. Start with the basics and gradually add more features as your application grows. Happy coding and see you around for more Go tutorials

Subscribe to my newsletter

Get the latest posts delivered right to your inbox.