ivanursul

How to trace your logs using SLF4J MDC

  Comments  

How do you use your logs for searching problem requests? For instance, you got a problem response, with all headers, response body, and you need to find appropriate logs. How would you do that?

Personally, I found it useful to write some words about MDC - Mapped Diagnostic Context. Shortly, it is a concept of mapping request specific information.

Usage

We will configure MDC in Spring Boot application. We will use SLF4J on top of Logback implementation. Using it all together, we will create a unique requestId for each request in our system.

Components

We will use 4 components here: Spring Boot, Slf4j, Logback and Java

Spring Boot

Spring Boot will be used for managing dependency injection and registering pure Java Filter.

Slf4j

Simple Logging Facade is used for following abstraction principles. Additionally, MDC class is located inside slf4j dependency. Similar classes are inside log4j and logback dependencies.

Logback

Logback is used as one of logging providers

Pure Java

Java is used for writing simple Java Filter.

Affected files

MDCFilter
package org.startup.queue.filter;

import org.slf4j.MDC;
import org.springframework.stereotype.Component;

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.UUID;

@Component
public class MDCFilter implements Filter {

    @Override
    public void init(FilterConfig filterConfig) throws ServletException { }

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        HttpServletRequest httpRequest = (HttpServletRequest) request;
        HttpServletResponse httpResponse = (HttpServletResponse) response;

        String requestId = httpRequest.getHeader("requestId");

        if (requestId == null) {
            requestId = UUID.randomUUID().toString();
        }

        MDC.put("requestId", requestId);
        httpResponse.setHeader("requestId", requestId);

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

    @Override
    public void destroy() {

    }
}

How MDC handle multiple requests ? It works per thread using ThreadLocal:

public class BasicMDCAdapter implements MDCAdapter {

    private InheritableThreadLocal<Map<String, String>> inheritableThreadLocal = new InheritableThreadLocal<Map<String, String>>();
...
}
logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>
                %d{yyyy-MM-dd HH:mm:ss} %X{requestId} [%thread] %-5level %logger{36} - %msg%n
            </Pattern>
        </layout>
    </appender>

    <root level="error">
        <appender-ref ref="STDOUT" />
    </root>

</configuration>

Result

The result of this little trick is to have requestId in your headers:

HTTP/1.1 200 OK
...
requestId: 11ae099f-3d8f-4574-9c40-1c38613f6605
...

You can now use it as an identifier for searching your logs.

Links