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
- Consistent Header Names: Use standard header names across all services
- MDC Cleanup: Always clear MDC to prevent memory leaks
- Async Context Propagation: Ensure trace context is propagated to async tasks
- Log Patterns: Use consistent log patterns across services
- Performance: Keep trace ID generation lightweight
- 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.