微服务学习系列13：MDC实现日志链路追踪

不念不忘少年蓝@ 2024-03-22 10:06 35阅读 0赞

## 系列文章目录 ##

--------------------

**目录**

系列文章目录

前言

一、MDC简介及常用API

简介

API

二、MDC使用

TraceInterceptor

修改logback日志格式

三、MDC的坑

--------------------

## 前言 ##

`开发过程中难免遇到需要查看日志来找出问题出在哪一环节的情况，而在实际情况中服务之间互相调用所产生的日志冗长且复杂，若是再加上同一时间别的请求所产生的日志，想要精准定位自己想要查看的日志就比较麻烦。为解决此问题，遂使用MDC日志追踪。`

--------------------

### 一、MDC简介及常用API ###

#### 简介 ####

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

#### API ####

*  clear() ：移除所有MDC

MDC.clear();

*  get (String key) ：获取当前线程MDC中指定key的值

MDC.get("traceId");

*  put(String key, Object o) ：往当前线程的MDC中存入指定的键值对

MDC.put("traceId", IdUtil.simpleUUID());

*  remove(String key) ：删除当前线程MDC中指定的键值对

MDC.remove("traceId");

### 二、MDC使用 ###

1.  拦截器中使用MDC put 键值对。使得所有请求，从一开始就标记上特定标识。
2.  如果是微服务之间的调用，则需要上层服务在header中添加标识同请求一起传输过来。下层服务直接使用上层服务的标识，就可以将日志串联起来。

#### TraceInterceptor ####

import cn.hutool.core.util.IdUtil;
    import org.apache.commons.lang3.StringUtils;
    import org.slf4j.MDC;
    import org.springframework.web.servlet.HandlerInterceptor;
    import org.springframework.web.servlet.ModelAndView;
    
    import javax.servlet.http.HttpServletRequest;
    import javax.servlet.http.HttpServletResponse;
    
    public class TraceInterceptor implements HandlerInterceptor {
        /**
         * 在业务处理器处理请求之前被调用。预处理，可以进行编码、安全控制、权限校验等处理
         */
        @Override
        public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
            String traceId = request.getHeader("requestId");
            if (StringUtils.isBlank(traceId)) {
                traceId = IdUtil.simpleUUID();
            }
    
            MDC.put("traceId", traceId);
    
            return true;
        }
    
        /**
         * 在业务处理器处理请求执行完成后，生成视图之前执行。后处理（调用了Service并返回ModelAndView，但未进行页面渲染），
         * 有机会修改ModelAndView （这个博主就基本不怎么用了）
         */
        @Override
        public void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {
            HandlerInterceptor.super.postHandle(request, response, handler, modelAndView);
        }
    
        /**
         * 在DispatcherServlet完全处理完请求后被调用，可用于清理资源等。返回处理（已经渲染了页面）
         */
        @Override
        public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
            MDC.clear();
        }
    }

#### 修改logback日志格式 ####

<appender name="file-all" class="ch.qos.logback.core.rolling.RollingFileAppender">
            <file>${LOG_HOME}/file-all.log</file>
            <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
                <fileNamePattern>${LOG_HOME}/file-all.log.%d{yyyy-MM-dd}</fileNamePattern>
            </rollingPolicy>
            
            
            <encoder>
                <pattern>[traceId:%X{traceId}]-[%d{yyyy-MM-dd HH:mm:ss:SSS}]-[%t]-[%p]-%m%n</pattern>
            </encoder>
        </appender>

#### 最终效果 ####

[traceId:a891644e7a844b57bf4a13c9ea40b128]-[2023-04-27 17:56:06:986]-[http-nio-7001-exec-2]-[INFO]-UserSignQueryHandler.param=UserSignQuery(type=1, userId=404278)
    [traceId:a891644e7a844b57bf4a13c9ea40b128]-[2023-04-27 17:56:06:986]-[http-nio-7001-exec-2]-[INFO]-shushan.user.sign.service.getUserSign cost time 0ms
    [traceId:]-[2023-04-27 17:56:13:229]-[http-nio-7001-exec-16]-[INFO]-CircleController.queryOwnerList#param=OwnerCirclePageQuery(ownerId=404278)
    [traceId:c4a58ea747da4d64a4b1b4b344078a33]-[2023-04-27 17:56:13:229]-[http-nio-7001-exec-16]-[INFO]-OwnerCirclePageQueryHandler.param=OwnerCirclePageQuery(ownerId=404278)
    [traceId:c4a58ea747da4d64a4b1b4b344078a33]-[2023-04-27 17:56:13:230]-[http-nio-7001-exec-16]-[DEBUG]-==>  Preparing: SELECT COUNT(*) FROM circle WHERE (owner_id = ? AND del_flag = ?)
    [traceId:c4a58ea747da4d64a4b1b4b344078a33]-[2023-04-27 17:56:13:230]-[http-nio-7001-exec-16]-[DEBUG]-==> Parameters: 404278(Long), 0(Integer)
    [traceId:c4a58ea747da4d64a4b1b4b344078a33]-[2023-04-27 17:56:13:234]-[http-nio-7001-exec-16]-[DEBUG]-<==      Total: 1

### 三、MDC的坑 ###

主线程中，如果使用了线程池，会导致线程池中丢失MDC信息；

解决办法：需要我们自己重写线程池，在调用线程跳动run之前，获取到主线程的MDC信息，重新put到子线程中的。

public class MDCThreadPoolExecutor extends ThreadPoolExecutor {
    
        public MDCThreadPoolExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, @NotNull TimeUnit unit, @NotNull BlockingQueue<Runnable> workQueue) {
            super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
        }
    
        @Override
        public void execute(Runnable command) {
            super.execute(MDCThreadPoolExecutor.executeRunable(command, MDC.getCopyOfContextMap()));
        }
    
        @Override
        public Future<?> submit(Runnable task) {
            return super.submit(MDCThreadPoolExecutor.executeRunable(task, MDC.getCopyOfContextMap()));
        }
    
        @Override
        public <T> Future<T> submit(Callable<T> callable) {
            return super.submit(MDCThreadPoolExecutor.submitCallable(callable,MDC.getCopyOfContextMap()));
        }
    
        public static Runnable executeRunable(Runnable runnable ,Map<String,String> mdcContext){
            return new Runnable() {
                @Override
                public void run() {
                    if (mdcContext == null) {
                        MDC.clear();
                    } else {
                        MDC.setContextMap(mdcContext);
                    }
    
                    try {
                        runnable.run();
                    } finally {
                        MDC.clear();
                    }
                }
            };
        }
    
        private static <T> Callable<T> submitCallable(Callable<T> callable, Map<String, String> context) {
            return () -> {
                if (context == null) {
                    MDC.clear();
                } else {
                    MDC.setContextMap(context);
                }
    
                try {
                    return callable.call();
                } finally {
                    MDC.clear();
                }
            };
        }
    }

###  ###

--------------------

##  ##