分析java 中aspectj切面执行两次的原因
背景
转眼之间，发现博客已经将近半年没更新了，甚是惭愧。话不多说，正如标题所言，最近在使用aspectj的时候，发现拦截器（aop切面）执行了两次了。我们知道，aspectj是aop的一种解决方案，本质上是通过代理类在目标方法执行通知（advice），然后由代理类再去调用目标方法。所以，从这点讲，拦截器应该只会执行一次。但是在测试的时候发现拦截器执行了两次。
问题重现
既然问题已经明了，那么可以通过代码简单重现这个问题，从而更深层次分析到底是什么原因导致的。
定义一个注解：
|
1
2
3
4
5
6
7
8
9
|
package com.rhwayfun.aspect;
import java.lang.annotation.*;
@target({elementtype.method})
@retention(retentionpolicy.class)
@documented
public @interface statsservice {
}
|
为该注解定义切面：
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
|
package com.rhwayfun.aspect;
import org.aspectj.lang.proceedingjoinpoint;
import org.aspectj.lang.annotation.around;
import org.aspectj.lang.annotation.aspect;
import org.slf4j.logger;
import org.slf4j.loggerfactory;
@aspect
public class statsserviceinterceptor {
private static logger log = loggerfactory.getlogger(statsserviceinterceptor.class);
@around("@annotation(statsservice)")
public object invoke(proceedingjoinpoint pjp) {
try {
log.info("before invoke target.");
return pjp.proceed();
} catch (throwable e) {
log.error("invoke occurs error:", e);
return null;
} finally {
log.info("after invoke target.");
}
}
}
|
方法测试：
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
|
package com.rhwayfun;
import com.rhwayfun.aspect.statsservice;
import org.slf4j.logger;
import org.slf4j.loggerfactory;
import java.time.localdatetime;
public class aspecttest {
private static logger log = loggerfactory.getlogger(aspecttest.class);
public static void main(string[] args) {
aspecttest.print();
}
@statsservice
public static void print(){
log.info("now: {}", localdatetime.now());
}
}
|
输出结果：
debug分析
由于是静态织入，所以可以通过反编译工具查看编译后的文件，如下：
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
|
public class aspecttest
{
private static logger log;
private static final /* synthetic */ joinpoint$staticpart ajc$tjp_0;
private static final /* synthetic */ joinpoint$staticpart ajc$tjp_1;
public static void main(final string[] args) {
statsserviceinterceptor.aspectof().invoke(((aroundclosure)new aspecttest$ajcclosure1(new object[] { factory.makejp(aspecttest.ajc$tjp_0, (object)null, (object)null) })).linkclosureandjoinpoint(0));
}
@statsservice
public static void print() {
statsserviceinterceptor.aspectof().invoke(((aroundclosure)new aspecttest$ajcclosure3(new object[] { factory.makejp(aspecttest.ajc$tjp_1, (object)null, (object)null) })).linkclosureandjoinpoint(65536));
}
static {
ajc$preclinit();
aspecttest.log = loggerfactory.getlogger((class)aspecttest.class);
}
private static /* synthetic */ void ajc$preclinit() {
final factory factory = new factory("aspecttest.java", (class)aspecttest.class);
ajc$tjp_0 = factory.makesjp("method-call", (signature)factory.makemethodsig("9", "print", "com.rhwayfun.aspecttest", "", "", "", "void"), 17);
ajc$tjp_1 = factory.makesjp("method-execution", (signature)factory.makemethodsig("9", "print", "com.rhwayfun.aspecttest", "", "", "", "void"), 22);
}
}
|
请注意两个连接点：ajc$tjp_0和ajc$tjp_1，这两个连接点是产生两次调用的关键，问题注解明明是加上print()方法上的，为什么main()方法也被注入了通知呢？正因为main（）方法也织入了通知，所以就形成了a call b, b call print()的调用链，有两次method-call，一次method-execution，method-execution才是我们的目标方法print（），所以我们才看到了两次输出。
|
1
|
method-call和method-execution都是连接点proceedingjoinpoint的kind属性
|
其实，这属于ajc编译器的一个bug，详见ajc-bug
所以，到这一步，问题就很清晰了，因为ajc编辑器的bug，导致了在main方法中也织入了通知，所以在执行的时候，输出了两次日志。
解决方法
方案一
因为两次调用的kind属性不一样，所以可以通过kind属性来判断时候调用切面。这样显得不优雅，而且如果切面有更多的逻辑的话，需要加各种if-else的判断，所以不推荐。
方法二
更优雅的方案是修改@around("@annotation(statsservice)")的逻辑，改为@around("execution(* *(..)) && @annotation(statsservice)")。
重新运行上面的测试类，结果如下：
如有疑问请留言或者到本站社区交流讨论，感谢阅读，希望能帮助到大家，谢谢大家对本站的支持！
原文链接：http://blog.csdn.net/u011116672/article/details/63685340