Logging and Observability

Updated

July 30, 2026

Logging and Observability

Overview

Production systems need three pillars: logs (event narrative), metrics (aggregates), and traces (request journeys). Go’s standard library covers solid baselines—log/slog for structured logs, expvar for simple metrics, runtime/trace and net/http/pprof for diagnostics—and interoperates with OpenTelemetry and Prometheus when you outgrow them.

This chapter focuses on idiomatic slog, context correlation, metrics exposure, and practical operational patterns.

The Three Pillars

request
  |-- trace id / span id  ---------> distributed tracer
  |-- counters / histograms -------> metrics backend
  +-- structured log lines --------> log shipper

Correlate them with a request ID (and trace IDs when tracing is enabled).

Standard `log` Package

Still fine for tiny tools:

import "log"

log.Println("starting")
log.Printf("user %d logged in", userID)
// log.Fatal / log.Panic for process exit / panic helpers

For services, prefer log/slog.

Structured Logging with `slog`

package main

import (
    "log/slog"
    "os"
)

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

    slog.Info("server starting", "addr", ":8080")
    slog.Error("db ping failed", "err", err)
}

Levels

Level	Use
Debug	High-volume diagnostics (off in prod by default)
Info	Normal lifecycle and business events
Warn	Recoverable anomalies
Error	Failures needing attention

slog.Debug("cache lookup", "key", key, "hit", hit)
slog.Warn("retrying upstream", "attempt", n)
slog.Error("checkout failed", "order_id", id, "err", err)

Child loggers and attributes

logger := slog.With("service", "checkout", "version", version)
logger.Info("ready")

reqLog := logger.With("request_id", reqID, "path", r.URL.Path)
reqLog.Info("request started")

Context-aware logging

Propagate IDs via context.Context:

type ctxKey struct{}

func WithRequestID(ctx context.Context, id string) context.Context {
    return context.WithValue(ctx, ctxKey{}, id)
}

func RequestID(ctx context.Context) string {
    if v, ok := ctx.Value(ctxKey{}).(string); ok {
        return v
    }
    return ""
}

func LogInfo(ctx context.Context, msg string, args ...any) {
    if id := RequestID(ctx); id != "" {
        args = append(args, "request_id", id)
    }
    slog.Info(msg, args...)
}

HTTP middleware sketch:

func withRequestID(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        id := r.Header.Get("X-Request-ID")
        if id == "" {
            id = uuidNew() // your id generator
        }
        w.Header().Set("X-Request-ID", id)
        ctx := WithRequestID(r.Context(), id)
        next.ServeHTTP(w, r.WithContext(ctx))
    })
}

Custom `log.Logger` (Legacy / Libraries)

logger := log.New(os.Stderr, "API ", log.Ldate|log.Ltime|log.LUTC|log.Lshortfile)
logger.Println("listening")

Prefer slog for new code; wrap slog if a dependency wants *log.Logger (slog.NewLogLogger).

Metrics with `expvar`

Quick and dependency-free:

import (
    "expvar"
    "net/http"
)

var (
    requests = expvar.NewInt("requests_total")
    errors   = expvar.NewInt("errors_total")
    inflight = expvar.NewInt("inflight")
)

func instrument(next http.Handler) http.Handler {
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        requests.Add(1)
        inflight.Add(1)
        defer inflight.Add(-1)
        next.ServeHTTP(w, r)
    })
}

func main() {
    mux := http.NewServeMux()
    mux.Handle("/debug/vars", expvar.Handler())
    // protect /debug/* in production
    http.ListenAndServe(":8080", instrument(mux))
}

For Prometheus histograms/labels, use prometheus/client_golang and a /metrics endpoint—same discipline: auth or private listener.

Runtime Tracing and pprof

import (
    "os"
    "runtime/trace"
)

f, err := os.Create("trace.out")
if err != nil {
    log.Fatal(err)
}
defer f.Close()
if err := trace.Start(f); err != nil {
    log.Fatal(err)
}
defer trace.Stop()
// run workload

go tool trace trace.out

HTTP pprof (import for side effects):

import _ "net/http/pprof"

// Serve on internal addr only:
go func() {
    log.Println(http.ListenAndServe("127.0.0.1:6060", nil))
}()

go tool pprof http://127.0.0.1:6060/debug/pprof/profile?seconds=30

Error Logging Hygiene

// Good: err is an attribute, message is stable for grouping
slog.Error("update user", "user_id", id, "err", err)

// Bad: free-form strings that explode cardinality
slog.Error(fmt.Sprintf("update user %s failed: %v", id, err))

Wrap errors with context for stacks of cause (fmt.Errorf("update user: %w", err)) and log once at the boundary—avoid logging-and-returning at every layer (duplicate noise).

Sampling and Cardinality

High-traffic debug logs can cost more than the product:

Gate debug behind level config (LOG_LEVEL=info).
Do not put unbounded IDs into metric labels (user ids, URLs).
Logs can carry high-cardinality fields; metrics should not.

level := slog.LevelInfo
if os.Getenv("LOG_LEVEL") == "debug" {
    level = slog.LevelDebug
}

OpenTelemetry (When You Need It)

For multi-service traces, adopt OTel exporters rather than inventing headers:

incoming HTTP
  --> extract trace context
  --> start span
  --> child client span for outbound HTTP/DB
  --> inject headers
  --> end span

Keep slog as the human log stream; attach trace_id as a slog attr when a span is present.

Production Checklist

JSON logs in production (machine-parseable)
request_id on every request log line
Log level configurable via env
Errors logged with err attribute once at boundary
/debug/pprof and /debug/vars not public
Metrics for rate, errors, latency (RED) on critical paths
Timeouts logged with enough context to act
PII redaction policy for logs
Trace sampling strategy documented

Common Pitfalls

Unstructured printf logs — hard to query in any backend.
Logging secrets — tokens in Authorization headers, raw card data.
Metric label explosion — path with raw IDs → millions of series.
Public pprof — remote attackers profile your heap.
Log-and-return everywhere — 5 identical errors per failure.
Synchronous remote logging in request path — prefer local shipper / async agent.
Forgetting Close on trace files — empty or truncated traces.

Exercises

JSON slog — Configure JSON handler; log Info with three attributes; pretty-print with jq.
Request middleware — Inject X-Request-ID; assert it appears in a log buffer during a handler test.
expvar counter — Increment on each hit to /; fetch /debug/vars and parse JSON in a test.
Error boundary — Build a small stack of functions that wrap %w errors; log only in main.
pprof bind — Serve pprof on 127.0.0.1 only; confirm LAN clients cannot connect.
Level gate — Read LOG_LEVEL and verify Debug lines disappear when set to info.

More examples

slog JSON to a buffer (testable logs)

mkdir -p /tmp/go-slog-buf && cd /tmp/go-slog-buf
go mod init example.com/slog-buf

Save as main.go:

package main

import (
    "bytes"
    "fmt"
    "log/slog"
    "strings"
)

func main() {
    var buf bytes.Buffer
    log := slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo}))
    log.Debug("hidden")
    log.Info("request", "method", "GET", "path", "/x", "dur_ms", 12)
    out := strings.TrimSpace(buf.String())
    fmt.Println(out)
    fmt.Println("has debug:", strings.Contains(out, "hidden"))
}

go run .

Expected output:

{"time":"...","level":"INFO","msg":"request","method":"GET","path":"/x","dur_ms":12}
has debug: false

expvar counter + debug vars snapshot

mkdir -p /tmp/go-expvar && cd /tmp/go-expvar
go mod init example.com/expvar

Save as main.go:

package main

import (
    "expvar"
    "fmt"
    "io"
    "net/http"
    "net/http/httptest"
    "strings"
)

func main() {
    hits := expvar.NewInt("hits")
    mux := http.NewServeMux()
    mux.HandleFunc("GET /", func(w http.ResponseWriter, _ *http.Request) {
        hits.Add(1)
        fmt.Fprintln(w, "ok")
    })
    mux.Handle("GET /debug/vars", expvar.Handler())

    ts := httptest.NewServer(mux)
    defer ts.Close()

    for i := 0; i < 3; i++ {
        r, _ := http.Get(ts.URL + "/")
        r.Body.Close()
    }
    r, _ := http.Get(ts.URL + "/debug/vars")
    defer r.Body.Close()
    body, _ := io.ReadAll(r.Body)
    fmt.Println("hits var:", hits.Value())
    fmt.Println("vars contains hits:", strings.Contains(string(body), "hits"))
}

go run .

Expected output:

hits var: 3
vars contains hits: true

Runnable example

Production observability starts with log/slog JSON, request IDs, and simple counters. This program logs structured events, correlates a request id, and prints a tiny text exposition counter (Prometheus-shaped, no client library).

mkdir -p /tmp/go-observ && cd /tmp/go-observ
go mod init example.com/observ

Save as main.go:

package main

import (
    "bytes"
    "context"
    "fmt"
    "log/slog"
    "net/http"
    "net/http/httptest"
    "sync/atomic"
    "time"
)

type ctxKey string

const requestIDKey ctxKey = "request_id"

func withRequestID(ctx context.Context, id string) context.Context {
    return context.WithValue(ctx, requestIDKey, id)
}

func requestID(ctx context.Context) string {
    if v, ok := ctx.Value(requestIDKey).(string); ok {
        return v
    }
    return ""
}

func main() {
    var buf bytes.Buffer
    log := slog.New(slog.NewJSONHandler(&buf, &slog.HandlerOptions{Level: slog.LevelInfo}))

    var hits atomic.Int64

    mux := http.NewServeMux()
    mux.HandleFunc("GET /work", func(w http.ResponseWriter, r *http.Request) {
        id := r.Header.Get("X-Request-ID")
        if id == "" {
            id = fmt.Sprintf("req-%d", time.Now().UnixNano())
        }
        ctx := withRequestID(r.Context(), id)
        start := time.Now()
        hits.Add(1)

        log.Info("handle",
            "msg_event", "work",
            "request_id", requestID(ctx),
            "path", r.URL.Path,
            "dur_ms", time.Since(start).Milliseconds(),
        )
        w.Header().Set("X-Request-ID", id)
        fmt.Fprintln(w, "ok")
    })
    mux.HandleFunc("GET /metrics", func(w http.ResponseWriter, _ *http.Request) {
        // Manual Prometheus text exposition (stdlib only).
        fmt.Fprintf(w, "# HELP work_hits_total Demo counter\n")
        fmt.Fprintf(w, "# TYPE work_hits_total counter\n")
        fmt.Fprintf(w, "work_hits_total %d\n", hits.Load())
    })

    // Drive with httptest (no real listen needed).
    for i := 0; i < 3; i++ {
        req := httptest.NewRequest(http.MethodGet, "/work", nil)
        req.Header.Set("X-Request-ID", fmt.Sprintf("demo-%d", i+1))
        rr := httptest.NewRecorder()
        mux.ServeHTTP(rr, req)
        fmt.Println("status:", rr.Code, "id:", rr.Header().Get("X-Request-ID"))
    }
    rr := httptest.NewRecorder()
    mux.ServeHTTP(rr, httptest.NewRequest(http.MethodGet, "/metrics", nil))
    fmt.Println("--- metrics ---")
    fmt.Print(rr.Body.String())
    fmt.Println("--- logs ---")
    fmt.Print(buf.String())
}

go run .

Expected output (illustrative):

status: 200 id: demo-1
status: 200 id: demo-2
status: 200 id: demo-3
--- metrics ---
# HELP work_hits_total Demo counter
# TYPE work_hits_total counter
work_hits_total 3
--- logs ---
{"time":"...","level":"INFO","msg":"handle","msg_event":"work","request_id":"demo-1",...}
...

What to notice

JSON logs are queryable (jq); keep stable field names (request_id, dur_ms).
Counters need _total and type comments if you want Prometheus-compatible scrapes.
Correlation ids must ride on context and outbound headers—not only access logs.

Try next

Redact an Authorization header before logging.
Start a real listener and curl /metrics; open pprof on localhost only.

Logging and Observability

Overview

The Three Pillars

Standard log Package

Structured Logging with slog

Levels

Child loggers and attributes

Context-aware logging

Custom log.Logger (Legacy / Libraries)

Metrics with expvar

Runtime Tracing and pprof

Error Logging Hygiene

Sampling and Cardinality

OpenTelemetry (When You Need It)

Production Checklist

Common Pitfalls

Exercises

More examples

slog JSON to a buffer (testable logs)

expvar counter + debug vars snapshot

Runnable example

Related Topics

Standard `log` Package

Structured Logging with `slog`

Custom `log.Logger` (Legacy / Libraries)

Metrics with `expvar`