Micro benchmark made with JFR API

Introduction

Everyone is a great Flight Recorder, but the JFR API has been officially added from Java 9. I was curious, but I couldn't try it, but it would be nice if I could get various information from JFR, not just the execution time, this time. I thought, I made it using JFR API. Gist - koduki/TinyBenchmark.java

How to use it is like this.

public static void main(String[] args) throws IOException, ParseException {
    Path path = Paths.get("test.jfr");

    benchmarks(path, "ConcatString Benchmark", 3, (loop) -> {
        System.err.println("benchmarking...");
        benchmark(loop, "Concat all string by 'plus'", () -> ConcatString.fixedStringWithPlus(1_000), 1_000);
        benchmark(loop, "Concat all string by 'plus'", () -> ConcatString.fixedStringWithPlus(100_000), 10_000);
    });
    printReport(makeReport(path));
}

The benchmarks method outputs test.jfr, the makeReport analyzes JFR, and not only the custom event created this time but also the GC value acquired as standard is summarized and output as LTSV. If JFR has it, you can take any value, so if you want to do CPU or file I / O, you are free.

Execution result:

testcase:Concat all string by 'plus'	loop:0	arguments:[1000]	response(ms):113	gc_count:0	gc_total(ms):0	gc_max(ms):0	gc_avg(ms):0.000000
testcase:Concat all string by 'plus'	loop:0	arguments:[10000]	response(ms):20784	gc_count:237	gc_total(ms):250	gc_max(ms):12	gc_avg(ms):1.054852
testcase:Concat all string by 'plus'	loop:1	arguments:[1000]	response(ms):2	gc_count:0	gc_total(ms):0	gc_max(ms):0	gc_avg(ms):0.000000
testcase:Concat all string by 'plus'	loop:1	arguments:[10000]	response(ms):13782	gc_count:224	gc_total(ms):67	gc_max(ms):10	gc_avg(ms):0.299107
testcase:Concat all string by 'plus'	loop:2	arguments:[1000]	response(ms):0	gc_count:0	gc_total(ms):0	gc_max(ms):0	gc_avg(ms):0.000000
testcase:Concat all string by 'plus'	loop:2	arguments:[10000]	response(ms):12776	gc_count:225	gc_total(ms):34	gc_max(ms):2	gc_avg(ms):0.151111

Of course you can also see it in Mission Control. This time I opened it with JMC7. It seems that it has changed quite a bit since 6 and it seems that performance hotspots are analyzed automatically to some extent unlike 5.5 attached to Java 8. What is that amazing.

Now, let's continue with the implementation.

Create a custom event

First, create a custom event to store the benchmark information.

@Label("Benchmark")
static class BenchmarkEvent extends Event {
    @Label("Test Case")
    String testcase;
    @Label("Loop Count")
    int loop;
    @Label("Response")
    long response;
    @Label("Arguments")
    String arguments;
}

Basically, it seems that it can be handled by inheriting jdk.jfr.Event and adding the necessary fields. There are a lot of annotations other than Label, but I haven't been able to hold them down yet. Article here is detailed, but the specific content can only be seen in javadoc and the source.

Recording to custom events

Next is how to record to a custom event. This is also pretty simple. Click here for an example that was actually used.

BenchmarkEvent event = new BenchmarkEvent();

event.begin();
long s = System.nanoTime();

callback.run();

long e = System.nanoTime();

event.loop = loopCount;
event.testcase = testcase;
event.response = (e - s);
List<String> args = Arrays.stream(arguments).map(x -> x.toString()).collect(Collectors.toList());
event.arguments = "[" + String.join(",", args) + "]";
event.commit();

As you can see, new the BenchmarkEvent of the custom event created earlier and execute begin at the start timing of the event. Fill the fields with the required values to get a commit. It's easy to understand. It seems that the period between begin and commit is recorded as duration, so this time we are executing the benchmark processing during that time.

Perform JFR recording from the program

The usual way to use JFR is to specify arguments to java-agent and JVM options, right? I thought that was the only thing, but recently it seems that it can be called normally from Java code. After making it properly as a tool, it is not easy to specify appropriate options, but it is very convenient that you do not have to bother to attach it from JMC when you want to bench the code under development directly from the IDE.

Configuration jfrConfig = Configuration.getConfiguration("default");
try (Recording recording = new Recording(jfrConfig)) {
    recording.setName(name);
    recording.start();
    recording.enable(BenchmarkEvent.class);

    for (int i = 0; i < loopCount; i++) {
        callback.accept(i);
    }

    recording.stop();
    recording.dump(path);
}

As you can see, open jdk.jfr.Recording and it's in the form of start / stop and dump. One point to note is that if you do not get and specify Configuration, only the event specified by ʻenable` will be registered, so you need to specify it properly if you want CPU resources or memory status.

JFR loading

This feature I've been waiting for for a long time! Well, just because I couldn't catch up, at least from Java 9, maybe even 8 if unofficial. Anyway, it is a method to analyze the long-awaited JFR with PG. I'm really happy because I wanted to convert JFR to CSV.

Use jdk.jfr.consumer.RecordingFile to read.

List<RecordedEvent> gcEvents = RecordingFile.readAllEvents(path).stream()
        .filter((e) -> e.getEventType().getName().equals("jdk.G1GarbageCollection"))
        .collect(Collectors.toList());

It's a form of getting all the events included in JFR with readAllEvents and filtering with Stream API if necessary.

RecordedEvent contains several values. Are the following items that you might use often?

getEventType
getValue
getStartTime
getEndTime
getDuration

Since it is the same as the basic name, detailed explanation is omitted, but you can get the value by entering the name of the field in getValue. Please note that it is not a Label name.

Summary

I made a micro benchmark using the JFR API. Isn't it convenient because you can see not only the execution time but also the resource status? I think.

Also, this is the first time I've touched the JFR API, and it feels pretty good. It's easy to use.

Not to mention custom events, but if you use the analysis API well, your dreams will spread, such as creating distributed tracing tools based on JFR values, making them into web applications, and analyzing them with Kibana. From Java 11, JMC can also use JFR normally with OSS and OpenJDK, so I hope that it will develop further in the future.

However, I can't find any official documentation other than Javadoc. Is it code-readable? If anyone knows, please let me know> <

Then Happy Hacking!