Structured logging with slog: handlers, attrs, levels, and the price of every line

Logger, Handler, Writer

Why did the standard library need a second logging API? Because log.Printf produces prose that you query with regexes — and regexes break when message wording changes. log/slog splits logging into a thin front-end and a pluggable back-end. A Logger is the API your code calls; it builds a Record — timestamp, level, message, attributes — and hands it to a Handler, which decides format and destination: JSONHandler and TextHandler ship in the box, custom handlers wrap others to add sampling, redaction or fan-out. The handler writes to an io.Writer. This split is why slog took over: libraries log against the neutral API, applications choose the output format once.

logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{
	Level: slog.LevelInfo,
}))
slog.SetDefault(logger) // also reroutes the legacy log package through slog

logger.Info("payment captured",
	slog.String("order_id", orderID),
	slog.Int("amount_cents", amount),
	slog.Duration("elapsed", elapsed),
)

The two calling conventions are not equivalent. Alternating key-value args — logger.Info("msg", "key", val) — are convenient and box every value into any, allocating for most non-pointer types, and a missing key produces a !BADKEY attr at runtime instead of a compile error. Typed constructors — slog.String, slog.Int, slog.Duration — store the value inside slog.Value, a small union type, avoiding the heap for common kinds; LogAttrs is the strictest, fastest form. And one trap survives all conventions: arguments evaluate before the level check. A logger.Debug("x", "stats", computeStats()) with the handler at Info never emits a line, but computeStats() runs every single time — guard expensive expressions with logger.Enabled(ctx, slog.LevelDebug) or push the laziness into a LogValuer.

Levels are a contract with the on-call

Ask yourself: if this log line fires at 2 a.m., should someone wake up? That one question is all the level semantics you need. Levels mean nothing until your team gives them operational semantics, and the useful semantics are about who has to act. Debug: off in production, switched on per-incident; assume nobody sees it. Info: sparse state changes worth grepping later — deploys, connections established, jobs completed; if it fires on every request, it is volume, not signal. Warn: something degraded and self-healed — a retry succeeded, a fallback engaged; nobody wakes up, someone reviews the aggregate tomorrow. Error: a human must act; this level feeds alerts and pages. The most common corruption is logging expected client failures — validation errors, 404s — at Error: the pager habituates, alert thresholds get raised to cope, and the one Error that matters drowns in the noise. If nobody should act on it, it is not an Error.

Redaction at the type, not the call site

The Hook’s PAN leak happens because redaction was left to call-site discipline — every engineer must remember, forever, on every line. LogValuer moves the rule into the type system:

type CardNumber string

func (CardNumber) LogValue() slog.Value {
	return slog.StringValue("[REDACTED]")
}

The handler resolves LogValue() at format time, so the raw value never reaches the writer — no matter who logs it, where, or inside which struct via a group. The same hook doubles as lazy evaluation: a LogValuer that computes an expensive summary only runs when the record actually passes the level gate, which is the clean fix for the Quiz-1 trap. Pair it with the Stringer-based redaction from the configuration lesson so fmt paths are covered too — the two interfaces protect different exits.

Per-request loggers and trace correlation

A request-scoped logger turns every log line into evidence: middleware does l := logger.With(slog.String("request_id", id)) and passes l down — typically through the context. With is cheap by design: the handler pre-formats the attached attrs once (JSONHandler renders them into a reusable byte prefix), so request_id costs once per request, not once per line. Carrying the logger in context technically bends the previous lesson’s rule against dependencies in context.Value — this is the accepted, eyes-open exception in most large Go codebases, because logging is ambient and a fallback to the default logger makes the failure mode harmless. The stricter alternative: pass plain ctx and use InfoContext, with a custom handler extracting trace_id and span_id from the context at format time. Either way, the goal is the same — every record carries the ids that let you pivot from a log line to the full distributed trace and back.

When logging is the bottleneck

The numbers that should be in your head: a JSON line with a handful of attrs costs on the order of a microsecond of CPU plus the writer syscall, and the writer is a mutex — every goroutine logging to the same os.Stderr serializes there. At 100k lines per second you are spending ten-plus percent of a core on formatting alone, contending on the writer lock, and shipping roughly 25 GB an hour into an ingestion pipeline that bills by the gigabyte. The discipline for hot paths: log decisions and failures, not progress; sample high-volume Info (first N per key per window, or 1-in-N) while never sampling errors; and emit rates as metrics instead of log lines — a counter increments in nanoseconds and aggregates for free. The Hook’s consumer kept one line per batch and a sampled one per thousand messages; throughput came back, and so did the ingestion budget.