你真的確定Spring AOP的執(zhí)行順序嗎
前言
公司這兩個(gè)月啟動(dòng)了全新的項(xiàng)目，項(xiàng)目排期滿滿當(dāng)當(dāng)，不過(guò)該學(xué)習(xí)還是要學(xué)習(xí)。這不，給公司搭項(xiàng)目的時(shí)候，。
本文內(nèi)容重點(diǎn)：
- 問題描述
- Spring AOP執(zhí)行順序
- 探究順序錯(cuò)誤的真相
- 代碼驗(yàn)證
- 結(jié)論
問題描述
公司新項(xiàng)目需要搭建一個(gè)新的前后分離HTTP服務(wù)，我選擇了目前比較熟悉的SpringBoot Web來(lái)快速搭建一個(gè)可用的系統(tǒng)。
魯迅說(shuō)過(guò)，不要隨便升級(jí)已經(jīng)穩(wěn)定使用的版本。我偏不信這個(gè)邪，仗著自己用了這么久Spring，怎么能不沖呢。不說(shuō)了，直接引入了最新的SprinBoot 2.3.4.RELEASE版本，開始給項(xiàng)目搭架子。
起初，大多數(shù)的組件引入都一切順利，本以為就要大功告成了，沒想到在搭建日志切面時(shí)栽了跟頭。
作為一個(gè)接口服務(wù)，為了方便查詢接口調(diào)用情況和定位問題，一般都會(huì)將請(qǐng)求日志打印出來(lái)，而Spring的AOP作為切面支持，完美的切合了日志記錄的需求。
之前的項(xiàng)目中，運(yùn)行正確的切面日志記錄效果如下圖：
可以看到圖內(nèi)的一次方法調(diào)用，會(huì)輸出請(qǐng)求url，出入?yún)ⅲ约罢?qǐng)求IP等等，之前為了好看，還加入了分割線。
我把這個(gè)實(shí)現(xiàn)類放入新項(xiàng)目中，執(zhí)行出來(lái)卻是這樣的：
我揉了揉眼睛，仔細(xì)看了看復(fù)制過(guò)來(lái)的老代碼，精簡(jiǎn)版如下：
- /**
- * 在切點(diǎn)之前織入
- * @param joinPoint
- * @throws Throwable
- */
- @Before("webLog()")
- public void doBefore(JoinPoint joinPoint) throws Throwable {
- // 開始打印請(qǐng)求日志
- ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
- HttpServletRequest request = attributes.getRequest();
- // 初始化traceId
- initTraceId(request);
- // 打印請(qǐng)求相關(guān)參數(shù)
- LOGGER.info("========================================== Start ==========================================");
- // 打印請(qǐng)求 url
- LOGGER.info("URL : {}", request.getRequestURL().toString());
- // 打印 Http method
- LOGGER.info("HTTP Method : {}", request.getMethod());
- // 打印調(diào)用 controller 的全路徑以及執(zhí)行方法
- LOGGER.info("Class Method : {}.{}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());
- // 打印請(qǐng)求的 IP
- LOGGER.info("IP : {}", IPAddressUtil.getIpAdrress(request));
- // 打印請(qǐng)求入?yún)?nbsp;
- LOGGER.info("Request Args : {}", joinPoint.getArgs());
- }
- /**
- * 在切點(diǎn)之后織入
- * @throws Throwable
- */
- @After("webLog()")
- public void doAfter() throws Throwable {
- LOGGER.info("=========================================== End ===========================================");
- }
- /**
- * 環(huán)繞
- * @param proceedingJoinPoint
- * @return
- * @throws Throwable
- */
- @Around("webLog()")
- public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
- long startTime = System.currentTimeMillis();
- Object result = proceedingJoinPoint.proceed();
- // 打印出參
- LOGGER.info("Response Args : {}", result);
- // 執(zhí)行耗時(shí)
- LOGGER.info("Time-Consuming : {} ms", System.currentTimeMillis() - startTime);
- return result;
- }
代碼感覺完全沒有問題，難道新版本的SpringBoot出Bug了。
顯然，成熟的框架不會(huì)在這種大方向上犯錯(cuò)誤，那會(huì)不會(huì)是新版本的SpringBoot把@After和@Around的順序反過(guò)來(lái)了?
其實(shí)事情也沒有那么簡(jiǎn)單。
Spring AOP執(zhí)行順序
我們先來(lái)回顧下Spring AOP執(zhí)行順序。
我們?cè)诰W(wǎng)上查找關(guān)于SpringAop執(zhí)行順序的的資料，大多數(shù)時(shí)候，你會(huì)查到如下的答案：
正常情況
異常情況
多個(gè)切面的情況
所以@Around理應(yīng)在@After之前，但是在SprinBoot 2.3.4.RELEASE版本中，@Around切切實(shí)實(shí)執(zhí)行在了@After之后。
當(dāng)我嘗試切換回2.2.5.RELEASE版本后，執(zhí)行順序又回到了@Around-->@After
探究順序錯(cuò)誤的真相
既然知道了是SpringBoot版本升級(jí)導(dǎo)致的問題(或者說(shuō)順序變化)，那么就要來(lái)看看究竟是哪個(gè)庫(kù)對(duì)AOP執(zhí)行的順序進(jìn)行了變動(dòng)，畢竟，SpringBoot只是“形”，真正的內(nèi)核在Spring。
我們打開pom.xml文件，使用插件查看spring-aop的版本，發(fā)現(xiàn)SpringBoot 2.3.4.RELEASE 版本使用的AOP是spring-aop-5.2.9.RELEASE。
而2.2.5.RELEASE對(duì)應(yīng)的是spring-aop-5.2.4.RELEASE
于是我去官網(wǎng)搜索文檔，不得不說(shuō)Spring由于過(guò)于龐大，官網(wǎng)的文檔已經(jīng)到了冗雜的地步，不過(guò)最終還是找到了：
https://docs.spring.io/spring-framework/docs/5.2.9.RELEASE/spring-framework-reference/core.html#aop-ataspectj-advice-ordering
As of Spring Framework 5.2.7, advice methods defined in the same @Aspect class that need to run at the same join point are assigned precedence based on their advice type in the following order, from highest to lowest precedence: @Around, @Before, @After, @AfterReturning, @AfterThrowing.
我粗淺的翻譯一下重點(diǎn)：
從Spring5.2.7開始，在相同@Aspect類中，通知方法將根據(jù)其類型按照從高到低的優(yōu)先級(jí)進(jìn)行執(zhí)行：@Around，@Before ，@After，@AfterReturning，@AfterThrowing。
這樣看其實(shí)對(duì)比不明顯，我們?cè)倩氐嚼习姹荆簿褪?.2.5.RELEASE對(duì)應(yīng)的spring-aop-5.2.4.RELEASE，當(dāng)時(shí)的文檔是這么寫的：
What happens when multiple pieces of advice all want to run at the same join point? Spring AOP follows the same precedence rules as AspectJ to determine the order of advice execution. The highest precedence advice runs first "on the way in" (so, given two pieces of before advice, the one with highest precedence runs first). "On the way out" from a join point, the highest precedence advice runs last (so, given two pieces of after advice, the one with the highest precedence will run second).
簡(jiǎn)單翻譯：在相同@Aspect類中Spring AOP遵循與AspectJ相同的優(yōu)先級(jí)規(guī)則來(lái)確定advice執(zhí)行的順序。
再挖深一點(diǎn)，那么AspectJ的優(yōu)先級(jí)規(guī)則是什么樣的?
我找了AspectJ的文檔：
https://www.eclipse.org/aspectj/doc/next/progguide/semantics-advice.html
At a particular join point, advice is ordered by precedence.
A piece of around advice controls whether advice of lower precedence will run by calling proceed. The call to proceed will run the advice with next precedence, or the computation under the join point if there is no further advice.
A piece of before advice can prevent advice of lower precedence from running by throwing an exception. If it returns normally, however, then the advice of the next precedence, or the computation under the join pint if there is no further advice, will run.
Running after returning advice will run the advice of next precedence, or the computation under the join point if there is no further advice. Then, if that computation returned normally, the body of the advice will run.
Running after throwing advice will run the advice of next precedence, or the computation under the join point if there is no further advice. Then, if that computation threw an exception of an appropriate type, the body of the advice will run.
Running after advice will run the advice of next precedence, or the computation under the join point if there is no further advice. Then the body of the advice will run.
大伙又要說(shuō)了，哎呀太長(zhǎng)不看!簡(jiǎn)短地說(shuō)，Aspectj的規(guī)則就是上面我們能夠在網(wǎng)上查閱到的順序圖展示的那樣，依舊是老的順序。
代碼驗(yàn)證
我把業(yè)務(wù)邏輯從代碼中刪除，只驗(yàn)證下這幾個(gè)advice的執(zhí)行順序：
- /**
- * 日志切面
- */
- @Aspect
- @Component
- public class WebLogAspect {
- private final static Logger LOGGER = LoggerFactory.getLogger(WebLogAspect.class);
- /** 以 controller 包下定義的所有請(qǐng)求為切入點(diǎn) */
- @Pointcut("execution(public * com.xx.xxx.xxx.controller..*.*(..))")
- public void webLog() {}
- /**
- * 在切點(diǎn)之前織入
- * @param joinPoint
- * @throws Throwable
- */
- @Before("webLog()")
- public void doBefore(JoinPoint joinPoint) throws Throwable {
- LOGGER.info("-------------doBefore-------------");
- }
- @AfterReturning("webLog()")
- public void afterReturning() {
- LOGGER.info("-------------afterReturning-------------");
- }
- @AfterThrowing("webLog()")
- public void afterThrowing() {
- LOGGER.info("-------------afterThrowing-------------");
- }
- /**
- * 在切點(diǎn)之后織入
- * @throws Throwable
- */
- @After("webLog()")
- public void doAfter() throws Throwable {
- LOGGER.info("-------------doAfter-------------");
- }
- /**
- * 環(huán)繞
- * @param proceedingJoinPoint
- * @return
- * @throws Throwable
- */
- @Around("webLog()")
- public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
- long startTime = System.currentTimeMillis();
- LOGGER.info("-------------doAround before proceed-------------");
- Object result = proceedingJoinPoint.proceed();
- LOGGER.info("-------------doAround after proceed-------------");
- return result;
- }
我們將版本改為2.2.5.RELEASE，結(jié)果如圖：
我們將版本改為2.3.4.RELEASE，結(jié)果如圖：
結(jié)論
經(jīng)過(guò)上面的資料文檔查閱，我能給出的結(jié)論是：
從Spring5.2.7開始，Spring AOP不再嚴(yán)格按照AspectJ定義的規(guī)則來(lái)執(zhí)行advice，而是根據(jù)其類型按照從高到低的優(yōu)先級(jí)進(jìn)行執(zhí)行：@Around，@Before ，@After，@AfterReturning，@AfterThrowing。
這次的研究思考十分倉(cāng)促，如果結(jié)論有誤請(qǐng)大家踴躍指正，也歡迎大家自己嘗試，畢竟口說(shuō)無(wú)憑，實(shí)驗(yàn)室檢驗(yàn)真理的唯一標(biāo)準(zhǔn)!
參考
https://www.cnblogs.com/dennyLee2025/p/13724981.html
https://segmentfault.com/a/1190000011283029
本文轉(zhuǎn)載自微信公眾號(hào)「后端技術(shù)漫談」，可以通過(guò)以下二維碼關(guān)注。轉(zhuǎn)載本文請(qǐng)聯(lián)系后端技術(shù)漫談公眾號(hào)。
