Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Enables parsing units for maxsize, fixes units for delay in JfrManager.java #3639

Merged
merged 2 commits into from
Aug 12, 2021

Conversation

Karm
Copy link
Contributor

@Karm Karm commented Jul 30, 2021

Fixes #3638

Unpatched ❌

$ export JAVA_HOME=/home/karm/X/JDKs/graalvm-ce-java11-21.2.0/;export PATH=${JAVA_HOME}/bin:${PATH}

$ native-image --version
GraalVM 21.2.0 Java 11 CE (Java Version 11.0.12+6-jvmci-21.2-b08)

$ javac Main.java

$ native-image -H:+AllowVMInspection Main

$ java -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10M,filename=flight-java.jfr -Xlog:jfr Main
[0.279s][info][jfr] Flight Recorder initialized
[0.279s][info][jfr] Created repository /tmp/2021_07_30_15_11_00_295289
[0.309s][info][jfr] Creating thread sampler for java:20 ms, native 0 ms
[0.309s][info][jfr] Enrolling thread sampler
[0.309s][info][jfr] Enrolling thread sampler
[0.309s][info][jfr] Updated thread sampler for java: 20  ms, native 0 ms
[0.309s][info][jfr] Updated thread sampler for java: 20  ms, native 0 ms
[0.309s][info][jfr] Updated thread sampler for java: 20  ms, native 20 ms
[0.322s][info][jfr] Started recording "1" (1) {maxsize=10.0MB, dumponexit=true, filename=/tmp/rep/flight-java.jfr}
Started recording 1.
Use jcmd 295289 JFR.dump name=1 to copy recording data to file.
Meh.
[0.343s][info][jfr] Updated thread sampler for java: 0  ms, native 20 ms
[0.344s][info][jfr] Disenrolling thread sampler
[0.344s][info][jfr] Stopped recording "1" (1). Reason "Dump on exit".
[0.382s][info][jfr] Wrote recording "1" (1) to /tmp/rep/flight-java.jfr
[0.382s][info][jfr] Closed recording "1" (1)
[0.383s][info][jfr] Removed repository /tmp/2021_07_30_15_11_00_295289

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10M,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
Exception in thread "main" com.oracle.svm.core.util.UserError$UserException: Could not parse JFR argument 'maxsize=10M'. Expected a number.
    at com.oracle.svm.core.util.UserError.abort(UserError.java:68)
    at com.oracle.svm.jfr.JfrManager.parseLong(JfrManager.java:171)
    at com.oracle.svm.jfr.JfrManager.initRecording(JfrManager.java:107)
    at com.oracle.svm.jfr.JfrManager.setup(JfrManager.java:72)
    at com.oracle.svm.core.jdk.RuntimeSupport.executeHooks(RuntimeSupport.java:125)
    at com.oracle.svm.core.jdk.RuntimeSupport.executeStartupHooks(RuntimeSupport.java:75)

Patched ✔️

$ export JAVA_HOME=/home/karm/tmp/mandrel-java11-21.3-SNAPSHOT/;export PATH=${JAVA_HOME}/bin:${PATH}

$ native-image --version
native-image 21.3.0-deveab4c4ec5cb5 Mandrel Distribution (Java Version 11.0.12+7)

$ native-image -H:+AllowVMInspection Main

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10M,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_13_28_295949
[info][jfr] Started recording "1" (1) {maxsize=10.0MB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10m,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_13_55_296117
[info][jfr] Started recording "1" (1) {maxsize=10.0MB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10k,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_14_00_296178
[info][jfr] Started recording "1" (1) {maxsize=10.0kB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10K,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_14_05_296238
[info][jfr] Started recording "1" (1) {maxsize=10.0kB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10g,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_14_11_296302
[info][jfr] Started recording "1" (1) {maxsize=10.0GB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10G,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_16_04_296529
[info][jfr] Started recording "1" (1) {maxsize=10.0GB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10000000,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_20_59_298189
[warn][jfr,system] Unable to commit. Requested size 8589 too large
[info][jfr       ] Started recording "1" (1) {maxsize=9.5MB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

FYI @jiekang Good / no good?

@jiekang jiekang self-requested a review August 2, 2021 01:23
return number * 1024 * 1024;
case 'g':
case 'G':
return number * 1024 * 1024 * 1024;
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In following https://github.com/openjdk/jdk/blob/master/src/hotspot/share/services/diagnosticArgument.cpp#L328 I think this just needs an addition to support the default case. (Code is similar in jdk11)

Everything else looks fine!

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jiekang See https://github.com/oracle/graal/pull/3639/files/355161c32f3a1bf3b5e09826527f32503fdf0d8c#r681255719

Would you like me to refactor that

                // Missing unit, number is plain bytes
                if (idx == value.length()) {
                    return number;

to a default switch branch or is it O.K. like this after all?

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think there's a slight difference in that the default switch catches multipliers or delimiters not in the given set, treating them as bytes, while the early return catches the no multiplier case.

E.g. it seems with the HotSpot code, something like maxsize=5c, would be accepted as a bytes while here we would throw an exception. I'm not sure I agree with that, but for best transfer of existing settings, it would be easiest to support the same.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Though let me actually test that to see what happens with an OpenJDK build; will be later this evening though.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jiekang You are right. I've just tested that. It is counter intuitive, but HotSpot really gracefully ignores unknown units and treats the number as bytes:


$ java -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=100000c,filename=flight-java.jfr -Xlog:jfr Main 
[0.370s][info][jfr] Started recording "1" (1) {maxsize=97.7kB, dumponexit=true, filename=/tmp/rep/flight-java.jfr}


$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=100000c,filename=flight-java.jfr -XX:FlightRecorderLogging=jfr
Exception in thread "main" com.oracle.svm.core.util.UserError$UserException: Could not parse JFR argument 'maxsize=100000c'. Unit is invalid.
    at com.oracle.svm.core.util.UserError.abort(UserError.java:68)
    at com.oracle.svm.jfr.JfrManager.parseMaxSize(JfrManager.java:238)
    at com.oracle.svm.jfr.JfrManager.initRecording(JfrManager.java:107)
    at com.oracle.svm.jfr.JfrManager.setup(JfrManager.java:72)
    at com.oracle.svm.core.jdk.RuntimeSupport.executeHooks(RuntimeSupport.java:125)
    at com.oracle.svm.core.jdk.RuntimeSupport.executeStartupHooks(RuntimeSupport.java:75)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jiekang I modified the behavior as you suggested. native-image and HotSpot behave the same now:

$  for maxsize in 100000c 100000 100000x 100000xxx 100k 100K 10M 10m 1g 1G 1gg; do echo;echo "maxsize: $maxsize";echo -e "Native-image:\c";./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=$maxsize -XX:FlightRecorderLogging=jfr 2>&1 | grep "maxsize=";echo -e "HotSpot:\c";java -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=$maxsize -Xlog:jfr 2>&1 | grep "maxsize=";done

maxsize: 100000c
Native-image:[info][jfr] Started recording "1" (1) {maxsize=97.7kB}
HotSpot:[0.334s][info][jfr] Started recording "1" (1) {maxsize=97.7kB}

maxsize: 100000
Native-image:[info][jfr] Started recording "1" (1) {maxsize=97.7kB}
HotSpot:[0.325s][info][jfr] Started recording "1" (1) {maxsize=97.7kB}

maxsize: 100000x
Native-image:[info][jfr] Started recording "1" (1) {maxsize=97.7kB}
HotSpot:[0.345s][info][jfr] Started recording "1" (1) {maxsize=97.7kB}

maxsize: 100000xxx
Native-image:[info][jfr] Started recording "1" (1) {maxsize=97.7kB}
HotSpot:[0.347s][info][jfr] Started recording "1" (1) {maxsize=97.7kB}

maxsize: 100k
Native-image:[info][jfr] Started recording "1" (1) {maxsize=100.0kB}
HotSpot:[0.345s][info][jfr] Started recording "1" (1) {maxsize=100.0kB}

maxsize: 100K
Native-image:[info][jfr] Started recording "1" (1) {maxsize=100.0kB}
HotSpot:[0.342s][info][jfr] Started recording "1" (1) {maxsize=100.0kB}

maxsize: 10M
Native-image:[info][jfr] Started recording "1" (1) {maxsize=10.0MB}
HotSpot:[0.322s][info][jfr] Started recording "1" (1) {maxsize=10.0MB}

maxsize: 10m
Native-image:[info][jfr] Started recording "1" (1) {maxsize=10.0MB}
HotSpot:[0.332s][info][jfr] Started recording "1" (1) {maxsize=10.0MB}

maxsize: 1g
Native-image:[info][jfr] Started recording "1" (1) {maxsize=1.0GB}
HotSpot:[0.334s][info][jfr] Started recording "1" (1) {maxsize=1.0GB}

maxsize: 1G
Native-image:[info][jfr] Started recording "1" (1) {maxsize=1.0GB}
HotSpot:[0.353s][info][jfr] Started recording "1" (1) {maxsize=1.0GB}

maxsize: 1gg
Native-image:[info][jfr] Started recording "1" (1) {maxsize=1.0GB}
HotSpot:[0.324s][info][jfr] Started recording "1" (1) {maxsize=1.0GB}

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Excellent, thank you!

Fixes oracle#3638

Example:

Unpatched
---------

```
$ export JAVA_HOME=/home/karm/X/JDKs/graalvm-ce-java11-21.2.0/;export PATH=${JAVA_HOME}/bin:${PATH}

$ native-image --version
GraalVM 21.2.0 Java 11 CE (Java Version 11.0.12+6-jvmci-21.2-b08)

$ javac Main.java

$ native-image -H:+AllowVMInspection Main

$ java -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10M,filename=flight-java.jfr -Xlog:jfr Main
[0.279s][info][jfr] Flight Recorder initialized
[0.279s][info][jfr] Created repository /tmp/2021_07_30_15_11_00_295289
[0.309s][info][jfr] Creating thread sampler for java:20 ms, native 0 ms
[0.309s][info][jfr] Enrolling thread sampler
[0.309s][info][jfr] Enrolling thread sampler
[0.309s][info][jfr] Updated thread sampler for java: 20  ms, native 0 ms
[0.309s][info][jfr] Updated thread sampler for java: 20  ms, native 0 ms
[0.309s][info][jfr] Updated thread sampler for java: 20  ms, native 20 ms
[0.322s][info][jfr] Started recording "1" (1) {maxsize=10.0MB, dumponexit=true, filename=/tmp/rep/flight-java.jfr}
Started recording 1.
Use jcmd 295289 JFR.dump name=1 to copy recording data to file.
Meh.
[0.343s][info][jfr] Updated thread sampler for java: 0  ms, native 20 ms
[0.344s][info][jfr] Disenrolling thread sampler
[0.344s][info][jfr] Stopped recording "1" (1). Reason "Dump on exit".
[0.382s][info][jfr] Wrote recording "1" (1) to /tmp/rep/flight-java.jfr
[0.382s][info][jfr] Closed recording "1" (1)
[0.383s][info][jfr] Removed repository /tmp/2021_07_30_15_11_00_295289

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10M,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
Exception in thread "main" com.oracle.svm.core.util.UserError$UserException: Could not parse JFR argument 'maxsize=10M'. Expected a number.
    at com.oracle.svm.core.util.UserError.abort(UserError.java:68)
    at com.oracle.svm.jfr.JfrManager.parseLong(JfrManager.java:171)
    at com.oracle.svm.jfr.JfrManager.initRecording(JfrManager.java:107)
    at com.oracle.svm.jfr.JfrManager.setup(JfrManager.java:72)
    at com.oracle.svm.core.jdk.RuntimeSupport.executeHooks(RuntimeSupport.java:125)
    at com.oracle.svm.core.jdk.RuntimeSupport.executeStartupHooks(RuntimeSupport.java:75)
```

Patched
-------

```
$ export JAVA_HOME=/home/karm/tmp/mandrel-java11-21.3-SNAPSHOT/;export PATH=${JAVA_HOME}/bin:${PATH}

$ native-image --version
native-image 21.3.0-deveab4c4ec5cb5 Mandrel Distribution (Java Version 11.0.12+7)

$ native-image -H:+AllowVMInspection Main

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10M,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_13_28_295949
[info][jfr] Started recording "1" (1) {maxsize=10.0MB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10m,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_13_55_296117
[info][jfr] Started recording "1" (1) {maxsize=10.0MB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10k,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_14_00_296178
[info][jfr] Started recording "1" (1) {maxsize=10.0kB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10K,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_14_05_296238
[info][jfr] Started recording "1" (1) {maxsize=10.0kB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10g,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_14_11_296302
[info][jfr] Started recording "1" (1) {maxsize=10.0GB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>

$ ./main -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10G,filename=flight-native.jfr -XX:FlightRecorderLogging=jfr
[info][jfr] Flight Recorder initialized
[info][jfr] Created repository /tmp/2021_07_30_15_16_04_296529
[info][jfr] Started recording "1" (1) {maxsize=10.0GB, dumponexit=true, filename=/tmp/rep/flight-native.jfr}
Meh.
<removed for brevity>
```

Signed-off-by: Michal Karm Babacek <karm@redhat.com>
@Karm Karm requested a review from jiekang August 2, 2021 21:43
@@ -193,7 +193,7 @@ private static Long parseDuration(Map<JfrStartArgument, String> args, JfrStartAr
return Duration.ofMinutes(time).toNanos();
} else if ("h".equals(unit)) {
return Duration.ofHours(time).toNanos();
} else if ("f".equals(unit)) {
} else if ("d".equals(unit)) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@jiekang This was supposed to be 'd' for days as HotSpot does, not 'f'. I changed that in a separate commit. Keeping it in the same PR as it's related to the same topic.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice catch, thanks!

@Karm Karm changed the title Enables parsing units for maxsize in JfrManager.java Enables parsing units for maxsize, fixes units for delay in JfrManager.java Aug 2, 2021
case 'G':
return number * 1024 * 1024 * 1024;
default:
return number;
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could a comment be added here to explain the default case?

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Rest LGTM!

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could a comment be added here to explain the default case?

Comment added. Squashed into the previous commit 👍

see:

```
java -XX:+FlightRecorder -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10000,maxage=10000m,delay=5f,filename=flight-native.jfr -Xlog:jfr  Main
java.lang.IllegalArgumentException: Integer parsing error nanotime value: illegal unit

whereas

java -XX:+FlightRecorder -XX:+FlightRecorder -XX:StartFlightRecording=maxsize=10000,maxage=10000m,delay=5d,filename=flight-native.jfr -Xlog:jfr  Main
[0.562s][info][jfr] Flight Recorder initialized
[0.562s][info][jfr] Created repository /tmp/2021_08_03_01_16_07_454665
[0.567s][info][jfr] Scheduled recording "1" (1) to start at 2021-08-08T01:16:07.684825
```

Signed-off-by: Michal Karm Babacek <karm@redhat.com>
@Karm
Copy link
Contributor Author

Karm commented Aug 4, 2021

Hello, @mcraj017, could it be merged?

@munishchouhan munishchouhan self-assigned this Aug 6, 2021
@munishchouhan
Copy link
Contributor

Hi @Karm sure, I have added the reviewer, once approved I will merge it

@jiekang
Copy link
Collaborator

jiekang commented Aug 6, 2021

@mcraj017 Hi! I briefly spoke with Christian H. about reviewing JFR changes on the GraalVM Slack and he mentioned adding him and Tom Shull as okay, so I've done that here.

Copy link
Member

@christianhaeubl christianhaeubl left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for the fixes, I added one minor question.

@Karm
Copy link
Contributor Author

Karm commented Aug 10, 2021

THX @christianhaeubl

@mcraj017 Is there anything else to be reviewed or anything else I can do for this PR?

@munishchouhan
Copy link
Contributor

@Karm thanks for the contribution, I will start the merging process

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

native-image, UX, JFR, -XX:StartFlightRecording flags/arguments units are not aligned with HotSpot convention
5 participants