SpringBoot使用AOP记录接口操作日志

目录

1. 1. 一、操作日志简介
   1. 1.1. 1.1、系统日志和操作日志的区别
   2. 1.2. 1.2、操作日志记录实现方式
2. 2. 二、AOP面向切面编程
   1. 2.1. 2.1、AOP简介
   2. 2.2. 2.2、AOP作用
   3. 2.3. 2.3、AOP相关术语
   4. 2.4. 2.4、JointPoint和ProceedingJoinPoint
   5. 2.5. 2.5、AOP相关注解
3. 3. 三、AOP切面实现接口日志记录
   1. 3.1. 3.1、引入AOP依赖
   2. 3.2. 3.2、创建日志信息封装类WebLog
   3. 3.3. 3.3、创建切面类WebLogAspect
   4. 3.4. 3.4、调用接口进行测试
4. 4. 四、AOP切面+自定义注解实现接口日志记录
   1. 4.1. 4.1、自定义日志注解
   2. 4.2. 4.2、定义拦截操作日志的切面
   3. 4.3. 4.3、在接口上增加操作日志注解

前言：我们项目中可能有这种需求，每个人请求了哪些接口？做了什么事情？参数是什么？重要的接口我们需要记录操作日志以便查找。操作日志和系统日志不一样，操作日志必须要做到简单易懂。所以如何让操作日志不跟业务逻辑耦合，如何让操作日志的内容易于理解，如何让操作日志的接入更加简单？我们不可能在每个接口中去一一处理，可以借助Spring提供的AOP能力+自定义注解轻松应对。

一、操作日志简介

日志记录量是很大的，所以只记录关键地方并按期归档，最好是存在如elasticsearch中；如果存在数据库中，分表是不错的选择。

1.1、系统日志和操作日志的区别

系统日志：系统日志主要是为开发排查问题提供依据，一般打印在日志文件中；系统日志的可读性要求没那么高，日志中会包含代码的信息，比如在某个类的某一行打印了一个日志。

操作日志：主要是对某个对象进行新增操作或者修改操作后记录下这个新增或者修改，操作日志要求可读性比较强，因为它主要是给用户看的，比如订单的物流信息，用户需要知道在什么时间发生了什么事情。再比如，客服对工单的处理记录信息。

操作日志记录的是：某一个“时间”“谁”对“什么”做了什么“事情”。
比如LogUtil.log(orderNo, “订单创建”, “小明”) ：这里解释下为什么记录操作日志的时候都绑定了一个 OrderNo，因为操作日志记录的是：某一个“时间”“谁”对“什么”做了什么“事情”。当查询业务的操作日志的时候，会查询针对这个订单的的所有操作，所以代码中加上了 OrderNo，记录操作日志的时候需要记录下操作人，所以传了操作人“小明”进来。

操作日志的记录格式大概分为下面几种：

• 单纯的文字记录，比如：2021-09-16 10:00 订单创建。
• 简单的动态的文本记录，比如：2021-09-16 10:00 订单创建，订单号：NO.11089999，其中涉及变量订单号“NO.11089999”。
• 修改类型的文本，包含修改前和修改后的值，比如：2021-09-16 10:00 用户小明修改了订单的配送地址：从“金灿灿小区”修改到“银盏盏小区” ，其中涉及变量配送的原地址“金灿灿小区”和新地址“银盏盏小区”。
• 修改表单，一次会修改多个字段。

1.2、操作日志记录实现方式

（1）使用 Canal 监听数据库记录操作日志

Canal是阿里开源的一款基于 MySQL 数据库增量日志解析中间件，提供增量数据订阅和消费的开源组件，通过采用监听数据库 Binlog 的方式，这样可以从底层知道是哪些数据做了修改，然后根据更改的数据记录操作日志。

这种方式的优点是和业务逻辑完全分离。缺点也很明显，局限性太高，只能针对数据库的更改做操作日志记录，如果修改涉及到其他团队的 RPC 的调用，就没办法监听数据库了。举个例子：给用户发送通知，通知服务一般都是公司内部的公共组件，这时候只能在调用 RPC 的时候手工记录发送通知的操作日志了。

（2）高度代码耦合：在业务逻辑中直接调用日志记录接口

通过日志文件的方式记录，这样就可以把日志单独保存在一个文件中，然后通过日志收集可以把日志保存在 Elasticsearch 或者数据库中，接下来我们看下如何生成可读的操作日志。

//操作日志记录的是：某一个“时间”“谁”对“什么”做了什么“事情”。
log.info("订单创建")
log.info("订单已经创建，订单编号:{}", orderNo)
log.info("修改了订单的配送地址：从“{}”修改到“{}”， "金灿灿小区", "银盏盏小区")

但是当业务变得复杂后，记录操作日志放在业务代码中会导致业务的逻辑比较繁杂。

（3）采用AOP方式：AOP方式能和业务逻辑解耦

为了解决上面问题，一般采用 AOP 的方式记录日志，让操作日志和业务逻辑解耦，接下来看一个简单的 AOP 日志的例子。

@LogRecord(content="修改了配送地址")
public void modifyAddress(updateDeliveryRequest request){
    // 更新派送信息 电话，收件人、地址
    doUpdate(request);
}

我们可以在注解的操作日志上记录固定文案，这样业务逻辑和业务代码可以做到解耦，让我们的业务代码变得纯净起来。可能有同学注意到，上面的方式虽然解耦了操作日志的代码，但是记录的文案并不符合我们的预期，文案是静态的，没有包含动态的文案，因为我们需要记录的操作日志是：用户%s修改了订单的配送地址，从“%s”修改到“%s”。接下来，我们介绍一下如何优雅地使用 AOP 生成动态的操作日志。

二、AOP面向切面编程

2.1、AOP简介

AOP为Aspect Oriented Programming的缩写，意为：面向切面编程，通过预编译方式和运行期间动态代理实现程序功能的统一维护的一种技术。这种在运行时，动态地将代码切入到类的指定方法或指定位置上的编程思想就是面向切面的编程。利用AOP可以将日志记录，性能统计，安全控制，事务处理，异常处理等代码从业务逻辑代码中划分出来作为公共部分，从而使得业务逻辑各部分之间的耦合度降低，提高程序的可重用性，同时提高了开发的效率。

2.2、AOP作用

日志记录，性能统计，安全控制，事务处理，异常处理等等。

在面向切面编程AOP的思想里面，核心业务和切面通用功能（例如事务处理、日志管理、权限控制等)分别独立进行开发，然后把切面功能和核心业务功能 “编织” 在一起，这就叫AOP。这种思想有利于减少系统的重复代码，降低模块间的耦合度，并有利于未来的可拓展性和可维护性。

2.3、AOP相关术语

通知（Advice）

通知描述了切面要完成的工作以及何时执行。比如我们的日志切面需要记录每个接口调用时长，就需要在接口调用前后分别记录当前时间，再取差值。

• 前置通知（Before）：在目标方法调用前调用通知功能；
• 后置通知（After）：在目标方法调用之后调用通知功能，不关心方法的返回结果；
• 返回通知（AfterReturning）：在目标方法成功执行之后调用通知功能；
• 异常通知（AfterThrowing）：在目标方法抛出异常后调用通知功能；
• 环绕通知（Around）：通知包裹了目标方法，在目标方法调用之前和之后执行自定义的行为。

切点（Pointcut）
切点定义了通知功能被应用的范围。比如日志切面的应用范围就是所有接口，即所有controller层的接口方法。

切面（Aspect）
切面是通知和切点的结合，定义了何时、何地应用通知功能。

引入（Introduction）
在无需修改现有类的情况下，向现有的类添加新方法或属性。

织入（Weaving）
把切面应用到目标对象并创建新的代理对象的过程。

连接点（JoinPoint）
通知功能被应用的时机。比如接口方法被调用的时候就是日志切面的连接点。

2.4、JointPoint和ProceedingJoinPoint

JointPoint是程序运行过程中可识别的连接点，这个点可以用来作为AOP切入点。JointPoint对象则包含了和切入相关的很多信息，比如切入点的方法，参数、注解、对象和属性等。我们可以通过反射的方式获取这些点的状态和信息，用于追踪tracing和记录logging应用信息。

（1）JointPoint
通过JpointPoint对象可以获取到下面信息

# 返回目标对象，即被代理的对象
Object getTarget();
 
# 返回切入点的参数
Object[] getArgs();
 
# 返回切入点的Signature
Signature getSignature();
 
# 返回切入的类型，比如method-call，field-get等等，感觉不重要 
 String getKind();

（2）ProceedingJoinPoint

Proceedingjoinpoint 继承了 JoinPoint。是在JoinPoint的基础上暴露出 proceed 这个方法。proceed很重要，这个是aop代理链执行的方法。环绕通知=前置+目标方法执行+后置通知，proceed方法就是用于启动目标方法执行的。

暴露出这个方法，就能支持 aop:around 这种切面（而其他的几种切面只需要用到JoinPoint，，这也是环绕通知和前置、后置通知方法的一个最大区别。这跟切面类型有关）， 能决定是否走代理链还是走自己拦截的其他逻辑。

ProceedingJoinPoint可以获取切入点的信息:

• 切入点的方法名字及其参数
• 切入点方法标注的注解对象（通过该对象可以获取注解信息）
• 切入点目标对象（可以通过反射获取对象的类名，属性和方法名）

//获取切入点方法的名字,getSignature());是获取到这样的信息 :修饰符+ 包名+组件名(类名) +方法名
String methodName = joinPoint.getSignature().getName()
 
//获取方法的参数,这里返回的是切入点方法的参数列表
Object[] args = joinPoint.getArgs();
 
//获取方法上的注解
Signature signature = joinPoint.getSignature();
MethodSignature methodSignature = (MethodSignature) signature;
Method method = methodSignature.getMethod();
if (method != null)
{
   xxxxxx annoObj= method.getAnnotation(xxxxxx.class);
}
 
//获取切入点所在目标对象
Object targetObj =joinPoint.getTarget();
//可以发挥反射的功能获取关于类的任何信息，例如获取类名如下
String className = joinPoint.getTarget().getClass().getName();

2.5、AOP相关注解

Spring中使用注解创建切面

• @Aspect：用于定义切面
• @Before：通知方法会在目标方法调用之前执行
• @After：通知方法会在目标方法返回或抛出异常后执行
• @AfterReturning：通知方法会在目标方法返回后执行
• @AfterThrowing：通知方法会在目标方法抛出异常后执行
• @Around：通知方法会将目标方法封装起来
• @Pointcut：定义切点表达式
• 切点表达式：指定了通知被应用的范围，表达式格式：

execution(方法修饰符 返回类型 方法所属的包.类名.方法名称(方法参数)
//com.hs.demo.controller包中所有类的public方法都应用切面里的通知
execution(public * com.hs.demo.controller.*.*(..))
//com.hs.demo.service包及其子包下所有类中的所有方法都应用切面里的通知
execution(* com.hs.demo.service..*.*(..))
//com.hs.demo.service.EmployeeService类中的所有方法都应用切面里的通知
execution(* com.hs.demo.service.EmployeeService.*(..))

(1)@POINTCUT定义切入点，有以下2种方式：

方式一：设置为注解@LogFilter标记的方法，有标记注解的方法触发该AOP，没有标记就没有。

@Aspect
@Component
public class LogFilter1Aspect {
    @Pointcut(value = "@annotation(com.hs.aop.annotation.LogFilter)")
    public void pointCut(){
    
    }
}

自定义注解LogFilter：

@Target(ElementType.METHOD)
@Retention(value = RetentionPolicy.RUNTIME)
public @interface LogFilter1 {
}

对应的Controller方法如下，手动添加@LogFilter注解：

@RestController
public class AopController {
 
    @RequestMapping("/aop")
    @LogFilter
    public String aop(){
        System.out.println("这是执行方法");
        return "success";
    }
}

方式二：采用表达式批量添加切入点，如下方法，表示AopController下的所有public方法都添加LogFilter1切面。

@Pointcut(value = "execution(public * com.train.aop.controller.AopController.*(..))")
public void pointCut(){
}

(2)@Around环绕通知

@Around集成了@Before、@AfterReturing、@AfterThrowing、@After四大通知。需要注意的是，他和其他四大通知注解最大的不同是需要手动进行接口内方法的反射后才能执行接口中的方法，换言之，@Around其实就是一个动态代理。

/**
  * 环绕通知是spring框架为我们提供的一种可以在代码中手动控制增强部分什么时候执行的方式。
  *
  */
 public void aroundPringLog(ProceedingJoinPoint pjp)
 {
     //拿到目标方法的方法签名
     Signature signature = pjp.getSignature();
     //获取方法名
     String name = signature.getName();
 
     try {
         //@Before
         System.out.println("【环绕前置通知】【"+name+"方法开始】");
         //这句相当于method.invoke(obj,args)，通过反射来执行接口中的方法
         proceed = pjp.proceed();
         //@AfterReturning
         System.out.println("【环绕返回通知】【"+name+"方法返回，返回值："+proceed+"】");
     } catch (Exception e) {
         //@AfterThrowing
         System.out.println("【环绕异常通知】【"+name+"方法异常，异常信息："+e+"】");
     }
     finally{
         //@After
         System.out.println("【环绕后置通知】【"+name+"方法结束】");
     }
 }

proceed = pjp.proceed(args)这条语句其实就是method.invoke，以前手写版的动态代理，也是method.invoke执行了，jdk才会利用反射进行动态代理的操作，在Spring的环绕通知里面，只有这条语句执行了，spring才会去切入到目标方法中。

为什么说环绕通知就是一个动态代理呢？

proceed = pjp.proceed(args)这条语句就是动态代理的开始，当我们把这条语句用try-catch包围起来的时候，在这条语句前面写的信息，就相当于前置通知，在它后面写的就相当于返回通知，在catch里面写的就相当于异常通知，在finally里写的就相当于后置通知。

三、AOP切面实现接口日志记录

通过AOP面向切面编程技术，实现操作日志记录功能以便进行信息监控和信息统计，不侵入业务代码逻辑，提高代码的可重用性。

3.1、引入AOP依赖

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

3.2、创建日志信息封装类WebLog

用于封装需要记录的日志信息，包括操作的描述、时间、消耗时间、url、请求参数和返回结果等信息。

@Data
public class WebLog {
    /**
     * 操作描述
     */
    private String description;
 
    /**
     * 操作用户
     */
    private String username;
 
    /**
     * 操作时间
     */
    private Long startTime;
 
    /**
     * 消耗时间
     */
    private Integer spendTime;
 
    /**
     * 根路径
     */
    private String basePath;
 
    /**
     * URI
     */
    private String uri;
 
    /**
     * URL
     */
    private String url;
 
    /**
     * 请求类型
     */
    private String method;
 
    /**
     * IP地址
     */
    private String ip;
 
    /**
     * 请求参数
     */
    private Object parameter;
 
    /**
     * 请求返回的结果
     */
    private Object result;
 
}

3.3、创建切面类WebLogAspect

import cn.hutool.core.util.StrUtil;
import cn.hutool.core.util.URLUtil;
import cn.hutool.json.JSONUtil;
import lombok.extern.slf4j.Slf4j;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.annotation.*;
import org.aspectj.lang.reflect.MethodSignature;
import org.springframework.core.annotation.Order;
import org.springframework.stereotype.Component;
import org.springframework.util.StringUtils;
import org.springframework.web.bind.annotation.RequestBody;
import org.springframework.web.bind.annotation.RequestParam;
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.lang.reflect.Parameter;
import java.util.ArrayList;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
 
/**
 * 统一日志处理切面
 */
@Aspect
@Component
@Order(1)
@Slf4j
public class WebLogAspect {
 
    //定义切点表达式,指定通知功能被应用的范围
    @Pointcut("execution(public * com.hs.notice.controller.*.*(..))")
    public void webLog() {
    }
 
    @Before("webLog()")
    public void doBefore(JoinPoint joinPoint) throws Throwable {
    }
 
    /**value切入点位置
     * returning 自定义的变量，标识目标方法的返回值,自定义变量名必须和通知方法的形参一样
     * 特点：在目标方法之后执行的,能够获取到目标方法的返回值，可以根据这个返回值做不同的处理
     */     
    @AfterReturning(value = "webLog()", returning = "ret")
    public void doAfterReturning(Object ret) throws Throwable {
    }
 
    //通知包裹了目标方法，在目标方法调用之前和之后执行自定义的行为
    //ProceedingJoinPoint切入点可以获取切入点方法上的名字、参数、注解和对象
    @Around("webLog()")
    public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable 
    {
        long startTime = System.currentTimeMillis();
        //获取当前请求对象
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();
        //记录请求信息
        WebLog webLog = new WebLog();
 
        //前面是前置通知，后面是后置通知
        Object result = joinPoint.proceed();
 
        Signature signature = joinPoint.getSignature();
        MethodSignature methodSignature = (MethodSignature) signature;
        Method method = methodSignature.getMethod();
        long endTime = System.currentTimeMillis();
        String urlStr = request.getRequestURL().toString();
        webLog.setBasePath(StrUtil.removeSuffix(urlStr, URLUtil.url(urlStr).getPath()));
        webLog.setIp(request.getRemoteUser());
        webLog.setMethod(request.getMethod());
        webLog.setParameter(getParameter(method, joinPoint.getArgs()));
        webLog.setResult(result);
        webLog.setSpendTime((int) (endTime - startTime));
        webLog.setStartTime(startTime);
        webLog.setUri(request.getRequestURI());
        webLog.setUrl(request.getRequestURL().toString());
        log.info("{}", JSONUtil.parse(webLog));
        return result;
    }
 
    /**
     * 根据方法和传入的参数获取请求参数
     */
    private Object getParameter(Method method, Object[] args) 
   {
        List<Object> argList = new ArrayList<>();
        Parameter[] parameters = method.getParameters();
        for (int i = 0; i < parameters.length; i++) {
            //将RequestBody注解修饰的参数作为请求参数
            RequestBody requestBody = parameters[i].getAnnotation(RequestBody.class);
            if (requestBody != null) {
                argList.add(args[i]);
            }
            //将RequestParam注解修饰的参数作为请求参数
            RequestParam requestParam = parameters[i].getAnnotation(RequestParam.class);
            if (requestParam != null) {
                Map<String, Object> map = new HashMap<>();
                String key = parameters[i].getName();
                if (!StringUtils.isEmpty(requestParam.value())) {
                    key = requestParam.value();
                }
                map.put(key, args[i]);
                argList.add(map);
            }
        }
        if (argList.size() == 0) {
            return null;
        } else if (argList.size() == 1) {
            return argList.get(0);
        } else {
            return argList;
        }
    }
}

3.4、调用接口进行测试

随便访问一个com.hs.notice.controller包下的接口，可以看到WebLogAspect输出的日志信息：

2022-01-07 10:43:33.732  INFO 11400 --- [nio-8086-exec-7] com.cernet.notice.util.WebLogAspect: 
{"result":{"code":200,"data":{"appName":"Tiktok","isSend":1,"id":1,"sendAT":1640596730378,
"tilte":"【测试数据】","receiverEmail":"110@qq.com","content":"测试"},"message":"请求成功"},
"basePath":"http://localhost:8086","method":"GET","startTime":1641523413722,
"uri":"/api/email-notices/1","url":"http://localhost:8086/api/email-notices/1","spendTime":6}

四、AOP切面+自定义注解实现接口日志记录

4.1、自定义日志注解

import java.lang.annotation.Documented;
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)
@Documented
public @interface OperatorLog 
{
    // 操作
    String operate();
 
    // 模块
    String module();
}

4.2、定义拦截操作日志的切面

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;
import com.elon.springbootdemo.manager.OperatorLog;
import com.elon.springbootdemo.model.ResponseModel;
 
/**
 * 操作日志切面定义
 */
@Aspect
@Component
public class OperatorLogApsect {
    
    private static Logger logger = LogManager.getLogger(OperatorLogApsect.class);
    
    @Pointcut("@annotation(com.hs.springbootdemo.aop.OperatorLog)")
    public void operatorLog() {
        
    }
    
    @SuppressWarnings("rawtypes")
    @AfterReturning(returning="result", pointcut="operatorLog()&&@annotation(log)")
    public void afterReturn(JoinPoint joinPoint, ResponseModel result, OperatorLog log) {
        
        /**
         * 接口调用信息可以记日志，也可以写到数据库
         */
        StringBuilder sb = new StringBuilder();
        sb.append("模块：").append(log.module());
        sb.append("|操作:").append(log.operate());
        sb.append("|接口名称:").append(joinPoint.getSignature().getName());
        sb.append("|错误码:").append(result.getRetCode());
        sb.append("|错误信息:").append(result.getErrorMsg());
        logger.info(sb.toString());
    }
}

4.3、在接口上增加操作日志注解

@RequestMapping(value="/v1/query-user", method=RequestMethod.GET)
@OperatorLog(operate="查询用户", module="用户管理")
public ResponseModel queryUser(@RequestParam(value="user", required=true) String user) 
{
    log.info("[INFO]user info:" + user);
    log.warn("[WARN]user info:" + user);
    log.error("[ERROR]user info:" + user);
    
    return ResponseModel.success(null);
}

调用接口，可以看到输出的日志信息

参考链接：
美团技术团队—如何优雅地记录操作日志？
SpringAOP中的ProceedingJoinPoint使用,配合注解的方式
使用（Annotation）自定义注解做日志记录
Spring 过滤器 拦截器 AOP区别
SpringBoot 拦截器解析
使用拦截器(intercept)和AOP写操作日志-springboot

扩展阅读：Spring AOP，应该不会有比这更详细的介绍了！