java jmh 使用

发表于 2020-06-14 更新于 2022-05-28 分类于 java 阅读次数： Waline：本文字数： 10k 阅读时长 ≈ 9 分钟

代码工具：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怎么用

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

添加依赖

<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

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("执行完成。");
    }

}

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

[
    {
        "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

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;
    }
}

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