背景
轉眼之間，發現部落格已經將近半年沒更新了，甚是慚愧。話不多說，正如標題所言，最近在使用AspectJ的時候，發現攔截器（AOP切面）執行了兩次了。我們知道，AspectJ是AOP的一種解決方案，本質上是通過代理類在目標方法執行通知（Advice），然後由代理類再去呼叫目標方法。所以，從這點講，攔截器應該只會執行一次。但是在測試的時候發現攔截器執行了兩次。

問題重現
既然問題已經明瞭，那麼可以通過程式碼簡單重現這個問題，從而更深層次分析到底是什麼原因導致的。

定義一個註解：

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分析
由於是靜態織入，所以可以通過反編譯工具檢視編譯後的檔案，如下：

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（），所以我們才看到了兩次輸出。

method-call和method-execution都是連線點ProceedingJoinPoint的kind屬性

其實，這屬於Ajc編譯器的一個Bug，詳見Ajc-bug

所以，到這一步，問題就很清晰了，因為Ajc編輯器的bug，導致了在main方法中也織入了通知，所以在執行的時候，輸出了兩次日誌。

解決方法

方案一
因為兩次呼叫的kind屬性不一樣，所以可以通過kind屬性來判斷時候呼叫切面。這樣顯得不優雅，而且如果切面有更多的邏輯的話，需要加各種if-else的判斷，所以不推薦。

方法二
更優雅的方案是修改@Around("@annotation(StatsService)")的邏輯，改為@Around("execution(* *(..)) && @annotation(StatsService)")。

重新執行上面的測試類，結果如下：