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

Fix JFR timestamps #20049

Merged
merged 1 commit into from
Aug 26, 2024
Merged

Fix JFR timestamps #20049

merged 1 commit into from
Aug 26, 2024

Conversation

tajila
Copy link
Contributor

@tajila tajila commented Aug 23, 2024

Set the ticks/second parameter in the chunk header. This indicates which granularity we report timestamps (millis, micros or nanos). Note, this is not to be confused with the event startime which is always milliseconds.

Also, chage threadsleep event to report on after the sleep as concluded which matches RI behaviour. The actual sleep duration must be recorded.

@tajila tajila requested a review from gacholio August 23, 2024 14:41
@gacholio
Copy link
Contributor

jenkins test sanity xlinux jdk21

@gacholio
Copy link
Contributor

There's a vast amount of output from the build, but I can't see what failed.

@gacholio
Copy link
Contributor

Found it:

04:33:24  Optimizing the exploded image
04:33:44  Unhandled exception
04:33:44  Type=Segmentation error vmState=0x00000000
04:33:44  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
04:33:44  Handler1=00002B885E0A4DE0 Handler2=00002B885CD68740 InaccessibleAddress=0000000000000000
04:33:44  RDI=000000000023CD00 RSI=0000000000000000 RAX=0000000000000000 RBX=000000000023D000
04:33:44  RCX=0000000000000020 RDX=0000000000000000 R8=0000000000000000 R9=0000000000000001
04:33:44  R10=00002B8867FB02A0 R11=0000000000000206 R12=00002B8860173FA0 R13=00002B8867FB0600
04:33:44  R14=000000000023CD00 R15=00002B8867FB0900
04:33:44  RIP=00002B885E0992D0 GS=0000 FS=0000 RSP=00002B8867FB03B0
04:33:44  EFlags=0000000000010202 CS=0033 RBP=0000000000016D70 ERR=0000000000000004
04:33:44  TRAPNO=000000000000000E OLDMASK=0000000000000000 CR2=0000000000000000
04:33:44  xmm0=0000000000612803 (f: 6367235.000000, d: 3.145832e-317)
04:33:44  xmm1=00000000390efe34 (f: 957283904.000000, d: 4.729611e-315)
04:33:44  xmm2=019ee085b7654321 (f: 3076866816.000000, d: 7.204105e-301)
04:33:44  xmm3=6c735f6461657268 (f: 1634038400.000000, d: 2.608708e+214)
04:33:44  xmm4=0000000000000002 (f: 2.000000, d: 9.881313e-324)
04:33:44  xmm5=00002b88601740c9 (f: 1612136704.000000, d: 2.364832e-310)
04:33:44  xmm6=0000000000016d80 (f: 93568.000000, d: 4.622873e-319)
04:33:44  xmm7=00002b88b40063e4 (f: 3019924480.000000, d: 2.364901e-310)
04:33:44  xmm8=dddddddddddddddd (f: 3722305024.000000, d: -1.456816e+144)
04:33:44  xmm9=1905120028b80027 (f: 683147328.000000, d: 3.783239e-188)
04:33:44  xmm10=ffffffffffffffff (f: 4294967296.000000, d: -nan)
04:33:44  xmm11=0000015200000151 (f: 337.000000, d: 7.172346e-312)
04:33:44  xmm12=0000013d00000140 (f: 320.000000, d: 6.726727e-312)
04:33:44  xmm13=000001380000013f (f: 319.000000, d: 6.620627e-312)
04:33:44  xmm14=0000000008001800 (f: 134223872.000000, d: 6.631540e-316)
04:33:44  xmm15=000001420000013b (f: 315.000000, d: 6.832826e-312)
04:33:44  Module=/home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/build/linux-x86_64-server-release/jdk/lib/default/libj9vm29.so
04:33:44  Module_base_address=00002B885E060000
04:33:44  Target=2_90_20240824_241 (Linux 3.10.0-1160.114.2.el7.x86_64)
04:33:44  CPU=amd64 (4 logical CPUs) (0x1e8cbc000 RAM)
04:33:44  ----------- Stack Backtrace -----------
04:33:44  walkStackForExceptionThrow+0x50 (0x00002B885E0992D0 [libj9vm29.so+0x392d0])
04:33:44  _ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread+0x13ea (0x00002B885E10DF3A [libj9vm29.so+0xadf3a])
04:33:44  bytecodeLoopCompressed+0xca (0x00002B885E10CB3A [libj9vm29.so+0xacb3a])
04:33:44   (0x00002B885E208932 [libj9vm29.so+0x1a8932])
04:33:44  ---------------------------------------
04:33:44  JVMDUMP039I Processing dump event "gpf", detail "" at 2024/08/24 08:33:41 - please wait.
04:33:44  JVMDUMP032I JVM requested System dump using '/home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/make/core.20240824.083341.4676.0001.dmp' in response to an event
04:33:44  JVMDUMP010I System dump written to /home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/make/core.20240824.083341.4676.0001.dmp
04:33:44  JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/make/javacore.20240824.083341.4676.0002.txt' in response to an event
04:33:44  JVMDUMP010I Java dump written to /home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/make/javacore.20240824.083341.4676.0002.txt
04:33:44  JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/make/Snap.20240824.083341.4676.0003.trc' in response to an event
04:33:44  JVMDUMP010I Snap dump written to /home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/make/Snap.20240824.083341.4676.0003.trc
04:33:44  JVMDUMP032I JVM requested JIT dump using '/home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/make/jitdump.20240824.083341.4676.0004.dmp' in response to an event
04:33:44  JVMDUMP051I JIT dump occurred in 'Attach API update file access time' thread 0x000000000023CD00
04:33:44  JVMDUMP010I JIT dump written to /home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/make/jitdump.20240824.083341.4676.0004.dmp
04:33:44  JVMDUMP013I Processed dump event "gpf", detail "".
04:33:44  gmake[3]: *** [/home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/build/linux-x86_64-server-release/jdk/_optimize_image_exec.marker] Error 1
04:33:44  ExplodedImageOptimize.gmk:39: recipe for target '/home/jenkins/workspace/Build_JDK21_x86-64_linux_Personal/build/linux-x86_64-server-release/jdk/_optimize_image_exec.marker' failed
04:33:44  make/Main.gmk:492: recipe for target 'exploded-image-optimize' failed
04:33:44  gmake[2]: *** [exploded-image-optimize] Error 1
04:33:44  gmake[2]: *** Waiting for unfinished jobs....
04:38:10  
04:38:10  ERROR: Build failed for target 'all' in configuration 'linux-x86_64-server-release' (exit code 2) 
04:38:10  
04:38:10  === Output from failing command(s) repeated here ===
04:38:10  * For target jdk__optimize_image_exec:
04:38:10  Unhandled exception
04:38:10  Type=Segmentation error vmState=0x00000000
04:38:10  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
04:38:10  Handler1=00002B885E0A4DE0 Handler2=00002B885CD68740 InaccessibleAddress=0000000000000000
04:38:10  RDI=000000000023CD00 RSI=0000000000000000 RAX=0000000000000000 RBX=000000000023D000
04:38:10  RCX=0000000000000020 RDX=0000000000000000 R8=0000000000000000 R9=0000000000000001
04:38:10  R10=00002B8867FB02A0 R11=0000000000000206 R12=00002B8860173FA0 R13=00002B8867FB0600
04:38:10  R14=000000000023CD00 R15=00002B8867FB0900
04:38:10  RIP=00002B885E0992D0 GS=0000 FS=0000 RSP=00002B8867FB03B0
04:38:10  EFlags=0000000000010202 CS=0033 RBP=0000000000016D70 ERR=0000000000000004
04:38:10  TRAPNO=000000000000000E OLDMASK=0000000000000000 CR2=0000000000000000
04:38:10  xmm0=0000000000612803 (f: 6367235.000000, d: 3.145832e-317)
04:38:10  xmm1=00000000390efe34 (f: 957283904.000000, d: 4.729611e-315)
04:38:10  xmm2=019ee085b7654321 (f: 3076866816.000000, d: 7.204105e-301)
04:38:10  xmm3=6c735f6461657268 (f: 1634038400.000000, d: 2.608708e+214)
04:38:10     ... (rest of output omitted)

@gacholio
Copy link
Contributor

The failures don't seem to be related to these changes (maybe the threadhelp one?) so I'll relaunch.

@gacholio
Copy link
Contributor

jenkins test sanity xlinux jdk21

@gacholio
Copy link
Contributor

It's suspicious that the crash is throwing an exception and the new code added to threadhelp throws, but I don't see any obvious problem with the code (the throw appears to be done while holding VM access).

@gacholio
Copy link
Contributor

It's also highly unlikely that the nanos call would faIl resulting in the throw.

@gacholio
Copy link
Contributor

jenkins test sanity xlinux jdk21

Set the ticks/second parameter in the chunk header. This indicates which
granularity we report timestamps (millis, micros or nanos). Note, this
is not to be confused with the event startime which is always
milliseconds.

Also, chage threadsleep event to report on after the sleep as concluded
which matches RI behaviour. The actual sleep duration must be recorded.

Signed-off-by: tajila <atobia@ca.ibm.com>
@tajila
Copy link
Contributor Author

tajila commented Aug 26, 2024

jenkins test sanity xlinux jdk21

@tajila
Copy link
Contributor Author

tajila commented Aug 26, 2024

jenkins test sanity alinux64 jdk17

@gacholio
Copy link
Contributor

@tajila Are you confident the earlier crashes are either resolved or unrelated to this change?

@tajila
Copy link
Contributor Author

tajila commented Aug 26, 2024

@tajila Are you confident the earlier crashes are either resolved or unrelated to this change?

The crashes are related to the following

if (0 == rc) {
	TRIGGER_J9HOOK_VM_SLEEP(javaVM->hookInterface, vmThread, millis, nanos);
	internalReleaseVMAccessSetStatus(vmThread, J9_PUBLIC_FLAGS_THREAD_SLEEPING);
	rc = timeCompensationHelper(vmThread, HELPER_TYPE_THREAD_SLEEP, NULL, millis, nanos);
	internalAcquireVMAccessClearStatus(vmThread, J9_PUBLIC_FLAGS_THREAD_SLEEPING);
	TRIGGER_J9HOOK_VM_SLEPT(javaVM->hookInterface, vmThread, millis, nanos, startNanos);
}

I undid the earlier change. combining the if blocks changes the logic

@gacholio gacholio merged commit 91b5703 into eclipse-openj9:master Aug 26, 2024
7 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants