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

业务需求

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


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

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

初学者的疑问

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

@ServiceAspect
public class FooService {
}

这个时候,我就不免要问了:

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

代理模式

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

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

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可以分成多种具体形式:

  1. Before Advice
  2. After Advice
  3. Aroud Adivce
  4. 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基础

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,271评论 5 476
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,275评论 2 380
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,151评论 0 336
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,550评论 1 273
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,553评论 5 365
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,559评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,924评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,580评论 0 257
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,826评论 1 297
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,578评论 2 320
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,661评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,363评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,940评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,926评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,156评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,872评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,391评论 2 342

推荐阅读更多精彩内容