Checklist and Capstone

The checklist

Structured logging

• All logs are JSON — one object per line
• Every entry has: timestamp, level, message
• Log levels: debug, info, warn, error, fatal
• Level filtering via LOG_LEVEL environment variable
• info in production, debug in development
• Logger class with consistent API: logger.info(), logger.error(), etc.
• Errors to stderr, everything else to stdout

Request logging

• Every request gets a unique request ID
• Request ID returned in X-Request-Id response header
• Client-provided request IDs honored
• Every request logged: method, path, status, duration
• Level by status: 2xx→info, 4xx→warn, 5xx→error
• Slow request warnings (duration > threshold)

Context and correlation

• Request-scoped child logger with requestId, method, path
• User ID added to logger context after authentication
• Child loggers for scoped operations (orders, payments)
• Correlation IDs passed to background jobs
• Correlation IDs passed to external service calls via X-Request-Id

Business and performance

• Business events logged: entity.action format
• Database query timing with slow query warnings
• External API call timing and status
• Cache hit/miss logging
• Metrics: counters, gauges, histograms
• Periodic metrics snapshot (every 60 seconds)
• Health endpoint with metrics

Production

• Logs to stdout (twelve-factor app)
• Sensitive data redacted automatically
• Passwords, tokens, PII never appear in logs
• Request bodies not logged by default
• Environment and version in base context

Common mistakes

console.log in production. Every console.log should be replaced with a structured logger call. No exceptions.

Logging too little. No request logs, no error context. When something breaks, you cannot investigate. Log every request and every error with full context.

Logging too much. Logging every SQL query, every cache operation, every variable value — at info level in production. Use debug for verbose traces and set LOG_LEVEL=info in production.

No request IDs. Without request IDs, you cannot correlate multiple log entries to the same request. Every request must have an ID.

Logging sensitive data. Passwords, tokens, and PII in logs are security vulnerabilities. Use automatic redaction as a safety net.

No correlation IDs in jobs. The background job logs are disconnected from the request that triggered them. Pass the request ID as a correlation ID.

Metrics without logs. Metrics tell you “error rate is 5%” but not why. Logs tell you why. You need both.

The fully observable book catalog

// src/logger.ts
export const logger = new Logger({
  level: (process.env.LOG_LEVEL as Level) ?? "info",
  context: {
    service: "book-catalog",
    environment: process.env.NODE_ENV ?? "development",
    version: process.env.APP_VERSION ?? "unknown",
  },
});

// src/app.ts
import { setup, route } from "@hectoday/http";
import { logger } from "./logger.js";
import { metrics } from "./metrics.js";

export const app = setup({
  onRequest: ({ request }) => {
    const requestId = request.headers.get("x-request-id") ?? generateRequestId();
    const url = new URL(request.url);

    let userId: string | undefined;
    const authHeader = request.headers.get("authorization");
    if (authHeader) {
      try {
        userId = verifyToken(authHeader.replace("Bearer ", "")).userId;
      } catch {}
    }

    const log = logger.child({
      requestId,
      method: request.method,
      path: url.pathname,
      ...(userId ? { userId } : {}),
    });

    return {
      requestId,
      startTime: Date.now(),
      method: request.method,
      path: url.pathname,
      userId,
      log,
    };
  },

  onResponse: ({ response, locals }) => {
    const duration = Date.now() - (locals.startTime as number);
    const status = response.status;
    const level = status >= 500 ? "error" : status >= 400 ? "warn" : "info";

    (locals.log as Logger)[level]("request completed", { status, duration });

    metrics.increment("http.requests.total");
    metrics.increment(`http.status.${status}`);
    metrics.observe("http.response_time_ms", duration);

    if (duration > 100) {
      (locals.log as Logger).warn("slow request", { duration, threshold: 100 });
    }

    response.headers.set("X-Request-Id", locals.requestId as string);
    response.headers.set("X-Response-Time", `${duration}ms`);
  },

  onError: ({ error, request, locals }) => {
    const log = (locals?.log as Logger) ?? logger;

    log.error("unhandled error", {
      error: error.message,
      stack: error.stack,
      name: error.name,
    });

    metrics.increment("http.errors.unhandled");

    return Response.json(
      { error: { code: "INTERNAL_ERROR", message: "An unexpected error occurred" } },
      { status: 500 },
    );
  },

  routes: [
    route.get("/health", {
      resolve: () =>
        Response.json({
          status: "healthy",
          uptime: Math.round(process.uptime()),
          metrics: metrics.getSnapshot(),
        }),
    }),
    // ... book routes, review routes, etc.
  ],
});

// Periodic metrics logging
setInterval(() => {
  logger.info("metrics snapshot", metrics.getSnapshot());
  metrics.reset();
}, 60_000);

Every request logged. Every error contextualized. Every slow operation flagged. Metrics collected. Sensitive data redacted. Correlation IDs propagated. The API is observable.

Challenges

Challenge 1: Add alert thresholds. If the error rate exceeds 5% in a metrics window, log at fatal level. This simulates an alert.

Challenge 2: Add request body logging in debug mode. When LOG_LEVEL=debug, log the redacted request body. Verify sensitive fields are hidden.

Challenge 3: Build a log viewer. Create an endpoint that reads the last N log entries from a file and returns them as JSON. Add filtering by level, path, and time range.

Challenge 4: Integrate with the testing course. Write tests that verify: request IDs are returned in responses, errors are logged with stack traces, sensitive data is redacted.