Structured logging that is still greppable in six months

Logs have a second life, and it starts the day you stop reading them. When the next engineer is on call and the page fires at 2am, they will grep for stable log fields across six months of rotated files — and every formatting convenience you chose for the original author becomes their tax. The fix is a set of conventions that keep logs machine-parsable and human-greppable at the same time.

Pick a format that grep can parse predictably

Newline-delimited JSON — one event per line, one line per event — is the baseline every other choice here builds on. A JSON log format only helps grep when the structure stays predictable line by line, so each field becomes a key you can search by exact value, and jq gives you a query layer when substring matching is too coarse:

grep '"level":"error"' app.ndjson | jq -r '.message'

Most structured logging best practices assume a shipper and a search UI; I'm going to assume grep is the UI, because it is the only tool guaranteed to be installed on whatever box you're debugging at 2am. The JSON Lines spec is short and worth sending to anyone who argues for pretty-printed output.

Pretty-printed multi-line JSON breaks tail, breaks grep -c, and breaks any log shipper that assumes one event per line. Most modern Node logging libraries write NDJSON by default; if you inherit a service that pretty-prints, fix that first, because nothing downstream works until it's done. It's usually one config flag.

Adopt Logstash-style field names as a minimum contract: @timestamp, level, message. Resist adding arbitrary nesting. A flat object is easier to grep, easier to jq, and easier to validate; nested objects force every consumer to agree on a path before they can ask a question.

Correlation IDs that survive service boundaries

Correlation ID logging pays for itself the first night you follow a failing checkout across three services. Generate a trace ID at the ingress — HTTP request start, queue consumer, cron run — and thread it through every downstream call via a header or context. In Node, AsyncLocalStorage from node:async_hooks is the mechanism that saves you from threading it by hand:

import { AsyncLocalStorage } from 'node:async_hooks';
import { randomUUID } from 'node:crypto';
import { createServer } from 'node:http';
import pino from 'pino';
 
const logger = pino({ base: { service: 'checkout-api' } });
const store = new AsyncLocalStorage<{ trace_id: string; span_id: string }>();
 
export function traceContext() {
  return store.getStore();
}
 
createServer((req, res) => {
  const trace_id = req.headers.traceparent?.split('-')[1] ?? randomUUID();
  const span_id = randomUUID();
  const requestLogger = logger.child({ trace_id, span_id });
 
  store.run({ trace_id, span_id }, () => {
    requestLogger.info({ method: req.method, url: req.url }, 'request started');
    res.end('ok');
  });
}).listen(3000);

The child logger carries trace_id and span_id on every line it writes, and any utility deep in the call tree can call traceContext() to get the same IDs without accepting an extra argument. If the caller already has a trace context — a W3C traceparent, or an opaque x-trace-id — continue it rather than generating a fresh ID. That's what turns per-service logs into a single timeline.

Name spans after the operation, not the function. process_payment beats handlePayment_v2 when you're searching six months later, because operations outlive implementations and renames.

Levels are for routing, not filtering only

Levels decide what gets persisted and who gets called, not just what you see in a terminal. Use error for failures that require human intervention, warn for recoverable anomalies worth knowing about, info for lifecycle events — boot, config load, shutdown — and debug for detailed observations you rarely grep in production. Reserve fatal for genuinely unrecoverable process exits, if you use it at all.

Set log level verbosity deliberately: production runs at info, and debug sits behind a config flag or environment variable so you can toggle it without a redeploy. Reading LOG_LEVEL at startup is fine; re-reading it on a signal is better.

Do not log sensitive data at any level. If a field name contains password, token, or secret, strip it at the log library boundary, not in analysis. Analysis-time redaction is security theater — the bytes have already left the host. A pino config that does the stripping looks like this:

import pino from 'pino';
 
export const logger = pino({
  level: process.env.LOG_LEVEL ?? 'info',
  base: { service: 'checkout-api' },
  formatters: {
    level: (label) => ({ level: label }),
  },
  redact: {
    paths: ['req.headers.authorization', '*.password', '*.token', '*.secret'],
    censor: '[redacted]',
  },
});

The redact option rewrites those paths anywhere they appear. The formatters.level callback is what keeps the grep patterns in this article honest, because pino's default numeric levels would write "level":30 and silently break grep '"level":"error"'.

Debug logs are the production analogue of breakpoints that log instead of pausing, and like breakpoints, they should be the exception, not the default.

Field naming and consistency

Pick one naming convention — snake_case or camelCase — write it in the contributing guide, and reject PRs that violate it. A mix of user_id in one service and userId in another breaks grep for stable log fields, and it's the first step toward ELK stack schema drift: schema drift is how the ELK stack goes from useful to decorative. It starts with one service renaming a field, and ends with dashboards showing gaps where data used to be.

Document a schema of required fields — severity, timestamp, message, service, trace_id — and make it part of code review. A new log line that omits one of them is a draft, not a merged feature. The service field should match the deployable unit, not the repo name; if the same unit runs in two regions, put region in its own field rather than embedding it in the service name.

Use enums for known values instead of free text. If order.status only takes values from [pending, confirmed, shipped, cancelled], grep for confirmed won't match a "confirmation email sent" line by accident, and aggregations over statuses come out clean.

Multi-line messages and stack traces

Multi-line log handling is where otherwise sane pipelines fall apart, and JavaScript makes it worse: JSON.stringify(new Error('boom')) is {} because Error properties are non-enumerable. Store the stack trace in a dedicated stack field, JSON-escaped like any other string, and keep the log to one line. Grep for the error message without matching every trace line.

If you use pino, pino.stdSerializers.err turns an Error into { type, message, stack } for you; in other libraries, serialize with Object.getOwnPropertyNames(err) rather than the default stringifier.

If you must write multi-line logs — legacy shippers sometimes force it — agree on a codec upfront instead of discovering it at 3am. The Logstash multiline codec folds continuation lines into the previous event with a pattern; fluentd's multiline filter does the same. Without one, the first line of a stack trace is one event and the rest are garbage, and grep across a restart boundary misses the error entirely.

Prefer structured error fields — error.type, error.code — over embedding error text in the message. That is harder to grep the day you introduce it, because you have to learn the field names. It's what lets you answer how many payment failures were timeouts versus declines without a regex against prose.

Rotation and grep without index files

Log rotation and grep are a pair: the rotation scheme you choose determines which grep patterns survive the month boundary. Date-rotated filenames shift the token you grep for — grep '2025-03' silently returns nothing in April. Size-based rotation with a fixed prefix keeps patterns stable, because only the numeric suffix changes.

Compress rotated shards with gzip and use zgrep; ripgrep's -z flag decompresses gzip in-process and is usually faster for the same search. If you haven't already aliased the common variants, shell functions that earn their dotfiles spot is the right home for a zlog function that greps the last N shards.

Avoid log shippers that mutate the original line. If you use ELK, keep the raw message untouched alongside any parsed fields: parsed fields feed dashboards, and the raw line feeds six-months-later grep for the thing you didn't think to parse.

Testing log output in CI

Field drift is a CI problem, not a Friday problem. A test that captures log output and asserts every error log carries trace_id and error.message catches drift before merge; a JSON schema validator catches the rest. This schema is the contract from earlier made executable:

{
  "$schema": "https://json-schema.org/draft/2020-12/schema",
  "type": "object",
  "additionalProperties": false,
  "required": ["@timestamp", "severity", "message", "service", "trace_id"],
  "properties": {
    "severity": { "enum": ["debug", "info", "warn", "error"] },
    "message": { "type": "string" },
    "service": { "type": "string" },
    "trace_id": { "type": "string", "minLength": 1 },
    "error": { "type": "object", "required": ["message"] }
  }
}

Feed every line your test suite emitted into Ajv and fail the build on the first violation. With additionalProperties: false, an unexpected field is a violation too — which makes renaming a field a build error instead of a silent gap in a production dashboard. This pairs well with GitHub Actions that fail fast and explain why: the job output should say which log line violated which field.

Finally, include a grep smoke test for known failure paths. If a payment decline is supposed to log at error, this should never be zero:

#!/usr/bin/env bash
set -euo pipefail
 
errors=$(grep -c '"level":"error"' test-results/checkout-failure.ndjson || true)
if (( errors == 0 )); then
  echo "expected at least one error log for the payment decline path" >&2
  exit 1
fi

It's a dumb test — that's the point. It fails when someone silences the logger, changes the level threshold, or removes the error call, and it fails in CI instead of in the incident review.

Key takeaways

• Newline-delimited JSON with flat, Logstash-style fields: one line per event, and every field is a key you can grep or jq.
• Generate a trace ID at the ingress and carry trace_id and span_id on every line; in Node, AsyncLocalStorage keeps you from threading it by hand.
• Levels route: error pages a human, warn survives, info is lifecycle, debug sits behind a flag — and redaction happens at the logger boundary, never in analysis.
• One naming convention, a documented required-field schema, and enums for known values, enforced in code review.
• Rotate by size, gzip the shards, and validate log shape in CI so drift fails the build, not the dashboard.