Bug 53920 - Slow performance updating target
Summary: Slow performance updating target
Status: RESOLVED FIXED
Alias: None
Product: Platform
Classification: Eclipse Project
Component: SWT (show other bugs)
Version: 3.0   Edit
Hardware: PC Windows 2000
: P3 normal (vote)
Target Milestone: 3.0 RC3   Edit
Assignee: Steve Northover CLA
QA Contact:
URL:
Whiteboard:
Keywords: performance
: 62922 (view as bug list)
Depends on:
Blocks:
 
Reported: 2004-03-05 14:26 EST by Ritchie Schacher CLA
Modified: 2004-06-19 05:39 EDT (History)
5 users (show)

See Also:


Attachments
Profile of updating the target platform using 2.1.3 (60.90 KB, image/gif)
2004-06-14 19:23 EDT, Wassim Melhem CLA
no flags Details
Profile using 3.0RC2 (62.78 KB, image/gif)
2004-06-14 19:27 EDT, Wassim Melhem CLA
no flags Details
Inside table viewer in 3.0 (42.27 KB, image/gif)
2004-06-14 19:35 EDT, Wassim Melhem CLA
no flags Details
Inside table viewer in 2.1.3 (45.89 KB, image/gif)
2004-06-14 19:40 EDT, Wassim Melhem CLA
no flags Details
3.0 Profiles (5.70 KB, application/x-zip-compressed)
2004-06-15 00:53 EDT, Wassim Melhem CLA
no flags Details
Profile using 2.1.3 (5.99 KB, application/x-zip-compressed)
2004-06-15 01:22 EDT, Wassim Melhem CLA
no flags Details
Inside Control.windowProc (5.05 KB, application/x-zip-compressed)
2004-06-15 01:42 EDT, Wassim Melhem CLA
no flags Details
Standalone JFace example showing the problem (3.86 KB, application/octet-stream)
2004-06-15 02:52 EDT, Nick Edgar CLA
no flags Details
Standalone SWT example showing the problem (2.84 KB, application/octet-stream)
2004-06-15 11:31 EDT, Nick Edgar CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Ritchie Schacher CLA 2004-03-05 14:26:03 EST
I have a target platform with ~400 plugins.  I'm using dynamic classpaths.  
When I go to the PDE preferences, reload a new target, click not in workspace, 
and hit ok, it takes a very long time before I have control again.

Seems like some refresh is going on as well as threads in the job queue.  This 
is using M7 as the development environment.
Comment 1 Wassim Melhem CLA 2004-03-06 11:43:40 EST
Is this reproducible or a bad concidence that you updated your target platform 
while other jobs were going on in the background?

The code that parses and resolves the target platform has not changed in about 
a year.
Comment 2 Ritchie Schacher CLA 2004-03-08 09:52:50 EST
It seems to be this way most of the time.
Comment 3 Wassim Melhem CLA 2004-03-08 09:55:38 EST
how many seconds are we talking about?  It is a costly operation to parse and 
resolve hundreds of plug-ins, but in the past, when I was doing my testing 
against WSADIE's 1200 plug-ins, it used to take 6 seconds.
Comment 4 Ritchie Schacher CLA 2004-03-08 10:04:35 EST
On a recent trial it took 15 seconds to load the plugins after I changed the 
target location, and another 20 after applied the preference.  This was with 
the Java perspective open.  When I opened the defect, it took what seemed like 
minutes but I can't recreate that at the moment.
Comment 5 Wassim Melhem CLA 2004-05-19 11:42:31 EDT
*** Bug 62922 has been marked as a duplicate of this bug. ***
Comment 6 Wassim Melhem CLA 2004-05-19 11:44:27 EDT
cc Pascal to keep him up-to-date on my findings.
Comment 7 Wassim Melhem CLA 2004-06-14 19:08:38 EDT
cc Jeff, JohnW
Also cc Nick as the bottleneck in 3.0 appears to be the refreshing of a table 
viewer.

Will attach several profiles.
Comment 8 Wassim Melhem CLA 2004-06-14 19:23:12 EDT
Created attachment 12100 [details]
Profile of updating the target platform using 2.1.3

In all my test cases, the target platform was WSADIE-5.1.1 which contains 1708
plug-ins and fragments.
In all the profiles that I am attaching, we will be showing the amount of time
it takes to load such a target.  That is, the amount of time elapsed between
the time you hit 'Reload' until the time the table viewer refreshes with the
new content.

In this first profile, I am using Eclipse 2.1.3 as my host platform.  This is
the old world with the old runtime, old PDE, old platform, etc.

The method that invokes everything is the one highlighted in blue:
ExternalPluginsBlock.handleReload().

In this profile, it takes 8.964 seconds for the whole reload operation to
complete:
5.489 seconds to load the target platform
3.105 seconds to refresh the table viewer.
Comment 9 Wassim Melhem CLA 2004-06-14 19:27:44 EDT
Created attachment 12101 [details]
Profile using 3.0RC2

Now let's look at the exact same operation using 3.0RC2 as the host platform.

You will see that ExternalPluginsBlock.handleReload now takes 17.547 seconds.
But note that the amount of time taken to parse the target platform (with all
its 1708 plugins) is 3.064 seconds.
The rest of the time is spent refreshing the table viewer (>10 seconds).

This is really obvious too when you see it in action.  You will see that the
progress monitor dialog goes to completion (i.e. the parsing finished), but the
UI hangs for a long time waiting for the table viewer to refresh.

I will attach another profile showing where the time is spent when refreshing
the table viewer.
Comment 10 Wassim Melhem CLA 2004-06-14 19:35:38 EDT
Created attachment 12102 [details]
Inside table viewer in 3.0

This is an expansion of what is happening during the refreshing of the table
viewer in 3.0
Comment 11 Wassim Melhem CLA 2004-06-14 19:40:52 EDT
Created attachment 12104 [details]
Inside table viewer in 2.1.3

On the other hand, here is what the expansion inside the refreshing of a table
viewer looked like in 2.1.3.
Comment 12 Wassim Melhem CLA 2004-06-14 19:43:52 EDT
Note that, although the screenshots are of profiles made using Yourkit, I also 
performed the same runs using the heavy OptimizeIt.  Although the numbers were 
higher, because OptimizeIt is more accurate and intensive, the same slowness 
with the table viewer was still a key.

I also put debug statements in the code to see how long it takes to refresh 
the tree and the numbers were still alarmingly high.  Much higher than the 
time it takes to resolve, parse and populate the target platform in 3.0.
Comment 13 Wassim Melhem CLA 2004-06-14 19:47:22 EDT
The reason why resolving and parsing the target platform is super fast using 
3.0RC2 is because of improvements made when addressing bug 66525.
Comment 14 Wassim Melhem CLA 2004-06-15 00:53:59 EDT
Created attachment 12107 [details]
3.0 Profiles

OptimizeIt profiles for loading WSADIE 5.1.1 on the target platform preference
page using Eclipse 3.0RC2
Comment 15 Wassim Melhem CLA 2004-06-15 01:22:23 EDT
Created attachment 12108 [details]
Profile using 2.1.3

Profiles using 2.1.3 and OptimizeIt.

The problem is in SWT.

Compare 2.1.3 with 3.0, and you will see how 
in 3.0: Display.windowProc() gets invoked 1,465,962 times,
while in 2.1: Display.windowProc() gets invoked 3,140 times.
Comment 16 Wassim Melhem CLA 2004-06-15 01:42:41 EDT
Created attachment 12109 [details]
Inside Control.windowProc

Did another run to capture the expansion of Control.windowProc().
Comment 17 Wassim Melhem CLA 2004-06-15 01:49:24 EDT
Moving to SWT and raising severity to Critical.
In the meantime, Nick suggested to wrap the refresh call on the viewer with 
setRedraw(false), setRedraw(true) to alleviate the problem.
Comment 18 Nick Edgar CLA 2004-06-15 02:37:31 EDT
Alternatively, you can update the viewer via viewer.setInput(Object), which does
a setRedraw(false) around a refresh().
Comment 19 Nick Edgar CLA 2004-06-15 02:52:39 EDT
Created attachment 12110 [details]
Standalone JFace example showing the problem

This uses a plain CheckBoxTableViewer around a Table with no TableColumns and
adds 2000 items.  Press Set Input, Clear, then Refresh.  The main difference
between Set Input and Refresh is that the former does a setRedraw(false).

On 2.1.3:
Set Input (2000) took 450ms
Clear took 150ms
Refresh (2000) took 1672ms

On 3.0 RC2:
Set Input (2000) took 240ms
Clear took 30ms
Refresh (2000) took 26348ms
Comment 20 Nick Edgar CLA 2004-06-15 02:56:41 EDT
Time on RC2 if there is a TableColumn:

Set Input (2000) took 220ms
Clear took 30ms
Refresh (2000) took 191ms

To see this, replace:
        Table table = new Table(shell, SWT.CHECK | SWT.H_SCROLL | SWT.V_SCROLL |
SWT.BORDER);
        viewer = new CheckboxTableViewer(table);

with:
        viewer = new CheckboxTableViewer(shell);
Comment 21 Nick Edgar CLA 2004-06-15 11:31:21 EDT
Created attachment 12159 [details]
Standalone SWT example showing the problem

Here are the times on RC2:

Add 2000 (redraw off) took 81ms
Clear took 20ms
Add 2000 (redraw on) took 23303ms
Add 2000 (redraw on) took 60387ms

Note that the second batch of 2000 takes over twice as long as the first.

Time on 2.1.3:
Add 2000 (redraw off) took 150ms
Add 2000 (redraw off) took 171ms
Clear took 20ms
Add 2000 (redraw on) took 1602ms
Add 2000 (redraw on) took 4277ms
Comment 22 Steve Northover CLA 2004-06-16 15:33:47 EDT
I have a fix but am just checking it twice (like Santa) before releasing it.
Comment 23 Steve Northover CLA 2004-06-17 02:54:35 EDT
Fixed > 20040617
Comment 24 Wassim Melhem CLA 2004-06-19 05:39:08 EDT
Using 20040618-1804, I verified that the table viewer on the Target Platform 
preference page now refreshes instantly when it contains 1708 plugins.  This 
happens when I refresh it using either viewer.refresh() or viewer.setInput(..).