March 2024 - hotspot-jfr-dev

RFR: 8326521: JFR: CompilerPhase event test fails on windows 32 bit
by Robert Toyonaga 20 Mar '24

20 Mar '24

This test failure is a problem for the Adoptium CI. The reason that this test fails on 32 bit Windows is that Hotspot only uses the C1 compiler in this configuration by design. If the system is Windows and not 64 bit, [NeverActAsServerClassMachine](https://github.com/openjdk/jdk/blob/master/sr… will be set. This results in setting the compilation mode to be [quick_only](https://github.com/openjdk/jdk/blob/master/src/hotspot/share/co…, which results in [constraining to C1 compilation](https://github.com/openjdk/jdk/blob/master/src/hotspot/share/c…. The CompilerPhase JFR events are only emitted from C2 code in hotspot. So although the test succeeds in compiling the method it intends to (with C1), it isn't able to generate the JFR events it expects, and so fails. ----------System.out:(4/182)---------- CompileCommand: compileonly jdk/jfr/event/compiler/TestCompilerPhase.dummyMethod bool compileonly = true 1 compiler directives added WB error: invalid compilation level 4 ----------System.err:(16/1050)---------- java.lang.RuntimeException: No events: expected false, was true at jdk.test.lib.Asserts.fail(Asserts.java:594) at jdk.test.lib.Asserts.assertFalse(Asserts.java:461) at jdk.test.lib.jfr.Events.hasEvents(Events.java:161) at jdk.jfr.event.compiler.TestCompilerPhase.main(TestCompilerPhase.java:76) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138) at java.base/java.lang.Thread.run(Thread.java:840) JavaTest Message: Test threw exception: java.lang.RuntimeException: No events: expected false, was true JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.RuntimeException: No events: expected false, was true This PR prevents `NeverActAsServerClassMachine` from being set during the test, so that it isn't restricted to C1. ------------- Commit messages: - Prevent NeverActAsServerClassMachine since we require C2 Changes: https://git.openjdk.org/jdk/pull/18379/files Webrev: https://webrevs.openjdk.org/?repo=jdk&pr=18379&range=00 Issue: https://bugs.openjdk.org/browse/JDK-8326521 Stats: 1 line in 1 file changed: 1 ins; 0 del; 0 mod Patch: https://git.openjdk.org/jdk/pull/18379.diff Fetch: git fetch https://git.openjdk.org/jdk.git pull/18379/head:pull/18379 PR: https://git.openjdk.org/jdk/pull/18379

2 2

RFR: 8327884: JFR view: Improve time display accuracy to milliseconds
by Long Yang 15 Mar '24

15 Mar '24

Could I have a review of this patch for [8327884](https://bugs.openjdk.org/browse/JDK-8327884) ? Now the time display accuracy is seconds. It's better if we can display milliseconds, especially when printing original events. This is a break change, consider this is a command line utility, it's acceptable. Testing: test/jdk/jdk/jfr/tool/TestView.java test/jdk/jdk/jfr/jcmd/TestJcmdView.java All passed. Thanks ------------- Commit messages: - 8327884: JFR view: Improve time display accuracy to milliseconds Changes: https://git.openjdk.org/jdk/pull/18219/files Webrev: https://webrevs.openjdk.org/?repo=jdk&pr=18219&range=00 Issue: https://bugs.openjdk.org/browse/JDK-8327884 Stats: 1 line in 1 file changed: 0 ins; 0 del; 1 mod Patch: https://git.openjdk.org/jdk/pull/18219.diff Fetch: git fetch https://git.openjdk.org/jdk.git pull/18219/head:pull/18219 PR: https://git.openjdk.org/jdk/pull/18219

2 7

RFR: 8327799: JFR view: the "Park Until" field of jdk.ThreadPark is invalid if the parking method is not absolute
by Long Yang 14 Mar '24

14 Mar '24

Hi all Could I have a review of this patch for [JDK-8327799](https://bugs.openjdk.org/browse/JDK-8327799)? UNSAFE.park(true, System.currentTimeMillis() + 1000); UNSAFE.park(false, 2000L * 1000 * 1000); jfr view jdk.ThreadPark test.jfr Java Thread Park Start Time Duration Event Thread Stack Trace Class Parked On Park Timeout Park Until Address of Object Pa... ---------- -------- ------------ ----------------------- --------------- ------------ ---------- ----------------------- 20:13:21 1.00 s main jdk.internal.misc.Un... N/A N/A 20:13:22 0x00000000 20:13:22 2.00 s main jdk.internal.misc.Un... N/A 2.00 s 08:05:43 0x00000000 If the parking method is not absolute (the second event), the real value of "until" in JFR event is `Long.MIN_VALUE`, which will be convert back to `java.time.Instant.MIN`, but `JFR view` displays this value as '08:05:43' of my timezone. This is somewhat misleading, better to show as `N/A`, just like what `jfr print --events` does. Testing: test/jdk/jdk/jfr/tool/TestView.java test/jdk/jdk/jfr/jcmd/TestJcmdView.java All passed. Thanks ------------- Commit messages: - 8327799: JFR view: the "Park Until" field of jdk.ThreadPark is invalid if the parking method is not absolute Changes: https://git.openjdk.org/jdk/pull/18214/files Webrev: https://webrevs.openjdk.org/?repo=jdk&pr=18214&range=00 Issue: https://bugs.openjdk.org/browse/JDK-8327799 Stats: 3 lines in 1 file changed: 3 ins; 0 del; 0 mod Patch: https://git.openjdk.org/jdk/pull/18214.diff Fetch: git fetch https://git.openjdk.org/jdk.git pull/18214/head:pull/18214 PR: https://git.openjdk.org/jdk/pull/18214

2 6

JFR causes spike in HeapMemoryAfterGC in prod ssystems
by Gaurav Gupta 12 Mar '24

12 Mar '24

Hi Team, I am Gaurav Gupta, Principal Engineer at Amazon India (gagup(a)amazon.com) My team is trying to enable JFR on production systems for studying any issues using custom events in JMC. Also we plan to study the impact of code changes in our application on system performance by studying JFR dumps using JMC and Flamescope (sub-second profiling). We tried enabling JFR in our prod system by adding following JVM args in our application startup (we have not yet added any custom event in our code: -XX:+FlightRecorder -XX:StartFlightRecording=name=SomeServiceJFR,disk=false,path-to-gc-roots=false -XX:FlightRecorderOptions=stackdepth=256,memorysize=60M,numglobalbuffers=2,globalbuffersize=30M,old-object-queue-size=64 (The reason we turned off the disk parameter is to avoid disk space issues during spiky traffic. We plan to take JFR dump on demand basis by running JFR.dump command line option to study application behavior and keep JFR recording on all the time). We saw the system performance metrics on HeapMemoryAfterGC rising from 5% to 30% (on our test fleet) after starting our application with above JVM args (i.e. with JFR enabled). As per our reading about JFR, it is claimed to be safe in prod systems with continuous JFR profiling. But the rise of the HeapMemory use raised concern. I seek your advice in this regard, if we are missing anything (wrt parameter configuration above) or are there other options to try without affecting the prod system. Also, is there a slack channel that I join for live discussion in this regard? How can I get added? PS: I won't be able to share the JFR dump file outside Amazon as it records events and stack traces for our proprietary software. But I am happy to come to a meeting on slack or other means and discuss this. Slack email: gagup(a)amazon.com -- Best regards, *Gaurav Gupta* ------------------------------------------------------------------------------------------------------------------------------- *"Perfection is achieved not when there is nothing more to add,but rather when there is nothing more to take away."*

3 5

RFR: 8327812: JFR: Remove debug message in Function.Maximum
by Erik Gahlin 11 Mar '24

11 Mar '24

Could I have a review of a change that removes a debug message that was accidentally checked in. Testing: jdk/jdk/jfr Thanks Erik ------------- Commit messages: - Initial Changes: https://git.openjdk.org/jdk/pull/18193/files Webrev: https://webrevs.openjdk.org/?repo=jdk&pr=18193&range=00 Issue: https://bugs.openjdk.org/browse/JDK-8327812 Stats: 4 lines in 1 file changed: 0 ins; 3 del; 1 mod Patch: https://git.openjdk.org/jdk/pull/18193.diff Fetch: git fetch https://git.openjdk.org/jdk.git pull/18193/head:pull/18193 PR: https://git.openjdk.org/jdk/pull/18193

3 3

Re: RFR: 8326446: The User and System of jdk.CPULoad on Apple M1 are inaccurate [v2]
by Long Yang 08 Mar '24

08 Mar '24

> hi > > I would like to fix this. > > As the description in [JDK-8326446](https://bugs.openjdk.org/browse/JDK-8326446). > JFR uses task_info() with flavor TASK_ABSOLUTETIME_INFO to read User and System time is not reliable on Apple m1. > > Libc provides the [times](https://man7.org/linux/man-pages/man2/times.2.html) function, which uses TASK_BASIC_INFO_COUNT and TASK_THREAD_TIMES_INFO_COUNT. It will also return the real time of the process, and the time unit is the same, which is suitable for solving this problem. > > I ran test/jdk/jdk/jfr/event/os/TestCPULoad.java and passed. > > I would appreciate it if you could review this. Long Yang has updated the pull request incrementally with one additional commit since the last revision: update copyright header ------------- Changes: - all: https://git.openjdk.org/jdk/pull/17976/files - new: https://git.openjdk.org/jdk/pull/17976/files/20a3e526..4cf1dba3 Webrevs: - full: https://webrevs.openjdk.org/?repo=jdk&pr=17976&range=01 - incr: https://webrevs.openjdk.org/?repo=jdk&pr=17976&range=00-01 Stats: 1 line in 1 file changed: 0 ins; 0 del; 1 mod Patch: https://git.openjdk.org/jdk/pull/17976.diff Fetch: git fetch https://git.openjdk.org/jdk.git pull/17976/head:pull/17976 PR: https://git.openjdk.org/jdk/pull/17976

3 14

Integrated: 8326446: The User and System of jdk.CPULoad on Apple M1 are inaccurate
by Long Yang 08 Mar '24

08 Mar '24

On Fri, 23 Feb 2024 07:49:45 GMT, Long Yang <duke(a)openjdk.org> wrote: > hi > > I would like to fix this. > > As the description in [JDK-8326446](https://bugs.openjdk.org/browse/JDK-8326446). > JFR uses task_info() with flavor TASK_ABSOLUTETIME_INFO to read User and System time. it is not reliable on Apple m1. > > Libc provides the [times](https://man7.org/linux/man-pages/man2/times.2.html) function, which uses TASK_BASIC_INFO_COUNT and TASK_THREAD_TIMES_INFO_COUNT. It will also return the real time of the process, and the time unit is the same, which is suitable for solving this problem. > > I ran test/jdk/jdk/jfr/event/os/TestCPULoad.java and passed. > > I would appreciate it if you could review this. This pull request has now been integrated. Changeset: 8dbd4b39 Author: yibo.yl <yibo.yl(a)alibaba-inc.com> Committer: Denghui Dong <ddong(a)openjdk.org> URL: https://git.openjdk.org/jdk/commit/8dbd4b391f7deb1a46a5f07f0bc46f23d6715ddb Stats: 30 lines in 1 file changed: 1 ins; 7 del; 22 mod 8326446: The User and System of jdk.CPULoad on Apple M1 are inaccurate Reviewed-by: mgronlun, egahlin ------------- PR: https://git.openjdk.org/jdk/pull/17976

1 0

RFR: 8327450: The result of jfr view active-settings is invalid if jfr file is created by JDK 11 or JDK 8
by Long Yang 07 Mar '24

07 Mar '24

Hi all Could I have a review of this patch ? If the jfr file is created by JDK 8 or JDK 11, and use jfr view to show the active-settings view, the result is invalid, missing many settings. jfr view active-settings j11.jfr Active Settings Event Type Enabled Threshold Stack Trace Period Cutoff Throttle ------------- ---------- ------------ -------------- --------- --------- ----------- File Force true 20 ms true --------------------------------------------------------- jfr summary j11.jfr ... Event Type Count Size (bytes) ============================================================= ... jdk.ActiveSetting 292 9528 ... The reason is the endTime of jdk.ActiveSetting on JDK 8 or JDK 11 increases naturally, the time between two consecutive events is approximately a few microseconds, but the query statement of active-settings view used LAST_BATCH(), It assumes that the end time of events are the same. For JDK 17 and above, this assumption is correct, but not for JDK 8 and JDK 11. ------------- Commit messages: - 8327450: The result of jfr view active-settings is invalid if jfr file is created by JDK 11 or JDK 8 Changes: https://git.openjdk.org/jdk/pull/18137/files Webrev: https://webrevs.openjdk.org/?repo=jdk&pr=18137&range=00 Issue: https://bugs.openjdk.org/browse/JDK-8327450 Stats: 42 lines in 7 files changed: 27 ins; 0 del; 15 mod Patch: https://git.openjdk.org/jdk/pull/18137.diff Fetch: git fetch https://git.openjdk.org/jdk.git pull/18137/head:pull/18137 PR: https://git.openjdk.org/jdk/pull/18137

2 3