google-site-verification: google61fe8ba583a51912.html
Log Correlation with Trace ID in Java: Implementing End-to-End Request Tracking

Log correlation is essential for debugging and monitoring distributed systems. By propagating a unique trace ID across service boundaries, you can track a request's entire journey through your microservices architecture.


Core Concepts

What is Log Correlation?

  • Associating all log entries related to a single request with a unique identifier
  • Enabling end-to-end request tracing across service boundaries
  • Essential for debugging in microservices and distributed systems

Key Components:

  • Trace ID: Unique identifier for the entire request flow
  • Span ID: Identifier for individual operations within a trace
  • MDC (Mapped Diagnostic Context): Thread-local storage for contextual information
  • HTTP Headers: Propagation mechanism for trace context

Dependencies and Setup

Maven Dependencies
<properties> <slf4j.version>2.0.7</slf4j.version> <logback.version>1.4.11</logback.version> <spring-boot.version>3.1.0</spring-boot.version> </properties> <dependencies> <!-- Logging --> <dependency> <groupId>org.slf4j</groupId> <artifactId>slf4j-api</artifactId> <version>${slf4j.version}</version> </dependency> <dependency> <groupId>ch.qos.logback</groupId> <artifactId>logback-classic</artifactId> <version>${logback.version}</version> </dependency> <!-- Spring Boot --> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-web</artifactId> <version>${spring-boot.version}</version> </dependency> <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-aop</artifactId> <version>${spring-boot.version}</version> </dependency> </dependencies>
Logback Configuration
<!-- src/main/resources/logback-spring.xml --> <configuration> <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{traceId}] %-5level %logger{36} - %msg%n</pattern> </encoder> </appender> <appender name="JSON" class="ch.qos.logback.core.ConsoleAppender"> <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder"> <providers> <timestamp/> <logLevel/> <loggerName/> <message/> <mdc/> <threadName/> <pattern> <pattern> { "service": "user-service", "thread": "%thread", "level": "%level", "logger": "%logger", "message": "%message", "traceId": "%mdc{traceId}", "spanId": "%mdc{spanId}" } </pattern> </pattern> </providers> </encoder> </appender> <root level="INFO"> <appender-ref ref="JSON" /> </root> </configuration>

Core Implementation

1. Trace Context Model
public class TraceContext { private final String traceId; private final String spanId; private final String parentSpanId; private final Map<String, String> baggage; public TraceContext(String traceId, String spanId, String parentSpanId) { this.traceId = traceId; this.spanId = spanId; this.parentSpanId = parentSpanId; this.baggage = new HashMap<>(); } // Getters public String getTraceId() { return traceId; } public String getSpanId() { return spanId; } public String getParentSpanId() { return parentSpanId; } public Map<String, String> getBaggage() { return baggage; } public void addBaggage(String key, String value) { baggage.put(key, value); } public String getBaggage(String key) { return baggage.get(key); } public TraceContext createChild() { String newSpanId = generateId(); TraceContext child = new TraceContext(traceId, newSpanId, spanId); child.baggage.putAll(this.baggage); return child; } private static String generateId() { return UUID.randomUUID().toString().replace("-", "").substring(0, 16); } public static TraceContext createNew() { String traceId = generateId(); String spanId = generateId(); return new TraceContext(traceId, spanId, null); } }
2. Trace ID Generator
@Component public class TraceIdGenerator { public String generateTraceId() { // Option 1: UUID-based return UUID.randomUUID().toString().replace("-", "").substring(0, 16); // Option 2: Timestamp + random // return System.currentTimeMillis() + "-" + RandomStringUtils.randomAlphanumeric(8); } public String generateSpanId() { return RandomStringUtils.randomAlphanumeric(8); } }
3. Trace Context Holder (ThreadLocal)
@Component public class TraceContextHolder { private static final ThreadLocal<TraceContext> currentContext = new ThreadLocal<>(); public void setCurrentContext(TraceContext context) { currentContext.set(context); updateMDC(context); } public TraceContext getCurrentContext() { return currentContext.get(); } public String getCurrentTraceId() { TraceContext context = currentContext.get(); return context != null ? context.getTraceId() : null; } public String getCurrentSpanId() { TraceContext context = currentContext.get(); return context != null ? context.getSpanId() : null; } public void clear() { currentContext.remove(); clearMDC(); } private void updateMDC(TraceContext context) { if (context != null) { MDC.put("traceId", context.getTraceId()); MDC.put("spanId", context.getSpanId()); // Add baggage to MDC context.getBaggage().forEach(MDC::put); } } private void clearMDC() { MDC.clear(); } public TraceContext createChildContext() { TraceContext parent = getCurrentContext(); if (parent == null) { return TraceContext.createNew(); } return parent.createChild(); } }
4. HTTP Headers Constants
public class TraceHeaders { public static final String TRACE_ID = "X-Trace-Id"; public static final String SPAN_ID = "X-Span-Id"; public static final String PARENT_SPAN_ID = "X-Parent-Span-Id"; public static final String BAGGAGE_PREFIX = "X-Baggage-"; private TraceHeaders() { // Constants class } }

Spring Boot Integration

1. HTTP Filter for Incoming Requests
@Component public class TraceFilter implements Filter { private final TraceContextHolder traceContextHolder; private final TraceIdGenerator traceIdGenerator; private static final Logger logger = LoggerFactory.getLogger(TraceFilter.class); public TraceFilter(TraceContextHolder traceContextHolder, TraceIdGenerator traceIdGenerator) { this.traceContextHolder = traceContextHolder; this.traceIdGenerator = traceIdGenerator; } @Override public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException { HttpServletRequest httpRequest = (HttpServletRequest) request; HttpServletResponse httpResponse = (HttpServletResponse) response; try { // Extract or generate trace context from headers TraceContext context = extractOrCreateContext(httpRequest); traceContextHolder.setCurrentContext(context); // Add trace ID to response headers for client convenience httpResponse.setHeader(TraceHeaders.TRACE_ID, context.getTraceId()); logger.info("Incoming request: {} {} [TraceId: {}]", httpRequest.getMethod(), httpRequest.getRequestURI(), context.getTraceId()); chain.doFilter(request, response); } finally { logger.info("Request completed: {} {} [Status: {}]", httpRequest.getMethod(), httpRequest.getRequestURI(), httpResponse.getStatus()); traceContextHolder.clear(); } } private TraceContext extractOrCreateContext(HttpServletRequest request) { String traceId = getHeader(request, TraceHeaders.TRACE_ID); String spanId = getHeader(request, TraceHeaders.SPAN_ID); String parentSpanId = getHeader(request, TraceHeaders.PARENT_SPAN_ID); if (traceId == null) { // No existing trace - create new one traceId = traceIdGenerator.generateTraceId(); spanId = traceIdGenerator.generateSpanId(); logger.debug("Created new trace context: traceId={}, spanId={}", traceId, spanId); } else if (spanId == null) { // Has trace but no span - create new span spanId = traceIdGenerator.generateSpanId(); logger.debug("Created new span in existing trace: traceId={}, spanId={}", traceId, spanId); } TraceContext context = new TraceContext(traceId, spanId, parentSpanId); // Extract baggage headers extractBaggage(request, context); return context; } private String getHeader(HttpServletRequest request, String headerName) { String value = request.getHeader(headerName); return (value != null && !value.trim().isEmpty()) ? value.trim() : null; } private void extractBaggage(HttpServletRequest request, TraceContext context) { Enumeration<String> headerNames = request.getHeaderNames(); while (headerNames.hasMoreElements()) { String headerName = headerNames.nextElement(); if (headerName.startsWith(TraceHeaders.BAGGAGE_PREFIX)) { String key = headerName.substring(TraceHeaders.BAGGAGE_PREFIX.length()); String value = request.getHeader(headerName); context.addBaggage(key, value); } } } }
2. RestTemplate Interceptor for Outgoing Requests
@Component public class TraceRestTemplateInterceptor implements ClientHttpRequestInterceptor { private final TraceContextHolder traceContextHolder; private static final Logger logger = LoggerFactory.getLogger(TraceRestTemplateInterceptor.class); public TraceRestTemplateInterceptor(TraceContextHolder traceContextHolder) { this.traceContextHolder = traceContextHolder; } @Override public ClientHttpResponse intercept(HttpRequest request, byte[] body, ClientHttpRequestExecution execution) throws IOException { TraceContext currentContext = traceContextHolder.getCurrentContext(); if (currentContext != null) { // Propagate trace context to downstream services request.getHeaders().add(TraceHeaders.TRACE_ID, currentContext.getTraceId()); request.getHeaders().add(TraceHeaders.SPAN_ID, currentContext.getSpanId()); request.getHeaders().add(TraceHeaders.PARENT_SPAN_ID, currentContext.getParentSpanId()); // Propagate baggage currentContext.getBaggage().forEach((key, value) -> { request.getHeaders().add(TraceHeaders.BAGGAGE_PREFIX + key, value); }); logger.debug("Propagating trace context to downstream service: {} [TraceId: {}]", request.getURI(), currentContext.getTraceId()); } return execution.execute(request, body); } } @Configuration public class RestTemplateConfig { @Bean public RestTemplate restTemplate(TraceRestTemplateInterceptor traceInterceptor) { RestTemplate restTemplate = new RestTemplate(); // Add trace interceptor List<ClientHttpRequestInterceptor> interceptors = new ArrayList<>(); interceptors.add(traceInterceptor); restTemplate.setInterceptors(interceptors); return restTemplate; } }
3. WebClient Filter for Reactive Applications
@Component public class TraceWebClientFilter { private final TraceContextHolder traceContextHolder; public TraceWebClientFilter(TraceContextHolder traceContextHolder) { this.traceContextHolder = traceContextHolder; } public ExchangeFilterFunction traceExchangeFilter() { return ExchangeFilterFunction.ofRequestProcessor(clientRequest -> { TraceContext context = traceContextHolder.getCurrentContext(); if (context == null) { return Mono.just(clientRequest); } // Add trace headers to the request ClientRequest mutatedRequest = ClientRequest.from(clientRequest) .header(TraceHeaders.TRACE_ID, context.getTraceId()) .header(TraceHeaders.SPAN_ID, context.getSpanId()) .header(TraceHeaders.PARENT_SPAN_ID, context.getParentSpanId()) .build(); context.getBaggage().forEach((key, value) -> { mutatedRequest.headers().set(TraceHeaders.BAGGAGE_PREFIX + key, value); }); return Mono.just(mutatedRequest); }); } }
4. AOP for Method-Level Tracing
@Aspect @Component public class TraceAspect { private final TraceContextHolder traceContextHolder; private static final Logger logger = LoggerFactory.getLogger(TraceAspect.class); public TraceAspect(TraceContextHolder traceContextHolder) { this.traceContextHolder = traceContextHolder; } @Around("@annotation(Traced)") public Object traceMethod(ProceedingJoinPoint joinPoint) throws Throwable { String methodName = joinPoint.getSignature().toShortString(); String traceId = traceContextHolder.getCurrentTraceId(); logger.debug("Entering method: {} [TraceId: {}]", methodName, traceId); long startTime = System.currentTimeMillis(); try { Object result = joinPoint.proceed(); long duration = System.currentTimeMillis() - startTime; logger.debug("Exiting method: {} [Duration: {}ms, TraceId: {}]", methodName, duration, traceId); return result; } catch (Exception e) { long duration = System.currentTimeMillis() - startTime; logger.error("Method failed: {} [Duration: {}ms, TraceId: {}, Error: {}]", methodName, duration, traceId, e.getMessage()); throw e; } } } @Retention(RetentionPolicy.RUNTIME) @Target(ElementType.METHOD) public @interface Traced { String value() default ""; }

Usage Examples

1. Service with Trace Logging
@Service public class UserService { private static final Logger logger = LoggerFactory.getLogger(UserService.class); private final RestTemplate restTemplate; private final TraceContextHolder traceContextHolder; public UserService(RestTemplate restTemplate, TraceContextHolder traceContextHolder) { this.restTemplate = restTemplate; this.traceContextHolder = traceContextHolder; } @Traced public User getUserById(String userId) { String traceId = traceContextHolder.getCurrentTraceId(); logger.info("Fetching user by ID: {} [TraceId: {}]", userId, traceId); try { // Simulate database call User user = fetchUserFromDatabase(userId); logger.debug("User found: {} [TraceId: {}]", user.getName(), traceId); return user; } catch (Exception e) { logger.error("Failed to fetch user: {} [TraceId: {}, Error: {}]", userId, traceId, e.getMessage()); throw e; } } public void processUserOrder(String userId, Order order) { String traceId = traceContextHolder.getCurrentTraceId(); logger.info("Processing order for user: {}, Order: {} [TraceId: {}]", userId, order.getId(), traceId); // Call inventory service with trace propagation String inventoryUrl = "http://inventory-service/api/items/check"; ResponseEntity<String> response = restTemplate.postForEntity( inventoryUrl, order, String.class); logger.debug("Inventory service response: {} [TraceId: {}]", response.getStatusCode(), traceId); } private User fetchUserFromDatabase(String userId) { // Simulate database access return new User(userId, "John Doe", "[email protected]"); } }
2. REST Controller
@RestController @RequestMapping("/api/users") public class UserController { private static final Logger logger = LoggerFactory.getLogger(UserController.class); private final UserService userService; private final TraceContextHolder traceContextHolder; public UserController(UserService userService, TraceContextHolder traceContextHolder) { this.userService = userService; this.traceContextHolder = traceContextHolder; } @GetMapping("/{userId}") public ResponseEntity<User> getUser(@PathVariable String userId) { String traceId = traceContextHolder.getCurrentTraceId(); logger.info("Received request for user: {} [TraceId: {}]", userId, traceId); try { User user = userService.getUserById(userId); return ResponseEntity.ok(user); } catch (Exception e) { logger.error("Error processing request for user: {} [TraceId: {}]", userId, traceId, e); return ResponseEntity.status(HttpStatus.INTERNAL_SERVER_ERROR).build(); } } @PostMapping("/{userId}/orders") public ResponseEntity<Void> createOrder(@PathVariable String userId, @RequestBody Order order) { String traceId = traceContextHolder.getCurrentTraceId(); logger.info("Creating order for user: {} [TraceId: {}]", userId, traceId); try { userService.processUserOrder(userId, order); return ResponseEntity.accepted().build(); } catch (Exception e) { logger.error("Failed to create order for user: {} [TraceId: {}]", userId, traceId, e); return ResponseEntity.status(HttpStatus.INTERNAL_SERVER_ERROR).build(); } } }
3. Async Task Tracing
@Component public class AsyncTaskService { private static final Logger logger = LoggerFactory.getLogger(AsyncTaskService.class); private final TraceContextHolder traceContextHolder; private final TaskExecutor taskExecutor; public AsyncTaskService(TraceContextHolder traceContextHolder, @Qualifier("taskExecutor") TaskExecutor taskExecutor) { this.traceContextHolder = traceContextHolder; this.taskExecutor = taskExecutor; } @Async("taskExecutor") public void processBackgroundTask(String taskData) { // Trace context is automatically propagated with TaskExecutor configuration String traceId = traceContextHolder.getCurrentTraceId(); logger.info("Processing background task: {} [TraceId: {}]", taskData, traceId); // Simulate work try { Thread.sleep(1000); logger.debug("Background task completed: {} [TraceId: {}]", taskData, traceId); } catch (InterruptedException e) { logger.error("Background task interrupted: {} [TraceId: {}]", taskData, traceId); Thread.currentThread().interrupt(); } } } @Configuration @EnableAsync public class AsyncConfig implements AsyncConfigurer { @Bean("taskExecutor") public TaskExecutor taskExecutor() { ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor(); executor.setCorePoolSize(5); executor.setMaxPoolSize(10); executor.setQueueCapacity(25); executor.setThreadNamePrefix("async-"); executor.setTaskDecorator(new TraceContextTaskDecorator()); executor.initialize(); return executor; } } public class TraceContextTaskDecorator implements TaskDecorator { private final TraceContextHolder traceContextHolder; public TraceContextTaskDecorator() { // In real implementation, this would be injected this.traceContextHolder = ApplicationContextHolder.getBean(TraceContextHolder.class); } @Override public Runnable decorate(Runnable runnable) { TraceContext parentContext = traceContextHolder.getCurrentContext(); return () -> { if (parentContext != null) { traceContextHolder.setCurrentContext(parentContext); } try { runnable.run(); } finally { traceContextHolder.clear(); } }; } }

Testing

1. Unit Tests
@ExtendWith(MockitoExtension.class) class TraceContextHolderTest { @InjectMocks private TraceContextHolder traceContextHolder; @Test void shouldSetAndGetTraceContext() { // Given TraceContext context = new TraceContext("trace123", "span456", null); // When traceContextHolder.setCurrentContext(context); // Then assertThat(traceContextHolder.getCurrentContext()).isEqualTo(context); assertThat(traceContextHolder.getCurrentTraceId()).isEqualTo("trace123"); assertThat(traceContextHolder.getCurrentSpanId()).isEqualTo("span456"); } @Test void shouldClearContext() { // Given TraceContext context = new TraceContext("trace123", "span456", null); traceContextHolder.setCurrentContext(context); // When traceContextHolder.clear(); // Then assertThat(traceContextHolder.getCurrentContext()).isNull(); } } @SpringBootTest class TraceFilterTest { @Autowired private TestRestTemplate restTemplate; @Test void shouldPropagateTraceIdInResponse() { // When ResponseEntity<String> response = restTemplate.getForEntity("/api/users/123", String.class); // Then assertThat(response.getHeaders().get(TraceHeaders.TRACE_ID)).isNotNull(); } }

Best Practices

  1. Consistent Header Names: Use standard header names across all services
  2. MDC Cleanup: Always clear MDC to prevent memory leaks
  3. Async Context Propagation: Ensure trace context is propagated to async tasks
  4. Log Patterns: Use consistent log patterns across services
  5. Performance: Keep trace ID generation lightweight
  6. Security: Be cautious about what information you put in baggage
// Example of safe baggage usage public void addSafeBaggage(TraceContext context, String key, String value) { // Don't include sensitive information in baggage if (!isSensitive(key)) { context.addBaggage(key, value); } } private boolean isSensitive(String key) { return key.toLowerCase().contains("password") || key.toLowerCase().contains("token") || key.toLowerCase().contains("secret"); }

Conclusion

Log correlation with trace IDs provides:

  • End-to-end visibility of request flows across microservices
  • Faster debugging by grouping related log entries
  • Better monitoring and observability
  • Performance analysis across service boundaries

By implementing the patterns shown above, you can significantly improve your ability to understand, debug, and monitor complex distributed systems. The trace ID becomes the golden thread that connects all log entries related to a single user request, making it much easier to identify and resolve issues.

Leave a Reply

Your email address will not be published. Required fields are marked *


Macro Nepal Helper