Logging and Monitoring: Concepts and Go Implementation

"A server without logging is a black box in flight with no flight recorder: if something goes wrong at 3 a.m., you're left guessing what happened from the wreckage. Logging and monitoring are the instruments on the dashboard — they tell you what the system is doing right now, and leave a trail for figuring out what it did five minutes ago."

Why This Matters More for Network Applications

Every server built in this book so far handles requests from clients you can't see and can't step through with a debugger while they happen. When a client on the other side of a TCP connection reports "it's slow" or "it failed," logs and metrics are usually the only window into what actually happened on your side of the wire.

Logs record discrete events: a connection was accepted, a request failed, a token was rejected.
Metrics record aggregate numbers over time: requests per second, error rate, average latency, open connection count.

Both matter. Logs tell you the story of one specific request; metrics tell you the health of the whole system at a glance.

Consider a concrete scenario: a client reports intermittent 500 errors on POST /orders around 3 a.m. Without logs, you have only the client's word to go on. With structured logs, you can filter for path=/orders and status>=500 and find the exact requests, their remote addresses, and how long each took before failing. Layer metrics on top and you can also tell whether the failure rate spiked for every client or just one — the difference between a systemic bug and a single flaky caller.

If you can't answer "what was this server doing five minutes ago" without redeploying it, you don't have observability — you have hope.

Structured Logging with `log/slog`

Plain fmt.Println debugging output — which earlier chapters leaned on for simplicity — doesn't scale to a real service: it's hard to search, filter, or feed into a log aggregation system. Go's standard library ships log/slog, a structured logging package that emits key-value pairs instead of free-form text, in either a human-readable or JSON format.

package main

import (
	"log/slog"
	"os"
)

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
		Level: slog.LevelInfo,
	}))
	slog.SetDefault(logger)

	slog.Info("server starting", "addr", ":8080")
	slog.Warn("slow response", "path", "/api/users", "duration_ms", 842)
	slog.Error("connection failed",
		"remote_addr", "203.0.113.5:51234", "error", "timeout")
}

Each call produces a single JSON line with the message and its attributes as separate fields — trivially parseable by log aggregation tools, unlike a formatted string you'd have to pick apart with regular expressions.

Adjusting Verbosity at Runtime

The slog.LevelInfo above is fixed at startup, but a misbehaving server in production often needs more detail than Info gives you — ideally without a redeploy. slog.LevelVar holds a level that can be changed safely while the program runs, since it synchronizes reads and writes internally:

var logLevel = new(slog.LevelVar) // defaults to LevelInfo

func init() {
	handler := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
		Level: logLevel,
	})
	slog.SetDefault(slog.New(handler))
}

func setLogLevelHandler(w http.ResponseWriter, r *http.Request) {
	switch r.URL.Query().Get("level") {
	case "debug":
		logLevel.Set(slog.LevelDebug)
	case "info":
		logLevel.Set(slog.LevelInfo)
	case "warn":
		logLevel.Set(slog.LevelWarn)
	default:
		http.Error(w, "unknown level", http.StatusBadRequest)
		return
	}
	fmt.Fprintf(w, "log level set to %s\n", logLevel.Level())
}

Wiring setLogLevelHandler up on an internal-only route lets you flip a production server from Info to Debug for a few minutes to catch an intermittent bug in the act, then flip it back — without restarting the process and losing whatever state triggered the problem.

Never log secrets

It's tempting to log the full request while debugging — headers, body, everything. Don't: Authorization headers, session cookies, and password fields end up in your log aggregator, often a less secure place than the system the secret was meant to protect. Log the request ID, path, and method; add specific sanitized fields deliberately, never a whole request or response object by default.

Logging Middleware for HTTP Servers

The middleware pattern from the authentication chapter applies just as well here: wrap a handler to log every request that passes through it.

func loggingMiddleware(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		start := time.Now()

		rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK}
		next.ServeHTTP(rec, r)

		slog.Info("request handled",
			"method", r.Method,
			"path", r.URL.Path,
			"status", rec.status,
			"duration_ms", time.Since(start).Milliseconds(),
			"remote_addr", r.RemoteAddr,
		)
	})
}

// statusRecorder wraps http.ResponseWriter to capture the status code,
// since the standard interface has no way to read it back afterward.
type statusRecorder struct {
	http.ResponseWriter
	status int
}

func (r *statusRecorder) WriteHeader(status int) {
	r.status = status
	r.ResponseWriter.WriteHeader(status)
}

Exercise: HTTP Logging Middleware

Wrapping http.ResponseWriter this way — capturing the status code as a side effect of intercepting WriteHeader — is a common pattern any time you need to observe what a handler did without changing its behavior.

A wrapped ResponseWriter can silently break upgrades

statusRecorder embeds the http.ResponseWriter interface, so it satisfies Header, Write, and WriteHeader — but nothing else. A handler further down the chain that upgrades to a WebSocket needs w.(http.Hijacker) to succeed; that type assertion fails outright on *statusRecorder, since only the embedded interface's own methods are promoted, not Hijack from a different interface the underlying writer might also implement. The same applies to http.Flusher for streaming responses. Middleware in front of upgrade-capable or streaming handlers must implement Hijack()/Flush() explicitly and delegate to the underlying writer.

Contextual Logging with Request IDs

In a concurrent server handling many requests at once, log lines from different requests interleave in the output. Attaching a unique request ID to each request — carried through context.Context, the same mechanism used for cancellation and for the authenticated user ID in Chapter 3.18 — lets you filter a log stream down to a single request's story:

type contextKey string

const requestIDKey contextKey = "requestID"

func requestIDMiddleware(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		id := generateRequestID()
		ctx := context.WithValue(r.Context(), requestIDKey, id)
		slog.InfoContext(ctx, "request started",
			"request_id", id, "path", r.URL.Path)
		next.ServeHTTP(w, r.WithContext(ctx))
	})
}

slog.InfoContext accepts a context.Context alongside the message, letting handlers that support context-aware logging (or custom slog.Handler implementations) enrich every log line with values pulled from that context automatically.

Generating Request IDs Safely

generateRequestID needs values that won't collide across concurrent requests, which rules out an unseeded math/rand source or a plain in-memory counter that resets to zero on every restart. crypto/rand is cheap enough to call once per request and gives genuinely unpredictable bytes:

func generateRequestID() string {
	b := make([]byte, 8)
	if _, err := rand.Read(b); err != nil {
		// crypto/rand.Read only fails if the OS entropy
		// source is broken; fall back rather than crash.
		return fmt.Sprintf("fallback-%d", time.Now().UnixNano())
	}
	return hex.EncodeToString(b)
}

Why context keys use an unexported custom type

requestIDKey is declared as type contextKey string, not a bare string constant. If two packages both used the literal "requestID" as a context.WithValue key, one could silently overwrite the other's value — plain string keys collide across packages with no compile-time warning. An unexported named type scoped to a single package guarantees no other package can construct a colliding key, since they have no way to reference the unexported contextKey type at all.

context.Value is not a general-purpose parameter bag

It's tempting to stuff more and more values into the request context once context.WithValue is available — user ID, request ID, feature flags, a database handle. Reserve it for values that genuinely belong to the request's lifetime and cross API boundaries you don't control, like a request ID threaded through middleware and handlers you didn't write. Anything a function actually depends on to do its job should be an explicit parameter; hiding it in the context makes the function's real dependencies invisible to its own signature.

Monitoring: Metrics and Health Checks

Beyond individual log lines, a running service benefits from exposing aggregate numbers. A minimal, dependency-free approach uses sync/atomic counters updated as requests flow through, exposed on their own HTTP endpoint:

var (
	totalRequests  atomic.Int64
	failedRequests atomic.Int64
)

func metricsMiddleware(next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		totalRequests.Add(1)
		rec := &statusRecorder{ResponseWriter: w, status: http.StatusOK}
		next.ServeHTTP(rec, r)
		if rec.status >= 500 {
			failedRequests.Add(1)
		}
	})
}

func metricsHandler(w http.ResponseWriter, r *http.Request) {
	fmt.Fprintf(w, "requests_total %d\n", totalRequests.Load())
	fmt.Fprintf(w, "requests_failed_total %d\n", failedRequests.Load())
}

This plain-text key value format is intentionally close to what tools like Prometheus scrape from a /metrics endpoint — the concept (expose numbers over HTTP, let an external system poll and aggregate them) is the same whether you write the exposition format by hand or use a metrics library that formats it for you.

Plain counters race under concurrent handlers

totalRequests and failedRequests are atomic.Int64, not plain int64, on purpose: many requests call Add concurrently from different goroutines. Change either field to a plain int64 incremented with totalRequests++ and go test -race flags a data race immediately — without the race detector running, you'd instead just see a silent undercount in production, which is far harder to notice than a test failure.

From hand-rolled counters to a real metrics library

The exposition format above is fine for two counters, but a real service tracks dozens — request duration buckets, in-flight counts, per-route breakdowns. prometheus/client_golang provides counters, gauges, and histograms plus an http.Handler that serves /metrics in the exact text format Prometheus expects. The underlying idea — atomic counters exposed over HTTP for an external scraper — is identical to the code above; the library just does the bookkeeping at scale.

A health check endpoint follows the same idea in miniature — a cheap handler an orchestrator (load balancer, container scheduler) can poll to decide whether this instance is still healthy:

func healthHandler(w http.ResponseWriter, r *http.Request) {
	w.WriteHeader(http.StatusOK)
	w.Write([]byte("ok"))
}

This works well as a liveness check: is the process alive at all? Real orchestrators (Kubernetes among them) also want a separate readiness check: is this instance currently able to serve traffic? The distinction matters because the two failures call for different responses — a deadlocked process should be restarted, but an instance that's merely waiting on a database to come back up should just stop receiving new traffic, not be killed and immediately replaced with another instance in the same broken state:

func readinessHandler(db *sql.DB) http.HandlerFunc {
	return func(w http.ResponseWriter, r *http.Request) {
		ctx, cancel := context.WithTimeout(r.Context(), 2*time.Second)
		defer cancel()

		if err := db.PingContext(ctx); err != nil {
			http.Error(w, "not ready", http.StatusServiceUnavailable)
			return
		}
		w.WriteHeader(http.StatusOK)
		w.Write([]byte("ready"))
	}
}

Bounding PingContext with a short timeout matters: a readiness probe that blocks indefinitely on a hung dependency defeats the entire point of the check. The orchestrator's own probe timeout would eventually fire anyway — better to fail fast with a clear 503 than to time out with no information at all.

pprof is part of monitoring too

net/http/pprof — covered in depth in the performance chapter — exposes live CPU and memory profiles over HTTP. It's less about steady-state metrics and more about answering "why is this instance slow right now," but it belongs in the same observability toolbox as logs and metrics.

Try It Yourself

Add setLogLevelHandler from earlier in this chapter to a small HTTP server, alongside healthHandler and a readinessHandler backed by a fake dependency that fails for the first five seconds after startup. Use curl to confirm: /health returns 200 immediately, /ready returns 503 until the dependency "warms up," and ?level=debug makes subsequent request logs noticeably more verbose. Watching all three move independently makes clear why "alive," "ready," and "verbose enough to debug" are separate questions.

Frequently Asked Questions

Why switch from fmt.Println to log/slog at all — isn't a print statement just as informative? A print statement is fine for the one-off debugging earlier chapters leaned on, but it doesn't scale to a real service: free-form text is hard to search, filter, or feed into a log aggregator. log/slog emits key-value pairs instead, so a query like "every request with path=/orders and status>=500" is a field filter rather than a regular expression pulled apart from a sentence.

Why does statusRecorder embed http.ResponseWriter instead of implementing it directly, and what does that cost? Embedding the interface is what lets statusRecorder satisfy http.ResponseWriter cheaply while only overriding WriteHeader to capture the status code as a side effect. The cost is that nothing beyond the embedded interface's own methods gets promoted — a downstream handler that upgrades to a WebSocket needs w.(http.Hijacker) to succeed, and that type assertion fails outright on *statusRecorder even though the underlying writer supports it, so logging middleware in front of upgrade-capable handlers has to implement Hijack() and Flush() explicitly and delegate through.

Why is requestIDKey its own named type instead of just a string constant? Because context.WithValue keys collide by value across an entire program, with no compile-time warning — a plain "requestID" string used by two different packages would silently overwrite each other's value. Declaring type contextKey string as an unexported type scoped to one package makes that collision impossible, since no other package can construct a matching key without access to the type itself.

Why do liveness and readiness need separate endpoints instead of one /health? Because the two failures call for opposite responses. A deadlocked process should be killed and restarted, which is what a liveness check like healthHandler is for; an instance that's merely waiting on a database to come back, which is what readinessHandler checks via db.PingContext, should just stop receiving new traffic rather than being replaced with another instance in the same broken state.

Why bother with atomic.Int64 for something as simple as a request counter? Because metricsMiddleware calls Add from many concurrent request-handling goroutines at once, and a plain int64 incremented with totalRequests++ is a data race — one that go test -race catches immediately, but that would otherwise show up in production only as a quiet, hard-to-notice undercount rather than a crash or an error.

Key Takeaways

Logs tell the story of individual events; metrics summarize system health over time. Production services need both.
log/slog gives you structured, filterable logging in the standard library, with JSON output ready for log aggregation.
Wrapping http.Handler is the same pattern used for authentication middleware — apply it for logging, metrics, and request IDs alike.
Attaching a request ID to context.Context ties every log line from one request together, even under heavy concurrency.
A /metrics endpoint and a /health endpoint are cheap to build and are what load balancers and monitoring systems expect to poll.
slog.LevelVar lets you raise or lower verbosity in a running server without a restart; use it, and never log secrets, regardless of level.
Separate liveness from readiness: a deadlocked process should be restarted, but a process merely waiting on a dependency should just stop receiving traffic.