Spring Boot 中使用 MDC 追踪一次请求全过程

2022-08-31 09:47:25

MDC 的全称是Mapped Diagnostic Context，映射诊断上下文(MDC)。本质上是由日志框架维护的映射，其中应用程序代码提供键-值对，然后日志框架可以在日志消息中插入这些键-值对。MDC数据在过滤消息或触发某些操作方面也非常有用。管理开销。

SLF4J支持MDC，即映射的诊断上下文。如果底层日志框架提供MDC功能，那么SLF4J将委托给底层框架的MDC。注意，此时，只有log4j和logback提供MDC功能。如果底层框架不提供MDC，例如java.util。日志记录后，SLF4J仍将存储MDC数据，但其中的信息需要通过自定义用户代码检索。

为了惟一地标记每个请求，用户将上下文信息放入MDC中，MDC是映射诊断上下文的缩写。MDC类的比较重要的部分方法如下所示：

package org.slf4j;

public class MDC {
  //Put a context value as identified by key
  //into the current thread's context map.
  public static void put(String key, String val);

  //Get the context identified by the key parameter.
  public static String get(String key);

  //Remove the context identified by the key parameter.
  public static void remove(String key);

  //Clear all entries in the MDC.
  public static void clear();
}

MDC 类只包含静态方法。它允许开发人员在诊断上下文中放置信息，这些信息随后可由某些回签组件检索。MDC 按每个线程管理上下文信息。通常，在开始为新的客户机请求提供服务时，开发人员将插入相关的上下文信息，如客户机id、客户机的IP地址、请求参数等到 MDC 中。如果配置得当，登录组件将自动在每个日志条目中包含此信息。

请注意，由logback-classic实现的 MDC 假设以中等频率将值放置到 MDC 中。还请注意，子线程不会自动继承其父线程映射的诊断上下文的副本。

1、MDC 的基本使用

下一个使用名为 SimpleMDC 的应用程序演示了这一基本原理。

package chapters.mdc;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

import ch.qos.logback.classic.PatternLayout;
import ch.qos.logback.core.ConsoleAppender;

public class SimpleMDC {
  static public void main(String[] args) throws Exception {

    // You can put values in the MDC at any time. Before anything else
    // we put the first name
    MDC.put("first", "Dorothy");

    [ SNIP ]
    
    Logger logger = LoggerFactory.getLogger(SimpleMDC.class);
    // We now put the last name
    MDC.put("last", "Parker");

    // The most beautiful two words in the English language according
    // to Dorothy Parker:
    logger.info("Check enclosed.");
    logger.debug("The most beautiful two words in English.");

    MDC.put("first", "Richard");
    MDC.put("last", "Nixon");
    logger.info("I am not a crook.");
    logger.info("Attributed to the former US president. 17 Nov 1973.");
  }

  [ SNIP ]

}

main 方法首先将 Dorothy 值与 MDC 中的键关联起来。您可以在 MDC 中放置任意多的值/键关联。具有相同键的多次插入将覆盖较旧的值。然后代码继续配置logback。

为了简洁起见，我们省略了用配置文件simpleMDC.xml配置logback的代码。下面是该文件的相关部分。

<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"> 
  <layout>
    <Pattern>%X{first} %X{last} - %m%n</Pattern>
  </layout> 
</appender>

注意在 PatternLayout 转换模式中使用了 %X 说明符。 %X 转换说明符被使用两次，一次用于第一个命名的键，一次用于最后一个命名的键。在获得与 SimpleMDC对应的日志程序之后。类中，代码将值Parker与名为last的键关联。然后，它使用不同的消息两次调用日志程序。代码最后将MDC设置为不同的值并发出几个日志记录请求。运行 SimpleMDC 会得到以下结果：

Dorothy Parker - Check enclosed.
Dorothy Parker - The most beautiful two words in English.
Richard Nixon - I am not a crook.
Richard Nixon - Attributed to the former US president. 17 Nov 1973.

上面我们介绍了 MDC 的基本使用方法，下面我们就将这个技术使用到项目当中。

2、MDC 记录一次 HTTP 请求

使用 Java 开发 Web 项目的时候我们就可以通过 MDC 跟踪 Java 应用程序一次请求完整的请求路径。我们的项目一般使用 Spring MVC，所以这里我就在请求 Controller 之前添加 MDC 值，然后在请求完成之后就把 MDC 清空。我想大家应该已经猜到了这里我会使用 Spring MVC 里面提供的拦截器HandlerInterceptor，当然使用 Filter 也是可以的。

2.1 WebLogMdcHandlerInterceptor

调用 通过HandlerInterceptor#preHandle 在调用 Controller 请求之前通过 UUID 生成唯一值。

public class WebLogMdcHandlerInterceptor extends HandlerInterceptorAdapter {

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        MDC.put("ctxLogId", UUID.randomUUID().toString());
        return true;
    }

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

    @Override
    public void afterConcurrentHandlingStarted(HttpServletRequest request,
                                               HttpServletResponse response, Object handler) throws Exception {
        preHandle(request, response, handler);
    }
}

2.2 WebMvcConfig

它是一个配置类，通过实现WebMvcConfigurer 与 注解@EnableWebMvc 把我们创建的WebLogMdcHandlerInterceptor 添加到 Spring 的容器当中。

@Configuration
@EnableWebMvc
public class WebMvcConfig implements WebMvcConfigurer {

	@Override
	public void addInterceptors(InterceptorRegistry registry) {
		// MDC
		WebLogMdcHandlerInterceptor mdcInterceptor = new WebLogMdcHandlerInterceptor();
		registry.addInterceptor(mdcInterceptor);
	}

}

2.3 日志打印格式

根据上面 MDC 中的基本使用规则，只需要通过%{ctxLogId}，然后就可以把添加到日志跟踪号添加到日志打印当中了。

[%d{yyyy-MM-dd HH:mm:ss:SSS}] [%-5level] [%t] [%X{ctxLogId}] [%c(%L)] %m%n

打印效果如下：
在这里插入图片描述
这样你就可以通过请求的业务 ID 查询到一条或者多条日志信息，然后就可得到这个 MDC 值。通过这个 MDC 值你就可以把一次请求的整个日志的整个链路串联起来。这样排查问题就比较容易一点。

3、MDC 记录一次 Dubbo 请求

因为 MDC 的请求是通过 Dubbo 调用，所以我们使用HandlerInterceptor 并不会拦截它的请求。在这里我们可以使用 Dubbo 框架中的Filter 拦截机制，把 MDC 添加到请求上下文当中。

3.1 ProviderMdcFilter

实现 Dubbo 提供的 Filter 机制，如果上游中传递过来了 MDC 值就使用上游传递过来的。否则就通过 UUID 自动生成一个添加到 MDC 当中。

publicclassProviderMdcFilterimplementsFilter{private Logger logger= LoggerFactory.getLogger(ProviderMdcFilter.class);@Overridepublic Resultinvoke(Invoker<?> invoker, Invocation invocation)throws RpcException{
        String logId= invocation.getAttachment("ctxLogId",);if(StringUtils.isBlank(logId)){
            logId= UUID.randomUUID().toString();
            logger.warn("ProviderLogTraceIdFilter MDC log Id is null, UUID generate log id : {}", logId);}
        MDC.put("ctxLogId",, logId);try{return invoker.invoke(invocation);}finally{
            MDC.clear();}}}

3.2 配置生效

要使得这个配置生效，首先需要把它添加到 dubbo 的容器里面。

  • 最开始在resources 目录下面创建META-INF.duboo 目录
  • 然后在该目录下面创建文件名为org.apache.dubbo.rpc.Filter
  • 最后在 Filter 文件中添加一个key = Filter 类全名 这种格式的值
-- resources-- META-INF.dubbo-- org.apache.dubbo.rpc.Filter

providerLoggerFilter=com.fintech.test.interceptor.ProviderMdcFilter

然后在 dubbo 配置文件当中添加以下代码就可以了。

dubbo.provider.filter=providerLoggerFilter

4、线程池打印 MDC

在我们项目中往往需要定时任务完成一些业务逻辑，而执行定时任务的时候往往是使用异步执行的。但是MDC 是通过ThreadLocal 执行的，所以普通方法我们行不通。下面我就分享一下我在项目当中是如何实现的。

在这里面我借鉴了一下 Spring 事务处理是通过模板方式来处理的，也就是TransactionTemplate.

4.1 TaskLogIdTemplate

因为定时任务是查询出来多个结果，然后遍历结果传递到这个模板类当中。在这个模板类当中封装了定时任务异步执行的逻辑，并且每个需要执行的业务都可以自定义的传递上下文日志 ID 到模板类当中。

@Slf4j@Service("taskLogIdTemplate")publicclassTaskLogIdTemplate{@Resource(name="taskThreadPoolExecutor")private ThreadPoolTaskExecutor taskThreadPoolExecutor;publicvoidexecute(String ctxLogId, TaskLogIdCallback action){
        taskThreadPoolExecutor.execute(()->{
            MDC.put(CommonConstants.CTX_LOG_ID_MDC, ctxLogId);try{
                action.doInExecute();}catch(Exception e){
                log.error("TaskLogIdTemplate#execute is error", e);}finally{
                MDC.clear();}});}}

4.2 TaskLogIdCallback

定时任务回调类，因为定时任务不需要返回值，所以就没有像事务处理一样定义返回值。

@FunctionalInterfacepublicinterfaceTaskLogIdCallback{/**
     * 定时任务回调
     * @return
     */voiddoInExecute();}

4.3 TaskServiceImpl

以下就是模拟订单完成的定时任务，这里我是通过订单号加上方法名来做为唯一的 MDC 值的。

publicvoidfinishOrder(){
	List<Order> orders=queryObject(startTime, endTime);if(CollectionUtils.isEmpty(orders)){return;}for(Order order: orders){
	    String contextLogId=getContextLogId(order, methodName);
	    taskLogIdTemplate.execute(contextLogId,()-> taskService.finishOrder(order));}}private StringgetContextLogId(Order order, String methodName){return order.getOrderNo+":"+ methodName;}
  • 作者：carl-zhao
  • 原文链接：https://carlzone.blog.csdn.net/article/details/109406093
    更新时间：2022-08-31 09:47:25