本文转自【美团技术团队】公众号
原文链接：https://mp.weixin.qq.com/s/JC51S_bI02npm4CE5NEEow
操作日志几乎存在于每个系统中，而这些系统都有记录操作日志的一套 API。操作日志和系统日志不一样，操作日志必须要做到简单易懂。所以如何让操作日志不跟业务逻辑耦合，如何让操作日志的内容易于理解，如何让操作日志的接入更加简单？上面这些都是本文要回答的问题。我们主要围绕着如何“优雅”地记录操作日志展开描述，希望对从事相关工作的同学能够有所帮助或者启发。
-
1. 操作日志的使用场景
-
2. 实现方式
-
2.1 使用 Canal 监听数据库记录操作日志
-
2.2 通过日志文件的方式记录
-
2.3 通过 LogUtil 的方式记录日志
-
2.4 方法注解实现操作日志
-
3. 优雅地支持 AOP 生成动态的操作日志
-
3.1 动态模板
-
4. 代码实现解析
-
4.1 代码结构
-
4.2 模块介绍
-
5. 总结
1. 操作日志的使用场景
-
单纯的文字记录，比如：2021-09-16 10:00 订单创建。 -
简单的动态的文本记录，比如：2021-09-16 10:00 订单创建，订单号：NO.11089999，其中涉及变量订单号“NO.11089999”。 -
修改类型的文本，包含修改前和修改后的值，比如：2021-09-16 10:00 用户小明修改了订单的配送地址：从“金灿灿小区”修改到“银盏盏小区” ，其中涉及变量配送的原地址“金灿灿小区”和新地址“银盏盏小区”。 -
修改表单，一次会修改多个字段。
2. 实现方式
2.1 使用 Canal 监听数据库记录操作日志
2.2 通过日志文件的方式记录
log.info("订单创建")
log.info("订单已经创建，订单编号:{}", orderNo)
log.info("修改了订单的配送地址：从“{}”修改到“{}”， "金灿灿小区", "银盏盏小区")
@Component
public class UserInterceptor extends HandlerInterceptorAdapter {
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
//获取到用户标识
String userNo = getUserNo(request);
//把用户 ID 放到 MDC 上下文中
MDC.put("userId", userNo);
return super.preHandle(request, response, handler);
}
private String getUserNo(HttpServletRequest request) {
// 通过 SSO 或者Cookie 或者 Auth信息获取到 当前登陆的用户信息
return null;
}
}
<pattern>"%d{yyyy-MM-dd HH:mm:ss.SSS} %t %-5level %X{userId} %logger{30}.%method:%L - %msg%n"</pattern>
//不同业务日志记录到不同的文件
<appender name="businessLogAppender" class="ch.qos.logback.core.rolling.RollingFileAppender">
<File>logs/business.log</File>
<append>true</append>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>INFO</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>logs/业务A.%d.%i.log</fileNamePattern>
<maxHistory>90</maxHistory>
<timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
<maxFileSize>10MB</maxFileSize>
</timeBasedFileNamingAndTriggeringPolicy>
</rollingPolicy>
<encoder>
<pattern>"%d{yyyy-MM-dd HH:mm:ss.SSS} %t %-5level %X{userId} %logger{30}.%method:%L - %msg%n"</pattern>
<charset>UTF-8</charset>
</encoder>
</appender>
<logger name="businessLog" additivity="false" level="INFO">
<appender-ref ref="businessLogAppender"/>
</logger>
//记录特定日志的声明
private final Logger businessLog = LoggerFactory.getLogger("businessLog");
//日志存储
businessLog.info("修改了配送地址");
2.3 通过 LogUtil 的方式记录日志
LogUtil.log(orderNo, "订单创建", "小明")
LogUtil.log(orderNo, "订单创建，订单号"+"NO.11089999", "小明")
String template = "用户%s修改了订单的配送地址：从“%s”修改到“%s”"
LogUtil.log(orderNo, String.format(tempalte, "小明", "金灿灿小区", "银盏盏小区"), "小明")
这里解释下为什么记录操作日志的时候都绑定了一个 OrderNo，因为操作日志记录的是：某一个“时间”“谁”对“什么”做了什么“事情”。当查询业务的操作日志的时候，会查询针对这个订单的的所有操作，所以代码中加上了 OrderNo，记录操作日志的时候需要记录下操作人，所以传了操作人“小明”进来。
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);
}
2.4 方法注解实现操作日志
@LogRecord(content="修改了配送地址")
public void modifyAddress(updateDeliveryRequest request){
// 更新派送信息 电话，收件人、地址
doUpdate(request);
}
3. 优雅地支持 AOP 生成动态的操作日志
3.1 动态模板
@LogRecord(content = "修改了订单的配送地址：从“#oldAddress”, 修改到“#request.address”")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
// 更新派送信息 电话，收件人、地址
doUpdate(request);
}
-
操作日志需要知道是哪个操作人修改的订单配送地址。 -
修改订单配送地址的操作日志需要绑定在配送的订单上，从而可以根据配送订单号查询出对这个配送订单的所有操作。 -
为了在注解上记录之前的配送地址是什么，在方法签名上添加了一个和业务无关的 oldAddress 的变量，这样就不优雅了。
@LogRecord(
content = "修改了订单的配送地址：从“#oldAddress”, 修改到“#request.address”",
operator = "#request.userName", bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
// 更新派送信息 电话，收件人、地址
doUpdate(request);
}
operator = "#{T(com.meituan.user.UserContext).getCurrentUser()}"
@LogRecord(content = "修改了订单的配送地址：从“#oldAddress”, 修改到“#request.address”",
bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request, String oldAddress){
// 更新派送信息 电话，收件人、地址
doUpdate(request);
}
@LogRecord(content = "修改了订单的配送地址：从“#oldAddress”, 修改到“#request.address”",
bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
// 查询出原来的地址是什么
LogRecordContext.putVariable("oldAddress", DeliveryService.queryOldAddress(request.getDeliveryOrderNo()));
// 更新派送信息 电话，收件人、地址
doUpdate(request);
}
@LogRecord(content = "修改了订单的配送员：从“#oldDeliveryUserId”, 修改到“#request.userId”",
bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
// 查询出原来的地址是什么
LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
// 更新派送信息 电话，收件人、地址
doUpdate(request);
}
@LogRecord(content = "修改了订单的配送员：从“{deliveryUser{#oldDeliveryUserId}}”, 修改到“{deveryUser{#request.userId}}”",
bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
// 查询出原来的地址是什么
LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
// 更新派送信息 电话，收件人、地址
doUpdate(request);
}
@LogRecord(content = "修改了订单的配送员：从“{queryOldUser{#request.deliveryOrderNo()}}”, 修改到“{deveryUser{#request.userId}}”",
bizNo="#request.deliveryOrderNo")
public void modifyAddress(updateDeliveryRequest request){
// 更新派送信息 电话，收件人、地址
doUpdate(request);
}
4. 代码实现解析
4.1 代码结构
4.2 模块介绍
-
AOP 拦截逻辑 -
解析逻辑 -
模板解析 -
LogContext 逻辑 -
默认的 operator 逻辑 -
自定义函数逻辑 -
默认的日志持久化逻辑 -
Starter 封装逻辑
4.2.1 AOP 拦截逻辑
@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 "";
}
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;
}
4.2.2 解析逻辑
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));
}
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 的实现将会在下文介绍。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);
}
EvaluationContext evaluationContext = expressionEvaluator.createEvaluationContext(method, args, targetClass, ret, errorMsg, beanFactory);
getValue 方法传入的参数 evalContext，就是上面这个 EvaluationContext 对象。下面是 LogRecordEvaluationContext 对象的继承体系：-
把方法的参数都放到 SpEL 解析的 RootObject 中。 -
把 LogRecordContext 中的变量都放到 RootObject 中。 -
把方法的返回值和 ErrorMsg 都放到 RootObject 中。
public class LogRecordEvaluationContext extends MethodBasedEvaluationContext {
public LogRecordEvaluationContext(Object rootObject, Method method, Object[] arguments,
ParameterNameDiscoverer parameterNameDiscoverer, Object ret, String errorMsg) {
//把方法的参数都放到 SpEL 解析的 RootObject 中
super(rootObject, method, arguments, parameterNameDiscoverer);
//把 LogRecordContext 中的变量都放到 RootObject 中
Map<String, Object> variables = LogRecordContext.getVariables();
if (variables != null && variables.size() > 0) {
for (Map.Entry<String, Object> entry : variables.entrySet()) {
setVariable(entry.getKey(), entry.getValue());
}
}
//把方法的返回值和 ErrorMsg 都放到 RootObject 中
setVariable("_ret", ret);
setVariable("_errorMsg", errorMsg);
}
}
public class LogRecordContext {
private static final InheritableThreadLocal<Stack<Map<String, Object>>> variableMapStack = new InheritableThreadLocal<>();
//其他省略....
}
@LogRecord(content = "修改了订单的配送员：从“{deveryUser{#oldDeliveryUserId}}”, 修改到“{deveryUser{#request.getUserId()}}”",
bizNo="#request.getDeliveryOrderNo()")
public void modifyAddress(updateDeliveryRequest request){
// 查询出原来的地址是什么
LogRecordContext.putVariable("oldDeliveryUserId", DeliveryService.queryOldDeliveryUserId(request.getDeliveryOrderNo()));
// 更新派送信息 电话，收件人、地址
doUpdate(request);
}
public interface IOperatorGetService {
/**
* 可以在里面外部的获取当前登陆的用户，比如 UserContext.getCurrentUser()
*
* @return 转换成Operator返回
*/
Operator getUser();
}
public class DefaultOperatorGetServiceImpl implements IOperatorGetService {
@Override
public Operator getUser() {
//UserUtils 是获取用户上下文的方法
return Optional.ofNullable(UserUtils.getUser())
.map(a -> new Operator(a.getName(), a.getLogin()))
.orElseThrow(()->new IllegalArgumentException("user is null"));
}
}
String realOperatorId = "";
if (StringUtils.isEmpty(operatorId)) {
if (operatorGetService.getUser() == null || StringUtils.isEmpty(operatorGetService.getUser().getOperatorId())) {
throw new IllegalArgumentException("user is null");
}
realOperatorId = operatorGetService.getUser().getOperatorId();
} else {
spElTemplates = Lists.newArrayList(bizKey, bizNo, action, operatorId, detail);
}
executeBefore 函数代表了自定义函数是否在业务代码执行之前解析，上面提到的查询修改之前的内容。public interface IParseFunction {
default boolean executeBefore(){
return false;
}
String functionName();
String apply(String value);
}
public class ParseFunctionFactory {
private Map<String, IParseFunction> allFunctionMap;
public ParseFunctionFactory(List<IParseFunction> parseFunctions) {
if (CollectionUtils.isEmpty(parseFunctions)) {
return;
}
allFunctionMap = new HashMap<>();
for (IParseFunction parseFunction : parseFunctions) {
if (StringUtils.isEmpty(parseFunction.functionName())) {
continue;
}
allFunctionMap.put(parseFunction.functionName(), parseFunction);
}
}
public IParseFunction getFunction(String functionName) {
return allFunctionMap.get(functionName);
}
public boolean isBeforeFunction(String functionName) {
return allFunctionMap.get(functionName) != null && allFunctionMap.get(functionName).executeBefore();
}
}
apply 方法上最后返回函数的值。public class DefaultFunctionServiceImpl implements IFunctionService {
private final ParseFunctionFactory parseFunctionFactory;
public DefaultFunctionServiceImpl(ParseFunctionFactory parseFunctionFactory) {
this.parseFunctionFactory = parseFunctionFactory;
}
@Override
public String apply(String functionName, String value) {
IParseFunction function = parseFunctionFactory.getFunction(functionName);
if (function == null) {
return value;
}
return function.apply(value);
}
@Override
public boolean beforeFunction(String functionName) {
return parseFunctionFactory.isBeforeFunction(functionName);
}
}
4.2.3 日志持久化逻辑
public interface ILogRecordService {
/**
* 保存 log
*
* @param logRecord 日志实体
*/
void record(LogRecord logRecord);
}
@Slf4j
public class DefaultLogRecordServiceImpl implements ILogRecordService {
@Override
// @Transactional(propagation = Propagation.REQUIRES_NEW)
public void record(LogRecord logRecord) {
log.info("【logRecord】log={}", logRecord);
}
}
4.2.4 Starter 逻辑封装
@SpringBootApplication(exclude = DataSourceAutoConfiguration.class)
@EnableTransactionManagement
@EnableLogRecord(tenant = "com.mzt.test")
public class Main {
public static void main(String[] args) {
SpringApplication.run(Main.class, args);
}
}
LogRecordConfigureSelector.class，在 LogRecordConfigureSelector 类中暴露了 LogRecordProxyAutoConfiguration 类。@Target(ElementType.TYPE)
@Retention(RetentionPolicy.RUNTIME)
@Documented
@Import(LogRecordConfigureSelector.class)
public @interface EnableLogRecord {
String tenant();
AdviceMode mode() default AdviceMode.PROXY;
}
LogRecordProxyAutoConfiguration 就是装配上面组件的核心类了，代码如下：@Configuration
@Slf4j
public class LogRecordProxyAutoConfiguration implements ImportAware {
private AnnotationAttributes enableLogRecord;
@Bean
@Role(BeanDefinition.ROLE_INFRASTRUCTURE)
public LogRecordOperationSource logRecordOperationSource() {
return new LogRecordOperationSource();
}
@Bean
@ConditionalOnMissingBean(IFunctionService.class)
public IFunctionService functionService(ParseFunctionFactory parseFunctionFactory) {
return new DefaultFunctionServiceImpl(parseFunctionFactory);
}
@Bean
public ParseFunctionFactory parseFunctionFactory(@Autowired List<IParseFunction> parseFunctions) {
return new ParseFunctionFactory(parseFunctions);
}
@Bean
@ConditionalOnMissingBean(IParseFunction.class)
public DefaultParseFunction parseFunction() {
return new DefaultParseFunction();
}
@Bean
@Role(BeanDefinition.ROLE_INFRASTRUCTURE)
public BeanFactoryLogRecordAdvisor logRecordAdvisor(IFunctionService functionService) {
BeanFactoryLogRecordAdvisor advisor =
new BeanFactoryLogRecordAdvisor();
advisor.setLogRecordOperationSource(logRecordOperationSource());
advisor.setAdvice(logRecordInterceptor(functionService));
return advisor;
}
@Bean
@Role(BeanDefinition.ROLE_INFRASTRUCTURE)
public LogRecordInterceptor logRecordInterceptor(IFunctionService functionService) {
LogRecordInterceptor interceptor = new LogRecordInterceptor();
interceptor.setLogRecordOperationSource(logRecordOperationSource());
interceptor.setTenant(enableLogRecord.getString("tenant"));
interceptor.setFunctionService(functionService);
return interceptor;
}
@Bean
@ConditionalOnMissingBean(IOperatorGetService.class)
@Role(BeanDefinition.ROLE_APPLICATION)
public IOperatorGetService operatorGetService() {
return new DefaultOperatorGetServiceImpl();
}
@Bean
@ConditionalOnMissingBean(ILogRecordService.class)
@Role(BeanDefinition.ROLE_APPLICATION)
public ILogRecordService recordService() {
return new DefaultLogRecordServiceImpl();
}
@Override
public void setImportMetadata(AnnotationMetadata importMetadata) {
this.enableLogRecord = AnnotationAttributes.fromMap(
importMetadata.getAnnotationAttributes(EnableLogRecord.class.getName(), false));
if (this.enableLogRecord == null) {
log.info("@EnableCaching is not present on importing class");
}
}
}
IOperatorGetService、ILogRecordService、IParseFunction。业务可以自己实现相应的接口，因为配置了 @ConditionalOnMissingBean，所以用户的实现类会覆盖组件内的默认实现。5. 总结
6. 作者简介
7. 参考资料
-
Canal -
Spring-Framework -
Spring Expression Language (SpEL) -
ThreadLocal、InheritableThreadLocal、TransmittableThreadLocal三者之间区别