Practical OpenTelemetry — Part 6: Tracing: Supercharged Structured Logs
Distributed tracing is the signal most people associate with OpenTelemetry — and the one most misunderstood. Chapter 6 of Practical OpenTelemetry is the deepest technical chapter so far: the Tracing API, the span lifecycle, and the SDK machinery that moves spans from your code to a backend.
This post distills it, with emphasis on the parts that bite: span kinds, async causality, and the difference between recording and sampled.
A Trace Is Defined by Relationships
Start with the book’s definition, which is more precise than most:
- A trace is a logical concept linking all operations under one distributed transaction.
- A span is the structured data representation of each unit of work.
- There is no single event that defines a trace — the trace is defined by the relationships between spans.
Each span carries a start/end timestamp, a name, attributes, events, status — and crucially, the parent-child links that build the trace tree. Span contexts (TraceId + SpanId + flags) are what Part 5’s context propagation moves between services.
One of the book’s sharper analogies: traces are “supercharged, standardized, structured application logs” — the manual practice of adding transaction_id headers and MDC decoration, finally automated and standardized.
Creating Spans: Why Implicit Context Wins
The simplest possible span, a root of its own trace:
Span span = tracer.spanBuilder("my first span")
.setAttribute("isFirst", true)
.setNoParent()
.startSpan();
// ...
span.end();
Default SpanKind is INTERNAL; start/end timestamps default to when startSpan()/end() are called (both overridable). A span in isolation isn’t very useful, so the book builds a parent-child hierarchy the naive way first, specifically to show why it’s wrong:
void myMethod() {
// Automatically child of the current span in context
Span parentSpan = tracer.spanBuilder("main operation").startSpan();
try {
innerMethod(parentSpan);
} finally {
parentSpan.end();
}
}
void innerMethod(Span parentSpan) {
Span span = tracer.spanBuilder("inner operation")
.setParent(Context.current().with(parentSpan))
.startSpan();
try {
// do some work
} finally {
span.end();
}
}
The book’s own verdict on this, worth repeating verbatim: passing parentSpan around like this “would definitely not scale” and would be “a developer’s worst nightmare” for adding instrumentation to an existing codebase — every method signature on the call path has to change. The fix is Part 5’s implicit Scope, applied here:
void myMethod() {
Span parentSpan = tracer.spanBuilder("main operation").startSpan();
try (Scope ignored = parentSpan.makeCurrent()) {
innerMethod();
} finally {
parentSpan.end();
}
}
void innerMethod() {
// Automatically child of parentSpan
Span span = tracer.spanBuilder("inner operation").startSpan();
try (Scope ignored = span.makeCurrent()) {
// do some work
} finally {
span.end();
}
}
innerMethod() no longer needs the parent passed in at all — it reads Span.current() implicitly, through the exact same Context mechanism Part 5 used for Baggage. Caution, quoted directly from the book: “ending a span does not imply that the scope where it’s running is automatically closed… A span life cycle is independent from the scope or context under which it operates… closing a scope does not end a span” — both calls are required, or you get leaked scopes (wrong parent attribution) or leaked memory (spans that never end).
SpanKind and Links are both creation-time-only properties — set them on the builder, because they can’t change after startSpan():
Span span = tracer.spanBuilder("/api/v1")
.setSpanKind(SpanKind.SERVER)
.startSpan();
// A link to a related-but-not-causal span (e.g. a fire-and-forget task)
Span linked = tracer.spanBuilder("linkedSpan")
.setNoParent()
.addLink(Span.current().getSpanContext(),
Attributes.builder().put("submitter", "mainMethod").build())
.startSpan();
Span Kind: The Most Overlooked Field
Every span has a SpanKind, and choosing it correctly is what makes traces readable:
| Kind | Meaning | Lifecycle |
|---|---|---|
| SERVER | Callee side of a synchronous remote call | Starts when request received, ends when response sent |
| CLIENT | Caller side of a synchronous remote call | Starts when request sent, ends when response received |
| PRODUCER | Initiator of an async message | May finish before its CONSUMER child starts |
| CONSUMER | Receiver of an async message | May start after its PRODUCER parent finished |
| INTERNAL | Default — everything else | In-process work |
The classic trace structure: a CLIENT span in service A is the parent of a SERVER span in service B. The CLIENT/SERVER pairing across the network boundary is what lets tools show call graphs that actually match reality.
The Golden Rule: Statistically Significant Names
Span naming has one hard rule from the book: names must be statistically significant. No high-cardinality values — no user IDs, no URL parameters.
BAD: /api/customer/1763/pet/3
GOOD: /api/customer/{customer_id}/pet/{pet_id}
A span name shared by every call to the same operation is what makes aggregation, comparison, and anomaly detection possible. The updateName() method exists precisely so instrumentation can start with a generic name (HTTP GET) and refine it once the route template is known.
The same philosophy applies to span granularity. The book’s guidance: don’t span a private method that’s <1% of its parent’s duration and always propagates errors — use span events (lightweight, timestamped annotations) for those. Conversely, SERVER/CLIENT-only tracing is too coarse for complex internal processing. Start from SERVER spans and build tracing inward — the book’s worked example broke a PDF endpoint into get-content, load-tpl, and render-pdf, which immediately revealed rendering as the bottleneck.
This is also where the dropwizard-example from Part 4 gets a real follow-up. Its POST /people endpoint was already auto-instrumented with zero code changes; adding one manual attribute to the current span — the job title submitted in the request — needs exactly one line, no span creation at all:
@POST
@UnitOfWork
public Person createPerson(@Valid Person person) {
Span span = Span.current();
span.setAttribute("job.title", person.getJobTitle());
return peopleDAO.create(person);
}
Rebuild the same JAR, send the same POST request, and Jaeger shows the auto-instrumented PeopleResource.createPerson span now carrying job.title — auto-instrumentation and manual instrumentation aren’t two separate systems, they’re the same span, annotated from two different places. setAttribute() overwrites an existing key; setAllAttributes() sets several at once. For markers that don’t deserve a full span, there’s also addEvent():
span.addEvent("something happened");
span.addEvent("something happened earlier", Instant.ofEpochMilli(1664640662000L));
span.addEvent("something else happened", Attributes.builder().put("eventKey", 42).build());
And for renaming a SERVER span once route information becomes available (the mechanism that turns a generic HTTP GET into the statistically-significant name from the table above):
span.updateName("/api/people/{person_id}");
Caution: a sampler keying on span name may only ever see the name given at creation time, not after updateName().
Figure: span kinds encode causality. SERVER/CLIENT pair across the wire; PRODUCER/CONSUMER decouple async lifetimes.
Async: The Trace-Corrupting Subtlety
The book’s most valuable section for practitioners covers asynchronous tasks — because this is where traces silently break.
Parent-child spans are supposed to express causality and dependence. A fire-and-forget task (runAsync, background jobs) breaks both: the parent doesn’t wait for it, and its result doesn’t affect the client-visible response. Keeping it in the same trace misrepresents reality in two ways:
- The trace looks longer than the user experience actually was.
- Whole-trace sampling gets skewed — a trace retained because a background task was slow or failed, not because the client request was.
The fix pattern: give the background task a new root span (setNoParent()) and link it to the originating span with addLink() — the OTel equivalent of OpenTracing’s FOLLOWS_FROM. The trace tree stays honest; the relationship survives as a link.
The Tracing SDK: What Happens After span.end()
The SDK side is where spans get processed and shipped:
- Span processors — hooks on span start/end. The two built-ins:
SimpleSpanProcessor(export immediately — fine for demos, not production) andBatchSpanProcessor(queue spans, export in batches — the agent’s default, paired with the OTLP/gRPC exporter). - Samplers — the default is
parentBased(alwaysOn): mirror the parent’s decision, sample roots always. (Chapter 10 covers sampling properly.) - ID generator — default random 16-byte trace IDs, 8-byte span IDs.
- Span limits — attribute/event/link counts and value lengths, to protect against runaway instrumentation exhausting memory (agent default: 128).
Batch processing deserves a config note: otel.bsp.schedule.delay (max wait before export), otel.bsp.max.queue.size (drops spans when full — a real data-loss point), and otel.bsp.max.export.batch.size. The processor self-monitors with queueSize and processedSpans{dropped=true} — if the dropped counter is nonzero, your exporter can’t keep up.
One more lifecycle trap worth flagging here specifically because the SDK is where it actually bites: the span.end() / scope-closing caution from earlier in this post (“Creating Spans”) isn’t just an API-purity concern — an un-ended span is memory the batch processor’s queue never reclaims. The OTLP exporter itself retries up to 5 times with exponential backoff (1–5 seconds), which is why at-least-once delivery semantics matter (Part 9).
Errors, Exceptions, and Status
Error handling in spans follows semantic conventions. Status codes are UNSET (default, completed as expected), OK (deliberate success), and ERROR:
@WithSpan
void myMethod() {
try {
// some work
} catch (Exception e) {
Span.current().setStatus(StatusCode.ERROR, "an error occurred");
Span.current().recordException(e);
}
}
recordException(e) creates a standardized exception event with exception.type, exception.message, and exception.stacktrace pulled straight from the Throwable — the convention-compliant way to attach exceptions, and it accepts extra attributes appended to that same event.
OK exists as a conscious override: your cache miss that returns 404 as expected behavior can override the HTTP library’s automatic ERROR — the same problem Part 4’s extension example tackled at the Collector, available directly in application code too when you own the call site.
The chapter’s close echoes Part 1’s thesis with a sharper edge: tracing is for debugging, not for KPIs. Because traces are sampled — and sampling biases toward slow and failing transactions — spans make terrible long-term trend data. Metrics exist for that. In Part 7, we’ll build them.
Next: Practical OpenTelemetry — Part 7: Metrics and Cardinality
References
Have thoughts on this?
I read every email. If something resonated, felt wrong, or made you think — I'd love to hear from you.
Comments