Chapter 12 — Logging & Observability

The why

It's 3am. Your on-call phone rings. "The portal is down. Agents can't submit orders." Without observability, you're guessing. With it, you find the root cause in 12 minutes.

The three pillars

Every production system needs all three. Each answers a different question:

Logs — structured, not strings

Bad logging (never do this)

// ❌ You can't query this, can't filter it, can't aggregate it
console.log('Order created: ' + orderId + ' for user ' + userId);
console.error(e);

Good logging (structured JSON)

// ✅ Every log is a queryable JSON object
this.logger.log('order.created', {
  order_id: orderId,
  user_id: userId,
  restaurant_id: restaurantId,
  trace_id: cid,
});
 
this.

Why structured? Because you can search for user_id:usr-123 in a log aggregator and see everything that happened for that user.

Log levels — use the right one

Never log these

• Passwords (even hashed)
• JWT tokens
• Credit card numbers / PAN
• Full request body on auth endpoints
• Full database connection strings
• Any process.env dump

Correlation IDs — trace a request through everything

Every incoming request gets a unique ID. Every log line from that request includes that ID. When a bug is reported, you search for the ID and see the complete picture.

2026-05-01T10:23:01Z  cid=7f3a-abc  svc=api     msg=POST /orders received
2026-05-01T10:23:01Z  cid=7f3a-abc  svc=api      msg=placing order  restaurant_id=rst-xyz
2026-05-01T10:23:01Z  cid=7f3a-abc  svc=orders   msg=validating items  count=3
2026-05-01T10:23:02Z  cid=7f3a-abc  svc=orders   msg=restaurant closed  opens_at=18:00 → RestaurantClosedException
2026-05-01T10:23:02Z  cid=7f3a-abc  svc=api     msg=returning 422

Grep for cid=7f3a-abc and you get the entire story in order.

How correlation IDs work in this project

1. Middleware sets the ID:

const cid = req.headers['x-request-id'] ?? randomUUID();
res.setHeader('x-request-id', cid);  // send back to client
asyncLocalStorage.run({ cid }, () =>

2. Logger reads it:

const { cid } = asyncLocalStorage.getStore() ?? {};
this.logger.log({ ...event, cid });

3. Outbound HTTP calls pass it along:

axios.post(url, body, {
  headers: { 'x-request-id': cid }
});

Traces — find where time is spent

A trace is a recording of one request's journey, broken into spans:

Request total: 1.2 seconds
  ├── JwtGuard: 2ms
  ├── ValidationPipe: 1ms
  ├── OrdersService.create: 1197ms
  │     ├── restaurantsService.isOpen: 5ms
  │     ├── orderItems.validate: 12ms
  │     ├── paymentsService.charge: 1150ms   ← HERE IS THE PROBLEM
  │     │     └── payment gateway API call: 1100ms  (external timeout)
  │     └── Order.create: 28ms
  └── Response serialization: 1ms

Without tracing, you'd know the request took 1.2 seconds. With tracing, you know it spent 1.1 seconds waiting for a database lock.

What to log on every endpoint

On every request (middleware/interceptor):

• Request: method, path, trace_id, user_id (if authenticated)
• Response: status code, duration_ms

On every business event (service):

• Event name: order.created, payment.processed, kyc.submitted
• Relevant IDs: order_id, user_id, restaurant_id
• Never the full entity — just the IDs and key facts

On every error:

• Error code/type (not the raw message — it may contain PII or secrets)
• Context: which operation, which entity, which user
• Trace ID

Metrics to ship from day 1

The console.log rule

// ❌ Banned everywhere in this codebase
console.log('debugging...');
console.error(e);
 
// ✅ Use NestJS Logger
private readonly logger = new Logger(OrdersService.name);

console.log bypasses the Winston logger, bypasses log levels, bypasses structured formatting, and bypasses the trace ID injection. It is useless in production.

One thing to remember