Observability: Logs, Correlation IDs, Metrics and Traces
It’s 3:04am. The pager went off because checkout error rate crossed 5%. You SSH into a box, tail the logs, and this is what your past self left you:
error
error
TypeError: Cannot read properties of undefined (reading 'total')
error
undefined is not an objectNo timestamp you trust, no user, no request id, no idea which of the four services this line came from, no way to tell if these five errors are one broken customer retrying or five thousand. You have a symptom and nothing else. The gap between “the graph is red” and “here is the exact broken request and why it broke” is the gap you close tonight, by hand, at 3am, under load, while the error budget burns.
That gap has a name. Monitoring tells you whether the system is broken. Observability is whether you can figure out why from the outside, without shipping new code to add a console.log and waiting for it to break again. Monitoring is a red light on the dashboard. Observability is being able to ask a question you didn’t predict you’d need to ask, and get an answer from data you already have.
The good news: it’s almost entirely about what you write down before the incident. This article is the stuff to write down.
These are the three pillars: logs, metrics, and traces. They overlap, and modern tooling blurs the lines, but they answer genuinely different questions. Let’s do each one properly, starting with the one you already use badly.
Logs: write them for a machine, not for your eyes
console.log('user', userId, 'failed checkout') feels like logging. It isn’t, not the kind that survives contact with production. It produces a sentence, and a sentence is something a human reads one at a time. When you have forty million log lines an hour across sixty pods, nobody reads. Machines query. And you cannot query a sentence.
The fix is boring and total: log structured JSON, one object per line. Every field you’d ever want to filter or group by becomes a key.
// bad: a sentence. greppable at best, and only if the wording never changes.
console.log(`user ${userId} checkout failed after ${retries} retries`);
// good: a record. every field is queryable.
logger.error({
msg: "checkout failed",
userId,
retries,
cartTotal: 48.20,
paymentProvider: "stripe",
});The second form prints something like {"level":"error","msg":"checkout failed","userId":4821,"retries":3,...}. Ugly to read raw. But now your log backend parses it, and the difference is everything.
In Node you don’t hand-roll this. Reach for a fast JSON logger. Pino is the common pick because it’s genuinely fast (it does the JSON serialization off the hot path) and it defaults to line-delimited JSON on stdout, which is exactly what you want. You do not write files, you do not rotate logs, you do not set up log shipping in your app. Your process writes JSON to stdout and something else (the platform, a sidecar, a collector) ships it. That separation is the twelve-factor way and it’s right.
import pino from "pino";
const logger = pino();
logger.info({ route: "/checkout", userId: 4821 }, "request received");
// {"level":30,"time":1720000000000,"route":"/checkout","userId":4821,"msg":"request received"}Levels that actually mean something
Every logger has levels. Most teams use them as vibes (“this feels important, error it”). Pick real definitions and hold the line:
error/fatal: something failed that a human may need to act on. An error means one request died; a fatal means the process is going down. If it fires and nobody would ever care, it is not an error.warn: it worked, but something is off and trending wrong. A retry succeeded on attempt three. A cache is cold. A deprecated field was used.info: the audit trail of normal operation. Request received, order placed, job finished. One or two per request, not one per function call.debug/trace: firehose detail, off in production by default, flipped on for a service when you’re chasing something.
The discipline that pays off: an error log should mean “a person might need to do something.” If your error channel is full of expected, handled, retried-successfully noise, you have trained yourself and your alerts to ignore it, and the one real error scrolls past at 3am unseen. Log levels are a filter for future-you. Keep the filter honest.
Never log secrets. Be specific about what that means.
Logs get shipped to third-party backends, sit in cheaper storage for months, and get read by more people than your database ever will. A secret in a log is a secret in a dozen places you forgot about. This is one of the most common ways credentials leak, and it’s entirely self-inflicted.
Do not log, ever:
- Passwords, even “temporarily to debug.” Not the plaintext, not the hash.
- Tokens and keys: bearer tokens, session cookies, API keys, refresh tokens, the entire
Authorizationheader, signed URLs. - Full payment data: card numbers (PAN), CVV, anything that puts you in PCI scope.
- PII you don’t need: full emails, government IDs, precise location, date of birth. Under GDPR and similar laws this stuff has rules, and “it was in a log” is not a defense.
The trap is that you rarely log these on purpose. You log a whole object, logger.info({ req.headers }), and the cookie and authorization headers ride along. So redact at the logger, not at each call site, where you’ll forget:
// pino redacts by path before anything is written
const logger = pino({
redact: {
paths: ["req.headers.authorization", "req.headers.cookie", "*.password", "*.token"],
censor: "[redacted]",
},
});The correlation id: the single highest-value thing here
If you take one idea from this article, take this one. It is cheap to add, it pays off on every single incident, and most teams bolt it on only after a bad night.
A single user action fans out across your system. The browser hits your API gateway, which calls an auth service, which calls an orders service, which calls payments, which writes to a database. That’s five sets of logs on five different machines. When checkout fails, you need this user’s path through all five, and nothing else. Grepping each service for “error” near a timestamp is how you lose an hour.
The fix: mint one id at the very edge, the first moment a request enters your system, and thread it through everything. Every log line on every service carries it. Every outbound call passes it along. Now one filter, requestId = a1b2c3, reconstructs the entire journey in order, across every service, in seconds.
Two things make this work in Node, and both are worth knowing.
First, generate or accept the id at the edge. If the incoming request already has one (a header like x-request-id or a W3C traceparent, more on that soon), trust it so the trail extends past your boundary. Otherwise mint a fresh one.
import { randomUUID } from "node:crypto";
function requestId(req, res, next) {
const id = req.headers["x-request-id"] || randomUUID();
req.id = id;
res.setHeader("x-request-id", id); // hand it back so clients can quote it in bug reports
next();
}Second, and this is the trick that makes it painless: thread it without passing it to every function. Nobody wants id as the first argument of all 200 functions. Node’s AsyncLocalStorage gives you request-scoped storage that survives across await points, so any code deep in the call stack can read the current request’s id out of thin air.
import { AsyncLocalStorage } from "node:async_hooks";
const als = new AsyncLocalStorage();
// wrap each request so everything it triggers shares one store
function withContext(req, res, next) {
als.run({ requestId: req.id }, () => next());
}
// a logger that stamps the id automatically, from anywhere
function log(level, msg, fields = {}) {
const ctx = als.getStore();
process.stdout.write(
JSON.stringify({ time: Date.now(), level, msg, requestId: ctx?.requestId, ...fields }) + "\n"
);
}Now a log("error", "charge declined") buried four calls deep in the payments module comes out already tagged with the right requestId, and you never plumbed it there. This is the difference between “correlation ids sound nice but touch everything” and “we added it in an afternoon.” AsyncLocalStorage is stable and built in; use it.
When you call another service, pass the id on the wire so the chain continues:
await fetch("https://orders.internal/api/cart", {
headers: { "x-request-id": als.getStore().requestId },
});Metrics: cheap numbers you can watch forever
A log is one event, and events are expensive to store at scale. A metric is a number over time, pre-aggregated, tiny, and cheap to keep for a year. You don’t ask a metric “what happened to user 4821.” You ask it “how many checkouts per second, what fraction failed, how slow were they,” and you watch that on a dashboard and alert on it. Three shapes cover almost everything:
- Counter: a number that only goes up. Total requests, total errors, bytes sent. You never read the raw value, you read its rate: requests per second is the counter’s slope.
- Gauge: a number that goes up and down. Current in-flight requests, queue depth, connection pool size, memory used. A snapshot of “right now.”
- Histogram: a distribution. Instead of one number it keeps buckets (“how many requests took 0 to 10ms, 10 to 50ms, 50 to 100ms…”). This is how you get percentiles, and it’s the one that matters most for latency.
RED for services, USE for resources
Staring at a blank dashboard wondering what to graph is a rite of passage. Two recipes end it. They’re old, they’re boring, and they’re right.
RED, from Tom Wilkie, is for anything that serves requests (your API, a service, an endpoint). Track three things per service:
- Rate: requests per second.
- Errors: failed requests per second (or as a fraction).
- Duration: the distribution of how long requests take.
USE, from Brendan Gregg, is for resources (CPU, memory, disk, a connection pool, a queue). Track:
- Utilization: how busy it is (percent of time in use).
- Saturation: how much work is queued and waiting.
- Errors: error events for that resource.
RED watches the thing your users touch. USE watches the things that run out. A slow endpoint (RED duration climbing) explained by an exhausted connection pool (USE saturation pegged) is a five-minute diagnosis with both, and a two-hour one with neither.
// RED with the OpenTelemetry metrics API
import { metrics } from "@opentelemetry/api";
const meter = metrics.getMeter("checkout");
const requests = meter.createCounter("http.server.requests"); // Rate
const errors = meter.createCounter("http.server.errors"); // Errors
const duration = meter.createHistogram("http.server.request.duration", { unit: "s" }); // Duration
function record(route, status, seconds) {
const attrs = { route, status }; // low-cardinality labels only (see below)
requests.add(1, attrs);
if (status >= 500) errors.add(1, attrs);
duration.record(seconds, attrs);
}Averages lie. Percentiles tell the truth.
Here is the mistake that hides more pain than any other: the average latency. It feels like the summary number. It is almost useless, and worse, it’s reassuring while users suffer.
An average of 200ms sounds healthy. But an average is one number squashing a whole distribution, and a latency distribution is never symmetric. It has a long right tail: most requests are fast, and a few are catastrophically slow. Average those together and the slow ones basically vanish, diluted by thousands of fast ones. You can have a 200ms average sitting on top of a p99 of 8 seconds, and the average will never once flinch.
Percentiles refuse to hide the tail. p50 (the median) is the middle request: half are faster, half slower. p95 is the request slower than 95% of traffic. p99 is slower than 99%. And p99 is not some rare edge case you can ignore: it is one in a hundred requests. On a page that makes 100 API calls to render, that’s roughly once per page load. The p99 is a real, frequent, paying customer, and their experience is 8 seconds of spinner. That’s the customer who churns, and the average told you everything was fine.
Move the slider below and watch it happen. The base traffic is a normal skewed latency distribution. Drag in a handful of slow requests (say a database that hiccups for 1% of calls) and watch the three markers react. The median doesn’t budge. The mean drifts up a little, still landing in dashboard-green territory. And p99 leaps clean off the chart. Same data. One number is screaming and the other is whistling.
Cardinality: the label that detonates your bill
Metrics are cheap because they pre-aggregate. That cheapness has one hard rule, and breaking it is how teams get a surprise five-figure invoice.
Every unique combination of label values is a separate time series, stored and indexed independently. http.server.requests{route, status} with 20 routes and 6 status codes is 120 series. Totally fine. Now someone adds a userId label “to slice by user.” With five million users, you just asked your metrics backend to hold up to five million times as many series. Memory scales roughly linearly with series count, so this is an out-of-memory event for your monitoring, or a monstrous bill, or both. It has a name: a cardinality explosion.
Traces: where the time actually went
Metrics tell you p99 is 8 seconds. They will not tell you which part of the request ate the 8 seconds. That’s what a trace is for. A trace follows one request through your whole system and records every step as a span: a named, timed operation with a start, a duration, and a parent. Assemble the spans by parent and you get a waterfall, and the waterfall makes the slow part impossible to miss.
No guessing. The auth check, the cart load, the payment call, the insert are all thin slivers. One database SELECT is three-quarters of the whole request. You know exactly where to spend the next hour, and you knew it in ten seconds.
This is also how you see the problems from earlier articles that are otherwise invisible. An N+1 query doesn’t show up as one fat span; it shows up as a burst of two hundred nearly identical tiny DB spans, stacked like a picket fence, and the shape is unmistakable once you’ve seen it once. Connection pool exhaustion shows up as a suspicious gap: the span sits there doing nothing for 200ms before the query even starts, because it was waiting to borrow a connection. Neither is visible in a log or a metric. Both are obvious in a trace.
OpenTelemetry is the standard. Adopt it early.
You do not want to invent your own span format, and you really do not want to wire your code to one vendor’s tracing SDK and then re-do all of it when you switch vendors. OpenTelemetry (OTel) is the vendor-neutral standard that solved this, and it won decisively. As of mid-2026 it’s a CNCF graduated project, the same top maturity tier as Kubernetes and Prometheus, and its JavaScript API package pulls over a billion downloads a month. It is the default answer.
The shape of it: you instrument your code against the OTel API, and a swappable exporter ships the data to whatever backend you like (Jaeger, Grafana Tempo, Honeycomb, Datadog, a dozen others). Switch backends by changing config, not code. Even better, you get most spans for free: the auto-instrumentation package wraps Node’s HTTP, popular database drivers, and more, so incoming requests, outgoing fetch calls, and queries all become spans without you touching them.
import { trace, SpanStatusCode } from "@opentelemetry/api";
const tracer = trace.getTracer("checkout");
// wrap the interesting bit of your own code in a span
await tracer.startActiveSpan("charge-card", async (span) => {
span.setAttribute("payment.provider", "stripe");
span.setAttribute("cart.total", 48.20); // high-cardinality is fine on a span!
try {
await chargeCard();
} catch (err) {
span.recordException(err);
span.setStatus({ code: SpanStatusCode.ERROR });
throw err;
} finally {
span.end();
}
});Note the userId and cart.total going straight onto the span. That’s the payoff of the cardinality rule: the specifics you’re forbidden from putting in metrics live perfectly here, one per span, cheap. And because OTel propagates the traceparent header across services automatically, the trace id it carries is the correlation id from the top of this article. One instrumentation, and your logs, metrics, and traces all speak the same id.
Sampling: you can’t keep every trace
At real volume, storing a trace for every request is too much data and too much money. So you sample. Two flavors:
- Head sampling decides at the start of the request, before you know anything, usually a fixed ratio like “keep 5%.” Cheap and simple, but it’s a coin flip, so it throws away 95% of your errors and slow requests too.
- Tail sampling decides after the whole trace finishes, in a collector, so it can be smart: keep 100% of traces that errored or breached a latency threshold, and 1% of the boring successful ones. You keep the traces you’ll actually want at 3am and drop the ones you never open.
Tail sampling costs more to run (something has to buffer whole traces before deciding) but it’s usually the right trade, because the interesting traces are exactly the rare ones a fixed ratio would discard. Start with head sampling to get going; move to tail sampling when you notice the trace you wanted wasn’t kept.
Health checks: two questions, not one
Your orchestrator needs to ask your process two different things, and conflating them causes outages. A liveness check asks “is this process wedged, should I restart it?” A readiness check asks “should I send this process traffic right now?” They lead to opposite actions: liveness failure kills you, readiness failure just quietly takes you out of the load balancer until you recover.
The classic self-inflicted outage is putting a shared dependency (the database) in the liveness probe. The database hiccups for four seconds, every pod fails liveness at once, the orchestrator dutifully kills the entire fleet simultaneously, and now a cold fleet stampedes a database that was merely grumpy. You turned a blip into an outage with a reliability feature. Liveness should check almost nothing: can this process still answer? Readiness is where “is my pool warm, are my dependencies reachable” lives. This has its own long story, including how it interacts with shutdown; it’s covered in graceful shutdown.
Alerting: page on the symptom, not the cause
You have all this data. The last question is what wakes a human at 3am. Get this wrong in either direction and you’re worse off than with no alerts at all.
Alert on symptoms your users can feel. Error rate crossing a threshold. p99 latency breaching your target. Queue depth backing up so far that work won’t clear in time. A rising 429 rate. These are things a customer experiences, and every one of them is worth a human’s attention.
Do not page on causes. CPU at 85% is not a problem; it might be a service being efficient. High memory is not a problem until something actually fails. Disk at 70% is a ticket, not a page. The failure mode of cause-based alerting is that it fires constantly for conditions that resolve themselves, and here’s the thing that matters most:
A pager that cries wolf gets ignored. This isn’t a personality flaw, it’s inevitable. Wake someone five times for nothing and the sixth alert, the real one, gets silenced half-asleep. Every false page lowers the value of every future page. So the bar for paging is brutal: it fires only when a human genuinely needs to act now, on something a customer feels. Everything else is a dashboard you look at during the day, or a ticket. Guard the pager like it’s the scarce resource it is, because attention is.
Summary
- Monitoring tells you it’s broken; observability lets you ask why from data you already collected. Almost all of it is decided before the incident, by what you wrote down.
- Log structured JSON, one object per line, so a machine can query fields instead of grepping prose. Use a fast logger (Pino), give levels honest meanings, and never log passwords, tokens,
Authorization/Cookieheaders, card data, or PII. Redact at the logger as a backstop. - A correlation id minted at the edge and threaded through every log line and downstream call is the highest-value thing here. Use
AsyncLocalStorageto carry it without plumbing it through every function, and let OpenTelemetry’straceparentdo it across services. - Metrics are cheap numbers over time: counters, gauges, histograms. Use RED (rate, errors, duration) for services and USE (utilization, saturation, errors) for resources.
- Averages hide the tail. Track p50/p95/p99; a 200ms average can sit on an 8-second p99, and the p99 is one in a hundred real users. Store latency as histograms and never average a percentile.
- Cardinality is the trap: every label-value combination is a time series. Never put a user id, token, or raw path in a metric label. Put the specifics on a trace span or in a log instead.
- Traces show one request as a span waterfall, making the slow database query, the N+1 picket fence, and pool exhaustion gaps obvious. OpenTelemetry is the vendor-neutral standard (CNCF graduated; traces and metrics stable in JS); adopt it early and sample tails.
- Keep liveness and readiness separate, and never put a shared dependency in liveness. Covered fully in graceful shutdown.
- Page on symptoms users feel (errors, latency, queue depth), not causes (CPU). A pager that cries wolf gets ignored, so guard it.