Spring BootDistributed Logging
Spring Boot

Distributed Logging

Distributed logging connects log entries across multiple microservices into a single traceable request flow. A single user action may touch a dozen services — without a shared trace ID in every log line, diagnosing failures means manually correlating timestamps across separate log files. Spring Boot integrates with Micrometer Tracing and OpenTelemetry to propagate trace context automatically, making every log line part of a queryable distributed trace.

Trace Context and Propagation

Every request entering the system is assigned a trace ID — a unique identifier that follows the request across every service it touches. Each service creates a span (a unit of work within the trace) with its own span ID. The trace ID and span ID are injected into the MDC so every log line carries them automatically, and propagated to downstream services via HTTP headers (W3C Trace Context or B3 format).
Java
// ── How trace context flows through the system: ──────────────────────
//
//  Client → API Gateway → OrderService → UserService
//                                      → PaymentService → StripeAPI
//
//  traceId: 4bf92f3577b34da6  (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 = "4bf92f3577b34da6"
//    → see all logs from all services for this one request,
//      in chronological order.

// ── HTTP propagation headers: ─────────────────────────────────────────
//
// W3C Trace Context (standard — recommended):
//   traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01
//                 ↑  ↑                                ↑                ↑
//               ver  traceId (32 hex)                spanId (16 hex)  flags
//   tracestate:  vendor-specific state (optional)
//
// B3 (Zipkin legacy — still common):
//   X-B3-TraceId:      4bf92f3577b34da6a3ce929d0e0e4736
//   X-B3-SpanId:       00f067aa0ba902b7
//   X-B3-ParentSpanId: a2fb4a1d1a96d312
//   X-B3-Sampled:      1
//
// Spring Boot Micrometer Tracing supports both formats.
// Default in Spring Boot 3.x: W3C Trace Context.

Micrometer Tracing Setup (Spring Boot 3.x)

Spring Cloud Sleuth was deprecated in Spring Boot 3.x and replaced by Micrometer Tracing. Micrometer Tracing is the tracing facade (the API your code calls); a bridge connects it to a concrete implementation — either OpenTelemetry or Brave (Zipkin). Trace IDs are automatically injected into the SLF4J MDC, so all log lines from a traced request carry the trace context without any code changes.
XML
<!-- pom.xml — Micrometer Tracing with OpenTelemetry bridge: -->
<dependencies>

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

    <!-- OpenTelemetry exporter — sends spans to Zipkin: -->
    <dependency>
        <groupId>io.opentelemetry</groupId>
        <artifactId>opentelemetry-exporter-zipkin</artifactId>
    </dependency>

    <!-- OR: OpenTelemetry exporter — sends spans to OTLP (Tempo, Jaeger): -->
    <dependency>
        <groupId>io.opentelemetry</groupId>
        <artifactId>opentelemetry-exporter-otlp</artifactId>
    </dependency>

    <!-- Feign tracing — auto-propagates headers in Feign calls: -->
    <dependency>
        <groupId>io.github.openfeign</groupId>
        <artifactId>feign-micrometer</artifactId>
    </dependency>

    <!-- Brave bridge (alternative to OTel — 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>
    -->

</dependencies>

Tracing Configuration

Sampling controls what percentage of requests generate a full trace. In high-throughput production systems, 100% sampling is too expensive — use 1–10%. In staging and for low-traffic critical paths, 100% sampling is fine. The trace context is always propagated regardless of sampling — sampling only controls whether spans are exported to the tracing backend.
yaml
# application.yml
spring:
  application:
    name: order-service       # appears as service name in trace UI

management:
  tracing:
    sampling:
      probability: 1.0        # 1.0 = 100% (all requests traced)
                              # 0.1 = 10%  (production default)
                              # 0.0 = 0%   (disabled)
    enabled: true
  zipkin:
    tracing:
      endpoint: http://zipkin:9411/api/v2/spans

  # ── OTLP exporter (for Grafana Tempo / Jaeger): ──────────────────────
  # otlp:
  #   tracing:
  #     endpoint: http://tempo:4318/v1/traces

logging:
  pattern:
    # Include traceId and spanId in every log line:
    level: "%5p [${spring.application.name:},%X{traceId:-},%X{spanId:-}]"

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

// ── Log output with tracing (logback-spring.xml pattern): ────────────
// Console pattern — shows traceId and spanId in every line:
// %d{HH:mm:ss.SSS} %5p [order-service,%X{traceId:-},%X{spanId:-}]
//                  %-40logger{36} : %m%n
//
// Sample output:
// 14:23:01.456  INFO [order-service,4bf92f3577b34da6,00f067aa0ba902b7]
//              c.e.order.service.OrderService : Order placed orderId=1001
// 14:23:01.512  INFO [order-service,4bf92f3577b34da6,00f067aa0ba902b7]
//              c.e.order.client.UserClient : GET user-service/api/users/42
// 14:23:01.608  INFO [order-service,4bf92f3577b34da6,00f067aa0ba902b7]
//              c.e.order.client.PaymentClient : Payment SUCCESS amount=99.99
//                                              ↑
//              All three lines share the same traceId and spanId —
//              they belong to the same request.

Custom Spans and Trace Enrichment

Auto-instrumentation creates spans for HTTP requests and Feign calls automatically. Custom spans are needed for significant internal operations — database batch jobs, external API calls not covered by auto-instrumentation, or any operation whose duration and outcome should be separately visible in the trace timeline.
Java
@Service
@RequiredArgsConstructor
@Slf4j
public class OrderService {

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

    public OrderResponse placeOrder(CreateOrderRequest request) {

        // ── Custom span for the full order placement: ─────────────────
        Span orderSpan = tracer.nextSpan()
            .name("order.placement")
            .tag("channel",    request.getChannel())
            .tag("userId",     request.getUserId().toString())
            .tag("productId",  request.getProductId().toString());

        try (Tracer.SpanInScope scope = tracer.withSpan(orderSpan.start())) {

            // Check inventory — separate child span:
            InventoryResponse inventory =
                checkInventoryWithSpan(request.getProductId(),
                                       request.getQuantity());

            // Process payment — separate child span:
            PaymentResponse payment =
                processPaymentWithSpan(request);

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

            orderSpan.tag("orderId", order.getId().toString());
            log.info("Order placed successfully orderId={}", order.getId());

            return OrderResponse.from(order);

        } catch (Exception ex) {
            orderSpan.tag("error", "true")
                     .tag("error.message", ex.getMessage())
                     .error(ex);
            log.error("Order placement failed: {}", ex.getMessage(), ex);
            throw ex;
        } finally {
            orderSpan.end();
        }
    }

    private InventoryResponse checkInventoryWithSpan(
            Long productId, int quantity) {
        Span span = tracer.nextSpan()
            .name("inventory.check")
            .tag("productId", productId.toString());
        try (Tracer.SpanInScope ws = tracer.withSpan(span.start())) {
            InventoryResponse response =
                inventoryClient.checkStock(productId);
            span.tag("available", String.valueOf(response.isAvailable()));
            return response;
        } catch (Exception ex) {
            span.error(ex);
            throw ex;
        } finally {
            span.end();
        }
    }

    private PaymentResponse processPaymentWithSpan(
            CreateOrderRequest request) {
        Span span = tracer.nextSpan()
            .name("payment.process")
            .tag("amount",   request.getAmount().toString())
            .tag("currency", request.getCurrency());
        try (Tracer.SpanInScope ws = tracer.withSpan(span.start())) {
            PaymentResponse response = paymentClient.charge(
                PaymentRequest.from(request));
            span.tag("transactionId", response.getTransactionId());
            return response;
        } catch (Exception ex) {
            span.error(ex);
            throw ex;
        } finally {
            span.end();
        }
    }
}

Correlation ID for Non-Traced Systems

Not every service in a distributed system supports OpenTelemetry. Legacy systems, third-party APIs, and batch jobs may not propagate trace context. A correlation ID — a simpler UUID generated at the system entry point and forwarded as a custom header — provides basic request correlation even without a full tracing stack. It complements trace IDs rather than replacing them.
Java
// ── Correlation ID filter — entry point (API Gateway or first service): ─
@Component
@Order(Ordered.HIGHEST_PRECEDENCE)
@Slf4j
public class CorrelationIdFilter extends OncePerRequestFilter {

    public static final String CORRELATION_ID_HEADER = "X-Correlation-Id";
    public static final String CORRELATION_ID_MDC_KEY = "correlationId";

    @Override
    protected void doFilterInternal(HttpServletRequest request,
                                    HttpServletResponse response,
                                    FilterChain chain)
            throws ServletException, IOException {
        String correlationId = Optional
            .ofNullable(request.getHeader(CORRELATION_ID_HEADER))
            .filter(StringUtils::hasText)
            .orElse(generateCorrelationId());

        MDC.put(CORRELATION_ID_MDC_KEY, correlationId);

        // Return the correlation ID to the client:
        response.setHeader(CORRELATION_ID_HEADER, correlationId);

        try {
            chain.doFilter(request, response);
        } finally {
            MDC.remove(CORRELATION_ID_MDC_KEY);
        }
    }

    private String generateCorrelationId() {
        return UUID.randomUUID().toString().replace("-", "").substring(0, 16);
    }
}

// ── Propagate correlation ID in Feign calls: ──────────────────────────
@Component
public class CorrelationIdFeignInterceptor implements RequestInterceptor {

    @Override
    public void apply(RequestTemplate template) {
        String correlationId = MDC.get(
            CorrelationIdFilter.CORRELATION_ID_MDC_KEY);
        if (StringUtils.hasText(correlationId)) {
            template.header(
                CorrelationIdFilter.CORRELATION_ID_HEADER,
                correlationId);
        }
    }
}

// ── Propagate in RestTemplate calls: ─────────────────────────────────
@Component
public class CorrelationIdRestTemplateInterceptor
        implements ClientHttpRequestInterceptor {

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

// ── Log output with both traceId and correlationId: ───────────────────
// {
//   "timestamp":     "2025-05-30T14:23:01.456Z",
//   "level":         "INFO",
//   "service":       "order-service",
//   "traceId":       "4bf92f3577b34da6",     ← OpenTelemetry trace
//   "spanId":        "00f067aa0ba902b7",
//   "correlationId": "a3ce929d0e0e4736",     ← simpler correlation
//   "userId":        "42",
//   "message":       "Order placed orderId=1001"
// }

Async and Kafka Trace Propagation

Trace context must be explicitly propagated when crossing thread boundaries — @Async methods, CompletableFuture, and Kafka consumers all run on different threads where the MDC and span context are not inherited automatically. Micrometer Tracing provides utilities to capture and restore context across these boundaries.
Java
// ── @Async trace propagation with TaskDecorator: ────────────────────
@Configuration
@RequiredArgsConstructor
public class AsyncTracingConfig implements AsyncConfigurer {

    private final Tracer tracer;

    @Override
    public Executor getAsyncExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(5);
        executor.setMaxPoolSize(20);
        executor.setQueueCapacity(100);
        executor.setThreadNamePrefix("async-");

        // Capture trace context on the submitting thread,
        // restore it on the executing thread:
        executor.setTaskDecorator(runnable -> {
            // Capture current span from the calling thread:
            Span currentSpan = tracer.currentSpan();
            Map<String, String> mdcContext = MDC.getCopyOfContextMap();

            return () -> {
                // Restore span and MDC on the async thread:
                try (Tracer.SpanInScope scope = currentSpan != null
                        ? tracer.withSpan(currentSpan)
                        : tracer.withSpan(tracer.nextSpan())) {
                    if (mdcContext != null) {
                        MDC.setContextMap(mdcContext);
                    }
                    runnable.run();
                } finally {
                    MDC.clear();
                }
            };
        });
        executor.initialize();
        return executor;
    }
}

// ── Kafka producer — inject trace context into message headers: ───────
@Service
@RequiredArgsConstructor
@Slf4j
public class OrderEventPublisher {

    private final KafkaTemplate<String, OrderPlacedEvent> kafkaTemplate;
    private final Tracer tracer;

    public void publish(Order order) {
        Span span = tracer.nextSpan().name("kafka.publish.order.placed");

        try (Tracer.SpanInScope ws = tracer.withSpan(span.start())) {
            OrderPlacedEvent event = OrderPlacedEvent.from(order);

            ProducerRecord<String, OrderPlacedEvent> record =
                new ProducerRecord<>("order.placed",
                    order.getId().toString(), event);

            // Inject W3C trace context into Kafka headers:
            tracer.propagate().injector(
                (carrier, key, value) ->
                    carrier.headers().add(key, value.getBytes()))
                .inject(span.context(), record);

            kafkaTemplate.send(record);
            log.info("Published order.placed event orderId={}",
                order.getId());
        } finally {
            span.end();
        }
    }
}

// ── Kafka consumer — extract and restore trace context: ───────────────
@Service
@RequiredArgsConstructor
@Slf4j
public class PaymentEventListener {

    private final Tracer tracer;

    @KafkaListener(topics = "order.placed", groupId = "payment-service")
    public void handleOrderPlaced(
            ConsumerRecord<String, OrderPlacedEvent> record) {

        // Extract trace context from Kafka headers:
        TraceContext.Extractor<RecordHeaders> extractor =
            tracer.propagate().extractor(
                (carrier, key) -> {
                    Header header = carrier.lastHeader(key);
                    return header != null
                        ? new String(header.value()) : null;
                });

        TraceContextOrSamplingFlags extracted =
            extractor.extract(record.headers());

        Span span = tracer.nextSpan(extracted)
            .name("kafka.consume.order.placed")
            .tag("orderId", record.key());

        try (Tracer.SpanInScope ws = tracer.withSpan(span.start())) {
            log.info("Processing order.placed event orderId={}",
                record.key());
            processPayment(record.value());
        } catch (Exception ex) {
            span.error(ex);
            throw ex;
        } finally {
            span.end();
        }
    }
}