覚えたら書く

IT関係のデベロッパとして日々覚えたことを書き残したいです。twitter: @yyoshikaw

JMH - 初期化処理・終了処理を行う

JMHを使ってベンチマークの取得を行っている際に、計測処理の外側で初期化処理や終了処理を行いたい場合があると思います。

そのために用意されているのが以下のアノテーションになります

  • @Setup(org.openjdk.jmh.annotations.Setup) - 初期化処理用のアノテーション
  • @TearDown(org.openjdk.jmh.annotations.TearDown) - 終了処理用のアノテーション


基本的な使い方

Benchmark用のクラスの中に、@Setupを付与したメソッドと@TearDownを付与したメソッドを記述します。
@Setup@TearDownを使う場合には、ベンチマークに状態を持たせる必要があります。
それを示すためにBenchmark用のクラス自体に@State(org.openjdk.jmh.annotations.State)アノテーションを付与する必要あります。
状態のスコープを示すために、パラメータにScopeを指定します。ほとんどの場合このスコープはスレッド単位で良いと思いますので、Scope.Threadを指定します


以上の事を踏まえてベンチマーク用のクラスでは大まかに以下のようなコードを書くことになります。

import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.Setup;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.annotations.TearDown;

@State(Scope.Thread)
public class ExampleBenchmark {

    @Benchmark
    public void measure() {
        // 計測用のコードを記述する
    }

    @Setup
    public void setup() {
        // 初期化処理をここに書く
    }

    @TearDown
    public void tearDown() {
        // 終了処理をここに書く
    }
}


以下で具体的な実行サンプルを示します
(以下全てのサンプルで、ウォームアップを2イテレーション, 計測を3イテレーション実行しています)

@Setup/@TearDownを付与したメソッドで初期化処理/終了処理を実行

Benchmarkクラス内に@Setupを付与したsetupメソッドと@TearDownを付与したtearDownメソッドを記述して、その動きを確認します。

■サンプルコード

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

@State(Scope.Thread)
public class ExampleBenchmark1a {
    private long counter1 = 0;
    private long counter2 = 0;

    @Benchmark
    public void calendar() {
        java.util.Date d = java.util.Calendar.getInstance().getTime();
        counter1++;
    }

    @Benchmark
    public void date() {
        java.util.Date d = new java.util.Date();
        counter2++;
    }

    @Setup
    public void setup() {
        System.out.println("\n### setup ####################");

        counter1 = 0;
        counter2 = 0;
    }

    @TearDown
    public void tearDown() {
        System.out.println("\n### tear down ################");
        System.out.println("### counter1 = " + counter1 + ", counter2 = " + counter2);
    }

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(ExampleBenchmark1a.class.getSimpleName())
                .warmupIterations(2)
                .measurementIterations(3)
                .forks(1)
                .mode(Mode.Throughput)
                .build();
        new Runner(opt).run();
    }

}

■実行結果

(見やすいように一部省略しています)

# Benchmark: jmh.sample.ExampleBenchmark1a.calendar

# Run progress: 0.00% complete, ETA 00:00:10
# Fork: 1 of 1
# Warmup Iteration   1: 
### setup ####################
5209005.499 ops/s
# Warmup Iteration   2: 6127256.933 ops/s
Iteration   1: 7098798.158 ops/s
Iteration   2: 7102001.428 ops/s
Iteration   3: 
### tear down ################
### counter1 = 32656896, counter2 = 0
7087212.670 ops/s


Result "calendar":
  7096004.085 ±(99.9%) 141940.348 ops/s [Average]
  (min, avg, max) = (7087212.670, 7096004.085, 7102001.428), stdev = 7780.229
  CI (99.9%): [6954063.738, 7237944.433] (assumes normal distribution)


# Benchmark: jmh.sample.ExampleBenchmark1a.date

# Run progress: 50.00% complete, ETA 00:00:05
# Fork: 1 of 1
# Warmup Iteration   1: 
### setup ####################
96321238.106 ops/s
# Warmup Iteration   2: 96964646.037 ops/s
Iteration   1: 97109341.177 ops/s
Iteration   2: 97155337.144 ops/s
Iteration   3: 
### tear down ################
### counter1 = 0, counter2 = 485112651
97158416.186 ops/s


Result "date":
  97141031.502 ±(99.9%) 501479.306 ops/s [Average]
  (min, avg, max) = (97109341.177, 97141031.502, 97158416.186), stdev = 27487.773
  CI (99.9%): [96639552.197, 97642510.808] (assumes normal distribution)


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

Benchmark                     Mode  Cnt         Score        Error  Units
ExampleBenchmark1a.calendar  thrpt    3   7096004.085 ± 141940.348  ops/s
ExampleBenchmark1a.date      thrpt    3  97141031.502 ± 501479.306  ops/s

出力が少し前後している部分がありますが、各Benchmarkごとにウォームアップ前にsetupメソッドが実行され、計測終了後にtearDownメソッドが実行されていることが分かります


初期化処理/終了処理の実行単位を制御する

先の例では、Benchmarkの単位にウォームアップ前に初期化処理、計測終了後に終了処理が実行される状態となっていましたが、
初期化処理/終了処理の実行単位を制御することができます。 実行単位を制御する場合は、@Setup/@TearDownのパラメータにLevelを指定します。

Benchmarkの単位(ウォームアップ開始から計測終了まで)に実行

この単位での実行は既に示した通りですが、 明示的に書く場合は、@Setup/@TearDownのパラメータにLevel.Trialを記述します

■サンプルコード

import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.Level;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.Setup;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.annotations.TearDown;
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;

@State(Scope.Thread)
public class ExampleBenchmark1b {
    private long counter1 = 0;
    private long counter2 = 0;

    @Benchmark
    public void calendar() {
        java.util.Date d = java.util.Calendar.getInstance().getTime();
        counter1++;
    }

    @Benchmark
    public void date() {
        java.util.Date d = new java.util.Date();
        counter2++;
    }

    @Setup(Level.Trial)
    public void setup() {
        System.out.println("\n### setup ####################");

        counter1 = 0;
        counter2 = 0;
    }

    @TearDown(Level.Trial)
    public void tearDown() {
        System.out.println("\n### tear down ################");
        System.out.println("### counter1 = " + counter1 + ", counter2 = " + counter2);
    }

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(ExampleBenchmark1b.class.getSimpleName())
                .warmupIterations(2)
                .measurementIterations(3)
                .forks(1)
                .mode(Mode.Throughput)
                .build();
        new Runner(opt).run();
    }

}

■実行結果

(見やすいように一部省略しています)

# Benchmark: jmh.sample.ExampleBenchmark1b.calendar

# Run progress: 0.00% complete, ETA 00:00:10
# Fork: 1 of 1
# Warmup Iteration   1: 
### setup ####################
5148668.849 ops/s
# Warmup Iteration   2: 5545829.297 ops/s
Iteration   1: 7030056.715 ops/s
Iteration   2: 6487447.389 ops/s
Iteration   3: 
### tear down ################
### counter1 = 30994289, counter2 = 0
6754223.090 ops/s


Result "calendar":
  6757242.398 ±(99.9%) 4949836.910 ops/s [Average]
  (min, avg, max) = (6487447.389, 6757242.398, 7030056.715), stdev = 271317.264
  CI (99.9%): [1807405.488, 11707079.308] (assumes normal distribution)


# Benchmark: jmh.sample.ExampleBenchmark1b.date

# Run progress: 50.00% complete, ETA 00:00:05
# Fork: 1 of 1
# Warmup Iteration   1: 
### setup ####################
95139905.940 ops/s
# Warmup Iteration   2: 95480569.138 ops/s
Iteration   1: 96094757.863 ops/s
Iteration   2: 95506580.011 ops/s
Iteration   3: 
### tear down ################
### counter1 = 0, counter2 = 479010890
95991501.901 ops/s


Result "date":
  95864279.925 ±(99.9%) 5729440.152 ops/s [Average]
  (min, avg, max) = (95506580.011, 95864279.925, 96094757.863), stdev = 314049.948
  CI (99.9%): [90134839.773, 101593720.077] (assumes normal distribution)


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

Benchmark                     Mode  Cnt         Score         Error  Units
ExampleBenchmark1b.calendar  thrpt    3   6757242.398 ± 4949836.910  ops/s
ExampleBenchmark1b.date      thrpt    3  95864279.925 ± 5729440.152  ops/s

各Benchmark(ウォームアップ開始から計測終了まで)ごとに初期化処理/終了処理が実行されていることが分かります


Benchmarkのイテレーション単位に実行

Benchmarkのイテレーションの単位に、初期化処理/終了処理を実行する場合は、@Setup/@TearDownのパラメータにLevel.Iterationを記述します

■サンプルコード

import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.Level;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.Setup;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.annotations.TearDown;
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;

@State(Scope.Thread)
public class ExampleBenchmark2 {
    private long counter1 = 0;
    private long counter2 = 0;

    @Benchmark
    public void calendar() {
        java.util.Date d = java.util.Calendar.getInstance().getTime();
        counter1++;
    }

    @Benchmark
    public void date() {
        java.util.Date d = new java.util.Date();
        counter2++;
    }

    @Setup(Level.Iteration)
    public void setup() {
        System.out.println("\n### setup ####################");

        counter1 = 0;
        counter2 = 0;
    }

    @TearDown(Level.Iteration)
    public void tearDown() {
        System.out.println("\n### tear down ################");
        System.out.println("### counter1 = " + counter1 + ", counter2 = " + counter2);
    }

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(ExampleBenchmark2.class.getSimpleName())
                .warmupIterations(2)
                .measurementIterations(3)
                .forks(1)
                .mode(Mode.Throughput)
                .build();
        new Runner(opt).run();
    }

}

■実行結果

(見やすいように一部省略しています)

# Benchmark: jmh.sample.ExampleBenchmark2.calendar

# Run progress: 0.00% complete, ETA 00:00:10
# Fork: 1 of 1
# Warmup Iteration   1: 
### setup ####################

### tear down ################
### counter1 = 5459693, counter2 = 0
5456662.135 ops/s
# Warmup Iteration   2: 
### setup ####################

### tear down ################
### counter1 = 6327402, counter2 = 0
6326407.021 ops/s
Iteration   1: 
### setup ####################

### tear down ################
### counter1 = 7132768, counter2 = 0
7130105.519 ops/s
Iteration   2: 
### setup ####################

### tear down ################
### counter1 = 7216254, counter2 = 0
7213738.851 ops/s
Iteration   3: 
### setup ####################

### tear down ################
### counter1 = 7159058, counter2 = 0
7144734.779 ops/s


Result "calendar":
  7162859.716 ±(99.9%) 814867.378 ops/s [Average]
  (min, avg, max) = (7130105.519, 7162859.716, 7213738.851), stdev = 44665.631
  CI (99.9%): [6347992.338, 7977727.095] (assumes normal distribution)



# Benchmark: jmh.sample.ExampleBenchmark2.date

# Run progress: 50.00% complete, ETA 00:00:05
# Fork: 1 of 1
# Warmup Iteration   1: 
### setup ####################

### tear down ################
### counter1 = 0, counter2 = 96643989
96514687.983 ops/s
# Warmup Iteration   2: 
### setup ####################

### tear down ################
### counter1 = 0, counter2 = 96703330
96630201.133 ops/s
Iteration   1: 
### setup ####################

### tear down ################
### counter1 = 0, counter2 = 96986189
96949781.739 ops/s
Iteration   2: 
### setup ####################

### tear down ################
### counter1 = 0, counter2 = 97055331
97043232.329 ops/s
Iteration   3: 
### setup ####################

### tear down ################
### counter1 = 0, counter2 = 96976827
96883618.952 ops/s


Result "date":
  96958877.673 ±(99.9%) 1463046.415 ops/s [Average]
  (min, avg, max) = (96883618.952, 96958877.673, 97043232.329), stdev = 80194.511
  CI (99.9%): [95495831.259, 98421924.088] (assumes normal distribution)


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

Benchmark                    Mode  Cnt         Score         Error  Units
ExampleBenchmark2.calendar  thrpt    3   7162859.716 ±  814867.378  ops/s
ExampleBenchmark2.date      thrpt    3  96958877.673 ± 1463046.415  ops/s

ウォームアップの各イテレーションの前後と計測の各イテレーションの前後に初期化処理/終了処理が実行されていることが分かります


Benchmarkのメソッドが呼び出される度に実行

■サンプルコード

import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.Level;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.Setup;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.annotations.TearDown;
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;

@State(Scope.Thread)
public class ExampleBenchmark3 {
    private long counter1 = 0;
    private long counter2 = 0;

    @Benchmark
    public void calendar() {
        java.util.Date d = java.util.Calendar.getInstance().getTime();
        counter1++;
    }

    @Benchmark
    public void date() {
        java.util.Date d = new java.util.Date();
        counter2++;
    }

    @Setup(Level.Invocation)
    public void setup() {
        System.out.println("\n### setup ####################");

        counter1 = 0;
        counter2 = 0;
    }

    @TearDown(Level.Invocation)
    public void tearDown() {
        System.out.println("\n### tear down ################");
        System.out.println("### counter1 = " + counter1 + ", counter2 = " + counter2);
    }

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(ExampleBenchmark3.class.getSimpleName())
                .warmupIterations(2)
                .measurementIterations(3)
                .forks(1)
                .mode(Mode.Throughput)
                .build();
        new Runner(opt).run();
    }

}

■実行結果

例が悪いのですが、出力量がすごいので出力内容については省略します。
@Benchmarkの付与されたメソッドが呼び出されるたびに、setuptearDownの処理が実行される結果になります。


まとめ

@Setup@TearDownを使うことでJMHでの計測で初期化処理や終了処理を行うことができます。
その際に、どういう単位で初期化処理や終了処理を実行するかは、Levelの指定によって制御することができます。



関連エントリ