aop注解实现操作日志

一、动态模版

一提到动态模板，就会涉及到让变量通过占比特符的方式解析模板，从而达到通过注解记录操作日志的目的。模板解析的方式有很多种，这里使用了SpEL（Spring Expression Language，Spring表达式语言）来实现。我们可以先写下期望的记录日志的方式，然后再看看能否实现这样的功能。

@LogRecord(
     content = "修改了訂單的配送地址：從“#oldAddress”, 修改到“#request.address”",
     operator = "#request.userName", bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
    // 更新派送信息 電話，收件人、地址
    doUpdate(request);
}

修改后的代码在注解上添加两个参数，一个是操作人，一个是操作日志需要绑定的对象。但是，在普通的Web 应用中用户信息都是保存在一个线程上下文的静态方法中，所以operator 一般是这样的写法（假定获取当前登陆用户的方式是UserContext.getCurrentUser()）

operator = "#{T(com.meituan.user.UserContext).getCurrentUser()}"

这样的话，每个@LogRecord 的注解上的操作人都是这么长一串。为了避免过多的重复代码，我们可以把注解上的operator 参数设置为非必填，这样用户可以填写操作人。但是，如果用户不填写我们就取UserContext 的user（下文会介绍如何取user）。最后，最简单的日志变成了下面的形式：

@LogRecord(content = "修改了訂單的配送地址：從“#oldAddress”, 修改到“#request.address”", 
           bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
    // 更新派送信息 電話，收件人、地址
    doUpdate(request);
}

接下来，我们需要解决第三个问题：为了记录业务操作记录添加了一个oldAddress 变量，不管怎么样这都不是一个好的实现方式，所以接下来，我们需要把oldAddress 变量从修改地址的方法签名上去掉。但是操作日志确实需要oldAddress 变量，怎么办呢？

要么和产品经理PK 一下，让产品经理把文案从“修改了订单的配送地址：从xx 修改到yy” 改为“修改了订单的配送地址为：yy”。但是从用户体验上来看，第一种文案更人性化一些，显然我们不会PK 成功的。那么我们就必须要把这个oldAddress 查询出来然后供操作日志使用了。还有一种解决办法是：把这个参数放到操作日志的线程上下文中，供注解上的模板使用。我们按照这个思路再改下操作日志的实现代码。

@LogRecord(content = "修改了訂單的配送地址：從“#oldAddress”, 修改到“#request.address”",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // 查詢出原來的地址是什麼
    LogRecordContext.putVariable("oldAddress", DeliveryService.queryOldAddress(request.getDeliveryOrderNo()));
    // 更新派送信息 電話，收件人、地址
    doUpdate(request);
}

这时候可以看到，LogRecordContext 解决了操作日志模板上使用方法参数以外变量的问题，同时避免了为了记录操作日志修改方法签名的设计。虽然已经比之前的代码好了些，但是依然需要在业务代码里面加了一行业务逻辑无关的代码，如果有“强迫症”的同学还可以继续往下看，接下来我们会讲解自定义函数的解决方案。下面再看另一个例子：

@LogRecord(content = "修改了訂單的配送員：從“#oldDeliveryUserId”, 修改到“#request.userId”",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // 查詢出原來的地址是什麼
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // 更新派送信息 電話，收件人、地址
    doUpdate(request);
}

这个操作日志的模板最后记录的内容是这样的格式：修改了订单的配送员：从“10090”，修改到“10099”，显然用户看到这样的操作日志是不明白的。用户对于用户ID 是10090 还是10099 并不了解，用户期望看到的是：修改了订单的配送员：从“张三（18910008888）”，修改到“小明（13910006666）”。用户关心的是配送员的姓名和电话。但是我们方法中传递的参数只有配送员的ID，没有配送员的姓名可电话。我们可以通过上面的方法，把用户的姓名和电话查询出来，然后通过LogRecordContext 实现。

但是，“强迫症”是不期望操作日志的代码嵌入在业务逻辑中的。接下来，我们考虑另一种实现方式：自定义函数。如果我们可以通过自定义函数把用户ID 转换为用户姓名和电话，那么就能解决这一问题，按照这个思路，我们把模板修改为下面的形式：

@LogRecord(content = "修改了訂單的配送員：從“{deliveryUser{#oldDeliveryUserId}}”, 修改到“{deveryUser{#request.userId}}”",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // 查詢出原來的地址是什麼
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // 更新派送信息 電話，收件人、地址
    doUpdate(request);
}

其中deliveryUser 是自定义函数，使用大括号把Spring 的SpEL 表达式包裹起来，这样做的好处：一是把Spring EL 表达式和自定义函数区分开便于解析；二是如果模板中不需要SpEL 表达式解析可以容易的识别出来，减少SpEL 的解析提高性能。这时候我们发现上面代码还可以优化成下面的形式：

@LogRecord(content = "修改了訂單的配送員：從“{queryOldUser{#request.deliveryOrderNo()}}”, 修改到“{deveryUser{#request.userId}}”",
        bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
    // 更新派送信息 電話，收件人、地址
    doUpdate(request);
}

这样就不需要在modifyAddress 方法中通过LogRecordContext.putVariable() 设置老的快递员了，通过直接新加一个自定义函数queryOldUser() 参数把派送订单传递进去，就能查到之前的配送人了，只需要让方法的解析在modifyAddress() 方法执行之前运行。这样的话，我们让业务代码又变得纯净了起来，同时也让“强迫症”不再感到难受了。

二、代码实现解析

2.1 代码结构

上面的操作日志主要是通过一个AOP 拦截器实现的，整体主要分为AOP 模块、日志解析模块、日志保存模块、Starter 模块；组件提供了4个扩展点，分别是：自定义函数、默认处理人、业务保存和查询；业务可以根据自己的业务特性定制符合自己业务的逻辑。

2.2 模块介绍

有了上面的分析，已经得出一种我们期望的操作日志记录的方式，接下来我们看下如何实现上面的逻辑。实现主要分为下面几个步骤：

• AOP 拦截逻辑

• 解析逻辑

  • 模板解析
  • LogContext 逻辑
  • 默认的operator 逻辑
  • 自定义函数逻辑

• 默认的日志持久化逻辑

• Starter 封装逻辑

2.2.1 AOP 拦截逻辑

这块逻辑主要是一个拦截器，针对@LogRecord 注解分析出需要记录的操作日志，然后把操作日志持久化，这里把注解命名为@LogRecordAnnotation。接下来，我们看下注解的定义：

@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Inherited
@Documented
public @interface LogRecordAnnotation {
    String success();
    String fail() default "";
    String operator() default "";
    String bizNo();
    String category() default "";
    String detail() default "";
    String condition() default "";
}

注解中除了上面提到参数外，还增加了fail、category、detail、condition 等参数，这几个参数是为了满足特定的场景，后面还会给出具体的例子。

为了保持简单，组件的必填参数就两个。业务中的AOP 逻辑大部分是使用@Aspect 注解实现的，但是基于注解的AOP 在Spring boot 1.5 中兼容性是有问题的，组件为了兼容Spring boot1.5 的版本我们手工实现Spring 的AOP 逻辑。

切面选择 AbstractBeanFactoryPointcutAdvisor 实现，切点是通过 StaticMethodMatcherPointcut 匹配包含 LogRecordAnnotation 注解的方法。通过实现 MethodInterceptor 接口实现操作日志的增强逻辑。

public class LogRecordPointcut extends StaticMethodMatcherPointcut implements Serializable {
    // LogRecord的解析類
    private LogRecordOperationSource logRecordOperationSource;
    
    @Override
    public boolean matches(@NonNull Method method, @NonNull Class<?> targetClass) {
          // 解析 這個 method 上有沒有 @LogRecordAnnotation 注解，有的話會解析出來注解上的各個參數
        return !CollectionUtils.isEmpty(logRecordOperationSource.computeLogRecordOperations(method, targetClass));
    }
    void setLogRecordOperationSource(LogRecordOperationSource logRecordOperationSource) {
        this.logRecordOperationSource = logRecordOperationSource;
    }
}

切面的增强逻辑主要代码如下：

@Override
public Object invoke(MethodInvocation invocation) throws Throwable {
    Method method = invocation.getMethod();
    // 記錄日志
    return execute(invocation, invocation.getThis(), method, invocation.getArguments());
}
private Object execute(MethodInvocation invoker, Object target, Method method, Object[] args) throws Throwable {
    Class<?> targetClass = getTargetClass(target);
    Object ret = null;
    MethodExecuteResult methodExecuteResult = new MethodExecuteResult(true, null, "");
    LogRecordContext.putEmptySpan();
    Collection<LogRecordOps> operations = new ArrayList<>();
    Map<String, String> functionNameAndReturnMap = new HashMap<>();
    try {
        operations = logRecordOperationSource.computeLogRecordOperations(method, targetClass);
        List<String> spElTemplates = getBeforeExecuteFunctionTemplate(operations);
        //業務邏輯執行前的自定義函數解析
        functionNameAndReturnMap = processBeforeExecuteFunctionTemplate(spElTemplates, targetClass, method, args);
    } catch (Exception e) {
        log.error("log record parse before function exception", e);
    }
    try {
        ret = invoker.proceed();
    } catch (Exception e) {
        methodExecuteResult = new MethodExecuteResult(false, e, e.getMessage());
    }
    try {
        if (!CollectionUtils.isEmpty(operations)) {
            recordExecute(ret, method, args, operations, targetClass,
                    methodExecuteResult.isSuccess(), methodExecuteResult.getErrorMsg(), functionNameAndReturnMap);
        }
    } catch (Exception t) {
        //記錄日志錯誤不要影響業務
        log.error("log record parse exception", t);
    } finally {
        LogRecordContext.clear();
    }
    if (methodExecuteResult.throwable != null) {
        throw methodExecuteResult.throwable;
    }
    return ret;
}

拦截逻辑的流程：

可以看到，操作日志的记录持久化是在方法执行完之后执行的，当方法抛出异常之后会先捕获异常，等操作日志持久化完成后再抛出异常。在业务的方法执行之前，会对提前解析的自定义函数求值，解决了前面提到的需要查询修改之前的内容。

2.2.2 解析逻辑

模板解析

Spring 3 中提供了一个非常强大的功能：SpEL，SpEL 在Spring 产品中是作为表达式求值的核心基础模块，它本身是可以脱离Spring 独立使用的。举个例子：

public static void main(String[] args) {
        SpelExpressionParser parser = new SpelExpressionParser();
        Expression expression = parser.parseExpression("#root.purchaseName");
        Order order = new Order();
        order.setPurchaseName("張三");
        System.out.println(expression.getValue(order));
}

这个方法将打印“张三”。LogRecord 解析的类图如下：

解析核心类：LogRecordValueParser里面封装了自定义函数和SpEL 解析类LogRecordExpressionEvaluator。

public class LogRecordExpressionEvaluator extends CachedExpressionEvaluator {
    
    private Map<ExpressionKey, Expression> expressionCache = new ConcurrentHashMap<>(64);
    
    private final Map<AnnotatedElementKey, Method> targetMethodCache = new ConcurrentHashMap<>(64);
    
    public String parseExpression(String conditionExpression, AnnotatedElementKey methodKey, EvaluationContext evalContext) {
        return getExpression(this.expressionCache, methodKey, conditionExpression).getValue(evalContext, String.class);
    }
}

LogRecordExpressionEvaluator继承自 CachedExpressionEvaluator 类，这个类里面有两个Map，一个是expressionCache 一个是targetMethodCache。在上面的例子中可以看到，SpEL 会解析成一个Expression 表达式，然后根据传入的Object 获取到对应的值，所以expressionCache 是为了缓存方法、表达式和SpEL 的Expression 的对应关系，让方法注解上添加的SpEL 表达式只解析一次。下面的targetMethodCache 是为了缓存传入到Expression 表达式的Object。核心的解析逻辑是上面最后一行代码。

getExpression(this.expressionCache, methodKey, conditionExpression).getValue(evalContext, String.class);

getExpression方法会从expressionCache 中获取到@LogRecordAnnotation 注解上的表达式的解析Expression 的实例，然后调用 getValue 方法，getValue传入一个evalContext 就是类似上面例子中的order 对象。其中Context 的实现将会在下文介绍。

日志上下文实现

下面的例子把变量放到了LogRecordContext 中，然后SpEL 表达式就可以顺利的解析方法上不存在的参数了，通过上面的SpEL 的例子可以看出，要把方法的参数和LogRecordContext 中的变量都放到SpEL 的 getValue 方法的Object 中才可以顺利的解析表达式的值。下面看看如何实现：

@LogRecord(content = "修改了訂單的配送員：從“{deveryUser{#oldDeliveryUserId}}”, 修改到“{deveryUser{#request.getUserId()}}”",
            bizNo="#request.getDeliveryOrderNo()")
public void modifyAddress(updateDeliveryRequest request){
    // 查詢出原來的地址是什麼
    LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
    // 更新派送信息 電話，收件人、地址
    doUpdate(request);
}

在LogRecordValueParser 中创建了一个EvaluationContext，用来给SpEL 解析方法参数和Context 中的变量。相关代码如下：

EvaluationContext evaluationContext = expressionEvaluator.createEvaluationContext(method, args, targetClass, ret, errorMsg, beanFactory);

在解析的时候调用 getValue 方法传入的参数evalContext，就是上面这个EvaluationContext 对象。下面是LogRecordEvaluationContext 对象的继承体系：