前陣子有個用戶調用劵列表一直超時,后面經過性能排查:發現這個用戶下面有8000多張劵,db查詢花了10多毫秒。但是對象從entity到dto的復制卻花了幾百毫秒,后面定位到性能瓶頸是出現在了ApacheBeanUtils的org.apache.commons.beanutils.BeanUtils#copyProperties方法上面,復制8000多個對象花了幾百毫秒。
通過閱讀源碼發現了org.apache.commons.beanutils.BeanUtils#copyProperties的時間主要花在兩個地方:1、反射創建對象 2、值復制的類型轉換。 原來ApacheBeanUtils提供的copyProperties除了支持相同類型相同名稱的字段復制以外,還支持基本類型到包裝類型,包裝類型到基本類型, Date轉string,long 這些功能,只要字段名稱相同ApacheBeanUtils會盡可能進行類型轉換然后復制。ApacheBeanUtils的值復制是通過conveter進行的。有興趣的同學可以中央倉庫下載相應的源碼去了解。
beanutils --> <dependency> <groupId>commons-beanutils</groupId> <artifactId>commons-beanutils</artifactId> <version>1.9.1</version> </dependency>
具體包路徑是org/apache/commons/beanutils/converters下面可以看到各種各樣的converters。
后面也查明了性能瓶頸主要卡在了類型轉換這里。
上面提到了org.apache.commons.beanutils.BeanUtils#copyProperties的時間主要花在兩個地方:1、反射創建對象 2、值復制的類型轉換。那反射對性能的影響到底有多大呢,下面我們來探討一下。
反射是java語言的一個很重要的特性,它可以遍歷對象的屬性,方法。甚至動態去修改對象的值和行為,突破私有字段的保護機制,訪問並修改對象的私有字段。很多底層的框架的都利用了反射的特性, 比如spring的IOC就是利用了反射。
下面來分析一下的反射的方法調用:
這一段代碼,通過打印異常的堆棧,得到反射的方法調用鏈
public class ReflectTest { public void target(int i ){ new Exception("#" + i).printStackTrace(); } public static void main(String[] args) throws Exception { ReflectTest instance = ReflectTest.class.newInstance(); Method method = ReflectTest.class.getMethod("target", int.class); method.invoke(instance,1); } }
java.lang.Exception: #1
at ReflectTest.target(ReflectTest.java:7)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at ReflectTest.main(ReflectTest.java:13)
其中NativeMethodAccessorImpl表示調用的是本地的C++方法。所以我們知道了反射的方法調用是會經過java -> c++ ->java 的轉換,所以這個過程看上去的確是比較耗時。。。。這里簡稱這個為本地實現
既然本地實現的方法可能會比較耗時那么有沒有不用調用本地方法實現呢?其實是有的。在默認的JAVA反射機制里面如果反射的方法的調用次數超過一個閥值15,則會用有動態生成的字節碼去代替本地的C++方法調用,即動態實現。
看代碼:
public class ReflectTest { public void target(int i ){ if(i % 10 == 0) { new Exception("#" + i).printStackTrace(); } } public static void main(String[] args) throws Exception { ReflectTest instance = ReflectTest.class.newInstance(); Method method = ReflectTest.class.getMethod("target", int.class); int i = 0; while(i < 30) { method.invoke(instance, i++); } } } java.lang.Exception: #0 at ReflectTest.target(ReflectTest.java:7) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at ReflectTest.main(ReflectTest.java:16) java.lang.Exception: #10 at ReflectTest.target(ReflectTest.java:7) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at ReflectTest.main(ReflectTest.java:16) java.lang.Exception: #20 at ReflectTest.target(ReflectTest.java:7) at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at ReflectTest.main(ReflectTest.java:16)
看到最后一段輸出已經沒有了NativeMethodAccessorImpl的調用,取而代之的是GeneratedMethodAccessor1的調用。
這里會有個疑問就是既然動態實現不需要經過JAVA到C++的轉換那為什么一開始不用動態實現而是用本地實現呢?那是因為JAVA認為大部分的反射方法調用一般只調用一次或者幾次,而動態實現的第一次調用是要生成字節碼,這個是很耗費時間的,性能是本地實現的三到四倍。
ok,那現在我們知道了反射的方法調用過程。那具體是怎么調用的呢, 這就需要深入到字節碼的里面去看一下。把上面的代碼改一下:
import java.lang.reflect.Method; public class ReflectTest { public void target(int i ){ new Exception("#" + i).printStackTrace(); } public static void main(String[] args) throws Exception { ReflectTest instance = ReflectTest.class.newInstance(); Method method = ReflectTest.class.getMethod("target", int.class); int i = 128; method.invoke(instance, i); } }
編譯成class文件后用javap 命令查看,具體命令是: javap -p -v ReflectTest
public static void main(java.lang.String[]) throws java.lang.Exception; descriptor: ([Ljava/lang/String;)V flags: ACC_PUBLIC, ACC_STATIC Code: stack=6, locals=4, args_size=1 0: ldc #11 // class ReflectTest 2: invokevirtual #12 // Method java/lang/Class.newInstance:()Ljava/lang/Object; 5: checkcast #11 // class ReflectTest 8: astore_1 9: ldc #11 // class ReflectTest 11: ldc #13 // String target 13: iconst_1 14: anewarray #14 // class java/lang/Class 17: dup 18: iconst_0 19: getstatic #15 // Field java/lang/Integer.TYPE:Ljava/lang/Class; 22: aastore 23: invokevirtual #16 // Method java/lang/Class.getMethod:(Ljava/lang/String;[Ljava/lang/Class;)Ljava/lang/reflect/Method;
看到main方法的19:getstatic #15 和 23:invokevirtual
再結合Methond.invoke方法描述:public Object invoke(Object obj, Object... args)
所以我們知道 Method.invoke 是一個變長參數方法,所有參數都會封入一個Object[] args的數組中。 則傳入的參數int i 會進行一次裝箱的操作。其原因是因為Object[] args不支持基本類型的存儲,如果方法的調用次數非常頻繁這里就存在的兩個性能的隱患:
第一:頻繁的裝箱操作影響性能
第二:大量的裝箱對象導致GC
下面我們驗證一下:
import java.lang.reflect.Method; public class ReflectTest { public void target(int i ){ // new Exception("#" + i).printStackTrace(); } public static void main(String[] args) throws Exception { ReflectTest instance = ReflectTest.class.newInstance(); Method method = ReflectTest.class.getMethod("target", int.class); for(int i = 0; i < 30000000; i++) method.invoke(instance, i); } } 虛擬機參數加上: -XX:+PrintGc [GC (Allocation Failure) 33280K->504K(125952K), 0.0019714 secs] [GC (Allocation Failure) 33784K->536K(125952K), 0.0008074 secs] [GC (Allocation Failure) 33816K->472K(125952K), 0.0006326 secs] [GC (Allocation Failure) 33752K->472K(159232K), 0.0010250 secs] [GC (Allocation Failure) 67032K-fnj>504K(159232K), 0.0007691 secs] [GC (Allocation Failure) 67064K->472K(221696K), 0.0011877 secs] [GC (Allocation Failure) 133592K->424K(221696K), 0.0047642 secs] [GC (Allocation Failure) 133544K->424K(354816K), 0.0003638 secs] [GC (Allocation Failure) 266664K->424K(354816K), 0.0006019 secs] [GC (Allocation Failure) 266664K->424K(514560K), 0.0004477 secs] [GC (Allocation Failure) 426408K->424K(514560K), 0.0006819 secs] [GC (Allocation Failure) 426408K->424K(770560K), 0.0003766 secs]
在調用次數非常多的情況的確認會引發GC,所以反射的方法調用有時確實會很影響性能。。。
下面我們就用JMH(一個性能基准測試框架)來進行一個量化分析:
ReflectTest#target改成:
public void target(int i ){ for (int j = 0; j < 10000; j++) i++; }
然后運行下面程序:
import org.openjdk.jmh.annotations.Benchmark; import org.openjdk.jmh.annotations.BenchmarkMode; import org.openjdk.jmh.annotations.Mode; import org.openjdk.jmh.annotations.OutputTimeUnit; import org.openjdk.jmh.annotations.Scope; import org.openjdk.jmh.annotations.Setup; import org.openjdk.jmh.annotations.State; import org.openjdk.jmh.runner.Runner; import org.openjdk.jmh.runner.RunnerException; import org.openjdk.jmh.runner.options.Options; import org.openjdk.jmh.runner.options.OptionsBuilder; import java.lang.reflect.InvocationTargetException; import java.lang.reflect.Method; import java.util.concurrent.TimeUnit; @BenchmarkMode(Mode.AverageTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) @State(Scope.Thread) public class ReflectTestBenchMark { private ReflectTest reflectTest; private Method method; private ReflectTest instance; @Setup public void setUp() throws NoSuchMethodException, IllegalAccessException, InstantiationException { reflectTest = new ReflectTest(); method = ReflectTest.class.getMethod("target",int.class); instance = ReflectTest.class.newInstance(); } @Benchmark public void testNormalInvoke(){ for(int i = 0; i < 100000; i++){ reflectTest.target(i); } } @Benchmark public void testReflectInvoke() throws InvocationTargetException, IllegalAccessException { for(int i = 0; i < 100000; i++){ method.invoke(instance,i); } } public static void main(String[] args) throws RunnerException { Options opt = new OptionsBuilder() .include(ReflectTestBenchMark.class.getSimpleName()) .forks(1) .warmupIterations(5) .measurementIterations(5) .build(); new Runner(opt).run(); } }
測得結果如下:
Benchmark Mode Cnt Score Error Units ReflectTestBenchMark.testNormalInvoke avgt 5 0.001 ± 0.001 us/op ReflectTestBenchMark.testReflectInvoke avgt 5 382.222 ± 14.693 us/op
這里的結果是單次testNormalInvoke,testReflectInvoke平均調用時間,單位是微秒。上面顯示了100000次的target方法調用,反射的方法調用只比沒有用反射的調用慢了大概382us,還不到1ms, 看似真的影響不大。
不過具體問題還是具體分析吧,只有了解原理遇到問題時才能有效的快速定位到原因~。