Bug 33271

Created attachment 10176 [details]
IDE's thread dump.

it is logger module which calls Swing from outside AWT dispatch
thread.  See

"FolderChildren_Refresh" daemon prio=1 tid=0x0x884ba60 nid=0x4112
waiting for monitor entry [be9fe000..be9ff880]
	at java.awt.Container.invalidateTree(Container.java:1113)
	- waiting to lock <0x44a154f0> (a java.awt.Component$AWTTreeLock)
	at java.awt.Container.setFont(Container.java:1145)
	at javax.swing.JComponent.setFont(JComponent.java:2307)
	at javax.swing.LookAndFeel.installColorsAndFont(LookAndFeel.java:89)
	at
javax.swing.plaf.basic.BasicButtonUI.installDefaults(BasicButtonUI.java:124)
	at
javax.swing.plaf.metal.MetalButtonUI.installDefaults(MetalButtonUI.java:53)
	at javax.swing.plaf.basic.BasicButtonUI.installUI(BasicButtonUI.java:60)
	at javax.swing.JComponent.setUI(JComponent.java:449)
	at javax.swing.AbstractButton.setUI(AbstractButton.java:1594)
	at javax.swing.JButton.updateUI(JButton.java:119)
	at javax.swing.AbstractButton.init(AbstractButton.java:1930)
	at javax.swing.JButton.<init>(JButton.java:109)
	at javax.swing.JButton.<init>(JButton.java:82)
	at org.netbeans.core.LoggerButton.initialize(LoggerButton.java:76)
	at org.netbeans.core.LoggerButton.addLogButton(LoggerButton.java:89)
	at
org.netbeans.modules.sim.bugsubmitter.ui.BugsubmitterErrorManager.notify(BugsubmitterErrorManager.java:204)
	- locked <0x44c5dec8> (a
org.netbeans.modules.sim.bugsubmitter.ui.BugsubmitterErrorManager)
	at
org.openide.ErrorManager$DelegatingErrorManager.notify(ErrorManager.java:390)
	at org.openide.loaders.InstanceNode.initName(InstanceNode.java:259)
	at org.openide.loaders.InstanceNode.<init>(InstanceNode.java:78)
	at org.openide.loaders.InstanceNode.<init>(InstanceNode.java:64)
	at
org.openide.loaders.InstanceDataObject.createNodeDelegateImpl(InstanceDataObject.java:463)
	at
org.openide.loaders.InstanceDataObject.createNodeDelegate(InstanceDataObject.java:412)
	at org.openide.loaders.DataObject$1.run(DataObject.java:242)
	- locked <0x442e3a88> (a java.lang.Object)
	at org.openide.util.Mutex.readAccess(Mutex.java:239)
	at org.openide.loaders.DataObject.getNodeDelegate(DataObject.java:238)
	at
org.openide.loaders.DataObject.getClonedNodeDelegate(DataObject.java:263)
	at org.openide.loaders.FolderChildren.createNodes(FolderChildren.java:132)
	at org.openide.nodes.Children$Keys$KE.nodes(Children.java:1983)
	at org.openide.nodes.ChildrenArray.nodesFor(ChildrenArray.java:109)
	at org.openide.nodes.Children$Info.nodes(Children.java:1077)
	at org.openide.nodes.Children.updateAdd(Children.java:885)
	at org.openide.nodes.Children.setEntries(Children.java:672)
	at org.openide.nodes.Children$3.run(Children.java:1874)
	at org.openide.util.Mutex.postRequest(Mutex.java:875)
	at org.openide.util.Mutex.postWriteRequest(Mutex.java:375)
	at org.openide.nodes.Children$Keys.applyKeys(Children.java:1882)
	at org.openide.nodes.Children$Keys.setKeys(Children.java:1841)
	at org.openide.loaders.FolderChildren.access$501(FolderChildren.java:32)
	at
org.openide.loaders.FolderChildren$ChildrenRefreshRunnable.run(FolderChildren.java:250)
	at org.openide.util.Task.run(Task.java:136)
	at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:328)
	at
org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:670)

I guess you meant the 'sim' module, not 'logger'. Reassigning.

I have not been able to actually cause this deadlock in several
attempts (setting an internal executor and calling notify with
ErrorLevel of Informational from a new thread hasn't caused it).  I
was hoping that the reporter (or some other party) could assist in
providing a test case or showing a way to reliably reproduce this issue.

An alternate (less desirable) solution is to provide an nbm with the
proposed fix should the issue prove reliably reproducible in only one
environment.


Proposed fix:
As far as this thread dump can indicate, it seems that the
construction of the LoggerButton in the LoggerButton.initialize()
method is causing this locking issue, so pushing the construction of
the Button to the AWT Event Thread using an invokeLater runnable is
the proposed solution:

Diff:
cvs diff -uw LoggerButton.java
Index: LoggerButton.java
===================================================================
RCS file: /cvs/sim/bugsubmitter/src/org/netbeans/core/LoggerButton.java,v
retrieving revision 1.6.2.1
diff -u -w -r1.6.2.1 LoggerButton.java
--- LoggerButton.java   10 Mar 2003 17:33:32 -0000      1.6.2.1
+++ LoggerButton.java   29 Apr 2003 21:35:24 -0000
@@ -71,11 +71,15 @@
         if (initialized) 
                return;
 
-        ResourceBundle b;
-       b =
ResourceBundle.getBundle("org/netbeans/modules/sim/bugsubmitter/ui/Bundle");
// NOI18N
+        final ResourceBundle b =
ResourceBundle.getBundle("org/netbeans/modules/sim/bugsubmitter/ui/Bundle");
// NOI18N
+        javax.swing.SwingUtilities.invokeLater(new Runnable() {
+            public void run() {
         log = new JButton(b.getString("LBL_LOG_REPORT")); // NOI18N
        
log.setMnemonic(b.getString("LBL_LOG_REPORT_MNEMONIC").charAt(0)); //
NOI18N
         log.addActionListener(new LoggerButton());
+       }
+});
+
 
        Class tmp = BugsubmitterWizardAction.class;
        bswa = (BugsubmitterWizardAction)
BugsubmitterWizardAction.get(tmp);

I'm probably just showing my ignorance here, but I though
it was okay to construct Swing objects outside the event
thread.  I thought the only problem was accessing them after
they were realized (in the X11 sense of that word).  The SIM
code in question only constructs a button, it doesn't realize
it until it is on the AWT thread.  Never the less, it should
be harmless to run that code in an invokeLater(), so we probably
should go ahead and do that.

Also, the AWT thread seems to be hung up trying to get a 
read lock on the children of some nodes in the 
component palette (um, I think...)  At first sight, that
doesn't seem to be anything to do with the kind of Swing
lossage one would expect from a bug which accessed Swing
from the wrong thread.  But of course, there may be some
connection I don't see.  I'd welcome further comments on
that...

I agree with Terry's statement that the construction of a 
GUI object without displaying that object seems to be the 
sort of thing one *should* be able to do without being on 
the event thread, and it does seem innoculous to create 
the JButton in invokeLater...

I'd like to define more clearly the test case that causes 
this issue or have some notion about how it is reproduced, 
otherwise the proposed fix cannot be confirmed as a 
resolution to this issue.

Has anyone been able to reliably cause this to occur?

Could any of core developers with expertise in AWT/Swing respond to
Terry's and Ethan's comments? Creating a not yet displayed button from
a non-AWT thread should be perfectly safe, shouldn't it? Is this the
real cause of the problem?

To Eman: are you able to reproduce reliably/often? Can you provide a
more specific test case?

I don't think Ethan's fix should go into release35 until there is a
clear understanding of the problem.

I reproduced it only twice. In both cases I only started IDE into
Editing workspace with several forms opened in GUI Editing workspace.
Then I switched to GUI Editing workspace and the deadlock occured.

"Creating a not yet displayed button from a non-AWT thread should be
perfectly safe, shouldn't it?"
I thought that too, but unfortunately it's not true, especially in
Netbeans context.
Correct sentence is "Creating and manipulating of not yet realized
swing controls from a non-AWT thread is legal." Nothing about that
it's safe, unfortunately.

Problem is that swing control constructor code often locks
java.awt.Component$AWTTreeLock. I thought that it is kind of violation
of Swing thread model, and I filled in bugtraq bug #4833969.
But JDK engineers say that such code is valid.

Result: You *can* manipulate not-yet realized swing controls in
non-AWT thread, but you have to be sure (to be safe) that:
1) AWT thread will not wait for completion of the thread where swing
controls are being constructed.
2) You don't manipulate swing controls in non-AWT thread under some
public lock that code in AWT thread can lock as well.

When you translate above to the Netbens context, result is: In currect
Netbeans threading model, you can't safely build and construct swing
components in request processor threads.

So above proposed patch is AFAIK only easy way how to correct this
problem now.

CCing thread guru Jesse in case I'm wrong.

Basically agree with David's summary. Small refinement: it should be
safe to build an unrealized Swing component in a request processor
thread if you posted the top runnable to it, because then you know
there are no held locks which AWT code might try to grab.

Because of the way the LoggerButton code is meant to work, and the
multiple uses of initialize, the proposed fix needs to be modified
such that:
0) No changes are made to initialize()

1) In ensureButtonRegistered() we check to see if we are AWT EDT and
if not use an invokeAndWait to actually ensure we register the button
before returning.

2) Move the call to initialize() inside the invokeLater() runnable
already in the addLoggerButton method to ensure initialization of the
log button prior to use.

If this seems acceptable it will be committed on 4/31

Just be careful with invokeAndWait - you need to ensure that you are
not holding any locks when you call it, or you can produce a different
deadlock!

The case where we would do the invokeAndWait() is from the
actionPerformed() of a CallableSystemAction subclass.
It looks like it is running on a RequestProcessor thread
(Module-Actions).  I looked at openide/doc-files/threading.html
where it says "Actions which definitely require the event thread
should use it".  Does this imply that it is okay to call
invokeAndWait() in these circumstances? I'm not entirely
clear what that sentence is saying (probably my fault, sorry...)

Yes, actions invoked by the ActionManager are run in a private request
processor with no external locks held, so that is OK.

Created attachment 10204 [details]
proposed patch #2

Proposed fix #2 committed to nevada branch and trunk.

TM -> 'S1S 5'.

Verified.