Spring Boot + MDC 实现全链路调用日志跟踪

Posted 2025-03-7 Updated 2025-03- 7

By lin

51~66 min read

前言

日志追踪是一种追踪请求在系统中流转过程的技术，可以帮助我们定位问题、分析性能瓶颈以及进行故障排查。但在多线程环境中，若没有相关框架的支持，想要实现日志追踪，就需要编码实现将主线程的日志参数传递给子线程，本文就在线程池场景下借助 MDC 实现了 traceId 参数的透传。

`MDC` 介绍

MDC（Mapped Diagnostic Context，映射调试上下文）是 log4j 和 logback 提供的一种方便在多线程条件下记录日志的功能。MDC 可以看成是一个与当前线程绑定的哈希表，可以往其中添加键值对。MDC 中包含的内容可以被同一线程中执行的代码所访问。当需要记录日志信息时，只需要从 MDC 中获取所需的信息即可。MDC 的内容由程序在适当的时候保存进去，对于 Web 应用来说，通常在请求被处理的最开始保存这些信息（如通过拦截器将 traceId 写入 MDC）。

1. Api 使用

clear() ：移除所有 MDC
get (String key) ：获取当前线程 MDC 中指定 key 的值
getContext() ：获取当前线程 MDC 的 MDC
put(String key, Object o) ：往当前线程的 MDC 中存入指定的键值对
remove(String key) ：删除当前线程 MDC 中指定的键值对

2. 依赖坐标

以 Log4j2 为例

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-log4j2</artifactId>
    <version>2.7.1</version>
</dependency>

`MDC` 使用

在 web 请求开始处理的时候，利用 Srping 提供的拦截器将 traceId 写入到 MDC 中。

1. 添加拦截器

public class MDCInterceptor implements HandlerInterceptor {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        this.setTraceId(request);
        return true;
    }

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

    private void setTraceId(HttpServletRequest request) {
        String traceId = request.getHeader(MDCUtil.TRACE_ID);
        if (StringUtils.isBlank(traceId)) MDCUtil.setTraceIdIfAbsent();
        else MDC.put(MDCUtil.TRACE_ID, traceId);
    }
}

2. 注册拦截器

@Slf4j
@Configuration
public class InterceptorConfig implements WebMvcConfigurer {

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        log.info("[注册拦截器] MDCInterceptor");
        registry.addInterceptor(new MDCInterceptor());}
}

3. 修改日志配置

核心配置，注意 %X{TRACE_ID} 中的 TRACE_ID 需要和放入 MDC 的 key 相同。

<PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss}][%p][%X{TRACE_ID}][%t][%c.%M] %m%n"/>

完整示例：log4j2-spring.xml

<?xml version="1.0" encoding="UTF-8"?>
<!--
    status : 这个用于设置 log4j2 自身内部的信息输出, 可以不设置, 当设置成 trace 时, 会看到 log4j2 内部各种详细输出
    monitorInterval : Log4j 能够自动检测修改配置文件和重新配置本身, 设置间隔秒数。
-->
<Configuration status="INFO" monitorInterval="30">
    <Properties>
        <Property name="log-directory" value="./logs"/>
        <Property name="history-log-directory" value="./logs/history"/>
        <Property name="split-size">100MB</Property>
        <Property name="file-age">7d</Property>
        <Property name="trace-id">TRACE_ID</Property>
    </Properties>
    <Appenders>
        <!-- 这个输出控制台的配置 -->
        <Console name="Console" target="SYSTEM_OUT">
            <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
            <!-- 输出日志的格式 -->
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss}][%p][%X{TRACE_ID}][%t][%c] %m%n"/>
        </Console>

        <!-- 这个会打印出所有的 info 及以下级别的信息，每次大小超过 size，则这 size 大小的日志会自动存入按年份 - 月份建立的文件夹下面并进行压缩，作为存档 -->
        <RollingFile name="RollingFileInfo" fileName="${log-directory}/trace.log"
                     filePattern="${history-log-directory}/trace-%d{yyyy-MM-dd}-%i.log.gz">
            <!-- 控制台只输出 level 及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
            <ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss}][%p][%X{TRACE_ID}][%t][%c.%M] %m%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <!-- 不是日志文件的最大保存数目，而是和 filePattern 中的 %i 有关 -->
                <SizeBasedTriggeringPolicy size="${split-size}"/>
            </Policies>
        </RollingFile>

        <RollingFile name="RollingFileError" fileName="${log-directory}/error.log"
                     filePattern="${history-log-directory}/error-%d{yyyy-MM-dd}-%i.log.gz">
            <ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
            <PatternLayout pattern="[%d{yyyy-MM-dd HH:mm:ss}][%p][%X{TRACE_ID}][%t][%c.%M] %m%n"/>
            <!-- 日志文件切分策略 -->
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="${split-size}"/>
            </Policies>
            <!-- 默认日志滚动策略 -->
            <DefaultRolloverStrategy>
                <Delete basePath="${log-directory}" maxDepth="2">
                    <IfFileName glob="*/trace-*.log.gz"/>
                    <IfLastModified age="${file-age}"/>
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>
    </Appenders>
    <!-- 然后定义 logger，只有定义了 logger 并引入的 appender，appender 才会生效 -->
    <Loggers>
        <!-- 过滤掉 spring 和 mybatis 的一些无用的 DEBUG 信息 -->
        <logger name="org.springframework" level="INFO"/>
        <logger name="org.mybatis" level="INFO"/>
        <root level="all">
            <appender-ref ref="Console"/>
            <appender-ref ref="RollingFileInfo"/>
            <appender-ref ref="RollingFileError"/>
        </root>
    </Loggers>
</Configuration>

多线程间使用

1. `MDC` 线程工具类

自定义 MDC 工具类，支持 Runnable 和 Callable 两种，目的就是为了把父线程的 traceId 设置给子线程

public class MDCUtil {
    public static final String TRACE_ID = "TRACE_ID";

     public static <T> Callable<T> wrap(final Callable<T> callable, final Map<String,String> context){
         return ()-> {MDCUtil.setCurThreadMDCContextIfAbsent(context);
             try {
                 return callable.call();} finally {MDC.clear();
             }
         };
     }

     public static Runnable wrap(final Runnable runnable, final Map<String, String> context){
         return ()-> {MDCUtil.setCurThreadMDCContextIfAbsent(context);
             try {runnable.run();
             } finally {MDC.clear();
             }
         };
     }

    public static void setTraceIdIfAbsent() {
        if (MDC.get(TRACE_ID) == null){MDC.put(TRACE_ID, MDCUtil.getTraceId());
        }
    }

    public static String getTraceId() {
        return UUID.randomUUID().toString().replace("-", "");}

    public static void setCurThreadMDCContextIfAbsent(final Map<String, String> context){
        if (CollectionUtils.isEmpty(context)) MDC.clear();
        else MDC.setContextMap(context);
        MDCUtil.setTraceIdIfAbsent();}

}

2. 线程池装饰器

通过 org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor 提供的线程装饰器 (TaskDecorator)，在执行线程的时候，将当前线程的 MDC 信息信息传递给子线程，实现父子线程之间的 MDC 传递

@Configuration
public class CommonThreadTaskExecutorConfig {

    public static final String COMMON_THREAD_TASK_EXECUTOR_NAME = "common_thread_task_executor";
    private static final int CORE_POOL_SIZE = 4;
    private static final int MAX_POOL_SIZE = 8;
    private static final int KEEP_ALIVE_SECONDS = 30;
    private static final int QUEUE_CAPACITY = 1024;
    private final AtomicLong atomicLong = new AtomicLong(0);

    @Bean(name = COMMON_THREAD_TASK_EXECUTOR_NAME)
    public ThreadPoolTaskExecutor commonThreadTaskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(CORE_POOL_SIZE);
        executor.setMaxPoolSize(MAX_POOL_SIZE);
        executor.setKeepAliveSeconds(KEEP_ALIVE_SECONDS);
        executor.setQueueCapacity(QUEUE_CAPACITY);
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        // 装饰器
        executor.setTaskDecorator(runnable -> MDCUtil.wrap(runnable, MDC.getCopyOfContextMap()));
        executor.setThreadNamePrefix(COMMON_THREAD_TASK_EXECUTOR_NAME);
        executor.initialize();
        return executor;
    }
}

3. 测试样例

@RestController
@Slf4j
public class TestController {
    @Autowired
    @Qualifier(CommonThreadTaskExecutorConfig.COMMON_THREAD_TASK_EXECUTOR_NAME)
    private ThreadPoolTaskExecutor executor;

    @RequestMapping(value = "about")
    @ResponseBody
    public Map<String,String> about(@RequestHeader(value = MDCUtil.TRACE_ID, required = false)String traceId) throws InterruptedException {
        Map<String, String> res = new HashMap<>();
        log.info("RequestHeader TRACE_ID {}", traceId);
        res.put(MDCUtil.TRACE_ID,traceId);
        log.info("MDC: {}", MDC.getCopyOfContextMap());
        log.info("打印日志，开始测试");
        for (int i = 0; i < 100; i++){executor.submit(() -> log.info("子线程打印日志，时间: {}", System.currentTimeMillis()));}
        Thread.sleep(3000);
        log.info("打印日志，结束测试");
        res.put("version","1.1");
        return res;
    }
}

后记：http 调用过程中可能会存在 traceId 丢失的情况，解决方法是将 traceId 放到请求头中，至于如何优雅的实现，待完善

License: CC BY 4.0

前言

MDC 介绍