Structured Logging
Log events as typed key-value records rather than sentences, because the consumer is a query engine, not a person reading a terminal.
The requirement, the obvious build, and why it breaks
Every lesson starts where the work starts: someone asked for something, and the first implementation that comes to mind has a problem.
Why does it matter whether a log line is a sentence or a JSON object?
We need to answer "how many checkout failures did tenant 42 have on version 1.9.3 in the last hour" without writing a regex.
Write readable log messages with the values interpolated: logger.info(Order ${id} for tenant ${tenant} failed after ${ms}ms). It reads well in a terminal and it contains everything.
Every query becomes a regex against free text, and the regex breaks the first time someone rewords the message or adds a field in the middle.
- Every query becomes a regex against free text, and the regex breaks the first time someone rewords the message or adds a field in the middle.
- Values cannot be typed.
after 1200msis a string; you cannot ask for "duration greater than 1000" without parsing, and the parse is per-message-format. - Aggregation is impossible. Counting by tenant means extracting the tenant from a sentence whose shape differs in every one of the forty places it is logged.
- A multi-line stack trace becomes forty log records that the collector treats as unrelated events, so grouping and alerting on it does not work.
- Interpolated values with spaces, quotes or newlines silently corrupt the format, and a user-controlled value with a newline forges a whole extra log entry.
What is actually happening
- A structured log line is a record: a set of named, typed fields serialized in a machine-readable encoding — in practice one JSON object per line, though logfmt and binary formats exist.
- The message becomes one field among many, and stops being the carrier of data.
msg: 'order failed'plusorderId,tenantId,durationMsas separate fields. - Log pipelines index fields. An indexed field supports exact match, range queries, aggregation and grouping at scale; free text supports substring search, which is both slower and semantically weaker.
- Field names become a schema whether you design one or not. Two services calling it
tenant_idandtenantIdcannot be queried together, and nothing will tell you until the query returns nothing. - Context binding is what makes it ergonomic: a child logger carries
correlationId,tenantIdandversionso every line gets them without a call site remembering (Correlation Ids That Survive Every Hop). - Errors need explicit serialization. Passing an
Errorobject to a JSON serializer usually yields{}becausemessageandstackare non-enumerable — this surprises people once per language.
The consumer is a query engine
Free-text logging optimises for a person reading a scrolling terminal. That person exists during development and essentially never in production, where the reader is a search backend answering a question posed hours later by someone who was not there.
Once you accept that, the design follows: named fields, stable types, a consistent schema and a message that is decoration rather than data.
logger.info(`Order ${id} for tenant ${tenantId} failed after ${ms}ms: ${err.message}`)
// Order 8fa2 for tenant 42 failed after 1200ms: connection timeout
//
// To count failures by tenant you must regex the tenant out of a sentence
// whose wording differs in each of the 40 places it is written.
// To find slow ones you must parse "1200ms" back into a number.log.error({
event: 'order_create_failed',
orderId: id,
tenantId,
durationMs: ms,
error: serializeError(err), // { name, message, stack, cause: {...} }
}, 'order create failed')
// {"level":"error","event":"order_create_failed","orderId":"8fa2",
// "tenantId":42,"durationMs":1200,"error":{...},"msg":"order create failed"}
//
// count by tenantId where event = order_create_failed and durationMs > 1000The right-hand form supports exact match, numeric range and group-by directly on indexed fields. The left-hand form supports substring search, and every analysis is a parsing project that breaks when someone rewords the sentence.
Bind context once, not at every call site
redact and child APIs are its own. Python's structlog binds context via bind() and contextvars; Go's slog uses With() on a Logger; Java's Logback uses MDC. The pattern — bind at the boundary, never mutate a shared logger — is identical in all four.Structured logging fails in practice when every call site has to remember to include correlationId and tenantId. Half of them will not, and those are the lines you need. A child logger bound at the request boundary makes the fields automatic.
This is also where redaction and the core schema get enforced: one construction point, applied to every line the request produces.
1const root = pino({2 level: process.env.LOG_LEVEL ?? 'info',3 base: { service: 'orders-api', version: BUILD_SHA },4 // Enforced in the logger, so no call site can bypass it.5 redact: {6 paths: [7 'req.headers.authorization',8 'req.headers.cookie',9 '*.password',10 '*.token',11 'payment.card',12 ],13 censor: '[redacted]',14 },15})16 17// One child per request; never mutate the parent.18app.use((req, _res, next) => {19 req.log = root.child({20 correlationId: req.correlationId,21 tenantId: req.auth?.tenantId,22 userId: req.auth?.userId,23 })24 next()25})26 27// Every line downstream inherits the identifying fields for free.28req.log.warn({ event: 'inventory_degraded', sku }, 'falling back to cached stock')Redaction here is a safety net, not the control. The control is choosing which fields to pass — a path-based redactor cannot protect you from log.info({ user }) where user gains a sessionToken field next sprint.
The schema you did not design
Field names are a contract between every service that writes logs and every dashboard, alert and query that reads them. Nobody usually owns it, so it drifts, and drift is silent: a query filtering on tenant_id simply returns fewer rows when half the fleet writes tenantId.
A small enforced core is enough. The rest can be per-event, because per-event fields are only read alongside the event that produces them.
| Field | Type | Set by | Why it is core |
|---|---|---|---|
timestamp | RFC 3339 string | Logger | Ordering across hosts; never rely on ingestion time |
level | enum | Call site | Routing and alerting; the one field alerts may depend on |
service, version | string | Logger base | Narrowing to a deploy — the second question in every incident |
event | stable string | Call site | Machine identity of the event; msg may be reworded freely |
correlationId | string | Boundary child logger | Joining across services and workers (Correlation Ids That Survive Every Hop) |
tenantId, userId | string | Boundary child logger | Blast radius, and per-tenant investigation (Multi-Tenancy) |
error | object | Error serializer | Grouping by cause; must include the cause chain (Error Boundaries: Three Translations, Not One) |
durationMs | number | Call site | Numeric range queries — impossible if it is text |
How to build it
Most important first.
- Emit one JSON object per line to stdout. Let the platform collect it; do not build your own shipping unless you must (Infrastructure Logs).
- Fix a small core schema and enforce it:
timestamp,level,service,version,event,msg,correlationId,tenantId,userId,error. Everything else is per-event. - Prefer
snake_caseorcamelCaseconsistently across every service. Pick one; the choice does not matter and the consistency does. - Use a stable
eventfield for the machine andmsgfor the human. Queries filter onevent; dashboards and alerts should never depend onmsgtext. - Bind request context to a child logger at the boundary rather than passing fields to every call (Request Context Propagation).
- Serialize errors deliberately with a helper that extracts
name,message,stackand walks thecausechain into a nested field. - Configure redaction paths in the logger itself (
req.headers.authorization,payment.token), so a call site cannot bypass it (Secrets in Logs). - Keep a pretty-printer for local development. The reason teams resist structured logs is that raw JSON is unreadable in a terminal, and that is solvable in one line of configuration.
What can go wrong
- Schema drift:
tenant,tenantIdandtenant_idall in use, so a cross-service query silently under-reports rather than erroring. - A field whose type changes —
userIdas a number in one service and a string in another — which some log backends reject outright and others coerce into a second, invisible field. - Unbounded field explosion: putting a dynamic key in the object (
{ [userId]: true }) creates a new field per user, which is the log-index equivalent of high-cardinality labels and is far more expensive. - Logging a huge object because it is now easy: structured logging removes the friction that used to discourage dumping an entire entity.
- The mitigation failing — redaction configured by path, and the secret arrives at a different path because a caller nested the object one level deeper.
- JSON serialization cost on the hot path for large objects, and a crash inside the serializer on circular references.
- A shared logger with mutable bound context is a cross-request leak: if one request mutates the parent logger's fields, another request's line gets them. Child loggers must be created per request, never mutated globally (Backend Races).
- Structured logging removes log injection by construction: a newline inside a field value is escaped by the JSON encoder rather than starting a new record (Every Input Surface).
- It also makes redaction reliable, because the logger can address
passwordas a path rather than trying to find it inside a sentence. - The new risk is convenience: passing whole objects is now one argument, and whole objects contain tokens. Field allowlists are the control, not redaction denylists.
- A log backend with typed fields makes secrets easier to search for — which helps you audit, and helps anyone with read access to the log index. Access to logs is access to whatever is in them (Security-Safe Logging).
- "Structured means JSON." JSON is the common encoding; the property that matters is named typed fields. logfmt is structured; a JSON object containing one giant interpolated string is not.
- "We are structured — we log JSON." Not if the values are still embedded in
msg. The test is whether you can filter and aggregate without parsing text. - "The message text is the identity of the event." Use a separate stable
eventfield, or every reworded message breaks a dashboard. - "Structured logging replaces metrics." Counting log lines is a legitimate technique and an expensive one; a counter is orders of magnitude cheaper to aggregate (The Metrics a Backend Must Emit).
Operating it
- Query for the absence of core fields: any line with no
correlationIdor noservicenames a code path outside the standard logger. - Track distinct field names per service over time. A jump means someone introduced a dynamic key or a new schema.
- Alert on lines where
errorserialized to an empty object — the classic sign that anErrorwas passed to a raw JSON serializer. - Compare the count of
event: 'http_request'lines against your request-rate metric. A gap means requests are bypassing the boundary logger.
- At 10x, structured logs get *relatively* cheaper than free text because you can drop low-value fields and sample by event type rather than all-or-nothing.
- At 100x, the schema is what makes sampling intelligent: keep every line where
level >= warnorstatus >= 500, sampleevent: 'http_request'successes (The Log Bill and What It Is Buying). - JSON encoding cost becomes measurable at very high line rates. Loggers that serialize on a worker thread or use a faster encoder exist for this reason; the shape of the fix is "move it off the request path".
- Raw JSON is hostile to read without tooling. Local development needs a pretty-printer, and
kubectl logson a bad day needsjq. - A schema is a coordination cost. It needs an owner, and changing a core field name across services is a migration.
- Slightly higher bytes per line than terse free text, because field names repeat on every record. Compression recovers most of it, and it is a real cost at high volume.
Where this applies
Backend advice is context-sensitive. These labels say what each claim is specific to, and where a different stack or scale would differ.
- GENERALApplies to any language and any log backend. The technique predates and outlives any specific tool.
- LANGUAGE-SPECIFICError serialization differs and is the usual trip-hazard: JavaScript's Error has non-enumerable
messageandstack, soJSON.stringify(err)gives{}; Python's logging needsexc_info=Trueto attach a traceback; Go errors are interfaces whose useful detail is only reachable via errors.As. Each needs an explicit serializer. - CLOUD-SPECIFICSome managed log backends parse JSON on stdout automatically and index fields; others treat the line as text unless you configure a parser, and a few reserve field names (
message,severity,timestamp) with their own semantics. Whether your fields become queryable without configuration is a property of the platform, not of your logger.
Where the depth lives
This domain teaches the application-side mechanism and hands the rest off.