我写了一个 JMH 基准测试，涉及 2 个方法:M1 和 M2。 M1 调用 M2，但出于某种原因，JMH 声称 M1 比 M2 快。
这是基准源代码:
import java.util.concurrent.TimeUnit;
import static org.bitbucket.cowwoc.requirements.Requirements.assertThat;
import static org.bitbucket.cowwoc.requirements.Requirements.requireThat;
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.runner.Runner;
import org.openjdk.jmh.runner.RunnerException;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;
@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
public class MyBenchmark {
@Benchmark
public void assertMethod() {
assertThat("value", "name").isNotNull().isNotEmpty();
}
@Benchmark
public void requireMethod() {
requireThat("value", "name").isNotNull().isNotEmpty();
}
public static void main(String[] args) throws RunnerException {
Options opt = new OptionsBuilder()
.include(MyBenchmark.class.getSimpleName())
.forks(1)
.build();
new Runner(opt).run();
}
}
在上面的例子中，M1是assertThat()，M2是requireThat()。意思是，assertThat() 在后台调用了 requireThat()。
这是基准输出:
# JMH 1.13 (released 8 days ago)
# VM version: JDK 1.8.0_102, VM 25.102-b14
# VM invoker: C:\Program Files\Java\jdk1.8.0_102\jre\bin\java.exe
# VM options: -ea
# Warmup: 20 iterations, 1 s each
# Measurement: 20 iterations, 1 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: com.mycompany.jmh.MyBenchmark.assertMethod
# Run progress: 0.00% complete, ETA 00:01:20
# Fork: 1 of 1
# Warmup Iteration 1: 8.268 ns/op
# Warmup Iteration 2: 6.082 ns/op
# Warmup Iteration 3: 4.846 ns/op
# Warmup Iteration 4: 4.854 ns/op
# Warmup Iteration 5: 4.834 ns/op
# Warmup Iteration 6: 4.831 ns/op
# Warmup Iteration 7: 4.815 ns/op
# Warmup Iteration 8: 4.839 ns/op
# Warmup Iteration 9: 4.825 ns/op
# Warmup Iteration 10: 4.812 ns/op
# Warmup Iteration 11: 4.806 ns/op
# Warmup Iteration 12: 4.805 ns/op
# Warmup Iteration 13: 4.802 ns/op
# Warmup Iteration 14: 4.813 ns/op
# Warmup Iteration 15: 4.805 ns/op
# Warmup Iteration 16: 4.818 ns/op
# Warmup Iteration 17: 4.815 ns/op
# Warmup Iteration 18: 4.817 ns/op
# Warmup Iteration 19: 4.812 ns/op
# Warmup Iteration 20: 4.810 ns/op
Iteration 1: 4.805 ns/op
Iteration 2: 4.816 ns/op
Iteration 3: 4.813 ns/op
Iteration 4: 4.938 ns/op
Iteration 5: 5.061 ns/op
Iteration 6: 5.129 ns/op
Iteration 7: 4.828 ns/op
Iteration 8: 4.837 ns/op
Iteration 9: 4.819 ns/op
Iteration 10: 4.815 ns/op
Iteration 11: 4.872 ns/op
Iteration 12: 4.806 ns/op
Iteration 13: 4.811 ns/op
Iteration 14: 4.827 ns/op
Iteration 15: 4.837 ns/op
Iteration 16: 4.842 ns/op
Iteration 17: 4.812 ns/op
Iteration 18: 4.809 ns/op
Iteration 19: 4.806 ns/op
Iteration 20: 4.815 ns/op
Result "assertMethod":
4.855 �(99.9%) 0.077 ns/op [Average]
(min, avg, max) = (4.805, 4.855, 5.129), stdev = 0.088
CI (99.9%): [4.778, 4.932] (assumes normal distribution)
# JMH 1.13 (released 8 days ago)
# VM version: JDK 1.8.0_102, VM 25.102-b14
# VM invoker: C:\Program Files\Java\jdk1.8.0_102\jre\bin\java.exe
# VM options: -ea
# Warmup: 20 iterations, 1 s each
# Measurement: 20 iterations, 1 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: com.mycompany.jmh.MyBenchmark.requireMethod
# Run progress: 50.00% complete, ETA 00:00:40
# Fork: 1 of 1
# Warmup Iteration 1: 7.193 ns/op
# Warmup Iteration 2: 4.835 ns/op
# Warmup Iteration 3: 5.039 ns/op
# Warmup Iteration 4: 5.053 ns/op
# Warmup Iteration 5: 5.077 ns/op
# Warmup Iteration 6: 5.102 ns/op
# Warmup Iteration 7: 5.088 ns/op
# Warmup Iteration 8: 5.109 ns/op
# Warmup Iteration 9: 5.096 ns/op
# Warmup Iteration 10: 5.096 ns/op
# Warmup Iteration 11: 5.091 ns/op
# Warmup Iteration 12: 5.089 ns/op
# Warmup Iteration 13: 5.099 ns/op
# Warmup Iteration 14: 5.097 ns/op
# Warmup Iteration 15: 5.090 ns/op
# Warmup Iteration 16: 5.096 ns/op
# Warmup Iteration 17: 5.088 ns/op
# Warmup Iteration 18: 5.086 ns/op
# Warmup Iteration 19: 5.087 ns/op
# Warmup Iteration 20: 5.097 ns/op
Iteration 1: 5.097 ns/op
Iteration 2: 5.088 ns/op
Iteration 3: 5.092 ns/op
Iteration 4: 5.097 ns/op
Iteration 5: 5.082 ns/op
Iteration 6: 5.089 ns/op
Iteration 7: 5.086 ns/op
Iteration 8: 5.084 ns/op
Iteration 9: 5.090 ns/op
Iteration 10: 5.086 ns/op
Iteration 11: 5.084 ns/op
Iteration 12: 5.088 ns/op
Iteration 13: 5.091 ns/op
Iteration 14: 5.092 ns/op
Iteration 15: 5.085 ns/op
Iteration 16: 5.096 ns/op
Iteration 17: 5.078 ns/op
Iteration 18: 5.125 ns/op
Iteration 19: 5.089 ns/op
Iteration 20: 5.091 ns/op
Result "requireMethod":
5.091 �(99.9%) 0.008 ns/op [Average]
(min, avg, max) = (5.078, 5.091, 5.125), stdev = 0.010
CI (99.9%): [5.082, 5.099] (assumes normal distribution)
# Run complete. Total time: 00:01:21
Benchmark Mode Cnt Score Error Units
MyBenchmark.assertMethod avgt 20 4.855 � 0.077 ns/op
MyBenchmark.requireMethod avgt 20 5.091 � 0.008 ns/op
在本地重现:
创建一个包含上述基准的 Maven 项目。
添加如下依赖:
<dependency> <groupId>org.bitbucket.cowwoc</groupId> <artifactId>requirements</artifactId> <version>2.0.0</version> </dependency>
我有以下问题:
- 你能重现这个结果吗？
- 基准测试有什么问题(如果有的话)？
更新:我终于得到了一致的、有意义的结果。
Benchmark Mode Cnt Score Error Units
MyBenchmark.assertMethod avgt 60 22.552 ± 0.020 ns/op
MyBenchmark.requireMethod avgt 60 22.411 ± 0.114 ns/op
通过一致，我的意思是我在运行中得到几乎相同的值。
有意义，我的意思是 assertMethod() 比 requireMethod() 慢。
我做了以下更改:
- 锁定 CPU 时钟(在 Windows 电源选项中将最小/最大 CPU 设置为 99%)
- 添加了 JVM 选项
-XX:-TieredCompilation -XX:-ProfileInterpreter
有没有人能够在不将运行时间加倍的情况下实现这些结果？
UPDATE2:禁用内联会产生相同的结果，而不会明显降低性能。我发布了更详细的答案 here .
最佳答案
在这种特殊情况下，由于寄存器分配问题，assertMethod 确实比 requireMethod 编译得更好。
基准测试看起来是正确的，我可以始终如一地重现您的结果。
分析我做的问题the simplified benchmark :
package bench;
import com.google.common.collect.ImmutableMap;
import org.openjdk.jmh.annotations.*;
@State(Scope.Benchmark)
public class Requirements {
private static boolean enabled = true;
private String name = "name";
private String value = "value";
@Benchmark
public Object assertMethod() {
if (enabled)
return requireThat(value, name);
return null;
}
@Benchmark
public Object requireMethod() {
return requireThat(value, name);
}
public static Object requireThat(String parameter, String name) {
if (name.trim().isEmpty())
throw new IllegalArgumentException();
return new StringRequirementsImpl(parameter, name, new Configuration());
}
static class Configuration {
private Object context = ImmutableMap.of();
}
static class StringRequirementsImpl {
private String parameter;
private String name;
private Configuration config;
private ObjectRequirementsImpl asObject;
StringRequirementsImpl(String parameter, String name, Configuration config) {
this.parameter = parameter;
this.name = name;
this.config = config;
this.asObject = new ObjectRequirementsImpl(parameter, name, config);
}
}
static class ObjectRequirementsImpl {
private Object parameter;
private String name;
private Configuration config;
ObjectRequirementsImpl(Object parameter, String name, Configuration config) {
this.parameter = parameter;
this.name = name;
this.config = config;
}
}
}
首先，我已经通过 -XX:+PrintInlining 验证了整个基准测试被内联到一个大方法中。显然这个编译单元有很多节点，而且没有足够的 CPU 寄存器来保存所有的中间变量。也就是说，编译器需要 spill其中一些。
- 在
assertMethod中 4 registers在调用trim()之前溢出到堆栈。 - 在
requireMethod中7 registers在调用new Configuration()之后溢出。
-XX:+PrintAssembly 输出:
assertMethod | requireMethod
-------------------------|------------------------
mov %r11d,0x5c(%rsp) | mov %rcx,0x20(%rsp)
mov %r10d,0x58(%rsp) | mov %r11,0x48(%rsp)
mov %rbp,0x50(%rsp) | mov %r10,0x30(%rsp)
mov %rbx,0x48(%rsp) | mov %rbp,0x50(%rsp)
| mov %r9d,0x58(%rsp)
| mov %edi,0x5c(%rsp)
| mov %r8,0x60(%rsp)
这几乎是两种编译方法除了if (enabled)检查之外唯一的区别。因此，性能差异可以用更多变量溢出到内存来解释。
为什么较小的方法编译得不太理想？好吧，众所周知，寄存器分配问题是 NP 完全问题。由于无法在合理的时间内理想地解决，因此编译器通常依赖于某些启发式方法。在大方法中，像额外的 if 这样的小东西可能会显着改变寄存器分配算法的结果。
但是您不必担心这一点。我们看到的效果并不意味着 requireMethod 总是被编译得更糟。在其他用例中，由于内联，编译图将完全不同。无论如何，1 纳秒的差异对实际应用程序性能来说毫无意义。
关于java - jmh 表示 M1 比 M2 快，但 M1 委托(delegate)给 M2，我们在Stack Overflow上找到一个类似的问题： https://stackoverflow.com/questions/38686958/