简而言之,我的问题是:为什么 JMH 基准测试结果可以在 fork 中保持稳定,但在 fork 之间却存在显着差异。
我在许多基准测试中都观察到了这一点(通常涉及数据集的处理)。这是一个简单的例子:
import static java.util.concurrent.TimeUnit.*;
import static java.util.stream.Collectors.*;
import java.util.*;
import org.openjdk.jmh.infra.Blackhole;
import org.openjdk.jmh.annotations.*;
@Warmup(iterations = 5, time = 1, timeUnit = SECONDS)
@Measurement(iterations = 15, time = 1, timeUnit = SECONDS)
@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(MICROSECONDS)
@Fork(50)
@State(Scope.Benchmark)
public class AvgTest {
private long[] longs = new Random(1).longs(1000).toArray();
@Benchmark
public void test(Blackhole bh) {
bh.consume(Arrays.stream(longs).boxed().collect(averagingLong(x->x)));
}
}
我使用 5 次一秒预热迭代和 15 次一秒测量迭代。整个过程重复 50 次(连同 JVM 重新启动),如@Fork(50)
. 通常的分叉看起来像这样:
# Run progress: 8,00% complete, ETA 00:15:34
# Fork: 5 of 50
# Warmup Iteration 1: 10,752 us/op
# Warmup Iteration 2: 5,504 us/op
# Warmup Iteration 3: 5,107 us/op
# Warmup Iteration 4: 5,144 us/op
# Warmup Iteration 5: 5,157 us/op
Iteration 1: 5,140 us/op
Iteration 2: 5,157 us/op
Iteration 3: 5,148 us/op
Iteration 4: 5,143 us/op
Iteration 5: 5,153 us/op
Iteration 6: 5,148 us/op
Iteration 7: 5,151 us/op
Iteration 8: 5,143 us/op
Iteration 9: 5,143 us/op
Iteration 10: 5,138 us/op
Iteration 11: 5,144 us/op
Iteration 12: 5,142 us/op
Iteration 13: 5,151 us/op
Iteration 14: 5,144 us/op
Iteration 15: 5,135 us/op
如您所见,每次迭代的结果非常稳定,标准偏差很低。但是有时(可能几十次)我会看到这样的分叉:
# Run progress: 26,00% complete, ETA 00:12:31
# Fork: 14 of 50
# Warmup Iteration 1: 13,482 us/op
# Warmup Iteration 2: 12,800 us/op
# Warmup Iteration 3: 12,140 us/op
# Warmup Iteration 4: 12,102 us/op
# Warmup Iteration 5: 12,094 us/op
Iteration 1: 12,114 us/op
Iteration 2: 12,164 us/op
Iteration 3: 12,263 us/op
Iteration 4: 12,271 us/op
Iteration 5: 12,319 us/op
Iteration 6: 12,309 us/op
Iteration 7: 12,305 us/op
Iteration 8: 12,308 us/op
Iteration 9: 12,257 us/op
Iteration 10: 12,267 us/op
Iteration 11: 12,270 us/op
Iteration 12: 12,285 us/op
Iteration 13: 12,292 us/op
Iteration 14: 12,242 us/op
Iteration 15: 12,253 us/op
结果也相当稳定,但比通常的分叉慢 2 倍以上。
这是每个分叉的摘要(按平均时间排序的分叉数、平均时间和以微秒为单位的标准偏差):
Fork# Mean SD
37 5.142 0.006
23 5.142 0.007
46 5.143 0.014
5 5.145 0.006
15 5.145 0.007
17 5.146 0.011
9 5.147 0.024
47 5.148 0.006
7 5.149 0.005
44 5.149 0.004
33 5.150 0.010
18 5.151 0.006
26 5.151 0.008
11 5.153 0.007
22 5.153 0.005
6 5.154 0.006
12 5.155 0.008
50 5.156 0.006
20 5.157 0.009
45 5.157 0.006
49 5.157 0.010
25 5.160 0.009
34 5.160 0.006
21 5.163 0.009
27 5.163 0.018
16 5.163 0.010
31 5.163 0.014
3 5.165 0.006
29 5.167 0.008
30 5.170 0.033
48 5.174 0.008
_____________________
38 5.210 0.020
8 5.219 0.008
24 5.220 0.005
4 5.224 0.007
39 5.225 0.007
35 5.227 0.006
10 5.229 0.007
13 5.229 0.007
41 5.232 0.005
42 5.232 0.007
40 5.249 0.008
_____________________
36 5.625 0.028
1 5.653 0.032
32 5.669 0.029
19 5.706 0.035
28 5.772 0.051
2 5.858 0.032
_____________________
43 8.948 0.010
14 12.261 0.055
如您所见,对于大多数迭代,平均值落入5.142..5.174 us
区间,然后小跳到5.210..5.249 us
区间,然后大跳到5.625..5.858 us
,然后是两个异常值。原始结果可在此gist中获得。
那么这些跳跃和异常值是什么?是基准测试程序故障还是这样的效果也会出现在生产中,并且我的程序在极少数情况下会变慢 2.5 倍?这是一些与硬件或 JVM 相关的问题吗?我可以在执行开始时预测我是在快速分叉还是慢速分叉?
使用 Oracle JDK 1.8.0_45 和 JMH 1.10.3 在 Windows 7 64 位 Intel i5 QuadCore 系统中执行测量。