RFR: 8316814: NMT: A separate script or Java program is needed to analyze and make useful reports ouf of JMH benchmarks outputs.

[Johan Sjölen]

On Fri, 6 Oct 2023 10:22:23 GMT, Afshin Zafari <azafari at openjdk.org> wrote:

> It reads the benchmark report file whose path is given as command line. Then extract percentage of overhead of NMT modes for different methods used in benchmarks.
> Locally tested with some sample report files.
> From an input benchmark report like this: 
> 
> # JMH version: 1.37
> # VM version: JDK 22-internal, OpenJDK 64-Bit Server VM,......in...
> # VM invoker:.....
> # VM options: -XX:NativeMemoryTracking=detail --add-exports java.base/jdk.internal.misc=ALL-UNNAMED -Djava.library.path=...
> # Blackhole mode: compiler (auto-detected, use -Djmh.blackhole.autoDetect=false to disable)
> # Warmup: 2 iterations, 1 s each
> # Measurement: 5 iterations, 1 s each
> # Timeout: 10 min per iteration
> # Threads: 1 thread, will synchronize iterations
> # Benchmark mode: Average time, time/op
> # Benchmark: org.openjdk.bench.vm.runtime.NMTBenchmark.NMTDetail.mixAallocateFreeMemory
> # Parameters: (N = 100000, THREADS = 4)
> 
> .
> .
> .
> 
> 
> Benchmark                                               (N)  (THREADS)  Mode  Cnt    Score    Error  Units
> NMTBenchmark.NMTDetail.mixAallocateFreeMemory        100000          0  avgt   10   87.010 ? 10.630  ms/op
> NMTBenchmark.NMTDetail.mixAallocateFreeMemory        100000          4  avgt   10    2.473 ?  0.728  ms/op
> NMTBenchmark.NMTDetail.mixAllocateReallocateMemory   100000          0  avgt   10  225.054 ?  4.381  ms/op
> NMTBenchmark.NMTDetail.mixAllocateReallocateMemory   100000          4  avgt   10    2.247 ?  0.599  ms/op
> NMTBenchmark.NMTDetail.onlyAllocateMemory            100000          0  avgt   10  147.346 ?  8.226  ms/op
> NMTBenchmark.NMTDetail.onlyAllocateMemory            100000          4  avgt   10    2.285 ?  0.611  ms/op
> NMTBenchmark.NMTOff.mixAallocateFreeMemory           100000          0  avgt   10   40.405 ?  8.115  ms/op
> NMTBenchmark.NMTOff.mixAallocateFreeMemory           100000          4  avgt   10    2.299 ?  0.658  ms/op
> NMTBenchmark.NMTOff.mixAllocateReallocateMemory      100000          0  avgt   10  158.700 ? 10.750  ms/op
> NMTBenchmark.NMTOff.mixAllocateReallocateMemory      100000          4  avgt   10    2.282 ?  0.723  ms/op
> NMTBenchmark.NMTOff.onlyAllocateMemory               100000          0  avgt   10  113.949 ? 21.257  ms/op
> NMTBenchmark.NMTOff.onlyAllocateMemory               100000          4  avgt   10    2.155 ?  0.682  ms/op
> NMTBenchmark.NMTSummary.mixAallocateFreeMemory       100000          0  avgt   10   50.436 ?  4.576  ms/op
> NMTBenchmark.NMTSummary.mixAallocateFreeMemory       100000          4  avgt   10    2.192 ?  0.7...

Hi Afshin!

PR output looks good, but I've got some comments on the code.

Hi Afshin, thanks for the ping. Changes looks good! Could you fix the whitespace issues that the bot has commented on?

test/micro/org/openjdk/bench/vm/runtime/NMTAnalyze.java line 42:

> 40:     public String units;
> 41:   }
> 42:   public static class BenchmarkFields {

Could use an enum here.

test/micro/org/openjdk/bench/vm/runtime/NMTAnalyze.java line 56:

> 54:   public static String fileName;
> 55:   public static List<BenchmarkRecord> records = new ArrayList<>();
> 56:   private static void skipUntilReport() {

Style: Missing newline to separate methods and properties.

test/micro/org/openjdk/bench/vm/runtime/NMTAnalyze.java line 61:

> 59:       while (line != null) {
> 60:         String ReportStartKeyword = "Benchmark";
> 61:         if (!line.startsWith(ReportStartKeyword) || line.contains("#")) {

Are there lines which starts with `Benchmark` but contains a `#` that we need to skip?

test/micro/org/openjdk/bench/vm/runtime/NMTAnalyze.java line 70:

> 68:     } catch (IOException ioe) {
> 69:       System.out.println(ioe.getMessage());
> 70:     }

Shouldn't the method itself just throw the `IOException`, since the caller handles it anyway? Otherwise, the rest of the body of `main` will execute.

test/micro/org/openjdk/bench/vm/runtime/NMTAnalyze.java line 73:

> 71:   }
> 72:   private static void readRecords() {
> 73:     try {

Same thing here regarding `IOException` should be thrown

test/micro/org/openjdk/bench/vm/runtime/NMTAnalyze.java line 74:

> 72:   private static void readRecords() {
> 73:     try {
> 74:       do {

Why not the same loop pattern as in `skipUntilReport`?

test/micro/org/openjdk/bench/vm/runtime/NMTAnalyze.java line 82:

> 80:         BenchmarkRecord rec = new BenchmarkRecord();
> 81:         List<String> __fields = Arrays.asList(_fields);
> 82:         String[] fields = __fields.stream().filter(f -> f.length() > 0).collect(Collectors.toList()).toArray(new String[0]);

Could fold the fields handling into one line without loss of readability: `Arrays.asList(line.split(" ")).stream()`

test/micro/org/openjdk/bench/vm/runtime/NMTAnalyze.java line 152:

> 150:     }
> 151: 
> 152:   }

Use try-with-resources here to not leak file descriptor in case of error https://docs.oracle.com/javase/tutorial/essential/exceptions/tryResourceClose.html

-------------

PR Review: https://git.openjdk.org/jdk/pull/16070#pullrequestreview-1673710105
Marked as reviewed by jsjolen (Reviewer).

PR Review: https://git.openjdk.org/jdk/pull/16070#pullrequestreview-1689609991
PR Review Comment: https://git.openjdk.org/jdk/pull/16070#discussion_r1356545990
PR Review Comment: https://git.openjdk.org/jdk/pull/16070#discussion_r1356584430
PR Review Comment: https://git.openjdk.org/jdk/pull/16070#discussion_r1356588411
PR Review Comment: https://git.openjdk.org/jdk/pull/16070#discussion_r1356586202
PR Review Comment: https://git.openjdk.org/jdk/pull/16070#discussion_r1356589182
PR Review Comment: https://git.openjdk.org/jdk/pull/16070#discussion_r1356590419
PR Review Comment: https://git.openjdk.org/jdk/pull/16070#discussion_r1356593355
PR Review Comment: https://git.openjdk.org/jdk/pull/16070#discussion_r1356583280