Implementing Observability in Microservices: A Step-by-Step Guide with Real Code

// package.json
{
  "scripts": {
    "start": "node --require ./dist/instrumentation.js dist/server.js",
    "dev": "ts-node --require ./src/instrumentation.ts src/server.ts"
  }
}

Step 3 — Structured Logging with Pino + Trace Correlation

The key requirement: every log line must include the active trace_id and span_id so Grafana can link logs → traces automatically.

src/logger.ts

import pino from "pino";
import { context, trace, isSpanContextValid } from "@opentelemetry/api";

// Custom mixin: inject trace_id + span_id from the active OTel span
function otelMixin() {
  const span = trace.getActiveSpan();
  if (!span) return {};

  const ctx = span.spanContext();
  if (!isSpanContextValid(ctx)) return {};

  return {
    trace_id: ctx.traceId,
    span_id: ctx.spanId,
    trace_flags: ctx.traceFlags,
  };
}

const logger = pino({
  level: process.env.LOG_LEVEL ?? "info",
  mixin: otelMixin,
  // Always include these fields on every log line
  base: {
    service: process.env.SERVICE_NAME ?? "order-service",
    version: process.env.SERVICE_VERSION ?? "1.0.0",
    environment: process.env.NODE_ENV ?? "development",
    pid: process.pid,
  },
  // Rename pino's default 'msg' field to 'message' for Loki compatibility
  messageKey: "message",
  timestamp: pino.stdTimeFunctions.isoTime,
});

export default logger;
export type Logger = typeof logger;

src/http-logger.ts — Automatic HTTP Request Logging

import pinoHttp from "pino-http";
import logger from "./logger";

export const httpLogger = pinoHttp({
  logger,
  // Custom log level per status code
  customLogLevel(req, res, err) {
    if (res.statusCode >= 500 || err) return "error";
    if (res.statusCode >= 400) return "warn";
    return "info";
  },
  // What to include in the request log
  customSuccessMessage(req, res) {
    return `${req.method} ${req.url} ${res.statusCode}`;
  },
  customErrorMessage(req, res, err) {
    return `${req.method} ${req.url} ${res.statusCode} — ${err.message}`;
  },
  // Redact sensitive fields before logging
  redact: {
    paths: ["req.headers.authorization", "req.body.password", "req.body.card_number"],
    censor: "[REDACTED]",
  },
  serializers: {
    req(req) {
      return {
        method: req.method,
        url: req.url,
        user_agent: req.headers["user-agent"],
        request_id: req.headers["x-request-id"],
      };
    },
    res(res) {
      return { status_code: res.statusCode };
    },
  },
});

Step 4 — Custom Application Metrics

OpenTelemetry auto-instrumentation gives you HTTP metrics for free. For business metrics, create them explicitly.

src/metrics.ts

import { metrics } from "@opentelemetry/api";

const meter = metrics.getMeter("order-service", "1.0.0");

// ── HTTP RED Metrics (supplement auto-instrumentation) ────────────────────────

export const requestCounter = meter.createCounter("http_requests_total", {
  description: "Total number of HTTP requests",
});

export const requestDuration = meter.createHistogram("http_request_duration_ms", {
  description: "HTTP request duration in milliseconds",
  unit: "ms",
  advice: {
    // Define explicit bucket boundaries for meaningful percentiles
    explicitBucketBoundaries: [5, 10, 25, 50, 100, 250, 500, 1000, 2500, 5000],
  },
});

export const activeRequests = meter.createUpDownCounter("http_active_requests", {
  description: "Number of requests currently being processed",
});

// ── Business Metrics ──────────────────────────────────────────────────────────

export const ordersCreated = meter.createCounter("orders_created_total", {
  description: "Total orders created",
});

export const orderValue = meter.createHistogram("order_value_usd", {
  description: "Monetary value of each order in USD",
  unit: "USD",
  advice: {
    explicitBucketBoundaries: [10, 50, 100, 250, 500, 1000, 5000],
  },
});

export const paymentOutcome = meter.createCounter("payment_outcomes_total", {
  description: "Payment outcomes broken down by result",
});

Middleware to Record Metrics Automatically

// src/middleware/metrics.middleware.ts
import { Request, Response, NextFunction } from "express";
import { requestCounter, requestDuration, activeRequests } from "../metrics";

export function metricsMiddleware(req: Request, res: Response, next: NextFunction) {
  const start = Date.now();
  const labels = { method: req.method, route: req.route?.path ?? req.path };

  activeRequests.add(1, labels);

  res.on("finish", () => {
    const duration = Date.now() - start;
    const fullLabels = { ...labels, status_code: String(res.statusCode) };

    requestCounter.add(1, fullLabels);
    requestDuration.record(duration, fullLabels);
    activeRequests.add(-1, labels);
  });

  next();
}

Step 5 — Wire It All Together in the Express Server

src/server.ts

import express from "express";
import { httpLogger } from "./http-logger";
import { metricsMiddleware } from "./middleware/metrics.middleware";
import logger from "./logger";
import { ordersCreated, orderValue, paymentOutcome } from "./metrics";
import { trace, SpanStatusCode } from "@opentelemetry/api";

const app = express();
app.use(express.json());
app.use(httpLogger);        // structured HTTP logs
app.use(metricsMiddleware); // RED metrics

const tracer = trace.getTracer("order-service");

// ── POST /orders ──────────────────────────────────────────────────────────────
app.post("/orders", async (req, res) => {
  const span = trace.getActiveSpan();
  const { user_id, items, total_usd } = req.body;

  // Attach business-relevant attributes to the trace
  span?.setAttributes({
    "order.user_id": user_id,
    "order.item_count": items?.length ?? 0,
    "order.total_usd": total_usd,
  });

  try {
    // Simulate calling an inventory service — creates a child span automatically
    const order = await createOrder({ user_id, items, total_usd });

    // Record business metrics
    ordersCreated.add(1, { region: req.headers["x-region"] as string ?? "unknown" });
    orderValue.record(total_usd, { region: req.headers["x-region"] as string ?? "unknown" });

    logger.info({ order_id: order.id, user_id, total_usd }, "Order created");
    res.status(201).json(order);
  } catch (err: any) {
    // Mark the span as errored — this is visible in Tempo
    span?.recordException(err);
    span?.setStatus({ code: SpanStatusCode.ERROR, message: err.message });

    logger.error({ user_id, error: err.message }, "Order creation failed");
    res.status(500).json({ error: "Order creation failed" });
  }
});

// ── GET /health ───────────────────────────────────────────────────────────────
app.get("/health", (req, res) => {
  res.json({ status: "ok", service: "order-service", timestamp: new Date().toISOString() });
});

// ── Simulate a downstream call with its own span ──────────────────────────────
async function createOrder(data: { user_id: string; items: any[]; total_usd: number }) {
  return tracer.startActiveSpan("db.insert_order", async (span) => {
    try {
      // Simulate DB latency
      await new Promise((r) => setTimeout(r, Math.random() * 50 + 10));

      const order = { id: `ord-${Date.now()}`, ...data, created_at: new Date().toISOString() };
      span.setAttributes({ "db.operation": "INSERT", "db.table": "orders" });
      return order;
    } finally {
      span.end();
    }
  });
}

const PORT = process.env.PORT ?? 8080;
app.listen(PORT, () => {
  logger.info({ port: PORT }, "Order service started");
});

Start the service pointing at your local OTel Collector:

SERVICE_NAME=order-service \
SERVICE_VERSION=1.0.0 \
OTEL_ENDPOINT=http://localhost:4317 \
NODE_ENV=development \
npm run dev

Send a test request:

curl -X POST http://localhost:8080/orders \
  -H "Content-Type: application/json" \
  -H "X-Region: eu-west" \
  -d '{"user_id":"user-123","items":[{"sku":"WIDGET-1","qty":2}],"total_usd":49.99}'

Open Grafana → Explore → select Tempo — you should see your first trace appear within a few seconds.

Step 6 — Prometheus Alert Rules (RED Method)

prometheus/rules/red-alerts.yml

groups:
  - name: RED Metrics — Per Service
    interval: 30s
    rules:

      # ── Error Rate ────────────────────────────────────────────────────────────
      - alert: HighErrorRate
        expr: |
          (
            sum by (service_name) (
              rate(app_http_requests_total{status_code=~"5.."}[5m])
            )
            /
            sum by (service_name) (
              rate(app_http_requests_total[5m])
            )
          ) > 0.01
        for: 2m
        labels:
          severity: critical
        annotations:
          summary: "High error rate on {{ $labels.service_name }}"
          description: "Error rate is {{ $value | humanizePercentage }} (threshold: 1%) for the last 2 minutes."

      # ── Latency ───────────────────────────────────────────────────────────────
      - alert: HighP99Latency
        expr: |
          histogram_quantile(0.99,
            sum by (service_name, le) (
              rate(app_http_request_duration_ms_bucket[5m])
            )
          ) > 2000
        for: 5m
        labels:
          severity: warning
        annotations:
          summary: "High p99 latency on {{ $labels.service_name }}"
          description: "p99 latency is {{ $value | humanizeDuration }}ms (threshold: 2000ms)."

      # ── Request Rate Drop (traffic anomaly) ───────────────────────────────────
      - alert: RequestRateDrop
        expr: |
          (
            sum by (service_name) (rate(app_http_requests_total[5m]))
            /
            sum by (service_name) (rate(app_http_requests_total[30m] offset 5m))
          ) < 0.5
        for: 3m
        labels:
          severity: warning
        annotations:
          summary: "Request rate dropped >50% on {{ $labels.service_name }}"
          description: "Current rate is less than 50% of the 30-min average. Possible upstream failure or deployment issue."

      # ── No Traffic (service may be down) ─────────────────────────────────────
      - alert: NoIncomingTraffic
        expr: |
          sum by (service_name) (rate(app_http_requests_total[5m])) == 0
        for: 5m
        labels:
          severity: critical
        annotations:
          summary: "No traffic on {{ $labels.service_name }}"
          description: "{{ $labels.service_name }} has received zero requests for 5 minutes."

  - name: SLO — Order Service
    rules:
      # 99.5% success rate SLO over a 30-day window
      - alert: SLOBurnRateFast
        expr: |
          (
            sum(rate(app_http_requests_total{service_name="order-service",status_code=~"5.."}[1h]))
            /
            sum(rate(app_http_requests_total{service_name="order-service"}[1h]))
          ) > (14.4 * 0.005)
        for: 2m
        labels:
          severity: critical
          slo: order_success_rate
        annotations:
          summary: "SLO burn rate critical — Order Service"
          description: "Burning error budget at 14.4× normal rate. At this pace the monthly SLO will breach in under 1 hour."

      - alert: SLOBurnRateSlow
        expr: |
          (
            sum(rate(app_http_requests_total{service_name="order-service",status_code=~"5.."}[6h]))
            /
            sum(rate(app_http_requests_total{service_name="order-service"}[6h]))
          ) > (6 * 0.005)
        for: 15m
        labels:
          severity: warning
          slo: order_success_rate
        annotations:
          summary: "SLO burn rate elevated — Order Service"
          description: "Burning error budget at 6× normal rate. Investigate within 1 hour."

Reload Prometheus to pick up the new rules:

curl -X POST http://localhost:9090/-/reload

Step 7 — Grafana Dashboard via JSON

Provision a dashboard automatically — create this file and Grafana will load it on startup.

grafana/provisioning/dashboards/dashboard.yaml

apiVersion: 1

providers:
  - name: Default
    folder: Services
    type: file
    options:
      path: /etc/grafana/provisioning/dashboards

grafana/provisioning/dashboards/red-dashboard.json

{
  "title": "Service RED Metrics",
  "uid": "red-metrics",
  "timezone": "browser",
  "panels": [
    {
      "title": "Request Rate (req/s)",
      "type": "timeseries",
      "gridPos": { "x": 0, "y": 0, "w": 8, "h": 8 },
      "targets": [
        {
          "datasource": "Prometheus",
          "expr": "sum by (service_name) (rate(app_http_requests_total[1m]))",
          "legendFormat": "{{ service_name }}"
        }
      ]
    },
    {
      "title": "Error Rate (%)",
      "type": "timeseries",
      "gridPos": { "x": 8, "y": 0, "w": 8, "h": 8 },
      "fieldConfig": {
        "defaults": { "unit": "percentunit", "thresholds": {
          "steps": [
            { "color": "green", "value": 0 },
            { "color": "yellow", "value": 0.005 },
            { "color": "red", "value": 0.01 }
          ]
        }}
      },
      "targets": [
        {
          "datasource": "Prometheus",
          "expr": "sum by (service_name) (rate(app_http_requests_total{status_code=~\"5..\"}[1m])) / sum by (service_name) (rate(app_http_requests_total[1m]))",
          "legendFormat": "{{ service_name }}"
        }
      ]
    },
    {
      "title": "p50 / p95 / p99 Latency (ms)",
      "type": "timeseries",
      "gridPos": { "x": 16, "y": 0, "w": 8, "h": 8 },
      "fieldConfig": { "defaults": { "unit": "ms" } },
      "targets": [
        {
          "datasource": "Prometheus",
          "expr": "histogram_quantile(0.50, sum by (le, service_name) (rate(app_http_request_duration_ms_bucket[1m])))",
          "legendFormat": "p50 {{ service_name }}"
        },
        {
          "datasource": "Prometheus",
          "expr": "histogram_quantile(0.95, sum by (le, service_name) (rate(app_http_request_duration_ms_bucket[1m])))",
          "legendFormat": "p95 {{ service_name }}"
        },
        {
          "datasource": "Prometheus",
          "expr": "histogram_quantile(0.99, sum by (le, service_name) (rate(app_http_request_duration_ms_bucket[1m])))",
          "legendFormat": "p99 {{ service_name }}"
        }
      ]
    }
  ],
  "schemaVersion": 39,
  "version": 1
}

Restart Grafana to apply the provisioned dashboard:

docker compose restart grafana

Open http://localhost:3030/d/red-metrics — your RED dashboard is live.

Step 8 — Load Test to Verify the Full Pipeline

Generate real traffic to see traces, logs, and metrics populate together:

# Install k6 (load testing tool)
# macOS: brew install k6
# Linux: snap install k6

cat > load-test.js << 'EOF'
import http from "k6/http";
import { sleep, check } from "k6";
import { randomIntBetween } from "https://jslib.k6.io/k6-utils/1.4.0/index.js";

export const options = {
  stages: [
    { duration: "30s", target: 10 },  // ramp up
    { duration: "1m",  target: 10 },  // steady
    { duration: "15s", target: 0 },   // ramp down
  ],
};

const regions = ["eu-west", "us-east", "ap-south"];

export default function () {
  // 90% success, 10% invalid payload (to generate errors)
  const payload = Math.random() > 0.1
    ? JSON.stringify({
        user_id: `user-${randomIntBetween(1, 1000)}`,
        items: [{ sku: "WIDGET-1", qty: randomIntBetween(1, 5) }],
        total_usd: randomIntBetween(10, 500),
      })
    : JSON.stringify({ bad: "payload" }); // triggers validation error

  const res = http.post("http://localhost:8080/orders", payload, {
    headers: {
      "Content-Type": "application/json",
      "X-Region": regions[randomIntBetween(0, regions.length - 1)],
    },
  });

  check(res, { "status is 2xx": (r) => r.status >= 200 && r.status < 300 });
  sleep(randomIntBetween(1, 3) / 10);
}
EOF

k6 run load-test.js

While the load test runs, go to Grafana and watch:

1. Explore → Prometheus — request rate, error rate, and latency histograms populate
2. Explore → Tempo — traces appear; filter by status = error to see failed traces
3. Explore → Loki — log stream appears; filter by {service_name="order-service"} | json | level="error"
4. Click any trace in Tempo → click "Logs for this span" → jumps directly to the correlated Loki logs

Step 9 — The Correlation Flow in Practice

This is the payoff. Here's the exact workflow when an alert fires:

Without this setup, step C through F would take hours of grep-ing through disconnected log files. With it, it takes three clicks.

Summary: What You Now Have

The complete source for this guide is structured to run with a single docker compose up -d plus npm run dev. Start there, get the correlation working locally, and then point the same OpenTelemetry SDK at your production collector endpoint — the instrumentation code doesn't change.

Questions on wiring this into a specific framework or cloud environment? Get in touch.