Week 13: Observability & Production Readiness

1. Structured JSON Logging

console.log is fine for local development and a genuine liability in production: it produces free-text lines that a log aggregator (Datadog, CloudWatch, Loki) can't reliably filter or query on fields like status code or user ID. Structured logging emits each log line as a JSON object instead, so every field is queryable. pino is the standard choice for Node — it's fast and JSON-first by default.

npm install pino
npm install -D pino-pretty

import pino from "pino";

const isDev = process.env.NODE_ENV !== "production";

export const logger = pino({
  level: process.env.LOG_LEVEL ?? "info",
  // In dev, pretty-print for humans reading a terminal. In production,
  // emit raw JSON -- that's what the log aggregator actually wants.
  transport: isDev ? { target: "pino-pretty" } : undefined,
  redact: ["req.headers.authorization", "req.headers.cookie", "*.password"],
});

{"level":30,"time":1735682400123,"msg":"user created","userId":"usr_9f2","route":"/signup"}

Every field in that object is now something a log platform can filter, group, and alert on — "show me every log line where route is /signup and level is 50 (error)" is a query, not a manual grep through free-text output.

2. Request Correlation IDs with AsyncLocalStorage

A single user action can touch multiple log lines across middleware, a route handler, and — as of Week 12 — a queued job processed by a completely different worker process. A correlation ID (or request ID) is a unique value generated once per request and attached to every log line produced while handling it, so you can filter your log aggregator to that one ID and see the entire story.

Threading that ID through every function call as an extra parameter is invasive and easy to forget. Node's built-in AsyncLocalStorage solves this properly: it's a store that's automatically available to any code running "underneath" an async call, without passing it explicitly.

import { AsyncLocalStorage } from "node:async_hooks";

type RequestContext = { requestId: string };

export const requestContext = new AsyncLocalStorage<RequestContext>();

export function getRequestId(): string {
  return requestContext.getStore()?.requestId ?? "no-request-context";
}

import { randomUUID } from "node:crypto";
import type { Request, Response, NextFunction } from "express";
import { requestContext } from "../lib/request-context.js";

export function requestIdMiddleware(req: Request, res: Response, next: NextFunction): void {
  // Reuse an upstream ID (e.g. from a load balancer or gateway) if present,
  // so a request's ID stays the same across every hop, not just inside this service.
  const requestId = (req.headers["x-request-id"] as string | undefined) ?? randomUUID();
  res.setHeader("x-request-id", requestId);

  requestContext.run({ requestId }, () => {
    next();
  });
}

Mount it as the very first middleware, before anything else runs, then have your logger automatically pull the ID out of the store on every call:

import pino from "pino";
import { getRequestId } from "./request-context.js";

const base = pino({ level: process.env.LOG_LEVEL ?? "info" });

export const logger = {
  info: (obj: Record<string, unknown>, msg: string) =>
    base.info({ ...obj, requestId: getRequestId() }, msg),
  error: (obj: Record<string, unknown>, msg: string) =>
    base.error({ ...obj, requestId: getRequestId() }, msg),
};

Now any code deep inside a route handler, a service function, or an error handler can call logger.info(...) and the correlation ID appears automatically — nothing had to pass it down manually. Extend the same job payload in Week 12's queue to carry the originating requestId, and the worker's logs can be correlated back to the request that enqueued them too.

3. Liveness & Readiness Health Checks

Container orchestrators like Kubernetes (and the platform you'll deploy to in Week 14) need a way to ask your app two genuinely different questions, and conflating them causes real production incidents:

• Liveness — "is this process still running and not deadlocked?" A failing liveness check tells the orchestrator to kill and restart the container.
• Readiness — "is this instance currently able to serve real traffic?" A failing readiness check tells the orchestrator to stop routing new requests here, without restarting anything.

A liveness check should be cheap and dependency-free — it answers "is the Node process itself responsive," nothing more:

import { Router } from "express";
import { prisma } from "../lib/prisma.js";
import { redis } from "../lib/redis.js";

export const healthRouter = Router();

// Liveness: just confirm the process can respond at all. No dependency checks --
// if the database is down but the process is fine, restarting the container
// would NOT fix the database and would just add a pointless restart loop.
healthRouter.get("/healthz", (_req, res) => {
  res.status(200).json({ status: "ok" });
});

// Readiness: confirm this instance can actually serve a real request right now.
healthRouter.get("/readyz", async (_req, res) => {
  try {
    await prisma.$queryRaw`SELECT 1`;
    await redis.ping();
    res.status(200).json({ status: "ready" });
  } catch (err) {
    res.status(503).json({ status: "not ready", error: (err as Error).message });
  }
});

The difference matters most exactly when a dependency is briefly unavailable: if a database connection blip made /healthz fail too, the orchestrator would restart every instance of your app in response to a problem a restart can't fix, while genuinely making things worse (a burst of container restarts under a database outage, instead of instances simply pausing traffic until the database recovers).

4. Metrics & Timing Instrumentation

Logs answer "what happened on this one request." Metrics answer "how is the system behaving in aggregate, right now" — request rate, error rate, and latency distribution. prom-client is the standard Node library for exposing metrics in the Prometheus format most monitoring stacks (Prometheus, Grafana, Datadog) can scrape directly.

npm install prom-client

import client from "prom-client";

client.collectDefaultMetrics(); // process CPU, memory, event loop lag, etc.

export const httpRequestDuration = new client.Histogram({
  name: "http_request_duration_seconds",
  help: "HTTP request duration in seconds",
  labelNames: ["method", "route", "status_code"],
  buckets: [0.01, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5],
});

export const registry = client.register;

import type { Request, Response, NextFunction } from "express";
import { httpRequestDuration } from "../lib/metrics.js";

export function metricsMiddleware(req: Request, res: Response, next: NextFunction): void {
  const end = httpRequestDuration.startTimer();

  res.on("finish", () => {
    end({
      method: req.method,
      // req.route.path is the pattern ("/products/:id"), not the literal URL --
      // using the literal URL would create a separate metric series per product ID.
      route: req.route?.path ?? "unmatched",
      status_code: res.statusCode,
    });
  });

  next();
}

import { Router } from "express";
import { registry } from "../lib/metrics.js";

export const metricsRouter = Router();

metricsRouter.get("/metrics", async (_req, res) => {
  res.set("Content-Type", registry.contentType);
  res.send(await registry.metrics());
});

A histogram (rather than a running average) is the right shape for latency: it buckets observations so you can compute percentiles like p50, p95 and p99 after the fact. An average of 80ms can hide a p99 of 4 seconds affecting one in a hundred users; a histogram makes that tail visible instead of averaging it away.

5. Hands-on Exercise

6. Knowledge Check

Four quick questions. Expand each to check your answer.