Distributed tracing with OpenTelemetry
One request fans out across N services; per-service logs cannot tell you which hop is slow or where it broke. A trace stitches the request into one tree of spans via a shared traceId — if you propagate context across HTTP and async boundaries, and sample sanely.
Checkout got slow. Not broken — slow: p99 crept to 3 seconds and the support queue filled with “the spinner just sits there.” The flow crossed four services: api took the request, called orders, which called payments, which called inventory. We opened every dashboard we had. api p99: fine. orders p99: fine. payments p99: fine. inventory p99: fine. Every service swore it was healthy, and the request was still taking three seconds. The logs were no help either — four separate log streams, each with its own request id, none of them aware of the others. Nobody could answer the only question that mattered: which hop ate the time? That question is unanswerable with per-service logs alone. It needs a single object that follows the request through all four services and records where every millisecond went. That object is a trace, and this lesson is about how OpenTelemetry builds one, how the context that holds it together gets lost, and how to pay for it without going bankrupt.
What a trace is: spans, a traceId, and a parent chain
A trace is the whole journey of one request, represented as a tree. Each node is a span: one timed operation with a start, an end, and a bag of attributes (HTTP route, DB statement, status). Spans are tied together by two ids. The traceId is shared by every span in the request — it is the join key for the entire tree. The spanId identifies one span, and each span records its parent spanId, which is what gives the tree its shape: api’s span is the root, the orders span is its child, the payments span is a child of that, and so on.
// One span = one operation. The tracer creates it; you set attributes and end it.
const tracer = trace.getTracer('orders');
await tracer.startActiveSpan('chargeCustomer', async (span) => {
span.setAttribute('order.id', orderId);
span.setAttribute('payment.amount', amount);
try {
return await this.payments.charge(orderId, amount);
} catch (err) {
span.recordException(err);
span.setStatus({ code: SpanStatusCode.ERROR });
throw err;
} finally {
span.end(); // start→end is THIS span's duration on the trace
}
});With that tree, the checkout incident answers itself in one screen: open the trace, see four spans laid out on a timeline, and the payments span is visibly 2.6s wide while the other three are slivers. Drill into it and you find payments calling inventory synchronously in a loop, one round trip per line item. No dashboard could show that, because each individual inventory call was fast — it was the serial fan-out, the sum, that was slow, and the sum only exists in the trace.
Context propagation: the mechanism that makes one trace out of four services
The hard part is not creating spans — auto-instrumentation does that. The hard part is keeping every span in the same trace as the request crosses boundaries. That requires the trace context — the traceId, the current spanId, and the sampling flag — to travel two different kinds of boundary.
Across a service, over the network, the context rides in the W3C traceparent HTTP header. The caller injects it into outgoing request headers; the callee extracts it and continues the trace instead of starting a new one.
// traceparent: version-traceId-parentSpanId-flags
// 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01
// └─ 32 hex traceId ──────────────┘ └─ 16 hex spanId ┘ └ sampled
// The caller injects this header; the callee extracts it and the orders span
// becomes a CHILD of the api span — same traceId, new spanId, api's as parent.Within a process, across awaits and callbacks, there is no header to carry the context — so OTel’s Node context manager stores the “currently active span” in AsyncLocalStorage. ALS is the V8 mechanism that keeps a value attached to one logical async call chain: a span started in a guard is still the current span inside the handler, and inside the pg call the handler makes, because all of them run inside the same ALS-tracked chain. That is why a DB query auto-nests under the request span without you passing anything by hand.
The failure mode is symmetric: lose the context on either kind of boundary and the trace fragments. Skip traceparent on an outbound call and the callee starts a fresh root trace. Break out of the ALS chain — a fire-and-forget unawaited promise, a bare setTimeout, a queue hop with no propagation — and the continuation runs with no active span, so OTel sees no parent and opens a new root. Either way the request that should be one tree becomes several disconnected fragments, and you are back to staring at unrelated traces, unable to follow the request end to end.
▸Why this works
Why does a fire-and-forget or unawaited async call break the trace? Because the “current span” does not live in a variable you pass around — it lives in AsyncLocalStorage, bound to the awaited call chain that started the span. When you await, V8 keeps you inside that store, so the continuation still sees the span as current. When you don’t await — you call a function and drop the promise, or you schedule work with a bare setTimeout, or you push a job onto a queue and a different process picks it up — that continuation runs outside the original store. OTel looks for the current span, finds nothing, and starts a fresh root span with a brand-new traceId. The child work is now its own trace. The original tree never learns the work happened, and the new root has no parent, so on the trace view the one request looks like several unrelated traces that you cannot stitch back together.
Wiring OTel into Nest: bootstrap before the app
The one rule that bites everyone: instrumentation works by monkey-patching the modules it traces (http, express, pg, the Nest core), so the SDK must start before those modules are imported by your app. In practice you put the NodeSDK in its own file and load it first — node --require ./tracing.js dist/main.js, or an import './tracing' as the very first line of main.ts.
// tracing.ts — MUST be loaded before the Nest app so it patches http/pg/nest first
import { NodeSDK } from '@opentelemetry/sdk-node';
import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node';
import { TraceIdRatioBasedSampler } from '@opentelemetry/sdk-trace-base';
const sdk = new NodeSDK({
// auto-instruments http, express, @nestjs/core, pg — spans appear with no app code
instrumentations: [getNodeAutoInstrumentations()],
// head sampling: keep 10% of traces (see the sampling section)
sampler: new TraceIdRatioBasedSampler(0.1),
});
sdk.start();Once that is loaded, every HTTP request and every pg query produces a span automatically. You add manual spans (tracer.startActiveSpan) only around business operations the auto-instrumentation cannot name — “reserve inventory”, “score risk”. And you close the loop with L01’s structured logging: inject the active traceId into every log line. That single field is the correlation key — find a slow trace, copy its traceId, and pull every log from every service for that exact request. Logs answer what happened; the trace answers where the time went; the traceId is the join between them.
// L01's logger, now trace-aware: every line carries the active traceId
const span = trace.getActiveSpan();
const ctx = span?.spanContext();
this.logger.log({ msg: 'charge failed', orderId, traceId: ctx?.traceId, spanId: ctx?.spanId });
// now one traceId pulls every log from every service for this exact requestSampling: you cannot afford to keep every trace
Before you add tracing to a production service, ask yourself: at 5,000 RPS, how much span data do you actually want to pay to store? The answer shapes which of the two strategies below you reach for. Tracing every request is expensive — span storage and export bandwidth dominate, and unbounded spans or attributes per request add real cost. So you sample: keep some traces, drop the rest. There are two strategies, and the trade between them is the senior decision.
Head sampling decides at the root, before the request runs, usually by a ratio: TraceIdRatioBasedSampler(0.1) keeps 10%. It is cheap and needs no extra infrastructure — but the decision is blind. It cannot know the request you dropped was the one that took 3 seconds or threw a 500, so at a low rate you systematically miss the rare slow and failing requests, which are exactly the ones you wanted.
Tail sampling decides after the request finishes, when the outcome is known: keep all errors and all slow traces, sample a small fraction of the boring fast ones. It catches the rare bad request head sampling drops. The cost is that it cannot be decided in-process — every span of a trace must be buffered somewhere until the trace completes and the keep/drop verdict is made, which means you must run the OpenTelemetry Collector as a buffering tier between your services and your backend.
You must trace a high-traffic checkout flow across four services. Volume makes 100% tracing far too expensive, but the whole reason you're adding tracing is to catch the rare slow and failing checkouts. Which sampling approach fits?
Service api calls service orders over HTTP, and you want the orders span to be a child of the api span in the same trace. What carries the trace context across that service boundary?
A request enqueues a BullMQ job. In your tracing UI the job's spans show up as separate root traces, disconnected from the request that enqueued them. Why, and what's the fix?
- 01What is a trace made of, and how does context propagation keep one request in one trace as it crosses service and async boundaries?
- 02How do you wire OTel into a Nest app, and how do you choose between head and tail sampling?
A distributed trace turns one request that fans out across N services into a single tree, which is the only artifact that can answer “which hop ate the time” — per-service logs and dashboards each see one slice and miss the serial fan-out that made the whole request slow. A trace is a tree of spans (each a timed operation with attributes); every span shares one traceId (the join key), each has a spanId, and each records its parent spanId to give the tree its shape. The mechanism that keeps all those spans in one trace is context propagation of the trace context (traceId + current spanId + sampling flag): ACROSS services it rides the W3C traceparent HTTP header — caller injects, callee extracts — and WITHIN a process it lives in AsyncLocalStorage, OTel’s context manager, so a span started in a guard is still current inside the handler and its DB call. Lose the context — an unawaited fire-and-forget, a bare setTimeout, or a queue hop with no propagation — and the continuation runs with no active span, so OTel opens a fresh root and the request fragments into disconnected traces; the BullMQ fix is to inject traceparent into the job payload and restore it in the processor. Wire OTel by loading the NodeSDK before the app so auto-instrumentation can patch http/pg/nest first, add manual spans for business operations, and inject the active traceId into every log line as the correlation key tying logs to traces. Because keeping every trace is too expensive, you sample: head sampling (e.g. TraceIdRatioBasedSampler(0.1), 1-10%) is cheap but blind to the rare slow/failing request; tail sampling keeps all errors and slow traces but needs the OpenTelemetry Collector to buffer spans until the outcome is known. Now when you see a slow request in production and per-service dashboards all say “healthy,” you know where to look: open the trace, find the wide span, and read the serial fan-out that no individual metric could show.
Practice
Start at the top. Tasks go easiest → hardest: recall a fact, apply it to a case, then a senior-level stretch. Open one, attempt it, then reveal.
Something unclear?
Ask a question about this lesson. Questions are anonymous and go straight to the author to make the lesson better.