【SpringAOP案例】使用日志进行链路跟踪

一、产生问题及解决方法

问题： 消息处理是由多个服务协同完成。但目前还未建立完善的链路跟踪（skywarking，zipkin），无法查看完整的调用链，一旦处理过程出现问题，无法及时有效的定位问题（找到所有的相关日志）。
方法： 使用日志将消息处理的链路串联起来。将 消息id 写入打印的日志中，出现问题可根据 消息id 快速准确地查到各个服务的相关日志（kibana）。
步骤： 定义注解MsgId，消息处理的方法上添加注解来标识一个切入点，创建通知类，写通知逻辑，消息处理开始时将 消息id put进MDC，处理完成后remove 消息id，这样一来通过 消息id 就能轻松get整个处理流程的日志轨迹。

（补充）：SpringAOP的通知类型有五种，分别为：前置通知，正常返回通知，异常返回通知，返回通知，环绕通知（joinPoint.proceed()）。

二、代码

2.1 MsgId注解

package com.itheima.reggie.aop;

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

@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface MsgId {
}

2.2 Message类

package com.itheima.reggie.aop;

import lombok.Getter;
import lombok.Setter;

@Setter
@Getter
public class Message implements IMessage {
    private String id;

    @Override
    public String getMessageId() {
        return getId();
    }
}

2.3 Service类

package com.itheima.reggie.service.impl;

import com.itheima.reggie.aop.Message;
import com.itheima.reggie.aop.MsgId;
import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Service;

@Slf4j
@Service
public class TestServiceImpl {
    @MsgId
    public void checkMsg(Message msg) {
      log.info("check msg...");
    }

    @MsgId
    public void handleMsg(String name, Message msg) {
        log.info("handle msg...");
    }
}

2.4 Controller类

package com.itheima.reggie.controller;

import com.itheima.reggie.aop.Message;
import com.itheima.reggie.service.impl.TestServiceImpl;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
public class TestController {

    @Autowired
    private TestServiceImpl testService;

    @GetMapping(value = "/test/get")
    public String getString() {
        Message message = new Message();
        message.setId("messageId: 999");
        testService.checkMsg(message);
        return "101";
    }

}

2.5 通知类

package com.itheima.reggie.aop;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;

/**
 * msg id aspect
 */
@Component
@Aspect
public class MsgIdAspect {
    private static final String MSG_ID_KEY = "msg_id";

    /**
     * 线程进入方法时，如果调用栈无 msg_id，则设置值，方法调用结束时清除值。
     * @param joinPoint .
     * @return .
     * @throws Throwable .
     */
    @Around("@annotation(com.itheima.reggie.aop.MsgId)")
    public Object around(ProceedingJoinPoint joinPoint) throws Throwable {
        boolean setValue = false;
        String storeId = MDC.get(MSG_ID_KEY);
        if (storeId == null) {
            Object[] args = joinPoint.getArgs();
            for (Object arg : args) {
                if (arg instanceof IMessage) {
                    MDC.put(MSG_ID_KEY, ((IMessage) arg).getMessageId());
                    setValue = true;
                    break;
                }
            }
        }
        // 执行方法
        try {
            return joinPoint.proceed();
        } finally {
            if (setValue) {
                MDC.remove(MSG_ID_KEY);
            }
        }
    }

    /**
     * 对于非托管的 bean，直接调用方法
     * @param msgId .
     * @param task .
     */
    public static void withWsgId(String msgId, Runnable task) {
        boolean setValue = false;
        String storeId = MDC.get(MSG_ID_KEY);
        if (storeId == null) {
            MDC.put(MSG_ID_KEY, msgId);
            setValue = true;
        }

        // 执行方法
        try {
            task.run();
        } finally {
            if (setValue) {
                MDC.remove(MSG_ID_KEY);
            }
        }
    }
}

2.6. logback.xml 配置日志格式

<?xml version="1.0" encoding="UTF-8"?>

<configuration scan="true" scanPeriod="60 seconds" debug="false">
    <!-- 日志最大的历史 30天 -->
    <property name="maxHistory" value="30"/>
    <!-- ConsoleAppender 控制台输出日志 -->
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- 对日志进行格式化 -->
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss} [%X{msg_id}] [%thread] %-5level %logger -%msg%n</pattern>
        </encoder>
    </appender>

    <!-- root级别   DEBUG -->
    <root level="info">
        <!-- 控制台输出 -->
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

三、控制台打印

2022-09-07 15:08:43 [messageId: 999] [http-nio-8080-exec-1] INFO  com.itheima.reggie.service.impl.TestServiceImpl -check msg...