Java中Log4J按请求分组打日志及日志混乱问题解决方案咨询

Oh man, I’ve been there—debugging a production issue where logs from 10 different requests are all jumbled together, making it impossible to trace what happened to a single user’s request. The good news is Log4j has a built-in solution for this: Mapped Diagnostic Context (MDC). It’s designed exactly to attach request-specific context to all logs generated during that request’s lifecycle.

Let’s break down the steps to get this working:

1. Attach a Unique Request ID to MDC #

First, you need to generate a unique identifier for each incoming request and store it in MDC. MDC is thread-local storage, so any log statements from the same thread will automatically have access to this value.

Option A: Spring Boot Handler Interceptor #

If you’re using Spring Boot, a Handler Interceptor is a clean way to handle this:

import org.slf4j.MDC;
import org.springframework.web.servlet.HandlerInterceptor;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.UUID;

public class RequestIdInterceptor implements HandlerInterceptor {
    private static final String REQUEST_ID_KEY = "requestId";

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        // Generate a UUID for the request, or use one from a header if your gateway passes it
        String requestId = UUID.randomUUID().toString();
        // Uncomment below to use an upstream request ID (e.g., X-Request-ID from a gateway)
        // String requestId = request.getHeader("X-Request-ID");
        // if (requestId == null || requestId.isBlank()) {
        //     requestId = UUID.randomUUID().toString();
        // }
        MDC.put(REQUEST_ID_KEY, requestId);
        // Add the request ID to the response header so clients can track it too
        response.setHeader("X-Request-ID", requestId);
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        // Critical: Clean up MDC when the request finishes to avoid thread pool contamination
        MDC.remove(REQUEST_ID_KEY);
    }
}

Then register the interceptor in your Spring config:

import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

@Configuration
public class WebConfig implements WebMvcConfigurer {
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(new RequestIdInterceptor());
    }
}

Option B: Servlet Filter (Non-Spring Apps) #

If you’re not using Spring, a Servlet Filter works just as well:

import org.slf4j.MDC;
import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import java.io.IOException;
import java.util.UUID;

public class RequestIdFilter implements Filter {
    private static final String REQUEST_ID_KEY = "requestId";

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        try {
            String requestId = UUID.randomUUID().toString();
            MDC.put(REQUEST_ID_KEY, requestId);
            chain.doFilter(request, response);
        } finally {
            // Always clean up in a finally block to ensure it runs even if an exception occurs
            MDC.remove(REQUEST_ID_KEY);
        }
    }
}

Don’t forget to register the filter in your web.xml:

<filter>
    <filter-name>RequestIdFilter</filter-name>
    <filter-class>com.yourpackage.RequestIdFilter</filter-class>
</filter>
<filter-mapping>
    <filter-name>RequestIdFilter</filter-name>
    <url-pattern>/*</url-pattern>
</filter-mapping>

2. Update Log4j Configuration to Include the Request ID #

Now modify your Log4j config to print the requestId from MDC in every log line. This is what ties all logs from a single request together.

Log4j 2.x (XML Config) #

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <Appenders>
        <Console name="Console" target="SYSTEM_OUT">
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{36} - %X{requestId} - %msg%n"/>
        </Console>
    </Appenders>
    <Loggers>
        <Root level="info">
            <AppenderRef ref="Console"/>
        </Root>
    </Loggers>
</Configuration>

Log4j 1.x (Properties Config) #

log4j.rootLogger=INFO, stdout

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %-5level %logger{36} - %X{requestId} - %msg%n

The %X{requestId} part pulls the value we stored in MDC and inserts it into the log line.

3. Handle Thread Pool Edge Cases #

If your app uses thread pools (e.g., @Async methods, background jobs), MDC won’t automatically propagate to those threads because it’s thread-local. This can cause request IDs to leak between requests.

To fix this, wrap your thread pool to copy the MDC context when submitting tasks. Here’s how to do it for Spring’s async executor:

import org.slf4j.MDC;
import org.springframework.core.task.AsyncTaskExecutor;
import java.util.Map;
import java.util.concurrent.Callable;
import java.util.concurrent.Future;
import java.util.concurrent.Runnable;

public class MdcAwareAsyncExecutor implements AsyncTaskExecutor {
    private final AsyncTaskExecutor delegate;

    public MdcAwareAsyncExecutor(AsyncTaskExecutor delegate) {
        this.delegate = delegate;
    }

    @Override
    public void execute(Runnable task) {
        Map<String, String> context = MDC.getCopyOfContextMap();
        delegate.execute(() -> runWithContext(context, task));
    }

    @Override
    public <T> Future<T> submit(Callable<T> task) {
        Map<String, String> context = MDC.getCopyOfContextMap();
        return delegate.submit(() -> callWithContext(context, task));
    }

    @Override
    public Future<?> submit(Runnable task) {
        Map<String, String> context = MDC.getCopyOfContextMap();
        return delegate.submit(() -> runWithContext(context, task));
    }

    private void runWithContext(Map<String, String> context, Runnable task) {
        try {
            if (context != null) MDC.setContextMap(context);
            task.run();
        } finally {
            MDC.clear();
        }
    }

    private <T> T callWithContext(Map<String, String> context, Callable<T> task) throws Exception {
        try {
            if (context != null) MDC.setContextMap(context);
            return task.call();
        } finally {
            MDC.clear();
        }
    }
}

Then register this wrapper in your Spring config:

import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.scheduling.annotation.EnableAsync;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

@Configuration
@EnableAsync
public class AsyncConfig {
    @Bean
    public ThreadPoolTaskExecutor asyncTaskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(5);
        executor.setMaxPoolSize(10);
        executor.setQueueCapacity(25);
        executor.initialize();
        return new MdcAwareAsyncExecutor(executor);
    }
}

Final Result #

Once everything is set up, your logs will look like this—each line has a unique requestId that groups all logs from the same request:

2024-05-20 14:30:45.123 [http-nio-8080-exec-1] INFO  com.yourpackage.controller.UserController - 550e8400-e29b-41d4-a716-446655440000 - Fetching user details for ID: 123
2024-05-20 14:30:45.125 [http-nio-8080-exec-1] DEBUG com.yourpackage.service.UserService - 550e8400-e29b-41d4-a716-446655440000 - Querying database for user 123
2024-05-20 14:30:45.130 [http-nio-8080-exec-2] INFO  com.yourpackage.controller.OrderController - 7c9e6679-7425-40de-944b-e07fc1f90ae7 - Creating new order for user 456

Now you can easily filter logs by requestId to get a complete picture of any single request’s flow.

内容的提问来源于stack exchange，提问作者Chandeshwar Thakur