使用AOP切面记录日志遇到的坑

815 阅读4分钟

主要原因是@Aspect和@RestController切面的优先级与业务逻辑产生的冲突。

在公司实习被让做一个类似于查看用户操作记录的需求,

比如:
2022年7月21日13:39:29 小明新建了一个文档 -操作成功

2022年7月21日13:39:53 小明测试了一个任务 -操作成功

2022年7月21日13:40:30 小红删除了一个任务 -操作失败

就可以在平台上查看用户的一些历史操作记录

于是我就仿照日志AOP切面的方式,用@Aspect写了一个demo,@Aspect配合另外一个自定义的注解使用,这个自定义的注解我定义了两个东西,一个是operationType,标识这个接口的行为动作,另一个是args数组,标识这个接口的一些关键参数,使用这个自定义注解的时候,只要把注解上的operationType和args填充一下,就可以在切面里把它们组装成 2022年7月21日13:39:29 小明新建了一个文档 这样的一句话,然后插入数据库中,然后另外的接口可以来查询数据库中记录的历史操作日志。

在@Around中,我是这样写的

    @Around("DescriptionLogPointcut()")
    public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        // 记录开始时间
        long startTime = System.currentTimeMillis();

        // 获取请求
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();

        result = proceedingJoinPoint.proceed();
        // 1 获取请求的参数
        // 2 获取注解中的信息
        // 3 获取result中的信息
        // 4 整合操作信息,插入数据库中
        return result;
    }

这样看起来没有问题了,但是,给mentor进行code review之后,他给我提出了一个问题,虽然现在项目里的controller里的逻辑都用try catch包起来了,所以出现异常也会正常返回,但如果有些人在controller里面没有处理掉异常,而是用统一异常处理@ExceptionHandler去处理异常,那这个操作还会不会被记录,他让我先自己试试,一开始我以为这样应该也没问题,因为统一异常处理也会把异常处理掉并返回一个错误结果,不影响我的日志记录。

但是,我在自己做了实验之后,发现我想错了,调用没有处理异常的controller之后,结果返回确实被统一异常处理拦截到了,并且返回了正确的错误码格式。但是我的日志却没有被记录,于是我开始了debug找寻问题所在。

一开始我以为,在我设计的这个增强切面之前,统一异常处理的增强切面会先进行处理,然后再返回。但是事实上,Aspect的切面优先级是高于controllerAdvice,所以先会进入到记录日志的方法里,在进入到异常处理。这样就明显不会去进行记录日志的操作。

于是我对Around进行了如下的修改。

    @Around("DescriptionLogPointcut()")
    public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        // 记录开始时间
        long startTime = System.currentTimeMillis();

        // 获取请求
        ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
        HttpServletRequest request = attributes.getRequest();

        Object result = null;
        try {
            // 执行方法本身
            result = proceedingJoinPoint.proceed();
        } catch (Exception ex) {
            throw ex;
        } finally {
            try {
                // 1 获取请求的参数
                // 2 获取注解中的信息
                // 3 获取result中的信息
                // 4 整合操作信息,插入数据库中
            } catch (Exception ex) {
                logger.error(OBJECT_MAPPER.writeValueAsString(ex));
            }
        }
        return result;
    }

这样,就算proceedingJoinPoint.proceed()方法本身有异常没有处理,还是会去进行记日志的逻辑,等记录完日志,再把异常抛给到统一异常处理去处理。并且把finally里的日志逻辑使用try catch包起来,如果插入日志的地方出现异常,当即处理掉并logger打印,不会影响正当的业务返回。

但即便是这样,还是有问题,Around方法在异常处理的内层,所以没办法拿到统一异常处理之后的一个返回结果。我想了一下,可用采用这两种方案,一种是出现了异常Result为空时,就直接写入一个固定的失败返回结果。另外一种是在Around方法内再套一层统一异常处理,在Around方法内把异常处理掉,这样也就可以把请求返回结果拿到存到数据库中。