Logging Setup

Install structured logging with levels, request IDs, and correlation context from day one.

Why

console.log is fine for a 50-line script but fatal in production: you can't filter by level, can't correlate logs across a request, and can't search them without SSH-ing into a box. Structured logging (JSON with level, timestamp, request_id, user_id) turns logs into queryable data — you can ask 'show me every error for user 42 in the last hour' and get an answer in seconds. The request ID is the multiplier: it ties every log line in a request together, so a user report 'checkout failed at 3pm' becomes a single grep, not a scroll through 10k lines. Setting this up retroactively is painful because every call site needs updating; doing it on day one is a 20-line config.

When

Right after project-init, before the first feature. Takes 20-30 min. Skip only for CLI tools with no server.

How

1. Pick a structured logger: pino (Node, fastest), structlog (Python), zap (Go)
   - Avoid winston/log4j — they're configurable but slow and encourage string templates

2. Define log levels and what each means for your app
   - debug: dev only; info: request lifecycle; warn: degraded but handled; error: needs attention
   - Set prod level to info, staging to debug — never trace in prod (volume kills you)

3. Add a request ID middleware that generates a UUID per request and logs it on every line
   - Express: req.id = uuid(); logger.child({ requestId: req.id })
   - Propagate to downstream calls via x-request-id header so the trace spans services

4. Log structured objects, not interpolated strings
   - logger.info({ userId, action: "checkout", durationMs }, "checkout completed")
   - NEVER logger.info(`User ${userId} checked out in ${ms}ms`) — unsearchable

5. Ship logs to a searchable sink: Datadog, Loki, CloudWatch — not a file on disk
   - Keep a local file fallback for dev; in prod, stdout → container log driver → aggregator

Example

// logger.ts — pino with request-id child
import pino from "pino";
export const logger = pino({
  level: process.env.LOG_LEVEL ?? "info",
  formatters: { level: (label) => ({ level: label }) },
});

// middleware.ts — per-request child logger
import { v4 as uuid } from "uuid";
export function requestLogger(req, res, next) {
  req.id = req.headers["x-request-id"] ?? uuid();
  req.log = logger.child({ requestId: req.id, userId: req.user?.id });
  req.log.info({ method: req.method, url: req.url }, "request start");
  res.on("finish", () => req.log.info({ status: res.statusCode }, "request end"));
  next();
}

// usage in a route — structured, searchable
router.post("/checkout", async (req, res) => {
  const t0 = Date.now();
  await processCheckout(req.body);
  req.log.info({ action: "checkout", durationMs: Date.now() - t0 }, "checkout ok");
});

Common Problems

⚠Logging secrets (passwords, tokens, PII) in info-level logs that ship to a third-party aggregator — a compliance incident.
⚠Using console.log in dev and a different logger in prod, so prod behavior is a surprise.
⚠No request ID, so a user report 'it failed at 3pm' means scrolling 10k lines hoping to spot the error.
⚠Logging at info level inside a hot loop (per-row in a 10k-row batch), drowning the aggregator in volume.

Best Practices

✓Add a redaction formatter that strips known-secret keys (password, token, authorization) before the log leaves the process.
✓Use a correlation ID that propagates across service boundaries (HTTP header, message queue attribute) so a multi-service trace is one query.
✓Sample debug/trace logs in prod (1 in 1000 requests) so you get occasional deep traces without the volume cost.
✓Alert on error-rate spikes, not individual errors — a single error is normal; a 10x spike in 5 minutes is an incident.