RFR for JDK-8025198 Intermittent test failure: java/util/concurrent/ThreadPoolExecutor/ThrowingTasks.java

Mon Nov 4 06:40:31 UTC 2013

David and I might prefer a fix using AtomicInteger, but I don't think
there's anything incorrect with your fix - approved.  Especially if you
have seen the flakiness has gone away.  (I've never seen this test fail.)

On Sun, Nov 3, 2013 at 8:14 PM, Tristan Yan <tristan.yan at oracle.com> wrote:

>  Thank you Martin
> I updated the code as below
>
> http://cr.openjdk.java.net/~ewang/tristan/JDK-8025198/webrev.02/
> Thank you
>
>
>
> On 11/04/2013 11:38 AM, Martin Buchholz wrote:
>
> Tristan, I think your change it correct.
> There are some stylistic improvements I would make:
> - make lock final
> - make lessThanCorePoolSize "blank final"; final boolean
> lessThanCorePoolSize;
> - add spaces after // and before {
>
>
>  On Sun, Nov 3, 2013 at 4:49 PM, Tristan Yan <tristan.yan at oracle.com>wrote:
>
>>  Thank you Martin
>> I had code change. I took the similar way as you do here.
>>
>> Please review the code change for JDK-8025198.
>> Description:
>> Race condition exists in the test ThrowingTasks.java. We should sync
>> CountDownLatch.countDown and CountDownLatch.getCount.
>>
>>
>> http://cr.openjdk.java.net/~ewang/tristan/JDK-8025198/webrev.01/test/java/util/concurrent/ThreadPoolExecutor/ThrowingTasks.java.sdiff.html
>>
>> Thank you
>> Tristan
>>
>>
>>
>> On 11/03/2013 12:46 PM, Martin Buchholz wrote:
>>
>> I think the author of this test was sleep-deprived by baby Tristan back
>> in 2007.[image: Inline image 1]
>>
>>  I tried and failed to find a single synchronizer that properly does
>> what we are trying to do with allStarted here.  Too bad
>> CountDownLatch.countDown doesn't return the count.  Best to introduce
>> another synchronizer.  I propose this fix:
>>
>>   diff --git
>> a/test/java/util/concurrent/ThreadPoolExecutor/ThrowingTasks.java
>> b/test/java/util/concurrent/ThreadPoolExecutor/ThrowingTasks.java
>> --- a/test/java/util/concurrent/ThreadPoolExecutor/ThrowingTasks.java
>> +++ b/test/java/util/concurrent/ThreadPoolExecutor/ThrowingTasks.java
>> @@ -136,6 +136,7 @@
>>      }
>>
>>      static final CountDownLatch allStarted = new
>> CountDownLatch(flakes.size());
>> +    static final AtomicInteger taskSerial = new AtomicInteger(0);
>>      static final CountDownLatch allContinue = new CountDownLatch(1);
>>
>>      static class PermissiveSecurityManger extends SecurityManager {
>> @@ -164,7 +165,8 @@
>>          }
>>          @Override protected void beforeExecute(Thread t, Runnable r) {
>>              allStarted.countDown();
>> -            if (allStarted.getCount() < getCorePoolSize())
>> +            // Get last core pool cohort to start in unison
>> +            if (flakes.size() - taskSerial.incrementAndGet() <
>> getCorePoolSize())
>>                  try { allContinue.await(); }
>>                  catch (InterruptedException x) { unexpected(x); }
>>              beforeExecuteCount.getAndIncrement();
>>
>>
>>
>>  On Fri, Nov 1, 2013 at 6:48 PM, Tristan Yan <tristan.yan at oracle.com>wrote:
>>
>>>  This only happened when I tried a 1000 times loop run, see the jstack
>>> out put below:
>>> Also by using jmap/jhat, below values help me find the reason
>>>         flakes.size() = 25
>>>         allStarted.state = 1
>>>         beforeExecuteCount.count = 1
>>>
>>> Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.0-b56 mixed mode):
>>>
>>> "Attach Listener" #32 daemon prio=9 os_prio=31 tid=0x00007faf1d808000
>>> nid=0x390b waiting on condition [0x0000000000000000]
>>>    java.lang.Thread.State: RUNNABLE
>>>
>>> "Thread-22" #31 prio=5 os_prio=31 tid=0x00007faf1d07b000 nid=0x5d0b
>>> waiting on condition [0x000000019b530000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Thread-21" #30 prio=5 os_prio=31 tid=0x00007faf1d80c800 nid=0x5507
>>> waiting on condition [0x000000019ae1b000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Thread-20" #29 prio=5 os_prio=31 tid=0x00007faf1c10b000 nid=0x6307
>>> waiting on condition [0x000000019b227000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Thread-18" #27 prio=5 os_prio=31 tid=0x00007faf1c10a000 nid=0x6107
>>> waiting on condition [0x000000019b42d000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Thread-14" #23 prio=5 os_prio=31 tid=0x00007faf1d80c000 nid=0x500b
>>> waiting on condition [0x000000019ad18000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Thread-13" #22 prio=5 os_prio=31 tid=0x00007faf1c108800 nid=0x5f03
>>> waiting on condition [0x000000019b32a000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Thread-12" #21 prio=5 os_prio=31 tid=0x00007faf1d80b000 nid=0x540b
>>> waiting on condition [0x000000019ab12000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Thread-10" #19 prio=5 os_prio=31 tid=0x00007faf1d80a800 nid=0x5107
>>> waiting on condition [0x000000019af1e000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Thread-6" #14 prio=5 os_prio=31 tid=0x00007faf1d809800 nid=0x5807
>>> waiting on condition [0x000000019ac15000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Thread-8" #16 prio=5 os_prio=31 tid=0x00007faf1d809000 nid=0x5b03
>>> waiting on condition [0x000000019b124000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e9610> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at
>>> ThrowingTasks$CheckingExecutor.beforeExecute(ThrowingTasks.java:168)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1139)
>>>     at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>>>     at java.lang.Thread.run(Thread.java:744)
>>>
>>> "Service Thread" #8 daemon prio=9 os_prio=31 tid=0x00007faf1c837000
>>> nid=0x4b03 runnable [0x0000000000000000]
>>>    java.lang.Thread.State: RUNNABLE
>>>
>>> "C1 CompilerThread2" #7 daemon prio=9 os_prio=31 tid=0x00007faf1c816000
>>> nid=0x4903 waiting on condition [0x0000000000000000]
>>>    java.lang.Thread.State: RUNNABLE
>>>
>>> "C2 CompilerThread1" #6 daemon prio=9 os_prio=31 tid=0x00007faf1c809800
>>> nid=0x4703 waiting on condition [0x0000000000000000]
>>>    java.lang.Thread.State: RUNNABLE
>>>
>>> "C2 CompilerThread0" #5 daemon prio=9 os_prio=31 tid=0x00007faf1c818000
>>> nid=0x4503 waiting on condition [0x0000000000000000]
>>>    java.lang.Thread.State: RUNNABLE
>>>
>>> "Signal Dispatcher" #4 daemon prio=9 os_prio=31 tid=0x00007faf1c078800
>>> nid=0x4303 runnable [0x0000000000000000]
>>>    java.lang.Thread.State: RUNNABLE
>>>
>>> "Finalizer" #3 daemon prio=8 os_prio=31 tid=0x00007faf1c811000
>>> nid=0x2d03 in Object.wait() [0x00000001999be000]
>>>    java.lang.Thread.State: WAITING (on object monitor)
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0x0000000168286218> (a
>>> java.lang.ref.ReferenceQueue$Lock)
>>>     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:142)
>>>     - locked <0x0000000168286218> (a java.lang.ref.ReferenceQueue$Lock)
>>>     at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:158)
>>>     at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)
>>>
>>> "Reference Handler" #2 daemon prio=10 os_prio=31 tid=0x00007faf1c810800
>>> nid=0x2b03 in Object.wait() [0x00000001998bb000]
>>>    java.lang.Thread.State: WAITING (on object monitor)
>>>     at java.lang.Object.wait(Native Method)
>>>     - waiting on <0x0000000168285c88> (a java.lang.ref.Reference$Lock)
>>>     at java.lang.Object.wait(Object.java:502)
>>>     at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157)
>>>     - locked <0x0000000168285c88> (a java.lang.ref.Reference$Lock)
>>>
>>> "main" #1 prio=5 os_prio=31 tid=0x00007faf1c800000 nid=0x1b03 waiting on
>>> condition [0x000000010386e000]
>>>    java.lang.Thread.State: WAITING (parking)
>>>     at sun.misc.Unsafe.park(Native Method)
>>>     - parking to wait for  <0x00000001683e95e0> (a
>>> java.util.concurrent.CountDownLatch$Sync)
>>>     at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
>>>     at
>>> java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
>>>     at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
>>>     at ThrowingTasks.realMain(ThrowingTasks.java:207)
>>>     at ThrowingTasks.main(ThrowingTasks.java:267)
>>>
>>> "VM Thread" os_prio=31 tid=0x00007faf1c066000 nid=0x2903 runnable
>>>
>>> "GC task thread#0 (ParallelGC)" os_prio=31 tid=0x00007faf1c80d000
>>> nid=0x2103 runnable
>>>
>>> "GC task thread#1 (ParallelGC)" os_prio=31 tid=0x00007faf1c012000
>>> nid=0x2303 runnable
>>>
>>> "GC task thread#2 (ParallelGC)" os_prio=31 tid=0x00007faf1c80e000
>>> nid=0x2503 runnable
>>>
>>> "GC task thread#3 (ParallelGC)" os_prio=31 tid=0x00007faf1c013000
>>> nid=0x2703 runnable
>>>
>>> "VM Periodic Task Thread" os_prio=31 tid=0x00007faf1c06c800 nid=0x4d03
>>> waiting on condition
>>>
>>> JNI global references: 7
>>>
>>>
>>> On 02/11/2013 04:01, Martin Buchholz wrote:
>>>
>>>
>>>
>>> Including a jstack output extract might be useful for diagnosis.
>>>
>>>  I have never seen this test fail.  Is there a hint that might allow me
>>> to reproduce it?
>>>
>>>
>>>
>>
>>
>
>