SpringBoot MDC全局链路解决方案

需求

在访问量较大的分布式系统中，时时刻刻在打印着巨量的日志，当我们需要排查问题时，需要从巨量的日志信息中找到本次排查内容的日志是相对复杂的，那么，如何才能使日志看起来逻辑清晰呢？如果每一次请求都有一个全局唯一的id，当我们需要排查时，根据其他日志打印关键字定位到对应请求的全局唯一id，再根据id去搜索、筛选即可找到对应请求全流程的日志信息。接下来就是需要找一种方案，可以生成全局唯一id和在不同的线程中存储这个id。

解决方案

LogBack这个日志框架提供了MDC( Mapped Diagnostic Context，映射调试上下文 ) 这个功能，MDC可以理解为与线程绑定的数据存储器。数据可以被当前线程访问，当前线程的子线程会继承其父线程中MDC的内容。MDC 在 Spring Boot 中的作用是为日志事件提供上下文信息，并将其与特定的请求、线程或操作关联起来。通过使用 MDC，可以更好地理解和分析日志，并在多线程环境中确保日志的准确性和一致性。此外，MDC 还可以用于日志审计、故障排查和跟踪特定操作的执行路径。

代码

实现日志打印全局链路唯一id的功能，需要三个信息：

全局唯一ID生成器
请求拦截器
自定义线程池（可选）
日志配置

全局唯一ID生成器

生成器可选方案有：

UUID，快速随机生成、极小概率重复
Snowflake，有序递增
时间戳

雪花算法（Snowflake）更适用于需要自增的业务场景，如数据库主键、订单号、消息队列的消息ID等，时间戳一般是微秒级别，极限情况下，一微秒内可能同时多个请求进来导致重复。系统时钟回拨时，UUID可能会重复，但是一般不会出现该情况，因此UUID这种方案的缺点可以接受，本案例使用UUID方案。

/**
 * 全局链路id生成工具类
 *
 * @author Ltx
 * @version 1.0
 */
public class RequestIdUtil {

    public RequestIdUtil() {
    }

    public static void setRequestId() {
        //往MDC中存入UUID唯一标识
        MDC.put(Constant.TRACE_ID, UUID.randomUUID().toString());
    }

    public static void setRequestId(String requestId) {
        MDC.put(Constant.TRACE_ID, requestId);
    }

    public static String getRequestId() {
        return MDC.get(Constant.TRACE_ID);
    }

    public static void clear() {
        //需要释放，避免OOM
        MDC.clear();
    }
}

/**
 * Author:      liu_pc
 * Date:        2023/8/8
 * Description: 常量定义类
 * Version:     1.0
 */
public class Constant {

    /**
     * 全局唯一链路id
     */
    public final static String TRACE_ID = "traceId";
}

自定义全局唯一拦截器

Filter是Java Servlet 规范定义的一种过滤器接口，它的主要作用是在 Servlet 容器中对请求和响应进行拦截和处理，实现对请求和响应的预处理、后处理和转换等功能。通过实现 Filter 接口，开发人员可以自定义一些过滤器来实现各种功能，如身份验证、日志记录、字符编码转换、防止 XSS 攻击、防止 CSRF 攻击等。那么这里我们使用它对请求做MDC赋值处理。

@Component
public class RequestIdFilter implements Filter {
    @Override
    public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException{
        try {
            HttpServletRequest httpServletRequest = (HttpServletRequest) servletRequest;
            String requestId = httpServletRequest.getHeader("requestId");
            if (StringUtils.isBlank(requestId)) {
                RequestIdUtil.setRequestId();
            } else {
                RequestIdUtil.setRequestId(requestId);
            }

            // 继续将请求传递给下一个过滤器或目标资源（比如Controller）
            filterChain.doFilter(servletRequest, servletResponse);
        } finally {
            RequestIdUtil.clear();
        }
    }

    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
        Filter.super.init(filterConfig);
    }

    @Override
    public void destroy() {
        Filter.super.destroy();
    }
}

    /**
     * 测试MDC异步任务全局链路
     *
     * @param param 请求参数
     * @return new String Info
     */
    public String test(String param) {
        logger.info("测试MDC test 接口开始，请求参数:{}", param);
        String requestId = RequestIdUtil.getRequestId();
        logger.info("MDC RequestId :{}", requestId);
        return "hello";
    }

日志配置

输出到控制台:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <!-- 配置输出到控制台（可选输出到文件） -->
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <!-- 配置日志格式 -->
      <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %mdc %msg%n</pattern>
    </encoder>
  </appender>

  <!-- 配置根日志记录器 -->
  <root level="INFO">
    <appender-ref ref="CONSOLE"/>
  </root>

  <!-- 配置MDC -->
  <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator">
    <resetJUL>true</resetJUL>
  </contextListener>

  <!-- 配置MDC插件 -->
  <conversionRule conversionWord="%mdc" converterClass="org.springframework.boot.logging.logback.ExtendedWhitespaceThrowableProxyConverter"/>
</configuration>

输出到文件：

<configuration>
    <!-- 配置输出到文件 -->
    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
        <!-- 指定日志文件路径和文件名 -->
        <file>/Users/liu_pc/Documents/code/mdc_logback/logs/app.log</file>
        <encoder>
            <!-- 配置日志格式 -->
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %mdc %msg%n</pattern>
        </encoder>
    </appender>

    <!-- 配置根日志记录器 -->
    <root level="INFO">
        <appender-ref ref="FILE"/>
    </root>

    <!-- 其他配置... -->
</configuration>

功能实现。

子线程获取traceId问题

使用多线程时，子线程打印日志拿不到traceId。如果在子线程中获取traceId，那么就相当于往各自线程中的MDC赋值了traceId，会导致子线程traceId不一致的问题。

    public void wrongHelloAsync(String param) {
        logger.info("helloAsync 开始执行异步操作,请求参数:{}", param);
        List<Integer> simulateThreadList = new ArrayList<>(5);
        for (int i = 0; i <= 5; i++) {
            simulateThreadList.add(i);
        }
        for (Integer thread : simulateThreadList) {
            CompletableFuture.runAsync(() -> {
                //在子线程中赋值
                String requestId = RequestIdUtil.getRequestId();
                logger.info("子线程信息:{},traceId:{} ", thread, requestId);
            }, executor);
        }
    }
}

子线程获取traceId方案

使用子线程时，可以使用自定义线程池重写部分方法，在重写的方法中获取当前MDC数据副本，再将副本信息赋值给子线程的方案。

/**
 * Author:      liu_pc
 * Date:        2023/8/7
 * Description: 自定义异步线程池配置
 * Version:     1.0
 */
@Configuration
@EnableAsync
public class AsyncConfiguration implements AsyncConfigurer {
    private final Logger logger = LoggerFactory.getLogger(AsyncConfiguration.class);

    private final TaskExecutionProperties taskExecutionProperties;


    public AsyncConfiguration(TaskExecutionProperties taskExecutionProperties) {
        this.taskExecutionProperties = taskExecutionProperties;
    }

    @Override
    @Bean(name = "taskExecutor")
    public Executor initAsyncExecutor() {
        logger.debug("Creating Async Task Executor");
        ThreadPoolTaskExecutor executor = new MdcThreadPoolTaskExecutor();
        executor.setCorePoolSize(taskExecutionProperties.getPool().getCoreSize());
        executor.setMaxPoolSize(taskExecutionProperties.getPool().getMaxSize());
        executor.setQueueCapacity(taskExecutionProperties.getPool().getQueueCapacity());
        executor.setThreadNamePrefix(taskExecutionProperties.getThreadNamePrefix());
        return executor;
    }

    @Override
    public AsyncUncaughtExceptionHandler getAsyncUncaughtExceptionHandler() {
        return new SimpleAsyncUncaughtExceptionHandler();
    }
}

/**
 * Author:      liu_pc
 * Date:        2023/8/7
 * Description: 自定义携带MDC信息线程池
 * Version:     1.0
 */
public class MdcThreadPoolTaskExecutor extends ThreadPoolTaskExecutor {

    @Override
    public void execute(@Nonnull Runnable task) {
        Map<String, String> copyOfContextMap = MDC.getCopyOfContextMap();
        super.execute(
                () -> {
                    if (Objects.nonNull(copyOfContextMap)) {
                        String requestId = RequestIdUtil.getRequestId();
                        if (StringUtils.isBlank(requestId)) {
                            copyOfContextMap.put("traceId", UUID.randomUUID().toString());
                        }

                        //主线程MDC赋值子线程
                        MDC.setContextMap(copyOfContextMap);
                    } else {
                        RequestIdUtil.setRequestId();
                    }
                    try {
                        task.run();
                    } finally {
                        RequestIdUtil.clear();
                    }
                }
        );
    }
}

测试代码：

    /**
     * 测试MDC异步任务全局链路
     *
     * @param param 请求参数
     * @return new String Info
     */
    public String test(String param) {
        logger.info("测试MDC test 接口开始，请求参数:{}", param);
        String requestId = RequestIdUtil.getRequestId();
        logger.info("MDC RequestId :{}", requestId);
        helloAsyncService.helloAsync(param, requestId);
        return "hello";
    }

    /**
     * 使用异步数据测试打印日志
     *
     * @param param     请求参数
     * @param requestId 全局唯一id
     */
    @Async("taskExecutor")
    public void helloAsync(String param, String requestId) {
        logger.info("helloAsync 开始执行异步操作,请求参数:{}", param);
        List<Integer> simulateThreadList = new ArrayList<>(5);
        for (int i = 0; i <= 5; i++) {
            simulateThreadList.add(i);
        }
        for (Integer thread : simulateThreadList) {
            CompletableFuture.runAsync(() -> {
                //在子线程中赋值
                RequestIdUtil.setRequestId(requestId);
                logger.info("子线程信息:{},traceId:{} ", thread, requestId);
            }, executor);
        }
    }