用Spring AOP实现日志记录，及原理分析

2017-11-29 本文已影响502人小小浪把_Dont_know拍

业务需求

一般项目进入生产环境后，为了对系统进行监控，我们需要在业务逻辑里增加日志记录功能。
虽然这个需求很明确，但是要以面向对象的方式实现，并集成到整个系统中去，就需要每个业务对象都单独加入日志记录，这个需求的代码就会遍及所有业务对象。

加入各种系统需求后的系统模块关系示意图

那么，如何以一种更优雅的方式来解决这个需求呢？
这里就需要使用到AOP。

初学者的疑问

在介绍AOP之前，做过Spring项目的同学一定都接触过，在业务里加上注解，就可以直接使用公司内部的封装好的日志记录功能了。类似下面的功能：

@ServiceAspect
public class FooService {
}

这个时候，我就不免要问了：

加一个注解就可以记录日志，如何实现的？
《effective java》中提到“注解永远不会改变别注解代码的语义”，但是这个注解却在原有类上增加了行为，那这句话不是矛盾吗？
增加注解会影响业务代码的执行效率吗？
日志输出和业务代码是在同一个线程里执行吗？背后的原理是怎样的？
我们先将这些问题放一下，从代理模式开始讲起。

代理模式

代理模式相关类关系示意图

如何我要在业务代码之外增加功能，一种比较优雅的方式，就是使用代理模式。调用方并不会感知到它调用的是一个代理对象，而服务方可以灵活地做额外的处理。示例代码如下：

public class ServiceControlSubjectProxy implements ISubject {
    private static final Log logger = LogFactory.getLog(ServiceControlSubjectProxy.class);
    private ISubject subject;

    public ServiceControlSubjectProxy(ISubject s) {
        this.subject = s;
    }

    public String request() {
        TimeOfDay startTime = new TimeOfDay(0, 0, 0);
        TimeOfDay endTime = new TimeOfDay(5, 59, 59);
        TimeOfDay currentTime = new TimeOfDay();
        if (currentTime.isAfter(startTime) && currentTime.isBefore(endTime)) {
            return null;
        }
        String originalResult = subject.request();
        return "Proxy:" + originalResult;
    }
}

        ISubject target = new SubjectImpl();
        ISubject finalSubject = new ServiceControlSubjectProxy(target);
        finalSubject.request();

那Spring是如何实现AOP的功能的呢？Spring的AOP实现，其实是建立在IoC的基础上的。

IoC

让我们先回顾一下Spring IoC的代码。

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans.xsd">

    <bean id="fooService" class="FooService"/>
    <bean id="barService" class="BarService"/>

</beans>

import org.springframework.context.ApplicationContext;
import org.springframework.context.support.ClassPathXmlApplicationContext;

public class Main {
    public static void main(String[] args) {
        ApplicationContext ctx = new ClassPathXmlApplicationContext("applicationContext.xml");
        FooService fooService = (FooService)ctx.getBean("fooService");
        BarService barService = (BarService)ctx.getBean("barService");
        fooService.create(1L, "title");
        barService.create(2, "title");
    }
}

以上代码，可以将FooService和BarService视为具体的业务。

实现日志记录逻辑

这个时候，我们可以言归正传，正式开始AOP的部分了。
所谓AOP，全称Aspect-Oriented Programming，即面向切面编程。
第一代Spring的AOP，是采用AOP Alliance的标准接口：org.aopalliance.intercept.MethodInterceptor。

public interface MethodInterceptor extends Interceptor {
    
    /**
     * Implement this method to perform extra treatments before and
     * after the invocation. Polite implementations would certainly
     * like to invoke {@link Joinpoint#proceed()}.
     * @param invocation the method invocation joinpoint
     * @return the result of the call to {@link Joinpoint#proceed()};
     * might be intercepted by the interceptor
     * @throws Throwable if the interceptors or the target object
     * throws an exception
     */
    Object invoke(MethodInvocation invocation) throws Throwable;

}

那如何实现日志记录逻辑呢？直接实现这个接口就可以了。

public class ServiceInterceptor implements MethodInterceptor {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    public Object invoke(MethodInvocation invocation) throws Throwable {
        long startTime = System.currentTimeMillis();
        Object obj = null;
        try {
            obj = invocation.proceed();
            return obj;
        }
        finally {
            long costTime = System.currentTimeMillis() - startTime;
            logger.info("method={}, args={}, cost_time={}, result={}", invocation.getMethod(), invocation.getArguments(), costTime, obj);
        }
    }
}

将日志记录织入到业务代码

横切代码实现好了以后，就可以开始将这部分逻辑织入业务代码了。
Spring AOP的织入操作非常方便，它提供了自动代理（AutoProxy）机制，来实现横切逻辑的织入。
org.springframework.aop.framework.autoproxy包中提供了BeanNameAutoProxyCreator，可以通过指定一组容器内的目标对象对应的beanName，将指定的一组拦截器应用到这些目标对象之上。

    <bean id="serviceInterceptor" class="ServiceInterceptor">
    </bean>

    <bean class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator">
        <property name="beanNames">
            <list>
                <value>fooService</value>
                <value>barService</value>
            </list>
        </property>
        <property name="interceptorNames">
            <list>
                <value>serviceInterceptor</value>
            </list>
        </property>
    </bean>

织入逻辑配置好以后，运行代码，就可以看到打印日志逻辑已经加到执行方法中去了。
回过头，我们再来看之前提的代理模式和IoC，和AOP有什么关系呢？如果你用debug模式执行，就可以看到通过IoC拿到的fooService实例，其实并不是单纯的fooService实例，而是FooService$$EnhancerBySpringCGLIB。Spring在注册Bean的时候，对FooService做了手脚。最后我们拿到的类已经不是当初我们定义的FooService类了，而是基于CGLIB技术，构造了一个代理类。在代理类的方法里加入了打印日志的逻辑。

第二代的Spring AOP

第二代Spring AOP，可以使用POJO声明Aspect和相关的Advice。

@Aspect
public class ServiceAspect {
    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    @Pointcut("execution(public int *.test(Long, String)) || execution(public int *.test(Integer, String))")
    public void pointcutName() {}

    @Around("pointcutName()")
    public Object doLog(ProceedingJoinPoint joinPoint) throws Throwable {
        long startTime = System.currentTimeMillis();
        Object obj = null;
        try {
            obj = joinPoint.proceed();
            return obj;
        }
        finally {
            long costTime = System.currentTimeMillis() - startTime;
            MethodSignature signature = (MethodSignature)joinPoint.getSignature();
            logger.info("method={}, args={}, cost_time={}, result={}", signature.getName(), signature.getParameterNames(), costTime, obj);
        }
    }
}

Spring AOP会根据注解信息查找相关的Aspect定义，并将其声明的横切逻辑织入当前系统。
这段代码涉及到AOP的几个概念，这里逐个解释一下。

JoinPoint

public Object doLog(ProceedingJoinPoint joinPoint) throws Throwable {}

AOP的功能模块要织入到OOP的功能模块中，需要知道在系统的哪些执行点上进行织入操作，这些将要在其之上进行织入操作的系统执行点就称之为Joinpoint。

一般程序执行流程图

Pointcut

    @Pointcut("execution(public int *.test(Long, String)) || execution(public int *.test(Integer, String))")
    public void pointcutName() {}

Pointcut概念代表的是Joinpoint的表述方式。指定了系统中符合条件的一组Jointpoint。

Advice

Advice是单一横切关注点逻辑的载体，它代表将会织入到Joinpoint的横切逻辑。

如果将Aspect比作OOP中的Class，那么Advice就相当于Class中的Method。

按照Advice在Joinpoint位置执行时机的差异或者完成功能的不同，Advice可以分成多种具体形式:

Before Advice
After Advice
Aroud Adivce
Introduction

各种Advice的执行时机

Around Advice

@Around("pointcutName()")

Around Advice对附加其上的Joinpoint进行“包裹”，可以在Joinpoint之前和之后都指定相应的逻辑，甚至于中断或者忽略Joinpoint处原来程序流程的执行。

Aspect

Aspect是对系统中的横切关注点逻辑进行模块化封装的AOP概念实体。
通常情况下，Aspect可以包含多个Pointcut以及相关Advice定义。

织入Aspect

有了Aspect类以后，怎么织入到业务逻辑里呢？
只需要在IoC容器的配置文件中注册一下AnnotationAwareAspectJAutoProxyCreator，就会自动加载Aspect。

    <bean class="org.springframework.aop.aspectj.annotation.AnnotationAwareAspectJAutoProxyCreator">
        <property name="proxyTargetClass" value="true"/>
    </bean>

    <bean id="performanceAspect" class="PerformanceTraceAspect"/>

写在最后

这样基本就实现了AOP。至于怎样通过注解的方式来控制哪些类输出日志记录，其实就只是一步之遥，稍微修改一下Aspect类的Pointcut规则就行了。网上的例子很多，这里不再做过多的赘述。

最后再回顾一下文章开头提出的几个问题，相信大家心里应该都有答案了。至于“注解永远不会改变别注解代码的语义”，和通过注解实现AOP并不冲突，AOP只是借助注解实现了代理模式而已。《java编程思想》里有一句话对注解的表述很精辟：“注解为我们在代码中添加信息提供了一种形式化的方法，使我们可以在稍后某个时刻非常方便的使用这些数据。”

参考内容

《java编程思想》
《Spring揭秘》
Spring-aop 全面解析（从应用到原理）
代理模式与静态代理
 Spring AOP基础