Community
Participate
Working Groups
I20100119-0800 Typing in the filter box in the install wizard takes a very long time. It seems to freeze for up to 5 seconds on every keystroke, even though the repository is already loaded at this point. I took a couple of stack dumps that point to some potential hotspots, but we'll likely need to run with a profiler to get a good picture of where the bottlenecks are. Stack 1: "main" (TID:0x00216C00, sys_thread_t:0x009F5318, state:R, native ID:0x000015EC) prio=6 at org/eclipse/equinox/internal/p2/metadata/expression/RepeatableIterator.create(RepeatableIterator.java:54(Compiled Code)) at org/eclipse/equinox/internal/p2/metadata/expression/RepeatableIterator.create(RepeatableIterator.java:22(Compiled Code)) at org/eclipse/equinox/internal/p2/metadata/expression/Expression.evaluateAsIterator(Expression.java:132(Compiled Code)) at org/eclipse/equinox/internal/p2/metadata/expression/CollectionFilter.evaluate(CollectionFilter.java:54(Compiled Code)) at org/eclipse/equinox/internal/p2/metadata/expression/MatchExpression.isMatch(MatchExpression.java:69(Compiled Code)) at org/eclipse/equinox/internal/p2/metadata/expression/MatchExpression.isMatch(MatchExpression.java:73(Compiled Code)) at org/eclipse/equinox/internal/p2/metadata/RequiredCapability.isMatch(RequiredCapability.java:218(Compiled Code)) at org/eclipse/equinox/internal/p2/metadata/InstallableUnit.satisfies(InstallableUnit.java:288(Compiled Code)) at org/eclipse/equinox/p2/metadata/query/CategoryMemberQuery.isMatch(CategoryMemberQuery.java:51(Compiled Code)) at org/eclipse/equinox/p2/metadata/query/CategoryMemberQuery.isMatch(CategoryMemberQuery.java:1(Compiled Code)) at org/eclipse/equinox/p2/query/MatchQuery.perform(MatchQuery.java:68(Compiled Code)) at org/eclipse/equinox/internal/p2/metadata/repository/LocalMetadataRepository.query(LocalMetadataRepository.java:148) at org/eclipse/equinox/p2/query/CompoundQueryable.query(CompoundQueryable.java:87(Compiled Code)) at org/eclipse/equinox/internal/p2/metadata/repository/CompositeMetadataRepository.query(CompositeMetadataRepository.java:132) at org/eclipse/equinox/internal/p2/ui/ElementQueryDescriptor.performQuery(ElementQueryDescriptor.java:60) at org/eclipse/equinox/internal/p2/ui/model/QueriedElement.fetchChildren(QueriedElement.java:105(Compiled Code)) at org/eclipse/equinox/internal/p2/ui/model/QueriedElement.getChildren(QueriedElement.java:65(Compiled Code)) at org/eclipse/equinox/internal/p2/ui/viewers/DeferredQueryContentProvider.getChildren(DeferredQueryContentProvider.java:113(Compiled Code)) at org/eclipse/jface/viewers/AbstractTreeViewer.getRawChildren(AbstractTreeViewer.java:1351(Compiled Code)) Stack 2: "main" (TID:0x00216C00, sys_thread_t:0x009F5318, state:R, native ID:0x000015EC) prio=6 at java/util/HashMap.<init>(HashMap.java:287(Compiled Code)) at java/util/LinkedHashMap.<init>(LinkedHashMap.java:206(Compiled Code)) at org/eclipse/equinox/internal/p2/core/helpers/OrderedProperties.init(OrderedProperties.java:81(Compiled Code)) at org/eclipse/equinox/internal/p2/core/helpers/OrderedProperties.put(OrderedProperties.java:99(Compiled Code)) at org/eclipse/equinox/internal/p2/core/helpers/OrderedProperties$UnmodifiableProperties.<init>(OrderedProperties.java:195(Compiled Code)) at org/eclipse/equinox/internal/p2/core/helpers/OrderedProperties.unmodifiableProperties(OrderedProperties.java:34(Compiled Code)) at org/eclipse/equinox/internal/p2/engine/Profile.getInstallableUnitProperties(Profile.java:278(Compiled Code)) at org/eclipse/equinox/internal/p2/engine/Profile.snapshot(Profile.java:322(Compiled Code)) at org/eclipse/equinox/internal/p2/engine/SimpleProfileRegistry.getProfile(SimpleProfileRegistry.java:161(Compiled Code)) at org/eclipse/equinox/internal/p2/ui/QueryProvider.getQueryDescriptor(QueryProvider.java:84(Compiled Code)) at org/eclipse/equinox/internal/p2/ui/model/QueriedElement.fetchChildren(QueriedElement.java:102(Compiled Code)) at org/eclipse/equinox/internal/p2/ui/model/QueriedElement.getChildren(QueriedElement.java:65(Compiled Code)) at org/eclipse/equinox/internal/p2/ui/viewers/ProvElementContentProvider.getChildren(ProvElementContentProvider.java:132(Compiled Code)) at org/eclipse/equinox/internal/p2/ui/viewers/DeferredQueryContentProvider.getChildren(DeferredQueryContentProvider.java:112(Compiled Code)) at org/eclipse/ui/dialogs/PatternFilter.isParentMatch(PatternFilter.java:256(Compiled Code))
Last week I noticed this, too (and never opened a bug, just made a scribble somewhere). What I observed was that pre-API branch, a typical filter from Helios (ie, load Helios and type "Myl") was taking just under 2 seconds. Not great, but not terrible. The same filter now takes close to 5 seconds. I think that two things are at play: - the UI is doing a lot of querying (perhaps where a cache would do). ie, if the viewer is refreshed we query again, we aren't keeping local caches except where we have to. - querying has gotten slower now, so it's more noticeable Agree we need to profile it. The UI was getting away with repeated queries because they weren't so expensive as to notice. Now it's not the case.
re: stack #2. The UI retrieves the profile in the case of the "filter already installed" checkbox. So repeated querying would repeatedly fetch the profile. We might be able to do something involving caching the profile at the element level so that at least this could be avoided.
(In reply to comment #1) > What I observed was that pre-API branch, a typical filter from Helios (ie, load > Helios and type "Myl") was taking just under 2 seconds. Not great, but not > terrible. > > The same filter now takes close to 5 seconds. > I don't like the sound of that. What query is it? I'd like to have a look.
The filter is being applied to the "available IU" query...the exact query depends on the checkboxes, etc. in the install wizard (latest version, filter installed, etc.). The query is composed in QueryProvider see line 73 (AVAILABLE_IUS). I suspect that part of the issue might be filtered tree requesting the children multiple times, and we are not caching but rather re-querying. I haven't verified this for sure. I just noticed also that in this code we are getting the profile always, marking installed items, and then passing a boolean to the element wrappers indicating whether the "already installed" items need to be hidden. There is room for optimization here (not getting the profile unless we know we are hiding already installed). This may account for the original delays...
(In reply to comment #3) > I don't like the sound of that. What query is it? I'd like to have a look. You can see one of the queries running in stack #1 in comment #0 if that helps.
I did some profiling using JRockit Mission Control: 1. I loaded the Helios release: 2. Started method counter on CategoryMemberQuery.isMatch(). It's reset to 0 calls. 3. I now type the character 'M' in the filter field. The method counter now shows 554,008 calls (wow)! 4. I add the character 'y' The counter now shows 842,539 calls. 5. I add the character 'l' Counter is at 1,027,204 calls. I now repeat the exact same thing using an Eclipse 3.6M4. Instead of tracing the CategoryMemberQuery (it doesn't exist) I trace the InstallableUnitQuery. After the first character is typed, the counter only shows 195,808. So far the ratio showing a slow down from 2 to 5 seconds match fairly well. I type 'y' counter is now at 365,030. After the 'l', it reaches 448,164. I.e. less then half and still matching the ratio 2/5 fairly well. I don't know why the number of calls have more then doubled, but they have. The time it takes to evaluate the 'isMatch()' however has not increased. So the problem is higher up and I agree with Susan, there is room for optimization.
Also seeing this in I20100413-1521; thought the filtering was not working at all; after some initialization it takes ca. 1s/keystroke to update.
I concur with this analysis. Thomas, could you please take another look at this, as this may reveal another problem. Susan, do we buffer keystrokes?
I see a completely different behavior now compared to M6. There, the keystroke is just as fast as the rest (about 1 sec.). Now, the initial keystroke takes about 10 seconds for me. Then the rest is relatively fast. Something has definitely changed. I went back to an M6 installation and made a double check. The only changes to query that has been made since M6 is probably the move. So either something went wrong there, or there's been changes to the UI part. I'll have a look but it would be helpful if Susan could verify that things are unchanged on her side.
Nothing has changed since M6 on the UI side in this area. Please beware that you are comparing apples to apples, though, because it can change depending on whether repositories have been preloaded or not. The wizard preloads repos in the background when it is launched, so depending on how long you wait to try the filter, which repos are in the preferences, etc., the characteristics can differ. One way to ensure a fair comparison is to bring up the wizard, open the repo pref page from the wizard, delete all repos, and then add one or two repos that have not been used before. Close the pref page. This ensures that no repos are preloaded. Note we have a problem in bug 300914 whereby the wait for the load is longer than it needs to be. I intend to fix that one. In that bug, the behavior has always been questionable (loading all repos before filtering), but there's been a change in the "first time typing" behavior between M4 and M5.
The symptoms that I see is very consistent with what's described in bug 300914 so I'll wait until that has been addressed before I dig any deeper. Those symptoms aside, I think the performance is as good as it was prior to M5. What's been mentioned before about optimizing the filtering logic still stands. A fairly naive implementation mapping the translated displayed names (map key in lower case) to actual IU will probably improve performance quite a bit.
*** Bug 332415 has been marked as a duplicate of this bug. ***
Hello, I kindly ask for increasing the priority of this problem. It took me quite a long time to find what software I actually want to install - mostly waiting for the filtering. Thanks a lot, Tomas
It is funny that you ask since we just released a fix for this earlier this week.
This is fixed? It's still doing the same thing for me in Kepler.
There are still some issues and they are being tracked in bug #384646
