如何利用MDC快速查询应用接口全部执行日志

对于每一个开发者来说，查询接口的执行日志都是一个高频率的操作，每当测试说接口有问题时，我们都需要去服务器或者日志系统上查报错的原因。

一般情况下，我们会通过对应的关键字或者接口地址去查询这个接口到底报了什么错，但是这带来一个问题，就是我们可能少打日志或者忘打某些关键字的日志，导致查询记录比较麻烦。

那么有没有一种简单高效的方法，即使我们在日志中不打印任何关键字，系统会自动生成一个关键字，让我们一次性查询出这个接口的所有log记录呢？

MDC

MDC是日志门面框架SLF4J提供的一个类，可以提供在多线程情况下记录日志的功能，log4j、logback、log4j2都有对这个类的实现。

从本质上来说，MDC可以看做一个ThreadLocal，由于其线程安全的特性，可以让我们轻松安全的保存数据。

MDC主要的API有clear()、get()、put()、remove()方法等，简洁的api让我们使用上手基本没有难度。

如何使用

1，修改日志打印格式

以日志框架logback为例，在logback.xml中，找到日志打印规则的配置，添加**-%X{reqId}** 属性，其中reqId可以任意指定，你写其他的属性也可以，博主这里演示指定为reqId。

<encoder>
  <pattern>-%X{reqId} %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %file:%line %msg%n</pattern>
  <charset>UTF-8</charset>
</encoder>

2，添加过滤器MDCFilter

ps.使用拦截器也可以，效果是一样的。对每个接口做拦截。

@Component
@AllArgsConstructor
@Order(Ordered.HIGHEST_PRECEDENCE)
@Slf4j
public class MDCFilter implements Filter {


    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
    }

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) {
        try {
            //给每个请求接口生成一个requestId
            String requestId = RandomUtil.randomNumbers(10);
            //这里的reqId就是上面配置的，要保持一致
            MDC.put("reqId", "reqId:" + requestId);
            chain.doFilter(request, response);
        } finally {
            MDC.clear();
        }
    }

    @Override
    public void destroy() {
    }
}

经过简单的两步就配置好了，下面我们看一下效果。

@PostMapping(value = "/mdcTest")
public ResponseEntity<Object> mdcTest(String id, String name) {
    log.info("测试日志打印,id={},name={}", id, name);
    log.info("测试日志打印1");
    log.info("测试日志打印2");
    log.info("测试日志打印3");
    log.info("测试日志打印4");
    return ResponseEntity.ok().build();
}

每一行日志都有一个关键字reqId:9723829830，这样我们查询日志时只需要查询关键字9723829830就可以直接查出来这个接口所有的执行记录了。

如果想更方便的话，也可以把这个关键字直接输出到每一个接口的响应头或者响应体中。

进阶使用

对于普通的web应用我们可以直接拦截每个接口，自动生成一个请求id，那么对于微服务项目，一个接口可能会产生很多服务的调用，那如何一次性查出来所有系统内的日志呢？

对于日志的搜集本文暂不考虑，咱们先说如何做请求id的传递。

其实也很简单，当我们有多个系统间的调用时，把reqId放到request的header中进行传递，然后下游系统获取这个id就可以了。

比如下方的拦截器：

public class LogInterceptor implements HandlerInterceptor {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        //如果有上层调用就从header中取出上层的ID
        String traceId = request.getHeader("reqId");
        if (traceId == null) {
            //如果没有，就生成一个默认的
            traceId = RandomUtil.randomNumbers(10);
        }
        MDC.put("reqId", traceId);
        return true;
    }

    @Override
    public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView)
            throws Exception {
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex)
            throws Exception {
        //调用结束后删除
        MDC.remove("reqId");
    }
}

MDC存在的一些问题

我们在上文说过，MDC的本质是ThreadLocal，它会把数据都绑定到当前线程上。但是当我们使用多线程的时候，就会带来一个数据丢失的问题。

所以，我们需要进行线程间的数据传递，保证MDC数据不丢失。

以线程池传递数据为例，ThreadPoolTaskExecutor提供了一个taskDecorator装饰器，通过这个属性，我们就可以实现属性的传递。

首先，定义一个MDCContextDecorator，

public class MDCContextDecorator implements TaskDecorator {

    @Override
    public Runnable decorate(Runnable runnable) {
        Map<String,String> previous = MDC.getCopyOfContextMap();
        return () -> {
            try {
                if (previous != null) {
                    MDC.setContextMap(previous);
                }
                runnable.run();
            } finally {
                MDC.clear();
            }
        };
    }
}

然后设置线程池的taskDecorator属性，

public ThreadPoolTaskExecutor executor() {
  ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
  executor.setCorePoolSize(5);
  executor.setMaxPoolSize(20);
  //...其他属性
  //设置线程属性的自动传递
  executor.setTaskDecorator(new MDCContextDecorator());
  return executor;
}

最后

MDC的使用其实很简单，对于我们查询日志也很有帮助，应用也算是非常广泛了。有兴趣的同学也可以去看一下它的内部实现，代码也并不复杂。

感谢您的点赞和关注。