JMH 中的分叉之间的基准测试结果不同

Tag*_*eev 6 java performance benchmarking jmh

简而言之,我的问题是:为什么 JMH 基准测试结果在分叉内可以稳定,但分叉之间差异很大。

我在许多基准测试中观察到了这一点(通常涉及数据集的处理)。这是一个简单的例子:

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)));
    }
}
Run Code Online (Sandbox Code Playgroud)

我使用 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 Code Online (Sandbox Code Playgroud)

正如你所看到的,每次迭代的结果非常稳定,标准偏差很低。然而有时(可能是几十次)我会看到这样的叉子:

# 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
Run Code Online (Sandbox Code Playgroud)

结果也相当稳定,但比普通分叉慢 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 
Run Code Online (Sandbox Code Playgroud)

正如您所看到的,对于大多数迭代,平均值落入5.142..5.174 us区间,然后小跳转到5.210..5.249 us区间,然后较大跳转到5.625..5.858 us,然后是两个异常值。原始结果可在本要点中找到。

那么这些跳跃和异常值是什么?是否是基准测试程序出现故障,或者这种效果也会出现在生产中,并且我的程序在极少数情况下会变慢 2.5 倍?这是与硬件或 JVM 相关的问题吗?我可以在执行开始时预测我是处于快分叉还是慢速分叉吗?

测量是在 Windows 7 64 位 Intel i5 QuadCore 系统中使用 Oracle JDK 1.8.0_45 和 JMH 1.10.3 进行的。