Bug 561416 - Invalid thread access on rename compilation unit
Summary: Invalid thread access on rename compilation unit
Status: VERIFIED FIXED
Alias: None
Product: JDT
Classification: Eclipse Project
Component: UI (show other bugs)
Version: 4.14   Edit
Hardware: All All
: P3 normal (vote)
Target Milestone: 4.16 M3   Edit
Assignee: Mickael Istria CLA
QA Contact:
URL:
Whiteboard:
Keywords: regression
: 164643 563000 (view as bug list)
Depends on:
Blocks:
 
Reported: 2020-03-24 11:18 EDT by Kenneth Styrberg CLA
Modified: 2020-05-09 13:20 EDT (History)
9 users (show)

See Also:


Attachments
Thread access error (9.56 KB, image/png)
2020-03-24 11:18 EDT, Kenneth Styrberg CLA
no flags Details
Eclipse error log (105.10 KB, text/plain)
2020-03-24 11:25 EDT, Kenneth Styrberg CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Kenneth Styrberg CLA 2020-03-24 11:18:21 EDT
Created attachment 282207 [details]
Thread access error

Eclipse 2020-03

- Enable rename option "Update fully qualified names in non-Java text files..."
- In editor do a inline rename, (Alt+Shift+R)
- The rename dialog appear, and also the error dialog stating the thread access error.
Comment 1 Andrey Loskutov CLA 2020-03-24 11:20:48 EDT
Please attach error *log*.
Comment 2 Kenneth Styrberg CLA 2020-03-24 11:25:38 EDT
Created attachment 282208 [details]
Eclipse error log

Log as requested!
Comment 3 Andrey Loskutov CLA 2020-03-26 10:03:37 EDT
Thanks for the log, I can't reproduce and the log doesn't show the root cause (except the obvious issue with StatusLine monitor operated from non UI thread).

Can you please provide a small self containing project with the files affected in refactoring and exact steps to produce the error?
Comment 4 Kenneth Styrberg CLA 2020-03-26 11:29:11 EDT
I'm working in 'eclipse.jdt.ui' project and see this problem when renaming a class inline. 

Did you enable rename option "Update fully qualified names in non-Java text files..."? Because if it's disabled I see no error.


I'll see if I can create a small project with same problem.
Comment 5 Kenneth Styrberg CLA 2020-03-26 11:36:31 EDT
Ok, I've tested with a new project and cannot reproduce. If I import existing project 'eclipse.jdt.ui' into new workspace I see the problem again. 

Can it be connected to how many classes affected by rename?
Comment 6 Andrey Loskutov CLA 2020-03-26 12:10:12 EDT
(In reply to Kenneth Styrberg from comment #5)
> Ok, I've tested with a new project and cannot reproduce. If I import
> existing project 'eclipse.jdt.ui' into new workspace I see the problem
> again. 
> 
> Can it be connected to how many classes affected by rename?

I assume that some non java resource in the old project was the trigger.
Comment 7 Fabrice Tiercelin CLA 2020-04-07 15:20:26 EDT
I reproduce it renaming AbstractMultiFix on:
I20200407-0120
Eclipse 2020-03
I20191124
I20191110-1800

But I don't reproduce on:
I20190909-1520
Eclipse 2019-09
Comment 8 Andrey Loskutov CLA 2020-04-14 05:32:19 EDT
(In reply to Fabrice Tiercelin from comment #7)
> I reproduce it renaming AbstractMultiFix on:
> I20200407-0120
> Eclipse 2020-03
> I20191124
> I20191110-1800
> 
> But I don't reproduce on:
> I20190909-1520
> Eclipse 2019-09

Thanks, this is useful, probably we observe a side effect of bug 540953, more concrete patch https://git.eclipse.org/r/#/c/147600/ .

The change replaced SubProgressMonitor with SubMonitor in Workspace.run(), there seem to be a difference how the progress is reported, because the code in the actual stack below is unchanged since years

org.eclipse.swt.SWTException: Invalid thread access
	at org.eclipse.swt.SWT.error(SWT.java:4723)
	at org.eclipse.swt.SWT.error(SWT.java:4638)
	at org.eclipse.swt.SWT.error(SWT.java:4609)
	at org.eclipse.swt.widgets.Widget.error(Widget.java:550)
	at org.eclipse.swt.widgets.Widget.checkWidget(Widget.java:471)
	at org.eclipse.swt.widgets.Control.getForeground(Control.java:3118)
	at org.eclipse.jface.action.StatusLine.updateMessageLabel(StatusLine.java:681)
	at org.eclipse.jface.action.StatusLine.setMessage(StatusLine.java:559)
	at org.eclipse.jface.action.StatusLine.setMessage(StatusLine.java:545)
	at org.eclipse.jface.action.StatusLine.subTask(StatusLine.java:641)
	at org.eclipse.jface.action.StatusLineManager$1.subTask(StatusLineManager.java:192)
	at org.eclipse.core.runtime.SubMonitor$RootInfo.subTask(SubMonitor.java:255)
	at org.eclipse.core.runtime.SubMonitor.subTask(SubMonitor.java:667)
	at org.eclipse.core.runtime.ProgressMonitorWrapper.subTask(ProgressMonitorWrapper.java:168)
	at org.eclipse.core.runtime.SubProgressMonitor.subTask(SubProgressMonitor.java:197)
	at org.eclipse.core.runtime.ProgressMonitorWrapper.subTask(ProgressMonitorWrapper.java:168)
	at org.eclipse.core.runtime.SubProgressMonitor.subTask(SubProgressMonitor.java:197)
	at org.eclipse.core.runtime.ProgressMonitorWrapper.subTask(ProgressMonitorWrapper.java:168)
	at org.eclipse.core.runtime.SubProgressMonitor.subTask(SubProgressMonitor.java:197)
	at org.eclipse.search.internal.core.text.TextSearchVisitor$1.run(TextSearchVisitor.java:364)
	at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)

I assume changes in  bug 540953 uncovered old problem with StatusLine passed as ProgressMonitor (wrapped through few another monitors) to TextSearchVisitor (which is executed in background).

The stack where the text search is created (with offending monitor) is:

org.eclipse.jdt.internal.corext.refactoring.util.QualifiedNameFinder.process(QualifiedNameFinder.java:129),
org.eclipse.jdt.internal.corext.refactoring.rename.RenameTypeProcessor.computeQualifiedNameMatches(RenameTypeProcessor.java:1215),
org.eclipse.jdt.internal.corext.refactoring.rename.RenameTypeProcessor.doCheckFinalConditions(RenameTypeProcessor.java:580),
org.eclipse.jdt.internal.corext.refactoring.rename.JavaRenameProcessor.checkFinalConditions(JavaRenameProcessor.java:51),
org.eclipse.ltk.core.refactoring.participants.ProcessorBasedRefactoring.checkFinalConditions(ProcessorBasedRefactoring.java:226),
org.eclipse.ltk.core.refactoring.CheckConditionsOperation.run(CheckConditionsOperation.java:86),
org.eclipse.ltk.core.refactoring.CreateChangeOperation.run(CreateChangeOperation.java:122),
org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2292),
org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2317),
org.eclipse.ltk.internal.ui.refactoring.WorkbenchRunnableAdapter.run(WorkbenchRunnableAdapter.java:89),
org.eclipse.jface.operation.ModalContext.runInCurrentThread(ModalContext.java:436),
org.eclipse.jface.operation.ModalContext.run(ModalContext.java:352),
org.eclipse.ui.internal.WorkbenchWindow.lambda$5(WorkbenchWindow.java:2375),
org.eclipse.swt.custom.BusyIndicator.showWhile(BusyIndicator.java:72),
org.eclipse.ui.internal.WorkbenchWindow.run(WorkbenchWindow.java:2373),
org.eclipse.ltk.ui.refactoring.RefactoringWizard.createChange(RefactoringWizard.java:662),
org.eclipse.ltk.ui.refactoring.RefactoringWizard.computeUserInputSuccessorPage(RefactoringWizard.java:504),
org.eclipse.ltk.ui.refactoring.RefactoringWizard.getStartingPage(RefactoringWizard.java:476),
org.eclipse.ltk.internal.ui.refactoring.RefactoringWizardDialog2.createContents(RefactoringWizardDialog2.java:611),
org.eclipse.jface.window.Window.create(Window.java:431),
org.eclipse.jface.dialogs.Dialog.create(Dialog.java:1094),
org.eclipse.ltk.ui.refactoring.RefactoringWizardOpenOperation.lambda$0(RefactoringWizardOpenOperation.java:181),
org.eclipse.swt.custom.BusyIndicator.showWhile(BusyIndicator.java:72),
org.eclipse.ltk.ui.refactoring.RefactoringWizardOpenOperation.run(RefactoringWizardOpenOperation.java:209),
org.eclipse.ltk.ui.refactoring.RefactoringWizardOpenOperation.run(RefactoringWizardOpenOperation.java:126),
org.eclipse.jdt.internal.ui.refactoring.actions.RefactoringStarter.activate(RefactoringStarter.java:41),
org.eclipse.jdt.internal.ui.refactoring.UserInterfaceStarter.activate(UserInterfaceStarter.java:65),
org.eclipse.jdt.internal.ui.refactoring.reorg.RenameUserInterfaceStarter.activate(RenameUserInterfaceStarter.java:35),
org.eclipse.jdt.ui.refactoring.RenameSupport.openDialog(RenameSupport.java:163),
org.eclipse.jdt.internal.ui.refactoring.reorg.RenameLinkedMode.doRename(RenameLinkedMode.java:369),
org.eclipse.jdt.internal.ui.refactoring.reorg.RenameLinkedMode$EditorSynchronizer.left(RenameLinkedMode.java:125),
org.eclipse.jface.text.link.LinkedModeModel.exit(LinkedModeModel.java:338),
org.eclipse.jface.text.link.LinkedModeUI.lambda$2(LinkedModeUI.java:1172),
org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:40),
org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:185),
org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4928),
org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:4449),
Comment 9 Stephan Herrmann CLA 2020-04-14 06:14:53 EDT
I tested eclipse-SDK-I20190919-0850-linux-gtk-x86_64 like this:

Import org.eclipse.jdt.ui
Set target platform to 4.16 M1

Start a rename to enable "Update fully qualified names in non-Java text files..."

Cancel

Open CreateRefactoringScriptAction in an editor

Select the name and hit Alt+Shift+R

Enter a new name and hit Enter

Result: Rename Type dialog showing a change in plugin.xml

No error.
Comment 10 Andrey Loskutov CLA 2020-04-14 08:29:53 EDT
In 4.13 the *root* monitor object used by TextSearchVisitor is org.eclipse.jface.operation.AccumulatingProgressMonitor, and NOT the StatusLineManager$1.

Put a breakpoint in org.eclipse.ltk.internal.ui.refactoring.WorkbenchRunnableAdapter.run(IProgressMonitor).

In 4.13 we have AccumulatingProgressMonitor, in 4.14+ the monitor is org.eclipse.jface.action.StatusLineManager$1.

The first one doesn't access SWT widgets and can be used from non-UI threads, the last doing that and crashes if not running in UI thread.

The change is coming from bug 550560 patch https://git.eclipse.org/r/#/c/150517/, reverting change on this line below fixes the problem:

https://git.eclipse.org/r/#/c/150517/33/org.eclipse.ltk.ui.refactoring/src/org/eclipse/ltk/ui/refactoring/RefactoringWizard.java@664
Comment 11 Mickael Istria CLA 2020-04-14 09:56:58 EDT
(In reply to Andrey Loskutov from comment #10)
> In 4.13 we have AccumulatingProgressMonitor, in 4.14+ the monitor is
> org.eclipse.jface.action.StatusLineManager$1.
> The first one doesn't access SWT widgets and can be used from non-UI
> threads, the last doing that and crashes if not running in UI thread.
> The change is coming from bug 550560 patch
> https://git.eclipse.org/r/#/c/150517/, reverting change on this line below
> fixes the problem:
> https://git.eclipse.org/r/#/c/150517/33/org.eclipse.ltk.ui.refactoring/src/
> org/eclipse/ltk/ui/refactoring/RefactoringWizard.java@664

Thanks for the deep check Andrey!
What do you think is the best solution here? Do you think we should try to make the methods from StatusLine which are coming from IProgressMonitor runnable in non-UI Thread (ie check current display and if not same as widget one, wrap code in getDisplay().asyncExec(...) )?
Comment 12 Andrey Loskutov CLA 2020-04-14 10:17:15 EDT
Note: to reproduce, create *any* *plugin* project that has both java and non-java files.

Create two breakpoints in org.eclipse.search.internal.core.text.TextSearchVisitor.search(IFile[], IProgressMonitor):

First breakpoint at line 427 (at monitorUpdateJob.cancel(); )

and second at line 364 (at  fProgressMonitor.subTask(Messages.format(SearchMessages.TextSearchVisitor_scanning, args));)

Select java class name, use Alt+Shift+R for inline rename, click on "Options", enable "Update fully qualified names in non-Java text files...", Cancel.

Use Alt+Shift+R second time, change type name and enjoy the error.

The problem with reproducing it is due the timing constraints: if the refactoring is fast enough, monitorUpdateJob.cancel() wins the race and second job will not report progress via fProgressMonitor.subTask(), and so will not report the error.

The right fix would either make sure org.eclipse.search.internal.core.text.TextSearchVisitor.search(IFile[], IProgressMonitor) never receives a monitor that needs UI access, or never uses it inside monitorUpdateJob to report anything, or that StatusLine doesn't do anything SWT related if called from non-UI thread.

Regarding the original change that caused this bug in:

https://git.eclipse.org/r/#/c/150517/33/org.eclipse.ltk.ui.refactoring/src/org/eclipse/ltk/ui/refactoring/RefactoringWizard.java@664

I'm not sure, since I'm not in the refactoring business: changing unconditional "fork = true" to fork = context != PlatformUI.getWorkbench().getActiveWorkbenchWindow() could be dangerous as we see. The old code existed since 2004, so we are touching something that clients could have used for a long time (code is over 16 years old), and may rely on existing behavior of few refactoring wizard operations (should it run in same thread or not == will it be blocking or not). Not sure if that was intended / understood during the fix for bug 550560.
Comment 13 Mickael Istria CLA 2020-04-14 11:17:55 EDT
(In reply to Andrey Loskutov from comment #12)
> https://git.eclipse.org/r/#/c/150517/33/org.eclipse.ltk.ui.refactoring/src/
> org/eclipse/ltk/ui/refactoring/RefactoringWizard.java@664
> I'm not sure, since I'm not in the refactoring business

This comes as an echo of https://git.eclipse.org/r/#/c/150517/33/org.eclipse.ltk.ui.refactoring/src/org/eclipse/ltk/internal/ui/refactoring/actions/RenameResourceHandler.java@121

> changing
> unconditional "fork = true" to fork = context !=
> PlatformUI.getWorkbench().getActiveWorkbenchWindow() could be dangerous as
> we see. The old code existed since 2004, so we are touching something that
> clients could have used for a long time (code is over 16 years old), and may
> rely on existing behavior of few refactoring wizard operations (should it
> run in same thread or not == will it be blocking or not). Not sure if that
> was intended / understood during the fix for bug 550560.

I think the risk was just not identified/missed and it can (and probably does) cause some issues in some refactoring wizards as the default context used in computeUserInputSuccessorPage when invoking createChange is actually... PlatformUI.getWorkbench().getActiveWorkbenchWindow() since bug 283427 / commit a11e0cfdd145662338bcd0dae45d07168e39eb70 (which could also by itself be a cause of error as the default context should probably be the container when set and not overriden otherwise, but it's not the topic here).

From here, I suggest we investigate 2 fixes:
1. we make the StatusLine widget nicer when used as a progress monitor out of the UI Thread, by checking the current Display to decide whether to just run the code or wrap them to some Display.asyncExec (this is the suggestion from my previous comment)
2. we revert the change in RefactoringDialog, and create a dummy non-forking, non-reporting IRunnableContext from RenameHandler that just ignore the "fork" and run code in current thread.

Does that seem fine?
Comment 14 Andrey Loskutov CLA 2020-04-14 11:41:33 EDT
(In reply to Mickael Istria from comment #13)
> From here, I suggest we investigate 2 fixes:
> 1. we make the StatusLine widget nicer when used as a progress monitor out
> of the UI Thread, by checking the current Display to decide whether to just
> run the code or wrap them to some Display.asyncExec (this is the suggestion
> from my previous comment)

Yes. Note: some calls do not access SWT, so do not require any checks / async execs. Also note, async execs from monitor could flood SWT event queue. Probably just not doing anything being used from a wrong thread (if possible) would be the right thing, may be with some tracing option to see who does that.

> 2. we revert the change in RefactoringDialog, and create a dummy
> non-forking, non-reporting IRunnableContext from RenameHandler that just
> ignore the "fork" and run code in current thread.

Sounds good, but as said, I'm not really in that business.

> Does that seem fine?

Yep. Do you plan to work on that?
Comment 15 Andrew Obuchowicz CLA 2020-04-14 14:03:52 EDT
Just an update: I'm working on Mickael's second suggestion which seems to fix the issue. I need to clean up my patch a bit but will be submitting it soon enough.
Comment 16 Eclipse Genie CLA 2020-04-14 15:23:04 EDT
New Gerrit change created: https://git.eclipse.org/r/160939
Comment 17 Eclipse Genie CLA 2020-04-14 16:57:29 EDT
New Gerrit change created: https://git.eclipse.org/r/160944
Comment 20 Mickael Istria CLA 2020-04-15 16:20:12 EDT
Thanks Andrew for the patch, and thanks a lot Andrey for all the analysis and review, you really did the hardest part here!
Comment 21 Karsten Thoms CLA 2020-04-20 16:10:07 EDT
*** Bug 164643 has been marked as a duplicate of this bug. ***
Comment 22 Andrey Loskutov CLA 2020-05-09 13:20:26 EDT
*** Bug 563000 has been marked as a duplicate of this bug. ***