TritonDataCenter / pkgsrc-joyent

Various pkgsrc packages used by Joyent, not committed upstream yet
30 stars 31 forks source link

Java flight recorder files produced by OpenJDK 11 are not properly readable by JMC #44

Closed siepkes closed 5 years ago

siepkes commented 5 years ago

One of the nice improvements in OpenJDK 11 (vs 8) is the open sourcing and inclusion of Java Flight Recorder. This allows for low overhead profiling which is very useful when hunting down performance issues in production systems.

Unfortunately when using flight recorder with the pkgsrc OpenJDK 11 package it will always result in a file which JMC (JDK Mission Control) says contains only 2 seconds worth of events. No matter how long you actually specify flight recorder to record. Oddly enough the file size of the file with the recordings is about what you would expect it to be.

For example if you take this Java application in a file called Test.java:

class Test {
        public static void main(String[] args) throws Exception {
                int x = 0;
                while(true) {
                        System.out.println(String.format("Test %s", x));
                        x++;
                        Thread.sleep(1000);
                }
        }
}

Compile and run it:

$ javac Test.java
$ java Test

Flip over to another terminal and tell flight recorder to record 60 seconds worth of profiling information:

$ jcmd 563390 JFR.start duration=60s settings=profile filename=/var/tmp/pkgsrc-openjdk-test.jfr

The file size is actually about what you would expect. However when opening the file with Mission Control the recording duration says 1 minute however there is only 1.867 seconds of "Recording Time span". It seems to always exactly be 1.867 seconds.

I used the Vanilla pkgsrc OpenJDK which is version 11.0.2 (not the Shenandoah branch).

$  java -version
openjdk version "11.0.2-internal" 2019-01-15
OpenJDK Runtime Environment (build 11.0.2-internal+0-adhoc.root.openjdk11-11.0.2)
OpenJDK 64-Bit Server VM (build 11.0.2-internal+0-adhoc.root.openjdk11-11.0.2, mixed mode)

I also did a test with pkgsrc OpenJDK Shenandoah which is version 11.0.4+11 but ended up with the same result.

To test if this isn't some bug in OpenJDK itself (maybe affecting all Solaris-like OS'es) I downloaded the Tribblix OpenJDK 11 package ( http://pkgs.tribblix.org/openjdk/ ) and did the same test. That leads to a flight recorder file of about the same size however when opened with Mission Control the "Recording Time span" is 60 seconds as expected.

A quick peek with objdump -s --section .comment jdk11.0.4/bin/java indicates Tribblix was build with Sun Studio.

I tested this with both Liberica Mission Control as with my own build of jmc master.

siepkes commented 5 years ago

Alright I seem to now also be able to encounter the same issue with the Tribblix OpenJDK build in larger applications. I think it has something to do with Solaris support of JFR rather then a pkgsrc GCC specific thing.

Sorry for the noise.