Deadlock when opening a graph

development
#1

Development version of SNAP blocks when opening a graph. Debugging it, it seems to be a deadlock problem. Specifically, when loading a graph the AWT EventQueue thread at some point (loadGraph in GraphExecuter) spawns a helper thread (of type LoadGraphThread, which extends SwingWorker) and immediately waits for it, thus blocking. This thread in turn loads the graph, but then notifies some observers, one of which (update in GraphBuilderDialog) performs some action that waits for something to happen in the AWT EventQueue thread (because of reasons internal to the Swing/AWT implementation). This results in dead lock and the interface becomes irresponsive.

I am using current master commits on snap-engine, snap-desktop and s1tbx on OpenJDK 8 on Debian unstable. Looking at the stack traces below it might be that this deadlock is Linux-specific, so maybe it doesn’t happen on Windows. Still, I believe that EventQueue should never wait on other threads. Even if there aren’t deadlocks, it could result in the interface being temporarily unresponsive.

Stack trace for the EventQueue thread:

park:-1, Unsafe (sun.misc)
park:175, LockSupport (java.util.concurrent.locks)
awaitDone:429, FutureTask (java.util.concurrent)
get:191, FutureTask (java.util.concurrent)
get:602, SwingWorker (javax.swing)
loadGraph:357, GraphExecuter (org.esa.snap.graphbuilder.rcp.dialogs.support)
loadGraph:431, GraphBuilderDialog (org.esa.snap.graphbuilder.rcp.dialogs)
loadGraph:413, GraphBuilderDialog (org.esa.snap.graphbuilder.rcp.dialogs)
loadGraph:403, GraphBuilderDialog (org.esa.snap.graphbuilder.rcp.dialogs)
lambda$initButtonPanel$4:279, GraphBuilderDialog (org.esa.snap.graphbuilder.rcp.dialogs)
actionPerformed:-1, 1084023362 (org.esa.snap.graphbuilder.rcp.dialogs.GraphBuilderDialog$$Lambda$172)
fireActionPerformed:2022, AbstractButton (javax.swing)
actionPerformed:2348, AbstractButton$Handler (javax.swing)
fireActionPerformed:402, DefaultButtonModel (javax.swing)
setPressed:259, DefaultButtonModel (javax.swing)
mouseReleased:252, BasicButtonListener (javax.swing.plaf.basic)
mouseReleased:289, AWTEventMulticaster (java.awt)
processMouseEvent:6539, Component (java.awt)
processMouseEvent:3324, JComponent (javax.swing)
processEvent:6304, Component (java.awt)
processEvent:2239, Container (java.awt)
dispatchEventImpl:4889, Component (java.awt)
dispatchEventImpl:2297, Container (java.awt)
dispatchEvent:4711, Component (java.awt)
retargetMouseEvent:4904, LightweightDispatcher (java.awt)
processMouseEvent:4535, LightweightDispatcher (java.awt)
dispatchEvent:4476, LightweightDispatcher (java.awt)
dispatchEventImpl:2283, Container (java.awt)
dispatchEventImpl:2746, Window (java.awt)
dispatchEvent:4711, Component (java.awt)
dispatchEventImpl:760, EventQueue (java.awt)
access$500:97, EventQueue (java.awt)
run:709, EventQueue$3 (java.awt)
run:703, EventQueue$3 (java.awt)
doPrivileged:-1, AccessController (java.security)
doIntersectionPrivilege:74, ProtectionDomain$JavaSecurityAccessImpl (java.security)
doIntersectionPrivilege:84, ProtectionDomain$JavaSecurityAccessImpl (java.security)
run:733, EventQueue$4 (java.awt)
run:731, EventQueue$4 (java.awt)
doPrivileged:-1, AccessController (java.security)
doIntersectionPrivilege:74, ProtectionDomain$JavaSecurityAccessImpl (java.security)
dispatchEvent:730, EventQueue (java.awt)
dispatchEvent:159, TimableEventQueue (org.netbeans.core)
pumpOneEventForFilters:205, EventDispatchThread (java.awt)
pumpEventsForFilter:116, EventDispatchThread (java.awt)
pumpEventsForHierarchy:105, EventDispatchThread (java.awt)
pumpEvents:101, EventDispatchThread (java.awt)
pumpEvents:93, EventDispatchThread (java.awt)
run:82, EventDispatchThread (java.awt)

Stack trace for the helper thread:

park:-1, Unsafe (sun.misc)
park:175, LockSupport (java.util.concurrent.locks)
awaitDone:429, FutureTask (java.util.concurrent)
get:191, FutureTask (java.util.concurrent)
invokeInSwing:68, AtkUtil (org.GNOME.Accessibility)
hashCode:234, AtkObject (org.GNOME.Accessibility)
focusNotify:-1, AtkWrapper (org.GNOME.Accessibility)
dispatchFocusEvent:405, AtkWrapper (org.GNOME.Accessibility)
propertyChange:536, AtkWrapper$5 (org.GNOME.Accessibility)
fire:335, PropertyChangeSupport (java.beans)
firePropertyChange:327, PropertyChangeSupport (java.beans)
firePropertyChange:263, PropertyChangeSupport (java.beans)
firePropertyChange:768, AccessibleContext (javax.accessibility)
stateChanged:1932, JTabbedPane$AccessibleJTabbedPane (javax.swing)
fireStateChanged:132, DefaultSingleSelectionModel (javax.swing)
setSelectedIndex:67, DefaultSingleSelectionModel (javax.swing)
setSelectedIndexImpl:616, JTabbedPane (javax.swing)
setSelectedIndex:591, JTabbedPane (javax.swing)
insertTab:731, JTabbedPane (javax.swing)
addTab:767, JTabbedPane (javax.swing)
update:614, GraphBuilderDialog (org.esa.snap.graphbuilder.rcp.dialogs)
notifyObservers:159, Observable (java.util)
notifyGraphEvent:217, GraphExecuter (org.esa.snap.graphbuilder.rcp.dialogs.support)
setGraph:415, GraphExecuter (org.esa.snap.graphbuilder.rcp.dialogs.support)
access$000:56, GraphExecuter (org.esa.snap.graphbuilder.rcp.dialogs.support)
doInBackground:380, GraphExecuter$LoadGraphThread (org.esa.snap.graphbuilder.rcp.dialogs.support)
doInBackground:367, GraphExecuter$LoadGraphThread (org.esa.snap.graphbuilder.rcp.dialogs.support)
call:295, SwingWorker$1 (javax.swing)
run$$$capture:266, FutureTask (java.util.concurrent)
run:-1, FutureTask (java.util.concurrent)
run:334, SwingWorker (javax.swing)
runWorker:1149, ThreadPoolExecutor (java.util.concurrent)
run:624, ThreadPoolExecutor$Worker (java.util.concurrent)
run:748, Thread (java.lang)
#2

Many thanks for you report.
I just tried to reproduce ny opening a graoh and it worked.

But maybe @lveci can have a closer look.

#3

Thanks for replying!

By “it worked” you mean that the program worked properly and opened the graph, right? (as opposed to “the deadlock worked”)

Are you also using Debian? With Debian provided JDK or an Oracle one?

#4

Yes, the graph was proprly loaded and displayed.

No, I’m on Windows. For the JDK you should use an OpenJDK version 8. For higher versions, there can still be issues. That’s on our agenda to make SNAp compatible with the latest JDK developement.

#5

Yes, I am using OpenJDK 8. And this confirms my impression that this is something specific to Linux (because the stack trace has a few frames related to Gnome and ATK).

#6

Could siwtching to another Look and Feel help?
For example Nimbus.
You can switch in the options.
image

#7

No, nothing changes. Always freezes in the same way. Apparently it depends on the platform, but not on the LaF.

#8

For the record, the following patch works around the problem for me:

diff     --git a/snap-graph-builder/src/main/java/org/esa/snap/graphbuilder/rcp/dialogs/GraphBuilderDialog.java b/snap-graph-builder/src/main/java/org/esa/snap/graphbuilder/rcp/dialogs/GraphBuilderDialog.java
index 913366ebd..561b9ab00 100644
--- a/snap-graph-builder/src/main/java/org/esa/snap/graphbuilder/rcp/dialogs/GraphBuilderDialog.java
+++ b/snap-graph-builder/src/main/java/org/esa/snap/graphbuilder/rcp/dialogs/GraphBuilderDialog.java
@@ -400,7 +400,12 @@ public class GraphBuilderDialog extends ModelessDialog implements Observer, Grap
         final File graphFile = Dialogs.requestFileForOpen("Load Graph", false, fileFilter, LAST_GRAPH_PATH);
         if (graphFile == null) return;
 
-        loadGraph(graphFile);
+        new Thread() {
+            @Override
+            public void run() {
+                loadGraph(graphFile);
+            }
+        }.start();
     }
 
     /**

This is probably not the cleanest solution ever, though: if the thread loading the graph takes a bit longer, the user is free to mess with the interface and this might lead to inconsistencies.

#9

Thanks a lot.
Indeed it would be good to do the loading of the file off the AWT thread.