前阵子有个用户调用劵列表一直超时,后面经过性能排查:发现这个用户下面有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, 看似真的影响不大。
不过具体问题还是具体分析吧,只有了解原理遇到问题时才能有效的快速定位到原因~。