使用 Sprindg 的 AOP 机制来输出 Log
最近接到一个需求:
在所有的REST接口上,需要输出审计日志,日志内容如下:
ugi=user1 srcIP=10.10.10.10 dstIP=11.11.11.11 op=add obj=user info={useId:1, userName:testUser} res=Success
其中,ugi 是当前操作接口的用户的名称,srcIP是访问者的IP,dstIP是服务器的IP,op是某个操作的简称,obj是操作的对象,info是操作对象的备注信息(一般是接口的参数的信息),res是本次操作的结果。
刚拿到这个需求时,第一反应就是在每个接口中分别去加这个输出Log的语句,但是细想一下,就知道自己是多么的愚蠢了。
后来考虑了一些时间之后,决定采用Spring的AOP机制来实现这个需求。因为通过AOP,可以拦截将被执行的接口,并在该接口执行前后进行一些自定义行为。比如,我们的这个需求,就是要在接口执行后,根据执行的结果来输出处理成功或者失败的日志。
接着就查看了Spring的aop相关的方面的材料。以下是实现这一需求的过程。
添加依赖
<dependency>
<groupId>org.aspectj</groupId>
<artifactId>aspectjrt</artifactId>
<version>1.8.0</version>
</dependency>
<dependency>
<groupId>org.aspectj</groupId>
<artifactId>aspectjtools</artifactId>
<version>1.8.0</version>
</dependency>
<dependency>
<groupId>org.springframework</groupId>
<artifactId>spring-aop</artifactId>
<version>4.1.1.RELEASE</version>
</dependency>
开启AOP支持
在spring的配置文件中加入
<context:component-scan base-package="xxx.yyy.zzz.*"/>
<aop:aspectj-autoproxy />
@Component
@Aspect
// 此类实是实现 aop 功能的类
public class AuditLogAspect {
// ......
}
注意,context:component-scan中指定的package必须要包含AuditLogAspect类,不然@Component将不起作用,从而导致 AOP 无法生效。
审计日志的实现方案
考虑以下几个问题:
- 上面的日志格式中,有op和obj这两个字段,每个接口的这两个字段的值几乎是不会有重复的。那么,我们如果为每个接口指定这两个字段的值呢?
假设我们有100个接口,其中,有80个接口是需要写审计日志的,另外20个则不需要写。那么,如何才能将这20个接口排除在外呢?
上面的日志格式中,还有一个info字段,它需要把每个接口的参数组装成一个字符串,输出至日志中。这一点如何实现比较好呢?
对于这几个问题,一个愚蠢的方法就是在 aop 类中,写100个 if 分支,来判断当前拦截到的是哪个接口,然后设置相关的值或者决定要不要写审计日志。
但是,这么做,你会发现你很快会被搞死,比如,单元测试要弄死你;以后如果接口的方法名称改了,也会弄死你;等等等等。
那么,该怎么做呢?答案就是:自定义注解。
对于第一个问题: 我们可以在自定义注解中,声明两个字段,用于指定日志中所需的op和obj这两个字段的值。
对于第二个问题: 我们可以在aop中判断一下,只有加了相关自定义注解的 接口 我们才输出审计日志,否则就不输出。
对于第三个问题,我们可以再定义另外的一个自定义注解,当aop解析到接口的某个参数使用了这个注解时,就会将其值打印出来。
实现自定义注解
- AuditLog: 这个注解仅限用于 接口 级别,当aop解析到某个接口使用了这个注解后,将为此接口输出审计日志,并从该注解中获取op和**的值。
@Target({ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface AuditLog {
/**
* the operation
*/
AuditLogOperation op();
/**
* the operation target
*/
AuditLogObject obj();
}
其中,
op()对应日志中的op字段,它是一个枚举,里面列举了所有的op:
public enum AuditLogOperation {
ADD("add");
// other operation ...
private String operation;
AuditLogOperation(String operation) {
this.operation = operation;
}
public String val() {
return this.operation;
}
}
obj()对应日志中的obj字段,它是一个枚举,里面列举了所有的obj:
public enum AuditLogObject {
NODE("节点");
// other object ...
private String object;
AuditLogObject(String object) {
this.object = object;
}
public String val() {
return this.object;
}
}
- ParaDoc: 这个注解仅限用于 参数 级别,当aop解析到某个接口的某个参数使用了这个注解后,则该接口的该参数将会被输出审计日志中。
@Target(ElementType.PARAMETER)
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface ParaDoc {
/**
* The description of the parameter.
*
* @return the parameter description
*/
ParaDesc value();
/**
* The formatter used to format the parameter.<br>
* Only the first element in this array will have an effect.
*
* @return the formatter for the parameter
*/
Class<? extends IParaFormatter>[] formatter() default {};
}
其中,
value() 是参数的描述,它也是一个枚举,列出了所有接口的所有参数的描述:
public enum ParaDesc {
PD_000001("节点ID");
private String desc;
ParaDesc(String desc) {
this.desc = desc;
}
public String val() {
return this.desc;
}
}
如果节点ID这个参数的值为1的话,那么最终输出至审计日志中的内容将为: 节点ID:1。
formatter()的作用是:当一个参数是一个复杂对象(比如数组对象)时,如果直接将其输出的话,那么审计日志中将会产生类似节点ID:[I@420b8aff的内容,这个是我们所不希望发生的。为了避免这种情况,这里提供了formater来将参数的值进行format,使输出的内容变得阅读,如:节点ID:[1, 2]
PS:如果对象是一些DTO或者POJO之类的对象的话,我们只需要override一下它们的 toString()方法好即可。
formatter示例
public class ArrayFormatter implements IParaFormatter {
// format 数组
@Override
public String format(Object obj) {
if (obj == null) {
return "";
}
StringBuffer sb = new StringBuffer("");
int length = Array.getLength(obj);
for (int i = 0; i < length; i++) {
if (i == 0) {
sb.append(Symbol.LEFT_SQUARE_BRACKETS.getSymbol());
} else {
sb.append(Symbol.COMMA.getSymbol()).append(Symbol.BLANK.getSymbol());
}
sb.append(String.valueOf(Array.get(obj, i)));
if (i == length - 1) {
sb.append(Symbol.RIGHT_SQUARE_BRACKETS.getSymbol());
}
}
return sb.toString();
}
}
好了,至此,准备工作就算做完了。接下来就等主角上场了。
AOP实现
直接上代码(请注意看代码中的注释):
@Component
@Aspect
public class AuditLogAspect {
/**
* 输出审计日志用的logger
*/
private static final Logger LOG = LoggerFactory.getLogger(AuditLogAspect.class);
/**
* 用户Service
*/
@Autowired
private IUserService userService;
/**
* 审计日志内容格式。每个字段间使用Tab键进行分隔。
*/
private static final String LOG_MSG = "ugi={}\tsrcIP={}\tdstIP={}\top={}\tobj={}\tinfo={}\tres={}";
/**
* 定义一个point cut。
* 该 point cut的过滤规则是:xxx.yyy.zzz包下的所有类中,包含了 AuditLog 注解的方法将被拦截
* @annotation(auditLog)的作用是:将接口上的 AuditLog 注解作为参数直接传递给使用了该 point cut 的通知方法(比如,下面的 around 通知),
* 从而避免通过反射去获取这个 AuditLog 注解。注意名称变量须上下一致。
*/
@Pointcut(value = "within(xxx.yyy.zzz.*) && @annotation(auditLog)")
public void pointCut(AuditLog auditLog) {
// just a empty method
}
/**
* 使用 'around通知'(亦称 环绕通知),通过调用pjp.proceed()来执行被拦截的方法,
* 且将pjp.proceed()置于一个 try/catc 块中,当正常结束时,审计日志中的结果就是 Succ,
* 如果走到了catch分支,则审计日志中的结果就是 Fail
*/
@Around(value = "pointCut(auditLog)", argNames = "pjp, auditLog")
public Object around(ProceedingJoinPoint pjp, AuditLog auditLog) throws Throwable {
// 取得当前的 request 对象
RequestAttributes ra = RequestContextHolder.getRequestAttributes();
ServletRequestAttributes sra = (ServletRequestAttributes) ra;
HttpServletRequest request = sra.getRequest();
// 从request的Header中取得用户ID
int userId = Integer.parseInt(request.getHeader(ConstVar.userAuthTag));
// 通过用户ID获取用户信息,用于在日志中输出
User user = userService.getUser(userId);
// 解析 被拦截 的方法的参数,组装成备注信息,用于在日志中输出
String info = buildLogInfo(((MethodSignature) pjp.getSignature()).getMethod(), pjp.getArgs());
try {
// 执行被拦截的方法
Object result = pjp.proceed();
// 正常执行完了,说明请求处理成功,
LOG.info(LOG_MSG, user.getUserName(), request.getRemoteAddr(), request.getLocalAddr(), auditLog.op().val(), auditLog.obj().val(), info, AuditLogResult.SUCCESS.val());
return result;
} catch (Throwable throwable) {
// 抛出异常,说明请求处理失败
LOG.info(LOG_MSG, user.getUserName(), request.getRemoteAddr(), request.getLocalAddr(), auditLog.op().val(), auditLog.obj().val(), info, AuditLogResult.FAIL.val());
throw throwable;
}
}
/**
* Build the log info string.
*
* @param method the method to be executed
* @param args the values of the parameters of the method
* @return the log info string
*/
private String buildLogInfo(Method method, Object[] args) {
StringBuffer info = new StringBuffer("");
// 获取方法的每个参数对应的所有注解
Annotation[][] parameterAnnotations = method.getParameterAnnotations();
String msgPattern;
String arg;
ParaDoc paraDoc;
// 方法参数的注解是按照参数的声明顺序返回的。这一点可以查看JavaDoc。
for (int i = 0; i < parameterAnnotations.length; i++) {
// 一个参数可能有多个注解
for (int j = 0; j < parameterAnnotations[i].length; j++) {
// 如果参数包含了 ParaDoc 这个注解,那么就将其进行输出
if (parameterAnnotations[i][j] instanceof ParaDoc) {
paraDoc = (ParaDoc) parameterAnnotations[i][j];
// 如果有多个参数要输出,那么,每个参数之间使用 "|"进行分隔
// 比如: "用户ID:1|用户姓名:admin"
if (info.length() > 0) {
info.append(Symbol.VLINE.getSymbol());
}
msgPattern = paraDoc.value().val();
// 获取该参数对应的 formatter
Class<? extends IParaFormatter>[] formatter = paraDoc.formatter();
if (formatter.length > 0) {
// 如果存在formatter,那么取第1个formatter对参数进行格式化。
// 如果有多个 formatter,那么多余的 formatter 将会被忽略。
try {
// args这个数组中的元素的顺序和parameterAnnotations中元素的顺序是一致的,
// 所以,我们可以直接使用args[i]来取得对应参数的值
arg = formatter[0].newInstance().format(args[i]);
} catch (InstantiationException | IllegalAccessException e) {
arg = "";
}
} else {
// 如果不存在 formatter,那么直接将参数值输出即可
arg = String.valueOf(args[i]);
} info.append(msgPattern).append(Symbol.COLON.getSymbol()).append(arg);
}
}
}
return info.toString();
}
}
AOP相关资料链接