Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

JDK17 head ppc64le_linux java/util/logging/TestLoggerBundleSync.java - RuntimeException: Found 3 deadlocked threads #13778

Open
JasonFengJ9 opened this issue Oct 26, 2021 · 8 comments

Comments

@JasonFengJ9
Copy link
Member

JasonFengJ9 commented Oct 26, 2021

Failure link

From an internal build job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux/73/ (rhel8le-rt1-4):

00:54:41  openjdk version "17.0.1-beta" 2021-10-19
00:54:41  IBM Semeru Runtime Open Edition 17.0.1+12-202110260407 (build 17.0.1-beta+12-202110260407)
00:54:41  Eclipse OpenJ9 VM 17.0.1+12-202110260407 (build master-1e9433685, JRE 17 Linux ppc64le-64-Bit Compressed References 20211026_23 (JIT enabled, AOT enabled)
00:54:41  OpenJ9   - 1e9433685
00:54:41  OMR      - a6235250b
00:54:41  JCL      - 2475fcb8f4 based on jdk-17.0.1+12)

Rerun in Grinder - Change TARGET to run only the failed test targets.

Optional info

Failure output (captured from console output)

[2021-10-26T06:47:13.156Z] Running test jdk_util_0 ...
[2021-10-26T06:47:13.156Z] ===============================================
[2021-10-26T06:47:13.156Z] jdk_util_0 Start Time: Mon Oct 25 23:47:12 2021 Epoch Time (ms): 1635230832242
[2021-10-26T06:47:13.156Z] "/home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:destroyAll; "/home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux/openjdkbinary/j2sdk-image/bin/java" -Xshareclasses:groupAccess,destroyAll; echo "cache cleanup done";
[2021-10-26T06:47:13.156Z] JVMSHRC005I No shared class caches available
[2021-10-26T06:47:13.156Z] JVMSHRC005I No shared class caches available
[2021-10-26T06:47:13.156Z] cache cleanup done
[2021-10-26T06:47:13.156Z] variation: -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache Mode150
[2021-10-26T06:47:13.156Z] JVM_OPTIONS:  -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:+UseCompressedOops 

[2021-10-26T06:58:20.505Z] --------------------------------------------------
[2021-10-26T06:58:20.505Z] TEST: java/util/logging/TestLoggerBundleSync.java

[2021-10-26T06:58:20.507Z] java.lang.RuntimeException: Found 3 deadlocked threads
[2021-10-26T06:58:20.507Z] 	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)
[2021-10-26T06:58:20.507Z] java.lang.RuntimeException: Found 3 deadlocked threads
[2021-10-26T06:58:20.507Z] 	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)
[2021-10-26T06:58:20.507Z] 
[2021-10-26T06:58:20.507Z] JavaTest Message: Test threw exception: java.lang.RuntimeException: Found 3 deadlocked threads
[2021-10-26T06:58:20.507Z] JavaTest Message: shutting down test
[2021-10-26T06:58:20.507Z] 
[2021-10-26T06:58:20.507Z] STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Found 3 deadlocked threads

[2021-10-26T06:58:20.508Z] TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Found 3 deadlocked threads
[2021-10-26T06:58:20.508Z] --------------------------------------------------
[2021-10-26T07:27:16.403Z] Test results: passed: 883; failed: 1
[2021-10-26T07:27:26.997Z] Report written to /home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux/jvmtest/openjdk/report/html/report.html
[2021-10-26T07:27:26.997Z] Results written to /home/jenkins/workspace/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux/aqa-tests/TKG/output_16352242455790/jdk_util_0/work
[2021-10-26T07:27:26.997Z] Error: Some tests failed or other problems occurred.
[2021-10-26T07:27:26.997Z] 
[2021-10-26T07:27:26.997Z] jdk_util_0_FAILED

Launched a 50x grinder at job/Grinder/19010/ (Edit : all passed).

@pshipton
Copy link
Member

https://openj9-jenkins.osuosl.org/job/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/245
jdk_util_0 -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:+UseCompressedOops
java/util/logging/TestLoggerBundleSync.java

01:04:43  ACTION: main -- Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Found 4 deadlocked threads
01:04:43  REASON: User specified action: run main/othervm TestLoggerBundleSync 
01:04:43  TIME:   4.007 seconds
01:04:43  messages:
01:04:43  command: main TestLoggerBundleSync
01:04:43  reason: User specified action: run main/othervm TestLoggerBundleSync 
01:04:43  Mode: othervm [/othervm specified]
01:04:43  Additional options from @modules: --add-modules java.logging,java.management
01:04:43  elapsed time (seconds): 4.007
01:04:43  configuration:
01:04:43  Boot Layer
01:04:43    add modules: java.logging java.management
01:04:43  
01:04:43  STDOUT:
01:04:43  No security
01:04:43  3602 ms elapsed (4000 requested)
01:04:43  STDERR:
01:04:43  Mar 24, 2022 5:04:29 AM TestLoggerBundleSync$Stopper run
01:04:43  INFO: 3999ms remaining...
01:04:43  Mar 24, 2022 5:04:30 AM TestLoggerBundleSync$Stopper run
01:04:43  INFO: 2955ms remaining...
01:04:43  Mar 24, 2022 5:04:31 AM TestLoggerBundleSync$Stopper run
01:04:43  INFO: 1929ms remaining...
01:04:43  Mar 24, 2022 5:04:32 AM TestLoggerBundleSync$Stopper run
01:04:43  INFO: 918ms remaining...
01:04:43  Found 4 deadlocked threads: 
01:04:43  "Finalizer thread" prio=5 Id=14 RUNNABLE
01:04:43  
01:04:43  "Thread-4" prio=5 Id=29 BLOCKED on java.util.logging.LogManager$LoggerContext@3dcb5588 owned by "Thread-5" Id=31
01:04:43  
01:04:43  "Thread-5" prio=5 Id=31 RUNNABLE
01:04:43  
01:04:43  "Thread-6" prio=5 Id=32 BLOCKED on java.util.logging.LogManager$LoggerContext@3dcb5588 owned by "Thread-5" Id=31
01:04:43  
01:04:43  java.lang.RuntimeException: Found 4 deadlocked threads
01:04:43  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)
01:04:43  java.lang.RuntimeException: Found 4 deadlocked threads
01:04:43  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)
01:04:43  
01:04:43  JavaTest Message: Test threw exception: java.lang.RuntimeException: Found 4 deadlocked threads
01:04:43  JavaTest Message: shutting down test
01:04:43  
01:04:43  STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Found 4 deadlocked threads
01:04:43  rerun:
01:04:43  cd /home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16480956306895/jdk_util_0/work/scratch/0 && \
01:04:43  DISPLAY=:0 \
01:04:43  HOME=/home/jenkins \
01:04:43  LANG=en_US.UTF-8 \
01:04:43  PATH=/bin:/usr/bin:/usr/sbin \
01:04:43  CLASSPATH=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16480956306895/jdk_util_0/work/classes/1/java/util/logging/TestLoggerBundleSync.d:/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging:/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/jvmtest/openjdk/jtreg/lib/javatest.jar:/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/jvmtest/openjdk/jtreg/lib/jtreg.jar \
01:04:43      /home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/openjdkbinary/j2sdk-image/bin/java \
01:04:43          -Dtest.vm.opts='-ea -esa -Xmx1540m -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:+UseCompressedOops' \
01:04:43          -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx1540m -J-Xdump:system:none -J-Xdump:heap:none -J-Xdump:system:events=gpf+abort+traceassert+corruptcache -J-XX:+UseCompressedOops' \
01:04:43          -Dtest.compiler.opts= \
01:04:43          -Dtest.java.opts= \
01:04:43          -Dtest.jdk=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/openjdkbinary/j2sdk-image \
01:04:43          -Dcompile.jdk=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/openjdkbinary/j2sdk-image \
01:04:43          -Dtest.timeout.factor=8.0 \
01:04:43          -Dtest.nativepath=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/openjdkbinary/openjdk-test-image/jdk/jtreg/native \
01:04:43          -Dtest.root=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk \
01:04:43          -Dtest.name=java/util/logging/TestLoggerBundleSync.java \
01:04:43          -Dtest.file=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging/TestLoggerBundleSync.java \
01:04:43          -Dtest.src=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging \
01:04:43          -Dtest.src.path=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging \
01:04:43          -Dtest.classes=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16480956306895/jdk_util_0/work/classes/1/java/util/logging/TestLoggerBundleSync.d \
01:04:43          -Dtest.class.path=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16480956306895/jdk_util_0/work/classes/1/java/util/logging/TestLoggerBundleSync.d \
01:04:43          -Dtest.class.path.prefix=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16480956306895/jdk_util_0/work/classes/1/java/util/logging/TestLoggerBundleSync.d:/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/openjdk/openjdk-jdk/test/jdk/java/util/logging \
01:04:43          -Dtest.modules='java.logging java.management' \
01:04:43          --add-modules java.logging,java.management \
01:04:43          -ea \
01:04:43          -esa \
01:04:43          -Xmx1540m \
01:04:43          -Xdump:system:none \
01:04:43          -Xdump:heap:none \
01:04:43          -Xdump:system:events=gpf+abort+traceassert+corruptcache \
01:04:43          -XX:+UseCompressedOops \
01:04:43          -Djava.library.path=/home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/openjdkbinary/openjdk-test-image/jdk/jtreg/native \
01:04:43          com.sun.javatest.regtest.agent.MainWrapper /home/jenkins/jenkins-agent/workspace/Test_openjdk11_j9_sanity.openjdk_ppc64le_linux_Nightly/aqa-tests/TKG/output_16480956306895/jdk_util_0/work/java/util/logging/TestLoggerBundleSync.d/main.0.jta
01:04:43  
01:04:43  TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Found 4 deadlocked threads

@pshipton
Copy link
Member

pshipton commented May 5, 2022

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_ppc64le_linux_OpenJDK8/26
jdk_util_1 -Xdump:system:none -Xdump:heap:none -Xdump:system:events=gpf+abort+traceassert+corruptcache -XX:-UseCompressedOops
java/util/logging/TestLoggerBundleSync.java

07:06:17  ACTION: main -- Failed. Execution failed: `main' threw exception: java.lang.RuntimeException: Found 4 deadlocked threads
07:06:17  REASON: User specified action: run main/othervm TestLoggerBundleSync 
07:06:17  TIME:   1.52 seconds
07:06:17  messages:
07:06:17  command: main TestLoggerBundleSync
07:06:17  reason: User specified action: run main/othervm TestLoggerBundleSync 
07:06:17  Mode: othervm [/othervm specified]
07:06:17  elapsed time (seconds): 1.52
07:06:17  configuration:
07:06:17  STDOUT:
07:06:17  No security
07:06:17  1332 ms elapsed (4000 requested)
07:06:17  STDERR:
07:06:17  May 05, 2022 7:06:09 AM TestLoggerBundleSync$Stopper run
07:06:17  INFO: 4000ms remaining...
07:06:17  May 05, 2022 7:06:10 AM TestLoggerBundleSync$Stopper run
07:06:17  INFO: 2987ms remaining...
07:06:17  Found 4 deadlocked threads: 
07:06:17  "Finalizer thread" Id=44 RUNNABLE
07:06:17  
07:06:17  "Thread-4" Id=39 TIMED_WAITING
07:06:17  
07:06:17  "Thread-6" Id=41 TIMED_WAITING
07:06:17  
07:06:17  "Thread-7" Id=42 TIMED_WAITING
07:06:17  
07:06:17  java.lang.RuntimeException: Found 4 deadlocked threads
07:06:17  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:555)
07:06:17  java.lang.RuntimeException: Found 4 deadlocked threads
07:06:17  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:555)
07:06:17  
07:06:17  JavaTest Message: Test threw exception: java.lang.RuntimeException: Found 4 deadlocked threads
07:06:17  JavaTest Message: shutting down test
07:06:17  
07:06:17  STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Found 4 deadlocked threads

@pshipton
Copy link
Member

https://openj9-jenkins.osuosl.org/job/Test_openjdk21_j9_sanity.openjdk_ppc64le_linux_OMR_testList_0/34
jdk_util_1
java/util/logging/TestLoggerBundleSync.java

07:58:10  STDERR:
07:58:10  Feb 22, 2024 7:57:54 A.M. TestLoggerBundleSync$Stopper run
07:58:10  INFO: 3999ms remaining...
07:58:10  Found 5 deadlocked threads: 
07:58:10  "SetRB[MyBundle2]" prio=5 Id=37 RUNNABLE
07:58:10  
07:58:10  "SetRB[MyBundle3]" prio=5 Id=39 WAITING
07:58:10  
07:58:10  "Thread-1" prio=5 Id=41 BLOCKED on java.util.logging.LogManager$LoggerContext@c8cd2d58 owned by "SetRB[MyBundle2]" Id=37
07:58:10  
07:58:10  "Thread-2" prio=5 Id=43 BLOCKED on java.util.logging.LogManager$LoggerContext@c8cd2d58 owned by "SetRB[MyBundle2]" Id=37
07:58:10  
07:58:10  "Thread-3" prio=5 Id=44 BLOCKED on java.util.logging.LogManager$LoggerContext@c8cd2d58 owned by "SetRB[MyBundle2]" Id=37
07:58:10  
07:58:10  java.lang.RuntimeException: Found 5 deadlocked threads
07:58:10  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)
07:58:10  java.lang.RuntimeException: Found 5 deadlocked threads
07:58:10  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)

@pshipton
Copy link
Member

https://openj9-jenkins.osuosl.org/job/Test_openjdk23_j9_sanity.openjdk_ppc64le_linux_Nightly_testList_1/1

22:46:04  Found 2 deadlocked threads: 
22:46:04  "Finalizer thread" prio=5 Id=15 RUNNABLE
22:46:04  
22:46:04  "Thread-1" prio=5 Id=30 RUNNABLE
22:46:04  
22:46:04  java.lang.RuntimeException: Found 2 deadlocked threads
22:46:04  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)
22:46:04  java.lang.RuntimeException: Found 2 deadlocked threads
22:46:04  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)

@pshipton
Copy link
Member

https://openj9-jenkins.osuosl.org/job/Test_openjdk8_j9_sanity.openjdk_ppc64le_linux_OpenJDK8_testList_2/18

00:07:11  Sep 27, 2024 4:07:04 AM TestLoggerBundleSync$Stopper run
00:07:11  INFO: 3999ms remaining...
00:07:11  Sep 27, 2024 4:07:05 AM TestLoggerBundleSync$Stopper run
00:07:11  INFO: 2925ms remaining...
00:07:11  Found 3 deadlocked threads: 
00:07:11  "SetRB[MyBundle3]" Id=26 BLOCKED on java.util.logging.LogManager$LoggerWeakRef@f9f07e66 owned by "Finalizer thread" Id=34
00:07:11  
00:07:11  "Finalizer thread" Id=34 BLOCKED on java.lang.ref.ReferenceQueue@a4c41be5 owned by "SetRB[MyBundle3]" Id=26
00:07:11  
00:07:11  "Thread-4" Id=31 BLOCKED on java.lang.ref.ReferenceQueue@a4c41be5 owned by "SetRB[MyBundle3]" Id=26
00:07:11  
00:07:11  java.lang.RuntimeException: Found 3 deadlocked threads
00:07:11  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:555)
00:07:11  java.lang.RuntimeException: Found 3 deadlocked threads
00:07:11  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:555)

@pshipton
Copy link
Member

pshipton commented Dec 2, 2024

https://openj9-jenkins.osuosl.org/job/Test_openjdk17_j9_sanity.openjdk_ppc64le_linux_Nightly_testList_0/231

19:55:57  Found 2 deadlocked threads: 
19:55:57  "Finalizer thread" prio=5 Id=13 BLOCKED on java.lang.ref.ReferenceQueue@6c99128d owned by "Thread-6" Id=43
19:55:57  
19:55:57  "Thread-6" prio=5 Id=43 BLOCKED on java.util.logging.LogManager$LoggerWeakRef@b4295cee owned by "Finalizer thread" Id=13
19:55:57  
19:55:57  java.lang.RuntimeException: Found 2 deadlocked threads
19:55:57  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)
19:55:57  java.lang.RuntimeException: Found 2 deadlocked threads
19:55:57  	at TestLoggerBundleSync$DeadlockDetector.run(TestLoggerBundleSync.java:557)

@pshipton
Copy link
Member

pshipton commented Jan 20, 2025

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants