Community
Participate
Working Groups
Looking at I20081209-0100 performance results, it looks like the scenario: org.eclipse.jdt.text.tests.performance.ActivateTextEditorTest#testActivateEditor() got a regression since 3.4. The numbers for this test are really stable for all test machines: Win XP Sun 1.5.0_10 (2 x 3.00GHz - 3GB RAM) Builds Activate 30 text editors I20081118-1720 -17.0% I20081119-1600 -17.0% N20081120-2000 -17.0% I20081125-0840 -17.0% N20081127-2000 -17.0% N20081129-2000 -17.0% I20081202-1812 -17.0% N20081204-2000 -18.0% N20081206-2000 -17.0% I20081209-0100 -17.0% SLED 10 Sun 1.5.0_10 (2 x 3.00GHz - 3GB RAM) Builds Activate 30 text editors I20081118-1720 -18.0% I20081119-1600 -19.0% N20081120-2000 -20.0% I20081125-0840 -18.0% N20081127-2000 -17.0% N20081129-2000 -17.0% I20081202-1812 -17.0% N20081204-2000 -20.0% N20081206-2000 -25.0% I20081208-0921 -20.0% I20081209-0100 -17.0% RHEL 5.0 Sun 6.0_04 (2 x 3.00GHz - 3GB RAM) Builds Activate 30 text editors I20081118-1720 -16.0% I20081119-1600 -15.0% N20081120-2000 -16.0% I20081125-0840 -13.0% N20081127-2000 -13.0% N20081129-2000 -14.0% I20081202-1812 -23.0% N20081204-2000 -27.0% N20081206-2000 -28.0% I20081208-0921 -27.0% I20081209-0100 -27.0%
The regression happens in the org.eclipse.ui.internal.services classes. It looks like they are called much more often in I20090331-0901 than in R3.4. See attached ZIP for detailed result and comparison of the two builds.
Created attachment 130824 [details] ignore (wrong file)
Created attachment 130825 [details] Profiler data
Should this be a Platform/Text?
(In reply to comment #4) > Should this be a Platform/Text? Dani moved this one to Platform UI, the performance regression is in a Platform Text test, but the cause for it seems to be in Platform UI. See the attachment in comment 3.
(In reply to comment #1) > The regression happens in the org.eclipse.ui.internal.services classes. It > looks like they are called much more often in I20090331-0901 than in R3.4. > See attached ZIP for detailed result and comparison of the two builds. From the screenshots, the difference in the ExpressionAuthority.evaluate() is 35ms. The difference in test runs is about 380ms.
>From the screenshots, the difference in the ExpressionAuthority.evaluate() is >35ms. Take a look at diff.png and at the top items on that list.
On that screenshot the ExpressionAuthority is shown as "+40"ms (top row, last column). I assume it is the accumulated time spent in this class and its children. Let's assume that is the real difference, not a Java variability and not a result of profiler instrumentation. (40 ms difference is close to the resolution of measurements: about 12ms on each end. Moreover, for fast methods (120ms/500000calls = 0.00024 ms per call) called half a million times profiler instrumentation usually skews results to the point of being unusable. But let's assume for now that 40ms difference is real.) From the download page, the test results are +380ms. Assuming ExpressionAuthority were the same as in 3.4, the test results would still be +340ms? I guess I must be missing something? The difference might well turn out to be in the Platform/UI code but the data you attached neither supports no refutes this hypothesis.
You can't compare the numbers on your machine with what's on the download page. My machine is way faster. Also, you see that the UI code is invoked way more often and in the diff.png you need to add the top values as they are caused due to calls from the top level item. This test gets red with each release. I suggest Platform UI makes its own activate 30 editors test that activates a dummy/empty editor with many menu entries, tool bar contributions and global action retargettings. That way we will easily see in the future whether only the text editor test is red or whether both are red and hence not a problem in Text land.
Created attachment 132787 [details] Possible patch The extra calls to the ExpressionAuthority and its children are the result of the change made in the bug 266295. For the WorkbenchSourceProvider note that newShowInSelection is set to IEvaluationContext.UNDEFINED_VARIABLE (which is a java.lang.Object) but it is stored in the previous variable (lastShowInSelection) as "null". As a result, the check on "equals(newShowInSelection, lastShowInSelection)" always fails resulting in extra events being propagated through part service. I've attached the patch that fixes *this* problem. It would be good if somebody familiar with the code and the original fix could verify that it maintains desired behavior. On my computer this change results in about 3% improvement of the test's CPU performance.
Hi Oleg, the patch looks good to me - good catch! It is however not the real problem: if you look at the graph, e.g.: http://download.eclipse.org/eclipse/downloads/drops/I20090421-0930/performance/eplnx1/Scenario13.html You'll see that the performance difference is already there before bug 266295 was fixed and hence I guess while your fix is very good, it will not buy us back to 3.4.
Another change that adds 3% - 4% slowdown comparing to 3.4 was added in the bug 239715. See the class TypeExtensionManager, ver 1.15 -> 1.16. There are about 7K exceptions created during execution of this test and that little modification adds up. It seems that the change was added as a way to collect information and no feedback was received in half a year, so I'd recommend backing out that change. === With those three changes reversed (bug 266295, bug 11001, bug 239715) the test is about 8% slower on my computer comparing 3.4 to 3.5. From how differences dissipate as we drill down in the profiler I suspect that those 8% come from more than one fix. While we probably could figure out some more details, I think we are getting into diminishing returns on this bug. In absolute numbers those 8% difference not accounted for are < 0.5ms per editor activation.
TypeExtensionManager now only creates the Throwable when a debug option is set. I agree that after we commit the patch from this bug, we can mark this bug fixed.
(In reply to comment #12) > There are about 7K exceptions created during execution of this test and that > little modification adds up. Basically, whenever this exception is thrown, this indicates a bug in an expression. Unfortunately, most places where expressions are evaluated just swallow this exception and assume the expression is false. It turned out that all of wrong expressions that are hit during this test come from o.e.ui.ide. I filed bug 273583 for this. With that patch (but without Dani's last change for bug 239715), CPU time went down from 596ms to 621ms and elapsed process went down from 671ms to 646ms on my machine.
> CPU time went down from 596ms to 621ms down from 621ms to 596ms, of course
(In reply to comment #10) > Created an attachment (id=132787) [details] > Possible patch I've released this to HEAD PW
(In reply to comment #10) > For the WorkbenchSourceProvider note that newShowInSelection is set to > IEvaluationContext.UNDEFINED_VARIABLE (which is a java.lang.Object) but it is > stored in the previous variable (lastShowInSelection) as "null". I just found this bug while investigating another issue re WorkbenchSourceProvider. Searching for clients calling into WorkbenchSourceProvider.checkActivePart() I happended to find that PartListenerList.firePartActivated() iterates over 112 listeners, (one of them being a WorkbenchSourceProvider$1), while a similar setup in 3.4 only had 8 listeners. Reporting this here in case this increase of listeners is reproducable and might contribute to a performance regression.
(In reply to comment #17) never mind my previous comment, debugging a little further in 3.4 brought a second call into firePartDeactivated with a similar number (here 121) of listeners. Sorry for the noise.
Oleg, I've released the patch (we can mark it as fixed if you think we're done). PW
With all the changes the test is most likely going to be on the border of red/yellow so might be worth adding a desecription comment to it. Dani, would you like to add comment to the test and close the bug?
Yes, please close. I already made a bug for me to add the comment.
Closed :-).
Verified for M7 with I20090430-2300 results
