Java 代码性能基准测试

1、问题背景

long start = System.currentTimeMillis();
// ....
long end = System.currentTimeMillis();
System.out.println(end - start);
1
2
3
4

上面可能就是你最常见的性能测试了，这样的测试结果真的准确吗？答案是否定的，它有下面几个问题。

时间精度问题，本身获取到的时间戳就是存在误差的，它和操作系统有关。
JVM 在运行时会进行代码预热，说白了就是越跑越快。因为类需要装载、需要准备操作。
JVM 会在各个阶段都有可能对你的代码进行优化处理。
资源回收的不确定性，可能运行很快，回收很慢。
带着这些问题，突然发现进行一次严格的基准测试的难度大大增加。那么如何才能进行一次严格的基准测试呢？

2、JMH介绍

JMH 的全名是 Java Microbenchmark Harness，它是由 Java 虚拟机团队开发的一款用于 Java 微基准测试工具。用自己开发的工具测试自己开发的另一款工具，使用 JMH 可以让你方便快速的进行一次严格的代码基准测试，并且有多种测试模式，多种测试维度可供选择；而且使用简单、增加注解便可启动测试

3、JMH使用

<!--jmh 基准测试 -->
<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-core</artifactId>
    <version>1.23</version>
</dependency>
<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-generator-annprocess</artifactId>
    <version>1.23</version>
    <scope>provided</scope>
</dependency>
1
2
3
4
5
6
7
8
9
10
11
12

下面使用注解的方式指定测试参数，通过一个例子展示 JMH 基准测试的具体用法，先看一次运行效果，然后再了解每个注解的具体含义。

这个例子是使用 JMH 测试，使用加号拼接字符串和使用 StringBuilder 的 append 方法拼接字符串时的速度如何，每次拼接 1000 个数字进行平均速度比较。

package cn.haochen.jmhdemo;

import java.util.concurrent.TimeUnit;
import org.openjdk.jmh.annotations.*;
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)
@State(Scope.Thread)
@Fork(1)
@OutputTimeUnit(TimeUnit.MILLISECONDS)
@Warmup(iterations = 3)
@Measurement(iterations = 5)
public class JmhHello {

    String string = "";
    StringBuilder stringBuilder = new StringBuilder();

    @Benchmark
    public String stringAdd() {
        for (int i = 0; i < 1000; i++) {
            string = string + i;
        }
        return string;
    }

    @Benchmark
    public String stringBuilderAppend() {
        for (int i = 0; i < 1000; i++) {
            stringBuilder.append(i);
        }
        return stringBuilder.toString();
    }

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(JmhHello.class.getSimpleName())
                .build();
        new Runner(opt).run();
    }
}

```bash
D:\application\java\jdk\bin\java.exe "-javaagent:D:\application\idea\IntelliJ IDEA 2021.2.1\lib\idea_rt.jar=50133:D:\application\idea\IntelliJ IDEA 2021.2.1\bin" -Dfile.encoding=UTF-8 -classpath D:\application\java\jdk\jre\lib\charsets.jar;D:\application\java\jdk\jre\lib\deploy.jar;D:\application\java\jdk\jre\lib\ext\access-bridge-64.jar;D:\application\java\jdk\jre\lib\ext\cldrdata.jar;D:\application\java\jdk\jre\lib\ext\dnsns.jar;D:\application\java\jdk\jre\lib\ext\jaccess.jar;D:\application\java\jdk\jre\lib\ext\jfxrt.jar;D:\application\java\jdk\jre\lib\ext\localedata.jar;D:\application\java\jdk\jre\lib\ext\nashorn.jar;D:\application\java\jdk\jre\lib\ext\sunec.jar;D:\application\java\jdk\jre\lib\ext\sunjce_provider.jar;D:\application\java\jdk\jre\lib\ext\sunmscapi.jar;D:\application\java\jdk\jre\lib\ext\sunpkcs11.jar;D:\application\java\jdk\jre\lib\ext\zipfs.jar;D:\application\java\jdk\jre\lib\javaws.jar;D:\application\java\jdk\jre\lib\jce.jar;D:\application\java\jdk\jre\lib\jfr.jar;D:\application\java\jdk\jre\lib\jfxswt.jar;D:\application\java\jdk\jre\lib\jsse.jar;D:\application\java\jdk\jre\lib\management-agent.jar;D:\application\java\jdk\jre\lib\plugin.jar;D:\application\java\jdk\jre\lib\resources.jar;D:\application\java\jdk\jre\lib\rt.jar;D:\workplace\gitcode\jmhdemo\target\classes;C:\Users\浩宸\.m2\repository\org\openjdk\jmh\jmh-core\1.23\jmh-core-1.23.jar;C:\Users\浩宸\.m2\repository\net\sf\jopt-simple\jopt-simple\4.6\jopt-simple-4.6.jar;C:\Users\浩宸\.m2\repository\org\apache\commons\commons-math3\3.2\commons-math3-3.2.jar cn.haochen.jmhdemo.JmhHello
# JMH version: 1.23
# VM version: JDK 1.8.0_211, Java HotSpot(TM) 64-Bit Server VM, 25.211-b12
# VM invoker: D:\application\java\jdk\jre\bin\java.exe
# VM options: -javaagent:D:\application\idea\IntelliJ IDEA 2021.2.1\lib\idea_rt.jar=50133:D:\application\idea\IntelliJ IDEA 2021.2.1\bin -Dfile.encoding=UTF-8
# Warmup: 3 iterations, 10 s each
# Measurement: 5 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: cn.haochen.jmhdemo.JmhHello.stringAdd

# Run progress: 0.00% complete, ETA 00:02:40
# Fork: 1 of 1
# Warmup Iteration   1: 116.722 ms/op
# Warmup Iteration   2: 155.600 ms/op
# Warmup Iteration   3: 145.764 ms/op
Iteration   1: 195.496 ms/op
Iteration   2: 251.977 ms/op
Iteration   3: 298.298 ms/op
Iteration   4: 310.489 ms/op
Iteration   5: 347.816 ms/op


Result "cn.haochen.jmhdemo.JmhHello.stringAdd":
  280.815 ±(99.9%) 226.061 ms/op [Average]
  (min, avg, max) = (195.496, 280.815, 347.816), stdev = 58.707
  CI (99.9%): [54.754, 506.876] (assumes normal distribution)


# JMH version: 1.23
# VM version: JDK 1.8.0_211, Java HotSpot(TM) 64-Bit Server VM, 25.211-b12
# VM invoker: D:\application\java\jdk\jre\bin\java.exe
# VM options: -javaagent:D:\application\idea\IntelliJ IDEA 2021.2.1\lib\idea_rt.jar=50133:D:\application\idea\IntelliJ IDEA 2021.2.1\bin -Dfile.encoding=UTF-8
# Warmup: 3 iterations, 10 s each
# Measurement: 5 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: cn.haochen.jmhdemo.JmhHello.stringBuilderAppend

# Run progress: 50.00% complete, ETA 00:01:22
# Fork: 1 of 1
# Warmup Iteration   1: 1.898 ms/op
# Warmup Iteration   2: 4.408 ms/op
# Warmup Iteration   3: 5.807 ms/op
Iteration   1: 6.832 ms/op
Iteration   2: 7.782 ms/op
Iteration   3: 8.771 ms/op
Iteration   4: 9.465 ms/op
Iteration   5: 10.366 ms/op


Result "cn.haochen.jmhdemo.JmhHello.stringBuilderAppend":
  8.643 ±(99.9%) 5.336 ms/op [Average]
  (min, avg, max) = (6.832, 8.643, 10.366), stdev = 1.386
  CI (99.9%): [3.307, 13.979] (assumes normal distribution)


# Run complete. Total time: 00:02:43

REMEMBER: The numbers below are just data. To gain reusable insights, you need to follow up on
why the numbers are the way they are. Use profilers (see -prof, -lprof), design factorial
experiments, perform baseline and negative tests that provide experimental control, make sure
the benchmarking environment is safe on JVM/OS/HW level, ask for reviews from the domain experts.
Do not assume the numbers tell you what you want them to tell.

Benchmark                     Mode  Cnt    Score     Error  Units
JmhHello.stringAdd            avgt    5  280.815 ± 226.061  ms/op
JmhHello.stringBuilderAppend  avgt    5    8.643 ±   5.336  ms/op

Process finished with exit code 0

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119

4、注解说明

经过上面的示例，想必你也可以快速的使用 JMH 进行基准测试了，不过上面的诸多注解你可能还有疑惑，下面一一介绍。

@BenchmarkMode(Mode.AverageTime)
@State(Scope.Thread)
@Fork(1)
@OutputTimeUnit(TimeUnit.MILLISECONDS)
@Warmup(iterations = 3)
@Measurement(iterations = 5)

1
2
3
4
5
6
7

@BenchmarkMode(Mode.AverageTime) 表示统计平均响应时间，不仅可以用在类上，也可用在测试方法上。

除此之外还可以取值：

Throughput：统计单位时间内可以对方法测试多少次。
SampleTime：统计每个响应时间范围内的响应次数，比如 0-1ms，3 次；1-2ms，5 次。
SingleShotTime：跳过预热阶段，直接进行一次 **** 微基准测试。
@State(Scope.Thread)：每个进行基准测试的线程都会独享一个对象示例。

除此之外还能取值：

Benchmark：多线程共享一个示例。
Group：线程组共享一个示例，在测试方法上使用 @Group 设置线程组。
@Fork(1)：表示开启一个线程进行测试。

**OutputTimeUnit (TimeUnit.MILLISECONDS)：输出的时间单位，这里写的是毫秒。

@Warmup(iterations = 3)：微基准测试前进行三次预热执行，也可用在测试方法上。

@Measurement(iterations = 5)：进行 5 次微基准测试，也可用在测试方法上。

在两个测试方法上只使用了一个注解 @Benchmark，这个注解表示这个方法是要进行基准测试的方法，它类似于 Junit 中的 @Test 注解。上面还提到某些注解还可以用到测试方法上，也就是使用了 @Benchmark 的方法之上，如果类上和测试方法同时存在注解，会以方法上的注解为准。