分析java 中AspectJ切面執(zhí)行兩次的原因
分析java 中AspectJ切面執(zhí)行兩次的原因
背景
轉眼之間,發(fā)現(xiàn)博客已經(jīng)將近半年沒更新了,甚是慚愧。話不多說,正如標題所言,最近在使用AspectJ的時候,發(fā)現(xiàn)攔截器(AOP切面)執(zhí)行了兩次了。我們知道,AspectJ是AOP的一種解決方案,本質上是通過代理類在目標方法執(zhí)行通知(Advice),然后由代理類再去調用目標方法。所以,從這點講,攔截器應該只會執(zhí)行一次。但是在測試的時候發(fā)現(xiàn)攔截器執(zhí)行了兩次。
問題重現(xiàn)
既然問題已經(jīng)明了,那么可以通過代碼簡單重現(xiàn)這個問題,從而更深層次分析到底是什么原因導致的。
定義一個注解:
package com.rhwayfun.aspect; import java.lang.annotation.*; @Target({ElementType.METHOD}) @Retention(RetentionPolicy.CLASS) @Documented public @interface StatsService { }
為該注解定義切面:
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."); } } }
方法測試:
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分析
由于是靜態(tài)織入,所以可以通過反編譯工具查看編譯后的文件,如下:
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,這兩個連接點是產(chǎn)生兩次調用的關鍵,問題注解明明是加上print()方法上的,為什么main()方法也被注入了通知呢?正因為main()方法也織入了通知,所以就形成了A call B, B call print()的調用鏈,有兩次method-call,一次method-execution,method-execution才是我們的目標方法print(),所以我們才看到了兩次輸出。
method-call和method-execution都是連接點ProceedingJoinPoint的kind屬性
其實,這屬于Ajc編譯器的一個Bug,詳見Ajc-bug
所以,到這一步,問題就很清晰了,因為Ajc編輯器的bug,導致了在main方法中也織入了通知,所以在執(zhí)行的時候,輸出了兩次日志。
解決方法
方案一
因為兩次調用的kind屬性不一樣,所以可以通過kind屬性來判斷時候調用切面。這樣顯得不優(yōu)雅,而且如果切面有更多的邏輯的話,需要加各種if-else的判斷,所以不推薦。
方法二
更優(yōu)雅的方案是修改@Around("@annotation(StatsService)")的邏輯,改為@Around("execution(* *(..)) && @annotation(StatsService)")。
重新運行上面的測試類,結果如下:
如有疑問請留言或者到本站社區(qū)交流討論,感謝閱讀,希望能幫助到大家,謝謝大家對本站的支持!
相關文章
Elasticsearch?mapping?概念及自動創(chuàng)建示例
這篇文章主要為大家介紹了Elasticsearch?mapping?概念及自動創(chuàng)建示例詳解,有需要的朋友可以借鑒參考下,希望能夠有所幫助,祝大家多多進步,早日升職加薪2022-11-11為何修改equals方法時還要重寫hashcode方法的原因分析
這篇文章主要介紹了為何修改equals方法時還要重寫hashcode方法的原因分析,具有很好的參考價值,希望對大家有所幫助。如有錯誤或未考慮完全的地方,望不吝賜教2021-06-06