Spring AOP实战--之优雅的统一打印web请求的出参和入参

• 背景介绍

由于实际项目内网开发，项目保密，因此本文以笔者自己搭建的demo做演示，方便大家理解。

在项目开发过程中，团队成员为了方便调试，经常会在方法的出口和入口处加上log输出，由于每个人的log需求和输出方式不一样，在测试环境还好，但是上线后导致项目的日志输出特别的杂乱，有时候想要根据日志排查问题就特别地费劲。下面demo是项目中典型的日志输出方式

对于上面的日志打印位置和输出，其实是特别随意不规范的

• 例如controller层和service层都对请求的入参进行了打印，输出没有什么明显的改变，这个一般可以只保留一个
• 日志的整个请求缺少链路追踪，如果多个请求过来都打印分不清哪个是哪个

鉴于存在以上的不足，笔者痛下决心决定对日志打印进行改造。

• 架构思路

由于笔者的项目是微服务集群架构，但是单个服务是遵循MVC分层架构的，如下图所示：

鉴于这样的分层结构，笔者决定从controller层下手，使用spring AOP封装统一的入参和出参日志打印，以规范和解决项目中日志输出的乱象。

• Spring AOP 核心概念

开始撸代码之前先简单回顾下Spring AOP的相关知识点

1、切面（aspect）：切面就是对横切关注点的抽象，被@Aspect标记的类
2、横切关注点：对哪些方法进行拦截，拦截后怎么处理，这些关注点称之为横切关注点。
3、连接点（joinpoint）：被拦截到的点，因为 Spring 只支持方法类型的连接点，所以在 Spring
中连接点指的就是被拦截到的方法，实际上连接点还可以是字段或者构造器。
4、切入点（pointcut）：对连接点进行拦截的定义，可以是切点表达式，也可以是注解
5、通知（advice）：所谓通知指的就是指拦截到连接点之后要执行的代码，通知分为前置、后置、异常、最终、环绕通知五类。
6、目标对象：代理的目标对象
7、织入（weave）：将切面应用到目标对象并导致代理对象创建的过程

我们编码比较关注的就是 切点（pointcut） 和 通知 （advice）

下面我们开始撸代码！

• 代码实现

如果对AOP编码不熟悉的同学，可以移步官方文档：

https://docs.spring.io/spring-framework/reference/core/aop.html

下面上我的切面类的代码

package com.cjt.demo.springaopdemo.aop;

import com.cjt.demo.springaopdemo.utils.JsonUtil;
import com.fasterxml.jackson.databind.ObjectMapper;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.autoconfigure.condition.ConditionalOnClass;
import org.springframework.stereotype.Component;

import java.util.UUID;

/*****************************************************
 * @package com.cjt.demo.springaopdemo.aop
 * @class WebParamAspect
 * @author caojiantao
 * @datetime 2024/6/21 14:53
 * @describe WEB请求参数打印切面类
 *           https://docs.spring.io/spring-framework/reference/core/aop.html
 ****************************************************/
@Aspect
@Component
@ConditionalOnClass(value = {ObjectMapper.class})
public class WebParamAspect {

    /**
     * 全局日志记录
     */
    private static final Logger PARAM_LOG = LoggerFactory.getLogger(WebParamAspect.class);

    /**
     * 定义切点： execution ,with,target等，可以参考官方文档
     * https://docs.spring.io/spring-framework/reference/core/aop/ataspectj/pointcuts.html
     */
    @Pointcut(value = "execution(public * com.cjt.demo.springaopdemo.controller..*(..))")
    public void cut() {
    }

    /**
     * 使用环绕通知：可以拿到请求前和请求后的参数，同时打印
     *
     * @param joinPoint 连接点
     * @return
     */
    @Around(value = "cut()")
    public Object printWebParam(ProceedingJoinPoint joinPoint) throws Throwable {
        // 可以加入接口记录时间，方法进入的时间
        long start = System.currentTimeMillis();

        // 获取连接点方法签名，可以从中解析得到关于该方法的许多信息
        MethodSignature methodSignature = (MethodSignature) joinPoint.getSignature();

        // 方法所在类名称
        String declaringTypeName = methodSignature.getDeclaringTypeName();
        // 方法名
        String methodName = methodSignature.getMethod().getName();

        // 生成唯一的交易编码，便于观察出参和入参
        String uuid = UUID.randomUUID().toString();

        // 获取参数
        Object[] args = joinPoint.getArgs();
        String jsonString = JsonUtil.toJSONString(args);
        // 判断是否开启打印，打印请求信息
        if (PARAM_LOG.isInfoEnabled()) {
            PARAM_LOG.info("TRACE:{} , 请求服务{} - 请求方法{}, 请求参数： {}", uuid, declaringTypeName, methodName, jsonString);
        }

        Object result = null;
        try {
            // 执行代理类的实现逻辑
            result = joinPoint.proceed();
        } catch (Throwable throwable) {
            if (PARAM_LOG.isErrorEnabled()) {
                PARAM_LOG.error("TRACE:{} , 请求服务{} - 请求方法{}, 发生异常了，原因是： {}", uuid, declaringTypeName, methodName, throwable.getMessage(), throwable);
            }
            throw throwable;
        }
        // 方法结束的时间
        long end = System.currentTimeMillis();
        // 判断是否开启打印，打印结果信息
        if (PARAM_LOG.isInfoEnabled()) {
            PARAM_LOG.info("TRACE:{} , 请求服务{} - 请求方法{} , 请求耗时 ： {} ms , 请求结果： {}", uuid, declaringTypeName, methodName, (end - start), jsonString);
        }

        return result;
    }

}

• 切点使用了 execution表达式，只拦截controller层，关于如何定义切点可以参考官方文档：

​​​​​​​Declaring a Pointcut :: Spring Framework

• 通知类型使用了环绕通知，可以拿到代理方法执行前后的结果进行显示
• 日志打印个性化的加入了UUID作为链路跟踪，可以很清晰的看入参和出参，同时在打印出差记录的时候又显示了接口执行的时间。

• 演示效果

演示效果如下图所示：

可以看到成对的uuid可以明显的定位到一个请求的出参和入参情况，也能直观的看的请求的耗时，另外调用的类和方法也很明确的打印出来了，给后续的日志排查问题定位代码提供的便利，

• 源码地址

笔者的demo代码使用的是 springboot单体架构

主要技术点： SpringBoot + Sqlite + knife4j + Mybatis

https://github.com/1989Jiangtao/spring-aop-demo.githttps://github.com/1989Jiangtao/spring-aop-demo.git

Jiangtao/spring-aop-demohttps://gitee.com/caojiangtao1989/spring-aop-demo.git