1. Overview

In this tutorial, we'll look at how we can use MDC to include a correlation id to the logs in a web application. This way it will be easier to trace the logs for a specific request.

2. MDC Details

Let's first talk about some details on MDC.

Mapped Diagnostic Context or MDC manages contextual information on a per-thread basis. So we can benefit from MDC when logging in a multi-threaded application. For example, we can store the IP address of each request in a web application and insert this data to each log statement. In our case, we'll introduce a unique correlation id for each request.

Web servers generally have a thread pool for handling requests. Consequently, the same thread is used for multiple different requests. So we must maintain the MDC to prevent data corruption. More specifically, after adding an entry to MDC, we must remove it when the request ends.

3. Sample Application

Let's continue with our sample application.

@Slf4j
@RestController
public class HelloController {

    private final HelloService helloService;

    public HelloController(HelloService helloService) {
        this.helloService = helloService;
    }

    @GetMapping("/hello")
    public String hello(){
        log.info("Entered hello endpoint");
        return helloService.sayHello();
    }
}

HelloController has a single endpoint and uses the HelloService class.

@Slf4j
@Service
public class HelloService {

    public String sayHello() {
        log.info("Entered sayHello");
        return "Hello";
    }
}

HelloService is a simple service with the sayHello method.

4. MDC Filter

Firstly, we'll create an MDC filter to generate and store a correlation id. Moreover, this id must be unique for each request:

@WebFilter
public class MdcFilter extends HttpFilter {

    @Override
    protected void doFilter(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
      throws IOException, ServletException {
        try {
            MDC.put("CorrelationId", getCorrelationId());
            filterChain.doFilter(request, response);
        } finally {
            MDC.remove("CorrelationId");
        }
    }

    private String getCorrelationId() {
        return UUID.randomUUID().toString();
    }
}

In MDCFilter, we're putting the CorrelationId entry before the filterChain.doFilter call. By this way, all subsequent logging activities will include this correlation id. After the request is handled, we're removing CorrelationId in the finally block. Note that the remove operation will run even if an exception occurs.

Now that we have MDC ready, we must configure the log format to include the correlation id.

Spring Boot enables us to define the log format in application.properties:

logging.pattern.console=%-4relative [%thread] %-5level %logger{35} %X{CorrelationId} --- %msg %n

The %X{CorrelationId} expression adds the correlation id to the log output.

When we look at the application logs, we can identify the statements belonging to a specific request.

2458 [http-nio-auto-1-exec-1] INFO c.j.s.m.mdc.filter.HelloController 73d3d947-6242-429f-83b4-6264eb153a0d --- Entered hello endpoint 
2458 [http-nio-auto-1-exec-1] INFO c.j.s.mvc1.mdc.filter.HelloService 73d3d947-6242-429f-83b4-6264eb153a0d --- Entered sayHello 
2504 [http-nio-auto-1-exec-2] INFO c.j.s.m.mdc.filter.HelloController 745a17b3-8fbb-4221-955d-367056801425 --- Entered hello endpoint 
2504 [http-nio-auto-1-exec-2] INFO c.j.s.mvc1.mdc.filter.HelloService 745a17b3-8fbb-4221-955d-367056801425 --- Entered sayHello

5. MDC HandlerInterceptor

Now we'll look at how we can achieve similar behavior with HandlerInterceptor.

In the previous Filter implementation, we added the correlation id before DispatcherServlet handles the request. In the case of a HandlerInterceptor-based solution, we'll add the correlation id inside the DispatcherServlet processing flow.

public class MdcInterceptor implements HandlerInterceptor {

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        MDC.put("CorrelationId", getCorrelationId());
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        MDC.remove("CorrelationId");
    }

    private String getCorrelationId() {
        return UUID.randomUUID().toString();
    }
}

Here, we have the MDCInterceptor class where we add CorrelationId in preHandle and remove it in afterCompletion.

We must also register this interceptor:

@Component
public class WebMvcConfiguration implements WebMvcConfigurer {

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(new MdcInterceptor());
    }
}

When the application serves a request, it generates the correlation id:

2444 [http-nio-auto-1-exec-1] INFO  c.j.s.m.m.i.HelloController 624c23d1-b0a0-4299-b676-ca8c63b61163 --- Entered hello endpoint 
2445 [http-nio-auto-1-exec-1] INFO  c.j.s.m.m.interceptor.HelloService 624c23d1-b0a0-4299-b676-ca8c63b61163 --- Entered sayHello 
2486 [http-nio-auto-1-exec-2] INFO  c.j.s.m.m.i.HelloController 2cad80b4-8791-459d-a29b-113d060efefd --- Entered hello endpoint 
2486 [http-nio-auto-1-exec-2] INFO  c.j.s.m.m.interceptor.HelloService 2cad80b4-8791-459d-a29b-113d060efefd --- Entered sayHello

6. Summary

In this tutorial, we've looked at how we can correlate logs for a request using MDC.

Check out the source code for all examples over on Github.