Logging Architect

2024-01-15 14:23:45 ERROR Failed to process order #12345 for user john@example.com

{
  "timestamp": "2024-01-15T14:23:45.123Z",
  "level": "error",
  "message": "Failed to process order",
  "service": "order-service",
  "orderId": "12345",
  "userId": "usr_abc123",
  "error": {
    "type": "PaymentDeclined",
    "code": "CARD_DECLINED",
    "message": "Insufficient funds"
  },
  "requestId": "req_xyz789",
  "traceId": "trace_def456",
  "duration_ms": 342
}

import pino from "pino";

const logger = pino({
  level: ENV_CONFIG_VALUE || "info",
  formatters: {
    level: (label) => ({ level: label }),
  },
  timestamp: pino.stdTimeFunctions.isoTime,
  redact: ["req.headers.authorization", "user.email", "user.phone"],
});

// Create child logger with request context
function createRequestLogger(req) {
  return logger.child({
    requestId: req.id,
    method: req.method,
    path: req.url,
    userId: req.user?.id,
  });
}

// Usage
const log = createRequestLogger(req);
log.info({ orderId: order.id }, "Order created successfully");
log.error({ err, orderId: order.id }, "Failed to process payment");

Is the system about to crash or become unavailable?
  Yes -> FATAL

Did an operation fail with no automatic recovery?
  Yes -> ERROR

Did something unexpected happen but the system recovered?
  Yes -> WARN

Is this a normal business event that operators care about?
  Yes -> INFO

Is this technical detail needed only for troubleshooting?
  Yes -> DEBUG

Is this extremely granular, variable-level tracing?
  Yes -> TRACE

// Middleware to generate/propagate correlation ID
function correlationMiddleware(req, res, next) {
  const correlationId = req.headers["x-correlation-id"] || uuid();
  req.correlationId = correlationId;
  res.setHeader("x-correlation-id", correlationId);

  // Attach to all outgoing HTTP requests
  req.httpClient = HTTP client.create({
    headers: { "x-correlation-id": correlationId },
  });

  next();
}

Trace: req_abc123
  |
  +-- Span: API Gateway (12ms)
       |
       +-- Span: Auth Service - validateToken (3ms)
       |
       +-- Span: Order Service - createOrder (45ms)
            |
            +-- Span: Database - INSERT order (8ms)
            |
            +-- Span: Payment Service - charge (120ms)
            |    |
            |    +-- Span: Stripe API - POST /charges (95ms)
            |
            +-- Span: Email Service - sendConfirmation (15ms)

import { NodeSDK } from "@opentelemetry/sdk-node";
import { OTLPTraceExporter } from "@opentelemetry/exporter-trace-otlp-http";
import { getNodeAutoInstrumentations } from "@opentelemetry/auto-instrumentations-node";

const sdk = new NodeSDK({
  traceExporter: new OTLPTraceExporter({ url: "[reference URL]" }),
  instrumentations: [getNodeAutoInstrumentations()],
  serviceName: "order-service",
});
sdk.start();

[Service A] --logs--> [Log Shipper] --> [Message Queue] --> [Log Processor] --> [Storage] --> [Query/UI]

Example stack:
[App] --> [Fluentd/Filebeat] --> [Kafka] --> [Logstash] --> [Elasticsearch] --> [Kibana]

Or:
[App] --> [Promtail] --> [Loki] --> [Grafana]

Or:
[App] --> [OTLP] --> [OpenTelemetry Collector] --> [Backend of choice]

const logger = pino({
  redact: {
    paths: [
      "user.email",
      "user.phone",
      "user.ssn",
      "req.headers.authorization",
      "req.headers.cookie",
      "payment.cardNumber",
    ],
    censor: "[REDACTED]",
  },
});