Structured Logging
Structured logging means emitting each log entry as a machine-readable object of named fields — typically JSON — instead of a free-text sentence. The shift is from logs you read to logs you query. Once every field (userId, statusCode, durationMs, requestId) is a discrete, indexed key, your log platform can filter, aggregate, alert, and trace across millions of lines. This page covers the principle, correlation IDs for request tracing, propagating context with AsyncLocalStorage, a sensible field schema, and the practices that make logs genuinely useful in production.
Unstructured vs structured — the difference that matters
// ❌ Unstructured — a human sentence; a machine sees one opaque string:
logger.info(`User ${userId} fetched order ${orderId} in ${ms}ms`)
// "User 42 fetched order 9981 in 87ms"
// → to find slow requests you must regex-parse the message. Painful.
// ✅ Structured — discrete fields a log platform indexes:
logger.info({ event: 'order_fetched', userId: 42, orderId: 9981, durationMs: 87 }){"level":"info","time":...,"event":"order_fetched","userId":42,
"orderId":9981,"durationMs":87}
# Now you can run queries your log platform understands:
# event:"order_fetched" AND durationMs:>500
# userId:42 | count by event
# avg(durationMs) by event over 1hCorrelation IDs — tracing one request across many lines
Generate or accept a request id, attach it to every log of that request
import { randomUUID } from 'node:crypto'
app.use((req, res, next) => {
// Honour an incoming id (from an upstream gateway/service) or make one:
req.id = req.headers['x-request-id'] || randomUUID()
res.setHeader('x-request-id', req.id) // echo it back to the client
req.log = logger.child({ requestId: req.id })
next()
})# All four lines below share requestId — one query reconstructs the request:
{"requestId":"abc-123","msg":"request received","method":"POST","path":"/orders"}
{"requestId":"abc-123","msg":"validating payload"}
{"requestId":"abc-123","msg":"charging payment","amount":120}
{"requestId":"abc-123","level":"error","msg":"payment declined","code":"card_declined"}Propagating context with AsyncLocalStorage
No more threading req.log through every function call
import { AsyncLocalStorage } from 'node:async_hooks'
const als = new AsyncLocalStorage()
// Middleware: run the rest of the request inside a context store:
app.use((req, res, next) => {
als.run({ requestId: req.id, userId: req.user?.id }, () => next())
})
// A logger that pulls context from the store automatically:
function log(level, msg, fields = {}) {
const ctx = als.getStore() ?? {}
logger[level]({ ...ctx, ...fields }, msg)
}
// Anywhere deep in the call stack — no req passed in, context still attached:
function chargeCard(amount) {
log('info', 'charging card', { amount }) // includes requestId + userId
}A sensible field schema
Field | Purpose |
|---|---|
| When it happened (ISO 8601 or epoch ms) |
| Severity ( |
| Constant, human-readable event description |
| Correlation across log lines and services |
| Which app and environment emitted it |
| Who the operation was for |
| Machine-friendly event name ( |
| How long an operation took (for latency analysis) |
| Serialized error: message, stack, code |
Practices
Constant message, variable fields —
msg:"order placed"plus{ orderId, amount }, never the values baked into the string.One event, one log line — don't split a single event across multiple lines; emit one object with all its context.
Always include a correlation id — it's the single most valuable field for debugging production.
Log the error object as a field (
{ err }) so the stack and code are captured, not stringified to{}.Use ISO 8601 or epoch timestamps — and log in UTC to avoid timezone confusion across regions.
Keep cardinality sane — avoid unbounded unique values (like full URLs with ids) as indexed fields where it explodes platform costs.