Distributed Tracing with Micrometer and OpenTelemetry

A request entering the gateway may pass through order-service, product-service and payment-service before it returns. When it is slow or fails, which service was responsible? Logs alone cannot say.

Logs and their limit

Logs record, as plain text or JSON, what happened inside one application while it handled a request: information, warnings and errors. They serve:

• debugging: what the application did with a request;
• tracking errors and failures, with stack traces;
• spotting unusual behavior.

They can include the incoming request (URL, method, headers, body), events during processing, and the outgoing response (status, time taken, payload).

But each service keeps its own logs. A request going from order-service to payment-service leaves:

[order-service]    Order created for userId=55
[payment-service]  Payment timeout userId=55

Do both lines belong to the same request? Which service called which, and how long did each take? The logs do not say. They show no end-to-end journey and no time breakdown per service.

Tracing

Distributed tracing records the path of a request across services, at a high level:

• which service called which;
• how long each one took;
• the status of each call (200, 400, 500...).

It does not store detailed log messages; that remains the job of logs. It rests on two identifiers:

• Trace ID: one per request, shared by everything the request touches. One request = one trace.
• Span ID: one per unit of work. A span is a timed operation: it starts, does work, and ends. Every span also records its parent span.

Take a request that reaches service A, which calls B (which calls D) and then C:

Span	Service	Parent	Trace
S1	A	none	T1
S2	B	S1	T1
S4	D	S2	T1
S3	C	S1	T1

From these records a tracing backend rebuilds the tree and draws a timeline:

A  |================================================|
B     |====================|
D          |==========|
C                             |============|

A's span covers the whole request; B's and C's sit inside it, and D's inside B's. At a glance you see that most of the time went to B and D.

Spans are created automatically for incoming HTTP requests, outgoing HTTP calls and thread hand-offs, and you can create your own (Step 5).

Tracing also powers distributed logging. If each log line carries the trace ID, a log platform (Kibana, CloudWatch...) can gather every line from every service for one request by searching for that ID:

TRACE-ID=T123 [order-service]    Order created for userId=55
TRACE-ID=T123 [payment-service]  Payment timeout userId=55

That is the subject of chapters 16 to 19.

How it works: old and new

The old way (Spring Boot 2): Spring Cloud Sleuth created trace and span IDs and propagated them between services. It used the Brave library, which produces Zipkin's format. Finished spans went to an in-memory queue, and a Zipkin exporter sent them to a Zipkin server, which assembled and displayed traces. Using another backend, such as Jaeger, meant extra configuration work. Sleuth is not available for Spring Boot 3.

The modern way (Spring Boot 3): the same architecture, with standard, interchangeable parts:

• Micrometer Tracing is the API your code and Spring use: a tracer, spans, scopes.
• The OpenTelemetry SDK implements it: it creates trace and span IDs and propagates them. (Brave can implement the same API, but then you are back to Zipkin's format.)
• The OTLP exporter sends finished spans to the backend using OTLP, the OpenTelemetry Protocol.

Every major backend accepts OTLP. So switching from Jaeger to Zipkin or Grafana Tempo means changing one URL, not your code. That vendor neutrality is why OpenTelemetry is the choice.

Step 1: a backend

This chapter uses Jaeger, run as a container:

docker run -d -p 16686:16686 -p 4317:4317 -p 4318:4318 jaegertracing/all-in-one:latest

Port	Purpose
16686	the Jaeger UI: open http://localhost:16686
4317	OTLP over gRPC
4318	OTLP over HTTP (used below)

Step 2: the first service

Three dependencies, matching the three parts:

<!-- Micrometer (comes with Actuator) -->
<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-actuator</artifactId>
</dependency>
<!-- Micrometer Tracing implemented by OpenTelemetry -->
<dependency>
    <groupId>io.micrometer</groupId>
    <artifactId>micrometer-tracing-bridge-otel</artifactId>
</dependency>
<!-- send spans with OTLP -->
<dependency>
    <groupId>io.opentelemetry</groupId>
    <artifactId>opentelemetry-exporter-otlp</artifactId>
</dependency>

server.port=8080
spring.application.name=Trace-App-1

# trace every request (default 0.1 = 10%)
management.tracing.sampling.probability=1.0

# where to send spans: Jaeger's OTLP/HTTP endpoint
management.otlp.tracing.endpoint=http://localhost:4318/v1/traces

Sampling decides which requests are traced. The default, 10%, keeps tracing cheap under heavy load; 1.0 traces everything, which is right while learning.

A controller to try it:

@RestController
public class App1Controller {

    @GetMapping("/api")
    public String invokeApp2() {
        return "response from App1";       // will call App2 in Step 4
    }
}

Call GET localhost:8080/api, then open the Jaeger UI: service Trace-App-1 appears with a trace for http get /api, one span, with no parent, its start time and duration. Nothing in the controller mentions tracing: an observation filter on incoming requests (ServerHttpObservationFilter) created the trace and span.

Step 3: the second service

The same three dependencies and properties, with server.port=8082 and spring.application.name=Trace-App-2:

@RestController
public class App2Controller {

    @GetMapping("/api/hello")
    public String helloMethod() {
        return "hello from App2";
    }
}

Step 4: one service calls the other

App1 calls App2 with a RestClient built from Spring Boot's RestClient.Builder:

@Configuration
public class AppConfig {

    @Bean
    RestClient restClient(RestClient.Builder builder) {
        return builder.build();
    }
}

@RestController
public class App1Controller {

    @Autowired
    private RestClient restClient;

    @GetMapping("/api")
    public String invokeApp2() {
        String response = restClient.get()
                .uri("http://localhost:8082/api/hello")
                .retrieve()
                .body(String.class);
        return "Response from App2: " + response;
    }
}

Propagation: the traceparent header

For App2 to join App1's trace, the outgoing request must carry the trace context. An interceptor on the client adds the W3C traceparent header:

GET /api/hello HTTP/1.1
traceparent: 00-da313c8c6062126b3bb88d5f0a5e5d5e-221caf94e361674d-01

The format is version-traceId-parentSpanId-flags: 00, the 32-hex-digit trace ID, the 16-hex-digit ID of the calling span, and 01 meaning "sampled".

On App2's side, the incoming filter checks for this header:

• no traceparent: start a new trace and a root span;
• traceparent present: continue that trace, creating a new span whose parent is the one in the header.

In Jaeger

GET localhost:8080/api now produces one trace with three spans:

trace da313c8c...
├── http get /api          Trace-App-1   (no parent)          incoming request
│   └── http get           Trace-App-1   (parent: /api span)  outgoing call
│       └── http get /api/hello  Trace-App-2  (parent: http get span)  incoming at App2

The outgoing-call span lasts longer than App2's own span: it also includes network time and serialization, which App2 never sees.

Jaeger's JSON view shows the same structure: every span has the same traceID, its own spanID, and a CHILD_OF reference to its parent.

Which clients propagate?

Only clients that have the tracing interceptor attached. Calling App2 five ways from one App1 request each:

Client	Same trace in App2?
RestClient from Boot's RestClient.Builder	yes
RestClient.create()	no: App2 starts a new trace
RestTemplate from Boot's RestTemplateBuilder	yes
new RestTemplate()	no
Feign (spring-cloud-starter-openfeign alone)	no
Feign + io.github.openfeign:feign-micrometer	yes

Nothing fails when propagation is missing; you just get two unrelated traces instead of one. So:

• Build RestClient and RestTemplate from Spring Boot's builders, which carry the observation setup. A RestTemplate you must create yourself can be given it with Boot's ObservationRestTemplateCustomizer:

  @Bean
  RestTemplate restTemplate(ObservationRestTemplateCustomizer customizer) {
      RestTemplate restTemplate = new RestTemplate();
      customizer.customize(restTemplate);
      return restTemplate;
  }

• For Feign, add feign-micrometer; Spring Cloud OpenFeign then registers the tracing capability automatically:

  <dependency>
      <groupId>io.github.openfeign</groupId>
      <artifactId>feign-micrometer</artifactId>
  </dependency>

Step 5: creating spans by hand

To time a piece of work inside a service (a database operation, a computation), create a span yourself with Micrometer's Tracer:

@RestController
public class App1Controller {

    @Autowired
    Tracer tracer;

    @GetMapping("/api/test/span")
    public String manualSpanTest() {

        Span parentSpan = tracer.currentSpan();          // the span of this request

        Span childSpan = tracer.nextSpan(parentSpan).name("manual-child-span");
        childSpan.start();                               // start the timer

        try (Tracer.SpanInScope ws = tracer.withSpan(childSpan)) {   // make it current
            // business logic
            Thread.sleep(70);
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        } finally {
            childSpan.end();                             // stop the timer
        }
        return "Response from App1";
    }
}

• tracer.currentSpan(): the span currently active, here the one for the incoming request (or null if there is none).
• tracer.nextSpan(parent): a new span in the same trace with parent as its parent. (tracer.nextSpan() without arguments uses the current span as parent.)
• start() starts its timer but does not make it current. Anything that asks for the current span still gets the parent.
• tracer.withSpan(child) makes the child current and remembers the previous span. Spans created inside the block (by your code or by an HTTP call) become children of the child, giving a correct tree.
• Closing the SpanInScope (try-with-resources does it) restores the previous span as current; end() stops the child's timer and hands it to the exporter. Forgetting either leaves the wrong span current or the span never reported.

The values observed in one request:

parent        36f481e6c5254e21
child         184cb0795b484a5e
current inside the block  184cb0795b484a5e
current after the block   36f481e6c5254e21

In Jaeger, manual-child-span appears under http get /api/test/span, in the same trace, with its own duration.

Next: Tracing shows the path; logs hold the details. Chapter 16 starts distributed logging: how logging works in Java with SLF4J and Logback, before collecting logs from many services in one place.

Check yourself

1. What can logs tell you that traces cannot, and the other way round?
2. What are a trace ID and a span ID?
3. A request goes A → B → D and A → C. Which span is the parent of D's span?
4. Which events create spans automatically?
5. What were Sleuth and Brave, and why were they hard to use with backends other than Zipkin?
6. What roles do Micrometer Tracing, the OpenTelemetry SDK and the OTLP exporter play?
7. Why is OTLP important?
8. What does management.tracing.sampling.probability control, and what is its default?
9. What header carries the trace context, and what does it contain?
10. What does the receiving service do with and without that header?
11. Which of these propagate the trace: RestClient.create(), a RestClient from RestClient.Builder, new RestTemplate(), Feign alone?
12. What do you add so Feign propagates the trace?
13. What is the difference between childSpan.start() and tracer.withSpan(childSpan)?
14. What goes wrong if you do not close the SpanInScope or do not call end()?

Answers

1. Logs hold detailed events inside one application; traces show the request's path across services, the time per service and each status, without the details.
2. The trace ID identifies one request across all services; a span ID identifies one timed unit of work within it.
3. B's span.
4. Incoming HTTP requests, outgoing HTTP calls, and thread hand-offs.
5. Sleuth created and propagated trace context in Spring Boot 2, using Brave, which produced Zipkin's format; other backends needed extra configuration.
6. Micrometer Tracing is the API; the OpenTelemetry SDK implements it (creates and propagates IDs); the OTLP exporter sends finished spans to the backend.
7. All major backends accept it, so the backend can be changed by changing an endpoint URL.
8. The fraction of requests traced; default 0.1 (10%).
9. traceparent: version-traceId-parentSpanId-flags, e.g. 00-<32 hex>-<16 hex>-01.
10. With it, continue that trace, with a new span whose parent is the header's span; without it, start a new trace.
11. Only the RestClient built from RestClient.Builder. The others start a new trace in the receiving service.
12. The io.github.openfeign:feign-micrometer dependency.
13. start() only starts the span's timer; withSpan makes it the current span so that spans created inside become its children.
14. Without closing the scope, the finished span stays "current" and later spans get the wrong parent; without end(), the span is never completed and never exported.