ObservabilityGENERALLANGUAGE-SPECIFICCLOUD-SPECIFIC

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.

What actually happensHow to build it

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.

The question

Why does it matter whether a log line is a sentence or a JSON object?

The requirement

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.

The obvious build

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.

Why it breaks

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.

How it breaks in production
  • 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 1200ms is 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.
RequirementAPI ContractApplication LogicData AccessExternal DepsConcurrencyFailureSecurityObservabilityDeploymentScale

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' plus orderId, tenantId, durationMs as 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_id and tenantId cannot 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, tenantId and version so every line gets them without a call site remembering (Correlation Ids That Survive Every Hop).
  • Errors need explicit serialization. Passing an Error object to a JSON serializer usually yields {} because message and stack are 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.

The same event, two encodings
Free text
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.
Structured record
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 > 1000

The 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

LANGUAGE-SPECIFICpino is a Node library and the 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.

A request-scoped child logger with enforced redaction
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.

FieldTypeSet byWhy it is core
timestampRFC 3339 stringLoggerOrdering across hosts; never rely on ingestion time
levelenumCall siteRouting and alerting; the one field alerts may depend on
service, versionstringLogger baseNarrowing to a deploy — the second question in every incident
eventstable stringCall siteMachine identity of the event; msg may be reworded freely
correlationIdstringBoundary child loggerJoining across services and workers (Correlation Ids That Survive Every Hop)
tenantId, userIdstringBoundary child loggerBlast radius, and per-tenant investigation (Multi-Tenancy)
errorobjectError serializerGrouping by cause; must include the cause chain (Error Boundaries: Three Translations, Not One)
durationMsnumberCall siteNumeric 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_case or camelCase consistently across every service. Pick one; the choice does not matter and the consistency does.
  • Use a stable event field for the machine and msg for the human. Queries filter on event; dashboards and alerts should never depend on msg text.
  • 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, stack and walks the cause chain 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

Failure modes
  • Schema drift: tenant, tenantId and tenant_id all in use, so a cross-service query silently under-reports rather than erroring.
  • A field whose type changes — userId as 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.
What can race
  • 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).
Security
  • 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 password as 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).
Misreads
  • "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 event field, 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

How you see it in production
  • Query for the absence of core fields: any line with no correlationId or no service names 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 error serialized to an empty object — the classic sign that an Error was 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.
What changes at 10x and 100x
  • 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 >= warn or status >= 500, sample event: '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".
What this costs
  • Raw JSON is hostile to read without tooling. Local development needs a pretty-printer, and kubectl logs on a bad day needs jq.
  • 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 message and stack, so JSON.stringify(err) gives {}; Python's logging needs exc_info=True to 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.