一、编写背景
1. 日常开发中,我们在查看业务日志的时候,会发现需要在一堆与业务无关的系统组件输出的日志中去找我们为特定业务功能所打印的关键日志信息,为了快速查找业务日志,我们可以采用在配置logback.xml日志的时候,将业务日志和系统日志分别输出到不同的文件中
2. 我们在编写代码的时候,我们通常把打印日志的代码嵌入到业务代码中,如果后续要对日志内容修改的时候,修改起来会变得很繁琐,为了解决这一问题,我们可以将一些内容相同的日志抽取出来,以注解的形式添加在底层调用方法上,这样每次只要调用该方法对应的日志就会输出到响应的日志文件中
例如:
a). 通常我们会将日志打印代码写在业务代码中
//业务日志输出到businessLog.log文件中
private final Logger businessLog = LoggerFactory.getLogger("businessLog");
@Override
// @Transactional(propagation = Propagation.REQUIRES_NEW)
public void record(LogRecord logRecord) {
record(logRecord.getMessage());
}
@Override
public void record(String msg) {
if (businessLog.isInfoEnabled()) {
businessLog.info("{}", msg);
}
//业务代码
//TODO
}
b). 以下是我们修改一个菜单的业务代码,日志打印嵌套在业务代码中,controller层调用menu的service层修改某个菜单信息
/**
* 修改
* @param sysMenuDTO
* @return
*/
@PostMapping("/update")
public ResponseEntity<?> update(@RequestBody SysMenuDTO sysMenuDTO) {
if(log.isInfoEnabled()) {
log.info("update SysMenu start....");
log.info("request param:{}", JSON.toJSONString(sysMenuDTO));
}
SysMenu oldMenu = this.sysMenuService.get(sysMenuDTO.getMenuId());
log.info("{}修改了菜单【{}】", UserUtil.getUserName(), oldMenu.getMenuName());
try{
final int count = this.sysMenuService.update(sysMenuDTO);
log.info("修改后的菜单名为【{}】,业务流水号:{}", sysMenuDTO.getMenuName(), SysHeadUtil.getSeqNo());
return CommonResultUtil.success("更新成功", count);
} catch (Exception e) {
log.error("error:", e);
throw e;
}
}
c). 日志打印与业务代码分离的方式
controller 层
/**
* 修改
* @param sysMenuDTO
* @return
*/
@PostMapping("/update")
@LogRecord(content = "update SysMenu start...\nrequest param:#{T(com.alibaba.fastjson.JSON).toJSONString(#sysMenuDTO)}", bizNo="")
public ResponseEntity<?> update(@RequestBody SysMenuDTO sysMenuDTO) {
try{
return CommonResultUtil.success("更新成功", this.sysMenuService.update(sysMenuDTO));
} catch (Exception e) {
log.error("error:", e);
throw e;
}
}
service interface,我们通过注解的方式,编写固定的日志模板,任何调用该接口修改菜单方法的代码都不需要在业务代码中嵌入日志打印代码
/**
* 修改
* @param sysMenu 修改请求体DTO
* @return 成功更新个数
**/
@LogRecord(content = "修改了菜单【#{@{getOldMenuName(#sysMenuDTO.menuId)}}】," +
"修改后的菜单名为【#{#sysMenuDTO.menuName}}】",
operator = "#{T(com.lkyl.UserUtil).getUserName()}",
bizNo = "#{T(com.lkyl.SysHeadUtil).getSeqNo()}")
int update(SysMenuDTO sysMenuDTO);
二、技术实现
接下来我们来讨论,如何从技术层面实现通过注解打印日志这一功能
首先我们需要了解面向切面编程知识,也就是AOP(aspect oriented programming),以及了解SPEL(spring expression language)知识
1. 使用AOP
Advisor 是 Spring AOP 对 Advice 和 Pointcut 的抽象,可以理解为“执行通知者”,一个 Pointcut (一般对应方法)和用于“增强”它的 Advice 共同组成这个方法的一个 Advisor
1.1 我们自定义一个@LogRecord注解,这个注解作用在方法上,对应的类需要注入到spring的bean容器中
1.2 @LogRecord
package com.lkyl.oceanframework.log.annotation;
import java.lang.annotation.*;
@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Inherited
@Documented
public @interface LogRecord {
//日志模板
String content();
String fail() default "";
//操作员,默认为空,则调用默认实现的operatorService
String operator() default "";
//业务流水号
String bizNo();
String category() default "";
String detail() default "";
String condition() default "";
}
1.3 注:摘自美团技术文档,链接请至文章末尾查看。
业务中的 AOP 逻辑大部分是使用 @Aspect 注解实现的,但是基于注解的 AOP 在 Spring boot 1.5 中兼容性是有问题的,组件为了兼容 Spring boot1.5 的版本我们手工实现 Spring 的 AOP 逻辑。
切面选择 AbstractBeanFactoryPointcutAdvisor
实现,切点是通过 StaticMethodMatcherPointcut
匹配包含 LogRecord
注解的方法。通过实现 MethodInterceptor
接口实现操作日志的增强逻辑。
1.4 定义一个Advisor
本例中的advisor继承了AbstractBeanFactoryPointcutAdvisor抽象类 ,该抽象类基于提供的 adviceBeanName
从容器中获取 Advice,在向beanFactory工厂注入实例时,可以指定adviceName,当执行具体的切面代码时,
AbstractBeanFactoryPointcutAdvisor会从beanFactory工厂通过adviceName获取具体的bean对像,如果手动set了advice,那么在执行advice逻辑时会优先获取手动set的advice,本例中注入advisor的时候set了一个advice。
在下面的advisor中指定了它的pointCut
package com.lkyl.oceanframework.log.adviser;
import com.lkyl.oceanframework.log.parser.LogRecordOperationSource;
import com.lkyl.oceanframework.log.pointcut.LogRecordPointcut;
import org.springframework.aop.Pointcut;
import org.springframework.aop.support.AbstractBeanFactoryPointcutAdvisor;
/**
* TODO
*
* @version 1.0
* @author: nicholas
* @createTime: 2022年05月28日 12:47
*/
public class BeanFactoryLogRecordAdvisor extends AbstractBeanFactoryPointcutAdvisor {
private LogRecordOperationSource logRecordOperationSource;
@Override
public Pointcut getPointcut() {
LogRecordPointcut logRecordPointcut = new LogRecordPointcut();
logRecordPointcut.setLogRecordOperationSource(logRecordOperationSource);
return logRecordPointcut;
}
public void setLogRecordOperationSource(LogRecordOperationSource logRecordOperationSource) {
this.logRecordOperationSource = logRecordOperationSource;
}
}
1.5 定义一个PointCut 对于point我们继承了StaticMethodMatcherPointcut
静态方法切点:org.springframework.aop.support.StaticMethodMatcerPointcut是静态方法切点的抽象基类,默认情况下它匹配所有的类。StaticMethodMatcherPointcut包括两个主要的子类 分别是NameMatchMethodPointcut和AbstractRegexpMethodPointcut,前者提供简单字符串匹配方法前面,而后者使用正则表达式匹配方法前面。 动态方法切点:org.springframework.aop.support.DynamicMethodMatcerPointcut是动态方法切点的抽象基类,默认情况下它匹配所有的类,DynamicMethodMatcerPointcut已经过时, 可以使用DefaultPointcutAdvisor和DynamicMethodMatcherPointcut动态方法代替
package com.lkyl.oceanframework.log.pointcut;
import com.lkyl.oceanframework.log.parser.LogRecordOperationSource;
import org.springframework.aop.support.StaticMethodMatcherPointcut;
import org.springframework.lang.NonNull;
import org.springframework.util.CollectionUtils;
import java.io.Serializable;
import java.lang.reflect.Method;
/**
* @author nicholas
*/
public class LogRecordPointcut extends StaticMethodMatcherPointcut implements Serializable {
// LogRecord的解析类
private LogRecordOperationSource logRecordOperationSource;
@Override
public boolean matches(@NonNull Method method, @NonNull Class<?> targetClass) {
// 解析 这个 method 上有没有 @LogRecord 注解,有的话会解析出来注解上的各个参数
return !CollectionUtils.isEmpty(logRecordOperationSource.computeLogRecordOperations(method, targetClass));
}
public void setLogRecordOperationSource(LogRecordOperationSource logRecordOperationSource) {
this.logRecordOperationSource = logRecordOperationSource;
}
}
</