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 queueHow 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_msorlatency, 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#
| Level | Use for | Who reads it |
|---|---|---|
| ERROR | Something failed and needs attention | On-call |
| WARN | Unexpected but handled | Reviewed periodically |
| INFO | Significant events — one per request is plenty | Debugging |
| DEBUG | Detail, off in production | Developers |
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_idWhy 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 uncompressedColumn 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#
| Store | Model | Good at |
|---|---|---|
| Grafana Loki | Indexes labels only; scans compressed chunks | Cheap, Kubernetes-native, grep-style queries |
| Elasticsearch / OpenSearch | Full-text inverted index | Search over message text |
| ClickHouse and similar column stores | Columns per field | Aggregations over wide events at large scale |
| Object storage (Parquet) | Files | Cheap 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#
- Run
wide.go. Addgpuandversionfields. Invent a problem that depends on both and find it with a group-by. - Estimate the daily volume of wide events for a service you know. What would you sample?
- Rewrite three unstructured log lines from a real project as structured events.
Check yourself#
- Why should the log message be a constant string?
- Why is high cardinality acceptable in an event but not in a metric label?
- Which categories of data must never be logged?