“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
/metrics and scrapingrate()error ratios01 The investigation
- 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.
- 10:05
FINDING
All containers running, health checks green, CPU 12%
The platform says everything is healthy.
/healthzreturns 200, because it doesn't touch the database or the payment provider. Infrastructure health isn't user-facing health. - 10:09
DEAD END
Grep the logs by hand
Unstructured
console.logoutput 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 ──11831,183 of what? Out of how many requests? Since when? A number without a denominator or a timeline answers nothing. - 10:21
DEAD END
Hypothesis: the payment provider is down
Their status page is green and a manual test payment succeeds. Twelve minutes gone.
- 10:38
FINDING
A developer spots
could not obtain lock on row in relation "stock"in the log noiseAn admin script started at 10:00 was holding a long transaction on the
stocktable. Checkouts that touched the same rows timed out waiting for the lock. - 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
01The lab layout
One folder, one
docker compose up. ShopLite (the API) calls a smallpaymentsservice 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.js02docker-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]03ShopLite, instrumented — with built-in incidents
Three kinds of instrumentation.
tracing.jsstarts OpenTelemetry BEFORE anything else is required, so Express,pg,fetch, andpinoare auto-instrumented: every request becomes a trace, and every log line gets thetrace_id.prom-clientexposes default process metrics plus one histogram for RED.pinowrites one JSON object per log line.The
chaosset 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"));04OpenTelemetry bootstrap (shared by both services)
OTEL_SERVICE_NAMEandOTEL_EXPORTER_OTLP_ENDPOINTcome 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.jsonneedsexpress@4,pg,pino,pino-http,prom-client,@opentelemetry/sdk-node,@opentelemetry/auto-instrumentations-node, and@opentelemetry/exporter-trace-otlp-http. The Dockerfile isnode:22-alpinewithnpm install --omit=devandCMD ["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)));05The payments service
A deliberately tiny dependency: it waits 40–100 ms and 'captures' the payment. Its
slow-paymentsscenario 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"));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" } }); } }07Prometheus, Tempo, Alloy, and Grafana configuration
Prometheus scrapes both services every 15 seconds. Tempo accepts OTLP on 4317/4318; the explicit
0.0.0.0endpoints 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: atrace_idin 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 }08Start it and confirm every target is up
Give it a minute after
up: containers build, Postgres seeds, k6 starts. Then open Prometheus athttp://localhost:9090(or Grafana Explore athttp://localhost:3001) and run the first query in every monitoring setup,up. Every target should report 1.PromQL· Prometheusupresultup{instance="localhost:9090", job="prometheus"} 1 up{instance="payments:8081", job="payments"} 1 up{instance="shoplite:8080", job="shoplite"} 1terminal$ cd obs-lab && docker compose up -d --builddocker compose ps --format 'table {{.Service}}\t{{.State}}'── expected output ──SERVICE STATEalloy runninggrafana runningk6 runningloki runningpayments runningpostgres runningprometheus runningshoplite runningtempo running
04 Make sure it never surprises you again
01RATE — how much traffic, per route
_countof 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· Prometheussum by (route) (rate(http_request_duration_seconds_count{job="shoplite"}[1m]))result{route="/checkout"} 6.02 {route="/products"} 13.9702ERRORS — replay today's incident and watch it show up
Trigger the
errorsscenario, 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· Prometheussum 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.198terminal$ curl -s -X POST localhost:8080/admin/chaos -H 'content-type: application/json' -d '{"scenario":"errors"}'── expected output ──{"active":["errors"]}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.
Write a query that returns the total requests per second across ALL services (shoplite and payments), broken down by job.
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.
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
What's the difference between monitoring and observability?
Explain the RED and USE methods.
Why does Prometheus pull metrics instead of having apps push them?