Log every request with a request id

Go · Go · intermediate · modification

Adds request ids and an access log. `reqlog.Middleware` wraps the whole mux, so every request it lets through, health checks and 404s included, gets an id (if reading the random source fails, the request is answered 500 without one): the load balancer's `X-Request-ID` when it looks like one, otherwise a fresh 128-bit id from `crypto/rand`. The id goes into the request context (`reqlog.ID(ctx)`) and back to the client in the same header, and once the handler returns we log one JSON line with method, path, status, bytes and duration. A small `ResponseWriter` wrapper captures the status and the byte count, and keeps `http.ResponseController` working for the streaming endpoints. Tests cover the id rules and the logged status and bytes.

Orders API in Go 1.22, standard library only (`net/http` method-pattern `ServeMux`, `log/slog`). Unchanged: `orders.Register(mux, db, logger)` adds the `/orders` routes; `httpserver.Serve(ctx, addr, h)` runs an `http.Server` with `h` as its handler until `ctx` is cancelled, then drains in-flight requests. The service runs behind a load balancer that sets `X-Request-ID` on the requests it forwards, but clients can send the header too.

Requirements

• Every request the server handles, `/healthz` included, gets a request id. An incoming `X-Request-ID` is reused when it is 1 to 64 characters of `A-Z`, `a-z`, `0-9`, `.`, `_` and `-`; only the first `X-Request-ID` header counts. Any other value, or none, is replaced by a new id: 16 bytes from `crypto/rand`, hex-encoded. The id only correlates log lines and is trusted for nothing else, so a client that picks its own id, or reuses one, is acceptable.
• The id is returned in the `X-Request-ID` response header, and handlers read it with `reqlog.ID(ctx)`, which returns `""` for a context that did not come through the middleware. If reading the random source fails, the request is answered `500` `internal error`, the failure is logged at error level, and the request does not reach the handler.
• After the handler returns, one `request` line is logged at info level with `request_id`, `method`, `path`, `status`, `bytes` and `duration`. `path` is the URL path only: query strings can carry tokens and are never logged. `status` is the final status the client got: 200 when the handler wrote or flushed a body without calling `WriteHeader`, or wrote nothing at all; the first one when `WriteHeader` is called more than once; informational 1xx responses (103 Early Hints) are not a final status. `bytes` is the sum of what the handler's `Write` calls reported as written (for a `HEAD` request net/http accepts and discards the body, and that count is fine). `duration` runs from the middleware receiving the request to the handler returning.
• Handlers flush streamed responses and set deadlines through `http.NewResponseController` (the service's convention: no handler type-asserts its `ResponseWriter`), and both keep working behind the middleware. No handler hijacks the connection or serves WebSockets. A request whose handler panics needs no access line: net/http's own recovery logs the panic.
• Logs stay JSON (`slog.NewJSONHandler`, set up in `main` and unchanged), so request values in them are escaped. Ship tests for the id rules and for the logged status and bytes.

Files touched

• cmd/server/main.go
• internal/reqlog/reqlog.go
• internal/reqlog/reqlog_test.go

--- cmd/server/main.go
 	"example.com/shop/internal/httpserver"
 	"example.com/shop/internal/orders"
+	"example.com/shop/internal/reqlog"
 	"example.com/shop/internal/store"
 )
 		w.WriteHeader(http.StatusNoContent)
 	})
-	return httpserver.Serve(ctx, cfg.Addr, mux)
+	return httpserver.Serve(ctx, cfg.Addr, reqlog.Middleware(logger, mux))
 }
 
--- internal/reqlog/reqlog.go
+// Package reqlog gives every request an id and writes one access log line
+// per request.
+package reqlog
+
+import (
+	"context"
+	"crypto/rand"
+	"encoding/hex"
+	"log/slog"
+	"net/http"
+	"regexp"
+	"time"
+)
+
+// Header carries the request id in both directions.
+const Header = "X-Request-ID"
+

Review this PR

Go practice