登录 注册

Spring Boot 中使用自定义注解，AOP 切面打印出入参日志及 Dubbo 链路追踪透传 traceId

本贴最后更新于 1742 天前，其中的信息可能已经水流花落

一，使用背景

开发排查系统问题用得最多的手段就是查看系统日志，在分布式环境中一般使用 ELK 来统一收集日志，但是在并发大时使用日志定位问题还是比较麻烦，由于大量的其他用户/其他线程的日志也一起输出穿行其中导致很难筛选出指定请求的全部相关日志，以及下游线程/服务对应的日志。

二，解决思路

每个请求都使用一个唯一标识来追踪全部的链路显示在日志中，并且不修改原有的

使用 Logback 的 MDC 机制日志模板中加入 traceId 标识，取值方式为 %X{traceId}

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

三、方案实现

由于 MDC 内部使用的是 ThreadLocal 所以只有本线程才有效，子线程和下游的服务 MDC 里的值会丢失;所以方案主要的难点是解决值的传递问题。

1.logback 配置文件模板格式添加标识 %X

 <!--格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符-->
    <property name="log.pattern" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{traceId}] [%thread] %-5level %logger{20} - [%method,%line] - %msg%n" />

2.添加 AOP maven 依赖

<dependency>
	<groupId>org.springframework.boot</groupId>
	<artifactId>spring-boot-starter-aop</artifactId>
</dependency>

3.自定义日志注解

import java.lang.annotation.*;

/**
 * @Description: 自定义日志注解
 */
//什么时候使用该注解，我们定义为运行时
@Retention(RetentionPolicy.RUNTIME)
//注解用于什么地方，我们定义为作用于方法上
@Target({ElementType.METHOD})
//注解是否将包含在 JavaDoc 中
@Documented
public @interface WebLog {

    /**
     * 日志描述信息
     *
     * @return
     */
    String description() default "";
}

4.配置 AOP 切面

在配置 AOP 切面之前，我们需要了解下 aspectj 相关注解的作用：

  • @Aspect：声明该类为一个注解类；
  • @Pointcut：定义一个切点，后面跟随一个表达式，表达式可以定义为切某个注解，也可以切某个 package 下的方法；

切点定义好后，就是围绕这个切点做文章了：

  • @Before: 在切点之前，织入相关代码；
  • @After: 在切点之后，织入相关代码;
  • @AfterReturning: 在切点返回内容后，织入相关代码，一般用于对返回值做些加工处理的场景；
  • @AfterThrowing: 用来处理当织入的代码抛出异常后的逻辑处理;
  • @Around: 环绕，可以在切入点前后织入代码，并且可以自由的控制何时执行切点；
import com.alibaba.dubbo.rpc.RpcContext;
import com.google.gson.Gson;
import com.common.annotation.WebLog;
import com.common.constant.Constants;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.*;
import org.slf4j.MDC;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import javax.servlet.http.HttpServletRequest;
import java.lang.reflect.Method;
import java.util.UUID;

@Component
@Aspect
@Order(1)
@Slf4j
public class WebLogAspect {

   /**
    * 换行符
    */
   private static final String LINE_SEPARATOR = System.lineSeparator();

   /**
    * 以自定义 @WebLog 注解为切点
    */
   @Pointcut("@annotation(com.pet.common.annotation.WebLog)")
   public void WebLogAspect() {
   }


   /**
    * 在切点之前织入
    *
    * @param joinPoint
    * @throws Throwable
    */
   @Before("WebLogAspect()")
   public void doBefore(JoinPoint joinPoint) throws Throwable {
       // 开始打印请求日志
       ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
       HttpServletRequest request = attributes.getRequest();

       // 获取 @WebLog 注解的描述信息
       String methodDescription = getAspectLogDescription(joinPoint);

       String traceId = String.valueOf(UUID.randomUUID());
       MDC.put(Constants.LOG_TRACE_ID, traceId);
       RpcContext.getContext().setAttachment(Constants.LOG_TRACE_ID,traceId);
       // 打印请求相关参数
       log.info("========================================== Start ==========================================");
       // 打印请求 url
       log.info("URL            : {}", request.getRequestURL().toString());
       // 打印描述信息
       log.info("Description    : {}", methodDescription);
       // 打印 Http method
       log.info("HTTP Method    : {}", request.getMethod());
       // 打印调用 controller 的全路径以及执行方法
       log.info("Class Method   : {}.{}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());
       // 打印请求的 IP
       log.info("IP             : {}", request.getRemoteAddr());
       // 打印请求入参
       log.info("Request Args   : {}", new Gson().toJson(joinPoint.getArgs()));
   }

   /**
    * 在切点之后织入
    *
    * @throws Throwable
    */
   @After("WebLogAspect()")
   public void doAfter() throws Throwable {
       // 接口结束后换行，方便分割查看
       log.info("=========================================== End ===========================================" + LINE_SEPARATOR);
       MDC.clear();
   }

   /**
    * 环绕
    *
    * @param proceedingJoinPoint
    * @return
    * @throws Throwable
    */
   @Around("WebLogAspect()")
   public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
       long startTime = System.currentTimeMillis();
       Object result = null;
       try {
           result = proceedingJoinPoint.proceed();
       } catch (Exception e) {
           log.info("exception      :{}", e.getMessage());
           throw e;
       } finally {
           // 打印出参
           log.info("Response Args  : {}", new Gson().toJson(result));
           // 执行耗时
           log.info("Time-Consuming : {} ms", System.currentTimeMillis() - startTime);
       }
       return result;
   }

   /**
    * 获取切面注解的描述
    *
    * @param joinPoint 切点
    * @return 描述信息
    * @throws Exception
    */
   public String getAspectLogDescription(JoinPoint joinPoint) throws Exception {
       String targetName = joinPoint.getTarget().getClass().getName();
       String methodName = joinPoint.getSignature().getName();
       Object[] arguments = joinPoint.getArgs();
       Class targetClass = Class.forName(targetName);
       Method[] methods = targetClass.getMethods();
       StringBuilder description = new StringBuilder("");
       for (Method method : methods) {
           if (method.getName().equals(methodName)) {
               Class[] clazzs = method.getParameterTypes();
               if (clazzs.length == arguments.length) {
                   description.append(method.getAnnotation(WebLog.class).description());
                   break;
               }
           }
       }
       return description.toString();
   }

5.下游 dubbo 服务创建 DubboTraceFilter 过滤器 服务者端提供扩展

资源文件夹下创建 META-INF/dubbo 文件夹 创建 com.alibaba.dubbo.rpc.Filter 文件，并编辑文件内容

// xxx为你DubboTraceIdFilter文件所在的位置
dubboTraceIdFilter=com.xxx.DubboTraceIdFilter

import com.alibaba.dubbo.common.extension.Activate;
import com.alibaba.dubbo.rpc.*;
import org.slf4j.MDC;

/**
 * @Description: dubbo跟踪traceId
 */
@Activate(group = {com.alibaba.dubbo.common.Constants.CONSUMER, com.alibaba.dubbo.common.Constants.PROVIDER})
public class DubboTraceIdFilter implements Filter {

    private static final String LOG_TRACE_ID = "traceId";

    @Override
    public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {


        RpcContext rpcContext = RpcContext.getContext();

        // before
        if (rpcContext.isProviderSide()) {
            // get traceId from dubbo consumer，and set traceId to MDC
            String traceId = rpcContext.getAttachment(LOG_TRACE_ID);
            MDC.put(LOG_TRACE_ID, traceId);
        }

        if (rpcContext.isConsumerSide()) {
            // get traceId from MDC, and set traceId to rpcContext
            String traceId = MDC.get(LOG_TRACE_ID);
            rpcContext.setAttachment(LOG_TRACE_ID, traceId);
        }

        Result result = invoker.invoke(invocation);

        // after
        if (rpcContext.isProviderSide()) {
            // clear traceId from MDC
            MDC.remove(LOG_TRACE_ID);
        }
        return result;
    }

四，如何使用

因为我们的切点是自定义注解 @WebLog, 所以我们仅仅需要在 Controller 控制器的每个接口方法添加 @WebLog 注解即可，如果我们不想某个接口打印出入参日志，不加注解就可以了

image.png

五，打印效果

image.png
从上图中可以看到，每个对于每个请求，开始与结束一目了然，并且打印了以下参数：

  • URL: 请求接口地址；
  • Description: 接口的中文说明信息；
  • HTTP Method: 请求的方法，是 POST, GET, 还是 DELETE 等；
  • Class Method: 被请求的方法路径 : 包名 + 方法名;
  • IP: 请求方的 IP 地址；
  • Request Args: 请求入参，以 JSON 格式输出；
  • Response Args: 响应出参，以 JSON 格式输出；
  • Time-Consuming: 请求耗时，以此估算每个接口的性能指数；
  • Spring

    Spring 是一个开源框架，是于 2003 年兴起的一个轻量级的 Java 开发框架，由 Rod Johnson 在其著作《Expert One-On-One J2EE Development and Design》中阐述的部分理念和原型衍生而来。它是为了解决企业应用开发的复杂性而创建的。框架的主要优势之一就是其分层架构，分层架构允许使用者选择使用哪一个组件，同时为 JavaEE 应用程序开发提供集成的框架。

    943 引用 • 1460 回帖 • 1 关注
  • Dubbo

    Dubbo 是一个分布式服务框架，致力于提供高性能和透明化的 RPC 远程服务调用方案，是 [阿里巴巴] SOA 服务化治理方案的核心框架，每天为 2,000+ 个服务提供 3,000,000,000+ 次访问量支持，并被广泛应用于阿里巴巴集团的各成员站点。

    60 引用 • 82 回帖 • 604 关注
  • AOP
    21 引用 • 13 回帖
  • 微服务

    微服务架构是一种架构模式，它提倡将单一应用划分成一组小的服务。服务之间互相协调，互相配合，为用户提供最终价值。每个服务运行在独立的进程中。服务于服务之间才用轻量级的通信机制互相沟通。每个服务都围绕着具体业务构建，能够被独立的部署。

    96 引用 • 155 回帖
北京 位置
1.4k 13 298 78 101 27 3 12 879

相关帖子

回帖
Spring Boot 中使用自定义注解，AOP 切面打印出入参日志及 Dubbo 链路追踪透传 traceId

欢迎来到这里！

我们正在构建一个小众社区，大家在这里相互信任，以平等 • 自由 • 奔放的价值观进行分享交流。最终，希望大家能够找到与自己志同道合的伙伴，共同成长。

注册 关于
请输入回帖内容 ...
workJun
还在努力奋斗的小程序员 北京
回帖
2
 帖子
5
 积分
381