Community
Participate
Working Groups
When selecting text the keyboard repeat/update rate is slower than other keyboard actions. (My keyboard repeat rate is on maximum in the windows control panel.) * Hold down Shift+Right arrow: (it feels about) half speed * Hold down Right arrow: full speed I've recently updated to Eclipse 4.4M6. (Similar although probably not a duplicate: bug 388938)
Now that I've thought a bit more about testing this: * Occurs in a Java editor and a plain-text editor * It's a bit sluggish with a click-and-drag across text with the mouse too. * CPU is indeed peeked at 100% of 1 CPU Once selected, scrolling the screen seems as fluid as ever. So I guess it's doing too much work on that selection change. Next I thought to try Java Visual VM Profiler... Bang! Down goes Eclipse. Okay... then... Java Visual VM Sampler & some manual Thread Dumps? Sampler highlights 'ModelServiceImpl.findElementsRecursive' as a hotspot, and this seems like a typical trace of the busy looking thread (after taking a few): "main" #1 prio=6 os_prio=0 tid=0x02e2cc00 nid=0x1b68 runnable [0x0018e000] java.lang.Thread.State: RUNNABLE at org.eclipse.e4.ui.internal.workbench.ModelServiceImpl.findElementsRecursive(ModelServiceImpl.java:181) at org.eclipse.e4.ui.internal.workbench.ModelServiceImpl.findElementsRecursive(ModelServiceImpl.java:182) at org.eclipse.e4.ui.internal.workbench.ModelServiceImpl.findElementsRecursive(ModelServiceImpl.java:192) at org.eclipse.e4.ui.internal.workbench.ModelServiceImpl.findElements(ModelServiceImpl.java:261) at org.eclipse.e4.ui.internal.workbench.ModelServiceImpl.findElements(ModelServiceImpl.java:249) at org.eclipse.ui.internal.WorkbenchPage.getPerspectiveStack(WorkbenchPage.java:3975) at org.eclipse.ui.internal.WorkbenchPage.getCurrentPerspective(WorkbenchPage.java:4298) at org.eclipse.ui.internal.WorkbenchPage.getHiddenItems(WorkbenchPage.java:5291) at org.eclipse.ui.internal.WorkbenchWindow$3.getVisible(WorkbenchWindow.java:2937) at org.eclipse.jface.action.MenuManager.isChildVisible(MenuManager.java:1036) at org.eclipse.jface.action.MenuManager.isVisible(MenuManager.java:597) at org.eclipse.jface.action.MenuManager.isChildVisible(MenuManager.java:1040) at org.eclipse.jface.action.MenuManager.update(MenuManager.java:802) at org.eclipse.jface.action.MenuManager.update(MenuManager.java:721) at org.eclipse.ui.internal.WorkbenchWindow$8.run(WorkbenchWindow.java:678) at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35) at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:136) - locked <0x80aebd10> (a org.eclipse.swt.widgets.RunnableLock) at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4147) at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3764) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$9.run(PartRenderingEngine.java:1122) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332) at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine.run(PartRenderingEngine.java:1006) at org.eclipse.e4.ui.internal.workbench.E4Workbench.createAndRunUI(E4Workbench.java:147) at org.eclipse.ui.internal.Workbench$5.run(Workbench.java:630) at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:332) Note: I'm running Java8-ea-118 (32bit) on Windows x64
I cannot reproduce this using http://download.eclipse.org/eclipse/downloads/drops4/S-4.4M6-201403061200/ on Windows 7 with Oracle JRE 7. Maybe you've installed some additional bundles that cause this. Please reopen if you can reproduce this with said download and a fresh workspace.
OK, I've spent most of Sunday analysing this, mostly as a black box, but I think I've cracked it. There's a general scalability problem in conjunction with hidden junk in my workbench layout. In summary, the full slowness is observed with: * my workspace * the following (minimal) installation: - Eclipse SDK - CDT - m2e - EGit Although increased CPU can also be seen in certain other combinations. Some key findings... Installation Workspace % of 1 CPU used (when selecting text) ------------ --------- --------------- Original (23 items installed) Original 200% Original Clean 64% Clean Original 16% Clean Clean 16% Note "200% of 1 CPU" actually means 1 CPU running at 100% but taking 2x longer than normal to move the cursor. (Measured by timing how long it takes to scroll down 200 lines holding Shift.) This hinted I should look at software components, so I tried first keeping my own workspace. I worked through each component that had changed version in my M5 -> M6 upgrade, narrowing it eventually to these: 4.4 M6 Clean + m2e: 16% -- no change 4.4 M6 Clean + EGit: 22% -- tiny increase 4.4 M6 Clean + CDT: 120% -- quite a bump in CPU, bad for laptops, but not noticeable in raw speed 4.4 M6 Clean + CDT + m2e + EGit: 200% -- ah-ha! The connection with CDT surprised me, since I was testing only with .java files. Next I tried to make a clean workspace start to run badly... I tried putting projects in there with git and maven etc... none of it made any difference. Eventually I reflected back on the call-stack, and this method: "workbench.ModelServiceImpl.findElements" So I presume this is what's being called much more often with this particular set of features. Using JVisualVM's Sampler again I found the lion's share of time was going into, quite specifically, the third level of recursion into this method: ModelServiceImpl.findElementsRecursive "What's that searching?" I thought. Googling the workbench layout failed me, so I dived into the scary folder that is ".metadata" and shortly found org.eclipse.e4.workbench/workbench.xmi. To cut a long story short, the element for the main toolbar... <trimBars xmi:id="_xVM-J73fEeORoocf3zfrVg" elementId="org.eclipse.ui.main.toolbar"> ...is 7,000 lines long, and a mess! Duplicate <children> almost everywhere. (The 5 buttons of one sub-toolbar were repeated 90 times, for example.) Seems there are a couple of avenues to pursue: 1. What's creating the duplicate entries? Note, unlike bug 402561 I don't SEE any duplicate buttons. 2. Should Eclipse clean up toolbar duplicates automatically? (It looks like something like this was already attempted in bug 402561(?)) 3. Even with a clean workspace/toolbar, should the 64% CPU (of one i7-860 core) be investigated (e.g. by the CDT folk?) It seems rather on the high side for text-range updates.
Created attachment 241649 [details] My workbench.xmi file Attached my workbench.xmi file ... it seems to be growing each time I restart Eclipse.
Thanks for the analysis Luke. It would be great if you could profile the slow scenario and attach profiler outputs to this bug report.
The only profiler I'm familiar with is JVisual VM, but when I use its profiler to try and get an instrumented call-hierarchy Eclipse simply goes down. Also I can't seem to save a report from the Sampler in any form that JVisual VM will actually load up again. So I'll just attach some screenshots of its reports. Otherwise, any pointers or links as to how to profile Eclipse?
Created attachment 241661 [details] JVisual VM sampling report (top contribution)
Created attachment 241662 [details] JVisual VM sampling report (second & third contributions)
Eric, there seems to be a lot time spent in in findElements*. This is something we should look at. Related to bug 424367?
As a general comment, https://git.eclipse.org/r/#/c/24483/ offers to refactor and optimize the search tree. PW
See also Bug 430829 comment #7 PW
I'm actually more concerned with comment #3 which indicates that we're rampantly growing the set of menu / tb elements (most of which need to be re-evaluated when the selection changes, leading to many calls to MenuManager.isChildVisible which ultimately searches for the perpective stack (PS). Simply caching the PS in the MenuManager would tell us whether it's really the search or if it's just that we have leaked massive amounts of model elements into the top trim (and the main menu ??).
I've just done some tests to compare the state of the top trim on a clean start versus restarts. We're definitely growing by 13 elements per restart. Here's the diff, perhaps we can figure out what's going on: - org.eclipse.e4.ui.model.application.ui.menu.impl.ToolBarImplID: org.eclipse.debug.ui.launchActionSet - org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: debug - org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.debug.internal.ui.actions.DebugDropDownAction - org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.debug.internal.ui.actions.RunDropDownAction - org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.ui.externaltools.ExternalToolMenuDelegateToolbar + org.eclipse.e4.ui.model.application.ui.menu.impl.ToolBarImplID: org.eclipse.ui.tutorials.rcp.part3.toolbar + org.eclipse.e4.ui.model.application.ui.menu.impl.HandledToolItemImplID: org.eclipse.ui.tutorials.rcp.part3.open + org.eclipse.e4.ui.model.application.ui.menu.impl.HandledToolItemImplID: org.eclipse.ui.tutorials.rcp.part3.openMessage + org.eclipse.e4.ui.model.application.ui.menu.impl.ToolBarImplID: org.eclipse.debug.ui.launchActionSet + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: debug + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.debug.internal.ui.actions.DebugDropDownAction + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.debug.internal.ui.actions.RunDropDownAction + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.ui.externaltools.ExternalToolMenuDelegateToolbar + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: debug + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.debug.internal.ui.actions.DebugDropDownAction + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.debug.internal.ui.actions.RunDropDownAction + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.ui.externaltools.ExternalToolMenuDelegateToolbar + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: JavaWizards + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.jdt.ui.actions.OpenProjectWizard + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.jdt.ui.actions.OpenPackageWizard + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.jdt.ui.actions.NewTypeDropDown + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: Search + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: openType + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.search.OpenSearchDialogPage - org.eclipse.e4.ui.model.application.ui.menu.impl.ToolBarImplID: org.eclipse.ui.tutorials.rcp.part3.toolbar - org.eclipse.e4.ui.model.application.ui.menu.impl.HandledToolItemImplID: org.eclipse.ui.tutorials.rcp.part3.open - org.eclipse.e4.ui.model.application.ui.menu.impl.HandledToolItemImplID: org.eclipse.ui.tutorials.rcp.part3.openMessage + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: workingSets + org.eclipse.e4.ui.model.application.ui.menu.impl.DirectToolItemImplID: org.eclipse.ui.tests.action125011 - org.eclipse.e4.ui.model.application.ui.menu.impl.ToolBarImplID: org.eclipse.ui.tests.bug371611 - org.eclipse.e4.ui.model.application.ui.menu.impl.ToolControlImplID: org.eclipse.ui.tests.bug371611.control + org.eclipse.e4.ui.model.application.ui.menu.impl.ToolBarImplID: org.eclipse.ui.tests.bug371611 + org.eclipse.e4.ui.model.application.ui.menu.impl.ToolControlImplID: org.eclipse.ui.tests.bug371611.control Sanity check...adding the + and subtracting the - = 13
I've also just timed the WorkbenchPage#getCurrentPerspective() call: Single Call: 9868 (call it 10 uSec) Per Sec: 8619870 (call it 8 million / sec) Note that 'getPerspectiveStack' *does* cache the MPerspectiveStack but this is a *very* recent commit by Brian De Alwis... I think next I'll try my code out on the attached XMI file to see if I can at least get a count of the number of element in it.
OK then, there are 2275 items in the top trim of the given XMI...I've saved the file in my WS so we can go over it later... This looks to me like a major regression... Luke, what version of eclipse are you using ?
I'm on 4.4M6 32-bit (with quite a few features installed). While I don't recall any particular slowness before I upgraded from 4.4M5 to 4.4M6, I certainly could reproduce it during my investigation on Sunday when I downgraded to 4.4M5 to test. However, my toolbar also looked totally messed up back in 4.4M5 - showing 5 or 6 blank rows. (So I didn't do too much investigation in that version. I figured the data structures might have changed or something which would mean I was testing artificial / unrealistic scenarios.) Anyway, I leave it to you whether that might be a clue. Incidentally, now that I've deleted the main-toolbar section of `workbench.xmi` (and Eclipse recreated it) this resolved a number of other sluggishness/freezes that I'd felt in the UI as well. (Switching views, after saving files, dragging toolbar items...) It makes sense now that I understand what's behind it.
I was about to suggest this...;-). I'm not sure how you got the XMI into this state but as I pointed out above we *are* leaking elements into the top trim on every restart (but at 13 a pop it'd be 200 restarts...;-). I'm also wondering whether there may be an issue with CDT reacting to normal vs 'post' selection events. The difference is that the post-selection events are specifically designed not to 'spam' selection changes, allowing things like drag selection or arrow repeats to work smoothly. Dani, do you have any idea whether CDT uses the same pattern to handle selection changes as the JDT does ?
(In reply to Eric Moffatt from comment #17) > I was about to suggest this...;-). > > I'm not sure how you got the XMI into this state but as I pointed out above > we *are* leaking elements into the top trim on every restart (but at 13 a > pop it'd be 200 restarts...;-). > > I'm also wondering whether there may be an issue with CDT reacting to normal > vs 'post' selection events. The difference is that the post-selection events > are specifically designed not to 'spam' selection changes, allowing things > like drag selection or arrow repeats to work smoothly. > > Dani, do you have any idea whether CDT uses the same pattern to handle > selection changes as the JDT does ? No idea. We'd have to check in their source, or ask them.
(In reply to Eric Moffatt from comment #17) > I'm not sure how you got the XMI into this state but as I pointed out above > we *are* leaking elements into the top trim on every restart (but at 13 a > pop it'd be 200 restarts...;-). If the leaks were being introduced before 4.4M6, then 200 restarts doesn't sound too crazy for me - I probably average at least one restart a day normally & there were also periods when I was playing with JVM flags & installing features.
Dani, does it sound to you as if someone is doing heavy work on a selection listener rather than on a *post* selection Listener ? That's what seemed to cause this in JDT when the workbench was mistakenly sending a post event for every selection change...
(In reply to Eric Moffatt from comment #20) > Dani, does it sound to you as if someone is doing heavy work on a selection > listener rather than on a *post* selection Listener ? Yes, that's possible. > That's what seemed to > cause this in JDT when the workbench was mistakenly sending a post event for > every selection change... It was the other way around: JDT listens to post-selection changes and the workbench fired them immediately, see bug 391626 for details.
Moving to 4.6, please move back to 4.5.1 if you think these bugs are important enough to be addressed in the service release.
Mass move to 4.7 as M7 is approaching. Please move back in case you are planning to fix it for Neon.
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. As such, we're closing this bug. If you have further information on the current state of the bug, please add it and reopen this bug. 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.
