search

eclipse-openj9 / openj9

Eclipse OpenJ9: A Java Virtual Machine for OpenJDK that's optimized for small footprint, fast start-up, and high throughput. Builds on Eclipse OMR (https://github.com/eclipse/omr) and combines with the Extensions for OpenJDK for OpenJ9 repo.
Other
3.28k stars 720 forks source link

MiniMix, ConcurrentLoadTest hang, sometimes waiting on jsr166y/WaiterTask #11868

Open pshipton opened 3 years ago

pshipton commented 3 years ago

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

pshipton commented 3 years ago

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)
pshipton commented 3 years ago

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)
pshipton commented 3 years ago

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)
pshipton commented 3 years ago

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
JasonFengJ9 commented 3 years ago

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
pshipton commented 3 years ago

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
JasonFengJ9 commented 3 years ago

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
pshipton commented 2 years ago

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
pshipton commented 2 years ago

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

pshipton commented 2 years ago

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

pshipton commented 2 years ago

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

pshipton commented 2 years ago

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.

pshipton commented 2 years ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_extended.system_x86-64_windows_Nightly_testList_2/252/ ConcurrentLoadTest_5m_1

pshipton commented 2 years ago

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))
pshipton commented 2 years ago

@tajila @gacholio is it expected for all the monitors to be <unowned>?

gacholio commented 2 years ago

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).

pshipton commented 2 years ago

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

pshipton commented 2 years ago

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

JasonFengJ9 commented 2 years ago

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
pshipton commented 2 years ago

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
pshipton commented 2 years ago

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

pshipton commented 2 years ago

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>
pshipton commented 1 year ago

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
}
pshipton commented 1 year ago

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)
pshipton commented 1 year ago

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)
pshipton commented 1 year ago

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)
pshipton commented 1 year ago

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)
JasonFengJ9 commented 1 year ago

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
pshipton commented 1 year ago

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)
pshipton commented 1 year ago

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>
dmitripivkine commented 1 year ago

jdmpview couldn't print the java stack

FYI @pshipton jdmpview stack print is broken in latest builds. You might need to use older version. See https://github.com/eclipse-openj9/openj9/issues/16804

pshipton commented 1 year ago

I didn't try very hard since this is an old problem nobody is looking at. Actually my DDR was too old and giving java.lang.NoSuchFieldError: com/ibm/j9ddr/vm29/structure/J9Consts.J9_STACKWALK_INCLUDE_ARRAYLET_LEAVES but I didn't realize that because info thread doesn't provide that information. I updated and filled in the stack in the previous comment.

pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_x86-64_windows_Nightly_testList_0/439 ConcurrentLoadTest_5m_0

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_extended.system_x86-64_windows_Nightly_testList_0/439/system_test_output.tar.gz

LT  20:41:07.106 - Completed 100.0%. Number of tests started=1149 (+0)
LT  20:41:12.903 - **POSSIBLE HANG DETECTED**
STF 20:41:13.295 - **FAILED** Process LT  has hung
3XMTHREADINFO      "load-14" J9VMThread:0x00000000005AA000, omrthread_t:0x000000E59D2AEC10, java/lang/Thread:0x000000070044D680, state:P, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x21, isDaemon:false)
3XMJAVALTHRCCL            jdk/internal/loader/ClassLoaders$AppClassLoader(0x000000070006B9F8)
3XMTHREADINFO1            (native thread ID:0xD98, native priority:0x5, native policy:UNKNOWN, vmstate:P, vm thread flags:0x00020081)
3XMCPUTIME               CPU usage total: 50.250000000 secs, user: 17.484375000 secs, system: 32.765625000 secs, current category="Application"
3XMTHREADBLOCK     Parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x0000000700703DD0 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(Compiled Code))
4XESTACKTRACE                at java/util/concurrent/ForkJoinPool.invoke(ForkJoinPool.java:2639(Compiled Code))
4XESTACKTRACE                at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTest.testAPI(ForkJoinPoolTest.java:229(Compiled Code))
JasonFengJ9 commented 1 year ago

JDK19 aarch64_mac m2 build(macaarch64rt2)

openjdk version "19.0.2" 2023-01-17
IBM Semeru Runtime Open Edition 19.0.2.0-rc1 (build 19.0.2+7)
Eclipse OpenJ9 VM 19.0.2.0-rc1 (build v0.37.0-release-5db9c94a0, JRE 19 Mac OS X aarch64-64-Bit 20230117_84 (JIT enabled, AOT enabled)
OpenJ9   - 5db9c94a0
OMR      - d0b42675f
JCL      - a95c00a432d based on jdk-19.0.2+7)

[2023-04-11T20:16:08.119Z] variation: Mode650
[2023-04-11T20:16:08.119Z] JVM_OPTIONS:  -XX:-UseCompressedOops 

[2023-04-11T20:37:08.930Z] STF 16:37:07.023 - Monitoring Report Summary:
[2023-04-11T20:37:08.930Z] STF 16:37:07.023 -   o Process LT  has hung
[2023-04-11T20:37:08.930Z] STF 16:37:07.024 - Killing processes: LT 
[2023-04-11T20:37:08.930Z] STF 16:37:07.024 -   o Process LT  pid 45053 is not running
[2023-04-11T20:37:08.930Z] **FAILED** at step 1 (Run concurrency unit tests). Expected return value=0 Actual=1 at /Users/jenkins/workspace/Test_openjdk19_j9_extended.system_aarch64_mac_testList_0/aqa-tests/TKG/../TKG/output_16812441622948/ConcurrentLoadTest_5m_1/20230411-161608-ConcurrentLoadTest/execute.pl line 94.
[2023-04-11T20:37:08.930Z] STF 16:37:07.125 - **FAILED** execute script failed. Expected return value=0 Actual=1
[2023-04-11T20:37:08.930Z] ConcurrentLoadTest_5m_1_FAILED
JasonFengJ9 commented 1 year ago

JDK19 x86-64_windows m2 build(win11x86-rt3-1)

[2023-04-11T17:48:38.691Z] variation: Mode107-OSRG
[2023-04-11T17:48:39.122Z] JVM_OPTIONS:  -Xgcpolicy:optthruput -Xdebug -Xrunjdwp:transport=dt_socket,address=8888,server=y,onthrow=no.pkg.foo,launch=echo -

[2023-04-11T17:48:53.329Z] openjdk version "19.0.2" 2023-01-17
[2023-04-11T17:48:53.329Z] IBM Semeru Runtime Open Edition 19.0.2.0-rc1 (build 19.0.2+7)
[2023-04-11T17:48:53.329Z] Eclipse OpenJ9 VM 19.0.2.0-rc1 (build v0.37.0-release-5db9c94a0, JRE 19 Windows 11 amd64-64-Bit Compressed References 20230117_85 (JIT enabled, AOT enabled)
[2023-04-11T17:48:53.329Z] OpenJ9   - 5db9c94a0
[2023-04-11T17:48:53.329Z] OMR      - d0b42675f
[2023-04-11T17:48:53.329Z] JCL      - f3c7acc0b55 based on jdk-19.0.2+7)

[2023-04-11T18:08:18.077Z] DLT 11:07:56.951 - Completed 100.0%. Number of tests started=39 (+0)
[2023-04-11T18:08:18.077Z] DLT 11:07:56.951 - **POSSIBLE HANG DETECTED**
[2023-04-11T18:08:18.077Z] DLT 11:08:02.046 - **POSSIBLE HANG DETECTED**
[2023-04-11T18:08:18.077Z] DLT 11:08:07.083 - **POSSIBLE HANG DETECTED**

[2023-04-11T18:08:18.078Z] STF 11:08:12.930 - Overall result: **FAILED**
[2023-04-11T18:08:18.078Z] -----------------------------------
[2023-04-11T18:08:18.078Z] DaaLoadTest_daa1_special_5m_24_FAILED
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_s390x_linux_Release_testList_2/59 ConcurrentLoadTest_5m_1 -XX:-UseCompressedOops

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_extended.system_s390x_linux_Release_testList_2/59/system_test_output.tar.gz

LT  23:35:10.874 - Completed 100.0%. Number of tests started=833 (+0)
LT  23:35:14.073 - **POSSIBLE HANG DETECTED**
STF 23:35:14.184 - **FAILED** Process LT  has hung

Threads are waiting on load-4, which is parked on jsr166y/WaiterTask. 3XMTHREADBLOCK Parked on: java/util/concurrent/locks/ReentrantReadWriteLock$NonfairSync@0x000003FF1AFEEA38 Owned by: "load-4" (J9VMThread:0x000003FF9CAAAB00, java/lang/Thread:0x000003FF1AFD2F08)

3XMTHREADINFO      "load-4" J9VMThread:0x000003FF9CAAAB00, omrthread_t:0x000003FF9CAA8010, java/lang/Thread:0x000003FF1AFD2F08, state:P, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x1B, isDaemon:false)
3XMJAVALTHRCCL            jdk/internal/loader/ClassLoaders$AppClassLoader(0x000003FF1AA7A550)
3XMTHREADINFO1            (native thread ID:0xDE24, native priority:0x5, native policy:UNKNOWN, vmstate:P, vm thread flags:0x00020001)
3XMTHREADINFO2            (native stack address range from:0x000003FFA04C0000, to:0x000003FFA0500000, size:0x40000)
3XMCPUTIME               CPU usage total: 1.951352521 secs, current category="Application"
3XMTHREADBLOCK     Parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x000003FF1B2C9A80 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)
4XESTACKTRACE                at jdk/internal/reflect/NativeMethodAccessorImpl.invoke0(Native Method)
4XESTACKTRACE                at jdk/internal/reflect/NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
4XESTACKTRACE                at jdk/internal/reflect/DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
4XESTACKTRACE                at java/lang/reflect/Method.invoke(Method.java:568)
4XESTACKTRACE                at junit/framework/TestCase.runTest(TestCase.java:176)
4XESTACKTRACE                at junit/framework/TestCase.runBare(TestCase.java:141)
4XESTACKTRACE                at junit/framework/TestResult$1.protect(TestResult.java:122)
4XESTACKTRACE                at junit/framework/TestResult.runProtected(TestResult.java:142)
4XESTACKTRACE                at junit/framework/TestResult.run(TestResult.java:125)
4XESTACKTRACE                at junit/framework/TestCase.run(TestCase.java:129)
4XESTACKTRACE                at junit/framework/TestSuite.runTest(TestSuite.java:252)
4XESTACKTRACE                at junit/framework/TestSuite.run(TestSuite.java:247)
4XESTACKTRACE                at org/junit/internal/runners/JUnit38ClassRunner.run(JUnit38ClassRunner.java:86)
4XESTACKTRACE                at org/junit/runners/Suite.runChild(Suite.java:128)
4XESTACKTRACE                at org/junit/runners/Suite.runChild(Suite.java:27)
4XESTACKTRACE                at org/junit/runners/ParentRunner$3.run(ParentRunner.java:290)
4XESTACKTRACE                at org/junit/runners/ParentRunner$1.schedule(ParentRunner.java:71)
4XESTACKTRACE                at org/junit/runners/ParentRunner.runChildren(ParentRunner.java:288)
4XESTACKTRACE                at org/junit/runners/ParentRunner.access$000(ParentRunner.java:58(Compiled Code))
4XESTACKTRACE                at org/junit/runners/ParentRunner$2.evaluate(ParentRunner.java:268(Compiled Code))
4XESTACKTRACE                at org/junit/runners/ParentRunner.run(ParentRunner.java:363(Compiled Code))
4XESTACKTRACE                at org/junit/runner/JUnitCore.run(JUnitCore.java:137(Compiled Code))
4XESTACKTRACE                at org/junit/runner/JUnitCore.run(JUnitCore.java:115)
4XESTACKTRACE                at net/adoptopenjdk/loadTest/adaptors/JUnitAdaptor.executeTest(JUnitAdaptor.java:130(Compiled Code))
4XESTACKTRACE                at net/adoptopenjdk/loadTest/LoadTestRunner$2.run(LoadTestRunner.java:182)
4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
4XESTACKTRACE                at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
4XESTACKTRACE                at java/lang/Thread.run(Thread.java:857)
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk20_j9_extended.system_s390x_linux_Nightly_testList_0/28 ConcurrentLoadTest_5m_0

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk20_j9_extended.system_s390x_linux_Nightly_testList_0/28/system_test_output.tar.gz

LT  21:29:46.886 - Completed 100.0%. Number of tests started=588 (+0)
STF 21:30:01.275 - Heartbeat: Process LT  is still running
LT  21:30:06.839 - Completed 100.0%. Number of tests started=588 (+0)
LT  21:30:14.565 - **POSSIBLE HANG DETECTED**
STF 21:30:14.830 - **FAILED** Process LT  has hung

load threads are blocked on load-2

3XMTHREADINFO      "load-2" J9VMThread:0x00000000005F0900, omrthread_t:0x000003FF8C5102B8, java/lang/Thread:0x000000000E1BA0C0, state:P, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x1A, isDaemon:false)
3XMJAVALTHRCCL            jdk/internal/loader/ClassLoaders$AppClassLoader(0x000000000E146698)
3XMTHREADINFO1            (native thread ID:0x39C4, native priority:0x5, native policy:UNKNOWN, vmstate:P, vm thread flags:0x00020000)
3XMTHREADINFO2            (native stack address range from:0x000003FF85740000, to:0x000003FF85780000, size:0x40000)
3XMCPUTIME               CPU usage total: 0.361047875 secs, current category="Application"
3XMTHREADBLOCK     Parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x000000000E7B2298 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:2822)
4XESTACKTRACE                at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTest.testAPI(ForkJoinPoolTest.java:229)
4XESTACKTRACE                at java/lang/invoke/LambdaForm$DMH/0x00000000d801a060.invokeVirtual(LambdaForm$DMH)
4XESTACKTRACE                at java/lang/invoke/LambdaForm$MH/0x0000000000030cd0.invoke(LambdaForm$MH)
4XESTACKTRACE                at java/lang/invoke/LambdaForm$MH/0x000000008c221b20.invokeExact_MT(LambdaForm$MH)
4XESTACKTRACE                at jdk/internal/reflect/DirectMethodHandleAccessor.invokeImpl(DirectMethodHandleAccessor.java:154)
4XESTACKTRACE                at jdk/internal/reflect/DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
4XESTACKTRACE                at java/lang/reflect/Method.invoke(Method.java:578)
4XESTACKTRACE                at junit/framework/TestCase.runTest(TestCase.java:176)
4XESTACKTRACE                at junit/framework/TestCase.runBare(TestCase.java:141)
4XESTACKTRACE                at junit/framework/TestResult$1.protect(TestResult.java:122)
4XESTACKTRACE                at junit/framework/TestResult.runProtected(TestResult.java:142)
4XESTACKTRACE                at junit/framework/TestResult.run(TestResult.java:125)
4XESTACKTRACE                at junit/framework/TestCase.run(TestCase.java:129)
4XESTACKTRACE                at junit/framework/TestSuite.runTest(TestSuite.java:252)
4XESTACKTRACE                at junit/framework/TestSuite.run(TestSuite.java:247)
4XESTACKTRACE                at org/junit/internal/runners/JUnit38ClassRunner.run(JUnit38ClassRunner.java:86)
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_ppc64_aix_Nightly_testList_0/492/ ConcurrentLoadTest_5m_0

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_extended.system_ppc64_aix_Nightly_testList_0/492/

LT  00:44:23.731 - Completed 100.0%. Number of tests started=408 (+0)
LT  00:44:36.517 - **POSSIBLE HANG DETECTED**
STF 00:44:36.553 - **FAILED** Process LT  has hung

load threads are blocked on load-18

   properties:
    current effective priority=0     current/last signal taken=0
    processor on which I'm bound=0   processor usage=ffff0001
    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-18
    Thread object: java/lang/Thread @ 0x620181ff0
    Native info:   !j9vmthread 0x305bed00  !stack 0x305bed00
    Daemon:        false
    ID:            57 (0x39)
    Priority:      5
    Thread.State:  WAITING 
    JVMTI state:   ALIVE WAITING WAITING_INDEFINITELY PARKED 
      parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x62062f258 owner name: "<unknown>" owner id: <null>
    Java stack frames: 
     bp: 0x00000000305f9a38  method: void jdk/internal/misc/Unsafe.park(boolean, long)  (Native Method)
      objects: 0x62004aa30
     bp: 0x00000000305f9b08  method: void java/util/concurrent/locks/LockSupport.park()  source: LockSupport.java:341
      objects: <no objects in this frame>
     bp: 0x00000000305f9c80  method: int java/util/concurrent/ForkJoinTask.awaitDone(java.util.concurrent.ForkJoinPool, boolean, boolean, boolean, long)  source: ForkJoinTask.java:468
      objects: 0x6202a2258 0x62062f258 0x62062f8d0 0x6202a2640 0x620181ff0 0x62062f8d0 0x62062f258 0x6202a2258
     bp: 0x00000000305f9cb8  method: Object java/util/concurrent/ForkJoinTask.joinForPoolInvoke(java.util.concurrent.ForkJoinPool)  source: ForkJoinTask.java:1040
      objects: 0x62062f258
     bp: 0x00000000305f9ce0  method: Object java/util/concurrent/ForkJoinPool.invoke(java.util.concurrent.ForkJoinTask)  source: ForkJoinPool.java:2639
      objects: <no objects in this frame>
     bp: 0x00000000305f9d28  method: void net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTestAPI.testAPI()  source: ForkJoinPoolTestAPI.java:233
      objects: 0x6202e2f70 0x62062f8e8 0x62062f258
JasonFengJ9 commented 1 year ago

JDK11 aarch64_mac milestone 2(macaarch64rt2)

variation: Mode122
JVM_OPTIONS:  -Xgcpolicy:optavgpause -Xjit:count=0,optlevel=warm,gcOnResolve,rtResolve -Xnocompressedrefs 

openjdk version "11.0.20" 2023-07-18
IBM Semeru Runtime Open Edition 11.0.20.0-m2 (build 11.0.20+7)
Eclipse OpenJ9 VM 11.0.20.0-m2 (build v0.40.0-release-6eed0535c, JRE 11 Mac OS X aarch64-64-Bit 20230628_361 (JIT enabled, AOT enabled)
OpenJ9   - 6eed0535c
OMR      - e80bff83b
JCL      - 20e0e53157 based on jdk-11.0.20+7)

STF 20:02:20.439 - **FAILED** Process CLT has hung
STF 20:02:20.439 - Collecting dumps for: CLT
STF 20:02:20.440 - Sending SIG 3 to the java process to generate a javacore
STF 20:02:20.440 - Running command: kill -3 7382
STF 20:02:20.440 - Redirecting stderr to /Users/jenkins/workspace/Test_openjdk11_j9_special.system_aarch64_mac_testList_2/aqa-tests/TKG/output_16881605792317/ClassLoadingTest_special_5m_7/20230630-194204-ClassloadingLoadTest/results/1.CLT.kill_3.stderr
STF 20:02:20.440 - Redirecting stdout to /Users/jenkins/workspace/Test_openjdk11_j9_special.system_aarch64_mac_testList_2/aqa-tests/TKG/output_16881605792317/ClassLoadingTest_special_5m_7/20230630-194204-ClassloadingLoadTest/results/1.CLT.kill_3.stdout
STF 20:02:20.447 - Pausing for 30 seconds
STF 20:02:50.445 - Process CLT (pid 7382) is no longer running. Abandoning dump collection.
STF 20:02:50.446 - Monitoring Report Summary:
STF 20:02:50.446 -   o Process CLT has hung
STF 20:02:50.447 - Killing processes: CLT
STF 20:02:50.447 -   o Process CLT pid 7382 is not running
**FAILED** at step 1 (Run classloading tests). Expected return value=0 Actual=1 at /Users/jenkins/workspace/Test_openjdk11_j9_special.system_aarch64_mac_testList_2/aqa-tests/TKG/../TKG/output_16881605792317/ClassLoadingTest_special_5m_7/20230630-194204-ClassloadingLoadTest/execute.pl line 99.
STF 20:02:50.457 - **FAILED** execute script failed. Expected return value=0 Actual=1
STF 20:02:50.457 - 
STF 20:02:50.457 - ====================   T E A R D O W N   ====================
STF 20:02:50.457 - Running teardown: perl /Users/jenkins/workspace/Test_openjdk11_j9_special.system_aarch64_mac_testList_2/aqa-tests/TKG/../TKG/output_16881605792317/ClassLoadingTest_special_5m_7/20230630-194204-ClassloadingLoadTest/tearDown.pl
STF 20:02:50.518 - TEARDOWN stage completed
STF 20:02:50.527 - 
STF 20:02:50.527 - =====================   R E S U L T S   =====================
STF 20:02:50.527 - Stage results:
STF 20:02:50.527 -   setUp:     pass
STF 20:02:50.527 -   execute:  *fail*
STF 20:02:50.527 -   teardown:  pass
STF 20:02:50.527 - 
STF 20:02:50.527 - Overall result: **FAILED**
-----------------------------------
ClassLoadingTest_special_5m_7_FAILED
pshipton commented 1 year ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_special.system_ppc64le_linux_Personal_testList_0/101 MiniMix_3h_0

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_special.system_ppc64le_linux_Personal_testList_0/101/system_test_output.tar.gz

LT  12:50:43.769 - Completed 14.1%. Number of tests started=91841 (+0)
LT  12:50:47.673 - **POSSIBLE HANG DETECTED**
3XMTHREADINFO      "load-2" J9VMThread:0x00000000005B3700, omrthread_t:0x00007C9E0C5FAC00, java/lang/Thread:0x00000000829C5F80, state:CW, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x25, isDaemon:false)
3XMJAVALTHRCCL            jdk/internal/loader/ClassLoaders$AppClassLoader(0x0000000081BE0078)
3XMTHREADINFO1            (native thread ID:0x204450, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000100)
3XMTHREADINFO2            (native stack address range from:0x00007C9DEE400000, to:0x00007C9DEE480000, size:0x80000)
3XMCPUTIME               CPU usage total: 42.837876724 secs, current category="Application"
3XMTHREADBLOCK     Waiting on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x0000000082496A50 Owned by: <unowned>
pshipton commented 11 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_s390x_linux_Nightly_testList_2/609 ConcurrentLoadTest_5m_1

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk17_j9_extended.system_s390x_linux_Nightly_testList_2/609/system_test_output.tar.gz

LT  23:25:08.215 - Completed 100.0%. Number of tests started=646 (+0)
LT  23:25:28.258 - Completed 100.0%. Number of tests started=646 (+0)
LT  23:25:28.560 - **POSSIBLE HANG DETECTED**
STF 23:25:28.881 - **FAILED** Process LT  has hung

3XMTHREADINFO      "load-15" J9VMThread:0x000003FF90AFDC00, omrthread_t:0x000003FF90AEE430, java/lang/Thread:0x000003FF0CE34408, state:P, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x26, isDaemon:false)
3XMJAVALTHRCCL            jdk/internal/loader/ClassLoaders$AppClassLoader(0x000003FF0CBED2E0)
3XMTHREADINFO1            (native thread ID:0xF277, native priority:0x5, native policy:UNKNOWN, vmstate:P, vm thread flags:0x00020001)
3XMTHREADINFO2            (native stack address range from:0x000003FE92DBE000, to:0x000003FE92DFE000, size:0x40000)
3XMCPUTIME               CPU usage total: 2.949209754 secs, current category="Application"
3XMTHREADBLOCK     Parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x000003FF0D497620 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(Compiled Code))
4XESTACKTRACE                at java/util/concurrent/ForkJoinPool.invoke(ForkJoinPool.java:2639(Compiled Code))
4XESTACKTRACE                at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTest.testAPI(ForkJoinPoolTest.java:229(Compiled Code))
4XESTACKTRACE                at jdk/internal/reflect/NativeMethodAccessorImpl.invoke0(Native Method)
4XESTACKTRACE                at jdk/internal/reflect/NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
4XESTACKTRACE                at jdk/internal/reflect/DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
4XESTACKTRACE                at java/lang/reflect/Method.invoke(Method.java:574)
4XESTACKTRACE                at junit/framework/TestCase.runTest(TestCase.java:176)
pshipton commented 10 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_extended.system_s390x_linux_Nightly_testList_1/136 ConcurrentLoadTest_5m_0

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk21_j9_extended.system_s390x_linux_Nightly_testList_1/136/system_test_output.tar.gz

3XMTHREADINFO      "load-15" J9VMThread:0x0000000001CB4E00, omrthread_t:0x000003FF8456EBC0, java/lang/Thread:0x000000000E2788C8, state:P, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x27, isDaemon:false)
3XMJAVALTHRCCL            jdk/internal/loader/ClassLoaders$AppClassLoader(0x000000000DF47688)
3XMTHREADINFO1            (native thread ID:0x153B44, native priority:0x5, native policy:UNKNOWN, vmstate:P, vm thread flags:0x00020001)
3XMTHREADINFO2            (native stack address range from:0x000003FF621BF000, to:0x000003FF621FF000, size:0x40000)
3XMCPUTIME               CPU usage total: 17.615191016 secs, current category="Application"
3XMTHREADBLOCK     Parked on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x000000000E59F560 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:2822)
4XESTACKTRACE                at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTestAPI.testAPI(ForkJoinPoolTestAPI.java:233)
4XESTACKTRACE                at java/lang/invoke/LambdaForm$DMH/0x0000000008006a10.invokeVirtual(LambdaForm$DMH)
4XESTACKTRACE                at java/lang/invoke/LambdaForm$MH/0x000000000800a800.invoke(LambdaForm$MH)
4XESTACKTRACE                at java/lang/invoke/LambdaForm$MH/0x000000008423fdd0.invokeExact_MT(LambdaForm$MH(Compiled Code))
4XESTACKTRACE                at jdk/internal/reflect/DirectMethodHandleAccessor.invokeImpl(DirectMethodHandleAccessor.java:153)
4XESTACKTRACE                at jdk/internal/reflect/DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
4XESTACKTRACE                at java/lang/reflect/Method.invoke(Method.java:586)
4XESTACKTRACE                at junit/framework/TestCase.runTest(TestCase.java:176)
pshipton commented 9 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_s390x_linux_Nightly_testList_2/699/ MiniMix_aot_5m_0

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_extended.system_s390x_linux_Nightly_testList_2/699/system_test_output.tar.gz

2LKMONINUSE      sys_mon_t:0x000003FF34138B38 infl_mon_t: 0x000003FF34138BB8:
3LKMONOBJECT       net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x000000000F01D7F8: <unowned>
3LKNOTIFYQ            Waiting to be notified:
3LKWAITNOTIFY            "load-4" (J9VMThread:0x00000000015C4300)

3XMTHREADINFO      "load-4" J9VMThread:0x00000000015C4300, omrthread_t:0x000003FFA430EF00, java/lang/Thread:0x000000000DCAF140, state:CW, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x1A, isDaemon:false)
3XMJAVALTHRCCL            jdk/internal/loader/ClassLoaders$AppClassLoader(0x000000000DC00598)
3XMTHREADINFO1            (native thread ID:0x95C3D, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000101)
3XMTHREADINFO2            (native stack address range from:0x000003FFA8C40000, to:0x000003FFA8C80000, size:0x40000)
3XMCPUTIME               CPU usage total: 0.416256972 secs, current category="Application"
3XMTHREADBLOCK     Waiting on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x000000000F01D7F8 Owned by: <unowned>
3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at java/lang/Object.waitImpl(Native Method)
4XESTACKTRACE                at java/lang/Object.wait(Object.java:251)
4XESTACKTRACE                at java/lang/Object.wait(Object.java:219)
4XESTACKTRACE                at java/util/concurrent/ForkJoinTask.externalAwaitDone(ForkJoinTask.java:330)
4XESTACKTRACE                at java/util/concurrent/ForkJoinTask.doJoin(ForkJoinTask.java:398(Compiled Code))
4XESTACKTRACE                at java/util/concurrent/ForkJoinTask.join(ForkJoinTask.java:721)
4XESTACKTRACE                at java/util/concurrent/ForkJoinPool.invoke(ForkJoinPool.java:2423)
4XESTACKTRACE                at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTestAPI.testAPI(ForkJoinPoolTestAPI.java:233)
pshipton commented 9 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly_testList_2/675/ MiniMix_aot_5m_0

https://openj9-artifactory.osuosl.org/artifactory/ci-openj9/Test/Test_openjdk11_j9_extended.system_ppc64_aix_Nightly_testList_2/675/system_test_output.tar.gz

3XMTHREADINFO      "load-2" J9VMThread:0x000000003051A200, omrthread_t:0x000001002408B950, java/lang/Thread:0x000000008058E5D8, state:CW, prio=5
3XMJAVALTHREAD            (java/lang/Thread getId:0x28, isDaemon:false)
3XMJAVALTHRCCL            jdk/internal/loader/ClassLoaders$AppClassLoader(0x00000000803010F8)
3XMTHREADINFO1            (native thread ID:0x5C203C5, native priority:0x5, native policy:UNKNOWN, vmstate:CW, vm thread flags:0x00000181)
3XMTHREADINFO2            (native stack address range from:0x00000100241F0000, to:0x0000010024275888, size:0x85888)
3XMCPUTIME               CPU usage total: 0.289879000 secs, user: 0.283281000 secs, system: 0.006598000 secs, current category="Application"
3XMTHREADBLOCK     Waiting on: net/adoptopenjdk/test/concurrent/support/jsr166y/WaiterTask@0x0000000081C47638 Owned by: <unowned>
3XMHEAPALLOC             Heap bytes allocated since last GC cycle=0 (0x0)
3XMTHREADINFO3           Java callstack:
4XESTACKTRACE                at java/lang/Object.waitImpl(Native Method)
4XESTACKTRACE                at java/lang/Object.wait(Object.java:251)
4XESTACKTRACE                at java/lang/Object.wait(Object.java:219)
4XESTACKTRACE                at java/util/concurrent/ForkJoinTask.externalAwaitDone(ForkJoinTask.java:330)
4XESTACKTRACE                at java/util/concurrent/ForkJoinTask.doJoin(ForkJoinTask.java:398)
4XESTACKTRACE                at java/util/concurrent/ForkJoinTask.join(ForkJoinTask.java:721)
4XESTACKTRACE                at java/util/concurrent/ForkJoinPool.invoke(ForkJoinPool.java:2423)
4XESTACKTRACE                at net/adoptopenjdk/test/concurrent/jsr166y/ForkJoinPoolTest.testAPI(ForkJoinPoolTest.java:229)
pshipton commented 8 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_extended.system_ppc64_aix_Release_testList_0/83 MiniMix_5m_1

pshipton commented 6 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_x86-64_windows_Release_testList_0/98 ConcurrentLoadTest_5m_0

pshipton commented 6 months ago

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_x86-64_windows_Nightly_testList_0/707 MiniMix_5m_1

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_extended.system_s390x_linux_Nightly_testList_0/743 MiniMix_5m_0