Below the API

Structured Logs and Wide Events

Basic Beginner 40 min Difficulty 2/5

Prerequisites I.02

The idea in one minute#

A log line written for humans — user 42 failed to load model after 3 tries — has to be parsed with a regular expression before a machine can use it. A structured log is a set of named fields: {"msg":"model load failed","user":42,"attempts":3}. Nothing to parse; every field is queryable.

Take that one step further and you get the wide event: instead of ten small log lines per request, emit one record at the end carrying everything you learned about that request — fifty fields, a hundred. It is the most useful single thing you can emit, and it is the foundation of what people call “observability 2.0”.

An analogy#

A doctor’s notes scribbled as prose, versus a form with boxes: age, blood pressure, medication. Both hold the same facts. Only the form can answer “show me every patient over 60 on this drug” without someone reading every page.

A picture#

flowchart TB
  subgraph NARROW["Many narrow lines"]
    direction TB
    N1["request received"] --> N2["auth ok"] --> N3["queued"] --> N4["model loaded"] --> N5["done in 1.2 s"]
  end
  subgraph WIDE["One wide event"]
    W["tenant, model, route, status,<br/>prompt_tokens, output_tokens,<br/>queue_ms, prefill_ms, decode_ms,<br/>replica, gpu, version, trace_id, ..."]
  end
  NARROW -->|"must be joined by request ID,<br/>then parsed"| QN["Slow, fragile queries"]
  WIDE -->|"one row per request"| QW["Group by any field"]
  class N1,N2,N3,N4,N5 neutral
  class W memory
  class QN warn
  class QW queue

How it really works#

Structured logging in Go#

The standard library’s log/slog (Go 1.21+) is all you need:

logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))
logger.Info("request done",
    "route", "/v1/chat", "status", 200, "duration_ms", 1042.5, "tenant", "acme")
{"time":"2026-10-03T09:00:00Z","level":"INFO","msg":"request done","route":"/v1/chat","status":200,"duration_ms":1042.5,"tenant":"acme"}

Rules:

  • The message is a constant. Variables go in fields. "request done" groups cleanly; "request 8812 done in 1042 ms" is a different string every time.
  • Consistent field names across services: decide once whether it is duration_ms or latency, and follow OpenTelemetry’s semantic conventions where a name exists (lesson 03).
  • Always include correlation IDs: trace_id, span_id, and a request ID.
  • Log to stdout. Collecting, shipping and rotating are the platform’s job.

Levels#

LevelUse forWho reads it
ERRORSomething failed and needs attentionOn-call
WARNUnexpected but handledReviewed periodically
INFOSignificant events — one per request is plentyDebugging
DEBUGDetail, off in productionDevelopers

An ERROR that nobody acts on is not an error; downgrade it. Alert from metrics, not from log lines.

The wide event#

Accumulate fields in the request’s context as it moves through your code, and emit once:

identity    tenant, user tier, API key ID (not the key)
request     route, method, model, stream, max_tokens, prompt_tokens
result      status, error_type, finish_reason, output_tokens
timings     queue_ms, prefill_ms, ttft_ms, decode_ms, total_ms
placement   region, cluster, node, pod, gpu_uuid, replica
version     service version, model revision, engine version, config hash
correlation trace_id, span_id, request_id

Why one event beats many lines: every question becomes a GROUP BY. “p99 ttft_ms by model and gpu for tenant = acme since the deploy” needs no joins.

High cardinality is fine here. Unlike a metric label (II.05), a field with a million distinct values costs storage per row, not a series per value. That is the trade: metrics are cheap per request and expensive per dimension; events are the reverse.

What it costs, and how to pay less#

1,000 req/s × 1.5 kB/event × 86,400 s ≈ 130 GB/day uncompressed

Column stores compress repetitive events 10–20×. Beyond that: sample (keep all errors and slow requests, a fraction of the rest — IV.04), drop DEBUG, and set retention by value: days for raw events, months for aggregates.

What must never be logged#

Secrets, tokens, passwords, full payment or health data — and, for AI systems, prompts and completions by default. They contain whatever users typed. Treat content capture as an explicit, access-controlled, opt-in feature with its own retention (V.04).

Where logs go#

StoreModelGood at
Grafana LokiIndexes labels only; scans compressed chunksCheap, Kubernetes-native, grep-style queries
Elasticsearch / OpenSearchFull-text inverted indexSearch over message text
ClickHouse and similar column storesColumns per fieldAggregations over wide events at large scale
Object storage (Parquet)FilesCheap long retention, queried in batch

Code#

// wide.go — accumulate fields during a request, emit one wide event, then query them.
package main

import (
	"context"
	"log/slog"
	"math/rand"
	"os"
	"sort"
)

type ctxKey struct{}

// Event collects fields for the lifetime of one request.
type Event struct{ attrs []slog.Attr }

func (e *Event) Set(k string, v any) { e.attrs = append(e.attrs, slog.Any(k, v)) }

func From(ctx context.Context) *Event { return ctx.Value(ctxKey{}).(*Event) }

func handle(ctx context.Context, rng *rand.Rand, tenant, model string) {
	ev := From(ctx)
	ev.Set("tenant", tenant)
	ev.Set("model", model)

	queue := rng.Float64() * 30
	prefill := 20 + rng.Float64()*120
	decode := 200 + rng.Float64()*900
	if model == "large" && tenant == "globex" {
		queue += 400 // the thing we will discover from the events
	}
	ev.Set("queue_ms", queue)
	ev.Set("prefill_ms", prefill)
	ev.Set("decode_ms", decode)
	ev.Set("total_ms", queue+prefill+decode)
	ev.Set("status", 200)
}

func main() {
	rng := rand.New(rand.NewSource(5))
	logger := slog.New(slog.NewJSONHandler(os.Stdout, nil))

	type key struct{ tenant, model string }
	queueBy := map[key][]float64{}

	tenants, models := []string{"acme", "globex"}, []string{"small", "large"}
	for i := 0; i < 400; i++ {
		ev := &Event{}
		ctx := context.WithValue(context.Background(), ctxKey{}, ev)
		t, m := tenants[rng.Intn(2)], models[rng.Intn(2)]
		handle(ctx, rng, t, m)
		if i < 2 { // print two so you can see the shape
			logger.LogAttrs(ctx, slog.LevelInfo, "request done", ev.attrs...)
		}
		for _, a := range ev.attrs {
			if a.Key == "queue_ms" {
				queueBy[key{t, m}] = append(queueBy[key{t, m}], a.Value.Float64())
			}
		}
	}

	// The "query": median queue time grouped by two fields nobody planned a dashboard for.
	keys := make([]key, 0, len(queueBy))
	for k := range queueBy {
		keys = append(keys, k)
	}
	sort.Slice(keys, func(i, j int) bool { return keys[i].tenant+keys[i].model < keys[j].tenant+keys[j].model })
	for _, k := range keys {
		xs := queueBy[k]
		sort.Float64s(xs)
		slog.Info("median queue", "tenant", k.tenant, "model", k.model, "queue_ms", xs[len(xs)/2])
	}
}

Remember this#

  • Constant message, variable fields, consistent names, correlation IDs.
  • One wide event per request beats many narrow lines.
  • High-cardinality fields are fine in events and fatal in metric labels.
  • Never log secrets; treat prompts and completions as sensitive and opt-in.

Try it#

  1. Run wide.go. Add gpu and version fields. Invent a problem that depends on both and find it with a group-by.
  2. Estimate the daily volume of wide events for a service you know. What would you sample?
  3. Rewrite three unstructured log lines from a real project as structured events.

Check yourself#

  1. Why should the log message be a constant string?
  2. Why is high cardinality acceptable in an event but not in a metric label?
  3. Which categories of data must never be logged?

↑↓ navigate ↵ open