Deadlock in Cockpit?

[jpe...@gmail.com]

Many thanks for addressing the S3 PUT issue that blocked connections
from getting released. Now, I'm experiencing another issue.

Almost all of the time, after I pick a bucket, select "Upload files",
and then choose a directory and click "OK", I get "hung" waiting for
the upload to start. I don't see the Progress Bar, only the cockpit
screen showing my buckets and objects. The cursor is an hourglass. I
can still click around and do things in the UI (gear menus work, etc)
- so the AWT thread isn't blocked. I did a jstack on the process, and
it looks like there's a deadlock on ProgressDisplay$ProgressDialog.
AWT-EventQueue-0 has locked the ProgressDialog, and "Thread-18" (the
upload worker thread?) is waiting to lock it. Not sure why AWT-
EventQueue-0 isn't letting go.

Doesn't look like I can attach a file here, so I'm cutting and pasting
the output. Hope it's not too nasty. I'm running this on build
1.6.0_04-b12.

2008-01-16 08:30:30
Full thread dump Java HotSpot(TM) Client VM (10.0-b19 mixed mode,
sharing):

"Thread-18" prio=6 tid=0x02e9b800 nid=0xc94 waiting for monitor entry
[0x036df000..0x036dfd94]
java.lang.Thread.State: BLOCKED (on object monitor)
at java.awt.Window.postWindowEvent(Window.java:874)
- waiting to lock <0x229b28d0> (a
org.jets3t.apps.cockpit.gui.ProgressDisplay$ProgressDialog)
at java.awt.Window.doDispose(Window.java:1008)
at java.awt.Dialog.doDispose(Dialog.java:1243)
at java.awt.Window.dispose(Window.java:937)
at org.jets3t.apps.cockpit.gui.ProgressDisplay
$ProgressDialog.dispose(ProgressDisplay.java:278)
at
org.jets3t.apps.cockpit.gui.ProgressDisplay.dispose(ProgressDisplay.java:
145)
at org.jets3t.apps.cockpit.Cockpit.stopProgressDisplay(Cockpit.java:
896)
at org.jets3t.apps.cockpit.Cockpit.access$1800(Cockpit.java:158)
at org.jets3t.apps.cockpit.Cockpit$19.run(Cockpit.java:1834)
at java.lang.Thread.run(Thread.java:619)

"Swing-Shell" daemon prio=6 tid=0x03886800 nid=0xf7c waiting on
condition [0x0beef000..0x0beefc94]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x2314b588> (a
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
at java.util.concurrent.locks.AbstractQueuedSynchronizer
$ConditionObject.await(AbstractQueuedSynchronizer.java:1925)
at
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:
358)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:
946)
at java.util.concurrent.ThreadPoolExecutor
$Worker.run(ThreadPoolExecutor.java:906)
at sun.awt.shell.Win32ShellFolderManager2$ComInvoker
$3.run(Win32ShellFolderManager2.java:458)
at java.lang.Thread.run(Thread.java:619)

"MultiThreadedHttpConnectionManager cleanup" daemon prio=6
tid=0x02ab0000 nid=0xf28 in Object.wait() [0x03d2f000..0x03d2fa94]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x22f9d6a8> (a java.lang.ref.ReferenceQueue$Lock)
at org.apache.commons.httpclient.MultiThreadedHttpConnectionManager
$ReferenceQueueThread.run(MultiThreadedHttpConnectionManager.java:
1082)

"DestroyJavaVM" prio=6 tid=0x00296800 nid=0xa5c waiting on condition
[0x00000000..0x0090fd4c]
java.lang.Thread.State: RUNNABLE

"AWT-EventQueue-0" prio=6 tid=0x02fa4c00 nid=0x514 in Object.wait()
[0x0374f000..0x0374fb94]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at java.awt.EventQueue.getNextEvent(EventQueue.java:479)
- locked <0x22e81d70> (a java.awt.EventQueue)
at
java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:
245)
at
java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:
183)
at
java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:
177)
at java.awt.Dialog$1.run(Dialog.java:1045)
at java.awt.Dialog$3.run(Dialog.java:1097)
at java.security.AccessController.doPrivileged(Native Method)
at java.awt.Dialog.show(Dialog.java:1095)
at org.jets3t.apps.cockpit.gui.ProgressDisplay
$1.run(ProgressDisplay.java:90)
- locked <0x229b28d0> (a org.jets3t.apps.cockpit.gui.ProgressDisplay
$ProgressDialog)
at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:209)
at java.awt.EventQueue.dispatchEvent(EventQueue.java:597)
at
java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:
273)
at
java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:
183)
at
java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:
173)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:
168)
at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:
160)
at java.awt.EventDispatchThread.run(EventDispatchThread.java:121)

"TimerQueue" daemon prio=6 tid=0x02e16c00 nid=0xccc in Object.wait()
[0x035af000..0x035afa14]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at javax.swing.TimerQueue.run(TimerQueue.java:236)
- locked <0x22ed19e8> (a javax.swing.TimerQueue)
at java.lang.Thread.run(Thread.java:619)

"AWT-Windows" daemon prio=6 tid=0x02df1000 nid=0xee0 runnable
[0x030cf000..0x030cfa94]
java.lang.Thread.State: RUNNABLE
at sun.awt.windows.WToolkit.eventLoop(Native Method)
at sun.awt.windows.WToolkit.run(WToolkit.java:290)
at java.lang.Thread.run(Thread.java:619)

"AWT-Shutdown" prio=6 tid=0x02df0800 nid=0xfcc in Object.wait()
[0x0307f000..0x0307fb14]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java:259)
- locked <0x22ea0098> (a java.lang.Object)
at java.lang.Thread.run(Thread.java:619)

"Java2D Disposer" daemon prio=10 tid=0x02dec400 nid=0x9f8 in
Object.wait() [0x0302f000..0x0302fb94]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22ea0128> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x22ea0128> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at sun.java2d.Disposer.run(Disposer.java:125)
at java.lang.Thread.run(Thread.java:619)

"Low Memory Detector" daemon prio=6 tid=0x02a67000 nid=0xd4 runnable
[0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x02a59000 nid=0xb48 waiting on
condition [0x00000000..0x02d0f9bc]
java.lang.Thread.State: RUNNABLE

"Attach Listener" daemon prio=10 tid=0x02a57c00 nid=0x380 waiting on
condition [0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x02a57400 nid=0x8d8 runnable
[0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=0x02a52800 nid=0x250 in Object.wait()
[0x02c1f000..0x02c1fa94]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22e5aea8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
- locked <0x22e5aea8> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x02a4e400 nid=0xaf0 in
Object.wait() [0x02bcf000..0x02bcfb14]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22e5af30> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:485)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x22e5af30> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=10 tid=0x02a4d000 nid=0xc30 runnable

"VM Periodic Task Thread" prio=10 tid=0x02a68000 nid=0x428 waiting on
condition

JNI global references: 1179

[James Murty]

Hi jpelly,

I haven't had a chance to do much testing of Cockpit with the new Java version 1.6 as my primary dev machine is a Mac, however I have had a couple of reports that some of the GUI behaviour has changed for the worse when run on the latest version of Java.

Which version of JetS3t are you using? I cleaned up some of the GUI thread management code after the 0.5.0 release so I would be interested to know if the latest JetS3t code in CVS has the same problem. You could also try drag-and-dropping the files into Cockpit to see whether or not that causes it to hang as well.

James

        at java.lang.ref.ReferenceQueue.remove (ReferenceQueue.java:116)

        - locked <0x22f9d6a8> (a java.lang.ref.ReferenceQueue$Lock)
        at org.apache.commons.httpclient.MultiThreadedHttpConnectionManager
$ReferenceQueueThread.run(MultiThreadedHttpConnectionManager.java :
1082)

"DestroyJavaVM" prio=6 tid=0x00296800 nid=0xa5c waiting on condition
[0x00000000..0x0090fd4c]
   java.lang.Thread.State: RUNNABLE

"AWT-EventQueue-0" prio=6 tid=0x02fa4c00 nid=0x514 in Object.wait()
[0x0374f000..0x0374fb94]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:485)

        at java.awt.EventQueue.getNextEvent (EventQueue.java:479)

        - locked <0x22e81d70> (a java.awt.EventQueue)
        at
java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:
245)
        at
java.awt.EventDispatchThread.pumpEventsForFilter (EventDispatchThread.java:
183)
        at
java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:
177)
        at java.awt.Dialog$1.run(Dialog.java:1045)

        at java.awt.Dialog$3.run (Dialog.java:1097)

        at java.security.AccessController.doPrivileged(Native Method)
        at java.awt.Dialog.show(Dialog.java:1095)
        at org.jets3t.apps.cockpit.gui.ProgressDisplay
$1.run(ProgressDisplay.java :90)
        - locked <0x229b28d0> (a org.jets3t.apps.cockpit.gui.ProgressDisplay
$ProgressDialog)
        at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:209)

        at java.awt.EventQueue.dispatchEvent (EventQueue.java:597)

        at
java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:
273)
        at
java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:
183)
        at
java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:
173)
        at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:
168)
        at java.awt.EventDispatchThread.pumpEvents (EventDispatchThread.java:
160)
        at java.awt.EventDispatchThread.run(EventDispatchThread.java:121)

"TimerQueue" daemon prio=6 tid=0x02e16c00 nid=0xccc in Object.wait()
[0x035af000..0x035afa14]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at javax.swing.TimerQueue.run(TimerQueue.java:236)
        - locked <0x22ed19e8> (a javax.swing.TimerQueue )
        at java.lang.Thread.run(Thread.java:619)

"AWT-Windows" daemon prio=6 tid=0x02df1000 nid=0xee0 runnable
[0x030cf000..0x030cfa94]
   java.lang.Thread.State: RUNNABLE

        at sun.awt.windows.WToolkit.eventLoop (Native Method)

        at sun.awt.windows.WToolkit.run(WToolkit.java:290)
        at java.lang.Thread.run(Thread.java:619)

"AWT-Shutdown" prio=6 tid=0x02df0800 nid=0xfcc in Object.wait()
[0x0307f000..0x0307fb14]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:485)
        at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java :259)
        - locked <0x22ea0098> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:619)

"Java2D Disposer" daemon prio=10 tid=0x02dec400 nid=0x9f8 in
Object.wait() [0x0302f000..0x0302fb94]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x22ea0128> (a java.lang.ref.ReferenceQueue$Lock)

        at java.lang.ref.ReferenceQueue.remove (ReferenceQueue.java:116)

[jpe...@gmail.com]

Pardon for taking so long to reply. Just for fun, I checked out the
0.5.0 source and poked around. After a few minutes of looking at the
source and the jstack ouput I found the problem. In Cockpit.java
(compareRemoteAndLocalFiles()) there's a call to stopProgressDisplay()
from a Runnable. This calls dispose(), which eventually tries to grab
the lock on member variable progressDisplay. Problem is, that doesn't
take place in the AWT thread, and a few lines up there's a
startProgressDisplay() that grabs the lock in a synchronized method.
Result: instant deadlock of that worker thread.

Wrapping the stopProgressDisplay() in a SwingUtilities.invokeAndWait()
seems to fix it:

SwingUtilities.invokeAndWait(new Runnable() {
public void run() {
stopProgressDisplay();
}
});


I think SwingUtilities wasn't included in the JDK until 6.0, but
there's a version of it in the Java tutorial, if memory serves. I'm
sure there are other backports.

Would you like me to deliver this change in a more serviceable format?
As a patch? If you've taken care of it in 0.5.1 that's fine; I wonder
if others have the same problem with the 0.5.0 version running on JDK
6.0 though. Let me know.

John

> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)

> > - locked <0x22f9d6a8> (a java.lang.ref.ReferenceQueue$Lock)
> > at
> > org.apache.commons.httpclient.MultiThreadedHttpConnectionManager
> > $ReferenceQueueThread.run(MultiThreadedHttpConnectionManager.java:
> > 1082)
>
> > "DestroyJavaVM" prio=6 tid=0x00296800 nid=0xa5c waiting on condition
> > [0x00000000..0x0090fd4c]
> > java.lang.Thread.State: RUNNABLE
>
> > "AWT-EventQueue-0" prio=6 tid=0x02fa4c00 nid=0x514 in Object.wait()
> > [0x0374f000..0x0374fb94]
> > java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at java.lang.Object.wait(Object.java:485)

> > at java.awt.EventQueue.getNextEvent(EventQueue.java:479)

> > - locked <0x22e81d70> (a java.awt.EventQueue)
> > at
> > java.awt.EventDispatchThread.pumpOneEventForFilters(
> > EventDispatchThread.java:
> > 245)
> > at

> > java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:

> > 183)
> > at
> > java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:
> > 177)
> > at java.awt.Dialog$1.run(Dialog.java:1045)

> > at java.awt.Dialog$3.run(Dialog.java:1097)

> > at java.security.AccessController.doPrivileged(Native Method)
> > at java.awt.Dialog.show(Dialog.java:1095)
> > at org.jets3t.apps.cockpit.gui.ProgressDisplay
> > $1.run(ProgressDisplay.java:90)
> > - locked <0x229b28d0> (a
> > org.jets3t.apps.cockpit.gui.ProgressDisplay
> > $ProgressDialog)
> > at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java
> > :209)
> > at java.awt.EventQueue.dispatchEvent(EventQueue.java:597)
> > at
> > java.awt.EventDispatchThread.pumpOneEventForFilters(

> > EventDispatchThread.java:

> > at sun.awt.windows.WToolkit.eventLoop(Native Method)

> > at sun.awt.windows.WToolkit.run(WToolkit.java:290)
> > at java.lang.Thread.run(Thread.java:619)
>
> > "AWT-Shutdown" prio=6 tid=0x02df0800 nid=0xfcc in Object.wait()
> > [0x0307f000..0x0307fb14]
> > java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > at java.lang.Object.wait(Object.java:485)
> > at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java:259)
> > - locked <0x22ea0098> (a java.lang.Object)
> > at java.lang.Thread.run(Thread.java:619)
>
> > "Java2D Disposer" daemon prio=10 tid=0x02dec400 nid=0x9f8 in
> > Object.wait() [0x0302f000..0x0302fb94]
> > java.lang.Thread.State: WAITING (on object monitor)
> > at java.lang.Object.wait(Native Method)
> > - waiting on <0x22ea0128> (a java.lang.ref.ReferenceQueue$Lock)

> > at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)

[James Murty]

Hi John,

Thanks for doing such a thorough investigation into this issue.

I can confirm that, in the latest CVS codebase version, all operations on the progress dialog are performed within SwingUtilities.invokeLater() method calls - so this deadlock problem is hopefully solved in the current version. I will have to consider whether I should be using the invokeAndWait() method instead.

I ended up rewriting much of the code that interacted with the progress dialog after the release of 0.5.0 as I had experienced a couple of deadlocks. Literally, two deadlocks, in all my testing. It's interesting that the 6.0 version of Java is so much more susceptible to this GUI threading bug than 5.0.

James

[James Murty]

Hi John,

I have just created a new CVS branch for patches to the 0.5.0 version
codebase, called "Release-0_5_0-patches". If you get the chance, could
you confirm whether fix I applied to this branch prevents the Cockpit
deadlock you have been experiencing?

Cheers,
James

> ...
>
> read more »