Bug 506090 - [jobs] UILockListener should report error if interrupting UI thread
Summary: [jobs] UILockListener should report error if interrupting UI thread
Status: RESOLVED FIXED
Alias: None
Product: Platform
Classification: Eclipse Project
Component: UI (show other bugs)
Version: 3.8.2   Edit
Hardware: All All
: P3 normal (vote)
Target Milestone: 4.7 M3   Edit
Assignee: Andrey Loskutov CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-10-17 10:26 EDT by Andrey Loskutov CLA
Modified: 2018-04-30 05:29 EDT (History)
1 user (show)

See Also:


Attachments
example plugin which can be used to play with the problem (6.07 KB, application/zip)
2016-10-17 10:49 EDT, Andrey Loskutov CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Andrey Loskutov CLA 2016-10-17 10:26:41 EDT
Follow up on bug 94452 & Co.

UILockListener can interrupt UI thread execution at any time if UI joins on some job or owns an ILock and NON-UI thread tries to call into UI with Display.syncExec(). Because the interruption can happen in *any* code (like in bug 94452), it may break *any* operation. It is really hard to debug and in real live almost impossible to reproduce if one has no idea *who* interrupts the operation.

I'm not discussing here the usefulness of this feature, but *if* UILockListener interrupts UI thread, it should at least log this, so that we can understand why some absolutely innocent and unrelated code fail.

I have a patch.
Comment 1 Eclipse Genie CLA 2016-10-17 10:37:27 EDT
New Gerrit change created: https://git.eclipse.org/r/83370
Comment 2 Andrey Loskutov CLA 2016-10-17 10:49:20 EDT
Created attachment 264896 [details]
example plugin which can be used to play with the problem

An example log reported now by the workbench with attached plugin:

!ENTRY org.eclipse.ui 2 2 2016-10-17 16:48:10.106
!MESSAGE To avoid deadlock while executing Display.syncExec() with argument: testinterruptionlogging.handlers.SampleHandler$1$$Lambda$115/1538490820@41dace3, thread Worker-17 will interrupt UI thread.
!STACK 0
java.lang.IllegalStateException
	at org.eclipse.ui.internal.UILockListener.reportInterruption(UILockListener.java:206)
	at org.eclipse.ui.internal.UILockListener.interruptUI(UILockListener.java:178)
	at org.eclipse.ui.internal.UISynchronizer.syncExec(UISynchronizer.java:162)
	at org.eclipse.swt.widgets.Display.syncExec(Display.java:5442)
	at testinterruptionlogging.handlers.SampleHandler$1.run(SampleHandler.java:28)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)
!SUBENTRY 1 org.eclipse.ui 2 1 2016-10-17 16:48:10.106
!MESSAGE Worker-17 thread is an instance of Worker or owns an ILock Stack: 
"Worker-17" Id=63 RUNNABLE
	at sun.management.ThreadImpl.dumpThreads0(Native Method)
	at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:448)
	at org.eclipse.ui.internal.UILockListener.reportInterruption(UILockListener.java:208)
	at org.eclipse.ui.internal.UILockListener.interruptUI(UILockListener.java:178)
	at org.eclipse.ui.internal.UISynchronizer.syncExec(UISynchronizer.java:162)
	at org.eclipse.swt.widgets.Display.syncExec(Display.java:5442)
	at testinterruptionlogging.handlers.SampleHandler$1.run(SampleHandler.java:28)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)


!SUBENTRY 1 org.eclipse.ui 2 1 2016-10-17 16:48:10.106
!MESSAGE UI thread waits on a lock. Stack: 
"main" Id=1 TIMED_WAITING on org.eclipse.core.internal.jobs.Semaphore@3017a48b
	at java.lang.Object.wait(Native Method)
	-  waiting on org.eclipse.core.internal.jobs.Semaphore@3017a48b
	at org.eclipse.core.internal.jobs.Semaphore.acquire(Semaphore.java:39)
	at org.eclipse.core.internal.jobs.JobManager.join(JobManager.java:909)
	at org.eclipse.core.internal.jobs.InternalJob.join(InternalJob.java:341)
	at org.eclipse.core.runtime.jobs.Job.join(Job.java:524)
	at testinterruptionlogging.handlers.SampleHandler.execute(SampleHandler.java:34)
	at org.eclipse.ui.internal.handlers.HandlerProxy.execute(HandlerProxy.java:295)
	at org.eclipse.ui.internal.handlers.E4HandlerProxy.execute(E4HandlerProxy.java:90)
Comment 4 Andrey Loskutov CLA 2016-10-18 08:25:31 EDT
(In reply to Eclipse Genie from comment #3)
> Gerrit change https://git.eclipse.org/r/83370 was merged to [master].
> Commit:
> http://git.eclipse.org/c/platform/eclipse.platform.ui.git/commit/
> ?id=cae8610165ab8314344004db6128e506afbed321

I'm keeping the bug open to see if the logged error will break some tests outside of Platform UI testsuite during the nightly SDK build. E.g. there could be some error log listener which would let a test to fail if it would detect an error reported during the test (like we have it in our tests at Advantest).
Comment 5 Andrey Loskutov CLA 2016-10-19 08:48:57 EDT
At least with http://download.eclipse.org/eclipse/downloads/drops4/I20161018-0800/testResults.php I can't see any regressions related to this => closing.
Comment 6 Andrey Loskutov CLA 2016-10-24 15:13:29 EDT
I've got my first real life example of such interruption report, and now I see something I've missed before: the reported stack traces should not be reported via "message" arguments in IStatus objects, because it seems that some clever code in there truncates longer messages and only few top method calls appear in the log file. An example is here: bug 506463. In worst case most important content will be just truncated, and this is not nice.

Instead, we should construct real exception objects and pass *them* to the status object. The patch is trivial, I will provide is ASAP.
Comment 7 Eclipse Genie CLA 2016-10-24 15:16:25 EDT
New Gerrit change created: https://git.eclipse.org/r/83818
Comment 9 Laurian CLA 2018-04-30 05:02:57 EDT
We are being flooded with this error when using MessageDialog.openQuestion to ask user a question from worker thread. Our application works fine, just lots of error messages in the log. What are we doing wrong here ?
Comment 10 Andrey Loskutov CLA 2018-04-30 05:29:39 EDT
(In reply to Laurian from comment #9)
> We are being flooded with this error when using MessageDialog.openQuestion
> to ask user a question from worker thread. Our application works fine, just
> lots of error messages in the log. What are we doing wrong here ?

Please ask such questions on a forum, not a bug. Beside this, two things should happen to produce an error (from my memory): UI joins on some job and some job wants to use syncExec. Both things are in general smells of a bad application design. So you should try to avoid joining from UI thread and / or avoid using syncExec from jobs.