APIs for Advanced Observability: Metrics and Logging

An earlier chapter in this book covered basic performance monitoring — enough to notice that something is slow. This chapter is about instrumenting an API properly: structured logs you can actually query, metrics that answer specific operational questions rather than vague ones, and health endpoints your orchestrator can trust to make correct decisions. The next chapter builds on this one by adding distributed tracing across service boundaries; this one is about getting the fundamentals — logs, metrics, health checks — solid within a single service first.

Structured logging with log/slog

Unstructured logs (log.Printf("user %s logged in", userID)) are fine to read in a terminal and painful to query at scale — you end up writing regular expressions against free text instead of filtering on a field. Go 1.21 added log/slog to the standard library specifically to fix this, producing structured, machine-parseable log entries by default:

package main

import (
	"log/slog"
	"net/http"
	"os"
	"time"
)

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

func loginHandler(w http.ResponseWriter, r *http.Request) {
	start := time.Now()
	// authenticate wraps parseToken, the token-parsing helper introduced
	// in Chapter 6.10's auth middleware.
	userID, err := authenticate(r)
	if err != nil {
		logger.Warn("login failed",
			"remote_addr", r.RemoteAddr,
			"error", err.Error(),
			"duration_ms", time.Since(start).Milliseconds(),
		)
		http.Error(w, "unauthorized", http.StatusUnauthorized)
		return
	}

	logger.Info("login succeeded",
		"user_id", userID,
		"duration_ms", time.Since(start).Milliseconds(),
	)
	writeJSON(w, http.StatusOK, map[string]string{"status": "ok"})
}

Every call emits a JSON object with consistent field names (user_id, duration_ms, error), which means your log aggregation system (Loki, Elasticsearch, CloudWatch Logs Insights) can filter on user_id="42" or aggregate duration_ms into a histogram, instead of parsing free-form sentences. Attach a request-scoped logger with common fields (a request ID, the route) once per request, so every log line inside that request automatically carries them:

import (
	"context"
	"crypto/rand"
	"encoding/hex"
)

type contextKey string

const loggerContextKey contextKey = "logger"

func generateRequestID() string {
	b := make([]byte, 8)
	rand.Read(b)
	return hex.EncodeToString(b)
}

func withRequestLogger(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 = generateRequestID()
		}
		reqLogger := logger.With("request_id", requestID, "path", r.URL.Path)
		ctx := context.WithValue(r.Context(), loggerContextKey, reqLogger)
		next.ServeHTTP(w, r.WithContext(ctx))
	})
}

logger.With returns a new logger carrying those fields on every subsequent call, without you passing requestID explicitly into every function that wants to log something.

Metrics with Prometheus client_golang

Logs answer "what happened in this one request." Metrics answer "how is the system behaving in aggregate, right now." github.com/prometheus/client_golang is the standard Go library for exposing metrics in the format Prometheus scrapes:

import (
	"fmt"

	"github.com/prometheus/client_golang/prometheus"
	"github.com/prometheus/client_golang/prometheus/promhttp"
)

var (
	requestDuration = prometheus.NewHistogramVec(
		prometheus.HistogramOpts{
			Name:    "http_request_duration_seconds",
			Help:    "HTTP request duration in seconds",
			Buckets: prometheus.DefBuckets,
		},
		[]string{"method", "path", "status"},
	)
	requestsInFlight = prometheus.NewGauge(prometheus.GaugeOpts{
		Name: "http_requests_in_flight",
		Help: "Number of HTTP requests currently being processed",
	})
)

func init() {
	prometheus.MustRegister(requestDuration, requestsInFlight)
}

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

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

// metricsMiddleware takes the route pattern as registered on the mux (for
// example "/users/{id}"), not the resolved request path, so that a path
// containing a real ID never becomes a label value — see the Warning below.
func metricsMiddleware(pattern string, next http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		requestsInFlight.Inc()
		defer requestsInFlight.Dec()

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

		requestDuration.WithLabelValues(
			r.Method, pattern, fmt.Sprint(rec.status),
		).Observe(time.Since(start).Seconds())
	})
}

requestDuration is a histogram, not a plain counter or gauge, because latency is exactly the kind of value where the distribution matters more than a single number — Prometheus can compute p50/p95/p99 from the bucketed histogram data, which a simple average would hide entirely (the same lesson from the load-testing chapter, applied to production traffic instead of a test run). Exposing the collected metrics is a single handler:

mux.Handle("/metrics", promhttp.Handler())
mux.Handle("/users/{id}", metricsMiddleware("/users/{id}", userHandler))

Health and readiness endpoints

Container orchestrators like Kubernetes need two different questions answered, and conflating them causes real outages: liveness ("is this process stuck and needs to be killed and restarted") and readiness ("is this process currently able to serve traffic, even if it's healthy"). A service can be alive but not ready — for instance, still warming its cache or waiting on a database connection at startup.

import (
	"context"
	"database/sql"
	"net/http"
	"time"
)

func livenessHandler(w http.ResponseWriter, r *http.Request) {
	// if this handler runs at all, the process is alive
	w.WriteHeader(http.StatusOK)
}

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 {
			w.WriteHeader(http.StatusServiceUnavailable)
			return
		}
		w.WriteHeader(http.StatusOK)
	}
}

A liveness check should be nearly free — checking that the process can respond at all — because Kubernetes will restart the container if it fails, and a slow or dependency-heavy liveness check causes needless restarts under load. A readiness check should verify the dependencies this instance actually needs to serve traffic (a database connection, a downstream service), because failing readiness only removes the instance from the load balancer's rotation — a much cheaper, safer response to a temporary dependency issue than restarting the whole process.

Alerting on symptoms, not causes

Once metrics exist, the temptation is to alert on everything measurable — CPU above 80 percent, every single error logged, every slow query. This produces alert fatigue fast, and fatigued on-call engineers start ignoring pages, including the ones that matter. Alert on symptoms visible to users first (elevated error rate, elevated p99 latency, failed readiness checks) and treat resource-level metrics (CPU, memory, queue depth) as diagnostic information you look at once a symptom-based alert has already fired, not as a source of alerts in their own right:

// Alert rule (expressed conceptually, evaluated by your metrics backend):
// ALERT if rate(http_requests_total{status=~"5.."}[5m])
//        / rate(http_requests_total[5m]) > 0.02 for 5m

A rule like this fires when the actual error rate a user experiences crosses a meaningful threshold for a sustained period, not on a single noisy spike — the combination of a rate-based threshold and a for duration is what keeps this from paging someone over a two-second blip that resolved on its own.

Instrumentation isn't something you add once a service breaks — it's what tells you it's about to, in time to do something about it.

Frequently Asked Questions

Why bother with log/slog and JSON output when log.Printf is so much easier to read in a terminal? Because readability in a terminal and queryability at scale are different goals, and the moment you have more than a handful of instances, you need to filter and aggregate logs rather than eyeball them. slog.NewJSONHandler gives every log line consistent field names like user_id and duration_ms, so your aggregation system can filter on user_id="42" or build a histogram from duration_ms instead of you writing regular expressions against free text.

Why is requestDuration a histogram instead of a simple gauge tracking average latency? Because an average hides exactly the information that matters for latency — a handful of very slow requests can vanish into an average dominated by many fast ones, while Prometheus can compute p50/p95/p99 directly from the bucketed histogram data. The chapter calls this the same lesson from the load-testing chapter, just applied to production traffic instead of a test run.

What actually goes wrong if I use the raw request path as a Prometheus label? Cardinality explosion — if r.URL.Path includes something like a user ID or UUID (/users/8f3a2b91-...), Prometheus creates a brand new time series for every distinct value it ever sees, and with enough distinct IDs that can produce millions of series and overwhelm the metrics backend, as the Warning above describes. The fix is always normalizing to the route pattern, /users/{id}, never the resolved path.

Why does a failing readiness check not restart the pod the way a failing liveness check does? Because the two questions mean different things to Kubernetes: liveness asks whether the process is stuck and needs killing and restarting, while readiness asks whether it can currently serve traffic even though it's otherwise healthy. A database failover making readinessHandler fail is the system working as intended — traffic routes away until the dependency recovers — whereas putting that same database check in liveness would trigger unnecessary restarts across every instance at once, exactly the mixup the DeepDive warns against.

If I have metrics on CPU, memory, and queue depth, why not just alert on those directly? Because alerting on every measurable resource metric produces alert fatigue fast, and fatigued on-call engineers start ignoring pages, including the ones that matter. The chapter's guidance is to alert on symptoms users actually feel first — elevated error rate, elevated p99 latency, failed readiness checks — and treat resource-level metrics as diagnostic information you consult once a symptom-based alert has already fired, not as alert sources in their own right.