Structured Logging

A log line like Payment failed for user 4412 after 3 retries is written for a human reading one line, and it is nearly useless to a machine reading ten million. Every fact in it — who, how many attempts, what outcome — is welded into English prose. To count these failures per minute you first write a regex that un-welds them, and that regex breaks the day someone rewords the message.

Structured logging emits each event as one JSON object per line: the same information, but with user_id, retries, and outcome as named fields a machine can filter, aggregate, and join on. The change costs a logging-library swap and roughly 2–3x the bytes. It buys every query in the rest of this chapter.

Free Text and Its Failure Mode

Printf-style logging encodes fields into sentence shapes, so extracting them back means one regex per message shape — and a codebase accumulates hundreds of shapes. The first question grep cannot answer arrives fast: how many payment failures per minute, grouped by processor response code? Now you are maintaining a parsing layer that has to know every format string in five services, and any developer who edits a message silently breaks it. The data was structured inside the program; the formatter destroyed that structure at the exact moment of writing it down.

One Event Per Line

The convention that fixes this is NDJSON: each event is a single self-contained JSON object terminated by a newline. Any tool can split the stream into events by splitting on newlines — no stateful parser, no ambiguity about where one event ends and the next begins. This is what bookings emits when a request waits too long for a connection from its pool.

{"timestamp":"2026-07-11T09:14:32.114Z","level":"error",
 "service":"bookings","request_id":"3f9c2a7b41d8",
 "event":"conn_pool_timeout",
 "error":"connection pool timeout after 5003 ms",
 "pool_size":10,"wait_ms":5003}

The snippet is wrapped to fit this page; on disk it is exactly one line. One rule needs enforcing to keep it that way: multi-line stack traces must fold into a single event, carried in an exception field on the error line. Let a traceback print raw and one crash shatters into 40 separate "events" with no level and garbled timestamps, unreconstructable once interleaved with the output of other containers.

The Fields That Pay Rent

Five fields ride on every Harborline line, and each earns its bytes with a concrete query. timestamp (UTC, RFC 3339, millisecond precision) orders events across hosts into one truthful timeline. level filters by severity. service scopes a search to bookings without touching the other four streams. request_id — and trace_id, once Chapter 8 lands — stitches scattered lines back into requests. A field that enables no query is a field paying no rent; cut it.

request_id End to End

The request ID is minted once, at the edge: nginx in web generates it and forwards it as a header to everything downstream. Middleware in bookings, search, and payments binds the value to the logging context, so every line those services emit for that request carries the same ID without any call site having to remember it. The payoff is Mara's favorite new move — paste one ID into a query and watch a checkout's entire life play out across three containers, in order.

Structured Logging in bookings

In Python this is a library swap, not a rewrite. The bookings team replaces the stdlib formatter with structlog and a JSON renderer, and the rule at every call site becomes: the event name is a short stable token, every variable is a named field, nothing gets interpolated into prose.

log = structlog.get_logger()

# the call site behind the JSON line above
log.error("conn_pool_timeout",
          error="connection pool timeout after 5003 ms",
          pool_size=10, wait_ms=5003)

The call names the event conn_pool_timeout and attaches the pool size and the milliseconds the caller spent waiting; the renderer adds timestamp, level, service, and the bound request_id automatically. Mark this call site. It is the exact line Mara will be counting hundreds of on Saturday morning, and its fields are the difference between counting the errors and merely noticing them.

What Structure Costs

The honest bill: JSON lines run 2–3x the bytes of terse text, and the raw output is unpleasant for a human tailing a terminal. The fix is not prettier raw logs — it is a query layer (LogQL, topic 35) that parses fields back out on demand, plus naming discipline at write time. user_id means user_id in all five services; the moment one service logs userId and another logs uid, every cross-service query needs three parsers and correlation joins start returning nothing without an error anywhere.