Distributed Logging in Spring Boot: Trace IDs and Micrometer

// ── How trace context flows through the system: ──────────────────────
//
//  Client → API Gateway → OrderService → UserService
//                                      → PaymentService → StripeAPI
//
//  traceId: 4bf92f3577b34da6a3ce929d0e0e4736  (same for the entire request)
//
//  API Gateway    spanId: a2fb4a1d1a96d312  parentSpanId: null
//  OrderService   spanId: 00f067aa0ba902b7  parentSpanId: a2fb4a1d1a96d312
//  UserService    spanId: b9a37ca3f3a21c7d  parentSpanId: 00f067aa0ba902b7
//  PaymentService spanId: c4e32f11d8b3901a  parentSpanId: 00f067aa0ba902b7
//
//  Every log line in every service carries the same traceId.
//  In a log aggregation tool (Kibana, Grafana Loki):
//    filter by traceId = "4bf92f3577b34da6a3ce929d0e0e4736"
//    → see all logs from all services for this one request,
//      in chronological order.

// ── HTTP propagation headers: ─────────────────────────────────────────
//
// W3C Trace Context (standard — recommended, the Spring Boot default):
//   traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01
//                 ↑  ↑                                ↑                ↑
//               ver  traceId (32 hex)                spanId (16 hex)  flags (01 = sampled)
//   tracestate:  vendor-specific state (optional)
//   baggage:     key=value pairs propagated with the request (optional)
//
// B3 (Zipkin legacy — still common):
//   X-B3-TraceId:      4bf92f3577b34da6a3ce929d0e0e4736
//   X-B3-SpanId:       00f067aa0ba902b7
//   X-B3-ParentSpanId: a2fb4a1d1a96d312
//   X-B3-Sampled:      1
//
// Select the format in application.yml:
//   management.tracing.propagation.type: w3c     # or b3, b3_multi

<!-- ═══ Spring Boot 4.x ═══════════════════════════════════════════════ -->
<dependencies>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-actuator</artifactId>
    </dependency>

    <!-- OpenTelemetry + OTLP (Tempo, Jaeger, vendors): -->
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-opentelemetry</artifactId>
    </dependency>

    <!-- OR Brave + Zipkin instead of the OpenTelemetry starter: -->
    <!--
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-zipkin</artifactId>
    </dependency>
    -->
</dependencies>

<!-- ═══ Spring Boot 3.x ═══════════════════════════════════════════════ -->
<dependencies>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-actuator</artifactId>
    </dependency>

    <!-- Bridge: Micrometer Tracing → OpenTelemetry: -->
    <dependency>
        <groupId>io.micrometer</groupId>
        <artifactId>micrometer-tracing-bridge-otel</artifactId>
    </dependency>

    <!-- Choose ONE exporter. OTLP (Tempo, Jaeger, vendors): -->
    <dependency>
        <groupId>io.opentelemetry</groupId>
        <artifactId>opentelemetry-exporter-otlp</artifactId>
    </dependency>

    <!-- OR Zipkin through OpenTelemetry (deprecated by OpenTelemetry): -->
    <!--
    <dependency>
        <groupId>io.opentelemetry</groupId>
        <artifactId>opentelemetry-exporter-zipkin</artifactId>
    </dependency>
    -->

    <!-- OR Brave bridge, for Zipkin-only setups: -->
    <!--
    <dependency>
        <groupId>io.micrometer</groupId>
        <artifactId>micrometer-tracing-bridge-brave</artifactId>
    </dependency>
    <dependency>
        <groupId>io.zipkin.reporter2</groupId>
        <artifactId>zipkin-reporter-brave</artifactId>
    </dependency>
    -->

    <!-- Feign: propagates trace headers in OpenFeign calls: -->
    <dependency>
        <groupId>io.github.openfeign</groupId>
        <artifactId>feign-micrometer</artifactId>
    </dependency>
</dependencies>

# application.yml
spring:
  application:
    name: order-service        # service name in the trace UI and in logs

management:
  tracing:
    sampling:
      probability: 1.0         # 1.0 = 100% (dev/staging); default is 0.1 (10%)
    propagation:
      type: w3c                # w3c (default), b3, b3_multi

  # ── Spring Boot 3.x: OTLP exporter (Tempo, Jaeger, vendors): ─────────
  otlp:
    tracing:
      endpoint: http://tempo:4318/v1/traces

  # ── Spring Boot 3.x: Zipkin exporter: ───────────────────────────────
  # zipkin:
  #   tracing:
  #     endpoint: http://zipkin:9411/api/v2/spans

  # ── Spring Boot 4.x: OTLP exporter: ─────────────────────────────────
  # opentelemetry:
  #   tracing:
  #     export:
  #       otlp:
  #         endpoint: http://tempo:4318/v1/traces

  # ── Spring Boot 4.x: Zipkin with Brave (spring-boot-starter-zipkin): ─
  # tracing:
  #   export:
  #     zipkin:
  #       endpoint: http://zipkin:9411/api/v2/spans

# ── application-prod.yml override: ───────────────────────────────────
# management:
#   tracing:
#     sampling:
#       probability: 0.05        # 5% sampling in production

# application.yml

# Sleuth-style correlation id: [order-service,4bf92f35...,00f067aa...]
logging:
  pattern:
    correlation: "[${spring.application.name:},%X{traceId:-},%X{spanId:-}] "

# Structured JSON logs (Spring Boot 3.4+). MDC values such as traceId and spanId are included:
# logging:
#   structured:
#     format:
#       console: ecs        # or logstash, gelf

# ── Roughly what a log line looks like with the default format: ──────
# 14:23:01.456 INFO 1 --- [order-service] [nio-8080-exec-1] [4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7] c.e.order.OrderService : Order placed orderId=1001
# 14:23:01.512 INFO 1 --- [order-service] [nio-8080-exec-1] [4bf92f3577b34da6a3ce929d0e0e4736-b9a37ca3f3a21c7d] c.e.order.client.UserClient : GET user-service/api/users/42
#                                                              ↑ same traceId on every line (the request),
#                                                                spanId differs per operation (the unit of work)

# ── Structured (JSON) example: ───────────────────────────────────────
# {
#   "@timestamp":   "2026-10-31T14:23:01.456Z",
#   "log.level":    "INFO",
#   "service.name": "order-service",
#   "traceId":      "4bf92f3577b34da6a3ce929d0e0e4736",
#   "spanId":       "00f067aa0ba902b7",
#   "message":      "Order placed orderId=1001"
# }

# 1. Call the first service with a known trace id:
curl -H "traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01" \
     http://localhost:8080/orders/1001

# 2. Search every service's logs for it:
#    Kibana (KQL):        traceId : "4bf92f3577b34da6a3ce929d0e0e4736"
#    Grafana Loki:        {app=~".+"} |= "4bf92f3577b34da6a3ce929d0e0e4736"
#    Local / Docker:      docker compose logs | grep 4bf92f3577b34da6a3ce929d0e0e4736

# 3. Open the same id in the trace UI (Zipkin, Tempo/Grafana, Jaeger):
#    you should see one trace with a span per service and per outgoing call.

# Checklist when it does not work:
#   - spring-boot-starter-actuator and a tracing starter/bridge are on the classpath
#   - management.tracing.sampling.probability is 1.0 while testing (default is 0.1)
#   - outgoing HTTP clients are created from Spring's builders (see below)
#   - every service uses the same propagation type

// ── WRONG: not instrumented, trace context is NOT propagated ─────────
RestTemplate bad = new RestTemplate();
WebClient    alsoBad = WebClient.create();

// ── RIGHT: build from the injected, pre-configured builders ───────────
@Configuration
public class HttpClientConfig {

    @Bean
    RestTemplate restTemplate(RestTemplateBuilder builder) {
        return builder.build();               // tracing interceptor is applied
    }

    @Bean
    WebClient webClient(WebClient.Builder builder) {
        return builder.baseUrl("http://user-service").build();
    }

    @Bean
    RestClient restClient(RestClient.Builder builder) {
        return builder.baseUrl("http://user-service").build();
    }
}

@Service
@RequiredArgsConstructor
@Slf4j
public class OrderService {

    private final ObservationRegistry observationRegistry;
    private final Tracer tracer;
    private final OrderRepository orderRepository;
    private final PaymentClient paymentClient;
    private final InventoryClient inventoryClient;

    // ── Recommended: Observation API (span + metric, errors recorded automatically) ──
    public OrderResponse placeOrder(CreateOrderRequest request) {
        return Observation.createNotStarted("order.placement", observationRegistry)
            .lowCardinalityKeyValue("channel", request.getChannel())            // metrics + traces
            .highCardinalityKeyValue("userId", String.valueOf(request.getUserId())) // traces only
            .observe(() -> {
                checkInventory(request);               // child span below
                PaymentResponse payment = processPayment(request);

                Order order = orderRepository.save(
                    Order.from(request, payment.getTransactionId()));

                log.info("Order placed successfully orderId={}", order.getId());
                return OrderResponse.from(order);
            });
    }

    private void checkInventory(CreateOrderRequest request) {
        Observation.createNotStarted("inventory.check", observationRegistry)
            .highCardinalityKeyValue("productId", String.valueOf(request.getProductId()))
            .observe(() -> inventoryClient.checkStock(request.getProductId()));
    }

    // ── Low-level Tracer API: a span without a metric ─────────────────
    private PaymentResponse processPayment(CreateOrderRequest request) {
        return inSpan("payment.process", () -> paymentClient.charge(PaymentRequest.from(request)));
    }

    // Small helper so every span is started, scoped, error-tagged and ended correctly:
    private <T> T inSpan(String name, Supplier<T> work) {
        Span span = tracer.nextSpan().name(name).start();
        try (Tracer.SpanInScope scope = tracer.withSpan(span)) {
            return work.get();
        } catch (RuntimeException ex) {
            span.error(ex);
            throw ex;
        } finally {
            span.end();
        }
    }
}

// ── Annotation style (needs management.observations.annotations.enabled=true + AspectJ) ──
@Service
public class ReportService {

    @Observed(name = "report.generate", contextualName = "generate-report")
    public Report generate(Long id) {
        // ...
        return new Report();
    }
}

# ── Option A (preferred): baggage, configured in application.yml ───────
# management:
#   tracing:
#     baggage:
#       enabled: true
#       remote-fields: tenantId        # propagated to downstream services
#       correlation:
#         fields: tenantId             # copied into the MDC → usable as %X{tenantId}

// ── Set baggage in code: ──────────────────────────────────────────────
try (BaggageInScope tenant = tracer.createBaggageInScope("tenantId", "acme")) {
    log.info("Handling request");     // MDC contains tenantId=acme; sent to downstream calls
    orderClient.fetch();
}

// ── Option B: custom correlation ID filter (entry point or first service) ─
@Component
@Order(Ordered.HIGHEST_PRECEDENCE)
public class CorrelationIdFilter extends OncePerRequestFilter {

    public static final String HEADER  = "X-Correlation-Id";
    public static final String MDC_KEY = "correlationId";
    private static final Pattern SAFE = Pattern.compile("^[A-Za-z0-9-]{8,64}$");

    @Override
    protected void doFilterInternal(HttpServletRequest request,
                                    HttpServletResponse response,
                                    FilterChain chain)
            throws ServletException, IOException {

        String incoming = request.getHeader(HEADER);
        String correlationId = (incoming != null && SAFE.matcher(incoming).matches())
            ? incoming                                   // accept only a safe format
            : UUID.randomUUID().toString();

        MDC.put(MDC_KEY, correlationId);
        response.setHeader(HEADER, correlationId);       // return it to the client
        try {
            chain.doFilter(request, response);
        } finally {
            MDC.remove(MDC_KEY);                         // remove only our key
        }
    }
}

// ── Propagate in Feign calls (RequestInterceptor beans are auto-registered): ──
@Component
public class CorrelationIdFeignInterceptor implements RequestInterceptor {

    @Override
    public void apply(RequestTemplate template) {
        String id = MDC.get(CorrelationIdFilter.MDC_KEY);
        if (StringUtils.hasText(id)) {
            template.header(CorrelationIdFilter.HEADER, id);
        }
    }
}

// ── Propagate in RestTemplate calls — must be registered explicitly: ───
public class CorrelationIdRestTemplateInterceptor implements ClientHttpRequestInterceptor {

    @Override
    public ClientHttpResponse intercept(HttpRequest request, byte[] body,
                                        ClientHttpRequestExecution execution)
            throws IOException {
        String id = MDC.get(CorrelationIdFilter.MDC_KEY);
        if (StringUtils.hasText(id)) {
            request.getHeaders().add(CorrelationIdFilter.HEADER, id);
        }
        return execution.execute(request, body);
    }
}

@Configuration
public class RestTemplateConfig {
    @Bean
    RestTemplate restTemplate(RestTemplateBuilder builder) {
        return builder
            .additionalInterceptors(new CorrelationIdRestTemplateInterceptor())
            .build();                                    // still instrumented for tracing
    }
}

// The MDC key is printed with %X{correlationId:-} or appears automatically in JSON logs.

# application.yml — declarative propagation
spring:
  task:
    execution:
      propagate-context: true        # auto-configured @Async executor
  reactor:
    context-propagation: auto        # Reactor / WebFlux
  kafka:
    template:
      observation-enabled: true      # producer side: writes trace context into headers
    listener:
      observation-enabled: true      # consumer side: restores trace context from headers

// ── Custom executor: register the decorator yourself ──────────────────
@Configuration
@EnableAsync
public class AsyncConfig {

    @Bean
    ContextPropagatingTaskDecorator contextPropagatingTaskDecorator() {
        return new ContextPropagatingTaskDecorator();
    }

    @Bean
    ThreadPoolTaskExecutor taskExecutor(ContextPropagatingTaskDecorator decorator) {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(5);
        executor.setMaxPoolSize(20);
        executor.setQueueCapacity(100);
        executor.setThreadNamePrefix("async-");
        executor.setTaskDecorator(decorator);   // trace + MDC follow the task
        executor.initialize();
        return executor;
    }
}

// ── Kafka with observation enabled: no tracing code needed ────────────
@Service
@RequiredArgsConstructor
@Slf4j
public class OrderEventPublisher {

    private final KafkaTemplate<String, OrderPlacedEvent> kafkaTemplate;

    public void publish(Order order) {
        kafkaTemplate.send("order.placed", order.getId().toString(), OrderPlacedEvent.from(order));
        log.info("Published order.placed orderId={}", order.getId());   // carries the traceId
    }
}

@Service
@Slf4j
public class PaymentEventListener {

    @KafkaListener(topics = "order.placed", groupId = "payment-service")
    public void handleOrderPlaced(OrderPlacedEvent event) {
        log.info("Processing order.placed orderId={}", event.orderId());  // same traceId as the producer
        // ...
    }
}

// ── Manual propagation for raw Kafka clients (Micrometer Propagator bean) ──
@Service
@RequiredArgsConstructor
public class RawKafkaTracing {

    private final Tracer tracer;
    private final Propagator propagator;

    // Producer: write the current context into the record headers
    public void inject(ProducerRecord<String, String> record) {
        Span current = tracer.currentSpan();
        if (current != null) {
            propagator.inject(current.context(), record.headers(),
                (headers, key, value) -> headers.add(key, value.getBytes(StandardCharsets.UTF_8)));
        }
    }

    // Consumer: continue the trace from the record headers
    public void consume(ConsumerRecord<String, String> record, Runnable work) {
        Span span = propagator.extract(record.headers(), (headers, key) -> {
                Header h = headers.lastHeader(key);
                return h == null ? null : new String(h.value(), StandardCharsets.UTF_8);
            })
            .name("kafka.consume.order.placed")
            .start();
        try (Tracer.SpanInScope scope = tracer.withSpan(span)) {
            work.run();
        } catch (RuntimeException ex) {
            span.error(ex);
            throw ex;
        } finally {
            span.end();
        }
    }
}