OpenJDK java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned timeout #18908

pshipton · 2024-02-06T20:18:43Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/1/
jdk_lang_0
java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned.java#id0

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/1/openjdk_test_output.tar.gz

06:20:19  Timeout information:
06:20:19  Running jcmd on process 798231
06:20:19  Dump written to /home/jenkins/workspace/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/aqa-tests/TKG/output_17072162697706/jdk_lang_0/work/scratch/1/core.20240206.111933.798231.0001.dmp
06:20:19  Dump written to /home/jenkins/workspace/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/aqa-tests/TKG/output_17072162697706/jdk_lang_0/work/scratch/1/javacore.20240206.112004.798231.0002.txt
06:20:19  Running jstack on process 798231
06:20:19  2024-02-06T11:20:04.428061278
06:20:19  Virtual machine: 798231 JVM information:
06:20:19  JRE 22 Linux s390x-64-Bit Compressed References 20240205_7 (JIT enabled, AOT enabled)
06:20:19  OpenJ9   - c92d58374fe
06:20:19  OMR      - 410ef0d2314
06:20:19  JCL      - 2a64d9c6fcb based on jdk-22+34
06:20:19  
06:20:19  "main" prio=5 Id=2 WAITING
06:20:19  	at java.base@22-internal/java.lang.Object.waitImpl(Native Method)
06:20:19  	at java.base@22-internal/java.lang.Object.wait(Object.java:255)
06:20:19  	at java.base@22-internal/java.lang.Object.wait(Object.java:221)
06:20:19  	at java.base@22-internal/java.lang.Thread.join(Thread.java:2069)
06:20:19  	at java.base@22-internal/java.lang.Thread.join(Thread.java:2145)
06:20:19  	at app//com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:85)
06:20:19  
06:20:19  "JIT Compilation Thread-000" prio=10 Id=4 RUNNABLE
06:20:19  
06:20:19  "JIT Compilation Thread-001 Suspended" prio=10 Id=5 RUNNABLE
06:20:19  
06:20:19  "JIT Compilation Thread-002 Suspended" prio=10 Id=6 RUNNABLE
06:20:19  
06:20:19  "JIT Compilation Thread-003 Suspended" prio=10 Id=7 RUNNABLE
06:20:19  
06:20:19  "JIT Compilation Thread-004 Suspended" prio=10 Id=8 RUNNABLE
06:20:19  
06:20:19  "JIT Compilation Thread-005 Suspended" prio=10 Id=9 RUNNABLE
06:20:19  
06:20:19  "JIT Compilation Thread-006 Suspended" prio=10 Id=10 RUNNABLE
06:20:19  
06:20:19  "JIT Diagnostic Compilation Thread-007 Suspended" prio=10 Id=11 RUNNABLE
06:20:19  
06:20:19  "JIT-SamplerThread" prio=10 Id=12 TIMED_WAITING
06:20:19  
06:20:19  "IProfiler" prio=5 Id=13 RUNNABLE
06:20:19  
06:20:19  "Common-Cleaner" prio=8 Id=3 TIMED_WAITING
06:20:19  	at java.base@22-internal/java.lang.Object.waitImpl(Native Method)
06:20:19  	at java.base@22-internal/java.lang.Object.wait(Object.java:255)
06:20:19  	at java.base@22-internal/java.lang.Object.wait(Object.java:221)
06:20:19  	at java.base@22-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
06:20:19  	at java.base@22-internal/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:140)
06:20:19  	at java.base@22-internal/java.lang.Thread.run(Thread.java:1582)
06:20:19  	at java.base@22-internal/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:186)
06:20:19  
06:20:19  "Finalizer thread" prio=5 Id=14 RUNNABLE
06:20:19  
06:20:19  "Concurrent Mark Helper" prio=1 Id=15 RUNNABLE
06:20:19  
06:20:19  "GC Worker" prio=5 Id=16 RUNNABLE
06:20:19  
06:20:19  "GC Worker" prio=5 Id=17 RUNNABLE
06:20:19  
06:20:19  "GC Worker" prio=5 Id=18 RUNNABLE
06:20:19  
06:20:19  "Attach API wait loop" prio=10 Id=21 RUNNABLE
06:20:19  	at java.base@22-internal/openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
06:20:19  	at java.base@22-internal/openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
06:20:19  	at java.base@22-internal/openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
06:20:19  	at java.base@22-internal/openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
06:20:19  
06:20:19  "MainThread" prio=5 Id=22 RUNNABLE
06:20:19  	at java.base@22-internal/java.lang.Thread.getStackTraceImpl(Native Method)
06:20:19  	at java.base@22-internal/java.lang.Thread.getStackTrace0(Thread.java:2476)
06:20:19  	- locked java.lang.Object@cea6ea87
06:20:19  	at java.base@22-internal/java.lang.Thread.asyncGetStackTrace(Thread.java:2457)
06:20:19  	at java.base@22-internal/java.lang.VirtualThread.asyncGetStackTrace(VirtualThread.java:978)
06:20:19  	at java.base@22-internal/java.lang.Thread.getStackTrace(Thread.java:2442)
06:20:19  	at app//GetStackTraceALotWhenPinned.main(GetStackTraceALotWhenPinned.java:84)
06:20:19  	at java.base@22-internal/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
06:20:19  	at java.base@22-internal/java.lang.reflect.Method.invoke(Method.java:586)
06:20:19  	at app//com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
06:20:19  	at java.base@22-internal/java.lang.Thread.run(Thread.java:1582)
06:20:19  
06:20:19  "ForkJoinPool-1-worker-1" prio=5 Id=24 BLOCKED on java.lang.Object@cea6ea87 owned by "MainThread" Id=22
06:20:19  	at java.base@22-internal/java.lang.VirtualThread.unmount(VirtualThread.java:399)
06:20:19  	at java.base@22-internal/java.lang.VirtualThread.runContinuation(VirtualThread.java:253)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute(ForkJoinTask.java:1726)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.compute(ForkJoinTask.java:1717)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinTask$InterruptibleTask.exec(ForkJoinTask.java:1641)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:507)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1491)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:2073)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2035)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)
06:20:19  
06:20:19  "ForkJoinPool-1-worker-2" prio=5 Id=25 WAITING
06:20:19  	at java.base@22-internal/jdk.internal.misc.Unsafe.park(Native Method)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:2145)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2036)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)
06:20:19  
06:20:19  "VirtualThread-unparker" prio=5 Id=26 WAITING
06:20:19  	at java.base@22-internal/jdk.internal.misc.Unsafe.park(Native Method)
06:20:19  	at java.base@22-internal/java.util.concurrent.locks.LockSupport.park(LockSupport.java:371)
06:20:19  	at java.base@22-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:519)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:4013)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3961)
06:20:19  	at java.base@22-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1707)
06:20:19  	at java.base@22-internal/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1170)
06:20:19  	at java.base@22-internal/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
06:20:19  	at java.base@22-internal/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1070)
06:20:19  	at java.base@22-internal/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
06:20:19  	at java.base@22-internal/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
06:20:19  	at java.base@22-internal/java.lang.Thread.run(Thread.java:1582)
06:20:19  	at java.base@22-internal/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:186)
06:20:19  
06:20:19  "ForkJoinPool-1-worker-3" prio=5 Id=27 WAITING
06:20:19  	at java.base@22-internal/jdk.internal.misc.Unsafe.park(Native Method)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:2145)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2036)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)
06:20:19  
06:20:19  "ForkJoinPool-1-worker-4" prio=5 Id=28 WAITING
06:20:19  	at java.base@22-internal/jdk.internal.misc.Unsafe.park(Native Method)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:2145)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2036)
06:20:19  	at java.base@22-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)
06:20:19  
06:20:19  "file lock watchdog" prio=10 Id=30 TIMED_WAITING
06:20:19  	at java.base@22-internal/java.lang.Object.waitImpl(Native Method)
06:20:19  	at java.base@22-internal/java.lang.Object.wait(Object.java:255)
06:20:19  	at java.base@22-internal/java.lang.Object.wait(Object.java:221)
06:20:19  	at java.base@22-internal/java.util.TimerThread.mainLoop(Timer.java:607)
06:20:19  	at java.base@22-internal/java.util.TimerThread.run(Timer.java:548)
06:20:19  
06:20:19  "Attachment portNumber: 44871" prio=10 Id=32 RUNNABLE
06:20:19  	at java.base@22-internal/openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
06:20:19  	at java.base@22-internal/openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:249)
06:20:19  	at java.base@22-internal/openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:185)
06:20:19  	at java.base@22-internal/openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:251)
06:20:19  	at java.base@22-internal/openj9.internal.tools.attach.target.Attachment.run(Attachment.java:161)
06:20:19  
06:20:19  
06:20:19  --- Timeout information end.

06:20:19  2024-02-06T11:19:30.248219936Z 336026 remaining ...
06:20:19  2024-02-06T11:19:30.749430608Z 335815 remaining ...
06:20:19  2024-02-06T11:19:31.405589797Z 335742 remaining ...
06:20:19  2024-02-06T11:19:31.908375978Z 335693 remaining ...
06:20:19  Timeout signalled after 960 seconds
06:20:19  2024-02-06T11:19:32.412877104Z 335644 remaining ...
06:20:19  2024-02-06T11:19:32.922927033Z 335592 remaining ...
06:20:19  2024-02-06T11:20:03.339294832Z 335583 remaining ...
06:20:19  2024-02-06T11:20:03.840195248Z 334276 remaining ...
06:20:19  2024-02-06T11:20:04.342183739Z 332638 remaining ...
06:20:19  2024-02-06T11:20:04.848906147Z 331119 remaining ...

The text was updated successfully, but these errors were encountered:

pshipton · 2024-02-06T20:21:51Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/1
jdk_lang_1
java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned.java#id0

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/1/openjdk_test_output.tar.gz

06:16:53  Timeout information:
06:16:53  Running jcmd on process 31288
06:16:53  Dump written to /home/jenkins/workspace/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/aqa-tests/TKG/output_17072160479527/jdk_lang_1/work/scratch/0/core.20240206.061600.31288.0001.dmp
06:16:53  Dump written to /home/jenkins/workspace/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/aqa-tests/TKG/output_17072160479527/jdk_lang_1/work/scratch/0/javacore.20240206.061630.31288.0002.txt
06:16:53  Running jstack on process 31288
06:16:53  2024-02-06T06:16:33.168758544
06:16:53  Virtual machine: 31288 JVM information:
06:16:53  JRE 22 Linux s390x-64-Bit 20240205_7 (JIT enabled, AOT enabled)
06:16:53  OpenJ9   - c92d58374fe
06:16:53  OMR      - 410ef0d2314
06:16:53  JCL      - 2a64d9c6fcb based on jdk-22+34
06:16:53  
06:16:53  "main" prio=5 Id=2 WAITING
06:16:53  	at java.base@22-internal/java.lang.Object.waitImpl(Native Method)
06:16:53  	at java.base@22-internal/java.lang.Object.wait(Object.java:255)
06:16:53  	at java.base@22-internal/java.lang.Object.wait(Object.java:221)
06:16:53  	at java.base@22-internal/java.lang.Thread.join(Thread.java:2069)
06:16:53  	at java.base@22-internal/java.lang.Thread.join(Thread.java:2145)
06:16:53  	at app//com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:85)
06:16:53  
06:16:53  "JIT Compilation Thread-000" prio=10 Id=4 RUNNABLE
06:16:53  
06:16:53  "JIT Compilation Thread-001 Suspended" prio=10 Id=5 RUNNABLE
06:16:53  
06:16:53  "JIT Compilation Thread-002 Suspended" prio=10 Id=6 RUNNABLE
06:16:53  
06:16:53  "JIT Compilation Thread-003 Suspended" prio=10 Id=7 RUNNABLE
06:16:53  
06:16:53  "JIT Compilation Thread-004 Suspended" prio=10 Id=8 RUNNABLE
06:16:53  
06:16:53  "JIT Compilation Thread-005 Suspended" prio=10 Id=9 RUNNABLE
06:16:53  
06:16:53  "JIT Compilation Thread-006 Suspended" prio=10 Id=10 RUNNABLE
06:16:53  
06:16:53  "JIT Diagnostic Compilation Thread-007 Suspended" prio=10 Id=11 RUNNABLE
06:16:53  
06:16:53  "JIT-SamplerThread" prio=10 Id=12 TIMED_WAITING
06:16:53  
06:16:53  "IProfiler" prio=5 Id=13 RUNNABLE
06:16:53  
06:16:53  "Common-Cleaner" prio=8 Id=3 TIMED_WAITING
06:16:53  	at java.base@22-internal/java.lang.Object.waitImpl(Native Method)
06:16:53  	at java.base@22-internal/java.lang.Object.wait(Object.java:255)
06:16:53  	at java.base@22-internal/java.lang.Object.wait(Object.java:221)
06:16:53  	at java.base@22-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
06:16:53  	at java.base@22-internal/jdk.internal.ref.CleanerImpl.run(CleanerImpl.java:140)
06:16:53  	at java.base@22-internal/java.lang.Thread.run(Thread.java:1582)
06:16:53  	at java.base@22-internal/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:186)
06:16:53  
06:16:53  "Finalizer thread" prio=5 Id=14 RUNNABLE
06:16:53  
06:16:53  "Concurrent Mark Helper" prio=1 Id=15 RUNNABLE
06:16:53  
06:16:53  "GC Worker" prio=5 Id=16 RUNNABLE
06:16:53  
06:16:53  "GC Worker" prio=5 Id=17 RUNNABLE
06:16:53  
06:16:53  "GC Worker" prio=5 Id=18 RUNNABLE
06:16:53  
06:16:53  "Attach API wait loop" prio=10 Id=21 RUNNABLE
06:16:53  	at java.base@22-internal/openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
06:16:53  	at java.base@22-internal/openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
06:16:53  	at java.base@22-internal/openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
06:16:53  	at java.base@22-internal/openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
06:16:53  
06:16:53  "MainThread" prio=5 Id=22 RUNNABLE
06:16:53  	at app//GetStackTraceALotWhenPinned$Barrier.await(GetStackTraceALotWhenPinned.java:117)
06:16:53  	at app//GetStackTraceALotWhenPinned.main(GetStackTraceALotWhenPinned.java:82)
06:16:53  	at java.base@22-internal/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
06:16:53  	at java.base@22-internal/java.lang.reflect.Method.invoke(Method.java:586)
06:16:53  	at app//com.sun.javatest.regtest.agent.MainWrapper$MainTask.run(MainWrapper.java:138)
06:16:53  	at java.base@22-internal/java.lang.Thread.run(Thread.java:1582)
06:16:53  
06:16:53  "ForkJoinPool-1-worker-1" prio=5 Id=24 WAITING
06:16:53  	at java.base@22-internal/jdk.internal.misc.Unsafe.park(Native Method)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:2145)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2036)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)
06:16:53  
06:16:53  "ForkJoinPool-1-worker-2" prio=5 Id=25 WAITING
06:16:53  	at java.base@22-internal/jdk.internal.misc.Unsafe.park(Native Method)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:2145)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2036)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)
06:16:53  
06:16:53  "ForkJoinPool-1-worker-3" prio=5 Id=26 WAITING
06:16:53  	at java.base@22-internal/jdk.internal.misc.Unsafe.park(Native Method)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:2145)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2036)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)
06:16:53  
06:16:53  "ForkJoinPool-1-worker-4" prio=5 Id=27 TIMED_WAITING
06:16:53  	at java.base@22-internal/jdk.internal.misc.Unsafe.park(Native Method)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.awaitWork(ForkJoinPool.java:2145)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:2036)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:187)
06:16:53  
06:16:53  "VirtualThread-unparker" prio=5 Id=28 WAITING
06:16:53  	at java.base@22-internal/jdk.internal.misc.Unsafe.park(Native Method)
06:16:53  	at java.base@22-internal/java.util.concurrent.locks.LockSupport.park(LockSupport.java:371)
06:16:53  	at java.base@22-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:519)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:4013)
06:16:53  	at java.base@22-internal/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3961)
06:16:53  	at java.base@22-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1707)
06:16:53  	at java.base@22-internal/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1170)
06:16:53  	at java.base@22-internal/java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:899)
06:16:53  	at java.base@22-internal/java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1070)
06:16:53  	at java.base@22-internal/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
06:16:53  	at java.base@22-internal/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
06:16:53  	at java.base@22-internal/java.lang.Thread.run(Thread.java:1582)
06:16:53  	at java.base@22-internal/jdk.internal.misc.InnocuousThread.run(InnocuousThread.java:186)
06:16:53  
06:16:53  "file lock watchdog" prio=10 Id=30 TIMED_WAITING
06:16:53  	at java.base@22-internal/java.lang.Object.waitImpl(Native Method)
06:16:53  	at java.base@22-internal/java.lang.Object.wait(Object.java:255)
06:16:53  	at java.base@22-internal/java.lang.Object.wait(Object.java:221)
06:16:53  	at java.base@22-internal/java.util.TimerThread.mainLoop(Timer.java:607)
06:16:53  	at java.base@22-internal/java.util.TimerThread.run(Timer.java:548)
06:16:53  
06:16:53  "Attachment portNumber: 36752" prio=10 Id=32 RUNNABLE
06:16:53  	at java.base@22-internal/openj9.internal.tools.attach.target.DiagnosticUtils.dumpAllThreadsImpl(Native Method)
06:16:53  	at java.base@22-internal/openj9.internal.tools.attach.target.DiagnosticUtils.getThreadInfo(DiagnosticUtils.java:249)
06:16:53  	at java.base@22-internal/openj9.internal.tools.attach.target.DiagnosticUtils.executeDiagnosticCommand(DiagnosticUtils.java:185)
06:16:53  	at java.base@22-internal/openj9.internal.tools.attach.target.Attachment.doCommand(Attachment.java:251)
06:16:53  	at java.base@22-internal/openj9.internal.tools.attach.target.Attachment.run(Attachment.java:161)
06:16:53  
06:16:53  
06:16:53  --- Timeout information end.

06:16:53  2024-02-06T11:15:56.354789666Z 334811 remaining ...
06:16:53  2024-02-06T11:15:57.304847040Z 334755 remaining ...
06:16:53  2024-02-06T11:15:57.810945791Z 334619 remaining ...
06:16:53  Timeout signalled after 960 seconds
06:16:53  2024-02-06T11:15:58.334285041Z 334475 remaining ...
06:16:53  2024-02-06T11:15:59.212961794Z 334434 remaining ...
06:16:53  2024-02-06T11:15:59.755126539Z 334421 remaining ...
06:16:53  2024-02-06T11:16:26.853400419Z 334404 remaining ...
06:16:53  2024-02-06T11:16:27.382698916Z 334374 remaining ...
06:16:53  2024-02-06T11:16:28.239463665Z 334372 remaining ...
06:16:53  2024-02-06T11:16:29.005149416Z 334370 remaining ...
06:16:53  2024-02-06T11:16:29.515176039Z 334354 remaining ...
06:16:53  2024-02-06T11:16:30.018537288Z 334315 remaining ...
06:16:53  2024-02-06T11:16:30.531717039Z 334294 remaining ...
06:16:53  2024-02-06T11:16:31.482719414Z 334291 remaining ...
06:16:53  2024-02-06T11:16:32.483652669Z 334250 remaining ...
06:16:53  2024-02-06T11:16:33.156306294Z 334246 remaining ...
06:16:53  2024-02-06T11:16:33.764316794Z 334227 remaining ...
06:16:53  2024-02-06T11:16:34.412770794Z 334225 remaining ...
06:16:53  2024-02-06T11:16:35.055028040Z 334191 remaining ...

pshipton · 2024-02-07T13:06:16Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/2/
jdk_lang_0
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/2/openjdk_test_output.tar.gz

https://openj9-jenkins.osuosl.org/job/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/2
jdk_lang_1
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk22_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/2/openjdk_test_output.tar.gz

eclipse-openj9/openj9#18908 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

pshipton · 2024-02-07T13:21:51Z

Excluding the test on zlinux via adoptium/aqa-tests#5042

…5042) eclipse-openj9/openj9#18908 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

tajila · 2024-02-08T15:39:08Z

@fengxue-IS Please take a look at this

Fix adoptium#5042 which added the excludes to the wrong files. Issue eclipse-openj9/openj9#18908 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

pshipton · 2024-02-08T19:04:31Z

Corrected the excludes in adoptium/aqa-tests#5051

…5051) Fix #5042 which added the excludes to the wrong files. Issue eclipse-openj9/openj9#18908 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

tajila · 2024-03-04T21:34:17Z

@fengxue-IS any update on this?

fengxue-IS · 2024-03-05T21:04:13Z

I wasn't able to reproduce this failure individually on a zlinux machine, running grinder to see if this is can only be reproduced in the suite.

fengxue-IS · 2024-03-07T20:28:13Z

[Grinder 20x run on 20 machines 19/20 passed] (https://hyc-runtimes-jenkins.swg-devops.com/view/Test_grinder/job/Grinder/38416/)
All the passing machines average 2~5mins per iteration, the only failed machine took 8~9 mins for the passing runs and 16+mins for the failed run.

All machines are spec to 4CPU and ~8G RAM. so perf delta isn't related to insufficient core count.

Looking at the failed test's output, its very similar to the original where timeout occurred while the test is still slowly making process. So this doesn't seem to be a functional issue, just performance.

I'll see if modifying the test set up parameters could speed this up.

fengxue-IS · 2024-03-11T18:21:31Z

I've tried to modify the test to get a bit more detail of where the perf issue is coming from.

Noticed that the Thread.getStackTrace() API is whats taking majority of the time. after setting the thread state to unmount whenever API is called, that resulted in a 100x perf improvement on the API runtime (ie 1800~3000us -> 20~27us per getStackTrace()). Compared to RI, they only have a 10x perf delta (80~100us -> 10~15us) changing from unsteady state to consistent unmounted state.

This is a perf issue that we should consider to investigate and address by looking into how the getstacktrace call is done for virtual threads.

pshipton · 2024-05-06T15:39:43Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/217 - rh7-390-2
jdk_lang_j9_0
java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned.java#id0

timeout

Changes from previous build
6e1e36f...2c34fcf
ibmruntimes/openj9-openjdk-jdk21@10c9cf1...5194f18 - update to 21.0.4

pshipton · 2024-05-07T12:26:29Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_Nightly_testList_0/218 - rh8-390-1
jdk_lang0, jdk_lang_j9_0
java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned.java#id0

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/218 - ub20-390-5
jdk_lang_1
java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned.java#id0

timeout

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_OMR_testList_0/107/
jdk_lang_0
java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned.java#id0

pshipton · 2024-05-09T18:14:17Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_Nightly_testList_1/219
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_OpenJDK21_testList_0/21/
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_OMR_testList_0/108/
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_OMR_testList_1/108/

pshipton · 2024-05-09T18:25:18Z

There was an update 21.0.3 -> 21.0.4+1 and this has been regularly failing on zlinux ever since. I've set it as a blocker for the next release to figure out what's going on.

fengxue-IS · 2024-05-09T18:40:58Z

I ll take a look at the update between 21.0.3 and 21.0.4+1

fengxue-IS · 2024-05-09T22:11:26Z

This test looks to be a back port to 21 from 22 in 21.0.4 with modification of a new class VThreadPinner added as a wrapper in the test code. looking at the output of test failures, seem to be same issue as previously mentioned due to performance, the test timed out after ~15mins completing 75~90% of total workload.

I will create a custom build to get some profiling data to see what is causing this bottleneck in performance in getStackTrace() API.

pshipton · 2024-05-10T16:36:27Z

It just fails once or more in every build, I'm not going to keep reporting them.

pshipton · 2024-05-10T16:36:40Z

We should probably exclude it.

pshipton · 2024-05-13T12:16:56Z

Some on xmac
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_x86-64_mac_Nightly_testList_0/159/
https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_x86-64_mac_Nightly_testList_1/159/

fengxue-IS · 2024-05-13T15:11:26Z

I created the PR to exclude test for zLinux until the perf issue is resolved.

The xmac failure looks to be different from zLinux as it triggered an assertion failure during stackwalk, will have to look more into the corefile generated to find the cause.

fengxue-IS · 2024-06-12T17:51:47Z

I launched a 50x grinder on zlinux with the latest JDK 21 nightly build, all passed, longest is ~4mins / iteration, which is much less than the timeout.

Currently looks like performance isn't preventing test from completing, given that getStackTrace is a slowpath and test targets a very edge scenario, can we remove the blocker tag for this (possibly move this to backlog as well)? @pshipton

Note: this have only be verified on internal machine, I don't have access to verify this on the openj9 jenkins farm, so we should also test this on openj9 jenkins.

pshipton · 2024-06-12T18:23:35Z

I will remove the blocker. Any update on the xmac failures?

fengxue-IS · 2024-06-12T18:25:13Z

I've been running grinders on xmac, have not been able to reproduce the failure yet

pshipton · 2024-06-12T18:38:15Z

Testing using default options on zlinux and xmac
60x across 3 machines https://openj9-jenkins.osuosl.org/view/Test/job/Grinder/3659 - passed on both xmac and AIX

pshipton · 2024-06-12T20:33:16Z

The grinders passed, we could re-enable the testing and see how it goes. Perhaps some change has improved the behavior, or it's possible the tests only fail when they are run as part of the larger group of tests, and not when run standalone.

hzongaro · 2024-06-22T11:44:18Z

I hit this timeout on zLinux in a PR build: https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_Personal_testList_1/28/ and https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_Personal_testList_0/28/

pshipton · 2024-06-25T15:04:59Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_s390x_linux_OMR_testList_0/128 - rh7-390-1
10:14:59 jdk_lang_0 - Test results: passed: 936; error: 1
10:14:59 Failed test cases:
10:14:59 TEST: java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned.java#id0
10:14:59
10:14:59 jdk_lang_j9_0 - Test results: passed: 936; error: 1
10:14:59 Failed test cases:
10:14:59 TEST: java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned.java#id0

fengxue-IS · 2024-06-25T17:06:51Z

Output show same timeout issue, 20% of workload completed in the 960s interval for jdk_lang_0, 80% complete for jdk_lang_j9_0

Running a 5 x 10x grinder on the jdk_lang_j9_0 suite to check failure rate as this have not been reproducible as stand alone test.

pshipton · 2024-06-26T12:37:55Z

Pls exclude the test again on zlinux, it's failing in pretty much every build.

fengxue-IS · 2024-06-26T16:20:30Z

PR open to disable test on zlinux

The 50x grinder from yesterday passed, so this seem to be specific to the openj9 jenkins environment.

pshipton · 2024-06-27T22:09:58Z

Removing from the 0.46 milestone.

JasonFengJ9 · 2024-09-10T22:04:17Z

JDK23 x86-64_windows(win22x86-rtp-rt4-1)

[2024-09-10T09:29:37.028Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage Mode650
[2024-09-10T09:29:37.912Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-JITServerTechPreviewMessage -XX:-UseCompressedOops 

[2024-09-10T13:03:51.276Z] TEST: java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned.java#id0

[2024-09-10T13:03:51.288Z] TEST RESULT: Error. Program `C:\Users\jenkins\workspace\Test_openjdk23_j9_sanity.openjdk_x86-64_windows_testList_0\jdkbinary\j2sdk-image\bin\java' timed out (timeout set to 960000ms, elapsed time including timeout handling was 1012676ms).
[2024-09-10T13:03:51.288Z] --------------------------------------------------
[2024-09-10T13:41:09.616Z] Test results: passed: 930; error: 1
[2024-09-10T13:43:52.575Z] Report written to C:\Users\jenkins\workspace\Test_openjdk23_j9_sanity.openjdk_x86-64_windows_testList_0\aqa-tests\TKG\output_17259605494566\jdk_lang_1\report\html\report.html
[2024-09-10T13:43:52.575Z] Results written to C:\Users\jenkins\workspace\Test_openjdk23_j9_sanity.openjdk_x86-64_windows_testList_0\aqa-tests\TKG\output_17259605494566\jdk_lang_1\work
[2024-09-10T13:43:52.575Z] Error: Some tests failed or other problems occurred.
[2024-09-10T13:43:52.575Z] -----------------------------------
[2024-09-10T13:43:52.575Z] jdk_lang_1_FAILED

pshipton added comp:vm test failure jdk22 labels Feb 6, 2024

pshipton added this to the Java 22 milestone Feb 6, 2024

pshipton mentioned this issue Feb 6, 2024

OpenJDK java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned Invalid JIT return address ASSERTION FAILED swalk.c:1629: ((0 )) #18910

Closed

pshipton added a commit to pshipton/openjdk-tests that referenced this issue Feb 7, 2024

Exclude GetStackTraceALotWhenPinned on OpenJ9 for jdk22+ on zlinux

2e92be0

eclipse-openj9/openj9#18908 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

pshipton added the test excluded label Feb 7, 2024

pshipton mentioned this issue Feb 7, 2024

Exclude GetStackTraceALotWhenPinned on OpenJ9 for jdk22+ on zlinux adoptium/aqa-tests#5042

Merged

JasonFengJ9 pushed a commit to adoptium/aqa-tests that referenced this issue Feb 7, 2024

Exclude GetStackTraceALotWhenPinned on OpenJ9 for jdk22+ on zlinux (#…

1296088

…5042) eclipse-openj9/openj9#18908 Signed-off-by: Peter Shipton <Peter_Shipton@ca.ibm.com>

pshipton mentioned this issue Feb 8, 2024

Exclude GetStackTraceALotWhenPinned on OpenJ9 for jdk22+ on zlinux adoptium/aqa-tests#5051

Merged

tajila assigned fengxue-IS Feb 26, 2024

tajila added the project:loom Used to track Project Loom related work label Feb 26, 2024

tajila modified the milestones: Java 22 (0.45), Release 0.46 (Java 8, 11, 17, 21, 22) July refresh Mar 11, 2024

tajila added the perf label Mar 11, 2024

pshipton added the blocker label May 9, 2024

pshipton removed the jdk22 label May 9, 2024

hzongaro mentioned this issue May 10, 2024

Skip HCR guards for inlining intrinsifiable methods #19469

Merged

fengxue-IS mentioned this issue May 13, 2024

Exclude GetStackTraceALotWhenPinned test on zLinux & xMac adoptium/aqa-tests#5309

Merged

pshipton removed the blocker label Jun 12, 2024

fengxue-IS mentioned this issue Jun 19, 2024

Re-enable test GetStackTraceALotWhenPinned.java adoptium/aqa-tests#5395

Merged

pshipton closed this as completed in adoptium/aqa-tests#5395 Jun 19, 2024

hzongaro mentioned this issue Jun 22, 2024

Extend arraycmp length child #19332

Merged

pshipton reopened this Jun 25, 2024

fengxue-IS mentioned this issue Jun 26, 2024

Disable GetStackTraceALotWhenPinned.java on zLinux due to timeout adoptium/aqa-tests#5407

Merged

pshipton removed this from the Release 0.46 (Java 8, 11, 17, 21, 22) July refresh milestone Jun 27, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

OpenJDK java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned timeout #18908

OpenJDK java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned timeout #18908

pshipton commented Feb 6, 2024

pshipton commented Feb 6, 2024

pshipton commented Feb 7, 2024

pshipton commented Feb 7, 2024

tajila commented Feb 8, 2024

pshipton commented Feb 8, 2024

tajila commented Mar 4, 2024

fengxue-IS commented Mar 5, 2024

fengxue-IS commented Mar 7, 2024 •

edited

Loading

fengxue-IS commented Mar 11, 2024 •

edited

Loading

pshipton commented May 6, 2024 •

edited

Loading

pshipton commented May 7, 2024 •

edited

Loading

pshipton commented May 9, 2024 •

edited

Loading

pshipton commented May 9, 2024

fengxue-IS commented May 9, 2024

fengxue-IS commented May 9, 2024 •

edited

Loading

pshipton commented May 10, 2024

pshipton commented May 10, 2024

pshipton commented May 13, 2024

fengxue-IS commented May 13, 2024

fengxue-IS commented Jun 12, 2024

pshipton commented Jun 12, 2024

fengxue-IS commented Jun 12, 2024

pshipton commented Jun 12, 2024 •

edited

Loading

pshipton commented Jun 12, 2024

hzongaro commented Jun 22, 2024 •

edited

Loading

pshipton commented Jun 25, 2024 •

edited

Loading

fengxue-IS commented Jun 25, 2024

pshipton commented Jun 26, 2024

fengxue-IS commented Jun 26, 2024

pshipton commented Jun 27, 2024

JasonFengJ9 commented Sep 10, 2024

OpenJDK java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned timeout #18908

OpenJDK java/lang/Thread/virtual/stress/GetStackTraceALotWhenPinned timeout #18908

Comments

pshipton commented Feb 6, 2024

pshipton commented Feb 6, 2024

pshipton commented Feb 7, 2024

pshipton commented Feb 7, 2024

tajila commented Feb 8, 2024

pshipton commented Feb 8, 2024

tajila commented Mar 4, 2024

fengxue-IS commented Mar 5, 2024

fengxue-IS commented Mar 7, 2024 • edited Loading

fengxue-IS commented Mar 11, 2024 • edited Loading

pshipton commented May 6, 2024 • edited Loading

pshipton commented May 7, 2024 • edited Loading

pshipton commented May 9, 2024 • edited Loading

pshipton commented May 9, 2024

fengxue-IS commented May 9, 2024

fengxue-IS commented May 9, 2024 • edited Loading

pshipton commented May 10, 2024

pshipton commented May 10, 2024

pshipton commented May 13, 2024

fengxue-IS commented May 13, 2024

fengxue-IS commented Jun 12, 2024

pshipton commented Jun 12, 2024

fengxue-IS commented Jun 12, 2024

pshipton commented Jun 12, 2024 • edited Loading

pshipton commented Jun 12, 2024

hzongaro commented Jun 22, 2024 • edited Loading

pshipton commented Jun 25, 2024 • edited Loading

fengxue-IS commented Jun 25, 2024

pshipton commented Jun 26, 2024

fengxue-IS commented Jun 26, 2024

pshipton commented Jun 27, 2024

JasonFengJ9 commented Sep 10, 2024

fengxue-IS commented Mar 7, 2024 •

edited

Loading

fengxue-IS commented Mar 11, 2024 •

edited

Loading

pshipton commented May 6, 2024 •

edited

Loading

pshipton commented May 7, 2024 •

edited

Loading

pshipton commented May 9, 2024 •

edited

Loading

fengxue-IS commented May 9, 2024 •

edited

Loading

pshipton commented Jun 12, 2024 •

edited

Loading

hzongaro commented Jun 22, 2024 •

edited

Loading

pshipton commented Jun 25, 2024 •

edited

Loading