-
Bug
-
Resolution: Won't Fix
-
P3
-
7
-
Ubuntu linux 14.04
-
generic
-
generic
At Google, we've been seeing threads waiting in LockSupport.park for some event and apparently never getting woken from the expected call to unpark. After much effort, we seem to have a reproduction that reduces to simple calls to park and unpark, strongly suggesting a lost unpark bug in hotspot.
It's very hard to reproduce - we've typically had to spend a couple of days of CPU time per repro. Nevertheless, we have seen enough of these (10 so far) that we can be fairly confident of being able to create the conditions again.
We've been able to reproduce this with openjdk7 and Oracle jdk1.7.0_80-b05, but not any flavor of jdk8, on Ubuntu Linux 14.04.
The repro is checked into jsr166 CVS
http://gee.cs.oswego.edu/cgi-bin/viewcvs.cgi/jsr166/src/test/jtreg/util/concurrent/locks/LockSupport/ParkLoops.java?view=markup
We've been running it with a stupid loop like:
repeat 300000 (date; time ~/jdk/jdk1.7.0_80-b05/bin/java ParkLoops)
for days until it fails/hangs.
It is easier to reproduce when run only for a few seconds (but more java process invocations) suggesting that a one-time event during startup (e.g. c2 compilation with OSR?) is the problem.
Here's a jstack output of a process not making progress:
2015-03-08 16:59:10
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.80-b07 mixed mode):
"Attach Listener" daemon prio=10 tid=0x00007fee4c001000 nid=0x3f42 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"pool-1-thread-8" prio=10 tid=0x00007feea40d5800 nid=0x22f2 runnable [0x00007fee8478e000]
java.lang.Thread.State: RUNNABLE
at ParkLoops$2.run(ParkLoops.java:50)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-6" prio=10 tid=0x00007feea40d1800 nid=0x22f0 runnable [0x00007fee84990000]
java.lang.Thread.State: RUNNABLE
at ParkLoops$2.run(ParkLoops.java:50)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-5" prio=10 tid=0x00007feea40cf800 nid=0x22ef waiting on condition [0x00007fee84a91000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:315)
at ParkLoops$1.run(ParkLoops.java:36)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-4" prio=10 tid=0x00007feea40cd800 nid=0x22ee runnable [0x00007fee84b92000]
java.lang.Thread.State: RUNNABLE
at ParkLoops$2.run(ParkLoops.java:50)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-2" prio=10 tid=0x00007feea40c9000 nid=0x22ec runnable [0x00007fee84d94000]
java.lang.Thread.State: RUNNABLE
at ParkLoops$2.run(ParkLoops.java:50)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"Service Thread" daemon prio=10 tid=0x00007feea40a5800 nid=0x22e9 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread1" daemon prio=10 tid=0x00007feea40a3000 nid=0x22e8 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" daemon prio=10 tid=0x00007feea40a0000 nid=0x22e7 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" daemon prio=10 tid=0x00007feea409e000 nid=0x22e6 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" daemon prio=10 tid=0x00007feea407c800 nid=0x22e5 in Object.wait() [0x00007fee8631c000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000758c84858> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked <0x0000000758c84858> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
"Reference Handler" daemon prio=10 tid=0x00007feea407a800 nid=0x22e4 in Object.wait() [0x00007fee8641d000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000758c84470> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:503)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
- locked <0x0000000758c84470> (a java.lang.ref.Reference$Lock)
"main" prio=10 tid=0x00007feea4009000 nid=0x22d6 waiting on condition [0x00007feead99b000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000758cd3338> (a java.util.concurrent.CountDownLatch$Sync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:994)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:236)
at ParkLoops.main(ParkLoops.java:56)
"VM Thread" prio=10 tid=0x00007feea4076000 nid=0x22e3 runnable
"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007feea401f000 nid=0x22d7 runnable
"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007feea4021000 nid=0x22d8 runnable
"GC task thread#2 (ParallelGC)" prio=10 tid=0x00007feea4022800 nid=0x22d9 runnable
"GC task thread#3 (ParallelGC)" prio=10 tid=0x00007feea4024800 nid=0x22da runnable
"GC task thread#4 (ParallelGC)" prio=10 tid=0x00007feea4026800 nid=0x22db runnable
"GC task thread#5 (ParallelGC)" prio=10 tid=0x00007feea4028000 nid=0x22dc runnable
"GC task thread#6 (ParallelGC)" prio=10 tid=0x00007feea402a000 nid=0x22de runnable
"GC task thread#7 (ParallelGC)" prio=10 tid=0x00007feea402c000 nid=0x22df runnable
"GC task thread#8 (ParallelGC)" prio=10 tid=0x00007feea402e000 nid=0x22e0 runnable
"GC task thread#9 (ParallelGC)" prio=10 tid=0x00007feea402f800 nid=0x22e2 runnable
"VM Periodic Task Thread" prio=10 tid=0x00007feea40b0000 nid=0x22ea waiting on condition
JNI global references: 120
It's very hard to reproduce - we've typically had to spend a couple of days of CPU time per repro. Nevertheless, we have seen enough of these (10 so far) that we can be fairly confident of being able to create the conditions again.
We've been able to reproduce this with openjdk7 and Oracle jdk1.7.0_80-b05, but not any flavor of jdk8, on Ubuntu Linux 14.04.
The repro is checked into jsr166 CVS
http://gee.cs.oswego.edu/cgi-bin/viewcvs.cgi/jsr166/src/test/jtreg/util/concurrent/locks/LockSupport/ParkLoops.java?view=markup
We've been running it with a stupid loop like:
repeat 300000 (date; time ~/jdk/jdk1.7.0_80-b05/bin/java ParkLoops)
for days until it fails/hangs.
It is easier to reproduce when run only for a few seconds (but more java process invocations) suggesting that a one-time event during startup (e.g. c2 compilation with OSR?) is the problem.
Here's a jstack output of a process not making progress:
2015-03-08 16:59:10
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.80-b07 mixed mode):
"Attach Listener" daemon prio=10 tid=0x00007fee4c001000 nid=0x3f42 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"pool-1-thread-8" prio=10 tid=0x00007feea40d5800 nid=0x22f2 runnable [0x00007fee8478e000]
java.lang.Thread.State: RUNNABLE
at ParkLoops$2.run(ParkLoops.java:50)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-6" prio=10 tid=0x00007feea40d1800 nid=0x22f0 runnable [0x00007fee84990000]
java.lang.Thread.State: RUNNABLE
at ParkLoops$2.run(ParkLoops.java:50)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-5" prio=10 tid=0x00007feea40cf800 nid=0x22ef waiting on condition [0x00007fee84a91000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:315)
at ParkLoops$1.run(ParkLoops.java:36)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-4" prio=10 tid=0x00007feea40cd800 nid=0x22ee runnable [0x00007fee84b92000]
java.lang.Thread.State: RUNNABLE
at ParkLoops$2.run(ParkLoops.java:50)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"pool-1-thread-2" prio=10 tid=0x00007feea40c9000 nid=0x22ec runnable [0x00007fee84d94000]
java.lang.Thread.State: RUNNABLE
at ParkLoops$2.run(ParkLoops.java:50)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"Service Thread" daemon prio=10 tid=0x00007feea40a5800 nid=0x22e9 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread1" daemon prio=10 tid=0x00007feea40a3000 nid=0x22e8 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" daemon prio=10 tid=0x00007feea40a0000 nid=0x22e7 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" daemon prio=10 tid=0x00007feea409e000 nid=0x22e6 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" daemon prio=10 tid=0x00007feea407c800 nid=0x22e5 in Object.wait() [0x00007fee8631c000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000758c84858> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked <0x0000000758c84858> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
"Reference Handler" daemon prio=10 tid=0x00007feea407a800 nid=0x22e4 in Object.wait() [0x00007fee8641d000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x0000000758c84470> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:503)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
- locked <0x0000000758c84470> (a java.lang.ref.Reference$Lock)
"main" prio=10 tid=0x00007feea4009000 nid=0x22d6 waiting on condition [0x00007feead99b000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x0000000758cd3338> (a java.util.concurrent.CountDownLatch$Sync)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:834)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:994)
at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1303)
at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:236)
at ParkLoops.main(ParkLoops.java:56)
"VM Thread" prio=10 tid=0x00007feea4076000 nid=0x22e3 runnable
"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007feea401f000 nid=0x22d7 runnable
"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007feea4021000 nid=0x22d8 runnable
"GC task thread#2 (ParallelGC)" prio=10 tid=0x00007feea4022800 nid=0x22d9 runnable
"GC task thread#3 (ParallelGC)" prio=10 tid=0x00007feea4024800 nid=0x22da runnable
"GC task thread#4 (ParallelGC)" prio=10 tid=0x00007feea4026800 nid=0x22db runnable
"GC task thread#5 (ParallelGC)" prio=10 tid=0x00007feea4028000 nid=0x22dc runnable
"GC task thread#6 (ParallelGC)" prio=10 tid=0x00007feea402a000 nid=0x22de runnable
"GC task thread#7 (ParallelGC)" prio=10 tid=0x00007feea402c000 nid=0x22df runnable
"GC task thread#8 (ParallelGC)" prio=10 tid=0x00007feea402e000 nid=0x22e0 runnable
"GC task thread#9 (ParallelGC)" prio=10 tid=0x00007feea402f800 nid=0x22e2 runnable
"VM Periodic Task Thread" prio=10 tid=0x00007feea40b0000 nid=0x22ea waiting on condition
JNI global references: 120
- relates to
-
JDK-8145138 CyclicBarrier/Basic.java failed with "3 not equal to 4"
- Resolved