Community
Participate
Working Groups
4.11M1 Saving GIT\org.eclipse.ocl\plugins\org.eclipse.ocl.pivot\emf-gen\org\eclipse\ocl\pivot\PivotPackage.java locks out the UI for 70 seconds. Measured by observing the time that the wait cursor is a timer and for the Build Workspace in the Progress View to advance from Waiting. At the time of save, the 38000 line auto-generated EMF file, i.e. substantially auto-commented, has a single redundant end of line space for the default order imports, additional save actions to go to work on. While a 38,000 line file is unlikely to save instantly, surely it shouldn't take significantly longer than a compile which is fast. Bug 1: Save should not lock out UI. Bug 2: Save should not be devastatingly slow.
Ed, if you report UI freezes, please always attach 2-3 jstack dumps?
I took three thread dumps at about 5 second intervals. Each was similar to the trace below (in the JavaIndenter). Why is a time-consuming activity such as indentation happening on the UI thread? Why is indentation so SLOW? "main" #1 prio=6 os_prio=0 tid=0x0000000002a23800 nid=0x9fc runnable [0x00000000029ba000] java.lang.Thread.State: RUNNABLE at org.eclipse.jdt.internal.ui.text.JavaHeuristicScanner.previousToken(JavaHeuristicScanner.java:437) at org.eclipse.jdt.internal.ui.text.JavaIndenter.nextToken(JavaIndenter.java:1994) at org.eclipse.jdt.internal.ui.text.JavaIndenter.nextToken(JavaIndenter.java:1983) at org.eclipse.jdt.internal.ui.text.JavaIndenter.isTryWithResources(JavaIndenter.java:1272) at org.eclipse.jdt.internal.ui.text.JavaIndenter.findReferencePosition(JavaIndenter.java:1040) at org.eclipse.jdt.internal.ui.text.JavaIndenter.findReferencePosition(JavaIndenter.java:830) at org.eclipse.jdt.internal.ui.text.JavaIndenter.getReferenceIndentation(JavaIndenter.java:456) at org.eclipse.jdt.internal.ui.text.JavaIndenter.computeIndentation(JavaIndenter.java:489) at org.eclipse.jdt.internal.ui.text.JavaIndenter.computeIndentation(JavaIndenter.java:475) at org.eclipse.jdt.internal.ui.actions.IndentAction.computeReplaceData(IndentAction.java:353) at org.eclipse.jdt.internal.ui.actions.IndentAction.indent(IndentAction.java:271) at org.eclipse.jdt.internal.corext.fix.CodeFormatFix.createCleanUp(CodeFormatFix.java:148) at org.eclipse.jdt.internal.ui.fix.CodeFormatCleanUp.createFix(CodeFormatCleanUp.java:64) at org.eclipse.jdt.internal.corext.fix.CleanUpRefactoring.calculateChange(CleanUpRefactoring.java:792) at org.eclipse.jdt.internal.corext.fix.CleanUpPostSaveListener.saved(CleanUpPostSaveListener.java:390) at org.eclipse.jdt.internal.ui.javaeditor.CompilationUnitDocumentProvider$5.run(CompilationUnitDocumentProvider.java:1639) at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45) at org.eclipse.jdt.internal.ui.javaeditor.CompilationUnitDocumentProvider.notifyPostSaveListeners(CompilationUnitDocumentProvider.java:1633) at org.eclipse.jdt.internal.ui.javaeditor.CompilationUnitDocumentProvider.commitWorkingCopy(CompilationUnitDocumentProvider.java:1413) at org.eclipse.jdt.internal.ui.javaeditor.CompilationUnitDocumentProvider$4.execute(CompilationUnitDocumentProvider.java:1491) at org.eclipse.ui.editors.text.TextFileDocumentProvider$DocumentProviderOperation.run(TextFileDocumentProvider.java:133) at org.eclipse.ui.actions.WorkspaceModifyDelegatingOperation.execute(WorkspaceModifyDelegatingOperation.java:71) at org.eclipse.ui.actions.WorkspaceModifyOperation.lambda$0(WorkspaceModifyOperation.java:110) at org.eclipse.ui.actions.WorkspaceModifyOperation$$Lambda$695/1957109117.run(Unknown Source) at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2295) at org.eclipse.core.internal.resources.Workspace.run(Workspace.java:2322) at org.eclipse.ui.actions.WorkspaceModifyOperation.run(WorkspaceModifyOperation.java:131) - locked <0x00000007b63b3b98> (a org.eclipse.ui.actions.WorkspaceModifyDelegatingOperation) at org.eclipse.ui.internal.editors.text.WorkspaceOperationRunner.run(WorkspaceOperationRunner.java:76) at org.eclipse.ui.internal.editors.text.WorkspaceOperationRunner.run(WorkspaceOperationRunner.java:66) at org.eclipse.ui.editors.text.TextFileDocumentProvider.executeOperation(TextFileDocumentProvider.java:461) at org.eclipse.ui.editors.text.TextFileDocumentProvider.saveDocument(TextFileDocumentProvider.java:764) at org.eclipse.ui.texteditor.AbstractTextEditor.performSave(AbstractTextEditor.java:5007) at org.eclipse.jdt.internal.ui.javaeditor.CompilationUnitEditor.performSave(CompilationUnitEditor.java:1275) at org.eclipse.jdt.internal.ui.javaeditor.CompilationUnitEditor.doSave(CompilationUnitEditor.java:1329) - locked <0x00000007b388fe00> (a org.eclipse.jdt.internal.core.CompilationUnit) at org.eclipse.ui.texteditor.AbstractTextEditor$TextEditorSavable.doSave(AbstractTextEditor.java:7115) at org.eclipse.ui.Saveable.doSave(Saveable.java:223) at org.eclipse.ui.internal.SaveableHelper.doSaveModel(SaveableHelper.java:343) at org.eclipse.ui.internal.SaveableHelper.lambda$1(SaveableHelper.java:196) at org.eclipse.ui.internal.SaveableHelper$$Lambda$713/752344362.run(Unknown Source) at org.eclipse.ui.internal.SaveableHelper.lambda$3(SaveableHelper.java:274) at org.eclipse.ui.internal.SaveableHelper$$Lambda$714/98525160.run(Unknown Source) at org.eclipse.jface.operation.ModalContext.runInCurrentThread(ModalContext.java:440) at org.eclipse.jface.operation.ModalContext.run(ModalContext.java:356) at org.eclipse.ui.internal.WorkbenchWindow.lambda$4(WorkbenchWindow.java:2249) at org.eclipse.ui.internal.WorkbenchWindow$$Lambda$599/1008667695.run(Unknown Source) at org.eclipse.swt.custom.BusyIndicator.showWhile(BusyIndicator.java:72) at org.eclipse.ui.internal.WorkbenchWindow.run(WorkbenchWindow.java:2247) at org.eclipse.ui.internal.SaveableHelper.runProgressMonitorOperation(SaveableHelper.java:281) at org.eclipse.ui.internal.SaveableHelper.runProgressMonitorOperation(SaveableHelper.java:262) at org.eclipse.ui.internal.SaveableHelper.saveModels(SaveableHelper.java:207) at org.eclipse.ui.internal.SaveableHelper.savePart(SaveableHelper.java:151) at org.eclipse.ui.internal.WorkbenchPage.saveSaveable(WorkbenchPage.java:3976) at org.eclipse.ui.internal.WorkbenchPage.saveEditor(WorkbenchPage.java:3990) at org.eclipse.ui.internal.handlers.SaveHandler.execute(SaveHandler.java:57) at org.eclipse.ui.internal.handlers.HandlerProxy.execute(HandlerProxy.java:294) at org.eclipse.ui.internal.handlers.E4HandlerProxy.execute(E4HandlerProxy.java:96) at sun.reflect.GeneratedMethodAccessor93.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.eclipse.e4.core.internal.di.MethodRequestor.execute(MethodRequestor.java:58) at org.eclipse.e4.core.internal.di.InjectorImpl.invokeUsingClass(InjectorImpl.java:320) at org.eclipse.e4.core.internal.di.InjectorImpl.invoke(InjectorImpl.java:254) at org.eclipse.e4.core.contexts.ContextInjectionFactory.invoke(ContextInjectionFactory.java:167) at org.eclipse.e4.core.commands.internal.HandlerServiceHandler.execute(HandlerServiceHandler.java:156) at org.eclipse.core.commands.Command.executeWithChecks(Command.java:497) at org.eclipse.core.commands.ParameterizedCommand.executeWithChecks(ParameterizedCommand.java:490) at org.eclipse.e4.core.commands.internal.HandlerServiceImpl.executeHandler(HandlerServiceImpl.java:213) at org.eclipse.e4.ui.bindings.keys.KeyBindingDispatcher.executeCommand(KeyBindingDispatcher.java:308) at org.eclipse.e4.ui.bindings.keys.KeyBindingDispatcher.press(KeyBindingDispatcher.java:584) at org.eclipse.e4.ui.bindings.keys.KeyBindingDispatcher.processKeyEvent(KeyBindingDispatcher.java:653) at org.eclipse.e4.ui.bindings.keys.KeyBindingDispatcher.filterKeySequenceBindings(KeyBindingDispatcher.java:443) at org.eclipse.e4.ui.bindings.keys.KeyBindingDispatcher.access$2(KeyBindingDispatcher.java:386) at org.eclipse.e4.ui.bindings.keys.KeyBindingDispatcher$KeyDownFilter.handleEvent(KeyBindingDispatcher.java:96) at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:89) at org.eclipse.swt.widgets.Display.filterEvent(Display.java:1193) at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1054) at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1079) at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1064) at org.eclipse.swt.widgets.Widget.sendKeyEvent(Widget.java:1106) at org.eclipse.swt.widgets.Widget.sendKeyEvent(Widget.java:1102) at org.eclipse.swt.widgets.Widget.wmChar(Widget.java:1489) at org.eclipse.swt.widgets.Control.WM_CHAR(Control.java:4888) at org.eclipse.swt.widgets.Canvas.WM_CHAR(Canvas.java:353) at org.eclipse.swt.widgets.Control.windowProc(Control.java:4768) at org.eclipse.swt.widgets.Canvas.windowProc(Canvas.java:348) at org.eclipse.swt.widgets.Display.windowProc(Display.java:4770) at org.eclipse.swt.internal.win32.OS.DispatchMessage(Native Method) at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3545) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$5.run(PartRenderingEngine.java:1173) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:339) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine.run(PartRenderingEngine.java:1062) at org.eclipse.e4.ui.internal.workbench.E4Workbench.createAndRunUI(E4Workbench.java:155) at org.eclipse.ui.internal.Workbench.lambda$3(Workbench.java:636) at org.eclipse.ui.internal.Workbench$$Lambda$38/480498267.run(Unknown Source) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:339) at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:563) at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:151) at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:155) at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:203) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:137) at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:107) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:400) at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:255) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:659) at org.eclipse.equinox.launcher.Main.basicRun(Main.java:595) at org.eclipse.equinox.launcher.Main.run(Main.java:1501) at org.eclipse.equinox.launcher.Main.main(Main.java:1474)
(In reply to Ed Willink from comment #2) > I took three thread dumps at about 5 second intervals. Each was similar to > the trace below (in the JavaIndenter). > > Why is a time-consuming activity such as indentation happening on the UI > thread? All text changing operations happen in the UI thread, like e.g. also the refactorings. > Why is indentation so SLOW? I doubt it's the indentation that's causing it. Please make stack traces at several points during those 70s. Also, attach the full stack traces, not just 'main'.
Created attachment 277206 [details] Three full thread dumps Three dumps attached. Indentation during save is not a text changing operation; it is a save operation and so should not be on the main thread.
(In reply to Dani Megert from comment #3) > I doubt it's the indentation that's causing it. > > not just 'main'. Scanning the Runables I see the debugger contributing twice as below. My machine is still in the state when I created the dumps. I have only one editor open on PivotPackage.java. The debugger is suspended a few single steps after a breakpoint. PivotPackage.java is a source file contributing to the debug session, although saving an 'unchanged' copy should not really provoke any activity. "Output Stream Monitor" #2124 daemon prio=1 os_prio=-2 tid=0x0000000028209800 nid=0x352c runnable [0x000000004bc3f000] java.lang.Thread.State: RUNNABLE at java.io.FileInputStream.readBytes(Native Method) at java.io.FileInputStream.read(FileInputStream.java:255) at java.io.BufferedInputStream.read1(BufferedInputStream.java:284) at java.io.BufferedInputStream.read(BufferedInputStream.java:345) - locked <0x00000007b3844098> (a java.io.BufferedInputStream) at java.io.FilterInputStream.read(FilterInputStream.java:107) at org.eclipse.debug.internal.core.OutputStreamMonitor.internalRead(OutputStreamMonitor.java:161) at org.eclipse.debug.internal.core.OutputStreamMonitor.read(OutputStreamMonitor.java:138) at org.eclipse.debug.internal.core.OutputStreamMonitor.lambda$0(OutputStreamMonitor.java:224) at org.eclipse.debug.internal.core.OutputStreamMonitor$$Lambda$744/1770967415.run(Unknown Source) at java.lang.Thread.run(Thread.java:748) Locked ownable synchronizers: - None "Output Stream Monitor" #2123 daemon prio=1 os_prio=-2 tid=0x0000000028202000 nid=0x1978 runnable [0x000000004bb3f000] java.lang.Thread.State: RUNNABLE at java.io.FileInputStream.readBytes(Native Method) at java.io.FileInputStream.read(FileInputStream.java:255) at java.io.BufferedInputStream.read1(BufferedInputStream.java:284) at java.io.BufferedInputStream.read(BufferedInputStream.java:345) - locked <0x00000007b383f7a8> (a java.io.BufferedInputStream) at java.io.BufferedInputStream.read1(BufferedInputStream.java:284) at java.io.BufferedInputStream.read(BufferedInputStream.java:345) - locked <0x00000007b3841b68> (a java.io.BufferedInputStream) at java.io.FilterInputStream.read(FilterInputStream.java:107) at org.eclipse.debug.internal.core.OutputStreamMonitor.internalRead(OutputStreamMonitor.java:161) at org.eclipse.debug.internal.core.OutputStreamMonitor.read(OutputStreamMonitor.java:138) at org.eclipse.debug.internal.core.OutputStreamMonitor.lambda$0(OutputStreamMonitor.java:224) at org.eclipse.debug.internal.core.OutputStreamMonitor$$Lambda$744/1770967415.run(Unknown Source) at java.lang.Thread.run(Thread.java:748) Locked ownable synchronizers: - None
OK, couple of questions: 1. Is this a regression compared to 4.10 (or even 4.9)? 2. Is it faster if you disable the 'Correct indentation' save action? 3. If you then open PivotPackage.java, select all, and Ctrl+I, is it slow? 4. Why do you perform any save actions on generated code? Performance issues regarding the indent save action are supposed to be fixed by bug 519754.
(In reply to Dani Megert from comment #6) > Performance issues regarding the indent save action are supposed to be fixed > by bug 519754. They are not fully fixed, but reduced: https://git.eclipse.org/r/#/c/101547/1//COMMIT_MSG <quote> This improves performance in some situations, when adjusting indentation during save action. E.g. for 16k commented lines, indentation takes 1/3 of the original time (40 seconds, down from 120 seconds). </quote> How big is the PivotPackage.java file?
(In reply to Andrey Loskutov from comment #7) > How big is the PivotPackage.java file? I see 38000 lines in comment 0. So 70 seconds for 38k matches "40 seconds for 16k lines" as described in the patch, and it would be 210 seconds before the patch for bug 519754. Still questionable performance for a questionable action on a generated file.
(In reply to Dani Megert from comment #6) > OK, couple of questions: > > 1. Is this a regression compared to 4.10 (or even 4.9)? Hard to say. I get depressed about how many things in Eclipse are slow these days. Building/indexing/API-checking are a different but serious problems too. For a while I was probably blaming build for this problem since just as soon as the save completes build becomes the problem. > 2. Is it faster if you disable the 'Correct indentation' save action? Yes, much. 0.5 to 1.0 seconds. (Since correct indentation (and formatting etc) should have no semantic significance, perhaps they should be on a background thread that doesn't trigger a build on completion.) > 3. If you then open PivotPackage.java, select all, and Ctrl+I, is it slow? Yes. Exactly same problem. UI Lockout. Why on the UI thread? Why no <esc> or <Ctrl>+\ ability to cancel anyway? > 4. Why do you perform any save actions on generated code? There can be manual contributions. Some JDT annotations / unused imports / redundant casts need fixing up. Some auto-comments are misformatted with spaces rather than tabs making a GIT commit look necessary when it isn't. Unfortunately since the auto-generation occurs from MWE2 (standalone), EMF is not clever enough to invoke the UI-based JDT clean up actions standalone. Clean-up has to be manual on the UI thread. (It would be great if JDT provided a standalone clean-up actions API. I already have my own ConvertToUnixLineEndings build step to clean up after EMF, I'd love to have my own fix-imports etc too).
(In reply to Ed Willink from comment #9) > (In reply to Dani Megert from comment #6) > > OK, couple of questions: > > > > 1. Is this a regression compared to 4.10 (or even 4.9)? > > Hard to say. You could jus test with the older build – not really hard. But looks like the indent action is the issue, so, no regression.
(In reply to Dani Megert from comment #10) > > > 1. Is this a regression compared to 4.10 (or even 4.9)? On 4.8. Select All, correct indentation is incredibly slow too. (It was only a couple of years ago that I discovered save actions. Maybe that contributes to why I now think Eclipse is slow.) > You could jus test with the older build – not really hard. Not hard, but 5 minutes by the time I have started the old installation and waited for the re-build to complete. And 5 minutes to change back again.
Using StringBuilder rather than StringBuffer in JavaIndenter can't do any harm - JDT isn't multithreaded is it? Why does the indenter parse at all? Heuristic parsers are notoriously inefficient. There already is a good parse. Surely it is just necessary to make sure that the known constructs are sensibly positioned and that intervening characters are prettily presented?. (If the good parser fails, then the heuristic parser is liable to do something magic. Indeed it does. A missing/extra brace causes everything below the typo to go weird making it hard to work out where the typo is.)
(In reply to Ed Willink from comment #12) > Using StringBuilder rather than StringBuffer in JavaIndenter can't do any > harm - JDT isn't multithreaded is it? > > Why does the indenter parse at all? Heuristic parsers are notoriously > inefficient. There already is a good parse. Surely it is just necessary to > make sure that the known constructs are sensibly positioned and that > intervening characters are prettily presented?. (If the good parser fails, > then the heuristic parser is liable to do something magic. Indeed it does. A > missing/extra brace causes everything below the typo to go weird making it > hard to work out where the typo is.) We are happy to get a high quality Gerrit change that improves the performance.
This bug hasn't had any activity in quite some time. Maybe the problem got resolved, was a duplicate of something else, or became less pressing for some reason - or maybe it's still relevant but just hasn't been looked at yet. If you have further information on the current state of the bug, please add it. The information can be, for example, that the problem still occurs, that you still want the feature, that more information is needed, or that the bug is (for whatever reason) no longer relevant. -- The automated Eclipse Genie.
Still have plenty of opportunities for coffee breaks when saving files.
