基于Spring Aop及log4j2的MDC实现全链路调用跟踪（traceid）

梦里梦外; 2023-07-06 08:52 31阅读 0赞

### **环境：** ###

Springboot：2.2.3.RELEASE

Spring-boot-starter-log4j2: 2.2.2.RELEASE

jdk：1.8

### 目标： ###

实现Springboot框架下的全链路跟踪。子目标有两个：

1.  http/https请求内包含traceId（当前决策放置到协议header部分）

2. 业务系统日志能根据traceId跟踪业务对应请求的业务日志

### 实施： ###

###     1. 配置log4j2 ###

![20200217142650943.png][]

注：%X表示输出mdc信息， key为guid

配置完毕，日志显示格式如下：

![watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21hc3RlcjMzNg_size_16_color_FFFFFF_t_70][]

### 2. 声明Aop ###

（以下步骤为辅助理解切面类）

1. 新建类，并声明为切面及Spring组件（@Aspect、 @Component）

2. 定义key，包含mdc key及http/https协议下header的name

3. 定义ThreadLocal，存储当前线程变量（traceId）

4. 自动装配request、response, （原因：要对其header部分填充requestId）

5. \[可选\]初始化方法

6. 定义切点@Pointcut

7. 定义通知，这里定义了如下通知：

@Before（执行前生成当前线程的guid）

@AfterReturning（返回前执行检查，确认离开当前方法携带有效的guid）

@After （方法执行完毕，检查确认guid存在且有效）

@AfterThrowing （执行异常时，抓取异常信息并关联guid）

当然你也可以使用@Arround

8. 测试

完整代码如下：（可考虑使用环绕通知简化代码）

import org.aspectj.lang.JoinPoint;
    import org.aspectj.lang.annotation.*;
    import org.slf4j.MDC;
    import org.springframework.beans.factory.annotation.Autowired;
    import org.springframework.core.NamedThreadLocal;
    import org.springframework.stereotype.Component;
    import org.springframework.util.StringUtils;
    
    import javax.servlet.http.HttpServletRequest;
    import javax.servlet.http.HttpServletResponse;
    import java.util.UUID;
    
    /**
     * https://blog.csdn.net/master336/article/details/104356565
     * @Aspect 表明该类为切面类
     * @Component 声明为Spring组件，由Spring容器统一管理
     * @author master336 2020-02-17
     * 
     */
    @Aspect
    @Component
    public class LogGuidAspect {
        /**
         * 会话ID
         * GUID ： mdc的key
         * REQUEST_GUID ： http/https协议内的guid key
         */
        public final static String GUID = "guid";
        public final static String REQUEST_GUID = "requestGuid";
        /**
         * GUID ThreadLocal 存储当前线程的guid
         */
        public static final ThreadLocal<String> GuidhreadLocal = new NamedThreadLocal<String>("GuidhreadLocal");
        /**
         * 通过自动装配 拿到request及response
         * 切点定义的不同，可能导致自动装配失败，这里定义required=false，忽略无法装配的情况
         */
        @Autowired(required=false)
        HttpServletRequest request;
        @Autowired(required=false)
        HttpServletResponse response;
    
        public static void init(){
            String guid = UUID.randomUUID().toString().replace("-", "");
            GuidhreadLocal.set(guid);
            MDC.put(GUID, guid);
        }
    
        /*** * 切入规则，拦截*Controller.java下所有方法 */
        @Pointcut("execution(* com..*Controller.*(..))")
        public void beanAspect(){
    
        }
        /**
         * 前置通知 记录开始时间
         * @param joinPoint 切点
         * @throws InterruptedException
         */
        @Before("beanAspect()")
        public void doBefore(JoinPoint joinPoint) throws InterruptedException{
            dealGuid();
        }
        /**
         * 后置通知 返回通知
         * @param res 响应内容
         */
        @AfterReturning(returning = "res", pointcut = "beanAspect()")
        public void doAfterReturning(Object res) throws Throwable {
            // 处理完请求，返回内容
            dealGuid();
        }
        /**
         * 后置通知 记录用户的操作
         * @param joinPoint 切点
         */
        @After("beanAspect()")
        public void doAfter(JoinPoint joinPoint) {
            dealGuid();
        }
    
        /**
         *  异常通知 即使出现错误，也不要丢了guid信息
         * @param joinPoint
         * @param e
         */
        @AfterThrowing(pointcut = "beanAspect()", throwing = "e")
        public  void doAfterThrowing(JoinPoint joinPoint, Throwable e) {
            dealGuid();
        }
        public void dealGuid(){
            // 依次从 request threadlocal 里取
            String guid = GuidhreadLocal.get();
            if(StringUtils.isEmpty(guid) && request != null) {
                try {
                    guid = request.getHeader(REQUEST_GUID);
                }catch (Throwable e){
                    // response 不可用 直接忽略
                }
            }
            // 无法读取有效的guid重新生成
            if(StringUtils.isEmpty(guid)){
                guid = UUID.randomUUID().toString().replace("-", "");
            }
            // 设置SessionId
            GuidhreadLocal.set(guid);
            if(response != null) {
                try {
                    response.setHeader(REQUEST_GUID, guid);
                }catch (Throwable e){
                    // response 不可用 直接忽略
                }
            }
            MDC.put(GUID, guid);
        }
    }

完成切面定义，测试日志输出：

![watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21hc3RlcjMzNg_size_16_color_FFFFFF_t_70 1][]

web请求

![watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21hc3RlcjMzNg_size_16_color_FFFFFF_t_70 2][]

注：日志中有行未显示traceId，原因是sevlet由容器负责创建，与启动入口main方法非同一个线程，且未被LogGuidAspect拦截。

已知有些公司对DispatcherServlet.java增强进行了增强，这里简单罗列一下Spring DispatcherServlet调用执行关系，方便有兴趣的同学研究能不能从servlet这一层实现同样的效果。

--> DispatcherServlet.service(实际执行：FrameworkServlet.service()）
    --> HttpServlet.service() 
    --> DispatcherServlet.doGet/doPost/doHeader....()(实际执行FrameworkServlet..doGet/doPost/doHeader....())-->
    --> FrameworkServlet.processRequest()
    --> DispatcherServlet.doService()
    --> DispatcherServlet.doDispatch()
    --> HandlerAdapter.handle()
    --> *Controller.method()[业务代码]
    --> 返回处理 略

### 拓展资料： ###

[https://logging.apache.org/log4j/2.x/manual/logbuilder.html][https_logging.apache.org_log4j_2.x_manual_logbuilder.html]

[https://logging.apache.org/log4j/2.x/manual/thread-context.html][https_logging.apache.org_log4j_2.x_manual_thread-context.html]

### 后续的思考： ###

基于filter实现全链路的跟踪

已知：filter的作用在Controller之前，在DispatcherServlet.init之后，DispatcherServlet是单利的。

那么来思考在Filter中是否有必要加入呢？

是否有必要那就要想，Filter执行到业务代码（Controller）之前还有什么？！以HandlerInterceptor举例

如果仅关注业务执行过程中的变化，HandlerInterceptor中没有必要的业务代码，那么加入就变的非必要，如果HandlerInterceptor中实现了权限等内容，那么就变的有必要了。（执行LogGuidAspect.init() 或者修改dealGuid为static并调用即可）

[20200217142650943.png]: https://img-blog.csdnimg.cn/20200217142650943.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21hc3RlcjMzNg_size_16_color_FFFFFF_t_70]: https://img-blog.csdnimg.cn/20200217143241996.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21hc3RlcjMzNg==,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21hc3RlcjMzNg_size_16_color_FFFFFF_t_70 1]: https://img-blog.csdnimg.cn/20200217153422424.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21hc3RlcjMzNg==,size_16,color_FFFFFF,t_70
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21hc3RlcjMzNg_size_16_color_FFFFFF_t_70 2]: https://img-blog.csdnimg.cn/20200217215934158.png?x-oss-process=image/watermark,type_ZmFuZ3poZW5naGVpdGk,shadow_10,text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L21hc3RlcjMzNg==,size_16,color_FFFFFF,t_70
[https_logging.apache.org_log4j_2.x_manual_logbuilder.html]: https://logging.apache.org/log4j/2.x/manual/logbuilder.html
[https_logging.apache.org_log4j_2.x_manual_thread-context.html]: https://logging.apache.org/log4j/2.x/manual/thread-context.html