如何优雅地记录日志操作日志？

前言

1. 本文是通过阅读美团的《如何优雅地记录操作日志？》后，整理总结为自己项目落地的方案
2. 由于美团的那篇文章没有给出完整的代码，没有采取文档中自定义函数的实现机制，直接依赖SPEL的bean引用
3. 参考资料
   3.1 spring cache：https://docs.spring.io/spring-framework/docs/5.3.9/reference/html/integration.html#cache
   3.2 SPEL官网：https://docs.spring.io/spring-framework/docs/5.3.9/reference/html/core.html#expressions

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

1. 系统日志：系统日志主要是为开发排查问题提供依据，一般打印在日志文件中；系统日志的可读性要求没那么高，日志中会包含代码的信息，比如在某个类的某一行打印了一个日志
2. 操作日志：主要是对某个对象进行新增操作或者修改操作后记录下这个新增或者修改，操作日志要求可读性比较强，因为它主要是给用户看的，比如订单的物流信息，用户需要知道在什么时间发生了什么事情。

方法注解实现操作日志

注解记录操作日志的优势

private OnesIssueDO updateAddress(updateDeliveryRequest request) {
    DeliveryOrder deliveryOrder = deliveryQueryService.queryOldAddress(request.getDeliveryOrderNo());
    // 更新派送信息，电话，收件人，地址
    doUpdate(request);
    String logContent = getLogContent(request, deliveryOrder);
    LogUtils.logRecord(request.getOrderNo(), logContent, request.getOperator);
    return onesIssueDO;
}

private String getLogContent(updateDeliveryRequest request, DeliveryOrder deliveryOrder) {
    String template = "用户%s修改了订单的配送地址：从“%s”修改到“%s”";
    return String.format(tempalte, request.getUserName(), deliveryOrder.getAddress(), request.getAddress);
}

1. 可以看到上面的例子使用了两个方法代码，外加一个 getLogContent 的函数实现了操作日志的记录
2. 当业务变得复杂后，记录操作日志放在业务代码中会导致业务的逻辑比较繁杂，最后导致 LogUtils.logRecord() 方法的调用存在于很多业务的代码中
3. 类似 getLogContent() 这样的方法也散落在各个业务类中，对于代码的可读性和可维护性来说是一个灾难。下面介绍下如何避免这个灾难

优雅地支持 AOP 生成动态的操作日志

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

1. operator 参数设置为非必填，如果用户不填写我们就取 UserContext的user
2. 自定义函数解决了操作日志模板上使用方法参数以外变量的问题
3. SpEL支持使用“@”符号来引用Bean，在引用Bean时需要使用BeanResolver接口实现来查找Bean

      @Test
       public void test(){
       	//模拟Spring容器中注册order的bean实例 
           DefaultListableBeanFactory factory = new DefaultListableBeanFactory();
           Order order = new Order();
           order.setPurchaseName("purchaseName");
           factory.registerSingleton("order", order);
   
           StandardEvaluationContext context = new StandardEvaluationContext();
           context.setBeanResolver(new BeanFactoryResolver(factory));
           context.setVariable("aaaa","bbbb");
   
           ExpressionParser parser = new SpelExpressionParser();
           String expressionString = "修改了订单的配送员：从#{@order.getName()}, 修改到#{@order.purchaseName},#{#aaaa}";
           String content = parser.parseExpression(expressionString,new TemplateParserContext()).getValue(context,String.class);
           System.out.println(content);
       }
   

代码实现

代码结构

1.1 上面的操作日志主要是通过一个 AOP 拦截器实现的，整体主要分为 AOP 模块、日志解析模块、日志保存模块、Starter 模块
1.2 组件提供了默认处理人扩展点

拦截逻辑的流程：

日志上下文实现

1. 把方法的参数和 LogRecordContext 中的变量都放到 SpEL 的 getValue 方法的 Object 中才可以顺利的解析表达式的值
2. LogRecordContext 的实现，这个类里面通过一个 ThreadLocal 变量保持了一个栈，栈里面是个 Map，Map 对应了变量的名称和变量的值
   2.1 如果支持线程池可以使用阿里巴巴开源的 TTL 框架
3. 为什么不直接设置一个 ThreadLocal<Map<String, Object>> 对象，而是要设置一个 Stack 结构呢？
   3.1 当方法二执行了释放变量后，继续执行方法一的 logRecord 逻辑，此时解析的时候 ThreadLocal<Map<String, Object>>的 Map 已经被释放掉
   3.2 方法一和方法二共用一个变量 Map 还有个问题是：如果方法二设置了和方法一相同的变量两个方法的变量就会被相互覆盖
4. LogRecordContext 每执行一个方法都会压栈一个 Map，方法执行完之后会 Pop 掉这个 Map，从而避免变量共享和覆盖问题