We use cookies to enhance your experience on the site

Distributed Tracing with OpenTelemetry - the Empire's courier routes

The metrics say the 95th percentile of response time rose from 200 ms to two seconds. You know that it is slow - but not where. A request passes through the authentication gate, the legions service, the database and an external payments API. Which of those links takes those two seconds?

Rome had a register of stations for this. A courier carrying a dispatch from Gaul to Rome reported at every mansio, and from those reports you could later read where he had lost a day. Distributed tracing does exactly that to a request.

Trace and span

Two terms that must be separated at once.

A trace is a request's whole road - from entry to exit, across every service. A span is a single operation within a trace - one database query, one external API call, one service method.

So a span is not an identifier of the whole request (that is the trace ID), not a format for exporting data, and not a visualisation tool. It is one stretch of the road, with its own start and end time.

Spans form a tree. For a request creating a legion it looks like this, from the root downwards:

POST /legiones
- the root span, the whole HTTP request.
auth.verify
- token verification.
legion.create
- the business logic.
mongodb.insert
- the write to the database.

The nesting is information in itself: since

mongodb.insert

sits inside

legion.create

, its time counts towards the parent's. When the root span takes two seconds and

mongodb.insert

takes one and a half - you already know where to look.

Configuration

We start OpenTelemetry before the application, in a separate file loaded first:

1const sdk = new NodeSDK({
2  resource: new Resource({
3    [SemanticResourceAttributes.SERVICE_NAME]: 'legion-api',
4  }),
5  traceExporter: new OTLPTraceExporter({
6    url: 'http://jaeger:4318/v1/traces',
7  }),
8  instrumentations: [getNodeAutoInstrumentations()],
9});
10
11sdk.start();

resource

gives the service a name - it is how you recognise your spans among those from other services. traceExporter
says where to send the data; here to Jaeger, the tool that draws a timeline out of it.

instrumentations

is the most interesting part.

getNodeAutoInstrumentations()

switches on automatic tracing of popular libraries - HTTP, Express, MongoDB, Redis. You add not a line to your services, and spans for database queries appear by themselves.

Order matters: the SDK must start before you import Express or the database driver. Automatic instrumentation works by swapping those libraries at load time, and it cannot swap something already loaded.

A custom span

Auto-instrumentation covers infrastructure but knows nothing of your domain. To see

legion.create

in the tree, you create a span yourself:

1@Injectable()
2export class LegionService {
3  private tracer = trace.getTracer('legion-service');
4
5  async create(dto: CreateLegionDto) {
6    return this.tracer.startActiveSpan('legion.create', async (span) => {
7      try {
8        span.setAttribute('legion.name', dto.name);
9        span.setAttribute('legion.rank', dto.rank);
10
11        const legion = await this.repo.save(dto);
12
13        span.setStatus({ code: SpanStatusCode.OK });
14        return legion;
15      } catch (error) {
16        span.recordException(error);
17        span.setStatus({ code: SpanStatusCode.ERROR });
18        throw error;
19      } finally {
20        span.end();
21      }
22    });
23  }
24}

You create the tracer once, as a class field - the written order is

private tracer

, =
, trace.getTracer('legion-service')
.

Five things happen inside.

startActiveSpan

opens a span and makes it active, so everything created within it - including spans from auto-instrumentation - nests underneath automatically.

setAttribute

adds data searchable later in Jaeger; this is where you put the identifiers you will hunt a specific case by.

setStatus

marks the outcome,

recordException

records an exception along with its stack trace.

The most important part is

span.end()

in the
finally
block. A span never ended is never exported at all - the same symmetry you know from connections and test hooks: what you opened you must close, including when an exception flew.

Context propagation

That leaves the question of how spans from different services end up in one tree. That is the job of context propagation - the automatic passing of a trace ID between services through HTTP headers.

When service A calls service B, the instrumentation adds a

traceparent

header carrying the trace's identifier and the current span's. Service B reads it and creates its spans as children of that one. Nobody copies anything by hand, synchronises databases or moves configuration files.

Hence the whole value of tracing in a distributed system: one tree spans every service, so those two seconds can be pinned on a specific link even when it lives in somebody else's service.

Summary

The couriers report at every station:

metrics say that it is slow, tracing says where,
a trace is a request's whole road; a span is a single operation within a trace - not a request identifier, not an export format, not a visualisation tool,

spans form a tree from the root down: POST /legiones
→
auth.verify
→
legion.create
→
mongodb.insert
,

a child's time counts towards its parent's - which is why the tree points at the guilty link immediately,
```
NodeSDK
```
is configured by three things:
```
resource
```
with the service name,
```
traceExporter
```
with the recipient's address,
```
instrumentations
```
,
```
getNodeAutoInstrumentations()
```
traces popular libraries with no code changes - but the SDK must start before they are imported,
the tracer:
```
private tracer
```
```
=
```
```
trace.getTracer('name')
```
,
```
startActiveSpan
```
nests everything created inside it;
```
setAttribute
```
adds searchable data,
```
setStatus
```
and
```
recordException
```
describe the outcome,
span.end()
belongs in
finally
- a span never ended is never exported,
context propagation automatically passes the trace ID between services through HTTP headers - it does not copy logs or synchronise databases.

In the next lesson you will gather this whole module into one deployment project. For now remember: a metric shows a chart, a trace shows a route - and only on the route can you see at which station the courier lost a day.

Go to CodeWorlds→