沧海一粟

天下事有难易乎?为之,则难者亦易矣;不为,则易者亦难矣。

0%

java jmh 使用

代码工具:jmh JMH是一个Java工具,用于构建、运行和分析nano/micro/mili/macro基准,这些基准是用Java和其他针对JVM的语言编写的。
Code Tools: jmh JMH is a Java harness for building, running, and analysing nano/micro/milli/macro benchmarks written in Java and other languages targetting the JVM.

JMH解决了什么问题

JMH怎么用

  1. 添加对应jar包
  2. 根据实际情况配置参数
  3. 编写代码运行

添加依赖

1
2
3
4
5
6
7
8
9
10
<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>
</dependency>

配置参数

@BenchmarkMode
用来配置 Mode 选项,可用于类或者方法上,这个注解的 value 是一个数组,可以把几种 Mode 集合在一起执行,如:@BenchmarkMode({Mode.SampleTime, Mode.AverageTime}),还可以设置为 Mode.All,即全部执行一遍。

Throughput:整体吞吐量,每秒执行了多少次调用,单位为 ops/time
AverageTime:用的平均时间,每次操作的平均时间,单位为 time/op
SampleTime:随机取样,最后输出取样结果的分布
SingleShotTime:只运行一次,往往同时把 Warmup 次数设为 0,用于测试冷启动时的性能
All:上面的所有模式都执行一次
@State
通过 State 可以指定一个对象的作用范围,JMH 根据 scope 来进行实例化和共享操作。@State 可以被继承使用,如果父类定义了该注解,子类则无需定义。由于 JMH 允许多线程同时执行测试,不同的选项含义如下:

Scope.Benchmark:所有测试线程共享一个实例,测试有状态实例在多线程共享下的性能
Scope.Group:同一个线程在同一个 group 里共享实例
Scope.Thread:默认的 State,每个测试线程分配一个实例
@OutputTimeUnit
为统计结果的时间单位,可用于类或者方法注解

@Warmup
预热所需要配置的一些基本测试参数,可用于类或者方法上。一般前几次进行程序测试的时候都会比较慢,所以要让程序进行几轮预热,保证测试的准确性。参数如下所示:

iterations:预热的次数
time:每次预热的时间
timeUnit:时间的单位,默认秒
batchSize:批处理大小,每次操作调用几次方法
为什么需要预热?

因为 JVM 的 JIT 机制的存在,如果某个函数被调用多次之后,JVM 会尝试将其编译为机器码,从而提高执行速度,所以为了让 benchmark 的结果更加接近真实情况就需要进行预热。

@Measurement
实际调用方法所需要配置的一些基本测试参数,可用于类或者方法上,参数和 @Warmup 相同。

@Threads
每个进程中的测试线程,可用于类或者方法上。

@Fork
进行 fork 的次数,可用于类或者方法上。如果 fork 数是 2 的话,则 JMH 会 fork 出两个进程来进行测试。

@Param
指定某项参数的多种情况,特别适合用来测试一个函数在不同的参数输入的情况下的性能,只能作用在字段上,使用该注解必须定义 @State 注解。

编写代码运行

建议 代码里不要打日志

测试1

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
import cn.wkq.java.string.StringInternTest;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.results.format.ResultFormatType;
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;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
* <pre>
*
* JMH使用样例
* http://hg.openjdk.java.net/code-tools/jmh/file/tip/jmh-samples/src/main/java/org/openjdk/jmh/samples/
*
* </pre>
*
* @author weikeqin
* @date 2020-06-14 17:11
*/
public class JmtTest {

private static final transient Logger log = LoggerFactory.getLogger(StringInternTest.class);

@Benchmark
public void print() {
if (log.isDebugEnabled()) {
log.debug("hello JMH");
}
}


/**
* @param args
*/
public static void main(String[] args) throws RunnerException {

log.info("开始执行。");

Options opt = new OptionsBuilder()
.include(JmtTest.class.getSimpleName())
.forks(1)
.result("jmh_result.json")
.resultFormat(ResultFormatType.JSON)
.build();

new Runner(opt).run();

log.info("执行完成。");
}

}
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
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.openjdk.jmh.util.Utils (file:/Users/weikeqin1/.m2/repository/org/openjdk/jmh/jmh-core/1.23/jmh-core-1.23.jar) to field java.io.PrintStream.charOut
WARNING: Please consider reporting this to the maintainers of org.openjdk.jmh.util.Utils
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
# JMH version: 1.23
# VM version: JDK 14.0.1, Java HotSpot(TM) 64-Bit Server VM, 14.0.1+7
# VM invoker: /Library/Java/JavaVirtualMachines/jdk-14.0.1.jdk/Contents/Home/bin/java
# VM options: -javaagent:/Applications/IntelliJ IDEA.app/Contents/lib/idea_rt.jar=57492:/Applications/IntelliJ IDEA.app/Contents/bin -Dfile.encoding=UTF-8
# Warmup: 5 iterations, 10 s each
# Measurement: 5 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Throughput, ops/time
# Benchmark: cn.wkq.java.jmh.JmtTest.print

# Run progress: 0.00% complete, ETA 00:01:40
# Fork: 1 of 1
# Warmup Iteration 1: 660097134.157 ops/s
# Warmup Iteration 2: 650765740.996 ops/s
# Warmup Iteration 3: 661961002.718 ops/s
# Warmup Iteration 4: 672329475.200 ops/s
# Warmup Iteration 5: 611127628.164 ops/s
Iteration 1: 615120987.535 ops/s
Iteration 2: 645989044.177 ops/s
Iteration 3: 642876939.314 ops/s
Iteration 4: 640265656.368 ops/s
Iteration 5: 673185386.638 ops/s


Result "cn.wkq.java.jmh.JmtTest.print":
643487602.806 ±(99.9%) 79467866.034 ops/s [Average]
(min, avg, max) = (615120987.535, 643487602.806, 673185386.638), stdev = 20637552.448
CI (99.9%): [564019736.772, 722955468.841] (assumes normal distribution)


# Run complete. Total time: 00:01:42

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
JmtTest.print thrpt 5 643487602.806 ± 79467866.034 ops/s

Benchmark result is saved to jmh_result.json
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
[
{
"jmhVersion" : "1.23",
"benchmark" : "cn.wkq.java.jmh.JmtTest.print",
"mode" : "thrpt",
"threads" : 1,
"forks" : 1,
"jvm" : "/Library/Java/JavaVirtualMachines/jdk-14.0.1.jdk/Contents/Home/bin/java",
"jvmArgs" : [
"-javaagent:/Applications/IntelliJ IDEA.app/Contents/lib/idea_rt.jar=57492:/Applications/IntelliJ IDEA.app/Contents/bin",
"-Dfile.encoding=UTF-8"
],
"jdkVersion" : "14.0.1",
"vmName" : "Java HotSpot(TM) 64-Bit Server VM",
"vmVersion" : "14.0.1+7",
"warmupIterations" : 5,
"warmupTime" : "10 s",
"warmupBatchSize" : 1,
"measurementIterations" : 5,
"measurementTime" : "10 s",
"measurementBatchSize" : 1,
"primaryMetric" : {
"score" : 6.434876028063821E8,
"scoreError" : 7.946786603420861E7,
"scoreConfidence" : [
5.640197367721734E8,
7.229554688405907E8
],
"scorePercentiles" : {
"0.0" : 6.151209875347286E8,
"50.0" : 6.428769393141737E8,
"90.0" : 6.731853866384177E8,
"95.0" : 6.731853866384177E8,
"99.0" : 6.731853866384177E8,
"99.9" : 6.731853866384177E8,
"99.99" : 6.731853866384177E8,
"99.999" : 6.731853866384177E8,
"99.9999" : 6.731853866384177E8,
"100.0" : 6.731853866384177E8
},
"scoreUnit" : "ops/s",
"rawData" : [
[
6.151209875347286E8,
6.459890441766258E8,
6.428769393141737E8,
6.402656563679644E8,
6.731853866384177E8
]
]
},
"secondaryMetrics" : {
}
}
]

测试2

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
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
import org.junit.Test;
import org.openjdk.jmh.annotations.*;
import org.openjdk.jmh.results.format.ResultFormatType;
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;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.TimeUnit;

/**
* <pre>
*
* JMH使用样例
* http://hg.openjdk.java.net/code-tools/jmh/file/tip/jmh-samples/src/main/java/org/openjdk/jmh/samples/
*
* </pre>
*
* @author weikeqin
* @date 2020-06-14 16:06
*/
@BenchmarkMode(Mode.AverageTime)
@Warmup(iterations = 3, time = 1)
@Measurement(iterations = 5, time = 5)
@Threads(4)
@Fork(1)
@State(value = Scope.Benchmark)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
public class StringInternTest {

private static final transient Logger log = LoggerFactory.getLogger(StringInternTest.class);

@Param(value = {"10000", "100000", "1000000"})
private int count;

/**
*
*/
@Benchmark
public void stringTestWithIntern() {

long fm1 = Runtime.getRuntime().freeMemory();

List<SharedLocation> list = new ArrayList<>(count);
for (int i = 0; i < count; i++) {
String country = "中国";
String province = "山西";
String city = "运城";
SharedLocation sharedLocation = new SharedLocation();
sharedLocation.setCountry(country.intern());
sharedLocation.setProvince(province.intern());
sharedLocation.setCity(city.intern());

list.add(sharedLocation);


}

log.info("个数:{}", list.size());

long fm2 = Runtime.getRuntime().freeMemory();

log.info("{} {} use {} bytes", fm1, fm2, fm1 - fm2);
}

/**
*
*/
@Benchmark
public void stringTestWithOutIntern() {

long fm1 = Runtime.getRuntime().freeMemory();

List<SharedLocation> list = new ArrayList<>(count);
for (int i = 0; i < count; i++) {
String country = "中国";
String province = "山西";
String city = "运城";
SharedLocation sharedLocation = new SharedLocation();
sharedLocation.setCountry(country);
sharedLocation.setProvince(province);
sharedLocation.setCity(city);

list.add(sharedLocation);

}

log.info("个数:{}", list.size());

long fm2 = Runtime.getRuntime().freeMemory();

log.info("{} {} use {} bytes", fm1, fm2, fm1 - fm2);

}


/**
* @param args
*/
public static void main(String[] args) {

log.info("开始执行。");

Options opt = new OptionsBuilder()
.include(StringInternTest.class.getSimpleName())
.result("result.json")
.resultFormat(ResultFormatType.JSON).build();

try {
new Runner(opt).run();
} catch (RunnerException e) {
log.error("", e);
}

log.info("执行完成。");
}

}


/**
*
*/
class SharedLocation {

/**
* 市
*/
private String city;
/**
* 省
*/
private String province;
/**
* 国家
*/
private String country;

public String getCity() {
return city;
}

public void setCity(String city) {
this.city = city;
}

public String getProvince() {
return province;
}

public void setProvince(String province) {
this.province = province;
}

public String getCountry() {
return country;
}

public void setCountry(String country) {
this.country = country;
}
}
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
900761252.400 ±(99.9%) 836615744.826 ns/op


Result "cn.wkq.java.string.StringInternTest.stringTestWithOutIntern":
763138737.923 ±(99.9%) 930573867.253 ns/op [Average]
(min, avg, max) = (439268202.215, 763138737.923, 1017594855.563), stdev = 241667078.162
CI (99.9%): [≈ 0, 1693712605.176] (assumes normal distribution)


# Run complete. Total time: 00:03:34

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 (count) Mode Cnt Score Error Units
StringInternTest.stringTestWithIntern 10000 avgt 5 13128831.111 ± 1999580.768 ns/op
StringInternTest.stringTestWithIntern 100000 avgt 5 157188187.749 ± 99748905.878 ns/op
StringInternTest.stringTestWithIntern 1000000 avgt 5 1813072765.600 ± 619163864.504 ns/op
StringInternTest.stringTestWithOutIntern 10000 avgt 5 1511080.000 ± 872905.808 ns/op
StringInternTest.stringTestWithOutIntern 100000 avgt 5 8238751.953 ± 1401387.637 ns/op
StringInternTest.stringTestWithOutIntern 1000000 avgt 5 763138737.923 ± 930573867.253 ns/op

Benchmark result is saved to result.json

References

[1] 性能调优必备利器之JMH
[2] openjdk/jmh/samples/
[3] code-tools/jmh
[4] jmh-core api