Observability

When a service misbehaves in production, you can't attach a debugger. All you have is what the service tells you about itself. Observability is building services that answer questions you didn't think of in advance: why is checkout slow for some users, which dependency is failing, what happened to request ab12…. This lesson covers the three signals that answer those questions (logs, metrics and traces) and how to produce each idiomatically in Go.

#Three signals, three questions

They complement each other. A metric alert tells you the error rate jumped. A trace shows that the slow part is the call to the payment provider. Logs for that trace show the provider's exact error message. The glue is a shared trace ID that appears in all three, so you can jump from one to the next.

#Structured logging with slog

A log line like user 42 failed to pay order 981: card declined is easy to read and hard to query. Structured logs record the same event as key-value pairs that a log system can filter and aggregate: every failed payment for order 981, or every WARN from the billing component in the last hour.

Go's standard log/slog package does this. Use the JSON handler in production and set it as the default so every package's logs share one format:

func newLogger(level *slog.LevelVar) *slog.Logger {
	h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: level})
	return slog.New(contextHandler{h}) // contextHandler is defined below
}

func main() {
	var level slog.LevelVar // zero value is Info; level.Set(slog.LevelDebug) at runtime
	slog.SetDefault(newLogger(&level))

	slog.Info("starting", "port", 8080)
	slog.Info("grouped", slog.Group("user", slog.Int64("id", 7), slog.String("role", "admin")))
	billing := slog.Default().With("component", "billing")
	billing.Warn("payment failed", "order_id", 981, "err", errors.New("card declined"))
}

{"time":"2026-10-11T08:23:14.167482913Z","level":"INFO","msg":"starting","port":8080}
{"time":"2026-10-11T08:23:14.167527104Z","level":"INFO","msg":"grouped","user":{"id":7,"role":"admin"}}
{"time":"2026-10-11T08:23:14.167531390Z","level":"WARN","msg":"payment failed","component":"billing","order_id":981,"err":"card declined"}

A few conventions keep logs useful:

• The message is a constant; variable data goes in attributes. "payment failed" plus order_id=981 can be grouped and counted; "payment failed for 981" can't.
• logger.With(...) returns a child logger that adds attributes to every record, which suits per-component or per-request context.
• Levels mean something. DEBUG for detail you enable while investigating; INFO for normal significant events; WARN for something unexpected that was handled; ERROR for a failure someone may need to act on. A slog.LevelVar lets you change the level at runtime, for example from an admin endpoint.
• Log an error once, where it's handled. If every layer logs and returns the same error, one failure produces five log lines. Lower layers wrap and return; the top layer logs.

#Adding request context automatically

The request-logging middleware from the routing lesson logs one line per request. But logs written inside handlers also need to identify their request. Rather than passing IDs around by hand, wrap the handler so that every slog.InfoContext(ctx, ...) call picks up the trace and span IDs from the context:

type contextHandler struct{ slog.Handler }

func (h contextHandler) Handle(ctx context.Context, r slog.Record) error {
	if sc := trace.SpanContextFromContext(ctx); sc.IsValid() {
		r.AddAttrs(
			slog.String("trace_id", sc.TraceID().String()),
			slog.String("span_id", sc.SpanID().String()),
		)
	}
	return h.Handler.Handle(ctx, r)
}

// Without these two methods, logger.With(...) would return the inner
// handler and silently drop the wrapper.
func (h contextHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
	return contextHandler{h.Handler.WithAttrs(attrs)}
}

func (h contextHandler) WithGroup(name string) slog.Handler {
	return contextHandler{h.Handler.WithGroup(name)}
}

This only works if you use the Context variants (InfoContext, WarnContext, ...) and pass the request's context down. That's one more reason to thread ctx through every call.

#Metrics with Prometheus

Metrics are numbers sampled over time. Prometheus, the most common open-source metrics system, scrapes an HTTP endpoint on your service (usually /metrics) every 15–30 seconds and stores the values as time series. Three metric types cover almost everything:

• Counter: only goes up (requests served, errors). You query its rate.
• Gauge: goes up and down (in-flight requests, pool connections in use).
• Histogram: counts observations into buckets (request durations), so you can compute percentiles.

For an HTTP service, start with the RED method: Rate of requests, Errors, and Duration, per route:

var (
	httpRequests = promauto.NewCounterVec(prometheus.CounterOpts{
		Name: "http_requests_total",
		Help: "HTTP requests by route, method and status code.",
	}, []string{"route", "method", "code"})

	httpDuration = promauto.NewHistogramVec(prometheus.HistogramOpts{
		Name:    "http_request_duration_seconds",
		Help:    "HTTP request latency by route.",
		Buckets: prometheus.DefBuckets,
	}, []string{"route", "method"})
)

func metrics(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} // from the routing lesson
		next.ServeHTTP(rec, r)

		route := r.Pattern // e.g. "POST /v1/orders/{id}/pay", set by ServeMux while routing
		if route == "" {
			route = "unmatched"
		}
		httpRequests.WithLabelValues(route, r.Method, strconv.Itoa(rec.status)).Inc()
		httpDuration.WithLabelValues(route, r.Method).Observe(time.Since(start).Seconds())
	})
}

Register mux.Handle("GET /metrics", promhttp.Handler()) and the endpoint serves these alongside built-in Go runtime metrics such as go_goroutines:

http_requests_total{code="204",method="POST",route="POST /v1/orders/{id}/pay"} 1
http_requests_total{code="402",method="POST",route="POST /v1/orders/{id}/pay"} 1
http_request_duration_seconds_count{method="POST",route="POST /v1/orders/{id}/pay"} 2

Dashboards and alerts are then queries in PromQL:

# requests per second, per route, over the last 5 minutes
sum by (route) (rate(http_requests_total[5m]))

# 95th-percentile latency per route
histogram_quantile(0.95, sum by (le, route) (rate(http_request_duration_seconds_bucket[5m])))

#Tracing with OpenTelemetry

A trace follows one request through every service and component it touches. It is a tree of spans: each span has a name, a start and end time, attributes and a status, and a parent. Your HTTP handler's span might have children for a database query and a call to the payment service, which in turn has its own children in its process.

Traces cross process boundaries through context propagation. When your service calls another, it sends a W3C traceparent header carrying the trace ID and the current span ID; the receiving service continues the same trace. OpenTelemetry (OTel) is the vendor-neutral standard for producing traces, and its Go SDK exports them over OTLP to a collector or a backend such as Jaeger or Grafana Tempo.

Set up a tracer provider once at startup:

func setupTracing(ctx context.Context, exp sdktrace.SpanExporter) (func(context.Context) error, error) {
	res, err := resource.Merge(resource.Default(),
		resource.NewSchemaless(attribute.String("service.name", "orders-api")))
	if err != nil {
		return nil, err
	}
	tp := sdktrace.NewTracerProvider(
		sdktrace.WithBatcher(exp),
		sdktrace.WithResource(res),
		// Keep 10% of new traces, but always follow the caller's decision.
		sdktrace.WithSampler(sdktrace.ParentBased(sdktrace.TraceIDRatioBased(0.1))),
	)
	otel.SetTracerProvider(tp)
	otel.SetTextMapPropagator(propagation.TraceContext{})
	return tp.Shutdown, nil // call on exit to flush buffered spans
}

In production, pass otlptracegrpc.New(ctx), which reads its endpoint from OTEL_EXPORTER_OTLP_ENDPOINT. Then instrument at three levels:

1. Incoming HTTP: wrap your router with otelhttp.NewHandler(handler, "http.server"). It starts a span per request, continuing any incoming traceparent, and puts it in r.Context().
2. Outgoing HTTP: use &http.Client{Transport: otelhttp.NewTransport(http.DefaultTransport)} so calls carry traceparent and get child spans. Instrumentation libraries exist for pgx and go-redis too.
3. Your own code: start spans around interesting work.

var tracer = otel.Tracer("example.com/orders")

func chargeCard(ctx context.Context, orderID int64) error {
	ctx, span := tracer.Start(ctx, "chargeCard")
	defer span.End()
	span.SetAttributes(attribute.Int64("order.id", orderID))

	if err := paymentProvider.Charge(ctx, orderID); err != nil {
		span.RecordError(err)
		span.SetStatus(codes.Error, err.Error())
		return err
	}
	slog.InfoContext(ctx, "card charged", "order_id", orderID)
	return nil
}

tracer.Start returns a new context containing the span. Pass that context onward, or child spans and log correlation attach to the wrong parent. And always defer span.End(): a span that never ends is never exported.

#Alerting on what users feel

Collecting signals is half the job; the other half is deciding what wakes someone up. Alert on symptoms users experience, not on every possible cause:

• Error rate: the share of requests returning 5xx over the last few minutes, above an agreed threshold such as 1%.
• Latency: the 95th or 99th percentile of http_request_duration_seconds per route, above its target.
• Saturation that predicts trouble: database pool connections in use near MaxConns, or a queue growing without bound. Export these as gauges.

A CPU spike that users don't notice is a dashboard curiosity, not a page at 3 a.m. When a symptom alert fires, the workflow is the one this lesson built: the metric tells you which route and since when, a sampled trace from that window shows which span is slow or failing, and the logs carrying that trace ID tell you why.

#Practice

Build a small orders-api that ties all three signals together:

1. Configure slog with newLogger and contextHandler.
2. Add POST /v1/orders/{id}/pay, which calls chargeCard. Simulate the provider with a 20–50 ms sleep, and make orders whose ID is divisible by 5 fail with card declined (respond 402).
3. Wrap the mux with metrics and then otelhttp.NewHandler, and serve GET /metrics.
4. Export spans with stdouttrace.New(stdouttrace.WithPrettyPrint()) and sample everything.

Call POST /v1/orders/1/pay and /v1/orders/5/pay. Check that the trace_id in each log line matches the TraceID of the printed chargeCard span, and that /metrics shows a 204 and a 402.

func chargeCard(ctx context.Context, orderID int64) error {
	ctx, span := tracer.Start(ctx, "chargeCard")
	defer span.End()
	span.SetAttributes(attribute.Int64("order.id", orderID))

	time.Sleep(time.Duration(20+rand.IntN(30)) * time.Millisecond) // the "provider"
	if orderID%5 == 0 {
		err := errors.New("card declined")
		span.RecordError(err)
		span.SetStatus(codes.Error, err.Error())
		return err
	}
	slog.InfoContext(ctx, "card charged", "order_id", orderID)
	return nil
}

func main() {
	var level slog.LevelVar
	slog.SetDefault(newLogger(&level))

	exp, err := stdouttrace.New(stdouttrace.WithPrettyPrint())
	if err != nil {
		log.Fatal(err)
	}
	// In setupTracing, use sdktrace.AlwaysSample() while experimenting.
	shutdown, err := setupTracing(context.Background(), exp)
	if err != nil {
		log.Fatal(err)
	}
	defer shutdown(context.Background())

	mux := http.NewServeMux()
	mux.HandleFunc("POST /v1/orders/{id}/pay", func(w http.ResponseWriter, r *http.Request) {
		id, err := strconv.ParseInt(r.PathValue("id"), 10, 64)
		if err != nil {
			http.Error(w, "invalid id", http.StatusBadRequest)
			return
		}
		if err := chargeCard(r.Context(), id); err != nil {
			slog.WarnContext(r.Context(), "payment failed", "order_id", id, "err", err)
			http.Error(w, "payment failed", http.StatusPaymentRequired)
			return
		}
		w.WriteHeader(http.StatusNoContent)
	})
	mux.Handle("GET /metrics", promhttp.Handler())

	srv := &http.Server{Addr: ":8080", Handler: otelhttp.NewHandler(metrics(mux), "http.server")}
	log.Fatal(srv.ListenAndServe())
}

{"level":"INFO","msg":"card charged","order_id":1,"trace_id":"0778402bddc4eff033fad74ae4182829","span_id":"5aa6fab45aa38e4d"}
{"level":"WARN","msg":"payment failed","order_id":5,"err":"card declined","trace_id":"ca7cc8716787c9416079bdf0bc940a0b","span_id":"d2fc93ed6065a0f3"}

#Key takeaways

• Logs explain single events, metrics show aggregate health and trends, traces show where time went; a shared trace ID links them.
• Use slog with a JSON handler: constant messages, typed attributes, With for shared context, and errors logged once where they're handled.
• Redact secrets with LogValuer, and use a wrapping handler plus InfoContext to add trace IDs to every log line.
• Expose RED metrics (rate, errors, duration) with counters and histograms, labelled by route pattern, never by raw path or user ID.
• Set up an OpenTelemetry tracer provider once, wrap servers and clients with otelhttp, and always pass on the context returned by tracer.Start and defer span.End().