使用 Spring 的 AOP 机制来输出 Log

使用 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)@Documentedpublic @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)@Documentedpublic @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@Aspectpublic 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相关资料链接

• http://jinnianshilongnian.iteye.com/blog/1415606

• http://jinnianshilongnian.iteye.com/blog/1418598

• http://www.cnblogs.com/shipengzhi/articles/2716004.html

• http://www.cnblogs.com/davidwang456/p/4013631.html

• http://blog.csdn.net/wuxinzaiyu/article/details/8608394