jdk19 openjdk java/util/concurrent/tck/JSR166TestCase.java testAwaitUninterruptibly(ReentrantReadWriteLockTest): timed out waiting for thread to enter thread state WAITING #15465

pshipton · 2022-06-30T15:06:42Z

Failures in jdk-19+28 acceptance build.
https://openj9-jenkins.osuosl.org/job/Pipeline-OpenJDK19-Acceptance/6/

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_aarch64_linux_OpenJDK19/4
jdk_util_1
java/util/concurrent/tck/JSR166TestCase.java

15:45:23  ACTION: junit -- Failed. Execution failed: `main' threw exception: java.lang.Exception: JUnit test failure
15:45:23  REASON: User specified action: run junit/othervm/timeout=1000 -Djava.security.manager=allow JSR166TestCase 
15:45:23  TIME:   94.395 seconds
15:45:23  messages:
15:45:23  command: junit -Djava.security.manager=allow JSR166TestCase
15:45:23  reason: User specified action: run junit/othervm/timeout=1000 -Djava.security.manager=allow JSR166TestCase 
15:45:23  Mode: othervm [/othervm specified]
15:45:23  Additional options from @modules: --add-modules java.management
15:45:23  elapsed time (seconds): 94.395
15:45:23  configuration:
15:45:23  Boot Layer
15:45:23    add modules: java.management
15:45:23  
15:45:23  STDOUT:
15:45:23  STDERR:
15:45:23  JavaTest Message: JUnit Failure: testAwaitUninterruptibly(ReentrantReadWriteLockTest): timed out waiting for thread to enter thread state WAITING
15:45:23  junit.framework.AssertionFailedError: timed out waiting for thread to enter thread state WAITING
15:45:23  	at junit.framework.Assert.fail(Assert.java:57)
15:45:23  	at junit.framework.TestCase.fail(TestCase.java:223)
15:45:23  	at JSR166TestCase.assertThreadBlocks(JSR166TestCase.java:1221)
15:45:23  	at ReentrantReadWriteLockTest.testAwaitUninterruptibly(ReentrantReadWriteLockTest.java:1070)
15:45:23  	at ReentrantReadWriteLockTest.testAwaitUninterruptibly(ReentrantReadWriteLockTest.java:1037)

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_aarch64_mac_OpenJDK19/3
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_s390x_linux_OpenJDK19/4
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_OpenJDK19/4

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_OpenJDK19/4
jdk_util_0 & jdk_util_1

19:38:51  ACTION: junit -- Error. Program `/home/jenkins/workspace/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_OpenJDK19/openjdkbinary/j2sdk-image/bin/java' timed out (timeout set to 8000000ms, elapsed time including timeout handling was 10229994ms).
19:38:51  REASON: User specified action: run junit/othervm/timeout=1000 --add-opens java.base/java.util.concurrent=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED -Djsr166.testImplementationDetails=true JSR166TestCase 
19:38:51  TIME:   10230.013 seconds
19:38:51  messages:
19:38:51  command: junit --add-opens java.base/java.util.concurrent=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED -Djsr166.testImplementationDetails=true JSR166TestCase
19:38:51  reason: User specified action: run junit/othervm/timeout=1000 --add-opens java.base/java.util.concurrent=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED -Djsr166.testImplementationDetails=true JSR166TestCase 
19:38:51  Mode: othervm [/othervm specified]
19:38:51  Additional options from @modules: --add-modules java.management
19:38:51  Timeout information:
19:38:51  Running jcmd on process 13959668
19:38:51  Timeout refired 300 times
19:38:51  Error getting data from 13959668: Exception connecting to 13959668
19:38:51  Usage : jcmd <vmid> <arguments>
19:38:51  
19:38:51     -J : supply arguments to the Java VM running jcmd
19:38:51     -l : list JVM processes on the local machine
19:38:51     -h : print this help message
19:38:51  
19:38:51     <vmid> : Attach API VM ID as shown in jps or other Attach API-based tools
19:38:52  
19:38:52     arguments:
19:38:52        help : print the list of diagnostic commands
19:38:52        help <command> : print help for the specific command
19:38:52        <command> [command arguments] : command from the list returned by "help"
19:38:52  
19:38:52  list JVM processes on the local machine. Default behavior when no options are specified.
19:38:52  
19:38:52  NOTE: this utility might significantly affect the performance of the target JVM.
19:38:52      The available diagnostic commands are determined by
19:38:52      the target VM and may vary between VMs.

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_OpenJDK19/4
jdk_util_0 & jdk_util_1

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_windows_OpenJDK19/4

16:13:09  Looks like we're stuck running test: testAwaitUninterruptibly(ReentrantReadWriteLockTest)
16:13:09  ------ stacktrace dump start ------
16:13:09  "Thread-0" prio=5 Id=2 WAITING
16:13:09  	at java.base@19-internal/java.lang.Object.wait(Native Method)
16:13:09  	at java.base@19-internal/java.lang.Object.wait(Object.java:219)
16:13:09  	at java.base@19-internal/java.lang.Thread.join(Thread.java:2146)
16:13:09  	at java.base@19-internal/java.lang.Thread.join(Thread.java:2222)
16:13:09  	at app//com.sun.javatest.regtest.agent.MainWrapper.main(MainWrapper.java:74)
16:13:09  "JIT Compilation Thread-000" prio=10 Id=4 RUNNABLE
16:13:09  "JIT Compilation Thread-001 Suspended" prio=10 Id=5 RUNNABLE
16:13:09  "JIT Compilation Thread-002 Suspended" prio=10 Id=6 RUNNABLE
16:13:09  "JIT Compilation Thread-003 Suspended" prio=10 Id=7 RUNNABLE
16:13:09  "JIT Compilation Thread-004 Suspended" prio=10 Id=8 RUNNABLE
16:13:09  "JIT Compilation Thread-005 Suspended" prio=10 Id=9 RUNNABLE
16:13:09  "JIT Compilation Thread-006 Suspended" prio=10 Id=10 RUNNABLE
16:13:09  "JIT Diagnostic Compilation Thread-007 Suspended" prio=10 Id=11 RUNNABLE
16:13:09  "JIT-SamplerThread" prio=10 Id=12 RUNNABLE
16:13:09  "IProfiler" prio=5 Id=13 RUNNABLE
16:13:09  "Concurrent Mark Helper" prio=1 Id=14 RUNNABLE
16:13:09  "Finalizer thread" prio=5 Id=15 RUNNABLE
16:13:09  "GC Worker" prio=5 Id=16 RUNNABLE
16:13:09  "GC Worker" prio=5 Id=17 RUNNABLE
16:13:09  "GC Worker" prio=5 Id=18 RUNNABLE
16:13:09  "GC Worker" prio=5 Id=19 RUNNABLE
16:13:09  "GC Worker" prio=5 Id=20 RUNNABLE
16:13:09  "GC Worker" prio=5 Id=21 RUNNABLE
16:13:09  "GC Worker" prio=5 Id=22 RUNNABLE
16:13:09  "Attach API wait loop" prio=10 Id=25 RUNNABLE
16:13:09  	at java.base@19-internal/openj9.internal.tools.attach.target.IPC.waitSemaphore(Native Method)
16:13:09  	at java.base@19-internal/openj9.internal.tools.attach.target.CommonDirectory.waitSemaphore(CommonDirectory.java:264)
16:13:09  	at java.base@19-internal/openj9.internal.tools.attach.target.WaitLoop.waitForNotification(WaitLoop.java:66)
16:13:09  	at java.base@19-internal/openj9.internal.tools.attach.target.WaitLoop.run(WaitLoop.java:157)
16:13:09  "MainThread" prio=5 Id=27 RUNNABLE
16:13:09  	at java.base@19-internal/java.lang.Thread.sleepImpl(Native Method)
16:13:09  	at java.base@19-internal/java.lang.Thread.sleep0(Thread.java:477)
16:13:09  	at java.base@19-internal/java.lang.Thread.sleep(Thread.java:472)
16:13:09  	at app//JSR166TestCase.delay(JSR166TestCase.java:1032)
16:13:09  	at app//JSR166TestCase.assertThreadBlocks(JSR166TestCase.java:1211)
16:13:09  	at app//ReentrantReadWriteLockTest.testAwaitUninterruptibly(ReentrantReadWriteLockTest.java:1070)
16:13:09  	at app//ReentrantReadWriteLockTest.testAwaitUninterruptibly(ReentrantReadWriteLockTest.java:1037)
16:13:09  	at java.base@19-internal/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
16:13:09  	at java.base@19-internal/java.lang.reflect.Method.invoke(Method.java:578)
16:13:09  	at app//junit.framework.TestCase.runTest(TestCase.java:177)
16:13:09  	at app//JSR166TestCase.runTest(JSR166TestCase.java:382)
16:13:09  	at app//junit.framework.TestCase.runBare(TestCase.java:142)
16:13:09  	at app//JSR166TestCase.runBare(JSR166TestCase.java:373)
16:13:09  	at app//junit.framework.TestResult$1.protect(TestResult.java:122)
16:13:09  	at app//junit.framework.TestResult.runProtected(TestResult.java:142)
16:13:09  	at app//junit.framework.TestResult.run(TestResult.java:125)
16:13:09  	at app//junit.framework.TestCase.run(TestCase.java:130)
16:13:09  	at app//junit.framework.TestSuite.runTest(TestSuite.java:241)
16:13:09  	at app//junit.framework.TestSuite.run(TestSuite.java:236)
16:13:09  	at app//junit.framework.TestSuite.runTest(TestSuite.java:241)
16:13:09  	at app//junit.framework.TestSuite.run(TestSuite.java:236)
16:13:09  	at app//org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:90)
16:13:09  	at app//org.junit.runners.Suite.runChild(Suite.java:128)
16:13:09  	at app//org.junit.runners.Suite.runChild(Suite.java:27)
16:13:09  	at app//org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
16:13:09  	at app//org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:79)
16:13:09  	at app//org.junit.runners.ParentRunner.runChildren(ParentRunner.java:329)
16:13:09  	at app//org.junit.runners.ParentRunner.access$100(ParentRunner.java:66)
16:13:09  	at app//org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:293)
16:13:09  	at app//org.junit.runners.ParentRunner$3.evaluate(ParentRunner.java:306)
16:13:09  	at app//org.junit.runners.ParentRunner.run(ParentRunner.java:413)
16:13:09  	at app//org.junit.runner.JUnitCore.run(JUnitCore.java:137)
16:13:09  	at app//org.junit.runner.JUnitCore.run(JUnitCore.java:115)
16:13:09  	at app//org.junit.runner.JUnitCore.run(JUnitCore.java:105)
16:13:09  	at app//org.junit.runner.JUnitCore.runClasses(JUnitCore.java:62)
16:13:09  	at app//org.junit.runner.JUnitCore.runClasses(JUnitCore.java:49)
16:13:09  	at app//com.sun.javatest.regtest.agent.JUnitRunner.main(JUnitRunner.java:76)
16:13:09  	at app//com.sun.javatest.regtest.agent.JUnitRunner.main(JUnitRunner.java:43)
16:13:09  	at java.base@19-internal/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)
16:13:09  	at java.base@19-internal/java.lang.reflect.Method.invoke(Method.java:578)
16:13:09  	at app//com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127)
16:13:09  	at java.base@19-internal/java.lang.Thread.run(Thread.java:1573)
16:13:09  "ClassByNameCache Reaper" prio=5 Id=728 WAITING
16:13:09  	at java.base@19-internal/java.lang.Object.wait(Native Method)
16:13:09  	at java.base@19-internal/java.lang.Object.wait(Object.java:219)
16:13:09  	at java.base@19-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:137)
16:13:09  	at java.base@19-internal/java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:109)
16:13:09  	at java.base@19-internal/java.io.ClassByNameCache$Reaper.run(ClassByNameCache.java:232)
16:13:09  	at java.base@19-internal/java.lang.Thread.run(Thread.java:1573)
16:13:09  "Thread-504" prio=5 Id=1624 WAITING
16:13:09  	at java.base@19-internal/jdk.internal.misc.Unsafe.park(Native Method)
16:13:09  	at java.base@19-internal/java.util.concurrent.locks.LockSupport.park(LockSupport.java:371)
16:13:09  	at java.base@19-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:506)
16:13:09  	at java.base@19-internal/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3744)
16:13:09  	at java.base@19-internal/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3689)
16:13:09  	at java.base@19-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitUninterruptibly(AbstractQueuedSynchronizer.java:1580)
16:13:09  	at app//ReentrantReadWriteLockTest$31.realRun(ReentrantReadWriteLockTest.java:1050)
16:13:09  	at app//JSR166TestCase$CheckedRunnable.run(JSR166TestCase.java:1698)
16:13:09  	at java.base@19-internal/java.lang.Thread.run(Thread.java:1573)
16:13:09  "Thread-505" prio=5 Id=1625 RUNNABLE
16:13:09  	at java.base@19-internal/jdk.internal.misc.Unsafe.park(Native Method)
16:13:09  	at java.base@19-internal/java.util.concurrent.locks.LockSupport.park(LockSupport.java:371)
16:13:09  	at java.base@19-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:506)
16:13:09  	at java.base@19-internal/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3744)
16:13:09  	at java.base@19-internal/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3689)
16:13:09  	at java.base@19-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitUninterruptibly(AbstractQueuedSynchronizer.java:1580)
16:13:09  	at app//ReentrantReadWriteLockTest$32.realRun(ReentrantReadWriteLockTest.java:1060)
16:13:09  	at app//JSR166TestCase$CheckedRunnable.run(JSR166TestCase.java:1698)
16:13:09  	at java.base@19-internal/java.lang.Thread.run(Thread.java:1573)
16:13:09  ------ stacktrace dump end ------
16:13:09  JavaTest Message: JUnit Failure: testAwaitUninterruptibly(ReentrantReadWriteLockTest): timed out waiting for thread to enter thread state WAITING
16:13:09  junit.framework.AssertionFailedError: timed out waiting for thread to enter thread state WAITING
16:13:09  	at junit.framework.Assert.fail(Assert.java:57)
16:13:09  	at junit.framework.TestCase.fail(TestCase.java:223)
16:13:09  	at java.base/java.lang.AbstractStringBuilder.appendChars(AbstractStringBuilder.java:1776)
16:13:09  	at ReentrantReadWriteLockTest.testAwaitUninterruptibly(ReentrantReadWriteLockTest.java:1070)
16:13:09  	at ReentrantReadWriteLockTest.testAwaitUninterruptibly(ReentrantReadWriteLockTest.java:1037)

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

pshipton · 2022-06-30T16:13:46Z

Set high priority since it's blocking sanity.openjdk from running green.

pshipton · 2022-07-05T19:16:22Z

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64_aix_OpenJDK19/5
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_OpenJDK19/5
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_mac_OpenJDK19/5

JasonFengJ9 · 2022-07-07T14:55:57Z

Also seen at internal build job/Test_openjdk19_j9_sanity.openjdk_x86-64_mac_testList_1/6/

openjdk version "19-beta" 2022-09-20
IBM Semeru Runtime Open Edition 19+28-202207050535 (build 19-beta+28-202207050535)
Eclipse OpenJ9 VM 19+28-202207050535 (build master-0e480f25e, JRE 19 Mac OS X amd64-64-Bit Compressed References 20220705_18 (JIT enabled, AOT enabled)
OpenJ9   - 0e480f25e
OMR      - d018241d7
JCL      - 28e60ccf5a based on jdk-19+28)

[2022-07-05T07:30:17.997Z] TEST: java/util/concurrent/tck/JSR166TestCase.java

[2022-07-05T07:30:18.001Z] STDERR:
[2022-07-05T07:30:18.001Z] JavaTest Message: JUnit Failure: testAwaitUninterruptibly_fair(ReentrantLockTest): timed out waiting for thread to enter thread state WAITING
[2022-07-05T07:30:18.001Z] junit.framework.AssertionFailedError: timed out waiting for thread to enter thread state WAITING
[2022-07-05T07:30:18.001Z] 	at junit.framework.Assert.fail(Assert.java:57)
[2022-07-05T07:30:18.001Z] 	at junit.framework.TestCase.fail(TestCase.java:223)
[2022-07-05T07:30:18.001Z] 	at JSR166TestCase.assertThreadBlocks(JSR166TestCase.java:1221)
[2022-07-05T07:30:18.001Z] 	at ReentrantLockTest.testAwaitUninterruptibly(ReentrantLockTest.java:954)
[2022-07-05T07:30:18.001Z] 	at ReentrantLockTest.testAwaitUninterruptibly_fair(ReentrantLockTest.java:922)
[2022-07-05T07:30:18.001Z] 	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104)

tajila · 2022-11-03T17:48:27Z

@JasonFengJ9 does this still fail?

babsingh · 2022-11-03T17:54:45Z

The test passes locally. We can re-enable the test:

JasonFengJ9 · 2022-11-03T18:12:18Z

The the test passes locally. We can re-enable the test:

@babsingh I will create a PR to enable it.

JasonFengJ9 · 2022-11-03T18:24:56Z

Created adoptium/aqa-tests#4116 to enable java/util/concurrent/tck/JSR166TestCase.java except windows which matches ProblemList_openjdk19.txt for RI.

pshipton · 2022-11-07T14:33:17Z

Seems it's still failing. Pls exclude it again.
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_aarch64_mac_Nightly/46

20:28:54  JavaTest Message: JUnit Failure: testAwaitUninterruptibly_fair(ReentrantLockTest): timed out waiting for thread to enter thread state WAITING
20:28:54  junit.framework.AssertionFailedError: timed out waiting for thread to enter thread state WAITING
20:28:54  	at junit.framework.Assert.fail(Assert.java:57)
20:28:54  	at junit.framework.TestCase.fail(TestCase.java:223)
20:28:54  	at JSR166TestCase.assertThreadBlocks(JSR166TestCase.java:1221)
20:28:54  	at ReentrantLockTest.testAwaitUninterruptibly(ReentrantLockTest.java:954)
20:28:54  	at ReentrantLockTest.testAwaitUninterruptibly_fair(ReentrantLockTest.java:922)

https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_ppc64le_linux_Nightly/42/
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_s390x_linux_Nightly/44/
https://openj9-jenkins.osuosl.org/job/Test_openjdk19_j9_sanity.openjdk_x86-64_linux_Nightly/42/

Related: eclipse-openj9/openj9#15465 The failure related to JSR166TestCase is intermittent. Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>

babsingh · 2022-11-07T15:20:10Z

Disabled again via adoptium/aqa-tests#4120. The failure is intermittent. More investigation is required. The timeout may happen due to the GC race condition which was mentioned last week. fyi @LinHu2016. The other reason may be the transition to the RI's j.l.Thread.

pshipton · 2022-11-07T15:52:22Z

@babsingh don't forget to add the "test excluded" label when excluding tests.

Related: eclipse-openj9/openj9#15465 The failure related to JSR166TestCase is intermittent. Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>

tajila · 2022-11-22T16:18:26Z

@hangshao0 Can you please take a look at this #15465

hangshao0 · 2022-11-22T21:20:54Z

Looking at the java stack:

"Thread-505" prio=5 Id=1625 RUNNABLE
16:13:09  	at java.base@19-internal/jdk.internal.misc.Unsafe.park(Native Method)
16:13:09  	at java.base@19-internal/java.util.concurrent.locks.LockSupport.park(LockSupport.java:371)
16:13:09  	at java.base@19-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:506)
16:13:09  	at java.base@19-internal/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3744)
16:13:09  	at java.base@19-internal/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3689)
16:13:09  	at java.base@19-internal/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitUninterruptibly(AbstractQueuedSynchronizer.java:1580)
16:13:09  	at app//ReentrantReadWriteLockTest$32.realRun(ReentrantReadWriteLockTest.java:1060)
16:13:09  	at app//JSR166TestCase$CheckedRunnable.run(JSR166TestCase.java:1698)
16:13:09  	at java.base@19-internal/java.lang.Thread.run(Thread.java:1573)

We are already inside Unsafe.park() but the WAITING state is not set. The native code to set the state is:

openj9/runtime/oti/VMAccess.hpp

Lines 196 to 221 in 55c52ff

    
           inlineReleaseVMAccessSetStatus(J9VMThread *const vmThread, const UDATA flags) 
        
           { 
        
           	UDATA savedPublicFlags = vmThread->publicFlags; 
        
           	UDATA publicFlags = 0; 
        
           	VM_AtomicSupport::writeBarrier(); 
        
           	for (;;) { 
        
           		if (savedPublicFlags & J9_PUBLIC_FLAGS_VMACCESS_RELEASE_BITS) { 
        
           			break; 
        
           		} 
        
           		publicFlags = VM_AtomicSupport::lockCompareExchange(&vmThread->publicFlags, 
        
           				savedPublicFlags, (savedPublicFlags & (~J9_PUBLIC_FLAGS_VMACCESS_ACQUIRE_BITS)) | flags); 
        
           		if (savedPublicFlags == publicFlags) { 
        
           			/* success */ 
        
           			return; 
        
           		} 
        
           		/* update the saved value and try again */ 
        
           		savedPublicFlags = publicFlags; 
        
           	} 
        
           	omrthread_monitor_t const publicFlagsMutex = vmThread->publicFlagsMutex; 
        
           	omrthread_t const osThread = vmThread->osThread; 
        
           	omrthread_monitor_enter_using_threadId(publicFlagsMutex, osThread); 
        
           	VM_VMAccess::setPublicFlags(vmThread, flags);

.

It seems that we never reach VM_VMAccess::setPublicFlags(vmThread, flags).

hangshao0 · 2022-11-28T16:28:55Z

!j9vmthread 0x7f198091f400
J9VMThread at 0x7f198091f400 {
  Fields for J9VMThread:
        ...
        0x90: struct J9ThreadMonitor* publicFlagsMutex = !j9threadmonitor 0x00007F1A1C22A078
        0x98: UDATA publicFlags = 0x0000000000008020 (32800)
        0xa0: UDATA compressObjectReferences = 0x0000000000000000 (0)
        0xa8: struct J9Object* threadObject = !j9object 0x00007F1A1A2BA058 // java/lang/Thread
        ...
        0x140: struct J9Thread* osThread = !j9thread 0x00007F19805569D0
        ....
!j9thread 0x7f19805569d0
J9Thread at 0x7f19805569d0 {
  Fields for J9Thread:
        ...
        0x420: U64 flags = 0x0000000001000804 (16779268)  <--------- J9THREAD_FLAG_INTERRUPTED is set.
        ....

The thread entered Unsafe.park(), but with J9THREAD_FLAG_INTERRUPTED set. The thread won't park. It continued running.

Looking at the thread object, Thread.interrupted is false:

!j9object 0x00007F1A1A2BA058
!J9Object 0x00007F1A1A2BA058 {
        struct J9Class* clazz = !j9class 0x7F1A1C1CD100 // java/lang/Thread
        Object flags = 0x00000008;
        J lockword = 0x0000000000000000 (offset = 0) (java/lang/Object) <hidden>
        J eetop = 0x00007F198091F400 (offset = 8) (java/lang/Thread)
        J tid = 0x0000000000000669 (offset = 16) (java/lang/Thread)
        Ljava/lang/String; name = !fj9object 0x7f1a1a2ba5f8 (offset = 40) (java/lang/Thread)
        Z interrupted = 0x00000000 (offset = 152) (java/lang/Thread)

So we are in an incorrect state that Thread.interrupted is false, while J9THREAD_FLAG_INTERRUPTED is set on J9thread. It will never be parked by Unsafe.park().

hangshao0 · 2022-11-29T16:47:20Z

There is a race condition. One thread is interrupting the target thread (setting Thread.interrupted to true and J9THREAD_FLAG_INTERRUPTED flag):
https://github.com/ibmruntimes/openj9-openjdk-jdk19/blob/720d5357766d6cbb5dda08b469809da633f39129/src/java.base/share/classes/java/lang/Thread.java#L1757-L1759

Another thread is clearing the interruption (set Thread.interrupted to false and clear J9THREAD_FLAG_INTERRUPTED flag):
https://github.com/ibmruntimes/openj9-openjdk-jdk19/blob/720d5357766d6cbb5dda08b469809da633f39129/src/java.base/share/classes/java/lang/Thread.java#L1821-L1822. However, it is not done inside interruptLock.

Fixes: eclipse-openj9/openj9#15465 Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

hangshao0 · 2022-11-29T19:09:19Z

The issue goes away with ibmruntimes/openj9-openjdk-jdk19#51

Fixes: eclipse-openj9/openj9#15465 Port of ibmruntimes/openj9-openjdk-jdk19#51 Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

Fixes: eclipse-openj9/openj9#15465 Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

Fixes: eclipse-openj9/openj9#15465 Port of ibmruntimes/openj9-openjdk-jdk19#51 Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

babsingh · 2022-12-06T00:15:01Z

@hangshao0 The test needs to be re-enabled, and then the test excluded tag should be removed.

hangshao0 · 2022-12-06T16:30:34Z

PR to re-enable the test: adoptium/aqa-tests#4187

…4187) Enable JSR166TestCase.java except Windows which matches ProblemList_openjdk19.txt and ProblemList_openjdk20.txt Closes eclipse-openj9/openj9#15465 Signed-off-by: Hang Shao <hangshao@ca.ibm.com> Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

hangshao0 · 2022-12-06T21:16:52Z

PR to re-enable the test: adoptium/aqa-tests#4187

Merged. Closing this issue.

pshipton added test failure jdk19 labels Jun 30, 2022

pshipton added this to the Release 0.34 (Java 19) milestone Jun 30, 2022

pshipton added comp:vm prio:high labels Jun 30, 2022

JasonFengJ9 mentioned this issue Jul 7, 2022

Exclude JDK19 known failures adoptium/aqa-tests#3832

Merged

JasonFengJ9 added the test excluded label Jul 7, 2022

pshipton removed the prio:high label Jul 28, 2022

JasonFengJ9 mentioned this issue Nov 3, 2022

Enable tests JSR166TestCase.java & HCRLateAttachWorkload_previewEnabled adoptium/aqa-tests#4116

Merged

JasonFengJ9 removed the test excluded label Nov 3, 2022

babsingh added a commit to babsingh/aqa-tests that referenced this issue Nov 7, 2022

Disable JSR166TestCase

a100c77

Related: eclipse-openj9/openj9#15465 The failure related to JSR166TestCase is intermittent. Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>

babsingh added a commit to babsingh/aqa-tests that referenced this issue Nov 7, 2022

Disable JSR166TestCase

db11f4e

Related: eclipse-openj9/openj9#15465 The failure related to JSR166TestCase is intermittent. Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>

babsingh mentioned this issue Nov 7, 2022

Disable JSR166TestCase adoptium/aqa-tests#4120

Merged

pshipton added the test excluded label Nov 7, 2022

babsingh added a commit to babsingh/aqa-tests that referenced this issue Nov 8, 2022

Disable JSR166TestCase

218c4c0

Related: eclipse-openj9/openj9#15465 The failure related to JSR166TestCase is intermittent. Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>

llxia pushed a commit to adoptium/aqa-tests that referenced this issue Nov 8, 2022

Disable JSR166TestCase (#4120)

9832eba

Related: eclipse-openj9/openj9#15465 The failure related to JSR166TestCase is intermittent. Signed-off-by: Babneet Singh <sbabneet@ca.ibm.com>

dchopra001 mentioned this issue Nov 14, 2022

Disable countDecimalDigits transformation for AOT compilations #16273

Merged

hangshao0 added a commit to hangshao0/openj9-openjdk-jdk19 that referenced this issue Nov 29, 2022

Add synchronized block in getAndClearInterrupt()

93dd6e7

Fixes: eclipse-openj9/openj9#15465 Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

hangshao0 mentioned this issue Nov 29, 2022

Add synchronized block in getAndClearInterrupt() ibmruntimes/openj9-openjdk-jdk19#51

Merged

hangshao0 added a commit to hangshao0/openj9-openjdk-jdk that referenced this issue Nov 29, 2022

Add synchronized block in getAndClearInterrupt()

5695cda

Fixes: eclipse-openj9/openj9#15465 Port of ibmruntimes/openj9-openjdk-jdk19#51 Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

hangshao0 mentioned this issue Nov 29, 2022

Add synchronized block in getAndClearInterrupt() ibmruntimes/openj9-openjdk-jdk#525

Merged

hangshao0 added a commit to hangshao0/openj9-openjdk-jdk that referenced this issue Nov 29, 2022

Add synchronized block in getAndClearInterrupt()

8e26979

Fixes: eclipse-openj9/openj9#15465 Port of ibmruntimes/openj9-openjdk-jdk19#51 Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

hangshao0 added a commit to hangshao0/openj9-openjdk-jdk19 that referenced this issue Nov 29, 2022

Add synchronized block in getAndClearInterrupt()

b7e964a

Fixes: eclipse-openj9/openj9#15465 Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

hangshao0 added a commit to hangshao0/openj9-openjdk-jdk that referenced this issue Nov 29, 2022

Add synchronized block in getAndClearInterrupt()

3517096

Fixes: eclipse-openj9/openj9#15465 Port of ibmruntimes/openj9-openjdk-jdk19#51 Signed-off-by: Hang Shao <hangshao@ca.ibm.com>

tajila closed this as completed in ibmruntimes/openj9-openjdk-jdk19#51 Dec 1, 2022

babsingh reopened this Dec 6, 2022

hangshao0 mentioned this issue Dec 6, 2022

Enable JSR166TestCase on OpenJ9 Java 19 and Java 20 on non-Windows adoptium/aqa-tests#4187

Merged

hangshao0 removed the test excluded label Dec 6, 2022

hangshao0 closed this as completed Dec 6, 2022

pshipton mentioned this issue Feb 29, 2024

Remove unnecessary synchronization from Thread.getAndClearInterrupt() ibmruntimes/openj9-openjdk-jdk21#133

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

jdk19 openjdk java/util/concurrent/tck/JSR166TestCase.java testAwaitUninterruptibly(ReentrantReadWriteLockTest): timed out waiting for thread to enter thread state WAITING #15465

jdk19 openjdk java/util/concurrent/tck/JSR166TestCase.java testAwaitUninterruptibly(ReentrantReadWriteLockTest): timed out waiting for thread to enter thread state WAITING #15465

pshipton commented Jun 30, 2022 •

edited

Loading

pshipton commented Jun 30, 2022

pshipton commented Jul 5, 2022

JasonFengJ9 commented Jul 7, 2022

tajila commented Nov 3, 2022

babsingh commented Nov 3, 2022 •

edited

Loading

JasonFengJ9 commented Nov 3, 2022

JasonFengJ9 commented Nov 3, 2022

pshipton commented Nov 7, 2022 •

edited

Loading

babsingh commented Nov 7, 2022 •

edited

Loading

pshipton commented Nov 7, 2022

tajila commented Nov 22, 2022

hangshao0 commented Nov 22, 2022

hangshao0 commented Nov 28, 2022

hangshao0 commented Nov 29, 2022

hangshao0 commented Nov 29, 2022

babsingh commented Dec 6, 2022 •

edited

Loading

hangshao0 commented Dec 6, 2022

hangshao0 commented Dec 6, 2022

jdk19 openjdk java/util/concurrent/tck/JSR166TestCase.java testAwaitUninterruptibly(ReentrantReadWriteLockTest): timed out waiting for thread to enter thread state WAITING #15465

jdk19 openjdk java/util/concurrent/tck/JSR166TestCase.java testAwaitUninterruptibly(ReentrantReadWriteLockTest): timed out waiting for thread to enter thread state WAITING #15465

Comments

pshipton commented Jun 30, 2022 • edited Loading

pshipton commented Jun 30, 2022

pshipton commented Jul 5, 2022

JasonFengJ9 commented Jul 7, 2022

tajila commented Nov 3, 2022

babsingh commented Nov 3, 2022 • edited Loading

JasonFengJ9 commented Nov 3, 2022

JasonFengJ9 commented Nov 3, 2022

pshipton commented Nov 7, 2022 • edited Loading

babsingh commented Nov 7, 2022 • edited Loading

pshipton commented Nov 7, 2022

tajila commented Nov 22, 2022

hangshao0 commented Nov 22, 2022

hangshao0 commented Nov 28, 2022

hangshao0 commented Nov 29, 2022

hangshao0 commented Nov 29, 2022

babsingh commented Dec 6, 2022 • edited Loading

hangshao0 commented Dec 6, 2022

hangshao0 commented Dec 6, 2022

pshipton commented Jun 30, 2022 •

edited

Loading

babsingh commented Nov 3, 2022 •

edited

Loading

pshipton commented Nov 7, 2022 •

edited

Loading

babsingh commented Nov 7, 2022 •

edited

Loading

babsingh commented Dec 6, 2022 •

edited

Loading