1. 程式人生 > 程式設計 >基於AspectJ增強程式碼,實現一行註解記錄方法執行耗時

基於AspectJ增強程式碼,實現一行註解記錄方法執行耗時

背景

因需要對專案中的方法執行進行效能測試,如果在每個方法前後都加上如下程式碼

long beginTime = System.currentTimeMillis(); 
long endTime = System.currentTimeMillis(); 
long timeConsume = endTime - beginTime; 
複製程式碼

顯然會讓程式碼變得非常冗雜,而且需要統計效能的地方可能還會有很多,如果可以單純在方法上加上一個註解,就能實現方法執行耗時的記錄,這樣便能減少許多簡單且繁瑣的程式碼,更加方便的擴充套件

技術選型

像這種場景就是典型的AOP場景,搜尋SpringAOP就能找到很多的程式碼樣例,但是專案並不依賴於Spring, 也沒有必要引入Spring。通常要實現這樣的功能,有兩種方案,一種是像SpringAOP那樣,通過CGLib動態代理或JDK動態代理,在建立物件的時候,動態地生成代理類的物件,另一種是AspectJ,在編譯程式碼的時候就將需要執行的邏輯織入到位元組碼中。

對於動態代理,需要建立代理類的物件,才可以增強,而專案中,存在很多靜態方法,在使用的時候並不通過物件來呼叫,而且即便是通過物件來呼叫的方法,沒有Spring方便的IOC機制,也得修改所有程式碼中new物件的處理,才可以使用增強後的代理物件,略麻煩。而且如果是頻繁的建立物件,因為還有一步建立代理物件的操作,效能上會有一定的損失。

對於AspectJ這種方式,則可以對滿足切點表示式的地方,都織入增強後的邏輯,但是需要依賴於織入工具的協助,來對編譯後的位元組碼進行增強。幸好maven上已經有對應的aspectj編譯外掛,可以很方便的處理織入

綜合考慮之下,決定採用自定義註解(指定目標)+ ApsectJ(Aop增強) + aspectj的Maven編譯外掛來實現

技術實現

1、自定義註解

@Retention(RetentionPolicy.RUNTIME) 
@Target(ElementType.METHOD) 
public @interface TimeConsumeLogAnnotation { 

} 
複製程式碼

2、引入Aspectj依賴

<dependency> 
​    <groupId>org.aspectj</groupId> 
​    <artifactId>aspectjrt</artifactId> 
​    <version>1.8.9</version> 
</dependency> 
複製程式碼

3、Aspectj切面

@Aspect 
public class TimeConsumeLogAspectJ { 
​    //通過ThreadLocal隔離不同執行緒的變數 
​    ThreadLocal<Long> timeRecord = new ThreadLocal<>(); 

​    @Pointcut("execution(* *(..)) && @annotation(cn.freekiddo.annotation.TimeConsumeLogAnnotation)") 
​    public void jointPoint(){} 

​    @Before("jointPoint()") 
​    public void doBefore(JoinPoint joinPoint){ 
​        MethodSignature signature = (MethodSignature) joinPoint.getSignature(); 
​        Method method = signature.getMethod(); 
​        System.out.println("方法" + method.getName() + "開始"); 
​        timeRecord.set(System.currentTimeMillis()); 
​    } 

​    @After("jointPoint()") 
​    public void doAfter(JoinPoint joinPoint){ 
​        long beginTime = timeRecord.get(); 
​        System.out.println("方法" +joinPoint.getSignature().getName()+ "結束,耗時"+(System.currentTimeMillis()-beginTime) +"ms"); 
​    } 
} 
複製程式碼

4、引入maven編譯外掛

在maven-compiler-plugin處理完之後再工作

<plugin> 
​    <groupId>org.codehaus.mojo</groupId> 
​    <artifactId>aspectj-maven-plugin</artifactId> 
​    <version>1.10</version> 
​    <configuration> 
​        <source>1.8</source> 
​        <target>1.8</target> 
​        <complianceLevel>1.8</complianceLevel> 
​    </configuration> 
​    <executions> 
​        <execution> 
​            <phase>compile</phase> 
​            <goals> 
​                <goal>compile</goal> 
​            </goals> 
​        </execution> 
​    </executions> 
</plugin> 
複製程式碼

5、在目標方法上加入@TimeConsumeLogAnnotation註解編譯執行即可

@TimeConsumeLogAnnotation() 
public static void sayHelloWorld(String name) { 
​    System.out.println("Hello " + name); 
} 
複製程式碼

編譯後的位元組碼

@TimeConsumeLogAnnotation 
public static void sayHelloWorld(String name) { 
​    JoinPoint var1 = Factory.makeJP(ajc$tjp_0,(Object)null,name); 
​    try { 
​        TimeConsumeLogAspectJ.aspectOf().doBefore(var1); 
​        System.out.println("Hello " + name); 
​    } catch (Throwable var4) { 
​        TimeConsumeLogAspectJ.aspectOf().doAfter(var1); 
​        throw var4; 
​    } 
​    TimeConsumeLogAspectJ.aspectOf().doAfter(var1); 
} 
複製程式碼

效果

方法sayHelloWorld開始 
Hello world 
方法sayHelloWorld結束,耗時1ms 
複製程式碼

6、踩過的坑

(1)切面執行兩次

在一開始切面的表示式為

@Pointcut("@annotation(cn.freekiddo.annotation.TimeConsumeLogAnnotation)") 
複製程式碼

而aspectj的編譯器會識別出方法呼叫方法執行兩個階段的切入點,因為會在這兩個階段都執行

通過將切面表示式修改為

@Pointcut("execution(* *(..)) && @annotation(cn.freekiddo.annotation.TimeConsumeLogAnnotation)") 
複製程式碼

可以限定成只識別方法執行這個階段

(2)多模組專案aspectj編譯失敗

如果在多模組專案,在具體的某個子模組宣告切面類,定義切點表示式,但是連線點切分散在各個其他模組時,ajc掃描具到切點表示式時,只會在本模組掃描對應的連線點,其他模組的連線點是沒有辦法編繹期切入切面,ajc是不會在編繹其他模組時再去掃描有沒有某個切點表示式與當前連線點匹配的

通過在每個模組都加上自定義註解和切面,可解決編譯的問題

更多的操作

由於自定義註解支援賦值,Aspectj切面又可以攔截到方法,並且通過反射獲取到方法引數,因此可以在這基礎做更多定製化的優化

參考連結

Spring AOP 實現原理與 CGLIB 應用

關於AspectJ你可能不知道的事

AspectJ切面執行兩次原因分析

多模組maven專案使用Eclipse的 AspectJ編繹期織入