Chapter 9 — Logging & Debugging

The why

When production breaks, logs are usually all you have. If they're unstructured console.log strings, you'll spend an hour grepping. If they're structured JSON with request IDs, you'll find the bug in 30 seconds.

Logs are evidence

Treat every log line as evidence for a future investigation. The question is always "what happened to this one user at this one moment?"

To answer that, every log line needs:

• A timestamp (auto by every library).
• A level (debug, info, warn, error).
• A request ID (so you can chain logs for one user's journey).
• Context (user ID, route, params — minus secrets).
• A short, scannable message.

Unstructured strings can't answer that. Structured JSON can.

Pino — fast, structured

console.log flushes synchronously and prints arbitrary strings. Pino writes structured JSON and is ~10× faster.

npm install pino pino-http

import pino from 'pino';
 
export const logger = pino({
  level: process.env.LOG_LEVEL || 'info',
  // Pretty print in dev only
  transport: process.env.NODE_ENV

Two things to note:

• Pretty in dev, JSON in prod. A prod log line is a JSON object that log infra (Datadog, ELK, Loki) parses.
• redact — automatically strips sensitive fields. Always configure this.

Use it:

logger.info({ userId: 42 }, 'logged in');
logger.warn({ userId: 42, reason: 'wrong password' }, 'failed login');
logger.error({ err }, '

The first argument is structured context. The second is the human message. Don't put values inside the message string (logger.info('user 42 logged in')) — you can't filter on them.

Logging in Express with pino-http

import pinoHttp from 'pino-http';
import { logger } from './lib/logger';
 
app.use(pinoHttp({
  logger,
  customLogLevel: (req, res, err) => {
    if

Now every request automatically logs at completion with method, URL, status, latency.

Request IDs

A request ID is a UUID generated at the edge of your service. It travels through every log line and every outbound call. When you debug, you grep the ID and see every line for that one request.

import crypto from 'node:crypto';
export function requestId(req, res, next) {
  req.id = req.headers['x-request-id'] || crypto.randomUUID()

Forward it on outbound calls too:

fetch(url, { headers: { 'x-request-id': req.id } });

Now a single ID traces a request from the load balancer, through your service, to your downstream services. This is the single biggest debuggability win you can give yourself.

Log levels — when to use which

The rule of thumb: info is for expected events. error is for unexpected events. If a 4xx is normal (user typed wrong password), it's info, not error. If your alert system fires on every error, every wrong-password attempt wakes the on-call.

What NOT to log

• Passwords — ever, even hashed (in some flows).
• Full credit card numbers.
• Personal data the user can request to delete (GDPR).
• JWT signatures or refresh tokens.
• Big response bodies (filtering 50MB of logs sucks).

redact in Pino catches the obvious. Be thoughtful about the rest.

Debugging beyond logs

For tricky bugs, logs are step 1. Step 2: the Node inspector.

node --inspect-brk src/server.ts

Open Chrome → chrome://inspect → "inspect" your Node process. You get breakpoints, watch expressions, call stacks. The same UI you'd use for frontend JS.

VS Code has a built-in debugger:

{
  "version": "0.2.0",
  "configurations": [
    {
      "type": "node",
      "request": "launch",
      "name": "Debug server",
      "program"

Press F5. Set breakpoints. Step through.

Production observability — a preview

L5 covers the three pillars:

1. Logs (this chapter) — discrete events.
2. Metrics — aggregates (RPS, p95 latency, error rate).
3. Traces — request paths across services.

You don't need all three on day one. But your logs need a request ID now so day-one logs are still useful when you add traces in year two.

Common mistakes

Production · Performance · Security notes

Production. Ship logs to a remote service (Datadog, Logtail, ELK). Local files are a stopgap.

Performance. Pino is fast but logging is I/O. Don't put logger.debug({ entireDbResult }) in a hot loop.

Security. Configure redact paths before the first log line. Once a secret hits disk, it's logged forever.

Exercises

1. Beginner. Replace every console.log in your project with Pino.
2. Beginner. Add request IDs to every log line.
3. Intermediate. Configure redact for req.headers.authorization, *.password, *.token.
4. Advanced. Set up the VS Code debugger and breakpoint inside a route handler.

Summary

Use Pino for structured JSON logs. Add a request ID at the edge and propagate it through every log line and outbound call. Use levels meaningfully: info for expected, warn for degraded, error for unexpected. Configure redact so secrets never reach disk. When logs aren't enough, use the inspector or VS Code's debugger.

Quick recall

• Pino, not console.log.
• Request ID in every log line.
• info ≠ error. Don't page on user errors.
• redact before the first log.

Quiz

1. Why use Pino over console.log in production?
2. What log level should a 400 Bad Request get?
3. Where should request IDs be generated?
4. What does redact do in Pino config?