openj9
openj9 copied to clipboard
Published
20 hours ago •
eclipse-openj9
eclipse-openj9
MiniMix, ConcurrentLoadTest hang, sometimes waiting on jsr166y/WaiterTask
https://ci.eclipse.org/openj9/job/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/15 MiniMix_5m_0 javacore files and core file in diagnostics https://140-211-168-230-openstack.osuosl.org/artifactory/ci-eclipse-openj9/Test/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/15/system_test_output.tar.gz
LT 05:41:52.861 - Completed 100.0%. Number of tests started=50664 (+0)
LT 05:42:12.882 - Completed 100.0%. Number of tests started=50664 (+0)
LT 05:42:32.903 - Completed 100.0%. Number of tests started=50664 (+0)
STF 05:42:50.082 - Heartbeat: Process LT is still running
LT 05:42:52.824 - Completed 100.0%. Number of tests started=50664 (+0)
LT 05:43:12.248 - **POSSIBLE HANG DETECTED**
STF 05:43:12.621 - **FAILED** Process LT has hung
STF 05:43:12.621 - Collecting dumps for: LT
STF 05:43:12.621 - Sending SIG 3 to the java process to generate a javacore
STF 05:43:12.623 - Running command: kill -3 7285
STF 05:43:12.623 - Redirecting stderr to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_3.stderr
STF 05:43:12.623 - Redirecting stdout to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_3.stdout
STF 05:43:12.631 - Pausing for 30 seconds
STF 05:43:42.632 - Sending SIG 3 to the java process to generate a javacore
STF 05:43:42.636 - Running command: kill -3 7285
STF 05:43:42.636 - Redirecting stderr to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_3.stderr
STF 05:43:42.636 - Redirecting stdout to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_3.stdout
STF 05:43:42.642 - Pausing for 30 seconds
STF 05:44:12.644 - Sending SIG 3 to the java process to generate a javacore
STF 05:44:12.646 - Running command: kill -3 7285
STF 05:44:12.646 - Redirecting stderr to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_3.stderr
STF 05:44:12.646 - Redirecting stdout to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_3.stdout
STF 05:44:12.651 - Pausing for 30 seconds
STF 05:44:42.652 - Sending SIGABRT (kill -6) to the java process to generate a core
STF 05:44:42.654 - Running command: kill -6 7285
STF 05:44:42.654 - Redirecting stderr to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_6.stderr
STF 05:44:42.654 - Redirecting stdout to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_6.stdout
STF 05:44:42.659 - Pausing for 30 seconds
STF 05:45:12.661 - Sending SIGXCPU (kill -24) to the java process to generate an OS dump
STF 05:45:12.663 - Running command: kill -24 7285
STF 05:45:12.663 - Redirecting stderr to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_24.stderr
STF 05:45:12.663 - Redirecting stdout to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Nightly_testList_1/openjdk-tests/TKG/output_16123450529369/MiniMix_5m_0/20210203-052247-MixedLoadTest/results/1.LT.kill_24.stdout
LT 05:43:13.447 - Completed 100.0%. Number of tests started=50664 (+0)
LT 05:43:17.252 - **POSSIBLE HANG DETECTED**
LT 05:43:22.258 - **POSSIBLE HANG DETECTED**
LT 05:43:27.262 - **POSSIBLE HANG DETECTED**
LT 05:43:32.269 - **POSSIBLE HANG DETECTED**
LT 05:43:32.870 - Completed 100.0%. Number of tests started=50664 (+0)
LT 05:43:37.274 - **POSSIBLE HANG DETECTED**
LT 05:43:42.283 - **POSSIBLE HANG DETECTED**
LT 05:43:47.336 - **POSSIBLE HANG DETECTED**
LT 05:43:52.342 - **POSSIBLE HANG DETECTED**
LT 05:43:52.843 - Completed 100.0%. Number of tests started=50664 (+0)
LT 05:43:57.348 - **POSSIBLE HANG DETECTED**
LT 05:44:02.357 - **POSSIBLE HANG DETECTED**
LT 05:44:07.361 - **POSSIBLE HANG DETECTED**
LT 05:44:12.369 - **POSSIBLE HANG DETECTED**
LT 05:44:13.263 - Completed 100.0%. Number of tests started=50664 (+0)
LT 05:44:17.468 - **POSSIBLE HANG DETECTED**
LT 05:44:22.473 - **POSSIBLE HANG DETECTED**
LT 05:44:27.478 - **POSSIBLE HANG DETECTED**
LT 05:44:32.482 - **POSSIBLE HANG DETECTED**
LT 05:44:32.884 - Completed 100.0%. Number of tests started=50664 (+0)
LT 05:44:37.489 - **POSSIBLE HANG DETECTED**
LT 05:44:42.493 - **POSSIBLE HANG DETECTED**
LT 05:44:47.509 - **POSSIBLE HANG DETECTED**
LT 05:44:52.557 - **POSSIBLE HANG DETECTED**
LT 05:44:52.859 - Completed 100.0%. Number of tests started=50664 (+0)
LT 05:44:57.564 - **POSSIBLE HANG DETECTED**
Many threads are waiting on load-7.
2LKMONINUSE sys_mon_t:0x00003FFEEC403898 infl_mon_t: 0x00003FFEEC403918:
3LKMONOBJECT net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x0000000084283B40: <unowned>
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "load-7" (J9VMThread:0x0000000000548300)
3XMTHREADINFO "load-7" J9VMThread:0x0000000000548300, omrthread_t:0x00003FFFAC55E428, java/lang/Thread:0x0000000080E8DD58, state:CW, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0x29, isDaemon:false)
3XMTHREADINFO1 (native thread ID:0x1CA1, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000181)
3XMTHREADINFO2 (native stack address range from:0x00003FFF8EFC0000, to:0x00003FFF8F000000, size:0x40000)
3XMCPUTIME CPU usage total: 37.721936262 secs, current category="Application"
3XMTHREADBLOCK Waiting on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x0000000084283B40 Owned by: <unowned>
3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0)
1INTERNAL Unable to obtain lock context information
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at java/lang/Object.wait(Native Method)
4XESTACKTRACE at java/lang/Object.wait(Object.java:221(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ForkJoinTask.externalAwaitDone(ForkJoinTask.java:335)
4XESTACKTRACE at java/util/concurrent/ForkJoinTask.doJoin(ForkJoinTask.java:403(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ForkJoinTask.join(ForkJoinTask.java:726)
4XESTACKTRACE at java/util/concurrent/ForkJoinPool.invoke(ForkJoinPool.java:2432)
4XESTACKTRACE at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTestAPI.testAPI(ForkJoinPoolTestAPI.java:233)
3XMTHREADINFO "ForkJoinPool-4-worker-1" J9VMThread:0x0000000000979500, omrthread_t:0x00003FFEC8101968, java/lang/Thread:0x0000000082F9E660, state:CW, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0x10C, isDaemon:true)
3XMTHREADINFO1 (native thread ID:0x1D88, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000481)
3XMTHREADINFO2 (native stack address range from:0x00003FFED16F0000, to:0x00003FFED1730000, size:0x40000)
3XMCPUTIME CPU usage total: 0.040613120 secs, current category="Application"
3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at java/lang/Thread.sleep(Native Method)
4XESTACKTRACE at java/lang/Thread.sleep(Thread.java:983(Compiled Code))
4XESTACKTRACE at net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask.exec(WaiterTask.java:74)
4XESTACKTRACE at java/util/concurrent/ForkJoinTask.doExec(ForkJoinTask.java:295(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1016(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ForkJoinPool.scan(ForkJoinPool.java:1665(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ForkJoinPool.runWorker(ForkJoinPool.java:1598)
4XESTACKTRACE at java/util/concurrent/ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)
Possibly related to https://github.com/eclipse/openj9/issues/9999 and https://github.com/eclipse/openj9/issues/11836
https://ci.eclipse.org/openj9/job/Test_openjdk11_j9_extended.system_ppc64le_linux_Nightly_testList_0/62 ConcurrentLoadTest_5m_0 variation: Mode150 JVM_OPTIONS: -XX:+UseCompressedOops
https://140-211-168-230-openstack.osuosl.org/artifactory/ci-eclipse-openj9/Test/Test_openjdk11_j9_extended.system_ppc64le_linux_Nightly_testList_0/62/system_test_output.tar.gz
2LKMONINUSE sys_mon_t:0x00003FFECC008548 infl_mon_t: 0x00003FFECC0085C8:
3LKMONOBJECT net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x0000000080DEF8E0: <unowned>
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "load-5" (J9VMThread:0x0000000000509200)
https://ci.eclipse.org/openj9/job/Test_openjdk16_j9_extended.system_x86-64_mac_Nightly_testList_1/35 MiniMix_5m_1 variation: Mode650 JVM_OPTIONS: -XX:-UseCompressedOops
https://140-211-168-230-openstack.osuosl.org/artifactory/ci-eclipse-openj9/Test/Test_openjdk16_j9_extended.system_x86-64_mac_Nightly_testList_1/35/system_test_output.tar.gz
2LKMONINUSE sys_mon_t:0x00007F87090848A8 infl_mon_t: 0x00007F8709084928:
3LKMONOBJECT net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x00000000320B0DA0: <unowned>
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "load-2" (J9VMThread:0x0000000014E2F800)
https://ci.eclipse.org/openj9/job/Test_openjdk8_j9_extended.system_x86-64_linux_Nightly_testList_1/84 ConcurrentLoadTest_5m_0 variation: Mode150 JVM_OPTIONS: -XX:+UseCompressedOops
https://140-211-168-230-openstack.osuosl.org/artifactory/ci-eclipse-openj9/Test/Test_openjdk8_j9_extended.system_x86-64_linux_Nightly_testList_1/84/system_test_output.tar.gz
1LKMONPOOLDUMP Monitor Pool Dump (flat & inflated object-monitors):
2LKMONINUSE sys_mon_t:0x00007F578C020898 infl_mon_t: 0x00007F578C020918:
3LKMONOBJECT net/adoptopenjdk/test/concurrent/support/jsr166y/ArrayDoubler@0x0000000083501368: <unowned>
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "load-9" (J9VMThread:0x0000000000469E00)
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.system_x86-32_windows_Nightly/2 ConcurrentLoadTest_5m_2 variation: Mode1000 JVM_OPTIONS:
3 core files available. Probably the same as https://github.com/eclipse-openj9/openj9/issues/9999#issuecomment-763311479 https://140-211-168-230-openstack.osuosl.org/artifactory/ci-eclipse-openj9/Test/Test_openjdk8_j9_extended.system_x86-32_windows_Nightly_testList_2/2/system_test_output.tar.gz
LT 00:19:41.541 - Completed 100.0%. Number of tests started=1026 (+0)
LT 00:20:01.556 - Completed 100.0%. Number of tests started=1026 (+0)
LT 00:20:21.572 - Completed 100.0%. Number of tests started=1026 (+0)
LT 00:20:41.588 - Completed 100.0%. Number of tests started=1026 (+0)
STF 00:20:59.152 - Heartbeat: Process LT is still running
LT 00:21:01.619 - Completed 100.0%. Number of tests started=1026 (+0)
LT 00:21:21.634 - Completed 100.0%. Number of tests started=1026 (+0)
LT 00:21:41.541 - Completed 100.0%. Number of tests started=1026 (+0)
LT 00:21:51.603 - **POSSIBLE HANG DETECTED**
STF 00:21:51.746 - **FAILED** Process LT has hung
Also observed at JDK16 0.27 release build https://openj9-jenkins.osuosl.org/job/Test_openjdk16_j9_extended.system_ppc64le_linux_Release/6/tapResults/
===============================================
Running test ConcurrentLoadTest_5m_1 ...
===============================================
ConcurrentLoadTest_5m_1 Start Time: Thu Jul 22 12:20:33 2021 Epoch Time (ms): 1626970833293
variation: Mode650
JVM_OPTIONS: -XX:-UseCompressedOops
STF 12:43:27.437 - Redirecting stderr to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Release_testList_1/aqa-tests/TKG/output_16269664936518/ConcurrentLoadTest_5m_1/20210722-122033-ConcurrentLoadTest/results/1.LT.kill_24.stderr
STF 12:43:27.437 - Redirecting stdout to /home/jenkins/workspace/Test_openjdk16_j9_extended.system_ppc64le_linux_Release_testList_1/aqa-tests/TKG/output_16269664936518/ConcurrentLoadTest_5m_1/20210722-122033-ConcurrentLoadTest/results/1.LT.kill_24.stdout
LT 12:41:32.422 - **POSSIBLE HANG DETECTED**
LT 12:41:37.328 - Completed 100.0%. Number of tests started=1246 (+0)
LT 12:41:37.429 - **POSSIBLE HANG DETECTED**
STF 12:43:27.623 - ===================== R E S U L T S =====================
STF 12:43:27.623 - Stage results:
STF 12:43:27.623 - setUp: pass
STF 12:43:27.623 - execute: *fail*
STF 12:43:27.623 - teardown: pass
STF 12:43:27.623 -
STF 12:43:27.623 - Overall result: **FAILED**
ConcurrentLoadTest_5m_1_FAILED
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.system_x86-32_windows_Release_testList_0/7 ConcurrentLoadTest_5m_2 variation: Mode1000 JVM_OPTIONS:
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_extended.system_x86-32_windows_Release_testList_0/7/system_test_output.tar.gz
LT 18:08:31.740 - Completed 100.0%. Number of tests started=676 (+0)
STF 18:08:50.507 - Heartbeat: Process LT is still running
LT 18:08:51.756 - Completed 100.0%. Number of tests started=676 (+0)
LT 18:09:11.662 - Completed 100.0%. Number of tests started=676 (+0)
LT 18:09:15.928 - **POSSIBLE HANG DETECTED**
STF 18:09:16.289 - **FAILED** Process LT has hung
STF 18:09:16.289 - Collecting dumps for: LT
An occurrence at JDK17 Windows https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_x86-64_windows_Nightly/4/tapResults/
===============================================
Running test MiniMix_5m_0 ...
===============================================
MiniMix_5m_0 Start Time: Thu Aug 26 02:33:43 2021 Epoch Time (ms): 1629963223798
variation: Mode150
JVM_OPTIONS: -XX:+UseCompressedOops
openjdk version "17-internal" 2021-09-14
OpenJDK Runtime Environment (build 17-internal+0-adhoc.jenkins.buildjdk17x86-64windowsnightly)
Eclipse OpenJ9 VM (build master-4b629d2fc7f, JRE 17 Windows Server 2012 R2 amd64-64-Bit Compressed References 20210825_4 (JIT enabled, AOT enabled)
OpenJ9 - 4b629d2fc7f
OMR - 1d0a329
JCL - 72d25cf4859 based on jdk-17+35)
LT 02:37:47.079 - suite.isCreateDump() : false
LT 02:37:47.189 - Test failed
LT Failure num. = 1
LT Test number = 3718
LT Test details = 'JUnit[net.adoptopenjdk.test.concurrent.jsr166y.ForkJoinTaskTest]'
LT Suite number = 0
LT Thread number = 0
LT >>> Captured test output >>>
LT testStarted : testAPI(net.adoptopenjdk.test.concurrent.jsr166y.ForkJoinTaskTest)
LT testFailure: testAPI(net.adoptopenjdk.test.concurrent.jsr166y.ForkJoinTaskTest): 25 : getMySurplusQueuedTaskCount() expected:<1> but was:<-7>
LT junit.framework.AssertionFailedError: 25 : getMySurplusQueuedTaskCount() expected:<1> but was:<-7>
LT at junit.framework.Assert.fail(Assert.java:57)
LT at junit.framework.Assert.failNotEquals(Assert.java:329)
LT at junit.framework.Assert.assertEquals(Assert.java:78)
LT at junit.framework.Assert.assertEquals(Assert.java:234)
LT at junit.framework.TestCase.assertEquals(TestCase.java:401)
LT at net.adoptopenjdk.test.concurrent.jsr166y.ForkJoinTaskTest.testAPI(ForkJoinTaskTest.java:174)
LT at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
LT at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
LT at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
LT at java.base/java.lang.reflect.Method.invoke(Method.java:568)
LT at junit.framework.TestCase.runTest(TestCase.java:176)
LT at junit.framework.TestCase.runBare(TestCase.java:141)
LT at junit.framework.TestResult$1.protect(TestResult.java:122)
LT at junit.framework.TestResult.runProtected(TestResult.java:142)
LT at junit.framework.TestResult.run(TestResult.java:125)
LT at junit.framework.TestCase.run(TestCase.java:129)
LT at junit.framework.TestSuite.runTest(TestSuite.java:252)
LT at junit.framework.TestSuite.run(TestSuite.java:247)
LT at org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:86)
LT at org.junit.runners.Suite.runChild(Suite.java:128)
LT at org.junit.runners.Suite.runChild(Suite.java:27)
LT at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
LT at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
LT at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
LT at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
LT at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
LT at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
LT at org.junit.runner.JUnitCore.run(JUnitCore.java:137)
LT at org.junit.runner.JUnitCore.run(JUnitCore.java:115)
LT at net.adoptopenjdk.loadTest.adaptors.JUnitAdaptor.executeTest(JUnitAdaptor.java:130)
LT at net.adoptopenjdk.loadTest.LoadTestRunner$2.run(LoadTestRunner.java:182)
LT at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
LT at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
LT at java.base/java.lang.Thread.run(Thread.java:884)
LT testFinished: testAPI(net.adoptopenjdk.test.concurrent.jsr166y.ForkJoinTaskTest)
LT
LT JUnit Test Results for: net.adoptopenjdk.test.concurrent.jsr166y.ForkJoinTaskTest
LT Ran : 1
LT Passed : 0
LT Failed : 1
LT Ignored: 0
LT Result : FAILED
LT <<<
LT
LT 02:37:53.595 - Completed 80.3%. Number of tests started=38703 (+3027) (with 1 failure(s))
LT 02:38:13.517 - Completed 87.0%. Number of tests started=42734 (+4031) (with 1 failure(s))
LT 02:38:33.579 - Completed 93.7%. Number of tests started=45411 (+2677) (with 1 failure(s))
STF 02:38:50.456 - Heartbeat: Process LT is still running
LT 02:38:53.517 - Completed 100.0%. Number of tests started=48241 (+2830) (with 1 failure(s))
LT 02:38:53.610 - Thread completed. Suite=0 thread=7
LT 02:38:55.314 - Thread completed. Suite=0 thread=5
LT 02:38:55.517 - Thread completed. Suite=0 thread=0
LT 02:39:00.360 - Thread completed. Suite=0 thread=9
LT 02:39:01.767 - Thread completed. Suite=0 thread=6
LT 02:39:05.829 - Thread completed. Suite=0 thread=8
LT 02:39:13.548 - Completed 100.0%. Number of tests started=48241 (+0) (with 1 failure(s))
LT 02:39:17.376 - Thread completed. Suite=0 thread=3
LT 02:39:33.579 - Completed 100.0%. Number of tests started=48241 (+0) (with 1 failure(s))
LT 02:39:40.407 - Thread completed. Suite=0 thread=1
LT 02:39:53.595 - Completed 100.0%. Number of tests started=48241 (+0) (with 1 failure(s))
LT 02:54:33.517 - Completed 100.0%. Number of tests started=48241 (+0) (with 1 failure(s))
LT 02:54:40.517 - **POSSIBLE HANG DETECTED**
STF 02:54:40.753 - **FAILED** Process LT has hung
STF 02:54:40.753 - Collecting dumps for: LT
STF 02:55:42.520 - Pausing for 30 seconds
LT 02:54:48.486 - **POSSIBLE HANG DETECTED**
LT 02:54:53.517 - Completed 100.0%. Number of tests started=48241 (+0) (with 1 failure(s))
LT 02:54:53.517 - **POSSIBLE HANG DETECTED**
STF 02:56:13.223 - Overall result: **FAILED**
MiniMix_5m_0_FAILED
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_x86-64_mac_Nightly_testList_1/157 - osx1014-x86-2
ConcurrentLoadTest_5m_1 -XX:-UseCompressedOops
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_extended.system_x86-64_mac_Nightly_testList_1/157/system_test_output.tar.gz
STF 04:16:34.160 - Heartbeat: Process LT is still running
LT 04:16:36.066 - Completed 100.0%. Number of tests started=1159 (+0)
LT 04:16:56.110 - Completed 100.0%. Number of tests started=1159 (+0)
LT 04:17:16.085 - Completed 100.0%. Number of tests started=1159 (+0)
LT 04:17:17.707 - **POSSIBLE HANG DETECTED**
STF 04:17:18.002 - **FAILED** Process LT has hung
STF 04:17:18.002 - Collecting dumps for: LT
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_ppc64_aix_Nightly_testList_0/137 - p8-java1-ibm05
MiniMix_5m_1 -XX:-UseCompressedOops
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_extended.system_ppc64_aix_Nightly_testList_0/137/system_test_output.tar.gz
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_ppc64le_linux_Nightly_testList_2/207 - ub18-ppcle-1 MiniMix_5m_1
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_extended.system_ppc64le_linux_Nightly_testList_2/207/system_test_output.tar.gz
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_x86-64_mac_Nightly_testList_0/227 - osx1014-x86-3 ConcurrentLoadTest_5m_0
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_extended.system_x86-64_mac_Nightly_testList_0/227/system_test_output.tar.gz
https://openj9-jenkins.osuosl.org/job/Test_openjdk18_j9_extended.system_aarch64_mac_Release_testList_1/6/ - mac11-aarch64-2 ConcurrentLoadTest_5m_1
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk18_j9_extended.system_aarch64_mac_Release_testList_1/6/system_test_output.tar.gz
LT 03:00:39.026 - Completed 100.0%. Number of tests started=1292 (+66)
LT 03:00:39.356 - Thread completed. Suite=0 thread=10
STF 03:00:39.492 - **FAILED** Process LT has timed out
STF 03:00:39.492 - Collecting dumps for: LT
@knn-k fyi. This may be nothing different from the problem seen on other platforms as well.
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.system_x86-64_windows_Nightly_testList_2/252/ ConcurrentLoadTest_5m_1
https://openj9-jenkins.osuosl.org/job/Test_openjdk18_j9_special.system_s390x_linux_Personal_testList_2/5 MiniMix_3h_0
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk18_j9_special.system_s390x_linux_Personal_testList_2/5/system_test_output.tar.gz
LT 18:50:41.255 - Completed 100.0%. Number of tests started=1986033 (+0)
...
STF 19:04:59.342 - Heartbeat: Process LT is still running
LT 19:05:01.285 - Completed 100.0%. Number of tests started=1986033 (+0)
LT 19:05:21.304 - Completed 100.0%. Number of tests started=1986033 (+0)
LT 19:05:28.611 - **POSSIBLE HANG DETECTED**
2LKREGMON Thread public flags mutex lock (0x000003FF805CF958): <unowned>
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "load-2" (J9VMThread:0x0000000001277E00)
...
3XMTHREADINFO "load-2" J9VMThread:0x0000000001277E00, omrthread_t:0x000003FF80658A48, java/lang/Thread:0x00000000134C86B8, state:R, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0x19, isDaemon:false)
3XMJAVALTHRCCL jdk/internal/loader/ClassLoaders$AppClassLoader(0x000000000D76F960)
3XMTHREADINFO1 (native thread ID:0x35C725, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000001)
3XMTHREADINFO2 (native stack address range from:0x000003FF84E0A000, to:0x000003FF84E4A000, size:0x40000)
3XMCPUTIME CPU usage total: 6462.264335335 secs, current category="Application"
3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTestStress.testStress(ForkJoinPoolTestStress.java:131(Compiled Code))
4XESTACKTRACE at java/lang/invoke/LambdaForm$DMH/0x00000000f000f200.invokeVirtual(LambdaForm$DMH(Compiled Code))
4XESTACKTRACE at java/lang/invoke/LambdaForm$MH/0x00000000f41d5390.invoke(LambdaForm$MH(Compiled Code))
4XESTACKTRACE at java/lang/invoke/LambdaForm$MH/0x00000000802a70d0.invokeExact_MT(LambdaForm$MH(Compiled Code))
4XESTACKTRACE at jdk/internal/reflect/DirectMethodHandleAccessor.invokeImpl(DirectMethodHandleAccessor.java:154(Compiled Code))
4XESTACKTRACE at jdk/internal/reflect/DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104(Compiled Code))
4XESTACKTRACE at java/lang/reflect/Method.invoke(Method.java:577(Compiled Code))
4XESTACKTRACE at junit/framework/TestCase.runTest(TestCase.java:176(Compiled Code))
Not sure which monitors you're referring to, but a "livelock" scenario where all threads are waiting to be notified might result in this (monitors are unowned when being waiting upon).
https://openj9-jenkins.osuosl.org/job/Test_openjdk18_j9_extended.system_x86-64_windows_Nightly_testList_2/63 ConcurrentLoadTest_5m_1
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk18_j9_extended.system_x86-64_windows_Nightly_testList_2/63/system_test_output.tar.gz
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_aarch64_linux_Nightly_testList_2/170 MiniMix_5m_0
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_extended.system_aarch64_linux_Nightly_testList_2/170/system_test_output.tar.gz
job/Test_openjdk19_j9_special.system_x86-64_windows_testList_2/6/(win16x64rt3-6)
openjdk version "19-beta" 2022-09-20
IBM Semeru Runtime Open Edition 19+28-202207050540 (build 19-beta+28-202207050540)
Eclipse OpenJ9 VM 19+28-202207050540 (build master-0e480f25e, JRE 19 Windows Server 2016 amd64-64-Bit Compressed References 20220705_11 (JIT enabled, AOT enabled)
OpenJ9 - 0e480f25e
OMR - d018241d7
JCL - 28e60ccf5a based on jdk-19+28)
[2022-07-05T08:25:55.895Z] variation: Mode107-OSRG
[2022-07-05T08:25:56.413Z] JVM_OPTIONS: -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -Xjit:enableOSR,enableOSROnGuardFailure,count=1,disableAsyncCompilation
[2022-07-05T08:45:52.775Z] DLT 01:45:43.330 - Completed 100.0%. Number of tests started=88 (+0)
[2022-07-05T08:46:06.985Z] DLT 01:45:58.468 - **POSSIBLE HANG DETECTED**
[2022-07-05T08:46:06.985Z] STF 01:45:58.962 - **FAILED** Process DLT has hung
[2022-07-05T08:46:06.985Z] STF 01:45:58.962 - Collecting dumps for: DLT
[2022-07-05T08:47:40.271Z] STF 01:47:33.926 - Overall result: **FAILED**
[2022-07-05T08:47:40.271Z]
[2022-07-05T08:47:40.271Z] DaaLoadTest_daa1_special_5m_24_FAILED
https://openj9-jenkins.osuosl.org/job/Test_openjdk18_j9_extended.system_s390x_linux_Nightly_testList_1/113 MiniMix_5m_1
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk18_j9_extended.system_s390x_linux_Nightly_testList_1/113/system_test_output.tar.gz
STF 02:29:04.289 - Heartbeat: Process LT is still running
LT 02:29:08.267 - Completed 100.0%. Number of tests started=28500 (+0)
LT 02:29:28.337 - Completed 100.0%. Number of tests started=28500 (+0)
LT 02:29:36.847 - **POSSIBLE HANG DETECTED**
STF 02:29:36.914 - **FAILED** Process LT has hung
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_special.system_ppc64le_linux_Personal_testList_0/50 MiniMix_3h_0
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_special.system_ppc64le_linux_Personal_testList_0/50/system_test_output.tar.gz
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_ppc64_aix_Nightly_testList_0/322 ConcurrentLoadTest_5m_0
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_extended.system_ppc64_aix_Nightly_testList_0/322/system_test_output.tar.gz
LT 01:30:48.485 - Completed 100.0%. Number of tests started=383 (+0)
LT 01:30:53.102 - **POSSIBLE HANG DETECTED**
STF 01:30:53.303 - **FAILED** Process LT has hung
Load threads are waiting on
thread id: 126091643
registers:
cr = 0x0000000000000000 ctr = 0x0000000000000000 fpscr = 0x0000000000000000 gpr0 = 0x0000000000000000
gpr1 = 0x00000100250a23e0 gpr10 = 0x0000000000000000 gpr11 = 0x0000000000000000 gpr12 = 0x0000000000000000
gpr13 = 0x0000000000000000 gpr14 = 0x0000000000000000 gpr15 = 0x0000000000000000 gpr16 = 0x0000000000000000
gpr17 = 0x0000000000000000 gpr18 = 0x0000000000000000 gpr19 = 0x0000000000000000 gpr2 = 0x0000000000000000
gpr20 = 0x0000000000000000 gpr21 = 0x0000000000000000 gpr22 = 0x0000000000000000 gpr23 = 0x0000000000000000
gpr24 = 0x0000000000000000 gpr25 = 0x0000000000000000 gpr26 = 0x0000000000000000 gpr27 = 0x0000000000000000
gpr28 = 0x0000000000000000 gpr29 = 0x0000000000000000 gpr3 = 0x0000000000000000 gpr30 = 0x0000000000000000
gpr31 = 0x0000000000000000 gpr4 = 0x0000000000000000 gpr5 = 0x0000000000000000 gpr6 = 0x0000000000000000
gpr7 = 0x0000000000000000 gpr8 = 0x0000000000000000 gpr9 = 0x0000000000000000 iar = 0x0000000000000000
lr = 0x0000000000000000 msr = 0x0000000000000000 xer = 0x0000000000000000
native stack sections:
0x10010000000 to 0x10027c1a720 (length 0x17c1a720)
native stack frames:
properties:
current effective priority=0 current/last signal taken=0
processor on which I'm bound=0 processor usage=ffff0000
scheduling policy=52 suspend count=1
thread flags=8410404 thread state=5
type of thread wait=1 wait channel=0
associated Java thread:
name: load-4
Thread object: java/lang/Thread @ 0x620184840
Native info: !j9vmthread 0x3057d200 !stack 0x3057d200
Daemon: false
ID: 43 (0x2b)
Priority: 5
Thread.State: WAITING
JVMTI state: ALIVE WAITING WAITING_INDEFINITELY PARKED
parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x620620070 owner name: "<unknown>" owner id: <null>
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_special.system_s390x_linux_Personal_testList_0/85 MiniMix_3h_0
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_special.system_s390x_linux_Personal_testList_0/85/system_test_output.tar.gz
LT 00:21:32.586 - Completed 56.7%. Number of tests started=904747 (+0)
LT 00:21:35.396 - **POSSIBLE HANG DETECTED**
All the load threads are running net/adoptopenjdk/test/nio/NioApp.run()V
!monitors blocked
----------------
Object Monitors:
----------------
<!j9monitortablelistentry 0x3ffb40b2520>, "Default Monitor Table", itemCount=36
Object monitor for !j9object 0xdf85930
Inflated
!j9objectmonitor 0x1458888 !j9threadmonitor 0x3ff1c1b8ee8
Owner: !j9vmthread 0x1a52a00 "Thread-9771"
Blocking (Enter Waiter):
!j9vmthread 0x1a5a600 "Thread-9795"
!j9vmthread 0x264e300 "Thread-9835"
!j9vmthread 0x73def00 "Thread-9834"
!j9vmthread 0x2167800 "Thread-9955"
!j9vmthread 0x2867600 "Thread-9954"
!j9vmthread 0x1a54f00 "Thread-9958"
!j9vmthread 0x746c200 "Thread-9957"
!j9vmthread 0x7441d00 "Thread-9956"
!j9vmthread 0x7423400 "Thread-9960"
!j9vmthread 0x1a5db00 "Thread-9959"
!j9vmthread 0x2883100 "Thread-9963"
!j9vmthread 0x1aa9d00 "Thread-9962"
!j9vmthread 0x7422700 "Thread-9961"
!j9vmthread 0x390c700 "Thread-9837"
!j9vmthread 0x1a63100 "Thread-9838"
!j9vmthread 0x73eb900 "Thread-9842"
!j9vmthread 0x73dd700 "Thread-9839"
!j9vmthread 0x73ede00 "Thread-9843"
!j9vmthread 0x73e6e00 "Thread-9840"
!j9vmthread 0x73e9300 "Thread-9841"
!j9vmthread 0x2657900 "Thread-9793"
!j9vmthread 0x1d6de00 "Thread-9836"
!j9vmthread 0x1d38700 "Thread-9791"
!j9vmthread 0x1a53700 "Thread-9799"
!j9vmthread 0x1a4ec00 "Thread-9800"
!j9vmthread 0x265c400 "Thread-9798"
!j9vmthread 0x1df3d00 "Thread-9764"
!j9vmthread 0x73f9a00 "Thread-9870"
!j9vmthread 0x73f2a00 "Thread-9871"
!j9vmthread 0x7405600 "Thread-9865"
!j9vmthread 0x73f4f00 "Thread-9866"
!j9vmthread 0x73fe600 "Thread-9868"
!j9vmthread 0x1d5b100 "Thread-9864"
!j9vmthread 0x7403100 "Thread-9867"
!j9vmthread 0x740ed00 "Thread-9873"
!j9vmthread 0x740c700 "Thread-9872"
!j9vmthread 0x1d56f00 "Thread-9768"
!j9vmthread 0x7393600 "Thread-9869"
!j9vmthread 0x73cdb00 "Thread-9820"
!j9vmthread 0x7411200 "Thread-9889"
!j9vmthread 0x73db200 "Thread-9893"
!j9vmthread 0x7416b00 "Thread-9897"
!j9vmthread 0x7425a00 "Thread-9898"
!j9vmthread 0x73f7500 "Thread-9892"
!j9vmthread 0x740a200 "Thread-9890"
!j9vmthread 0x7415e00 "Thread-9896"
!j9vmthread 0x1d35c00 "Thread-9895"
!j9vmthread 0x7413800 "Thread-9894"
!j9vmthread 0x7400b00 "Thread-9891"
!j9vmthread 0x7436100 "Thread-9906"
!j9vmthread 0x7433c00 "Thread-9905"
!j9vmthread 0x7431600 "Thread-9904"
!j9vmthread 0x742cb00 "Thread-9902"
!j9vmthread 0x742f100 "Thread-9903"
!j9vmthread 0x743d200 "Thread-9909"
!j9vmthread 0x7428000 "Thread-9900"
!j9vmthread 0x7438700 "Thread-9907"
!j9vmthread 0x742a500 "Thread-9901"
!j9vmthread 0x73d2600 "Thread-9828"
!j9vmthread 0x743ac00 "Thread-9908"
!j9vmthread 0x743f800 "Thread-9911"
!j9vmthread 0x744c100 "Thread-9920"
!j9vmthread 0x7449b00 "Thread-9919"
!j9vmthread 0x2ae4600 "Thread-9913"
!j9vmthread 0x73a9100 "Thread-9915"
!j9vmthread 0x1dea700 "Thread-9914"
!j9vmthread 0x7442b00 "Thread-9916"
!j9vmthread 0x7418300 "Thread-9912"
!j9vmthread 0x7445000 "Thread-9917"
!j9vmthread 0x7447600 "Thread-9918"
!j9vmthread 0x1954d00 "Thread-9819"
!j9vmthread 0x2188700 "Thread-9824"
!j9vmthread 0x744e600 "Thread-9930"
!j9vmthread 0x7453200 "Thread-9928"
!j9vmthread 0x7455700 "Thread-9929"
!j9vmthread 0x7457d00 "Thread-9932"
!j9vmthread 0x7450c00 "Thread-9931"
!j9vmthread 0x745a200 "Thread-9933"
!j9vmthread 0x7461300 "Thread-9936"
!j9vmthread 0x745c800 "Thread-9934"
!j9vmthread 0x745ee00 "Thread-9935"
!j9vmthread 0x7463900 "Thread-9937"
!j9vmthread 0x1a5b500 "Thread-9796"
!j9vmthread 0x73ccd00 "Thread-9792"
!stack 0x01a52a00 !j9vmthread 0x01a52a00 !j9thread 0x3ff34a020f8 tid 0x364d90 (3558800) // (Thread-9771)
!stack 0x01a52a00
<1a52a00> !j9method 0x000000000192D708 sun/nio/ch/FileDispatcherImpl.force0(Ljava/io/FileDescriptor;Z)I
<1a52a00> !j9method 0x000000000192D4E8 sun/nio/ch/FileDispatcherImpl.force(Ljava/io/FileDescriptor;Z)I
<1a52a00> !j9method 0x00000000016DB740 sun/nio/ch/FileChannelImpl.force(Z)V
<1a52a00> !j9method 0x0000000002641228 net/adoptopenjdk/test/nio/AmendFile.AmendWithCommonFileChannel(Ljava/io/File;Ljava/nio/channels/FileChannel;IZ)V
<1a52a00> !j9method 0x0000000002640EE8 net/adoptopenjdk/test/nio/ThreadWork.run()V
<1a52a00> !j9method 0x0000000001495DB0 java/lang/Thread.run()V
!j9object 0xdf85930
!J9Object 0x000000000DF85930 {
struct J9Class* clazz = !j9class 0x147C100 // java/lang/Class
Object flags = 0x0000001A;
I lockword = 0x01458889 (offset = 0) (java/lang/Object) <hidden>
J vmRef = 0x0000000001919700 (offset = 4) (java/lang/Class)
Ljava/lang/ClassLoader; classLoader = !fj9object 0x140cf618 (offset = 12) (java/lang/Class)
Ljava/lang/Module; module = !fj9object 0x14445bf8 (offset = 16) (java/lang/Class)
Ljava/security/ProtectionDomain; protectionDomain = !fj9object 0xdf0edd0 (offset = 20) (java/lang/Class)
Ljava/lang/String; classNameString = !fj9object 0xdf85998 (offset = 24) (java/lang/Class)
Ljava/lang/String; cachedToString = !fj9object 0x0 (offset = 28) (java/lang/Class)
Ljava/lang/String; fileNameString = !fj9object 0x0 (offset = 32) (java/lang/Class)
Ljava/lang/String; packageNameString = !fj9object 0xdf0ef60 (offset = 36) (java/lang/Class)
Ljava/lang/Class$AnnotationVars; annotationVars = !fj9object 0x0 (offset = 40) (java/lang/Class)
Ljava/lang/ClassValue$ClassValueMap; classValueMap = !fj9object 0x0 (offset = 44) (java/lang/Class)
Ljava/lang/Class$EnumVars; enumVars = !fj9object 0x0 (offset = 48) (java/lang/Class)
Ljava/lang/J9VMInternals$ClassInitializationLock; initializationLock = !fj9object 0x0 (offset = 52) (java/lang/Class)
Ljava/lang/Object; methodHandleCache = !fj9object 0x0 (offset = 56) (java/lang/Class)
Ljava/lang/Class$ClassRepositoryHolder; classRepoHolder = !fj9object 0x0 (offset = 60) (java/lang/Class)
Ljava/lang/Class$AnnotationCache; annotationCache = !fj9object 0x0 (offset = 64) (java/lang/Class)
Ljava/lang/Class$MetadataCache; metadataCache = !fj9object 0x0 (offset = 68) (java/lang/Class)
[Ljava/lang/Class; cachedInterfaces = !fj9object 0x0 (offset = 72) (java/lang/Class)
Ljava/lang/Class; cachedDeclaringClass = !fj9object 0x0 (offset = 76) (java/lang/Class)
Ljava/lang/Class; cachedEnclosingClass = !fj9object 0x0 (offset = 80) (java/lang/Class)
Z cachedCheckInnerClassAttr = 0x00000000 (offset = 92) (java/lang/Class)
Ljava/lang/Class; nestHost = !fj9object 0x0 (offset = 84) (java/lang/Class)
Ljava/lang/Class$ReflectCache; reflectCache = !fj9object 0xdf91d80 (offset = 88) (java/lang/Class)
!j9objectmonitor 0x1458888
J9ObjectMonitor at 0x1458888 {
Fields for J9ObjectMonitor:
0x0: struct J9ThreadMonitor* monitor = !j9threadmonitor 0x000003FF1C1B8EE8
0x8: UDATA proDeflationCount = 0x0000000000003502 (13570)
0x10: UDATA antiDeflationCount = 0x00000000000026D7 (9943)
0x18: j9objectmonitor_t alternateLockword = !j9x 0x14588a0
0x20: U32 hash = 0xE26D2165 (3798802789)
}
!j9threadmonitor 0x3ff1c1b8ee8
J9ThreadMonitor at 0x3ff1c1b8ee8 {
Fields for J9ThreadMonitor:
0x0: U64 count = 0x0000000000000001 (1)
0x8: volatile struct J9Thread* owner = !j9thread 0x000003FF34A020F8
0x10: struct J9Thread* waiting = !j9thread 0x0000000000000000
0x18: U64 flags = 0x0000000001070000 (17235968)
0x20: U64 userData = 0x000000000DF85930 (234379568)
0x28: struct J9ThreadMonitorTracing* tracing = !j9threadmonitortracing 0x000003FF3C01F990
0x30: U8* name = !j9x 0x0000000000000000
0x38: U64 pinCount = 0x0000000000000054 (84)
0x40: U64 spinlockState = 0x0000000000000002 (2)
0x48: U64 spinCount1 = 0x0000000000000001 (1)
0x50: U64 spinCount2 = 0x0000000000000001 (1)
0x58: U64 spinCount3 = 0x0000000000000001 (1)
0x60: struct J9Thread* blocking = !j9thread 0x000003FF186B9EC8
0x68: U64 sampleCounter = 0x0000000000000203 (515)
0x70: const struct J9ThreadCustomSpinOptions* customSpinOptions = !j9threadcustomspinoptions 0x0000000000000000
0x78: volatile U64 spinThreads = 0x0000000000000000 (0)
0x80: pthread_mutex_t mutex = !pthread_mutex_t 0x000003FF1C1B8F68
0xa8: struct J9Thread* notifyAllWaiting = !j9thread 0x0000000000000000
}
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_x86-64_windows_Nightly_testList_2/415 - win2012-x86-3 MiniMix_5m_0
LT 23:51:06.441 - Completed 100.0%. Number of tests started=28838 (+0)
LT 23:51:26.457 - Completed 100.0%. Number of tests started=28838 (+0)
STF 23:51:42.380 - Heartbeat: Process LT is still running
LT 23:51:46.363 - Completed 100.0%. Number of tests started=28838 (+0)
LT 23:51:59.926 - **POSSIBLE HANG DETECTED**
No diagnostics.
[23:52:02] Dump 1 initiated: F:\Users\jenkins\workspace\Test_openjdk11_j9_extended.system_x86-64_windows_Nightly_testList_2\aqa-tests\TKG\output_16694403489031\MiniMix_5m_0\20221125-233137-MixedLoadTest\results\java.exe_221125_235202.dmp
[23:52:03] Dump 1 writing: Estimated dump file size is 1174 MB.
[23:53:34] Dump 1 error: Error writing dump file: 0x80070005
Access is denied. (0x80070005, -2147024891)
This one doesn't seem to be a hang, it's just running so slowly that it was detected as a hang. I don't know if it's running so slowly as a result of a JVM problem or machine problem. concurrent/jsr166y is running, many or all of the load threads are parked on load-4 which is sleeping. load-4 is sleeping in a loop waiting for other threads to complete.
https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_special.system_ppc64le_linux_Personal_testList_2/37
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk8_j9_special.system_ppc64le_linux_Personal_testList_2/37/system_test_output.tar.gz
LT 19:11:15.242 - Completed 21.3%. Number of tests started=272870 (+0)
LT 19:11:19.248 - **POSSIBLE HANG DETECTED**
LT 19:11:25.256 - **POSSIBLE HANG DETECTED**
LT 19:11:30.263 - **POSSIBLE HANG DETECTED**
LT 19:11:35.168 - Completed 21.5%. Number of tests started=272870 (+0)
LT 19:11:35.268 - **POSSIBLE HANG DETECTED**
LT 19:11:40.274 - **POSSIBLE HANG DETECTED**
LT 19:11:45.282 - **POSSIBLE HANG DETECTED**
LT 19:11:54.002 - **POSSIBLE HANG DETECTED**
LT 19:11:55.204 - Completed 21.7%. Number of tests started=272870 (+0)
LT 19:11:59.007 - **POSSIBLE HANG DETECTED**
LT 19:12:04.014 - **POSSIBLE HANG DETECTED**
LT 19:12:09.021 - **POSSIBLE HANG DETECTED**
LT 19:12:14.026 - **POSSIBLE HANG DETECTED**
LT 19:12:15.231 - Completed 21.9%. Number of tests started=272870 (+0)
LT 19:12:19.038 - **POSSIBLE HANG DETECTED**
LT 19:12:24.699 - **POSSIBLE HANG DETECTED**
LT 19:12:29.705 - **POSSIBLE HANG DETECTED**
LT 19:12:34.710 - **POSSIBLE HANG DETECTED**
LT 19:12:35.211 - Completed 22.0%. Number of tests started=272870 (+0)
LT 19:12:39.715 - **POSSIBLE HANG DETECTED**
LT 19:12:44.721 - **POSSIBLE HANG DETECTED**
LT 19:12:49.727 - **POSSIBLE HANG DETECTED**
LT 19:12:54.732 - **POSSIBLE HANG DETECTED**
LT 19:12:55.234 - Completed 22.2%. Number of tests started=272870 (+0)
LT 19:12:59.788 - **POSSIBLE HANG DETECTED**
3XMTHREADINFO "load-4" J9VMThread:0x0000000000512A00, omrthread_t:0x00003FFFB05B88F8, java/lang/Thread:0x00000000845F8FA8, state:CW, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0x27, isDaemon:false)
3XMJAVALTHRCCL sun/misc/Launcher$AppClassLoader(0x00000000809963D0)
3XMTHREADINFO1 (native thread ID:0x103B, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000400)
3XMTHREADINFO2 (native stack address range from:0x00003FFF9AE10000, to:0x00003FFF9AE90000, size:0x80000)
3XMCPUTIME CPU usage total: 175.569593744 secs, current category="Application"
3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at java/lang/Thread.sleepImpl(Native Method)
4XESTACKTRACE at java/lang/Thread.sleep(Thread.java:978(Compiled Code))
4XESTACKTRACE at java/lang/Thread.sleep(Thread.java:961(Compiled Code))
4XESTACKTRACE at net/adoptopenjdk/test/concurrent/ConcurrentTest.sleep(ConcurrentTest.java:118(Compiled Code))
4XESTACKTRACE at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTest.testAPI(ForkJoinPoolTest.java:139(Compiled Code))
Many threads are waiting as follows, all on ConditionObject@0x0000000083C406B0:
3XMTHREADINFO "pool-5-thread-18" J9VMThread:0x0000000000E4CD00, omrthread_t:0x00003FFEEC0DD7C8, java/lang/Thread:0x0000000083C44588, state:P, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0xFA, isDaemon:false)
3XMJAVALTHRCCL sun/misc/Launcher$AppClassLoader(0x00000000809963D0)
3XMTHREADINFO1 (native thread ID:0x110D, native priority:0x5, native policy:UNKNOWN, vmstate:P, vm thread flags:0x00020000)
3XMTHREADINFO2 (native stack address range from:0x00003FFECBB00000, to:0x00003FFECBB80000, size:0x80000)
3XMCPUTIME CPU usage total: 0.022620832 secs, current category="Application"
3XMTHREADBLOCK Parked on: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x0000000083C406B0 Owned by: <unknown>
3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at sun/misc/Unsafe.park(Native Method)
4XESTACKTRACE at java/util/concurrent/locks/LockSupport.park(LockSupport.java:175(Compiled Code))
4XESTACKTRACE at java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ArrayBlockingQueue.take(ArrayBlockingQueue.java:403(Compiled Code))
4XESTACKTRACE at sun/nio/ch/EPollPort$EventHandlerTask.run(EPollPort.java:262(Compiled Code))
4XESTACKTRACE at sun/nio/ch/AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_s390x_linux_Nightly_testList_0/366/ MiniMix_5m_1
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_extended.system_s390x_linux_Nightly_testList_0/366/system_test_output.tar.gz
LT 20:31:00.766 - Completed 100.0%. Number of tests started=40736 (+0)
LT 20:31:20.822 - Completed 100.0%. Number of tests started=40736 (+0)
LT 20:31:40.757 - Completed 100.0%. Number of tests started=40736 (+0)
STF 20:31:54.263 - Heartbeat: Process LT is still running
3XMTHREADINFO "load-0" J9VMThread:0x000003FF88209D00, omrthread_t:0x000003FF883A4EB8, java/lang/Thread:0x000003FF07140100, state:P, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0x17, isDaemon:false)
3XMJAVALTHRCCL jdk/internal/loader/ClassLoaders$AppClassLoader(0x000003FF06A863F0)
3XMTHREADINFO1 (native thread ID:0xE129, native priority:0x5, native policy:UNKNOWN, vmstate:P, vm thread flags:0x00020001)
3XMTHREADINFO2 (native stack address range from:0x000003FF8EAC0000, to:0x000003FF8EB00000, size:0x40000)
3XMCPUTIME CPU usage total: 32.380465936 secs, current category="Application"
3XMTHREADBLOCK Parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x000003FF0A8B5DE0 Owned by: <unknown>
3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at jdk/internal/misc/Unsafe.park(Native Method)
4XESTACKTRACE at java/util/concurrent/locks/LockSupport.park(LockSupport.java:341)
4XESTACKTRACE at java/util/concurrent/ForkJoinTask.awaitDone(ForkJoinTask.java:468(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ForkJoinTask.joinForPoolInvoke(ForkJoinTask.java:1040)
4XESTACKTRACE at java/util/concurrent/ForkJoinPool.invoke(ForkJoinPool.java:2639)
4XESTACKTRACE at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTest.testAPI(ForkJoinPoolTest.java:229)
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_extended.system_x86-64_windows_Nightly_testList_2/68 MiniMix_aot_5m_0
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk19_j9_extended.system_x86-64_windows_Nightly_testList_2/68/system_test_output.tar.gz
LT 01:07:16.060 - Completed 100.0%. Number of tests started=22908 (+0)
STF 01:07:32.452 - Heartbeat: Process LT is still running
LT 01:07:36.076 - Completed 100.0%. Number of tests started=22908 (+0)
LT 01:07:56.092 - Completed 100.0%. Number of tests started=22908 (+0)
LT 01:08:09.326 - **POSSIBLE HANG DETECTED**
STF 01:08:09.578 - **FAILED** Process LT has hung
load threads are all waiting on load-6
3XMTHREADINFO "load-6" J9VMThread:0x00000000005C5400, omrthread_t:0x00000056D5E07160, java/lang/Thread:0x000000008046F528, state:P, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0x19, isDaemon:false)
3XMJAVALTHRCCL jdk/internal/loader/ClassLoaders$AppClassLoader(0x00000000804125E0)
3XMTHREADINFO1 (native thread ID:0xE88, native priority:0x5, native policy:UNKNOWN, vmstate:P, vm thread flags:0x00020081)
3XMCPUTIME CPU usage total: 33.093750000 secs, user: 16.359375000 secs, system: 16.734375000 secs, current category="Application"
3XMTHREADBLOCK Parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x0000000083AC6A68 Owned by: <unknown>
3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at jdk/internal/misc/Unsafe.park(Native Method)
4XESTACKTRACE at java/util/concurrent/locks/LockSupport.park(LockSupport.java:371)
4XESTACKTRACE at java/util/concurrent/ForkJoinTask.awaitDone(ForkJoinTask.java:461(Compiled Code))
4XESTACKTRACE at java/util/concurrent/ForkJoinTask.join(ForkJoinTask.java:651)
4XESTACKTRACE at java/util/concurrent/ForkJoinPool.invoke(ForkJoinPool.java:2819)
4XESTACKTRACE at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTest.testAPI(ForkJoinPoolTest.java:229)
JDK17 internal build(macaarch64rt5)
java version "17.0.6" 2023-01-17
IBM Semeru Runtime Certified Edition 17.0.6+9 (build 17.0.6+9)
Eclipse OpenJ9 VM 17.0.6+9 (build master-a2475ea96, JRE 17 Mac OS X aarch64-64-Bit 20230117_192 (JIT enabled, AOT enabled)
OpenJ9 - a2475ea96
OMR - 7d8ea8b6b
JCL - 9a3078373f based on jdk-17.0.6+9)
[2023-01-01T13:15:37.532Z] variation: Mode104
[2023-01-01T13:15:37.532Z] JVM_OPTIONS: -Xgcpolicy:optthruput -Xjit:count=0,optlevel=hot,gcOnResolve,rtResolve -Xnocompressedrefs
[2023-01-01T13:55:13.593Z] STF 08:54:53.647 - Heartbeat: Process MLT is still running
[2023-01-01T13:55:13.593Z] MLT 08:54:53.672 - Completed 100.0%. Number of tests started=9691 (+901)
[2023-01-01T13:55:13.593Z] MLT 08:54:53.761 - **POSSIBLE HANG DETECTED**
[2023-01-01T13:55:13.593Z] MLT 08:54:53.792 - Thread completed. Suite=0 thread=0
[2023-01-01T13:55:13.593Z] MLT 08:54:53.800 - Thread completed. Suite=0 thread=5
[2023-01-01T13:55:13.593Z] MLT 08:54:53.807 - Thread completed. Suite=0 thread=1
[2023-01-01T13:55:13.593Z] MLT 08:54:53.826 - Thread completed. Suite=0 thread=6
[2023-01-01T13:55:13.593Z] MLT 08:54:53.832 - Thread completed. Suite=0 thread=2
[2023-01-01T13:55:13.593Z] MLT 08:54:53.850 - Thread completed. Suite=0 thread=4
[2023-01-01T13:55:13.593Z] MLT 08:54:53.857 - Thread completed. Suite=0 thread=3
[2023-01-01T13:55:13.593Z] MLT 08:54:53.866 - Completed 100.0%. Number of tests started=9691 (+0)
[2023-01-01T13:55:13.593Z] MLT 08:54:53.977 - Test stopped due to reaching runtime limit
[2023-01-01T13:55:13.593Z] MLT 08:54:53.977 - Load test completed
[2023-01-01T13:55:13.593Z] MLT 08:54:53.982 - Ran : 9691
[2023-01-01T13:55:13.593Z] MLT 08:54:53.982 - Passed : 9691
[2023-01-01T13:55:13.593Z] MLT 08:54:53.982 - Failed : 0
[2023-01-01T13:55:13.593Z] MLT 08:54:53.982 - Result : PASSED
[2023-01-01T13:55:13.593Z] STF 08:54:54.151 - **FAILED** Process MLT has hung
[2023-01-01T13:55:25.589Z] STF 08:55:24.320 - Overall result: **FAILED**
[2023-01-01T13:55:25.589Z] -----------------------------------
[2023-01-01T13:55:25.589Z] MathLoadTest_bigdecimal_special_5m_2_FAILED
https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_ppc64le_linux_Release_testList_1/44 ConcurrentLoadTest_5m_1
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_extended.system_ppc64le_linux_Release_testList_1/44/system_test_output.tar.gz
LT 21:51:12.531 - Completed 100.0%. Number of tests started=1145 (+0)
LT 21:51:28.454 - **POSSIBLE HANG DETECTED**
STF 21:51:28.683 - **FAILED** Process LT has hung
2LKMONINUSE sys_mon_t:0x00003FFDD40187F8 infl_mon_t: 0x00003FFDD4018878:
3LKMONOBJECT net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x00003FFF204506A0: <unowned>
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "load-14" (J9VMThread:0x00003FFFA0A3DB00)
3XMTHREADINFO "ForkJoinPool-3-worker-1" J9VMThread:0x00003FFE54028000, omrthread_t:0x00003FFE5401FF88, java/lang/Thread:0x00003FFF1FEBAB00, state:CW, prio=5
3XMJAVALTHREAD (java/lang/Thread getId:0x4C, isDaemon:true)
3XMJAVALTHRCCL jdk/internal/loader/ClassLoaders$AppClassLoader(0x00003FFF1F5A06F0)
3XMTHREADINFO1 (native thread ID:0x10A6, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000481)
3XMTHREADINFO2 (native stack address range from:0x00003FFE6BD70000, to:0x00003FFE6BDF0000, size:0x80000)
3XMCPUTIME CPU usage total: 0.045549456 secs, current category="Application"
3XMHEAPALLOC Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3 Java callstack:
4XESTACKTRACE at java/lang/Thread.sleepImpl(Native Method)
4XESTACKTRACE at java/lang/Thread.sleep(Thread.java:991(Compiled Code))
4XESTACKTRACE at java/lang/Thread.sleep(Thread.java:974(Compiled Code))
4XESTACKTRACE at net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask.exec(WaiterTask.java:74)
https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_ppc64_aix_Nightly_testList_0/418 MiniMix_5m_1
https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_extended.system_ppc64_aix_Nightly_testList_0/418/system_test_output.tar.gz
LT 02:30:20.717 - Completed 100.0%. Number of tests started=39182 (+0)
LT 02:30:23.927 - **POSSIBLE HANG DETECTED**
STF 02:30:24.229 - **FAILED** Process LT has hung
Load threads are
parked on: java/util/concurrent/locks/ReentrantReadWriteLock$NonfairSync@0xa00000000a24908 owner name: "load-13" owner id: 91227069
load-13 is
parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0xa000000047601b8 owner name: "<unknown>" owner id: <null>
Java stack frames:
bp: 0x00000100264fdb90 method: void jdk/internal/misc/Unsafe.park(boolean, long) (Native Method)
objects: <no objects in this frame>
bp: 0x0000000000000000 method: void java/util/concurrent/locks/LockSupport.park() source: LockSupport.java:341
objects: <no objects in this frame>
bp: 0x00000100264fdde0 method: int java/util/concurrent/ForkJoinTask.awaitDone(java.util.concurrent.ForkJoinPool, boolean, boolean, boolean, long) source: ForkJoinTask.java:468
objects: 0xa000000008e70f8 0xa000000047601b8 0xa00000004773f70 0xa000000008e70f8 0xa000000047601b8 0xa00000004773f70
bp: 0x00000100264fde10 method: Object java/util/concurrent/ForkJoinTask.joinForPoolInvoke(java.util.concurrent.ForkJoinPool) source: ForkJoinTask.java:1040
objects: 0xa000000047601b8
bp: 0x00000100264fde38 method: Object java/util/concurrent/ForkJoinPool.invoke(java.util.concurrent.ForkJoinTask) source: ForkJoinPool.java:2639
objects: <no objects in this frame>
bp: 0x00000100264fde78 method: void net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTest.testAPI() source: ForkJoinPoolTest.java:229
objects: 0xa00000004588af0 0xa00000004773f98 0xa000000047601b8
bp: 0x00000100264fde30 method: Object jdk/internal/reflect/NativeMethodAccessorImpl.invoke0(reflect.Method, Object, Object[]) (Native Method)
objects: <no objects in this frame>
bp: 0x0000000000000000 method: Object jdk/internal/reflect/NativeMethodAccessorImpl.invoke(Object, Object[]) source: NativeMethodAccessorImpl.java:77
objects: <no objects in this frame>
bp: 0x0000000000000000 method: Object jdk/internal/reflect/DelegatingMethodAccessorImpl.invoke(Object, Object[]) source: DelegatingMethodAccessorImpl.java:43
objects: <no objects in this frame>
bp: 0x0000000000000000 method: Object java/lang/reflect/Method.invoke(Object, Object[]) source: Method.java:568
objects: <no objects in this frame>
bp: 0x0000000000000000 method: void junit/framework/TestCase.runTest() source: TestCase.java:176
objects: <no objects in this frame>