| Summary: | [Edit] Save in Compare Editor throws OperationCanceledException | ||||||
|---|---|---|---|---|---|---|---|
| Product: | [Eclipse Project] Platform | Reporter: | Tomasz Zarna <tomasz.zarna> | ||||
| Component: | Compare | Assignee: | Tomasz Zarna <tomasz.zarna> | ||||
| Status: | RESOLVED FIXED | QA Contact: | |||||
| Severity: | major | ||||||
| Priority: | P2 | CC: | cgold, daniel_megert, eric_jodet, markus.kell.r, Mike_Wilson, Olivier_Thomann, steffen.pingel, Szymon.Brandys | ||||
| Version: | 3.5 | Flags: | daniel_megert:
review+
|
||||
| Target Milestone: | 3.5 RC1 | ||||||
| Hardware: | All | ||||||
| OS: | All | ||||||
| Whiteboard: | |||||||
| Attachments: |
|
||||||
|
Description
Tomasz Zarna
Note that the save completes successfully, with the exception of the logged error. *** Bug 249755 has been marked as a duplicate of this bug. *** *** Bug 233902 has been marked as a duplicate of this bug. *** An alternative set of steps to reproduce the exception can be found on bug 233902. Given that this is not a regression introduced by bug 169386 as I initially thought, I'm removing target milestone to better match the reality, ie we are focused on fixing regressions at this stage. Dani what do you think about this one? Looking at the root cause isn't it more like a JDT bug? > Looking at the root cause isn't it more like a JDT bug? Nope, this is not JDT. > we are focused on fixing regressions at this stage. Right and this one is a regression caused by changes in Compare, though not by bug 169386 but by bug 193324. There are several issues here: 1. the worker that computes the AST is canceled by Compare and hence the exception ==> the StructureCreate has to be prepared that an OperationCanceledException is thrown by anyone that check the monitor, this (and hence the logging of the exception gets fixed by my patch). 2. createStructure is called twice for both sides on save: - once in UI thread via: org.eclipse.team.ui.mapping.SaveableComparison.doSave(IProgressMonitor) - once via org.eclipse.compare.internal.WorkerJob This is very bad for performance reasons, especially because this means 4x building an AST in case of Java compare of which two are thrown away sometimes. Created attachment 132748 [details]
Fix for problem 1
(In reply to comment #7) > 2. createStructure is called twice for both sides on save: > - once via org.eclipse.compare.internal.WorkerJob This one is called in reaction to CompareEditorInput.flushViewers() which takes place before actual save[1]. StructureDiffViewer listens for content changes[2] and does refresh when needed ie it schedules refreshTask to run asynch. [1] org.eclipse.team.internal.ui.synchronize.LocalResourceSaveableComparison.performSave(IProgressMonitor) [2] org.eclipse.compare.structuremergeviewer.StructureDiffViewer line 208 > - once in UI thread via: > org.eclipse.team.ui.mapping.SaveableComparison.doSave(IProgressMonitor) And this one is called because StructureDiffViewer is listening on compare input changes[3] which are fired later on[4] in LocalResourceSaveableComparison.performSave. [3] org.eclipse.compare.structuremergeviewer.StructureDiffViewer line 213 [4] [1] line 140 I know that this probably doesn't help much but the number of events, listeners and jobs involved in the process of saving and re-creating the structure overwhelmed me. I'm still on it, hopefully I will move forward tomorrow. *** Bug 274735 has been marked as a duplicate of this bug. *** I'll try to take a closer look at this in RC1, otherwise I will apply Dani's fix and continue the investigation during 3.6. Something changed: with I20090429-1800 I got tons of those exceptions in my .log while almost not noting them before. I suspect it now also happens when we update the structure: !ENTRY org.eclipse.ui 4 0 2009-05-05 16:21:27.052 !MESSAGE Unhandled event loop exception !STACK 0 org.eclipse.swt.SWTException: Failed to execute runnable (org.eclipse.core.runtime.OperationCanceledException) at org.eclipse.swt.SWT.error(SWT.java:3881) at org.eclipse.swt.SWT.error(SWT.java:3796) at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:137) at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:3855) at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3476) at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2405) at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2369) at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2221) at org.eclipse.ui.internal.Workbench$5.run(Workbench.java:500) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332) at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:493) at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149) at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:113) at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:194) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:110) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:79) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:368) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:179) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:559) at org.eclipse.equinox.launcher.Main.basicRun(Main.java:514) at org.eclipse.equinox.launcher.Main.run(Main.java:1311) at org.eclipse.equinox.launcher.Main.main(Main.java:1287) Caused by: org.eclipse.core.runtime.OperationCanceledException at org.eclipse.jdt.core.dom.ASTConverter.checkCanceled(ASTConverter.java:402) at org.eclipse.jdt.core.dom.ASTConverter.convert(ASTConverter.java:2643) at org.eclipse.jdt.core.dom.ASTConverter.convert(ASTConverter.java:1264) at org.eclipse.jdt.core.dom.CompilationUnitResolver.convert(CompilationUnitResolver.java:256) at org.eclipse.jdt.core.dom.ASTParser.internalCreateAST(ASTParser.java:933) at org.eclipse.jdt.core.dom.ASTParser.createAST(ASTParser.java:657) at org.eclipse.jdt.internal.ui.compare.JavaStructureCreator.createStructureComparator(JavaStructureCreator.java:294) at org.eclipse.jdt.internal.ui.compare.JavaStructureCreator.createStructureComparator(JavaStructureCreator.java:253) at org.eclipse.compare.structuremergeviewer.StructureCreator.internalCreateStructure(StructureCreator.java:102) at org.eclipse.compare.structuremergeviewer.StructureCreator.access$0(StructureCreator.java:90) at org.eclipse.compare.structuremergeviewer.StructureCreator$1.run(StructureCreator.java:80) at org.eclipse.swt.custom.BusyIndicator.showWhile(BusyIndicator.java:70) at org.eclipse.compare.internal.Utilities$4.run(Utilities.java:779) at org.eclipse.ui.internal.UILockListener.doPendingWork(UILockListener.java:155) at org.eclipse.ui.internal.UISynchronizer$3.run(UISynchronizer.java:158) at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35) at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:134) ... 23 more Maybe I find time to debug tomorrow but no promise. But this is definitely a must fix for 3.5 now. *** Bug 275034 has been marked as a duplicate of this bug. *** What is strange about the stack from Steffen (bug 275034, comment 0) is the fact it shows that there was a deferred event setting focus on compare editor and it's run after the editor was disposed. I filed bug 275153 to address the regression mentioned by Dani in comment 7 and others discovered while investigation the issue. For now, I guess we will apply patch suggested by Dani, even though it does not fix the real cause but just hides the consequences. I still don't know what change made those exception to show up so often. Dani, I'm not sure if it's fair to ask you to review your own patch... I would give it +1 if you asked me. But again, I would consider it a temporarily fix, safe enough to release now, but to be revisited during 3.6 (by addressing bug 275153). Tomasz, we need to find and fix the cause for this for 3.5 as creating two ASTs in parallel is also a performance issue. This is a P2 if not a P1 issue. I filed two separate bugs: - bug 275286 indicating similar problem when opening compare editor - bug 275289 indicating similar problem when editing in compare editor Apparently the fix from bug 275286 drastically reduces number of OCE observed by Dani in comment 12. +1 to commit the attached patch given we continue to work on the other issues like bug 275286. Thanks Dani. The patch has been released. Available in builds >=I20090511-2000. |