Command Palette

Search for a command to run...

Hectal
Case 0.1·Seeing Anything at AllSEV2

“A customer tweeted that checkout is broken. Is it? For whom? Since when?”

case name: Flying blind — build the lab

Service
shoplite-api
Impact
~20% of checkouts failed for 47 minutes
Detected by
A customer on social media — not the team
Time to resolve
47 min, most of it spent guessing

Skills you'll use on this case

the three signalsRED metrics/metrics and scrapingrate()error ratios

01 The investigation

  1. 10:02

    REPORT

    Support forwards a tweet: 'tried to pay 3 times, just says something went wrong 😡'

    The on-call engineer has no dashboard, no alert, no metrics. The only question anyone can ask is 'does it work for me?', and it does.

  2. 10:05

    FINDING

    All containers running, health checks green, CPU 12%

    The platform says everything is healthy. /healthz returns 200, because it doesn't touch the database or the payment provider. Infrastructure health isn't user-facing health.

  3. 10:09

    DEAD END

    Grep the logs by hand

    Unstructured console.log output from three containers: thousands of lines a minute. You can see that SOME requests fail, but not how many, which endpoint, or whether it's getting worse.

    terminal
    $ docker logs --since 10m shoplite 2>&1 | grep -ci error
    ── expected output ──
    1183
    1,183 of what? Out of how many requests? Since when? A number without a denominator or a timeline answers nothing.
  4. 10:21

    DEAD END

    Hypothesis: the payment provider is down

    Their status page is green and a manual test payment succeeds. Twelve minutes gone.

  5. 10:38

    FINDING

    A developer spots could not obtain lock on row in relation "stock" in the log noise

    An admin script started at 10:00 was holding a long transaction on the stock table. Checkouts that touched the same rows timed out waiting for the lock.

  6. 10:49

    RESOLVED

    The admin script is killed; errors stop

    The postmortem's first action item isn't about locks. It's this: 'we had no way to know the error rate, the affected endpoint, or when it started'. The rest of this case builds exactly that.

Root cause

Technically: lock contention on stock from a long-running admin transaction. The reason it took 47 minutes, and a customer, to find: ShopLite emitted no METRICS, so nobody could answer 'what fraction of requests are failing, on which route, since when?'. It emitted only unstructured logs, which can't be aggregated.

02 The concepts behind it

Monitoring vs observability

MONITORING answers questions you decided on in advance: is the error rate above 1%? Is latency above 500 ms? It's dashboards and alerts for known failure modes.

OBSERVABILITY is the ability to answer NEW questions about your system from the outside, without shipping new code: 'why are only Android users in Mumbai seeing slow checkouts since 14:02?'. You get it by emitting rich, well-structured telemetry (metrics, logs, and traces) with the right context attached. Monitoring is something you do; observability is a property your system has.

The three signals, and what each is for

METRICS are numbers aggregated over time (request rate, error count, latency histograms). They're cheap to store and fast to query, perfect for dashboards and alerts, but they've lost the details of individual requests. They tell you THAT something is wrong.

LOGS are timestamped records of individual events, with as much detail as you like. They tell you WHAT happened: the exact error, the input, the user. TRACES record the path of one request across services, with the timing of each step. They tell you WHERE the time or the failure is. Chapter 0's other three cases each need a different one of these.

RED: the three numbers every service should expose

For request-driven services: RATE (requests per second), ERRORS (failed requests per second, or as a ratio), DURATION (latency, as a distribution). A single HISTOGRAM metric covers all three: http_request_duration_seconds with route and status labels gives you the count (rate), the count with status=~"5.." (errors), and buckets (duration).

For resources like CPUs, disks, and connection pools, the equivalent is USE: Utilisation, Saturation, Errors. Google's 'four golden signals' are RED plus saturation.

Pull-based scraping and rate()

The app exposes current counter values at /metrics as plain text. Prometheus SCRAPES (pulls) every target every 15 seconds and stores each sample. Counters only ever go up, so the raw number (http_request_duration_seconds_count = 184233) is useless on its own; rate(counter[1m]) turns it into 'per second, averaged over the last minute', and correctly handles counter resets when a process restarts.

Pulling means Prometheus knows when a target is DOWN (the up metric is 0), which push-based systems can't distinguish from 'nothing to report'.

03 The fix

  1. 01The lab layout

    One folder, one docker compose up. ShopLite (the API) calls a small payments service and Postgres. Telemetry flows to Prometheus (metrics), Loki (logs, collected from container output by Grafana Alloy), and Tempo (traces, sent over OTLP). Grafana reads all three. k6 generates steady traffic around the clock so there's always something to look at.

    obs-lab/ (tree)whole filebash
    obs-lab/
    ├── docker-compose.yml
    ├── db/init.sql
    ├── shoplite/      server.js · tracing.js · package.json · Dockerfile
    ├── payments/      server.js · tracing.js · package.json · Dockerfile
    ├── prometheus/    prometheus.yml · alerts.yml
    ├── grafana/provisioning/datasources/datasources.yml
    ├── alloy/config.alloy
    ├── tempo/tempo.yml
    └── k6/load.js
  2. 02docker-compose.yml

    Pin image versions, as with anything else you'd run for real. The versions below were current when this was written; newer patch versions are fine. Grafana runs on port 3001 so it doesn't collide with other things you might have on 3000. Anonymous admin access is for a local lab only.

    obs-lab/docker-compose.ymlwhole fileyaml
    services:
      postgres:
        image: postgres:16-alpine
        environment:
          POSTGRES_PASSWORD: shoplite
          POSTGRES_DB: shoplite
        volumes:
          - ./db/init.sql:/docker-entrypoint-initdb.d/init.sql:ro
    
      shoplite:
        build: ./shoplite
        container_name: shoplite
        restart: unless-stopped
        environment:
          DATABASE_URL: postgres://postgres:shoplite@postgres:5432/shoplite
          PAYMENTS_URL: http://payments:8081
          OTEL_SERVICE_NAME: shoplite
          OTEL_EXPORTER_OTLP_ENDPOINT: http://tempo:4318
        ports: ["8080:8080"]
        depends_on: [postgres, payments]
    
      payments:
        build: ./payments
        container_name: payments
        environment:
          OTEL_SERVICE_NAME: payments
          OTEL_EXPORTER_OTLP_ENDPOINT: http://tempo:4318
        ports: ["8081:8081"]
    
      prometheus:
        image: prom/prometheus:v3.5.0
        command:
          - --config.file=/etc/prometheus/prometheus.yml
          - --web.enable-lifecycle          # allows POST /-/reload after config edits
        volumes: ["./prometheus:/etc/prometheus:ro"]
        ports: ["9090:9090"]
    
      loki:
        image: grafana/loki:3.5.3
        command: -config.file=/etc/loki/local-config.yaml
        ports: ["3100:3100"]
    
      tempo:
        image: grafana/tempo:2.8.2
        command: -config.file=/etc/tempo.yml
        volumes: ["./tempo/tempo.yml:/etc/tempo.yml:ro"]
        ports: ["3200:3200"]
    
      alloy:
        image: grafana/alloy:v1.10.0
        command: run /etc/alloy/config.alloy
        volumes:
          - ./alloy/config.alloy:/etc/alloy/config.alloy:ro
          - /var/run/docker.sock:/var/run/docker.sock:ro
    
      grafana:
        image: grafana/grafana:12.1.0
        environment:
          GF_AUTH_ANONYMOUS_ENABLED: "true"
          GF_AUTH_ANONYMOUS_ORG_ROLE: Admin
        volumes: ["./grafana/provisioning:/etc/grafana/provisioning:ro"]
        ports: ["3001:3000"]
    
      k6:
        image: grafana/k6:1.2.0
        command: run /scripts/load.js
        volumes: ["./k6:/scripts:ro"]
        depends_on: [shoplite]
  3. 03ShopLite, instrumented — with built-in incidents

    Three kinds of instrumentation. tracing.js starts OpenTelemetry BEFORE anything else is required, so Express, pg, fetch, and pino are auto-instrumented: every request becomes a trace, and every log line gets the trace_id. prom-client exposes default process metrics plus one histogram for RED. pino writes one JSON object per log line.

    The chaos set is how this course reproduces incidents: POST /admin/chaos {"scenario": "..."} switches on a failure mode, and {"enabled": false} switches it off. Read the scenarios now. Each one is a later case.

    obs-lab/shoplite/server.jswhole filejs
    require("./tracing"); // must be first: patches express, pg, fetch, pino
    const express = require("express");
    const { Pool } = require("pg");
    const pino = require("pino");
    const pinoHttp = require("pino-http");
    const client = require("prom-client");
    
    const log = pino({ level: process.env.LOG_LEVEL ?? "info" });
    const db = new Pool({ connectionString: process.env.DATABASE_URL, max: 10 });
    const PAYMENTS_URL = process.env.PAYMENTS_URL ?? "http://payments:8081";
    
    // Incident switches — toggled with POST /admin/chaos
    const chaos = new Set();
    const leak = [];
    
    // ── Metrics ──────────────────────────────────────────
    client.collectDefaultMetrics();
    const httpDuration = new client.Histogram({
      name: "http_request_duration_seconds",
      help: "HTTP request duration in seconds",
      labelNames: ["method", "route", "status"],
      buckets: [0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10],
    });
    const cartViews = new client.Counter({
      name: "shoplite_cart_views_total",
      help: "Cart views",
      labelNames: ["user_id"],
    });
    
    const app = express();
    app.use(express.json());
    app.use(pinoHttp({ logger: log, autoLogging: { ignore: (req) => req.url === "/metrics" } }));
    app.use((req, res, next) => {
      const end = httpDuration.startTimer({ method: req.method });
      res.on("finish", () => end({ route: req.route?.path ?? "unmatched", status: String(res.statusCode) }));
      next();
    });
    
    app.get("/healthz", (_req, res) => res.json({ status: "ok" }));
    
    app.get("/metrics", async (_req, res) => {
      res.set("content-type", client.register.contentType);
      res.end(await client.register.metrics());
    });
    
    app.get("/products", async (req, res) => {
      if (chaos.has("cpu-burn")) { const t = Date.now() + 50; while (Date.now() < t); }
      if (chaos.has("memory-leak")) leak.push(Buffer.alloc(100 * 1024)); // ~1.4 MB/s at lab traffic
      if (chaos.has("log-flood")) for (let i = 0; i < 100; i++) req.log.info({ i }, "cache probe");
      if (chaos.has("cardinality")) cartViews.inc({ user_id: String(Math.floor(Math.random() * 1e6)) });
    
      const { rows } = await db.query("select id, name, price from products order by id");
      if (chaos.has("n-plus-one")) {
        for (const p of rows) {
          const s = await db.query("select qty from stock where product_id = $1", [p.id]);
          p.stock = s.rows[0]?.qty;
        }
      }
      res.json(rows);
    });
    
    app.post("/checkout", async (req, res) => {
      const { productId = 1, qty = 1, card = "" } = req.body ?? {};
      if (chaos.has("pii")) req.log.info({ card, productId }, "checkout started");
      else req.log.info({ card_last4: String(card).slice(-4), productId }, "checkout started");
    
      try {
        if (chaos.has("errors") && Math.random() < 0.2) {
          throw Object.assign(new Error('could not obtain lock on row in relation "stock"'), { code: "55P03" });
        }
        const slow = chaos.has("slow-checkout") && Math.random() < 0.1;
        await db.query(slow ? "select pg_sleep(3)" : "select 1");
    
        const pay = await fetch(`${PAYMENTS_URL}/charge`, {
          method: "POST",
          headers: { "content-type": "application/json" },
          body: JSON.stringify({ amount: qty * 120 }),
          signal: AbortSignal.timeout(5000),
        });
        if (!pay.ok) throw new Error(`payment failed: ${pay.status}`);
    
        await db.query("insert into orders (product_id, qty) values ($1, $2)", [productId, qty]);
        res.status(201).json({ ok: true });
      } catch (err) {
        req.log.error({ err }, "checkout failed");
        res.status(500).json({ error: "something went wrong" });
      }
    });
    
    app.post("/admin/chaos", (req, res) => {
      const { scenario, enabled = true } = req.body ?? {};
      if (enabled) chaos.add(scenario); else chaos.delete(scenario);
      log.warn({ scenario, enabled }, "chaos toggled");
      res.json({ active: [...chaos] });
    });
    
    app.listen(8080, () => log.info("shoplite listening on 8080"));
  4. 04OpenTelemetry bootstrap (shared by both services)

    OTEL_SERVICE_NAME and OTEL_EXPORTER_OTLP_ENDPOINT come from the environment (see compose), so the same file works for every service. The file-system instrumentation is disabled because it produces thousands of useless spans. package.json needs express@4, pg, pino, pino-http, prom-client, @opentelemetry/sdk-node, @opentelemetry/auto-instrumentations-node, and @opentelemetry/exporter-trace-otlp-http. The Dockerfile is node:22-alpine with npm install --omit=dev and CMD ["node", "server.js"].

    obs-lab/shoplite/tracing.jswhole filejs
    const { NodeSDK } = require("@opentelemetry/sdk-node");
    const { getNodeAutoInstrumentations } = require("@opentelemetry/auto-instrumentations-node");
    const { OTLPTraceExporter } = require("@opentelemetry/exporter-trace-otlp-http");
    
    const sdk = new NodeSDK({
      traceExporter: new OTLPTraceExporter(), // → $OTEL_EXPORTER_OTLP_ENDPOINT/v1/traces
      instrumentations: [
        getNodeAutoInstrumentations({ "@opentelemetry/instrumentation-fs": { enabled: false } }),
      ],
    });
    
    sdk.start();
    process.on("SIGTERM", () => sdk.shutdown().finally(() => process.exit(0)));
  5. 05The payments service

    A deliberately tiny dependency: it waits 40–100 ms and 'captures' the payment. Its slow-payments scenario adds 2.5 seconds (Case 0.4). It exposes the same histogram, so both services can be compared with the same query.

    obs-lab/payments/server.jswhole filejs
    require("./tracing");
    const crypto = require("node:crypto");
    const express = require("express");
    const pino = require("pino");
    const pinoHttp = require("pino-http");
    const client = require("prom-client");
    
    const log = pino();
    const chaos = new Set();
    client.collectDefaultMetrics();
    const httpDuration = new client.Histogram({
      name: "http_request_duration_seconds",
      help: "HTTP request duration in seconds",
      labelNames: ["method", "route", "status"],
      buckets: [0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10],
    });
    
    const app = express();
    app.use(express.json());
    app.use(pinoHttp({ logger: log, autoLogging: { ignore: (req) => req.url === "/metrics" } }));
    app.use((req, res, next) => {
      const end = httpDuration.startTimer({ method: req.method });
      res.on("finish", () => end({ route: req.route?.path ?? "unmatched", status: String(res.statusCode) }));
      next();
    });
    
    app.post("/charge", async (_req, res) => {
      const delay = 40 + Math.random() * 60 + (chaos.has("slow-payments") ? 2500 : 0);
      await new Promise((r) => setTimeout(r, delay));
      res.json({ status: "captured", id: crypto.randomUUID() });
    });
    
    app.get("/metrics", async (_req, res) => {
      res.set("content-type", client.register.contentType);
      res.end(await client.register.metrics());
    });
    
    app.post("/admin/chaos", (req, res) => {
      const { scenario, enabled = true } = req.body ?? {};
      if (enabled) chaos.add(scenario); else chaos.delete(scenario);
      res.json({ active: [...chaos] });
    });
    
    app.listen(8081, () => log.info("payments listening on 8081"));
  6. 06Database seed and steady traffic

    Three products and their stock. k6 sends 20 requests per second forever: 70% product listings, 30% checkouts. Real systems always have traffic, and so should your lab, or every graph is flat.

    obs-lab/db/init.sql + k6/load.jswhole filejs
    -- db/init.sql
    create table products (id int primary key, name text not null, price int not null);
    create table stock (product_id int not null references products(id), qty int not null);
    create table orders (id bigserial primary key, product_id int not null, qty int not null,
                         created_at timestamptz not null default now());
    insert into products values (1, 'Masala Chai', 120), (2, 'Filter Coffee', 90), (3, 'Mango Lassi', 150);
    insert into stock values (1, 500), (2, 500), (3, 500);
    
    // k6/load.js
    import http from "k6/http";
    
    export const options = {
      scenarios: {
        shoppers: {
          executor: "constant-arrival-rate",
          rate: 20, timeUnit: "1s", duration: "24h",
          preAllocatedVUs: 20, maxVUs: 200,
        },
      },
    };
    
    const BASE = "http://shoplite:8080";
    
    export default function () {
      if (Math.random() < 0.7) {
        http.get(`${BASE}/products`);
      } else {
        http.post(`${BASE}/checkout`,
          JSON.stringify({ productId: 1 + Math.floor(Math.random() * 3), qty: 1, card: "4111111111111111" }),
          { headers: { "content-type": "application/json" } });
      }
    }
  7. 07Prometheus, Tempo, Alloy, and Grafana configuration

    Prometheus scrapes both services every 15 seconds. Tempo accepts OTLP on 4317/4318; the explicit 0.0.0.0 endpoints matter, because recent Tempo versions listen on localhost only by default. Alloy discovers containers through the Docker socket and ships their stdout to Loki, labelled by container name. Grafana is provisioned with all three data sources and linked in both directions: a trace_id in a log line becomes a link to Tempo, and a trace links back to its logs.

    obs-lab/prometheus · tempo · alloy · grafanawhole fileyaml
    # prometheus/prometheus.yml
    global:
      scrape_interval: 15s
      evaluation_interval: 15s
    rule_files: [/etc/prometheus/alerts.yml]
    scrape_configs:
      - job_name: shoplite
        static_configs: [{ targets: ["shoplite:8080"] }]
      - job_name: payments
        static_configs: [{ targets: ["payments:8081"] }]
      - job_name: prometheus
        static_configs: [{ targets: ["localhost:9090"] }]
    
    # prometheus/alerts.yml  (empty for now — Case 0.3 adds the first rule)
    groups: []
    
    # tempo/tempo.yml
    server:
      http_listen_port: 3200
    distributor:
      receivers:
        otlp:
          protocols:
            grpc: { endpoint: 0.0.0.0:4317 }
            http: { endpoint: 0.0.0.0:4318 }
    storage:
      trace:
        backend: local
        local: { path: /var/tempo/traces }
        wal: { path: /var/tempo/wal }
    
    # alloy/config.alloy  (Alloy syntax, not YAML)
    discovery.docker "containers" {
      host = "unix:///var/run/docker.sock"
    }
    discovery.relabel "containers" {
      targets = []
      rule {
        source_labels = ["__meta_docker_container_name"]
        regex         = "/(.*)"
        target_label  = "container"
      }
    }
    loki.source.docker "containers" {
      host          = "unix:///var/run/docker.sock"
      targets       = discovery.docker.containers.targets
      relabel_rules = discovery.relabel.containers.rules
      forward_to    = [loki.write.local.receiver]
    }
    loki.write "local" {
      endpoint { url = "http://loki:3100/loki/api/v1/push" }
    }
    
    # grafana/provisioning/datasources/datasources.yml
    apiVersion: 1
    datasources:
      - { name: Prometheus, type: prometheus, uid: prometheus, url: http://prometheus:9090, isDefault: true }
      - name: Loki
        type: loki
        uid: loki
        url: http://loki:3100
        jsonData:
          derivedFields:
            - name: trace_id
              matcherRegex: '"trace_id":"(\w+)"'
              datasourceUid: tempo
              url: '$${__value.raw}'
      - name: Tempo
        type: tempo
        uid: tempo
        url: http://tempo:3200
        jsonData:
          tracesToLogsV2: { datasourceUid: loki, filterByTraceID: true }
  8. 08Start it and confirm every target is up

    Give it a minute after up: containers build, Postgres seeds, k6 starts. Then open Prometheus at http://localhost:9090 (or Grafana Explore at http://localhost:3001) and run the first query in every monitoring setup, up. Every target should report 1.

    PromQL· Prometheus
    up
    result
    up{instance="localhost:9090", job="prometheus"}   1
    up{instance="payments:8081", job="payments"}     1
    up{instance="shoplite:8080", job="shoplite"}     1
    terminal
    $ cd obs-lab && docker compose up -d --build
    docker compose ps --format 'table {{.Service}}\t{{.State}}'
    ── expected output ──
    SERVICE STATE
    alloy running
    grafana running
    k6 running
    loki running
    payments running
    postgres running
    prometheus running
    shoplite running
    tempo running

04 Make sure it never surprises you again

  1. 01RATE — how much traffic, per route

    _count of a histogram is a counter of observations, one per request. rate(...[1m]) gives requests per second; sum by (route) collapses every other label (method, status, instance).

    PromQL· Prometheus
    sum by (route) (rate(http_request_duration_seconds_count{job="shoplite"}[1m]))
    result
    {route="/checkout"}   6.02
    {route="/products"}  13.97
  2. 02ERRORS — replay today's incident and watch it show up

    Trigger the errors scenario, wait a minute, and compute the error RATIO: 5xx requests divided by all requests. Do it per route. Across all routes it's only about 6%, which sounds survivable. Per route, 20% of checkouts fail, which is the number that matters to a customer.

    PromQL· Prometheus
    sum by (route) (rate(http_request_duration_seconds_count{job="shoplite", status=~"5.."}[1m]))
    /
    sum by (route) (rate(http_request_duration_seconds_count{job="shoplite"}[1m]))
    result
    {route="/checkout"}  0.198
    terminal
    $ curl -s -X POST localhost:8080/admin/chaos -H 'content-type: application/json' -d '{"scenario":"errors"}'
    ── expected output ──
    {"active":["errors"]}
  3. 03Turn the incident off

    Every case ends by disabling its scenario so the next one starts clean. The error ratio returns to empty (no 5xx series at all) within a minute.

    terminal
    $ curl -s -X POST localhost:8080/admin/chaos -H 'content-type: application/json' -d '{"scenario":"errors","enabled":false}'
    ── expected output ──
    {"active":[]}

05 Your turn: write the query

Run each one against your lab before revealing the answer. Share your own version in the comments; there's usually more than one correct query.

01

Write a query that returns the total requests per second across ALL services (shoplite and payments), broken down by job.

02

Stop the payments container (docker compose stop payments). Which query tells you it's gone, and what happens to ShopLite's checkout error ratio? Start it again afterwards.

03

Why is rate(http_request_duration_seconds_count[1m]) better than looking at http_request_duration_seconds_count directly?

06 Interview questions from this case

01

What's the difference between monitoring and observability?

02

Explain the RED and USE methods.

03

Why does Prometheus pull metrics instead of having apps push them?

0/4 · 0%