Spring中使用MDC和traceId实现日志链路追踪

前言

在系统出现问题时，我们常需要对日志进行分析，而如果日志打印时没有明确的标识，且日志内容不同线程很多时，很难找出哪段日志是我们需要的。针对这一问题，我们可以考虑使用MDC来实现日志链路追踪，迅速找到所需要的日志信息。当然，这也十分适合当下流行的微服务，特别是上下游节点有多个时，通过一个traceId来串联起整个链路流程。

一、MDC是什么？

MDC（Mapped Diagnostic Context，映射调试上下文）是Java中用于日志跟踪的一个工具，它主要被集成在日志框架中，如Log4j、Logback等。MDC提供了一种机制，允许开发者在多线程环境下关联和传递特定的上下文信息，这些信息对于日志的追踪、诊断和调试非常有用。

1、线程本地：MDC是基于线程本地变量（ThreadLocal）实现的，这意味着每个线程都有自己独立的MDC存储空间，线程之间不会相互干扰。

2、可维护：MDC中的信息可以被设置、获取和清除，这为日志的上下文管理提供了极大的灵活性。

3、可传递：在分布式系统中，MDC信息可以随着请求在多个服务或节点之间传递，帮助开发者追踪请求的完整处理流程。

二、使用MDC实现日志追踪

1. 添加TraceIdUtil工具类：

package com.neo.util;
 
import org.slf4j.MDC;
 
import java.util.UUID;
 
public class TraceIdUtil {
 
    public static final String KEY_TRACE_ID = "traceId";
 
    public static final String HEADER_TRACE_ID = "x-traceId";
 
    public static String generateTraceId() {
        return UUID.randomUUID().toString().replace("-", "");
    }
 
    public static String getTraceId() {
        return MDC.get(KEY_TRACE_ID);
    }
 
    public static void setTraceId(String traceId) {
        MDC.put(KEY_TRACE_ID, traceId);
    }
 
    public static void clear() {
        MDC.clear();
    }
 
}

2. 在拦截器中设置traceId

有些同学可能要问，为什么在拦截器设置？因为请求在进入controller之前会先经过设置的拦截器（如果uri匹配到）。当然在filter过滤器中也可以，设置和清除的方式是相同的。

package com.neo.interceptor;
 
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
 
import com.neo.util.TraceIdUtil;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.util.StringUtils;
import org.springframework.web.servlet.HandlerInterceptor;
  
@Component
public class TraceIdInterceptor implements HandlerInterceptor {
 
    private static final Logger logger = LoggerFactory.getLogger(TraceIdInterceptor.class);
  
    @Override  
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        logger.info("TraceIdInterceptor preHandle");
 
        // 从请求头中获取traceId，如果没有则生成一个
        String headerTraceId = request.getHeader(TraceIdUtil.HEADER_TRACE_ID);
        String traceId = StringUtils.isEmpty(headerTraceId) ? TraceIdUtil.generateTraceId() : headerTraceId;
        TraceIdUtil.setTraceId(traceId);
 
        // TODO 业务逻辑处理
 
        return true;
    }  
  
    @Override  
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        logger.info("TraceIdInterceptor afterCompletion");
 
        // 请求处理完成后，清除MDC中的traceId，以免造成内存泄漏
        TraceIdUtil.clear();
    }
}

此处解释下为什么要先从header中获取，如果没有再重新生成。因为考虑到如今很多项目采用微服务架构或上下游节点很多时，为了全流程的日志追踪，建议保持traceId一致，这样更方便日志排查。如果微服务项目中使用了Skywalking或ELK等日志系统时，就可以通过一个traceId拉出整个上下游节点日志，一目了然！

需要注意，如果项目中有多个拦截器，最好在第一个拦截器中设置traceId，否则有可能前置的拦截器直接拦截了请求，而你在后置的拦截器设置的traceId，日志就不会打印traceId了。如下，则需要在loginInterceptor中设置：

package com.neo.controller.config;
 
import com.neo.interceptor.LoginInterceptor;
import com.neo.interceptor.TraceIdInterceptor;
import org.springframework.beans.factory.annotation.Autowired;
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 {  
  
    @Autowired  
    private TraceIdInterceptor traceIdInterceptor;
 
    @Autowired
    private LoginInterceptor loginInterceptor;
  
    @Override  
    public void addInterceptors(InterceptorRegistry registry) {
        // addPathPatterns 用于添加拦截规则
        // excludePathPatterns 用于排除拦截规则
 
        registry.addInterceptor(loginInterceptor)
                .addPathPatterns("/**")
                .excludePathPatterns("/static/**", "/css/**", "/js/**", "/images/**");
 
        registry.addInterceptor(traceIdInterceptor)
                .addPathPatterns("/**") // 拦截所有请求
                .excludePathPatterns("/static/**", "/css/**", "/js/**", "/images/**"); // 排除静态资源
    }
}

！！！一定要注意，因为MDC底层使用的是ThreadLocal， 一定要记得在最后清除掉，防止出现内存泄漏！！！

3. 根据你当前的日志框架来加入打印traceId

(1). 如果项目中使用的是logback（springboot默认的日志框架）

<configuration>  
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">  
        <encoder>  
            <pattern>%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %X{traceId} - %msg%n</pattern>  
        </encoder>  
    </appender>  
  
    <root level="debug">  
        <appender-ref ref="STDOUT" />  
    </root>  
</configuration>

(2). 如果项目中使用的是log4j2

<Configuration>  
    <Appenders>  
        <Console name="Console" target="SYSTEM_OUT">  
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss} [%t] %-5level %logger{36} - %X{traceId} - %msg%n"/>  
        </Console>  
    </Appenders>  
    <Loggers>  
        <Root level="debug">  
            <AppenderRef ref="Console"/>  
        </Root>  
    </Loggers>  
</Configuration>

启动项目，发起任意请求，请求经过拦截器，我们就可以在日志中打印出traceId了，如下：

4. 在不同的服务间传递traceId

不管你是使用httpUtil还是restTemplate还是feign等工具调用其他系统服务，都可以在请求header中设置traceId，类似如下：

request.getHeaders().add(TraceIdUtil.HEADER_TRACE_ID, TraceIdUtil.getTraceId());

下游系统再如上所述进行日志改造即可达成链路！

5. 多线程时MDC的跨线程解决方案

聪明的你可能要问了，文中说MDC底层是threadLocal，如果请求的链路有环节使用了多线程，如果不进行特殊设置，是不是无法正常打印出traceId了，这时候该怎么解决呢？
我们一般直接使用spring提供的线程池类，即ThreadPoolTaskExecutor，对其进行改造，如下：
先自定义TaskDecorator类

package com.neo.config;
 
import org.slf4j.MDC;
import org.springframework.core.task.TaskDecorator;
 
import java.util.Map;
 
public class MdcTaskDecorator implements TaskDecorator {
    @Override
    public Runnable decorate(Runnable runnable) {
        // 获取主线程的MDC
        Map<String, String> copyOfContextMap = MDC.getCopyOfContextMap();
        return () -> {
            try {
                // 将主线程的MDC设置到子线程中
                if (copyOfContextMap != null) {
                    MDC.setContextMap(copyOfContextMap);
                }
                runnable.run();
            } finally {
                // 清除MDC
                MDC.clear();
            }
        };
    }
}

定义好spring的线程池配置类

package com.neo.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;
 
import java.util.concurrent.ThreadPoolExecutor;
 
@Configuration
@EnableAsync
public class ThreadPoolConfig {
 
    @Bean("taskExecutor")
    public ThreadPoolTaskExecutor taskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(10);
        executor.setMaxPoolSize(20);
        executor.setQueueCapacity(200);
        executor.setKeepAliveSeconds(60);
        executor.setThreadNamePrefix("taskExecutor-");
        executor.setWaitForTasksToCompleteOnShutdown(true);
        executor.setAwaitTerminationSeconds(60);
        executor.setTaskDecorator(new MdcTaskDecorator());
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        return executor;
    }
 
}

测试请求代码如下：

package com.neo.controller;
 
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;
import org.springframework.web.bind.annotation.*;
 
@RestController
public class HelloController {
 
    private static final Logger logger = LoggerFactory.getLogger(HelloController.class);
 
    @Autowired
    private ThreadPoolTaskExecutor taskExecutor;
 
    @GetMapping("/test")
    public String test() {
        logger.info("you can see traceId in log");
        // 使用自定义的线程池，模拟多线程
        for (int i = 0; i < 10; i++) {
            taskExecutor.execute(() -> {
                logger.info("this is a async task");
            });
        }
        return "success";
    }
 
}

原文链接：https://blog.csdn.net/zzs1067632338/article/details/141723736