Structured Logging in Node.js: From console.log to Production Observability

Every Node.js service starts with console.log. And for the first thousand requests, it works fine. Then traffic spikes, an incident fires at 3 AM, and you're grepping through gigabytes of unstructured text trying to figure out which user hit which endpoint and why it returned a 500. That's the moment structured logging stops being optional.

This article covers the engineering decisions behind production-grade logging: format, transport, correlation, and integration with modern observability stacks.

Why console.log Breaks at Scale

console.log has three fundamental problems in production:

1. No structure. Output is a flat string. You can't filter, query, or aggregate without regex hacks.
2. No levels. Everything is the same priority. When your service emits 10,000 lines per minute, you need to distinguish a fatal database disconnection from a debug cache miss.
3. Synchronous stdout. In Node.js, console.log writes to stdout synchronously. Under heavy load, this blocks the event loop. Measured latency impact on a 50k RPM service: 12-18ms p99 increase.

There's also the operational gap: console.log output can't be parsed by log aggregators without custom transformers. Every minute you spend writing a Fluentd regex is a minute you're not shipping features.

Structured JSON Logging

Structured logging means every log entry is a machine-parseable JSON object with consistent fields:

{
  "level": "info",
  "time": 1711234567890,
  "pid": 42,
  "hostname": "prod-api-3",
  "reqId": "req-a1b2c3",
  "traceId": "4bf92f3577b34da6a3ce929d0e0e4736",
  "msg": "order created",
  "orderId": "ord-9182",
  "userId": "usr-7281",
  "durationMs": 47
}

Every field is indexed, queryable, and aggregatable. When your on-call engineer opens Grafana at 3 AM, they filter by level: "error" and traceId and see the full request lifecycle in seconds.

Pino vs Winston in 2026

Both are mature. The choice is straightforward.

Pino is the performance pick. It serializes JSON via sonic-boom (async I/O), uses worker threads for transport, and benchmarks at ~5x Winston throughput. Its API is minimal by design.

Winston is the flexibility pick. It has a rich transport ecosystem, custom formatters, and is easier to configure for teams that want printf-style output in development alongside JSON in production.

The verdict: For any service above 1,000 RPM, use Pino. The throughput difference is measurable. For internal tools and low-traffic services, either works. The rest of this article uses Pino because that's what we run at scale.

import pino from "pino";

const logger = pino({
  level: process.env.LOG_LEVEL || "info",
  formatters: {
    level(label: string) {
      return { level: label };
    },
  },
  timestamp: pino.stdTimeFunctions.isoTime,
  redact: ["req.headers.authorization", "body.password", "body.ssn"],
});

Note the redact array. This is non-negotiable. PII in logs is a compliance violation waiting to happen. Define your redaction paths in a shared config and enforce them via code review.

Correlation IDs: The Missing Link

A single user action often spans multiple services, queues, and database calls. Without correlation, you're matching timestamps and hoping.

Correlation IDs solve this. Generate one at the edge (API gateway or first service), then propagate it through every downstream call.

import { randomUUID } from "node:crypto";
import { AsyncLocalStorage } from "node:async_hooks";

interface RequestContext {
  reqId: string;
  traceId: string;
  userId?: string;
}

const als = new AsyncLocalStorage<RequestContext>();

// Express middleware
export function correlationMiddleware(req: Request, res: Response, next: NextFunction) {
  const traceId = (req.headers["x-trace-id"] as string) || randomUUID();
  const reqId = randomUUID();

  res.setHeader("x-trace-id", traceId);
  res.setHeader("x-request-id", reqId);

  als.run({ reqId, traceId, userId: req.user?.id }, () => next());
}

// Child logger that auto-injects context
export function getLogger(bindings?: Record<string, unknown>) {
  const ctx = als.getStore();
  return logger.child({
    reqId: ctx?.reqId,
    traceId: ctx?.traceId,
    userId: ctx?.userId,
    ...bindings,
  });
}

AsyncLocalStorage is the correct primitive here. It survives across await boundaries without manual threading. Every log call from getLogger() automatically includes the request context.

When you propagate traceId to downstream HTTP calls (via headers) and queue messages (via metadata), you get full distributed tracing from a single ID.

Log Levels in Practice

Most teams over-log. Here's how levels should map to operational reality:

Level	When to Use	Alert?
fatal	Process is crashing. Unrecoverable.	Page immediately
error	Operation failed, but service continues. Lost data or broken contract.	Alert within 5 min
warn	Degraded performance, retry succeeded, deprecated usage.	Dashboard only
info	Request completed, job finished, state transition.	Never
debug	Internal state, cache hits/misses, query plans.	Never
trace	Per-iteration data, raw payloads.	Never

Production should run at info. Flip to debug dynamically when investigating an issue -- Pino supports runtime level changes without restart:

// Expose an admin endpoint to toggle log level
app.put("/admin/log-level", requireAdmin, (req, res) => {
  const { level } = req.body;
  if (!["fatal", "error", "warn", "info", "debug", "trace"].includes(level)) {
    return res.status(400).json({ error: "Invalid level" });
  }
  logger.level = level;
  logger.info({ newLevel: level }, "log level changed at runtime");
  res.json({ level });
});

This avoids redeployment during incident investigation. Set it back to info when you're done.

Integrating with Grafana and Datadog

Structured JSON logs are already compatible with both stacks. The integration pattern is:

Grafana (Loki): Ship logs via Promtail or Grafana Agent. Loki indexes labels, not full text, so add consistent label fields (service, env, version). Query with LogQL:

{service="api-gateway"} | json | level="error" | traceId="4bf92f3577b34da6"

Datadog: Use the dd-trace library or ship via the Datadog Agent. Map traceId to Datadog's dd.trace_id for APM correlation. Add a Pino transport:

import pino from "pino";

const transport = pino.transport({
  targets: [
    {
      target: "pino-pretty",
      options: { colorize: true },
      level: "debug",
    },
    {
      target: "pino-datadog-transport",
      options: {
        apiKey: process.env.DD_API_KEY,
        service: "api-gateway",
        source: "nodejs",
      },
      level: "info",
    },
  ],
});

const logger = pino(transport);

Multi-target transports let you keep human-readable output in development while shipping JSON to your aggregator in production. Pino handles this via worker threads, so transports don't block your main event loop.

Log Rotation and Retention

If you're writing to files (non-containerized environments), rotation is mandatory. Use pino-roll or system-level logrotate:

const transport = pino.transport({
  target: "pino-roll",
  options: {
    file: "/var/log/api-gateway/app.log",
    frequency: "daily",
    limit: { count: 14 },
    mkdir: true,
  },
});

In containerized environments, write to stdout and let the orchestrator handle rotation. Docker and Kubernetes both have configurable log drivers with size limits.

Retention policy depends on compliance requirements. A reasonable default: 14 days hot (queryable in Loki/Datadog), 90 days cold (S3/GCS), 1 year archive for audit-sensitive services.

For tracking which code changes affect your logging configuration, tools like changelog-craft help you maintain a clear record of what changed and when. And when you need audit trails of repository activity -- who committed what, when, and in which services -- gitlog-weekly generates structured weekly reports that pair well with your log retention strategy.

Quick Start: Minimal Pino Setup

Copy this into a new service and you have production-grade logging in under 5 minutes:

// src/logger.ts
import pino from "pino";
import { AsyncLocalStorage } from "node:async_hooks";
import { randomUUID } from "node:crypto";

const als = new AsyncLocalStorage<{ reqId: string; traceId: string }>();

const baseLogger = pino({
  level: process.env.LOG_LEVEL || "info",
  formatters: {
    level: (label) => ({ level: label }),
  },
  timestamp: pino.stdTimeFunctions.isoTime,
  redact: ["req.headers.authorization", "body.password"],
});

export function withContext(traceId: string, fn: () => void) {
  als.run({ reqId: randomUUID(), traceId }, fn);
}

export function log(bindings?: Record<string, unknown>) {
  const ctx = als.getStore();
  return baseLogger.child({ ...ctx, ...bindings });
}

export { als, baseLogger };

// src/middleware.ts
import { Request, Response, NextFunction } from "express";
import { withContext, log } from "./logger";
import { randomUUID } from "node:crypto";

export function logging(req: Request, res: Response, next: NextFunction) {
  const traceId = (req.headers["x-trace-id"] as string) || randomUUID();
  const start = performance.now();

  res.on("finish", () => {
    log({ module: "http" }).info({
      method: req.method,
      url: req.url,
      status: res.statusCode,
      durationMs: Math.round(performance.now() - start),
    });
  });

  withContext(traceId, () => next());
}

Install: npm install pino pino-pretty. Run with pino-pretty piped in development: node dist/server.js | pino-pretty. In production, write raw JSON to stdout and let your log shipper handle it.

That's the full stack: structured output, correlation IDs, runtime level control, observability integration, and rotation. No more grepping through flat text at 3 AM.

---

Part of the Node.js Production Engineering series. Previously: Git Hooks for Node.js Teams, The Complete Dev Toolchain.