Showing posts with label jmh. Show all posts
Showing posts with label jmh. Show all posts

Sunday, 7 August 2022

Send the jmh log messages to a file

By setting the output file path using OptionsBuilder, we can send the log messages to a file.

 

Example

Options opt = new OptionsBuilder()
.include(SendLogMessagesToAFile.class.getSimpleName())
.forks(1)
.measurementIterations(4)
.warmupIterations(3)
.resultFormat(ResultFormatType.JSON)
.output("/Users/Shared/logMessages.log")
.build();

 

Above snippet send the log messages to the file "/Users/Shared/ logMessages.log".

 

Find the below working application.

 

SendLogMessagesToAFile.java
package com.sample.app;

import java.util.concurrent.TimeUnit;

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

public class SendLogMessagesToAFile {
    
    @Benchmark
    public void test1() throws InterruptedException {
        TimeUnit.MILLISECONDS.sleep(300);
    }
    
    public static void main(String[] args) throws RunnerException {
        Options opt = new OptionsBuilder()
                .include(SendLogMessagesToAFile.class.getSimpleName())
                .forks(1)
                .measurementIterations(4)
                .warmupIterations(3)
                .resultFormat(ResultFormatType.JSON)
                .output("/Users/Shared/logMessages.log")
                .build();

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

Run the above application and open the file ‘/Users/Shared/logMessages.log’ to see the log messages.

 

 

 

  

Previous                                                 Next                                                 Home

Wednesday, 3 August 2022

JMH: Send the benchmark results to a file

By setting the result option using OptionsBuilder, we can send the benchmark results to a file.

 

Example

Options opt = new OptionsBuilder()
.include(SendResultToAFile.class.getSimpleName())
.forks(1)
.measurementIterations(4)
.warmupIterations(3)
.resultFormat(ResultFormatType.JSON)
.result("/Users/Shared/result.json")
.build();

Above snippet send the benchmark results to the file "/Users/Shared/result.json".

 

Find the below working application.

 

SendResultToAFile.java

package com.sample.app;

import java.util.concurrent.TimeUnit;

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

public class SendResultToAFile {
	
	@Benchmark
	public void test1() throws InterruptedException {
		TimeUnit.MILLISECONDS.sleep(300);
	}
	
	public static void main(String[] args) throws RunnerException {
		Options opt = new OptionsBuilder()
				.include(SendResultToAFile.class.getSimpleName())
				.forks(1)
				.measurementIterations(4)
				.warmupIterations(3)
				.resultFormat(ResultFormatType.JSON)
				.result("/Users/Shared/result.json")
				.build();

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

Run the application and you can see result.json file will be created with benchmark results.

 


Previous                                                 Next                                                 Home

JMH: result format types

At the time of writing this post, JMH support following result format types.

 

a.   TEXT

b.   CSV

c.    SCSV

d.   JSON

e.   LATEX

 

For example, below snippet set the result format type to JSON.

 Options opt = new OptionsBuilder()
.include(OptionsBuilderDemo.class.getSimpleName())
.forks(1)
.measurementIterations(4)
.warmupIterations(3)
.resultFormat(ResultFormatType.JSON)
.result("/Users/Shared/result.json")
.build();

 

Find the below working application.

 


ResultFormatTypes.java
package com.sample.app;

import java.util.concurrent.TimeUnit;

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

public class ResultFormatTypes {
	
	@Benchmark
	public void test1() throws InterruptedException {
		TimeUnit.MILLISECONDS.sleep(300);
	}
	
	public static void main(String[] args) throws RunnerException {
		Options opt = new OptionsBuilder()
				.include(OptionsBuilderDemo.class.getSimpleName())
				.forks(1)
				.measurementIterations(4)
				.warmupIterations(3)
				.resultFormat(ResultFormatType.JSON)
				.result("/Users/Shared/result.json")
				.build();

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

Run the application and you can see result.json file will be created with benchmark results.

 

result.json

[
    {
        "jmhVersion" : "1.35",
        "benchmark" : "com.sample.app.OptionsBuilderDemo.randString",
        "mode" : "thrpt",
        "threads" : 1,
        "forks" : 1,
        "jvm" : "/Library/Java/JavaVirtualMachines/jdk-15.0.2.jdk/Contents/Home/bin/java",
        "jvmArgs" : [
            "-Dfile.encoding=UTF-8",
            "-XX:+ShowCodeDetailsInExceptionMessages"
        ],
        "jdkVersion" : "15.0.2",
        "vmName" : "Java HotSpot(TM) 64-Bit Server VM",
        "vmVersion" : "15.0.2+7-27",
        "warmupIterations" : 3,
        "warmupTime" : "10 s",
        "warmupBatchSize" : 1,
        "measurementIterations" : 4,
        "measurementTime" : "10 s",
        "measurementBatchSize" : 1,
        "primaryMetric" : {
            "score" : 89.14587141327391,
            "scoreError" : 4.071006493877836,
            "scoreConfidence" : [
                85.07486491939608,
                93.21687790715174
            ],
            "scorePercentiles" : {
                "0.0" : 88.43890338977174,
                "50.0" : 89.0898802448304,
                "90.0" : 89.96482177366312,
                "95.0" : 89.96482177366312,
                "99.0" : 89.96482177366312,
                "99.9" : 89.96482177366312,
                "99.99" : 89.96482177366312,
                "99.999" : 89.96482177366312,
                "99.9999" : 89.96482177366312,
                "100.0" : 89.96482177366312
            },
            "scoreUnit" : "ops/s",
            "rawData" : [
                [
                    89.96482177366312,
                    89.17330427249975,
                    89.00645621716103,
                    88.43890338977174
                ]
            ]
        },
        "secondaryMetrics" : {
        }
    }
]

 

Previous                                                 Next                                                 Home

Run JMH benchmarking from a junit test

Define a benchmark method in the test class.

@Benchmark
    public void test() {
        String result = StringUtil.replaceMultipleSpaces("Hello there how are you....  ");
        assertEquals("Hello there how are you.... ", result);
    }

Call the runner in the junit test method.

@Test
    public void benchmark() throws Exception {
        Options opt = new OptionsBuilder()
                .include(this.getClass().getSimpleName())
                .forks(2)
                .measurementIterations(1)
                .warmupIterations(1)
                .build();
        

        new Runner(opt).run();
    }

Find the below working application.

 

JunitTestDemo.java

package com.sample.app;

import static org.junit.Assert.assertEquals;

import org.junit.Test;
import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;

import com.sample.app.util.StringUtil;


public class JunitTestDemo {

    @Benchmark
    public void test() {
        String result = StringUtil.replaceMultipleSpaces("Hello there how are you....  ");
        assertEquals("Hello there how are you.... ", result);
    }

    @Test
    public void benchmark() throws Exception {
        Options opt = new OptionsBuilder()
                .include(this.getClass().getSimpleName())
                .forks(2)
                .measurementIterations(1)
                .warmupIterations(1)
                .build();
        

        new Runner(opt).run();
    }

}

Run the class ‘JunitTestDemo’ as junit test, you will get the jmh messages in system console.

# 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: -ea -Dfile.encoding=UTF-8 -XX:+ShowCodeDetailsInExceptionMessages
# Blackhole mode: full + dont-inline hint (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
# Warmup: 1 iterations, 10 s each
# Measurement: 1 iterations, 10 s each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Throughput, ops/time
# Benchmark: com.sample.app.JunitTestDemo.test

# Run progress: 0.00% complete, ETA 00:00:40
# Fork: 1 of 2
# Warmup Iteration   1: 2162584.129 ops/s
Iteration   1: 2341717.486 ops/s

# Run progress: 50.00% complete, ETA 00:00:20
# Fork: 2 of 2
# Warmup Iteration   1: 2077664.321 ops/s
Iteration   1: 2353474.007 ops/s


Result "com.sample.app.JunitTestDemo.test":
  2347595.747 ops/s


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

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
JunitTestDemo.test  thrpt    2  2347595.747          ops/s




 

Previous                                                 Next                                                 Home

Jmh: @Param: Benchmark with different values

Using @Param annotation, we can benchmark a method by passing different values.

 

Example

 

public class ParamDemo {

    @Param({ "2978169", "3324329", "53", "71", "1191267381" })
    public long primes;

    @Param({ "2", "4", "8", "16" })
    public int certainty;
    
    @Benchmark
    public boolean bench() {
        return BigInteger.valueOf(primes).isProbablePrime(certainty);
    }

    ..........
    ..........
}

 

Param fields should be non-final fields, and should only reside in State classes. JMH will inject the value into the annotated field before any Setup method is called. It is not guaranteed the field value would be accessible in any initializer or any constructor of State.

 


Find the below working application.

 

ParamDemo.java
package com.sample.app;

import java.io.IOException;
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.Fork;
import org.openjdk.jmh.annotations.Measurement;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.annotations.OutputTimeUnit;
import org.openjdk.jmh.annotations.Param;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.annotations.Warmup;
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;

@BenchmarkMode(Mode.AverageTime)
@OutputTimeUnit(TimeUnit.NANOSECONDS)
@Warmup(iterations = 3, time = 3, timeUnit = TimeUnit.SECONDS)
@Measurement(iterations = 3, time = 3, timeUnit = TimeUnit.SECONDS)
@Fork(2)
@State(Scope.Benchmark)
public class ParamDemo {

    @Param({ "2978169", "3324329", "53", "71", "1191267381" })
    public long primes;

    @Param({ "2", "4", "8", "16" })
    public int certainty;
    
    @Benchmark
    public boolean bench() {
        return BigInteger.valueOf(primes).isProbablePrime(certainty);
    }

    public static void main(String[] args) throws IOException, RunnerException {
        Options opt = new OptionsBuilder()
                .include(ParamDemo.class.getSimpleName())
                .build();

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

 


 

Previous                                                 Next                                                 Home

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

Jmh: be cautious with dead code

What is dead code?

Dead code is the one that never executed in run time.

 

DeadCodeEx.java

package com.sample.app;

public class DeadCodeEx {
    public static void main(String[] args) {
        final boolean b = true;
        
        if(b) {
            System.out.println("b is set to true");
        }else {
            System.out.println("b is set to false");
        }
    }
}

 

Notice above code snippet, the code is else block will never get executed, this is an example of dead code.

 

Now  a days compilers are smart enough to identify and delete the dead code. If the eliminated part was our benchmarked code, then we will get wrong benchmarking results.

 

Let me explain it with an example.

 

DeadcodeEliminationDemo.java

 

package com.sample.app;

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.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 DeadcodeEliminationDemo {

    private double fib(int n) {
        if (n <= 1) {
            return n;
        }
        
        int fib = 1;
        int prevFib = 1;

        for (int i = 2; i < n; i++) {
            int temp = fib;
            fib += prevFib;
            prevFib = temp;
        }
        return fib;

    }

    @Benchmark
    public void baseline() {
        // do nothing
    }

    @Benchmark
    public void measureWrong() {
        fib(20);
    }

    @Benchmark
    public double measureRight() {
        // Here result is returned to the calling function.
        return fib(20);
    }

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

        new Runner(opt).run();
    }

}

When I ran the application, I got below benchmark results.

Benchmark                             Mode  Cnt  Score   Error  Units
DeadcodeEliminationDemo.baseline      avgt    2  0.398          ns/op
DeadcodeEliminationDemo.measureRight  avgt    2  2.398          ns/op
DeadcodeEliminationDemo.measureWrong  avgt    2  0.570          ns/op

Even though both ‘measureWrong’ and ‘measureRight’ methods calling fib(20) internally, measureWrong method took 0.57 nano seconds per operation, where as measureRight  took 2.398 nano seconds per operation.

 


 

 

Why measureWrong taking very less time as compared to measureRight?

As you see the definition of ‘measureWrong’ method, it is not using the result of fib(20) anywhere, so compiler treat this as dead code and eliminate it.


public void measureWrong() {
        fib(20);
}

Be cautious, while measuring the benchmark with these kind of scenarios.

There are two approaches to handle this scenario.

 

Approach 1: Just return the created data.

public void measureWrong() {
        return fib(20);
}

 

Approach 2: Let the Blackhole consume the data.

@Benchmark
public void measureWrong(Blackhole blackhole) {
	blackhole.consume(fib(20));
}

 

 

Previous                                                 Next                                                 Home