Spring Boot - 利用MDC（Mapped Diagnostic Context）实现轻量级同步/异步日志追踪

文章目录

Pre
什么是MDC（Mapped Diagnostic Context）
Slf4j 和 MDC
基础工程
- 工程结构
- POM
- logback-spring.xml
- application.yml
- 同步方式
- - 方式一：拦截器
  - - 自定义日志拦截器
    - 添加拦截器
  - 方式二：自定义注解 + AOP
  - - 自定义注解 TraceLog
    - 切面
  - 测试
- 异步支持
- - 线程池配置类
  - 自定义线程池任务执行器
  - 线程MDC工具类
  - 模拟业务类@Async
  - 测试
小结

在这里插入图片描述

Pre

每日一博 - ThreadLocal VS InheritableThreadLocal VS TransmittableThreadLocal

什么是MDC（Mapped Diagnostic Context）

MDC（Mapped Diagnostic Context）是一个在日志框架中常用的概念，主要用于在多线程环境中关联和传递一些上下文信息，以便在日志输出中包含这些信息，从而实现更好的日志记录和调试。

在Java中，常见的日志框架如Log4j、Logback和Log4j2都提供了对MDC的支持。

MDC的主要特点包括：

线程绑定的上下文信息： MDC允许在多线程环境中将上下文信息与线程相关联。可以在应用程序的不同部分设置一些上下文信息，并确保在同一线程中的后续日志记录中能够访问到这些信息。
适用于跟踪请求或会话： MDC特别适用于跟踪请求或会话相关的信息，如请求ID、会话ID等。通过在请求开始时设置这些信息，并在请求结束时清理它们，可以确保在整个请求处理过程中，日志都包含了相同的上下文信息，方便排查问题。
日志格式化支持： MDC的值可以通过特殊的占位符在日志输出格式中引用。这样，在日志输出时，可以直接将MDC中的值包含在日志中，从而让日志更具可读性和可跟踪性。
避免参数传递的复杂性： 使用MDC可以避免在方法调用链中手动传递上下文信息的复杂性。相反，可以在适当的地方将信息设置到MDC中，在日志输出时框架会自动将这些信息包含在日志中。

简而言之，MDC是一个非常有用的工具，可以帮助开发人员在日志中记录和跟踪关键的上下文信息，提高了调试和排查问题的效率。

Slf4j 和 MDC

在这里插入图片描述

**SLF4J（Simple Logging Facade for Java）**是一个日志门面框架，它提供了一种简单的方式来访问各种日志系统，例如Log4j、Logback、java.util.logging等。SLF4J本身并不是一个日志实现，而是提供了统一的接口，开发人员可以通过它来编写日志代码，而不用关心底层日志系统的具体实现。

**MDC（Mapped Diagnostic Context）**是SLF4J的一个功能，用于在日志输出中关联和传递上下文信息。MDC允许开发人员在代码中设置一些上下文信息，例如请求ID、用户ID等，然后在日志输出时将这些信息包含在日志中，以便于跟踪和调试。

SLF4J和MDC之间的关系可以总结如下：

SLF4J提供了MDC的接口： SLF4J允许开发人员通过其API来使用MDC功能。它提供了一些方法，例如MDC.put(key, value)用于设置上下文信息，MDC.get(key)用于获取上下文信息等。
MDC依赖于底层的日志实现： 虽然MDC是SLF4J提供的功能，但其实现是依赖于底层的日志实现的。不同的日志实现，如Logback、Log4j等，都有自己的MDC实现。因此，开发人员需要确保在使用MDC时，底层的日志实现已经正确配置。
MDC提供了与SLF4J日志框架的集成： MDC的设计目的之一是与SLF4J的日志框架集成得很好。这意味着开发人员可以在使用SLF4J编写的日志代码中，轻松地使用MDC功能，从而在日志中记录和跟踪上下文信息。

SLF4J和MDC是紧密相关的，MDC是SLF4J的一个功能，用于在日志输出中传递上下文信息，而SLF4J提供了使用MDC功能的接口。这使得在使用SLF4J编写的日志代码中，可以方便地利用MDC来增强日志的可读性和可追踪性。

基础工程

工程结构

在这里插入图片描述

POM

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
	xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
	<modelVersion>4.0.0</modelVersion>
	<parent>
		<artifactId>boot2</artifactId>
		<groupId>com.artisan</groupId>
		<version>0.0.1-SNAPSHOT</version>
	</parent>

	<groupId>com.artisan</groupId>
	<artifactId>boot-trace</artifactId>
	<version>0.0.1-SNAPSHOT</version>
	<name>boot-trace</name>
	<description>boot-trace</description>

	<properties>
		<java.version>8</java.version>
	</properties>
	<dependencies>

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


		<dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-aop</artifactId>
		</dependency>

		<dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-web</artifactId>
		</dependency>
		<dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-test</artifactId>
			<scope>test</scope>
		</dependency>
		<dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-logging</artifactId>
		</dependency>
		<!--lombok配置-->
		<dependency>
			<groupId>org.projectlombok</groupId>
			<artifactId>lombok</artifactId>
		</dependency>

		<!-- ULID-->
		<dependency>
			<groupId>com.github.f4b6a3</groupId>
			<artifactId>ulid-creator</artifactId>
			<version>5.1.0</version>
		</dependency>
		<dependency>
			<groupId>de.huxhorn.sulky</groupId>
			<artifactId>de.huxhorn.sulky.ulid</artifactId>
			<version>8.3.0</version>
		</dependency>


	</dependencies>

	<build>
		<plugins>
			<plugin>
				<groupId>org.springframework.boot</groupId>
				<artifactId>spring-boot-maven-plugin</artifactId>
			</plugin>
		</plugins>
	</build>

</project>

logback-spring.xml

使用SLF4J门面是一个很好的实践，特别是在与logback等日志实现框架集成时。SLF4J提供了一个统一的接口，使得应用代码与具体的日志实现解耦，从而可以轻松地切换和替换底层的日志实现，而无需修改应用代码。

通过使用SLF4J门面，可以在应用程序中使用SLF4J的API编写日志代码，例如Logger接口中的方法，而不用关心底层的日志实现是logback、Log4j还是其他日志框架。这使得代码更具灵活性和可维护性，可以根据需要随时替换底层的日志实现，而不会影响应用程序的其他部分。

对于大多数Java项目来说，使用SLF4J门面和logback作为底层的日志实现是一个非常常见的选择。这样做不仅提供了对日志功能的灵活控制，还能够保持与标准的Java日志习惯的兼容性。同时，SLF4J和logback之间的集成也非常完善，可以充分发挥它们之间的协作优势。

这里我们使用logback ，其他日志组件均可无缝替换。

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false">
    <!--日志存储路径-->
    <property name="log" value="D:/log" />
    <!-- 控制台输出 -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <!--输出格式化-->
            <pattern>[%X{TRACE_ID}]  %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50}[%10method,%line] - %msg%n</pattern>
        </encoder>
    </appender>
    <!-- 按天生成日志文件 -->
    <appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--日志文件名-->
            <FileNamePattern>${log}/%d{yyyy-MM-dd}.log</FileNamePattern>
            <!--保留天数-->
            <MaxHistory>30</MaxHistory>
        </rollingPolicy>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>[%X{TRACE_ID}]  %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
        </encoder>
        <!--日志文件最大的大小-->
        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>10MB</MaxFileSize>
        </triggeringPolicy>
    </appender>

    <!-- 日志输出级别 -->
    <root level="INFO">
        <appender-ref ref="console" />
        <appender-ref ref="file" />
    </root>
</configuration>

application.yml

server:
  port: 9999
logging:
  config: classpath:logback-spring.xml

同步方式

方式一：拦截器

自定义日志拦截器

package com.artisan.boottrace.interceptor;

import com.artisan.boottrace.utils.TraceIdGenerator;
import org.slf4j.MDC;
import org.springframework.lang.Nullable;
import org.springframework.util.StringUtils;
import org.springframework.web.servlet.HandlerInterceptor;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

/**
 * @author 小工匠
 * @version 1.0
 * @mark: show me the code , change the world
 * <p>
 * MDC(Mapped Diagnostic Context)诊断上下文映射，是@Slf4j提供的一个支持动态打印日志信息的工具
 */
public class TraceLogInterceptor implements HandlerInterceptor {

    // 追踪ID在MDC中的键名
    private static final String TRACE_ID = "TRACE_ID";

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        // 生成追踪ID，如果客户端传入了追踪ID，则使用客户端传入的追踪ID，否则使用默认的ULID生成
        String tid = TraceIdGenerator.ulid();
        if (StringUtils.hasLength(request.getHeader(TRACE_ID))) {
            tid = request.getHeader(TRACE_ID);
        }
        // 将追踪ID放入MDC中
        MDC.put(TRACE_ID, tid);
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler,
                                @Nullable Exception ex) {
        // 请求处理完成后，从MDC中移除追踪ID
        MDC.remove(TRACE_ID);
    }
}

在请求处理前后设置和清理MDC中的追踪ID的请求追踪日志拦截器。

在preHandle方法中，它从请求头中获取追踪ID，如果不存在则使用默认的ULID生成器生成一个新的追踪ID，并将其放入MDC中。
在afterCompletion方法中，它简单地移除MDC中的追踪ID，以确保不影响后续请求的日志记录。

添加拦截器

package com.artisan.boottrace.interceptor;

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

/**
 * @author 小工匠
 * @version 1.0
 * @mark: show me the code , change the world
 */
@Configuration
public class WebConfigurerAdapter implements WebMvcConfigurer {

    /**
     * 注册TraceLogInterceptor拦截器
     */
    @Bean
    public TraceLogInterceptor logInterceptor() {
        return new TraceLogInterceptor();
    }

    /**
     * 添加拦截器到拦截器链
     */
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(logInterceptor());
        // 可以具体指定哪些需要拦截，哪些不拦截，其实也可以使用自定义注解更灵活完成
        // .addPathPatterns("/**")
        // .excludePathPatterns("/xxx.yyy");
    }
}

这个配置类是WebMvcConfigurer接口的实现类，用于配置拦截器。它注册了TraceLogInterceptor拦截器，并将其添加到拦截器链中。

可以通过addInterceptors方法来指定哪些请求需要被拦截，哪些请求不需要被拦截。通过这种方式，可以灵活地控制拦截器的应用范围，以满足不同的业务需求.

方式二：自定义注解 + AOP

自定义注解 TraceLog

package com.artisan.boottrace.annotations;

import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;

/**
 * @author artisan
 */
@Target({ElementType.METHOD, ElementType.TYPE})
@Retention(RetentionPolicy.RUNTIME)
public @interface TraceLog {
}

切面

package com.artisan.boottrace.aspect;

import com.artisan.boottrace.utils.TraceIdGenerator;
import org.aspectj.lang.annotation.After;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;

/**
 * @author 小工匠
 * @version 1.0
 * @mark: show me the code , change the world
 */

@Aspect
@Component
public class TraceLogAspect {

    private static final String TRACE_ID = "TRACE_ID";

    @Before("@annotation(com.artisan.boottrace.annotations.TraceLog)")
    public void beforeMethodExecution() {
        String tid = TraceIdGenerator.ulid();
        MDC.put(TRACE_ID, tid);
    }

    @After("@annotation(com.artisan.boottrace.annotations.TraceLog)")
    public void afterMethodExecution() {
        MDC.remove(TRACE_ID);
    }
}

测试

拦截器方式

package com.artisan.boottrace.controller;

import com.artisan.boottrace.service.IArtisanService;
import lombok.extern.slf4j.Slf4j;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;

/**
 * @author 小工匠
 * @version 1.0
 * @mark: show me the code , change the world
 */

@Slf4j
@RestController
public class ArtisanTestController {

    @Autowired
    private IArtisanService artisanService;

    @GetMapping("/testTrace")
    public String testTrace(@RequestParam("name") String name) throws InterruptedException {
        log.info("testTrace  name={}", name);
        doSomething1();
        // 异步任务
        // artisanService.addArtisan();
        log.info("testTrace Call Over name={}", name);
        return "Hello," + name;
    }

    private void doSomething1() {
        log.info("doSomething1  info  log");
        doSomething2();
        log.error("doSomething1 error log");
    }

    private void doSomething2() {
        log.info("doSomething2  info log");

    }
}

启动应用，访问：http://127.0.0.1:9999/testTrace?name=artisan

在这里插入图片描述

验证 AOP的方式

在这里插入图片描述

	@TraceLog
    @GetMapping("/testTrace2")
    public String testTraceByAnno(@RequestParam("name") String name) throws InterruptedException {
        log.info("======================");
        log.info("testTraceByAnno  name={}", name);
        doSomething1(); 
        log.info("testTraceByAnno Call Over name={}", name);
        return "Hello," + name;
    }

在这里插入图片描述

异步支持

日常开发中，异步处理必不可少，我们来看看如何实现一个轻量的异步日志追踪吧。

思路：将父线程的trackId传递下去给子线程

线程池配置类

package com.artisan.boottrace.config;

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

import java.util.concurrent.Executor;

/**
 * @author 小工匠
 * @version 1.0
 * @mark: show me the code , change the world
 * <p>
 * 线程池配置类，用于配置异步任务执行器
 */
@Configuration
@EnableAsync
public class ThreadPoolConfig {
    /**
     * 声明一个线程池
     *
     * @return 执行器
     */
    @Bean("ArtisanExecutor")
    public Executor asyncExecutor() {
        final int cpuSize = Runtime.getRuntime().availableProcessors();
        ArtisanThreadPoolTaskExecutor executor = new ArtisanThreadPoolTaskExecutor();
        executor.setCorePoolSize(cpuSize);
        executor.setMaxPoolSize(2 * cpuSize);
        executor.setQueueCapacity(500);
        executor.setKeepAliveSeconds(60);
        executor.setThreadNamePrefix("asyncArtisan-");
        executor.initialize();
        return executor;
    }
}

用于配置异步任务执行器，声明了一个名为"ArtisanExecutor"的Bean，返回一个自定义的ArtisanThreadPoolTaskExecutor执行器实例。在这个执行器中，配置了线程池的各种参数，如核心线程数、最大线程数、队列容量等。这样就创建了一个具有自定义配置的线程池执行器，用于执行异步任务。

自定义线程池任务执行器

package com.artisan.boottrace.config;

import com.artisan.boottrace.utils.ThreadMdcUtil;
import org.slf4j.MDC;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

import java.util.concurrent.Callable;
import java.util.concurrent.Future;

/**
 * @author 小工匠
 * @version 1.0
 * @mark: show me the code , change the world
 * <p>
 * 自定义线程池任务执行器，用于在任务执行时传递父线程的MDC上下文信息到子线程中。
 */
public class ArtisanThreadPoolTaskExecutor extends ThreadPoolTaskExecutor {
    public ArtisanThreadPoolTaskExecutor() {
        super();
    }

    /**
     * 执行任务，传递父线程的MDC上下文信息到子线程中
     */
    @Override
    public void execute(Runnable task) {
        super.execute(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
    }

    /**
     * 提交带有返回值的任务，传递父线程的MDC上下文信息到子线程中
     */
    @Override
    public <T> Future<T> submit(Callable<T> task) {
        return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
    }

    /**
     * 提交无返回值的任务，传递父线程的MDC上下文信息到子线程中
     */
    @Override
    public Future<?> submit(Runnable task) {
        return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
    }
}

继承自Spring的ThreadPoolTaskExecutor，在执行任务时使用了ThreadMdcUtil工具类来传递父线程的MDC上下文信息到子线程中。通过这种方式，可以确保异步任务在执行过程中能够访问到父线程的MDC上下文信息，从而实现了日志的跟踪。

线程MDC工具类

package com.artisan.boottrace.utils;

import org.slf4j.MDC;

import java.util.Map;
import java.util.concurrent.Callable;

/**
 * @author 小工匠
 * @version 1.0
 * @mark: show me the code , change the world
 * <p>
 * 线程MDC工具类，用于在多线程环境中传递MDC上下文信息
 */
public class ThreadMdcUtil {

    private static final String TRACE_ID = "TRACE_ID";

    /**
     * 生成唯一的追踪ID
     */
    public static String generateTraceId() {
        return TraceIdGenerator.ulid();
    }

    /**
     * 如果当前MDC中不存在追踪ID，则设置追踪ID
     */
    public static void setTraceIdIfAbsent() {
        if (MDC.get(TRACE_ID) == null) {
            MDC.put(TRACE_ID, generateTraceId());
        }
    }

    /**
     * 用于在父线程向线程池中提交任务时，将父线程的MDC上下文信息复制给子线程
     *
     * @param callable 要执行的任务
     * @param context  父线程的MDC上下文信息
     * @param <T>      任务返回类型
     * @return 复制了父线程MDC上下文信息的任务
     */
    public static <T> Callable<T> wrap(final Callable<T> callable, final Map<String, String> context) {
        return () -> {
            if (context == null) {
                MDC.clear();
            } else {
                MDC.setContextMap(context);
            }
            setTraceIdIfAbsent();
            try {
                return callable.call();
            } finally {
                MDC.clear();
            }
        };
    }

    /**
     * 用于在父线程向线程池中提交任务时，将父线程的MDC上下文信息复制给子线程
     *
     * @param runnable 要执行的任务
     * @param context  父线程的MDC上下文信息
     * @return 复制了父线程MDC上下文信息的任务
     */
    public static Runnable wrap(final Runnable runnable, final Map<String, String> context) {
        return () -> {
            if (context == null) {
                MDC.clear();
            } else {
                MDC.setContextMap(context);
            }
            setTraceIdIfAbsent();
            try {
                runnable.run();
            } finally {
                MDC.clear();
            }
        };
    }
}

在多线程环境中传递MDC上下文信息。提供了两个静态方法wrap，用于在父线程向线程池中提交任务时，将父线程的MDC上下文信息复制给子线程。这样可以确保在异步任务中也能够访问到父线程设置的MDC上下文信息，实现了日志的跟踪。

模拟业务类@Async

package com.artisan.boottrace.service;

import lombok.extern.slf4j.Slf4j;
import org.springframework.scheduling.annotation.Async;
import org.springframework.stereotype.Service;

import java.util.concurrent.TimeUnit;

/**
 * @author 小工匠
 * @version 1.0
 * @mark: show me the code , change the world
 */
@Slf4j
@Service
public class ArtisanService implements IArtisanService {

    @Async("ArtisanExecutor")
    @Override
    public void addArtisan() throws InterruptedException {
        TimeUnit.SECONDS.sleep(1);
        log.info("线程名称： {} ,执行方式：Async ---->  addArtisan ", Thread.currentThread().getName());
    }


}

测试

package com.artisan.boottrace.controller;

import com.artisan.boottrace.annotations.TraceLog;
import com.artisan.boottrace.service.IArtisanService;
import lombok.extern.slf4j.Slf4j;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;

/**
 * @author 小工匠
 * @version 1.0
 * @mark: show me the code , change the world
 */

@Slf4j
@RestController
public class ArtisanTestController {

    @Autowired
    private IArtisanService artisanService;

    @GetMapping("/testTrace")
    public String testTrace(@RequestParam("name") String name) throws InterruptedException {
        log.info("testTrace  name={}", name);
        doSomething1();
        // 异步任务
         artisanService.addArtisan();
        log.info("testTrace Call Over name={}", name);
        return "Hello," + name;
    }

    private void doSomething1() {
        log.info("doSomething1  info  log");
        doSomething2();
        log.error("doSomething1 error log");
    }

    private void doSomething2() {
        log.info("doSomething2  info log");
    }


    @TraceLog
    @GetMapping("/testTrace2")
    public String testTraceByAnno(@RequestParam("name") String name) throws InterruptedException {
        log.info("======================");
        log.info("testTraceByAnno  name={}", name);
        doSomething1();
        // 异步任务
        artisanService.addArtisan();
        log.info("testTraceByAnno Call Over name={}", name);
        return "Hello," + name;
    }


}