Switch to Structured Logging
12 Feb 2026Grepping through console.log("user login failed", userId) at 2am, trying to correlate it with three other log lines that don’t share any common field, is the tax you pay for skipping structured logging. Switching is a small change with a large payoff, and you don’t need to rewrite everything at once.
What “structured” means
Unstructured: a string, meant for a human eye scanning a terminal.
2026-02-12 14:03:22 User login failed for user 4821
Structured: a JSON object, meant for a machine to filter and correlate, that a human can also read.
{"timestamp":"2026-02-12T14:03:22Z","level":"error","msg":"login failed","user_id":4821,"request_id":"a3f9c2","reason":"invalid_password"}
The difference matters the moment you have more than one log line to correlate. “Show me every log line for request_id: a3f9c2” is a filter, not a grep pattern you have to guess at. “Show me every failed login in the last hour, grouped by reason” is a query your log aggregator can actually answer.
The fields worth including on every line
timestamp— ISO 8601, always UTC. Don’t log local time; it turns into a debugging session across timezones later.level—debug,info,warn,error. Consistent values so you can filter by severity.msg— the human-readable part, still useful, just not the only field.request_id— generated once per incoming request, threaded through every log line that request touches. This is the single highest-value field for debugging — it’s what lets you pull every log line related to one user’s one broken request out of a sea of concurrent traffic.
Add domain-specific fields as needed: user_id, order_id, whatever your app’s core entities are.
Setting it up: pino (Node)
import pino from 'pino'
const logger = pino({
level: process.env.LOG_LEVEL || 'info',
timestamp: pino.stdTimeFunctions.isoTime,
})
logger.info({ user_id: 4821, request_id: req.id }, 'login failed')
Pino is fast specifically because it doesn’t format strings in the hot path — it writes JSON directly. In development, pipe through pino-pretty to get human-readable colorized output without changing the app code:
node app.js | npx pino-pretty
Threading request_id through
Generate it once, at the edge, and pass it down:
app.use((req, res, next) => {
req.id = req.headers['x-request-id'] || crypto.randomUUID()
req.log = logger.child({ request_id: req.id })
next()
})
Every downstream log call uses req.log instead of the base logger, and request_id shows up automatically without repeating it at every call site.
Migrating incrementally
You don’t need a rewrite. Wrap console.log calls as you touch that code, not in one pass across the whole codebase:
// Before
console.log('processing order', orderId)
// After, next time you're in this file
logger.info({ order_id: orderId }, 'processing order')
Old console.log lines keep working and keep showing up in your logs unstructured — they just won’t have the queryable fields. That’s fine as a transitional state. The value compounds as more of your hot paths (auth, payments, anything you actually debug under pressure) get converted, and it’s fine if some low-traffic admin script never does.
Where this pays off
The actual test: next incident, can you filter your log aggregator by request_id and see the complete story of one broken request, in order, across every service it touched? If yes, structured logging is doing its job. If you’re still grepping for a substring and hoping the surrounding lines are related, it isn’t finished yet — usually because request_id isn’t threaded through one of the paths that matters.
Takeaway
Pick a request_id field and a JSON logger, wire the request_id through your middleware once, and convert call sites opportunistically. The field that matters most is the correlation ID — everything else is a nice-to-have on top of it.