Wednesday, 3 August 2022

JMH: Get the individual operations cost with @OperationsPerInvocation

@OperationsPerInvocation allows you to communicate the benchmark does more than one operation, and let JMH to adjust the scores appropriately.

 

For example, a benchmark which uses the internal loop to have multiple operations, may want to measure the performance of a single operation.

@Benchmark
 @OperationsPerInvocation(10)
 public BigInteger add10TimesWithInvocationCount() {
    for (int i = 0; i < 10; i++) {
        b1.add(b2);
    }

    return b1;
}

 This annotation may be put at Benchmark method to have effect on that method only, or at the enclosing class instance to have the effect over all Benchmark methods in the class.

 

Find the below working application.

 


 

OperationsPerInvocationDemo.java
package com.sample.app;

import java.math.BigInteger;
import java.util.concurrent.TimeUnit;

import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.BenchmarkMode;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.annotations.OperationsPerInvocation;
import org.openjdk.jmh.annotations.OutputTimeUnit;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.State;
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)
@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
public class OperationsPerInvocationDemo {

    private BigInteger b1 = new BigInteger("23433686961963291297886553421867564211323");
    private BigInteger b2 = new BigInteger("9788655342186756421132397886553421867564211323");


    @Benchmark
    @OperationsPerInvocation(10)
    public BigInteger add10TimesWithInvocationCount() {
        for (int i = 0; i < 10; i++) {
            b1.add(b2);
        }

        return b1;
    }
    
    @Benchmark
    public BigInteger add10Times() {
        for (int i = 0; i < 10; i++) {
            b1.add(b2);
        }

        return b1;
    }

    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(OperationsPerInvocationDemo.class.getSimpleName())
                .forks(1)
                .measurementIterations(10)
                .warmupIterations(5)
                .build();

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

Output

# JMH version: 1.35
# VM version: JDK 15.0.2, Java HotSpot(TM) 64-Bit Server VM, 15.0.2+7-27
# VM invoker: /Library/Java/JavaVirtualMachines/jdk-15.0.2.jdk/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -XX:+ShowCodeDetailsInExceptionMessages
# Blackhole mode: full + dont-inline hint (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 5 iterations, 10 s each
# Measurement: 10 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: com.sample.app.OperationsPerInvocationDemo.add10Times

# Run progress: 0.00% complete, ETA 00:05:00
# Fork: 1 of 1
# Warmup Iteration   1: 107.531 ns/op
# Warmup Iteration   2: 106.741 ns/op
# Warmup Iteration   3: 103.800 ns/op
# Warmup Iteration   4: 101.851 ns/op
# Warmup Iteration   5: 99.021 ns/op
Iteration   1: 97.184 ns/op
Iteration   2: 100.575 ns/op
Iteration   3: 101.358 ns/op
Iteration   4: 98.152 ns/op
Iteration   5: 102.376 ns/op
Iteration   6: 102.304 ns/op
Iteration   7: 101.872 ns/op
Iteration   8: 104.272 ns/op
Iteration   9: 104.036 ns/op
Iteration  10: 104.204 ns/op


Result "com.sample.app.OperationsPerInvocationDemo.add10Times":
  101.633 ±(99.9%) 3.687 ns/op [Average]
  (min, avg, max) = (97.184, 101.633, 104.272), stdev = 2.439
  CI (99.9%): [97.947, 105.320] (assumes normal distribution)


# JMH version: 1.35
# VM version: JDK 15.0.2, Java HotSpot(TM) 64-Bit Server VM, 15.0.2+7-27
# VM invoker: /Library/Java/JavaVirtualMachines/jdk-15.0.2.jdk/Contents/Home/bin/java
# VM options: -Dfile.encoding=UTF-8 -XX:+ShowCodeDetailsInExceptionMessages
# Blackhole mode: full + dont-inline hint (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 5 iterations, 10 s each
# Measurement: 10 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: com.sample.app.OperationsPerInvocationDemo.add10TimesWithInvocationCount

# Run progress: 50.00% complete, ETA 00:02:30
# Fork: 1 of 1
# Warmup Iteration   1: 10.766 ns/op
# Warmup Iteration   2: 10.316 ns/op
# Warmup Iteration   3: 9.563 ns/op
# Warmup Iteration   4: 9.545 ns/op
# Warmup Iteration   5: 9.820 ns/op
Iteration   1: 10.140 ns/op
Iteration   2: 10.121 ns/op
Iteration   3: 10.178 ns/op
Iteration   4: 10.023 ns/op
Iteration   5: 9.588 ns/op
Iteration   6: 9.473 ns/op
Iteration   7: 9.595 ns/op
Iteration   8: 9.559 ns/op
Iteration   9: 9.677 ns/op
Iteration  10: 9.419 ns/op


Result "com.sample.app.OperationsPerInvocationDemo.add10TimesWithInvocationCount":
  9.777 ±(99.9%) 0.456 ns/op [Average]
  (min, avg, max) = (9.419, 9.777, 10.178), stdev = 0.302
  CI (99.9%): [9.321, 10.233] (assumes normal distribution)


# Run complete. Total time: 00:05: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
OperationsPerInvocationDemo.add10Times                     avgt   10  101.633 ± 3.687  ns/op
OperationsPerInvocationDemo.add10TimesWithInvocationCount  avgt   10    9.777 ± 0.456  ns/op

From the output, you can notice that the average time for the method add10TimesWithInvocationCount is calculated for each loop iteration.



 

 

 

Previous                                                 Next                                                 Home

No comments:

Post a Comment