要するに、私の質問は、なぜ 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)));
}
}
1 秒のウォームアップを 5 回繰り返し、1 秒の測定を 15 回繰り返します。で指定されているように、手順全体が (JVM の再起動と共に) 50 回繰り返されます@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
ご覧のとおり、反復ごとの結果は非常に安定しており、標準偏差は低くなっています。ただし、時々 (おそらく数十回に 1 回)、次のようなフォークが表示されます。
# 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
ご覧のとおり、ほとんどの反復で、平均値は interval に分類され5.142..5.174 us、次に interval に小さなジャンプが5.210..5.249 usあり、次に に大きなジャンプが5.625..5.858 usあり、次に 2 つの外れ値があります。生の結果は、このgistで入手できます。
では、これらのジャンプと外れ値とは何ですか? ベンチマーク手順の不具合ですか、それともそのような影響が本番環境でも発生し、まれに私のプログラムが 2.5 倍遅くなることがありますか? これはハードウェアまたは JVM 関連の問題ですか? 実行の開始時に、自分が高速フォークか低速フォークかを予測できますか?
測定は、Oracle JDK 1.8.0_45 および JMH 1.10.3 を使用して、Windows 7 64 ビット Intel i5 QuadCore システムで実行されました。