使用JMH做Java微基准测试

一、什么是 JMH

二、为什么要使用 JMH

三、JMH基本参数概念

一、什么是 JMH

JMH 是 Java Microbenchmark Harness 的缩写。中文意思大致是 “JAVA 微基准测试套件”。官网：http://openjdk.java.net/projects/code-tools/jmh/

首先先明白什么是“基准测试”。百度百科给的定义如下：

基准测试是指通过设计科学的测试方法、测试工具和测试系统，实现对一类测试对象的某项性能指标进行定量的和可对比的测试。

可以简单的类比成我们电脑常用的鲁大师，或者手机常用的跑分软件安兔兔之类的性能检测软件。都是按一定的基准或者在特定条件下去测试某一对象的的性能，比如显卡、IO、CPU之类的。

二、为什么要使用 JMH

基准测试的特质有如下几种：

①、可重复性：可进行重复性的测试，这样做有利于比较每次的测试结果，得到性能结果的长期变化趋势，为系统调优和上线前的容量规划做参考。

②、可观测性：通过全方位的监控（包括测试开始到结束，执行机、服务器、数据库），及时了解和分析测试过程发生了什么。

③、可展示性：相关人员可以直观明了的了解测试结果（web界面、仪表盘、折线图树状图等形式）。

④、真实性：测试的结果反映了客户体验到的真实的情况（真实准确的业务场景+与生产一致的配置+合理正确的测试方法）。

⑤、可执行性：相关人员可以快速的进行测试验证修改调优（可定位可分析）。

可见要做一次符合特质的基准测试，是很繁琐也很困难的。外界因素很容易影响到最终的测试结果。特别对于 JAVA的基准测试。

有些文章会告诉我们 JAVA是 C++编写的，一般来说 JAVA编写的程序不太可能比 C++编写的代码运行效率更好。但是JAVA在某些场景的确要比 C++运行的更高效。不要觉得天方夜谭。其实 JVM随着这些年的发展已经变得很智能，它会在运行期间不断的去优化。
这对于我们程序来说是好事，但是对于性能测试就头疼的。你运行的次数与时间不同可能获得的结果也不同，很难获得一个比较稳定的结果。对于这种情况，有一个解决办法就是大量的重复调用，并且在真正测试前还要进行一定的预热，使结果尽可能的准确。

除了这些，对于结果我们还需要一个很好的展示，可以让我们通过这些展示结果判断性能的好坏。

在使用Java编程过程中，我们对于一些代码调用的细节有多种编写方式，但是不确定它们性能时，往往采用重复多次计数的方式来解决。但是随着JVM不断的进化，随着代码执行次数的增加，JVM会不断的进行编译优化，使得重复多少次才能够得到一个稳定的测试结果变得让人疑惑，这时候有经验的同学就会在测试执行前先循环上万次并注释为预热。

没错！这样做确实可以获得一个偏向正确的测试结果，但是我们试想如果每到需要斟酌性能的时候，都要根据场景写一段预热的逻辑吗？当预热完成后，需要多少次迭代来进行正式内容的测量呢？每次测试结果的输出报告是不是都需要用System.out来输出呢？

其实这些工作都可以交给 JMH (the Java Microbenchmark Harness) ，它被作为Java9的一部分来发布，但是我们完全不需要等待Java9，而可以方便的使用它来简化我们测试，它能够照看好JVM的预热、代码优化，让你的测试过程变得更加简单。

三、JMH基本参数概念

3.1　Mode 表示 JMH 进行 Benchmark 时所使用的模式

　　Mode 表示 JMH 进行 Benchmark 时所使用的模式。通常是测量的维度不同，或是测量的方式不同。目前 JMH 共有四种模式：

Throughput: 整体吞吐量，例如“1秒内可以执行多少次调用”。
AverageTime: 调用的平均时间，例如“每次调用平均耗时xxx毫秒”。
SampleTime: 随机取样，最后输出取样结果的分布，例如“99%的调用在xxx毫秒以内，99.99%的调用在xxx毫秒以内”
SingleShotTime: 以上模式都是默认一次 iteration 是 1s，唯有 SingleShotTime 是只运行一次。往往同时把 warmup 次数设为0，用于测试冷启动时的性能。

3.2　Iteration JMH 进行测试的最小单位

　　Iteration 是 JMH 进行测试的最小单位。在大部分模式下，一次 iteration 代表的是一秒，JMH 会在这一秒内不断调用需要 benchmark 的方法，然后根据模式对其采样，计算吞吐量，计算平均执行时间等。

3.3　Warmup 实际进行 benchmark 前先进行预热的行为

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

示例：

@BenchmarkMode({Mode.Throughput, Mode.AverageTime}) // 测试方法平均执行时间
@OutputTimeUnit(TimeUnit.SECONDS) // 输出结果的时间粒度为微秒
@State(Scope.Thread) // 每个测试线程一个实例
public class SimpleBenchmark {

    @Benchmark
    public void bench() {
        add(1, 1);
    }

    private static int add(int a, int b) {
        return a + b;
    }

    @Benchmark
    public String stringConcat() {
        String a = "a";
        String b = "b";
        String c = "c";
        return a + b + c;
    }

    public static void main(String[] args) throws RunnerException {
        Options options = new OptionsBuilder()
                .include(SimpleBenchmark.class.getSimpleName())  //代表我要测试的是哪个类的方法
                .exclude("stringConcat")                         //代表测试的时候需要排除stringConcat方法
                .forks(2)                                        //指的是做2轮测试，在一轮测试无法得出最满意的结果时,可以多测几轮以便得出更全面的测试结果，而每一轮都是先预热，再正式计量。
                .warmupIterations(5)                             //代表先预热5次
                .measurementIterations(5)                        //正式运行测试5次
                .build();
        new Runner(options).run();
    }
}

四、注解与选项

4.1 @BenchmarkMode

　　　　对应Mode选项，可用于类或者方法上，需要注意的是，这个注解的value是一个数组，可以把几种Mode集合在一起执行，还可以设置为Mode.All，即全部执行一遍。

4.2　@State

　　　　类注解，JMH测试类必须使用@State注解，State定义了一个类实例的生命周期，可以类比Spring Bean的Scope。由于JMH允许多线程同时执行测试，不同的选项含义如下：

Scope.Thread：默认的State，每个测试线程分配一个实例；
Scope.Benchmark：所有测试线程共享一个实例，用于测试有状态实例在多线程共享下的性能；
Scope.Group：每个线程组共享一个实例；

4.3　@OutputTimeUnit

　　　　benchmark 结果所使用的时间单位，可用于类或者方法注解，使用java.util.concurrent.TimeUnit中的标准时间单位。

4.4　@Benchmark

　　　　方法注解，表示该方法是需要进行 benchmark 的对象。

4.5　@Setup

　　　　方法注解，会在执行 benchmark 之前被执行，正如其名，主要用于初始化。

4.6　@TearDown

　　　　方法注解，与@Setup 相对的，会在所有 benchmark 执行结束以后执行，主要用于资源的回收等。

4.7　@Param

　　　　成员注解，可以用来指定某项参数的多种情况。特别适合用来测试一个函数在不同的参数输入的情况下的性能。@Param注解接收一个String数组，在@setup方法执行前转化为为对应的数据类型。多个@Param注解的成员之间是乘积关系，譬如有两个用@Param注解的字段，第一个有5个值，第二个字段有2个值，那么每个测试方法会跑5*2=10次。

五、示例

首先在项目中新增依赖，jmh-core以及jmh-generator-annprocess的依赖可以在maven仓库中找寻最新版本。

<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-core</artifactId>
    <version>1.19</version>
</dependency>
<dependency>
    <groupId>org.openjdk.jmh</groupId>
    <artifactId>jmh-generator-annprocess</artifactId>
    <version>1.19</version>
</dependency>

创建一个Helloworld类，里面只有一个空方法m()，标注了@Benchmark的注解，声明这个方法为一个微基准测试方法，JMH 会在编译期生成基准测试的代码，并运行它。

public class Helloworld {

    @Benchmark
    public void m() {

    }
}

接着添加一个main入口，由它来启动测试。

public class HelloworldRunner {

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include("Helloworld")
                .exclude("Pref")
                .warmupIterations(10)
                .measurementIterations(10)
                .forks(3)
                .build();

        new Runner(opt).run();
    }
}

简单介绍一下这个HelloworldRunner，它是一个入口的同时还完成了 JMH 测试的配置工作。默认场景下，JMH 会找寻标注了@Benchmark类型的方法，可能会跑一些你所不需要的测试，这样就需要通过include和exclude两个方法来完成包含以及排除的语义。

warmupIterations(10)的意思是预热做10轮，measurementIterations(10)代表正式计量测试做10轮，而每次都是先执行完预热再执行正式计量，内容都是调用标注了@Benchmark的代码。

forks(3)指的是做3轮测试，因为一次测试无法有效的代表结果，所以通过3轮测试较为全面的测试，而每一轮都是先预热，再正式计量。

我们运行HelloworldRunner，经过一段时间，测试结果如下：

Result "com.alibaba.microbenchmark.test.Helloworld.m":
  3084697483.521 ±(99.9%) 27096926.646 ops/s [Average]
  (min, avg, max) = (2951123277.601, 3084697483.521, 3121456015.904), stdev = 40557407.239
  CI (99.9%): [3057600556.875, 3111794410.166] (assumes normal distribution)


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

Benchmark      Mode  Cnt           Score          Error  Units
Helloworld.m  thrpt   30  3084697483.521 ± 27096926.646  ops/s

可以看到分数是30亿次，但是这30亿指的是什么呢？仔细观察 Mode 一项中类型是thrpt，其实就是Throughput吞吐量，代表着每秒完成的次数。

测试类型

前面提到测试的类型是吞吐量，也就是一秒钟调用完成的次数，但是如果想知道做一次需要多少时间该怎么办？

其实 1 / 吞吐量就是这个值

JMH 提供了以下几种类型进行支持：

类型	描述
Throughput	每段时间执行的次数，一般是秒
AverageTime	平均时间，每次操作的平均耗时
SampleTime	在测试中，随机进行采样执行的时间
SingleShotTime	在每次执行中计算耗时
All	顾名思义，所有模式，这个在内部测试中常用

使用这些模式也非常简单，只需要增加@BenchmarkMode注解即可，例如：

@Benchmark
@BenchmarkMode({Mode.Throughput, Mode.SingleShotTime})
public void m() {

}

配置策略

JMH 支持通过@Fork注解完成配置，例如：

@Benchmark
@Fork(value = 1, warmups = 2)
@BenchmarkMode(Mode.Throughput)
public void init() {

}

以上注解指init()方法测试时，预热2轮，正式计量1轮，但是如果测试方法比较多，还是建议通过Options进行配置，具体可以参考HelloworldRunner。

数据准备

开始测试前，往往有数据准备的需求，比如：初始化一个变量或者一批数据，可以通过构造函数进行初始化，不过 JMH 提供了一些手段帮助我们完成这个工作。

@State(Scope.Benchmark)
public class Helloworld {
    private long i;

    @Setup
    public void init() {
        i = System.currentTimeMillis();
    }
}

上面的例子中，初始化了成员变量i，JMH 会保证在构造Helloworld后调用init()方法。@State(Scope.Benchmark)是修饰成员变量作用域是整个测试，能够被整个测试过程可见。

实现策略

JMH 是通过什么手段来完成测试的呢？预热我们可以通过循环去做，大概1-2万次左右的调用已经足够让代码优化，测试过程我们就通过System.currentTimeMillis()看一下耗时不就行了？

这个问题先放一下，我们看一下 JMH 是如何驱动你的测试的。当我们运行 JMH 基准测试时，它会生成一些Java代码，通常会通过继承你的测试来完成，比如你的测试类型是A，测试方法m()，它会自动生成A_jmhType_B1、A_jmhType_B2、A_jmhType_B3和A_jmhType以及最终的测试执行逻辑A_m_jmhTest。生成代码的一般在classes目录下，看一下生成的类型信息：

public class Helloworld_jmhType_B1 extends com.alibaba.microbenchmark.test.Helloworld {
    boolean p000, p001, p002, p003, p004, p005, p006, p007, p008, p009, p010, p011, p012, p013, p014, p015;
    boolean p240, p241, p242, p243, p244, p245, p246, p247, p248, p249, p250, p251, p252, p253, p254, p255;
}

可以看到类型中定义了256个boolean，这理论是在做cache line padding，可以猜测 JMH 是想避免CPU缓存对测试过程带来的影响。

public BenchmarkTaskResult m_Throughput(InfraControl control, ThreadParams threadParams) throws Throwable {
  Helloworld_jmhType l_helloworld0_G = _jmh_tryInit_f_helloworld0_G(control);
  control.preSetup();
  control.announceWarmupReady();
  while (control.warmupShouldWait) {
      l_helloworld0_G.m();
      res.allOps++;
    }

  m_thrpt_jmhStub(control, res, benchmarkParams, iterationParams, threadParams, blackhole, notifyControl, startRndMask, l_helloworld0_G);
}

在最终的测试逻辑代码Helloworld_m_jmhTest中对吞吐量的测试，首先获取了针对Helloworld生成的子类，然后调用Setup，接下来预热，最后进行正式计量。

通过介绍 JMH 的测试过程，就可以回答之前的问题，因为 JMH 全面的考虑的性能测试中环境的影响，所以测试更加的客观。

示例1：循环的微基准测试

for循环大家平时经常使用，但是看到过一个优化策略，就是倒序遍历，比如：for (int i = length; i > 0; i--)优于for (int i = 0; i < length; i++)，有些不解。咨询了温少，温少给出的答案是i > 0优于i < length，因此倒序有优势，那么我们将这个场景做一下基准测试。

首先是正向循环，次数是1百万次迭代。

public class CountPerf {

    @Benchmark
    @BenchmarkMode(Mode.Throughput)
    public void count() {
        for (int i = 0; i < 1_000_000; i++) {

        }
    }
}

接着是逆向循环，次数也是1百万次。

public class CountPerf {

    @Benchmark
    @BenchmarkMode(Mode.Throughput)
    public void count() {
        for (int i = 1_000_000; i > 0; i--) {

        }
    }
}

最后是一个测试的入口，我们采用3组，每组预热10轮，正式计量10轮，测试类型是吞吐量。

public class BenchmarkRunner {

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include("Perf")
                .exclude("Helloworld")
                .warmupIterations(10)
                .measurementIterations(10)
                .forks(3)
                .build();

        new Runner(opt).run();
    }
}

测试结果如下，有数据表现可以看到逆序在宏观上是优于正序的。

Result "com.alibaba.microbenchmark.forward.CountPerf.count":
  3017436523.994 ±(99.9%) 74706077.393 ops/s [Average]
  (min, avg, max) = (2586477493.002, 3017436523.994, 3090537220.013), stdev = 111816548.191
  CI (99.9%): [2942730446.601, 3092142601.387] (assumes normal distribution)


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

Benchmark                        Mode  Cnt           Score          Error  Units
c.a.m.backward.CountPerf.count  thrpt   30  3070589161.097 ± 30858669.885  ops/s
c.a.m.forward.CountPerf.count   thrpt   30  3017436523.994 ± 74706077.393  ops/s

示例2：Calendar和dateTime对比的基准测试

https://www.cnblogs.com/tranquillity/p/9488572.html

　测试结果表明：

　　　　runCalendar方法平均运行时间为：619微秒

　　　　runJoda方法的平均运行时间为：34微秒

　　据用例测试结果可以看到，Calendar（非线程安全）在高并发情况下性能远远比不上dateTime（线程安全）。对代码性能和安全性要求比较高的可以放弃使用Calendar和SimpleDateFormat（底层实现是Calendar），转而使用joda-time

示例3：几种字符串拼接方法的基准测试

package com.dxz.statement;

import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.Mode;
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;

public class StringConnectBenchmark {

    /**
     * 字符串拼接之 StringBuilder 基准测试
     */
    @Benchmark
    public void testStringBuilder() {
        print(new StringBuilder().append(1).append(2).append(3).toString());
    }

    /**
     * 字符串拼接之直接相加基准测试
     */
    @Benchmark
    public void testStringAdd() {
        print(new String()+ 1 + 2 + 3);
    }

    /**
     * 字符串拼接之String Concat基准测试
     */
    @Benchmark
    public void testStringConcat() {
        print(new String().concat("1").concat("2").concat("3"));
    }

    /**
     * 字符串拼接之 StringBuffer 基准测试
     */
    @Benchmark
    public void testStringBuffer() {
        print(new StringBuffer().append(1).append(2).append(3).toString());
    }

    /**
     * 字符串拼接之 StringFormat 基准测试
     */
    @Benchmark
    public void testStringFormat(){
        print(String.format("%s%s%s", 1, 2, 3));
    }

    public void print(String str) {

    }

    public static void main( String[] args ) throws RunnerException {
        Options opt = new OptionsBuilder()
                // 导入要测试的类
                .include(StringConnectBenchmark.class.getSimpleName())
                // 预热5轮
                .warmupIterations(5)
                // 度量10轮
                .measurementIterations(10)
                .mode(Mode.Throughput)
                .forks(3)
                .build();

        new Runner(opt).run();

    }
}

结果：

C:\java\jdk1.8.0_111\bin\java.exe -Dfile.encoding=UTF-8 -classpath D:\study\jmh\benchmark-demo\target\classes;C:\Users\4cv748wpd3\.m2\repository\org\openjdk\jmh\jmh-core\1.25\jmh-core-1.25.jar;C:\Users\4cv748wpd3\.m2\repository\net\sf\jopt-simple\jopt-simple\4.6\jopt-simple-4.6.jar;C:\Users\4cv748wpd3\.m2\repository\org\apache\commons\commons-math3\3.2\commons-math3-3.2.jar;C:\Users\4cv748wpd3\.m2\repository\junit\junit\4.11\junit-4.11.jar;C:\Users\4cv748wpd3\.m2\repository\org\hamcrest\hamcrest-core\1.3\hamcrest-core-1.3.jar org.openjdk.jmh.Main com.dxz.statement.StringConnectBenchmark.*
# JMH version: 1.25
# VM version: JDK 1.8.0_111, Java HotSpot(TM) 64-Bit Server VM, 25.111-b14
# VM invoker: C:\java\jdk1.8.0_111\jre\bin\java.exe
# VM options: -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: com.dxz.statement.StringConnectBenchmark.testStringAdd

# Run progress: 0.00% complete, ETA 00:41:40
# Fork: 1 of 5
# Warmup Iteration   1: 62711684.234 ops/s
# Warmup Iteration   2: 59618263.486 ops/s
# Warmup Iteration   3: 60014649.317 ops/s
# Warmup Iteration   4: 58772171.747 ops/s
# Warmup Iteration   5: 58594536.979 ops/s
Iteration   1: 58630801.253 ops/s
Iteration   2: 58780478.004 ops/s
Iteration   3: 58575508.000 ops/s
Iteration   4: 59559551.638 ops/s
Iteration   5: 59933436.541 ops/s

# Run progress: 4.00% complete, ETA 00:40:31
# Fork: 2 of 5
# Warmup Iteration   1: 63815375.015 ops/s
# Warmup Iteration   2: 58233477.740 ops/s
# Warmup Iteration   3: 58908018.337 ops/s
# Warmup Iteration   4: 59638642.706 ops/s
# Warmup Iteration   5: 59701753.260 ops/s
Iteration   1: 59709525.618 ops/s
Iteration   2: 59554418.319 ops/s
Iteration   3: 58450779.960 ops/s
Iteration   4: 59180593.377 ops/s
Iteration   5: 58853053.925 ops/s

# Run progress: 8.00% complete, ETA 00:38:44
# Fork: 3 of 5
# Warmup Iteration   1: 64293022.011 ops/s
# Warmup Iteration   2: 60090959.287 ops/s
# Warmup Iteration   3: 60034240.399 ops/s
# Warmup Iteration   4: 60895232.124 ops/s
# Warmup Iteration   5: 60827419.501 ops/s
Iteration   1: 59449542.357 ops/s
Iteration   2: 60924678.198 ops/s
Iteration   3: 62238255.902 ops/s
Iteration   4: 61680741.515 ops/s
Iteration   5: 61810312.038 ops/s

# Run progress: 12.00% complete, ETA 00:37:02
# Fork: 4 of 5
# Warmup Iteration   1: 68553455.562 ops/s
# Warmup Iteration   2: 61910316.563 ops/s
# Warmup Iteration   3: 61973790.977 ops/s
# Warmup Iteration   4: 62281899.906 ops/s
# Warmup Iteration   5: 62115501.853 ops/s
Iteration   1: 62004965.525 ops/s
Iteration   2: 62046250.011 ops/s
Iteration   3: 61754344.586 ops/s
Iteration   4: 61949834.153 ops/s
Iteration   5: 63307326.964 ops/s

# Run progress: 16.00% complete, ETA 00:35:20
# Fork: 5 of 5
# Warmup Iteration   1: 71107679.386 ops/s
# Warmup Iteration   2: 63820558.845 ops/s
# Warmup Iteration   3: 63755676.303 ops/s
# Warmup Iteration   4: 63053974.144 ops/s
# Warmup Iteration   5: 62371607.324 ops/s
Iteration   1: 62693680.023 ops/s
Iteration   2: 62362935.112 ops/s
Iteration   3: 62421022.355 ops/s
Iteration   4: 62883599.548 ops/s
Iteration   5: 62168159.990 ops/s


Result "com.dxz.statement.StringConnectBenchmark.testStringAdd":
  60836951.796 ±(99.9%) 1211324.257 ops/s [Average]
  (min, avg, max) = (58450779.960, 60836951.796, 63307326.964), stdev = 1617083.227
  CI (99.9%): [59625627.539, 62048276.054] (assumes normal distribution)


# JMH version: 1.25
# VM version: JDK 1.8.0_111, Java HotSpot(TM) 64-Bit Server VM, 25.111-b14
# VM invoker: C:\java\jdk1.8.0_111\jre\bin\java.exe
# VM options: -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: com.dxz.statement.StringConnectBenchmark.testStringBuffer

# Run progress: 20.00% complete, ETA 00:33:38
# Fork: 1 of 5
# Warmup Iteration   1: 100471666.063 ops/s
# Warmup Iteration   2: 104535538.373 ops/s
# Warmup Iteration   3: 116332675.750 ops/s
# Warmup Iteration   4: 116390206.782 ops/s
# Warmup Iteration   5: 116769975.834 ops/s
Iteration   1: 110281272.718 ops/s
Iteration   2: 114689728.881 ops/s
Iteration   3: 115952778.447 ops/s
Iteration   4: 116395212.520 ops/s
Iteration   5: 116039051.418 ops/s

# Run progress: 24.00% complete, ETA 00:31:57
# Fork: 2 of 5
# Warmup Iteration   1: 101156087.693 ops/s
# Warmup Iteration   2: 104658890.600 ops/s
# Warmup Iteration   3: 116158367.822 ops/s
# Warmup Iteration   4: 116282230.116 ops/s
# Warmup Iteration   5: 114769777.817 ops/s
Iteration   1: 115240363.781 ops/s
Iteration   2: 114653428.687 ops/s
Iteration   3: 114734766.990 ops/s
Iteration   4: 114403912.320 ops/s
Iteration   5: 116160502.755 ops/s

# Run progress: 28.00% complete, ETA 00:30:16
# Fork: 3 of 5
# Warmup Iteration   1: 103517357.282 ops/s
# Warmup Iteration   2: 107610389.229 ops/s
# Warmup Iteration   3: 116603060.598 ops/s
# Warmup Iteration   4: 116511257.752 ops/s
# Warmup Iteration   5: 116460595.600 ops/s
Iteration   1: 116461474.029 ops/s
Iteration   2: 116189113.610 ops/s
Iteration   3: 116781421.188 ops/s
Iteration   4: 115767863.167 ops/s
Iteration   5: 115127246.617 ops/s

# Run progress: 32.00% complete, ETA 00:28:35
# Fork: 4 of 5
# Warmup Iteration   1: 105483122.724 ops/s
# Warmup Iteration   2: 109492677.923 ops/s
# Warmup Iteration   3: 117970020.734 ops/s
# Warmup Iteration   4: 117696362.725 ops/s
# Warmup Iteration   5: 112629994.219 ops/s
Iteration   1: 113387011.351 ops/s
Iteration   2: 113538578.911 ops/s
Iteration   3: 113357184.935 ops/s
Iteration   4: 112381645.060 ops/s
Iteration   5: 113089726.147 ops/s

# Run progress: 36.00% complete, ETA 00:26:54
# Fork: 5 of 5
# Warmup Iteration   1: 102160077.246 ops/s
# Warmup Iteration   2: 106152890.625 ops/s
# Warmup Iteration   3: 112648924.920 ops/s
# Warmup Iteration   4: 113554549.663 ops/s
# Warmup Iteration   5: 111823402.784 ops/s
Iteration   1: 111182399.956 ops/s
Iteration   2: 111995727.842 ops/s
Iteration   3: 114128676.053 ops/s
Iteration   4: 117461016.726 ops/s
Iteration   5: 117385739.483 ops/s


Result "com.dxz.statement.StringConnectBenchmark.testStringBuffer":
  114671433.744 ±(99.9%) 1425597.127 ops/s [Average]
  (min, avg, max) = (110281272.718, 114671433.744, 117461016.726), stdev = 1903131.378
  CI (99.9%): [113245836.617, 116097030.870] (assumes normal distribution)


# JMH version: 1.25
# VM version: JDK 1.8.0_111, Java HotSpot(TM) 64-Bit Server VM, 25.111-b14
# VM invoker: C:\java\jdk1.8.0_111\jre\bin\java.exe
# VM options: -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: com.dxz.statement.StringConnectBenchmark.testStringBuilder

# Run progress: 40.00% complete, ETA 00:25:13
# Fork: 1 of 5
# Warmup Iteration   1: 105530215.117 ops/s
# Warmup Iteration   2: 109521623.130 ops/s
# Warmup Iteration   3: 117412751.615 ops/s
# Warmup Iteration   4: 117820318.296 ops/s
# Warmup Iteration   5: 117311123.685 ops/s
Iteration   1: 117693193.275 ops/s
Iteration   2: 117603309.277 ops/s
Iteration   3: 117464363.937 ops/s
Iteration   4: 116837203.388 ops/s
Iteration   5: 108363765.743 ops/s

# Run progress: 44.00% complete, ETA 00:23:32
# Fork: 2 of 5
# Warmup Iteration   1: 94155684.169 ops/s
# Warmup Iteration   2: 97072229.627 ops/s
# Warmup Iteration   3: 103404307.612 ops/s
# Warmup Iteration   4: 103205644.859 ops/s
# Warmup Iteration   5: 102275100.752 ops/s
Iteration   1: 99694778.941 ops/s
Iteration   2: 103507888.755 ops/s
Iteration   3: 103384352.044 ops/s
Iteration   4: 101838919.847 ops/s
Iteration   5: 102692369.336 ops/s

# Run progress: 48.00% complete, ETA 00:21:51
# Fork: 3 of 5
# Warmup Iteration   1: 92892642.256 ops/s
# Warmup Iteration   2: 100168144.486 ops/s
# Warmup Iteration   3: 106545161.232 ops/s
# Warmup Iteration   4: 106326215.672 ops/s
# Warmup Iteration   5: 106357036.403 ops/s
Iteration   1: 105986648.703 ops/s
Iteration   2: 106459899.483 ops/s
Iteration   3: 106556973.907 ops/s
Iteration   4: 105527219.535 ops/s
Iteration   5: 106160558.202 ops/s

# Run progress: 52.00% complete, ETA 00:20:10
# Fork: 4 of 5
# Warmup Iteration   1: 95578365.868 ops/s
# Warmup Iteration   2: 99776340.139 ops/s
# Warmup Iteration   3: 106370340.718 ops/s
# Warmup Iteration   4: 106719239.205 ops/s
# Warmup Iteration   5: 106951560.960 ops/s
Iteration   1: 106611786.221 ops/s
Iteration   2: 106306718.276 ops/s
Iteration   3: 106426862.975 ops/s
Iteration   4: 105824064.135 ops/s
Iteration   5: 106770783.507 ops/s

# Run progress: 56.00% complete, ETA 00:18:29
# Fork: 5 of 5
# Warmup Iteration   1: 95910707.221 ops/s
# Warmup Iteration   2: 100518293.439 ops/s
# Warmup Iteration   3: 106795041.731 ops/s
# Warmup Iteration   4: 104930286.522 ops/s
# Warmup Iteration   5: 102218925.972 ops/s
Iteration   1: 103055990.801 ops/s
Iteration   2: 103671266.101 ops/s
Iteration   3: 102401511.433 ops/s
Iteration   4: 102733478.091 ops/s
Iteration   5: 103405153.843 ops/s


Result "com.dxz.statement.StringConnectBenchmark.testStringBuilder":
  106679162.390 ±(99.9%) 3873825.727 ops/s [Average]
  (min, avg, max) = (99694778.941, 106679162.390, 117693193.275), stdev = 5171446.515
  CI (99.9%): [102805336.663, 110552988.118] (assumes normal distribution)


# JMH version: 1.25
# VM version: JDK 1.8.0_111, Java HotSpot(TM) 64-Bit Server VM, 25.111-b14
# VM invoker: C:\java\jdk1.8.0_111\jre\bin\java.exe
# VM options: -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: com.dxz.statement.StringConnectBenchmark.testStringConcat

# Run progress: 60.00% complete, ETA 00:16:48
# Fork: 1 of 5
# Warmup Iteration   1: 39047397.305 ops/s
# Warmup Iteration   2: 40665559.100 ops/s
# Warmup Iteration   3: 41409024.371 ops/s
# Warmup Iteration   4: 41571160.597 ops/s
# Warmup Iteration   5: 41264604.252 ops/s
Iteration   1: 41299338.986 ops/s
Iteration   2: 41380579.837 ops/s
Iteration   3: 41633458.068 ops/s
Iteration   4: 41747399.534 ops/s
Iteration   5: 41833640.102 ops/s

# Run progress: 64.00% complete, ETA 00:15:07
# Fork: 2 of 5
# Warmup Iteration   1: 39373695.016 ops/s
# Warmup Iteration   2: 41146027.330 ops/s
# Warmup Iteration   3: 41673738.724 ops/s
# Warmup Iteration   4: 41843033.496 ops/s
# Warmup Iteration   5: 41800911.168 ops/s
Iteration   1: 42010191.865 ops/s
Iteration   2: 41822086.542 ops/s
Iteration   3: 41970012.060 ops/s
Iteration   4: 41777714.465 ops/s
Iteration   5: 41855616.418 ops/s

# Run progress: 68.00% complete, ETA 00:13:26
# Fork: 3 of 5
# Warmup Iteration   1: 40138092.634 ops/s
# Warmup Iteration   2: 41224933.340 ops/s
# Warmup Iteration   3: 41747778.396 ops/s
# Warmup Iteration   4: 41669514.117 ops/s
# Warmup Iteration   5: 41632108.214 ops/s
Iteration   1: 41793614.055 ops/s
Iteration   2: 41755781.925 ops/s
Iteration   3: 41657754.290 ops/s
Iteration   4: 41811371.784 ops/s
Iteration   5: 41452727.868 ops/s

# Run progress: 72.00% complete, ETA 00:11:45
# Fork: 4 of 5
# Warmup Iteration   1: 39303895.148 ops/s
# Warmup Iteration   2: 41306221.335 ops/s
# Warmup Iteration   3: 41485992.155 ops/s
# Warmup Iteration   4: 41826317.168 ops/s
# Warmup Iteration   5: 41769239.392 ops/s
Iteration   1: 41594017.204 ops/s
Iteration   2: 41691229.757 ops/s
Iteration   3: 41869145.571 ops/s
Iteration   4: 41733935.180 ops/s
Iteration   5: 41830238.433 ops/s

# Run progress: 76.00% complete, ETA 00:10:05
# Fork: 5 of 5
# Warmup Iteration   1: 40093567.211 ops/s
# Warmup Iteration   2: 41125116.267 ops/s
# Warmup Iteration   3: 41664834.910 ops/s
# Warmup Iteration   4: 41723251.754 ops/s
# Warmup Iteration   5: 41596794.033 ops/s
Iteration   1: 41796263.846 ops/s
Iteration   2: 41347597.552 ops/s
Iteration   3: 41674576.043 ops/s
Iteration   4: 41645885.337 ops/s
Iteration   5: 41651314.433 ops/s


Result "com.dxz.statement.StringConnectBenchmark.testStringConcat":
  41705419.646 ±(99.9%) 135498.955 ops/s [Average]
  (min, avg, max) = (41299338.986, 41705419.646, 42010191.865), stdev = 180887.228
  CI (99.9%): [41569920.691, 41840918.601] (assumes normal distribution)


# JMH version: 1.25
# VM version: JDK 1.8.0_111, Java HotSpot(TM) 64-Bit Server VM, 25.111-b14
# VM invoker: C:\java\jdk1.8.0_111\jre\bin\java.exe
# VM options: -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: com.dxz.statement.StringConnectBenchmark.testStringFormat

# Run progress: 80.00% complete, ETA 00:08:24
# Fork: 1 of 5
# Warmup Iteration   1: 975048.849 ops/s
# Warmup Iteration   2: 1005353.182 ops/s
# Warmup Iteration   3: 1003633.129 ops/s
# Warmup Iteration   4: 1003314.936 ops/s
# Warmup Iteration   5: 1005633.422 ops/s
Iteration   1: 1004699.196 ops/s
Iteration   2: 1000435.363 ops/s
Iteration   3: 999416.708 ops/s
Iteration   4: 1006986.920 ops/s
Iteration   5: 1003941.429 ops/s

# Run progress: 84.00% complete, ETA 00:06:43
# Fork: 2 of 5
# Warmup Iteration   1: 945934.002 ops/s
# Warmup Iteration   2: 1013994.623 ops/s
# Warmup Iteration   3: 1013542.660 ops/s
# Warmup Iteration   4: 1014834.973 ops/s
# Warmup Iteration   5: 1007721.233 ops/s
Iteration   1: 1007100.774 ops/s
Iteration   2: 1011266.480 ops/s
Iteration   3: 1012228.131 ops/s
Iteration   4: 1012071.849 ops/s
Iteration   5: 1010444.976 ops/s

# Run progress: 88.00% complete, ETA 00:05:02
# Fork: 3 of 5
# Warmup Iteration   1: 996795.163 ops/s
# Warmup Iteration   2: 1034566.810 ops/s
# Warmup Iteration   3: 1033006.128 ops/s
# Warmup Iteration   4: 1033769.206 ops/s
# Warmup Iteration   5: 1032642.345 ops/s
Iteration   1: 1034079.168 ops/s
Iteration   2: 1029908.423 ops/s
Iteration   3: 1035955.616 ops/s
Iteration   4: 1037266.116 ops/s
Iteration   5: 1031665.788 ops/s

# Run progress: 92.00% complete, ETA 00:03:21
# Fork: 4 of 5
# Warmup Iteration   1: 1003976.486 ops/s
# Warmup Iteration   2: 1022408.984 ops/s
# Warmup Iteration   3: 1020572.992 ops/s
# Warmup Iteration   4: 1023204.213 ops/s
# Warmup Iteration   5: 1020733.074 ops/s
Iteration   1: 1020652.780 ops/s
Iteration   2: 1072559.478 ops/s
Iteration   3: 1074862.664 ops/s
Iteration   4: 1076194.231 ops/s
Iteration   5: 1076650.831 ops/s

# Run progress: 96.00% complete, ETA 00:01:40
# Fork: 5 of 5
# Warmup Iteration   1: 1053092.552 ops/s
# Warmup Iteration   2: 1084625.965 ops/s
# Warmup Iteration   3: 1085293.339 ops/s
# Warmup Iteration   4: 1084669.666 ops/s
# Warmup Iteration   5: 1081582.054 ops/s
Iteration   1: 1082967.461 ops/s
Iteration   2: 1087299.617 ops/s
Iteration   3: 1088068.834 ops/s
Iteration   4: 1089727.432 ops/s
Iteration   5: 1089616.672 ops/s


Result "com.dxz.statement.StringConnectBenchmark.testStringFormat":
  1039842.677 ±(99.9%) 25605.464 ops/s [Average]
  (min, avg, max) = (999416.708, 1039842.677, 1089727.432), stdev = 34182.562
  CI (99.9%): [1014237.213, 1065448.142] (assumes normal distribution)


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

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
StringConnectBenchmark.testStringAdd      thrpt   25   60836951.796 ± 1211324.257  ops/s
StringConnectBenchmark.testStringBuffer   thrpt   25  114671433.744 ± 1425597.127  ops/s
StringConnectBenchmark.testStringBuilder  thrpt   25  106679162.390 ± 3873825.727  ops/s
StringConnectBenchmark.testStringConcat   thrpt   25   41705419.646 ±  135498.955  ops/s
StringConnectBenchmark.testStringFormat   thrpt   25    1039842.677 ±   25605.464  ops/s

Process finished with exit code 0

结果分析：

结果主要分成三个部分。
第一部分以 “#Warmup Iteration。。。。”这种形式的内容。这表明每次预热迭代的结果。
另一部分以“Iteration。。。”形式内容，这表明每次基准测试迭代的结果。

最后一部分以“Result。。。”形式的内容，这就是所有迭代跑完最终的结果。第一段结果告诉了我们最大值、最小值、平均值的信息。

而最最后的表格结构的信息才是我们分析的重点，但是它输出的结果有点错位，刚开始我一直在纠结 Error是± 906608.141代表什么意思，google了一圈发现，Error它其实什么都没输出，而且 Score 是63728919.269 ± 906608.141。我用表格排板了一下，解释如下：

Benchmark	Mode	Cnt	Score	Error	Units
基准测试执行的方法	测试模式，这里是吞吐量	运行多少次	分数	错误	单位
StringConnectBenchmark.testStringAdd	thrpt	30	63728919.269 ± 906608.141		ops/s
StringConnectBenchmark.testStringBuffer	thrpt	30	112423521.098 ± 1157072.848		ops/s
StringConnectBenchmark.testStringBuilder	thrpt	30	110558976.274 ± 654163.111		ops/s
StringConnectBenchmark.testStringConcat	thrpt	30	44820009.200 ± 524305.660		ops/s
StringConnectBenchmark.testStringFormat	thrpt	30	1132633.183 ± 16252.303		ops/s

结论：

StringBuffer >= StringBuilder > String直接相加 > StringConcat >> StringFormat

可见 StringBuffer 与 StringBuilder 大致性能相同，都比直接相加高几个数量级，而且直接相加与 Concat 方法相加差不多。但是这里不管哪种都比 StringFormat高 N 个数量级。所以 String的 Format方法一定要慎用、不用、禁用！！！

参考链接

参考：https://www.jianshu.com/p/bcb0b60c7ca7

参考：https://www.cnblogs.com/tranquillity/p/9488572.html

https://www.cnblogs.com/kiwifly/p/11477153.html

posted on 2014-01-02 16:26 duanxz 阅读(1683) 评论(0) 编辑收藏举报

使用JMH做Java微基准测试

一、什么是 JMH

二、为什么要使用 JMH

三、JMH基本参数概念

3.1 Mode 表示 JMH 进行 Benchmark 时所使用的模式

3.2 Iteration JMH 进行测试的最小单位

3.3 Warmup 实际进行 benchmark 前先进行预热的行为

四、注解与选项

4.1 @BenchmarkMode

4.2 @State

4.3 @OutputTimeUnit

4.4 @Benchmark

4.5 @Setup

4.6 @TearDown

4.7 @Param

五、示例

测试类型

配置策略

数据准备

实现策略

示例1：循环的微基准测试

示例2：Calendar和dateTime对比的基准测试

示例3：几种字符串拼接方法的基准测试

参考链接

3.1　Mode 表示 JMH 进行 Benchmark 时所使用的模式

3.2　Iteration JMH 进行测试的最小单位

3.3　Warmup 实际进行 benchmark 前先进行预热的行为

4.2　@State

4.3　@OutputTimeUnit

4.4　@Benchmark

4.5　@Setup

4.6　@TearDown

4.7　@Param