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.

Sign up for GitHub

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

Jump to bottom

jdk19 OpenJDK java/lang/Thread/virtual/stress/Skynet.java hang / timeout #16728

Closed
pshipton opened this issue Feb 15, 2023 · 129 comments · Fixed by #16855 or adoptium/aqa-tests#4926
Closed

jdk19 OpenJDK java/lang/Thread/virtual/stress/Skynet.java hang / timeout #16728

pshipton opened this issue Feb 15, 2023 · 129 comments · Fixed by #16855 or adoptium/aqa-tests#4926
Assignees
@fengxue-IS
Labels
comp:gc comp:jit comp:vm jdk19 perf project:loom Used to track Project Loom related work test failure
Milestone
Java 21 (0.42)

Comments

@pshipton
Copy link
Member

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_aarch64_linux_Nightly/111/
jdk_lang_0
java/lang/Thread/virtual/stress/Skynet.java

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk19_j9_sanity.openjdk_aarch64_linux_Nightly/111/openjdk_test_output.tar.gz

21:55:35  ACTION: main -- Error. Program `/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_aarch64_linux_Nightly/openjdkbinary/j2sdk-image/bin/java' timed out (timeout set to 2400000ms, elapsed time including timeout handling was 2404113ms).
21:55:35  REASON: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
21:55:35  TIME:   2404.116 seconds
21:55:35  messages:
21:55:35  command: main --enable-preview Skynet
21:55:35  reason: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
21:55:35  Mode: othervm [/othervm specified]
21:55:35  Timeout information:
21:55:35  Running jcmd on process 2529589
21:55:35  Dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_aarch64_linux_Nightly/aqa-tests/TKG/output_1676426825596/jdk_lang_0/work/scratch/2/core.20230214.215530.2529589.0001.dmp
21:55:35  Dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_aarch64_linux_Nightly/aqa-tests/TKG/output_1676426825596/jdk_lang_0/work/scratch/2/javacore.20230214.215531.2529589.0002.txt
21:55:35  Running jstack on process 2529589
21:55:35  2023-02-14T21:55:32.813679073
21:55:35  Virtual machine: 2529589 JVM information:
21:55:35  JRE 19 Linux aarch64-64-Bit Compressed References 20230215_180 (JIT enabled, AOT enabled)
21:55:35  OpenJ9   - 711ca6c2adb
21:55:35  OMR      - 6adea0343aa
21:55:35  JCL      - 47925e78c4e based on jdk-19.0.2+7
21:55:35  
21:55:35  "main" prio=5 Id=2 WAITING
21:55:35  	at java.base@19.0.2-internal/java.lang.Object.waitImpl(Native Method)
21:55:35  	at java.base@19.0.2-internal/java.lang.Object.wait(Object.java:255)
21:55:35  	at java.base@19.0.2-internal/java.lang.Object.wait(Object.java:221)
21:55:35  	at java.base@19.0.2-internal/java.lang.Thread.join(Thread.java:2151)
21:55:35  	at java.base@19.0.2-internal/java.lang.Thread.join(Thread.java:2227)
21:55:35  	at app//com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:74)
21:55:35  
21:55:35  "JIT Compilation Thread-000" prio=10 Id=4 RUNNABLE
21:55:35  
21:55:35  "JIT Compilation Thread-001 Suspended" prio=10 Id=5 RUNNABLE
21:55:35  
21:55:35  "JIT Compilation Thread-002 Suspended" prio=10 Id=6 RUNNABLE
21:55:35  
21:55:35  "JIT Compilation Thread-003 Suspended" prio=10 Id=7 RUNNABLE
21:55:35  
21:55:35  "JIT Compilation Thread-004 Suspended" prio=10 Id=8 RUNNABLE
21:55:35  
21:55:35  "JIT Compilation Thread-005 Suspended" prio=10 Id=9 RUNNABLE
21:55:35  
21:55:35  "JIT Compilation Thread-006 Suspended" prio=10 Id=10 RUNNABLE
21:55:35  
21:55:35  "JIT Diagnostic Compilation Thread-007 Suspended" prio=10 Id=11 RUNNABLE
21:55:35  
21:55:35  "JIT-SamplerThread" prio=10 Id=12 TIMED_WAITING
21:55:35  
21:55:35  "IProfiler" prio=5 Id=13 RUNNABLE
21:55:35  
21:55:35  "Common-Cleaner" prio=8 Id=3 TIMED_WAITING
21:55:35  	at java.base@19.0.2-internal/java.lang.Object.waitImpl(Native Method)
21:55:35  	at java.base@19.0.2-internal/java.lang.Object.wait(Object.java:255)
21:55:35  	at java.base@19.0.2-internal/java.lang.Object.wait(Object.java:221)
21:55:35  	at java.base@19.0.2-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
21:55:35  	at java.base@19.0.2-internal/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:140)
21:55:35  	at java.base@19.0.2-internal/java.lang.Thread.run(Thread.java:1573)
21:55:35  	at java.base@19.0.2-internal/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:186)
21:55:35  
21:55:35  "Concurrent Mark Helper" prio=1 Id=14 RUNNABLE
21:55:35  
21:55:35  "GC Worker" prio=5 Id=15 RUNNABLE
21:55:35  
21:55:35  "GC Worker" prio=5 Id=16 RUNNABLE
21:55:35  
21:55:35  "GC Worker" prio=5 Id=17 RUNNABLE
21:55:35  
21:55:35  "GC Worker" prio=5 Id=18 RUNNABLE
21:55:35  
21:55:35  "GC Worker" prio=5 Id=19 RUNNABLE
21:55:35  
21:55:35  "GC Worker" prio=5 Id=20 RUNNABLE
21:55:35  
21:55:35  "GC Worker" prio=5 Id=21 RUNNABLE
21:55:35  
21:55:35  "Attach API wait loop" prio=10 Id=24 RUNNABLE
21:55:35  	at java.base@19.0.2-internal/openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
21:55:35  	at java.base@19.0.2-internal/openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
21:55:35  	at java.base@19.0.2-internal/openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
21:55:35  	at java.base@19.0.2-internal/openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
21:55:35  
21:55:35  "Finalizer thread" prio=5 Id=25 RUNNABLE
21:55:35  
21:55:35  "MainThread" prio=5 Id=27 WAITING
21:55:35  	at java.base@19.0.2-internal/jdk.internal.misc.Unsafe.park(Native Method)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.locks.LockSupport.park(LockSupport.java:371)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.SynchronousQueue$TransferStack$SNode.block(SynchronousQueue.java:288)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3745)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3690)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:397)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:886)
21:55:35  	at app//Skynet$Channel.receive(Skynet.java:110)
21:55:35  	at app//Skynet.skynet(Skynet.java:60)
21:55:35  	at app//Skynet.main(Skynet.java:50)
21:55:35  	at java.base@19.0.2-internal/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
21:55:35  	at java.base@19.0.2-internal/java.lang.reflect.Method.invoke(Method.java:578)
21:55:35  	at app//com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
21:55:35  	at java.base@19.0.2-internal/java.lang.Thread.run(Thread.java:1573)
21:55:35  
21:55:35  "ForkJoinPool-1-worker-2" prio=5 Id=31 RUNNABLE
21:55:35  	at java.base@19.0.2-internal/jdk.internal.vm.Continuation.enterImpl(Native Method)
21:55:35  	at java.base@19.0.2-internal/jdk.internal.vm.Continuation.run(Continuation.java:198)
21:55:35  	at java.base@19.0.2-internal/java.lang.VirtualThread.runContinuation(VirtualThread.java:218)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1423)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1311)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1841)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1806)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177)
21:55:35  
21:55:35  "ForkJoinPool-1-worker-3" prio=5 Id=41 RUNNABLE
21:55:35  	at java.base@19.0.2-internal/java.lang.VirtualThread.notifyJvmtiUnmountEnd(Native Method)
21:55:35  	at java.base@19.0.2-internal/java.lang.VirtualThread.afterYield(VirtualThread.java:396)
21:55:35  	at java.base@19.0.2-internal/java.lang.VirtualThread.runContinuation(VirtualThread.java:223)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinTask$AdaptedRunnableAction.exec(ForkJoinTask.java:1403)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1311)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1841)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1806)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177)
21:55:35  
21:55:35  "ForkJoinPool-1-worker-6" prio=5 Id=47 RUNNABLE
21:55:35  	at java.base@19.0.2-internal/java.lang.VirtualThread.notifyJvmtiUnmountEnd(Native Method)
21:55:35  	at java.base@19.0.2-internal/java.lang.VirtualThread.afterTerminate(VirtualThread.java:424)
21:55:35  	at java.base@19.0.2-internal/java.lang.VirtualThread.runContinuation(VirtualThread.java:221)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1423)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1311)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1841)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1806)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177)
21:55:35  
21:55:35  "ForkJoinPool-1-worker-7" prio=5 Id=48 RUNNABLE
21:55:35  	at java.base@19.0.2-internal/java.lang.VirtualThread.notifyJvmtiMountBegin(Native Method)
21:55:35  	at java.base@19.0.2-internal/java.lang.VirtualThread.runContinuation(VirtualThread.java:215)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1423)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1311)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1841)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1806)
21:55:35  	at java.base@19.0.2-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177)
21:55:35  
21:55:35  "file lock watchdog" prio=10 Id=10700077 TIMED_WAITING
21:55:35  	at java.base@19.0.2-internal/java.lang.Object.waitImpl(Native Method)
21:55:35  	at java.base@19.0.2-internal/java.lang.Object.wait(Object.java:255)
21:55:35  	at java.base@19.0.2-internal/java.lang.Object.wait(Object.java:221)
21:55:35  	at java.base@19.0.2-internal/java.util.TimerThread.mainLoop(Timer.java:569)
21:55:35  	at java.base@19.0.2-internal/java.util.TimerThread.run(Timer.java:522)
21:55:35  
21:55:35  "Attachment portNumber: 40951" prio=10 Id=10708739 RUNNABLE
21:55:35  	at java.base@19.0.2-internal/openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
21:55:35  	at java.base@19.0.2-internal/openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:245)
21:55:35  	at java.base@19.0.2-internal/openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:181)
21:55:35  	at java.base@19.0.2-internal/openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:248)
21:55:35  	at java.base@19.0.2-internal/openj9.internal.tools.attach.target.Attachment.run(Attachment.java:159)
21:55:35  
21:55:35  
21:55:35  --- Timeout information end.
21:55:35  elapsed time (seconds): 2404.116
21:55:35  configuration:
21:55:35  STDOUT:
21:55:35  Result: 499999500000 in 396129 ms
21:55:35  Result: 499999500000 in 141690 ms
21:55:35  Result: 499999500000 in 344331 ms
21:55:35  Result: 499999500000 in 326083 ms
21:55:35  Result: 499999500000 in 300962 ms
21:55:35  Result: 499999500000 in 379486 ms
21:55:35  Result: 499999500000 in 222160 ms
21:55:35  Result: 499999500000 in 194157 ms
21:55:35  Result: 499999500000 in 50598 ms
21:55:35  Timeout refired 2400 times
@pshipton pshipton added this to the Java 19 0.37 milestone Feb 15, 2023
@pshipton
Copy link
Member Author

@fengxue-IS @babsingh @tajila fyi

@pshipton
Copy link
Member Author

pshipton commented Feb 15, 2023 •
edited
Loading

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_Nightly/110/

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_Nightly/110/openjdk_test_output.tar.gz

00:01:07  ACTION: main -- Error. Program `/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_Nightly/openjdkbinary/j2sdk-image/bin/java' timed out (timeout set to 2400000ms, elapsed time including timeout handling was 3146907ms).
00:01:07  REASON: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
00:01:07  TIME:   3146.924 seconds
00:01:07  messages:
00:01:07  command: main --enable-preview Skynet
00:01:07  reason: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
00:01:07  Mode: othervm [/othervm specified]
00:01:07  Timeout information:
00:01:07  Running jcmd on process 13500450
00:01:07  Timeout refired 300 times
00:01:07  Error getting data from 13500450: Exception connecting to 13500450
00:01:07  Usage : jcmd <vmid> <arguments>
00:01:07  
00:01:07     -J : supply arguments to the Java VM running jcmd
00:01:07     -l : list JVM processes on the local machine
00:01:07     -h : print this help message
00:01:07  
00:01:07     <vmid> : Attach API VM ID as shown in jps or other Attach API-based tools
00:01:07  
00:01:07     arguments:
00:01:07        help : print the list of diagnostic commands
00:01:07        help <command> : print help for the specific command
00:01:07        <command> [command arguments] : command from the list returned by "help"
00:01:07  
00:01:07  list JVM processes on the local machine. Default behavior when no options are specified.
00:01:07  
00:01:07  NOTE: this utility might significantly affect the performance of the target JVM.
00:01:07      The available diagnostic commands are determined by
00:01:07      the target VM and may vary between VMs.
00:01:07  Timeout handler interrupted: 
00:01:07  java.lang.InterruptedException
00:01:07  	at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1611)
00:01:07  	at java.base/java.lang.ProcessImpl.waitFor(ProcessImpl.java:447)
00:01:07  	at jtreg.openj9.CoreDumpTimeoutHandler.runJcmdCommand(CoreDumpTimeoutHandler.java:117)
00:01:07  	at jtreg.openj9.CoreDumpTimeoutHandler.runJcmd(CoreDumpTimeoutHandler.java:137)
00:01:07  	at jtreg.openj9.CoreDumpTimeoutHandler.runActions(CoreDumpTimeoutHandler.java:55)
00:01:07  	at com.sun.javatest.regtest.TimeoutHandler.handleTimeout(TimeoutHandler.java:120)
00:01:07  	at com.sun.javatest.regtest.exec.ProcessCommand$2.run(ProcessCommand.java:317)
00:01:07  --- Timeout information end.
00:01:07  elapsed time (seconds): 3146.924
00:01:07  configuration:
00:01:07  STDOUT:
00:01:07  Timeout refired 2400 times
00:01:07  STDERR:
00:01:07  Exception in thread "" Exception in thread "" Exception in thread "" Exception in thread "" Exception in thread "" Exception in thread "" Exception in thread "" Exception in thread "" Exception in thread "" java.lang.StackOverflowError
00:01:07  	at java.base/java.util.concurrent.atomic.Striped64$Cell.cas(Striped64.java:128)
00:01:07  	at java.base/java.util.concurrent.atomic.LongAdder.add(LongAdder.java:92)
00:01:07  	at java.base/jdk.internal.vm.ThreadContainers$RootContainer$CountingRootContainer.onExit(ThreadContainers.java:265)
00:01:07  	at java.base/java.lang.VirtualThread.start(VirtualThread.java:472)
00:01:07  	at java.base/java.lang.VirtualThread.start(VirtualThread.java:480)
00:01:07  	at java.base/java.lang.Thread.startVirtualThread(Thread.java:1484)
00:01:07  	at Skynet.skynet(Skynet.java:74)
00:01:07  	at Skynet.lambda$skynet$1(Skynet.java:74)
00:01:07  	at java.base/java.lang.VirtualThread.run(VirtualThread.java:292)
00:01:07  	at java.base/java.lang.VirtualThread$VThreadContinuation.lambda$new$0(VirtualThread.java:179)
00:01:07  	at java.base/jdk.internal.vm.Continuation.execute(Continuation.java:170)
00:01:07  Exception in thread "" Exception in thread "" java.lang.StackOverflowError
00:01:07  	at java.base/java.util.concurrent.atomic.Striped64$Cell.cas(Striped64.java:128)
00:01:07  	at java.base/java.util.concurrent.atomic.LongAdder.add(LongAdder.java:92)
00:01:07  	at java.base/jdk.internal.vm.ThreadContainers$RootContainer$CountingRootContainer.onExit(ThreadContainers.java:265)
00:01:07  	at java.base/java.lang.VirtualThread.start(VirtualThread.java:472)
00:01:07  	at java.base/java.lang.VirtualThread.start(VirtualThread.java:480)
00:01:07  	at java.base/java.lang.Thread.startVirtualThread(Thread.java:1484)
00:01:07  	at Skynet.skynet(Skynet.java:74)
00:01:07  	at Skynet.lambda$skynet$1(Skynet.java:74)
00:01:07  	at java.base/java.lang.VirtualThread.run(VirtualThread.java:292)
00:01:07  	at java.base/java.lang.VirtualThread$VThreadContinuation.lambda$new$0(VirtualThread.java:179)
00:01:07  	at java.base/jdk.internal.vm.Continuation.execute(Continuation.java:170)
...
StackOverflowError's repeat

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/111

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/111/openjdk_test_output.tar.gz

01:53:30  ACTION: main -- Error. Program `/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/openjdkbinary/j2sdk-image/bin/java' timed out (timeout set to 2400000ms, elapsed time including timeout handling was 3889808ms).
01:53:30  REASON: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
01:53:30  TIME:   3889.813 seconds
01:53:30  messages:
01:53:30  command: main --enable-preview Skynet
01:53:30  reason: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
01:53:30  Mode: othervm [/othervm specified]
01:53:30  Timeout information:
01:53:30  Running jcmd on process 11917
01:53:30  Timeout refired 300 times
01:53:30  Error getting data from 11917: Exception connecting to 11917
01:53:30  Usage : jcmd <vmid> <arguments>
01:53:30  
01:53:30     -J : supply arguments to the Java VM running jcmd
01:53:30     -l : list JVM processes on the local machine
01:53:30     -h : print this help message
01:53:30  
01:53:30     <vmid> : Attach API VM ID as shown in jps or other Attach API-based tools
01:53:30  
01:53:30     arguments:
01:53:30        help : print the list of diagnostic commands
01:53:30        help <command> : print help for the specific command
01:53:30        <command> [command arguments] : command from the list returned by "help"
01:53:30  
01:53:30  list JVM processes on the local machine. Default behavior when no options are specified.
01:53:30  
01:53:30  NOTE: this utility might significantly affect the performance of the target JVM.
01:53:30      The available diagnostic commands are determined by
01:53:30      the target VM and may vary between VMs.
01:53:30  Error getting data from 11917: Exception connecting to 11917
01:53:30  Usage : jcmd <vmid> <arguments>
01:53:30  
01:53:30     -J : supply arguments to the Java VM running jcmd
01:53:30     -l : list JVM processes on the local machine
01:53:30     -h : print this help message
01:53:30  
01:53:30     <vmid> : Attach API VM ID as shown in jps or other Attach API-based tools
01:53:30  
01:53:30     arguments:
01:53:30        help : print the list of diagnostic commands
01:53:30        help <command> : print help for the specific command
01:53:30        <command> [command arguments] : command from the list returned by "help"
01:53:30  
01:53:30  list JVM processes on the local machine. Default behavior when no options are specified.
01:53:30  
01:53:30  NOTE: this utility might significantly affect the performance of the target JVM.
01:53:30      The available diagnostic commands are determined by
01:53:30      the target VM and may vary between VMs.
01:53:30  Timeout handler interrupted: 
01:53:30  java.lang.InterruptedException
01:53:30  	at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1611)
01:53:30  	at java.base/java.lang.ProcessImpl.waitFor(ProcessImpl.java:447)
01:53:30  	at jtreg.openj9.CoreDumpTimeoutHandler.runJcmdCommand(CoreDumpTimeoutHandler.java:117)
01:53:30  	at jtreg.openj9.CoreDumpTimeoutHandler.runJcmd(CoreDumpTimeoutHandler.java:138)
01:53:30  	at jtreg.openj9.CoreDumpTimeoutHandler.runActions(CoreDumpTimeoutHandler.java:55)
01:53:30  	at com.sun.javatest.regtest.TimeoutHandler.handleTimeout(TimeoutHandler.java:120)
01:53:30  	at com.sun.javatest.regtest.exec.ProcessCommand$2.run(ProcessCommand.java:317)
01:53:30  --- Timeout information end.
01:53:30  elapsed time (seconds): 3889.813
01:53:30  configuration:
01:53:30  STDOUT:
01:53:30  Timeout refired 2400 times
01:53:30  STDERR:
01:53:30  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/15 01:34:18 - please wait.
01:53:30  JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/javacore.20230215.013418.11917.0001.txt' in response to an event
01:53:30  JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/javacore.20230215.013418.11917.0001.txt
01:53:30  JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/Snap.20230215.013418.11917.0002.trc' in response to an event
01:53:30  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/15 01:34:24 - please wait.
01:53:30  JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/Snap.20230215.013418.11917.0002.trc
01:53:30  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
01:53:30  JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/javacore.20230215.013424.11917.0003.txt' in response to an event
01:53:30  JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/javacore.20230215.013424.11917.0003.txt
01:53:30  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/15 01:34:26 - please wait.
01:53:30  JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/Snap.20230215.013424.11917.0004.trc' in response to an event
01:53:30  JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/Snap.20230215.013424.11917.0004.trc
01:53:30  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
01:53:30  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/15 01:34:30 - please wait.
01:53:30  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/15 01:34:30 - please wait.
01:53:30  JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/javacore.20230215.013426.11917.0005.txt' in response to an event
01:53:30  JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/javacore.20230215.013426.11917.0005.txt
01:53:30  JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/Snap.20230215.013430.11917.0006.trc' in response to an event
01:53:30  JVMDUMP010I Snap dump written to {nothing to snap}
01:53:30  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
01:53:30  JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/Snap.20230215.013426.11917.0008.trc' in response to an event
01:53:30  JVMDUMP010I Snap dump written to {nothing to snap}
01:53:30  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
01:53:30  JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/javacore.20230215.013430.11917.0007.txt' in response to an event
01:53:30  JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16764348034303/jdk_lang_1/work/scratch/1/javacore.20230215.013430.11917.0007.txt
01:53:30  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
01:53:30  Exception in thread "Attach API wait loop" java/lang/OutOfMemoryError: Java heap space
01:53:30  	at java/lang/Throwable.printStackTrace (java.base@19.0.2-internal/Throwable.java:554)
01:53:30  	at java/lang/Throwable.printStackTraceHelper (java.base@19.0.2-internal/Throwable.java:338)
01:53:30  	at java/lang/Throwable.printStackTrace (java.base@19.0.2-internal/Throwable.java:307)
01:53:30  	at java/lang/Throwable.printStackTrace (java.base@19.0.2-internal/Throwable.java:250)

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/111

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/111/openjdk_test_output.tar.gz

23:53:48  ACTION: main -- Error. Program `/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/openjdkbinary/j2sdk-image/bin/java' timed out (timeout set to 2400000ms, elapsed time including timeout handling was 3144194ms).
23:53:48  REASON: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
23:53:48  TIME:   3144.2 seconds
23:53:48  messages:
23:53:48  command: main --enable-preview Skynet
23:53:48  reason: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
23:53:48  Mode: othervm [/othervm specified]
23:53:48  Timeout information:
23:53:48  Running jcmd on process 6013
23:53:48  Timeout refired 300 times
23:53:48  Error getting data from 6013: Exception connecting to 6013
23:53:48  Usage : jcmd <vmid> <arguments>
23:53:48  
23:53:48     -J : supply arguments to the Java VM running jcmd
23:53:48     -l : list JVM processes on the local machine
23:53:48     -h : print this help message
23:53:48  
23:53:48     <vmid> : Attach API VM ID as shown in jps or other Attach API-based tools
23:53:48  
23:53:48     arguments:
23:53:48        help : print the list of diagnostic commands
23:53:48        help <command> : print help for the specific command
23:53:48        <command> [command arguments] : command from the list returned by "help"
23:53:48  
23:53:48  list JVM processes on the local machine. Default behavior when no options are specified.
23:53:48  
23:53:48  NOTE: this utility might significantly affect the performance of the target JVM.
23:53:48      The available diagnostic commands are determined by
23:53:48      the target VM and may vary between VMs.
23:53:48  Timeout handler interrupted: 
23:53:48  java.lang.InterruptedException
23:53:48  	at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1611)
23:53:48  	at java.base/java.lang.ProcessImpl.waitFor(ProcessImpl.java:447)
23:53:48  	at jtreg.openj9.CoreDumpTimeoutHandler.runJcmdCommand(CoreDumpTimeoutHandler.java:117)
23:53:48  	at jtreg.openj9.CoreDumpTimeoutHandler.runJcmd(CoreDumpTimeoutHandler.java:137)
23:53:48  	at jtreg.openj9.CoreDumpTimeoutHandler.runActions(CoreDumpTimeoutHandler.java:55)
23:53:48  	at com.sun.javatest.regtest.TimeoutHandler.handleTimeout(TimeoutHandler.java:120)
23:53:48  	at com.sun.javatest.regtest.exec.ProcessCommand$2.run(ProcessCommand.java:317)
23:53:48  --- Timeout information end.
23:53:48  elapsed time (seconds): 3144.2
23:53:48  configuration:
23:53:48  STDOUT:
23:53:48  Result: 499999500000 in 18817 ms
23:53:48  Result: 499999500000 in 13686 ms
23:53:48  Result: 499999500000 in 10776 ms
23:53:48  Result: 499999500000 in 13522 ms
23:53:48  Result: 499999500000 in 9920 ms
23:53:48  Result: 499999500000 in 9370 ms
23:53:48  Result: 499999500000 in 10632 ms
23:53:48  Result: 499999500000 in 9725 ms
23:53:48  Result: 499999500000 in 11140 ms
23:53:48  Timeout refired 2400 times
23:53:48  STDERR:
23:53:48  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/14 23:03:40 - please wait.
23:53:48  JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/javacore.20230214.230340.6013.0001.txt' in response to an event
23:53:48  JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/javacore.20230214.230340.6013.0001.txt
23:53:48  JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/Snap.20230214.230340.6013.0002.trc' in response to an event
23:53:48  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/14 23:03:41 - please wait.
23:53:48  JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/14 23:03:41 - please wait.
23:53:48  JVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/Snap.20230214.230340.6013.0002.trc
23:53:48  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
23:53:48  Exception in thread "" java.lang.OutOfMemoryError: Java heap space
23:53:48  	at java.base/java.util.concurrent.SynchronousQueue$TransferStack.snode(SynchronousQueue.java:328)
23:53:48  	at java.base/java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:371)
23:53:48  	at java.base/java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:886)
23:53:48  	at Skynet$Channel.receive(Skynet.java:110)
23:53:48  	at Skynet.skynet(Skynet.java:78)
23:53:48  	at Skynet.lambda$skynet$1(Skynet.java:74)
23:53:48  	at java.base/java.lang.VirtualThread.run(VirtualThread.java:292)
23:53:48  	at java.base/java.lang.VirtualThread$VThreadContinuation.lambda$new$0(VirtualThread.java:179)
23:53:48  	at java.base/jdk.internal.vm.Continuation.execute(Continuation.java:170)
23:53:48  JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/javacore.20230214.230341.6013.0004.txt' in response to an event
23:53:48  JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/javacore.20230214.230341.6013.0004.txt
23:53:48  JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/Snap.20230214.230341.6013.0005.trc' in response to an event
23:53:48  JVMDUMP010I Snap dump written to {nothing to snap}
23:53:48  JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
23:53:48  Exception in thread "" java.lang.OutOfMemoryError: Java heap space
23:53:48  JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/javacore.20230214.230341.6013.0003.txt' in response to an event
23:53:48  JVMDUMP010I Java dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/javacore.20230214.230341.6013.0003.txt
23:53:48  JVMDUMP032I JVM requested Snap dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/Snap.20230214.230341.6013.0006.trc' in response to an event
23:53:48  	at java.base/java.lang.invoke.DirectMethodHandleJVMDUMP010I Snap dump written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/aqa-tests/TKG/output_16764301149136/jdk_lang_1/work/scratch/1/Snap.20230214.230341.6013.0006.trc
23:53:48  .JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
23:53:48  allocateInstance(DirectMethodHandle.java:501)
23:53:48  	at java.base/java.lang.VirtualThread$VThreadContinuation.<init>(VirtualThread.java:179)
23:53:48  	at java.base/java.lang.VirtualThread.<init>(VirtualThread.java:170)
23:53:48  	at java.base/java.lang.ThreadBuilders.newVirtualThread(ThreadBuilders.java:384)
23:53:48  	at java.base/java.lang.Thread.startVirtualThread(Thread.java:1483)
23:53:48  	at Skynet.skynet(Skynet.java:74)
23:53:48  	at Skynet.lambda$skynet$1(Skynet.java:74)
23:53:48  	at java.base/java.lang.VirtualThread.run(VirtualThread.java:292)
23:53:48  	at java.base/java.lang.VirtualThread$VThreadContinuation.lambda$new$0(VirtualThread.java:179)
23:53:48  	at java.baseJVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/14 23:03:50 - please wait.

@pshipton
Copy link
Member Author

Changes 9160108...711ca6c

@babsingh is this caused by #16678 ?

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_mac_Nightly/110
jdk_lang_1
java/lang/Thread/virtual/stress/Skynet.java

00:33:06  ACTION: main -- Failed. Unexpected exit from test [exit code: 255]
00:33:06  REASON: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
00:33:06  TIME:   148.241 seconds
00:33:06  messages:
00:33:06  command: main --enable-preview Skynet
00:33:06  reason: User specified action: run main/othervm/timeout=300 --enable-preview Skynet 
00:33:06  Mode: othervm [/othervm specified]
00:33:06  elapsed time (seconds): 148.241
00:33:06  configuration:
00:33:06  STDOUT:
00:33:06  STDERR:
00:33:06  Unhandled exception
00:33:06  Type=Segmentation error vmState=0x00000000
00:33:06  J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000001
00:33:06  Handler1=0000000011437C60 Handler2=00000000117369F0 InaccessibleAddress=0000000000000000
00:33:06  RDI=0000000000000000 RSI=00007FDBB8C0C210 RAX=0000000000000400 RBX=000000003BA34B00
00:33:06  RCX=00007FDBB89F5E00 RDX=0000000000000113 R8=000070000C43CB08 R9=000070000C43CAE8
00:33:06  R10=00000000555BD4B1 R11=00007FDBB20C7900 R12=000070000C43CAF0 R13=FFFFFFFFFFFFFF00
00:33:06  R14=000070000C43CAF8 R15=000070000C43CAE8
00:33:06  RIP=00000000114E9182 GS=0000 FS=0000 RSP=000070000C43C830
00:33:06  RFlags=0000000000010206 CS=002B RBP=000070000C43CAD0 ERR=0000000000000004
00:33:06  TRAPNO=000000040000000E CPU=0000000000040000 FAULTVADDR=0000000000000000
00:33:06  XMM0 00007fdbb20c7900 (f: 2987161856.000000, d: 6.945652e-310)
00:33:06  XMM1 00000000555bd4b1 (f: 1432081536.000000, d: 7.075423e-315)
00:33:06  XMM2 00000000df000000 (f: 3741319168.000000, d: 1.848457e-314)
00:33:06  XMM3 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM4 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM5 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM6 3fca23bc1fe2b563 (f: 534951264.000000, d: 2.042155e-01)
00:33:06  XMM7 4028f40b5ed9812d (f: 1591312640.000000, d: 1.247665e+01)
00:33:06  XMM8 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM9 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM10 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM11 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM12 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  XMM15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
00:33:06  Module=/Users/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_mac_Nightly/openjdkbinary/j2sdk-image/lib/default/libj9vm29.dylib
00:33:06  Module_base_address=0000000011400000 Symbol=_ZN26VM_BytecodeInterpreterFull3runEP10J9VMThread
00:33:06  Symbol_address=00000000114C0510
00:33:06  Target=2_90_20230214_179 (Mac OS X 10.15.7)
00:33:06  CPU=amd64 (12 logical CPUs) (0x400000000 RAM)
00:33:06  ----------- Stack Backtrace -----------
00:33:06  _ZN26VM_BytecodeInterpreterFull3runEP10J9VMThread+0x28c73 (0x00000000114E9183 [libj9vm29.dylib+0xe9183])
00:33:06  bytecodeLoopFull+0xb4 (0x00000000114C0504 [libj9vm29.dylib+0xc0504])
00:33:06  ---------------------------------------

@fengxue-IS
Copy link
Contributor

Likely caused by adoptium/aqa-tests#4337.
The timeout issue with Skynet is due to current OpenJ9 perf. I suggest we revert the PR to continue exclude the test or increase the timeout to allow test to complete.

@LinHu2016 can you confirm if the segfault is related to #16713

@babsingh
Copy link
Contributor

@babsingh is this caused by #16678 ?

JDK19 impl stays the same in #16678. #16678 only renames a J9VMThread field in JDK19 to make clean up easier once JDK19 goes out of service. So, it should not cause this failure.

@pshipton
Copy link
Member Author

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_aarch64_linux_Nightly/112/
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_s390x_linux_Nightly/113/

@JasonFengJ9
Copy link
Member

JasonFengJ9 commented Feb 16, 2023 •
edited
Loading

#16728 (comment)
Similar Segmentation error vmState=0x00000000 observed at an internal build

openjdk version "19.0.2-beta" 2023-01-17
IBM Semeru Runtime Open Edition 19.0.2+7-202302150051 (build 19.0.2-beta+7-202302150051)
Eclipse OpenJ9 VM 19.0.2+7-202302150051 (build master-711ca6c2a, JRE 19 AIX ppc64-64-Bit Compressed References 20230214_43 (JIT enabled, AOT enabled)
OpenJ9   - 711ca6c2a
OMR      - 6adea0343
JCL      - 47925e78c4 based on jdk-19.0.2+7)

[2023-02-15T06:12:06.967Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode150
[2023-02-15T06:12:06.967Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:+UseCompressedOops 

[2023-02-15T06:51:30.849Z] TEST: java/lang/Thread/virtual/stress/Skynet.java#id0

[2023-02-15T06:51:30.850Z] STDERR:
[2023-02-15T06:51:30.850Z] Unhandled exception
[2023-02-15T06:51:30.850Z] Type=Segmentation error vmState=0x00000000
[2023-02-15T06:51:30.850Z] J9Generic_Signal_Number=00000018 Signal_Number=0000000b Error_Value=00000000 Signal_Code=00000032
[2023-02-15T06:51:30.850Z] Handler1=09001000A0C9AEF0 Handler2=09001000A0ACC278
[2023-02-15T06:51:30.850Z] R0=00000000FFDFCE44 R1=00000100237CB170 R2=09001000A0C9EC70 R3=00000000301F4A00
[2023-02-15T06:51:30.850Z] R4=0000000030223910 R5=0000000000000113 R6=0000000000000001 R7=30247A1000000008
[2023-02-15T06:51:30.850Z] R8=0000000000000400 R9=0000000000000003 R10=000000003007D418 R11=09001000A0C9EA78
[2023-02-15T06:51:30.850Z] R12=0000000084000242 R13=00000100237D6800 R14=0000000030BF1330 R15=000000003028EC00
[2023-02-15T06:51:30.850Z] R16=0000010021AA7318 R17=FFFFFFFFFFFFFFFF R18=0000000000000000 R19=09001000A07A7FB0
[2023-02-15T06:51:30.850Z] R20=0000000000000000 R21=000000003028F740 R22=00000100237CB900 R23=00000000FFDFCE00
[2023-02-15T06:51:30.850Z] R24=0000000000000000 R25=0000000000000001 R26=0000000000000000 R27=0000000000000001
[2023-02-15T06:51:30.850Z] R28=0A0001000939D0D9 R29=0000000030BF1320 R30=0000000000000000 R31=CFD9759DEA4DB69E
[2023-02-15T06:51:30.850Z] IAR=09000000041C5B58 LR=09000000041C78CC MSR=A00000000200D032 CTR=09000000041C5B0C
[2023-02-15T06:51:30.850Z] CR=4800024260040000 FPSCR=8202000000000000 XER=6004000082020000
[2023-02-15T06:51:30.851Z] FPR0 0000000000000043 (f: 67.000000, d: 3.310240e-322)
[2023-02-15T06:51:30.851Z] FPR1 c3e0000000000000 (f: 0.000000, d: -9.223372e+18)
[2023-02-15T06:51:30.851Z] FPR2 3fc6b8549f66f926 (f: 2674325760.000000, d: 1.775003e-01)
[2023-02-15T06:51:30.851Z] FPR3 3fb1784400000000 (f: 0.000000, d: 6.824136e-02)
[2023-02-15T06:51:30.851Z] FPR4 bf90ecf58ddc7f4a (f: 2380037888.000000, d: -1.652893e-02)
[2023-02-15T06:51:30.851Z] FPR5 40a6fb0000000000 (f: 0.000000, d: 2.941500e+03)
[2023-02-15T06:51:30.851Z] FPR6 4070b222714147a7 (f: 1900103552.000000, d: 2.671334e+02)
[2023-02-15T06:51:30.851Z] FPR7 bfb62e42fefa4000 (f: 4277813248.000000, d: -8.664340e-02)
[2023-02-15T06:51:30.851Z] FPR8 3f6069c0ff9e20ca (f: 4288553216.000000, d: 2.003552e-03)
[2023-02-15T06:51:30.851Z] FPR9 40288b308ea81820 (f: 2393380864.000000, d: 1.227185e+01)
[2023-02-15T06:51:30.851Z] FPR10 412e848000000000 (f: 0.000000, d: 1.000000e+06)
[2023-02-15T06:51:30.851Z] FPR11 43300000000f4240 (f: 1000000.000000, d: 4.503600e+15)
[2023-02-15T06:51:30.851Z] FPR12 4530000000000000 (f: 0.000000, d: 1.934281e+25)
[2023-02-15T06:51:30.851Z] FPR13 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR14 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR15 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR16 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR17 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR18 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR19 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR20 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR21 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR22 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR23 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR24 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR25 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR26 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR27 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR28 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR29 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR30 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] FPR31 0000000000000000 (f: 0.000000, d: 0.000000e+00)
[2023-02-15T06:51:30.851Z] Module=/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_testList_1/openjdkbinary/j2sdk-image/lib/default/libj9vm29.so
[2023-02-15T06:51:30.851Z] Module_base_address=0900000003F55000
[2023-02-15T06:51:30.851Z] Target=2_90_20230214_43 (AIX 7.2)
[2023-02-15T06:51:30.851Z] CPU=ppc64 (16 logical CPUs) (0x200000000 RAM)
[2023-02-15T06:51:30.851Z] ----------- Stack Backtrace -----------
[2023-02-15T06:51:30.851Z] (0x0900000003FDFAE8 [libj9vm29.so+0x8aae8])
[2023-02-15T06:51:30.851Z] runJavaThread+0x268 (0x0900000003FC7D4C [libj9vm29.so+0x72d4c])
[2023-02-15T06:51:30.852Z] _ZL23javaProtectedThreadProcP13J9PortLibraryPv+0x11c (0x0900000003F57F00 [libj9vm29.so+0x2f00])
[2023-02-15T06:51:30.852Z] omrsig_protect+0x4cc (0x09000000043405F0 [libj9prt29.so+0x5c5f0])
[2023-02-15T06:51:30.852Z] javaThreadProc+0x68 (0x0900000003F57D6C [libj9vm29.so+0x2d6c])
[2023-02-15T06:51:30.852Z] thread_wrapper+0x558 (0x09000000043A98BC [libj9thr29.so+0x58bc])
[2023-02-15T06:51:30.852Z] _pthread_body+0xe8 (0x09000000005B404C [libpthreads.a+0x404c])
[2023-02-15T06:51:30.852Z] ---------------------------------------
[2023-02-15T06:51:30.852Z] JVMDUMP039I Processing dump event "gpf", detail "" at 2023/02/15 01:51:10 - please wait.

[2023-02-15T06:51:30.852Z] TEST RESULT: Failed. Unexpected exit from test [exit code: 255]
[2023-02-15T06:51:30.852Z] --------------------------------------------------
[2023-02-15T07:03:13.617Z] Test results: passed: 853; failed: 1
[2023-02-15T07:03:13.617Z] Report written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_testList_1/aqa-tests/TKG/output_16764415259215/jdk_lang_0/report/html/report.html
[2023-02-15T07:03:13.617Z] Results written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_testList_1/aqa-tests/TKG/output_16764415259215/jdk_lang_0/work
[2023-02-15T07:03:13.617Z] Error: Some tests failed or other problems occurred.
[2023-02-15T07:03:13.617Z] -----------------------------------
[2023-02-15T07:03:13.617Z] jdk_lang_0_FAILED

Also seen at x86-64_mac

@JasonFengJ9
Copy link
Member

The time out occurred at an internal build(sles15le-rt1-9)

openjdk version "19.0.2-beta" 2023-01-17
IBM Semeru Runtime Open Edition 19.0.2+7-202302150049 (build 19.0.2-beta+7-202302150049)
Eclipse OpenJ9 VM 19.0.2+7-202302150049 (build master-711ca6c2a, JRE 19 Linux ppc64le-64-Bit Compressed References 20230214_43 (JIT enabled, AOT enabled)
OpenJ9   - 711ca6c2a
OMR      - 6adea0343
JCL      - 47925e78c4 based on jdk-19.0.2+7)

[2023-02-15T01:50:40.075Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode150
[2023-02-15T01:50:40.075Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:+UseCompressedOops 

[2023-02-15T03:14:08.552Z] TEST: java/lang/Thread/virtual/stress/Skynet.java#id0

[2023-02-15T03:14:08.557Z] TEST RESULT: Error. Program `/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_testList_1/openjdkbinary/j2sdk-image/bin/java' timed out (timeout set to 2400000ms, elapsed time including timeout handling was 2408903ms).
[2023-02-15T03:14:08.557Z] --------------------------------------------------
[2023-02-15T03:19:38.804Z] Test results: passed: 861; error: 1
[2023-02-15T03:20:05.153Z] Report written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_testList_1/aqa-tests/TKG/output_16764258388739/jdk_lang_0/report/html/report.html
[2023-02-15T03:20:05.153Z] Results written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_testList_1/aqa-tests/TKG/output_16764258388739/jdk_lang_0/work
[2023-02-15T03:20:05.153Z] Error: Some tests failed or other problems occurred.
[2023-02-15T03:20:05.153Z] -----------------------------------
[2023-02-15T03:20:05.153Z] jdk_lang_0_FAILED

@JasonFengJ9
Copy link
Member

OutOfMemoryError occurred at an internal build

[2023-02-15T01:09:45.019Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode650
[2023-02-15T01:09:45.019Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:-UseCompressedOops 

openjdk version "19.0.2-beta" 2023-01-17
IBM Semeru Runtime Open Edition 19.0.2+7-202302150036 (build 19.0.2-beta+7-202302150036)
Eclipse OpenJ9 VM 19.0.2+7-202302150036 (build master-711ca6c2a, JRE 19 Linux amd64-64-Bit Compressed References 20230215_43 (JIT enabled, AOT enabled)
OpenJ9   - 711ca6c2a
OMR      - 6adea0343
JCL      - 47925e78c4 based on jdk-19.0.2+7)

[2023-02-15T02:28:35.829Z] TEST: java/lang/Thread/virtual/stress/Skynet.java#id0

[2023-02-15T02:28:35.830Z] STDERR:
[2023-02-15T02:28:35.830Z] JVMDUMP055I Processing dump event "systhrow", detail "java/lang/OutOfMemoryError", exception "Java heap space" at 2023/02/14 20:37:55 - please wait.
[2023-02-15T02:28:35.830Z] JVMDUMP032I JVM requested Java dump using '/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_testList_1/aqa-tests/TKG/output_16764233839230/jdk_lang_1/work/scratch/javacore.20230214.203755.23458.0001.txt' in response to an event

[2023-02-15T02:28:35.831Z] JVMDUMP010I Snap dump written to {nothing to snap}
[2023-02-15T02:28:35.831Z] JVMDUMP013I Processed dump event "systhrow", detail "java/lang/OutOfMemoryError".
[2023-02-15T02:28:35.831Z] Exception in thread "" Exception in thread "" java.lang.OutOfMemoryError: Java heap space
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.Thread.<init>(Thread.java:320)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.BaseVirtualThread.<init>(BaseVirtualThread.java:41)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.VirtualThread.<init>(VirtualThread.java:156)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.ThreadBuilders.newVirtualThread(ThreadBuilders.java:384)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.Thread.startVirtualThread(Thread.java:1483)
[2023-02-15T02:28:35.831Z] 	at Skynet.skynet(Skynet.java:74)
[2023-02-15T02:28:35.831Z] 	at Skynet.lambda$skynet$1(Skynet.java:74)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.VirtualThread.run(VirtualThread.java:292)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.VirtualThread$VThreadContinuation.lambda$new$0(VirtualThread.java:179)
[2023-02-15T02:28:35.831Z] 	at java.base/jdk.internal.vm.Continuation.execute(Continuation.java:170)
[2023-02-15T02:28:35.831Z] java.lang.OutOfMemoryError: Java heap space
[2023-02-15T02:28:35.831Z] 	at java.base/jdk.internal.misc.Unsafe.allocateInstance(Native Method)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.invoke.DirectMethodHandle.allocateInstance(DirectMethodHandle.java:501)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.VirtualThread$VThreadContinuation.<init>(VirtualThread.java:179)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.VirtualThread.<init>(VirtualThread.java:170)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.ThreadBuilders.newVirtualThread(ThreadBuilders.java:384)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.Thread.startVirtualThread(Thread.java:1483)
[2023-02-15T02:28:35.831Z] 	at Skynet.skynet(Skynet.java:74)
[2023-02-15T02:28:35.831Z] 	at Skynet.lambda$skynet$1(Skynet.java:74)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.VirtualThread.run(VirtualThread.java:292)
[2023-02-15T02:28:35.831Z] 	at java.base/java.lang.VirtualThread$VThreadContinuation.lambda$new$0(VirtualThread.java:179)
[2023-02-15T02:28:35.831Z] 	at java.base/jdk.internal.vm.Continuation.execute(Continuation.java:170)

[2023-02-15T02:28:35.832Z] TEST RESULT: Error. Program `/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_testList_1/openjdkbinary/j2sdk-image/bin/java' timed out (timeout set to 2400000ms, elapsed time including timeout handling was 3142098ms).
[2023-02-15T02:28:35.832Z] --------------------------------------------------
[2023-02-15T02:34:26.204Z] Test results: passed: 862; error: 1
[2023-02-15T02:34:48.112Z] Report written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_testList_1/aqa-tests/TKG/output_16764233839230/jdk_lang_1/report/html/report.html
[2023-02-15T02:34:48.112Z] Results written to /home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_testList_1/aqa-tests/TKG/output_16764233839230/jdk_lang_1/work
[2023-02-15T02:34:48.112Z] Error: Some tests failed or other problems occurred.
[2023-02-15T02:34:48.112Z] -----------------------------------
[2023-02-15T02:34:48.112Z] jdk_lang_1_FAILED

@LinHu2016
Copy link
Contributor

Likely caused by adoptium/aqa-tests#4337. The timeout issue with Skynet is due to current OpenJ9 perf. I suggest we revert the PR to continue exclude the test or increase the timeout to allow test to complete.

@LinHu2016 can you confirm if the segfault is related to #16713

it is possible same issue with #16652, the issue(#16652) is not directly related with large cpus, but we have not seen the problem with OS native threads smaller than 64.

@pshipton
Copy link
Member Author

pshipton commented Feb 17, 2023 •
edited
Loading

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_Nightly/112/
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/113/
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_mac_Nightly/112

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_Nightly/113/
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/114/

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_aarch64_linux_Nightly/115/
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_mac_Nightly/114/

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_aarch64_linux_Nightly/116/
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_Nightly/115
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_mac_Nightly/115

@fengxue-IS fengxue-IS mentioned this issue Feb 21, 2023
Merged
@tajila tajila added the perf label Feb 21, 2023
@babsingh babsingh mentioned this issue Mar 13, 2023
Closed
@fengxue-IS fengxue-IS mentioned this issue Mar 28, 2023
Merged
@pshipton
Copy link
Member Author

pshipton commented Apr 3, 2023

Reopen until the backport to 0.37 is completed.

@pshipton pshipton reopened this Apr 3, 2023
@pshipton
Copy link
Member Author

pshipton commented Apr 3, 2023 •
edited
Loading

The test needs to be unexcluded adoptium/aqa-tests#4354

@pshipton
Copy link
Member Author

pshipton commented Apr 3, 2023

Skynet is unexcluded via adoptium/aqa-tests#4491

@pshipton pshipton closed this as completed Apr 3, 2023
@babsingh
Copy link
Contributor

Since there is no method JIT-ed (with that option shown), I don't see how java stack is JIT-optimized. @babsingh did you mean something else?

In my local run, the JIT was fully enabled. Locally, I couldn't reproduce the error with -Xjit:verbose,vlog=vlog.txt,exclude={*} -Xnoaot. I mentioned that grinder w.r.t. Invalid JIT return address; are there other reasons for Invalid JIT return address if there is no method JIT'ed?

@zl-wang
Copy link
Contributor

zl-wang commented Dec 15, 2023

as far as I can see, J9VMThread AIX specific fields:

        UDATA jitTOC;
        UDATA jitCurrentRIFlags;
        UDATA jitPendingRIFlags;
        struct J9RIParameters *riParameters;

all these fields are only relevant, when there are JIT-ed code running. (there is codertTOC field which seemed used by Z system only). And, I knew the latter 3 fields are not used at all nowadays (RI was disabled 3 years ago).

@zl-wang
Copy link
Contributor

zl-wang commented Dec 15, 2023

are there other reasons for Invalid JIT return address if there is no method JIT'ed?

No, I cannot think of one.
Could you look into where Invalid JIT return address can be emitted? maybe that can lead to something. If I remembered correctly, the check happened only at the point Interpreter is about to return to JIT-ed code (i.e. caller). How this can happen without JIT-ed code at all might be the thing ultimately.

@pshipton
Copy link
Member Author

What about if something is corrupted and the VM tries to return to JIT-ed code that doesn't actually exist.

@gita-omr
Copy link
Contributor

gita-omr commented Dec 16, 2023 •
edited
Loading

I think it would be good to enable some stack walking tracing. For example, I can see something like:

Trc_VRB_WalkStackFrames_Entry inside walkStackFrames().

But I am not sure how to enable it. Maybe some other VM tracing during stack unwinding would be useful?

@LinHu2016 LinHu2016 mentioned this issue Dec 16, 2023
Merged
@pshipton
Copy link
Member Author

Stack walk tracing is enabled via -verbose:stackwalk.

@gita-omr
Copy link
Contributor

I've been running grinder [1] with -Xjit:verbose,exclude={*} -Xnoaot -verbose:stackwalk with the build [2] that has a fix for [3] and I don't see any failures so far.

[1] https://hyc-runtimes-jenkins.swg-devops.com/job/Grinder/37043/
[2] https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Build_JDK21_ppc64_aix_Personal/92/OpenJ9-JDK21-ppc64_aix-20231218-173701.tar.gz
[3] #18637

@gita-omr
Copy link
Contributor

Correction to the above: the tests did fail but due to a timeout. Running without -verbose:stackwalk now.

babsingh added a commit to babsingh/openj9 that referenced this issue Dec 19, 2023
@babsingh
Initialize recycled continuations in createContinuation before usage
55ba222 
Currently, recycled continuations are reset and initialized in
freeContinuation at the end of their use. There are also gaps where
the recycled continuation might retain old values and not be properly
reset.

The above approach leads to corruption and segfaults as seen in
the runJavaThread failure reported in eclipse-openj9#16728.

To fix the above crash, all continuations (new and recycled) are
initialized and reset in createContinuation just before the
continuation begins execution.

Related: eclipse-openj9#16728

Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>
@babsingh babsingh mentioned this issue Dec 19, 2023
Merged
@babsingh
Copy link
Contributor

[ISSUE 2] ... crash in runJavaThread

I was able to get a better native stack for the runJavaThread crash. After looking at the core file in jdmpview and dbx, it was found that the current approach of recycling continuations retains old values which leads to segfaults when a stack grow is triggered by a JIT StackOverflow. Couldn't figure out why the runJavaThread crash is only seen on AIX, but all issues related to the crash are resolved with the fix proposed in #18649. Successfully ran Skynet 50 times locally on AIX and verified that #18649 resolves the runJavaThread crash.

...
generateDiagnosticFiles(??, ??), line 1162 in "gphandle.c"
omrsig_protect(??, ??, ??, ??, ??, ??, ??), line 425 in "omrsignal.c"
structuredSignalHandler(??, ??, ??, ??), line 837 in "gphandle.c"
mainSynchSignalHandler(??, ??, ??), line 1066 in "omrsignal.c"
growSlotIterator(J9VMThread*, J9StackWalkState*, J9Object**, void const*)(0x10035982000, 0x10037da9230, 0xb7654321bd90aba4, 0xb7654321bd90aba4), line 524 in "growstack.cpp"
IPRA.$walkMethodFrame(??), line 1585 in "swalk.c"
walkStackFrames(??, ??), line 331 in "swalk.c"
internalGrowJavaStack(J9VMThread*, unsigned long)(??, ??), line 235 in "growstack.cpp"
growJavaStack(??, ??), line 97 in "growstack.cpp"
old_slow_jitStackOverflow(??), line 1347 in "cnathelp.cpp"
jitStackOverflow(), line 1956 in "pnathelp.s"
runJavaThread(??), line 682 in "callin.cpp"
javaProtectedThreadProc(J9PortLibrary*, void*)(??, ??), line 2104 in "vmthread.cpp"
omrsig_protect(??, ??, ??, ??, ??, ??, ??), line 425 in "omrsignal.c"
javaThreadProc(??), line 383 in "vmthread.cpp"
thread_wrapper(??), line 1733 in "omrthread.c"

@gita-omr
Copy link
Contributor

Excellent! And just to confirm: with -Xjit:verbose,exclude={*} -Xnoaot the test case timeouts sometimes but generally passes.

@babsingh babsingh reopened this Dec 19, 2023
babsingh added a commit to babsingh/openj9 that referenced this issue Dec 19, 2023
@babsingh
Initialize recycled continuations in createContinuation before usage
cec7140 
Currently, recycled continuations are reset and initialized in
freeContinuation at the end of their use. There are also gaps where
the recycled continuation might retain old values and not be properly
reset.

The above approach leads to corruption and segfaults as seen in
the runJavaThread failure reported in eclipse-openj9#16728.

To fix the above crash, all continuations (new and recycled) are
initialized and reset in createContinuation just before the
continuation begins execution.

Related: eclipse-openj9#16728

Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>
@babsingh babsingh mentioned this issue Dec 19, 2023
Merged
babsingh added a commit to babsingh/openj9 that referenced this issue Dec 19, 2023
@babsingh
Initialize recycled continuations in createContinuation before usage
e46cfd1 
Currently, recycled continuations are reset and initialized in
freeContinuation at the end of their use. There are also gaps where
the recycled continuation might retain old values and not be properly
reset.

The above approach leads to corruption and segfaults as seen in
the runJavaThread failure reported in eclipse-openj9#16728.

To fix the above crash, all continuations (new and recycled) are
initialized and reset in createContinuation just before the
continuation begins execution.

Related: eclipse-openj9#16728

Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>
@babsingh babsingh mentioned this issue Dec 19, 2023
Merged
babsingh added a commit to babsingh/aqa-tests that referenced this issue Dec 19, 2023
@babsingh
Enable Skynet on AIX
84f0edf 
Depends on
- eclipse-openj9/openj9#18649
- eclipse-openj9/openj9#18657
- eclipse-openj9/openj9#18658

Closes eclipse-openj9/openj9#16728

Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>
@babsingh babsingh mentioned this issue Dec 19, 2023
Merged
@babsingh
Copy link
Contributor

babsingh commented Dec 19, 2023 •
edited
Loading

re #16728 (comment):

Fix for ISSUE 1 and ISSUE 3

@LinHu2016 Can you confirm if issues 1 and 2 in #16728 (comment) are fixed by the above PRs?

This issue can be closed after the below PRs are merged.

Fix for ISSUE 2

Enable Skynet on AIX

@LinHu2016
Copy link
Contributor

#18637
#18651
#18652

@babsingh yes, ISSUE 1 and ISSUE 3 are fixed by the above PRs.

babsingh added a commit to babsingh/aqa-tests that referenced this issue Dec 19, 2023
@babsingh
Enable Skynet on AIX
ed2c955 
Depends on
- eclipse-openj9/openj9#18649
- eclipse-openj9/openj9#18657
- eclipse-openj9/openj9#18658

Closes eclipse-openj9/openj9#16728

Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>
babsingh added a commit to babsingh/aqa-tests that referenced this issue Dec 19, 2023
@babsingh
Enable Skynet on AIX
7ab047f 
Depends on
- eclipse-openj9/openj9#18649
- eclipse-openj9/openj9#18657
- eclipse-openj9/openj9#18658

Closes eclipse-openj9/openj9#16728

Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>
@babsingh babsingh mentioned this issue Dec 19, 2023
Merged
JasonFengJ9 pushed a commit to adoptium/aqa-tests that referenced this issue Dec 20, 2023
@babsingh
Enable Skynet on AIX (#4926)
76d08d9 
Depends on
- eclipse-openj9/openj9#18649
- eclipse-openj9/openj9#18657
- eclipse-openj9/openj9#18658

Closes eclipse-openj9/openj9#16728

Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@fengxue-IS fengxue-IS

Labels
comp:gc comp:jit comp:vm jdk19 perf project:loom Used to track Project Loom related work test failure
Projects
None yet
Milestone
Java 21 (0.42)