Bug 34008 - Source lookup takes an extremely long time
Summary: Source lookup takes an extremely long time
Status: RESOLVED FIXED
Alias: None
Product: PDE
Classification: Eclipse Project
Component: UI (show other bugs)
Version: 2.1   Edit
Hardware: PC Windows 2000
: P1 critical (vote)
Target Milestone: 2.1 RC3   Edit
Assignee: Wassim Melhem CLA
QA Contact:
URL:
Whiteboard:
Keywords:
: 34768 (view as bug list)
Depends on:
Blocks:
 
Reported: 2003-03-06 14:31 EST by Wassim Melhem CLA
Modified: 2003-03-20 16:24 EST (History)
5 users (show)

See Also:


Attachments
Zip of optimize it profile of creating a source locator (3.25 KB, application/octet-stream)
2003-03-06 17:09 EST, Darin Wright CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Wassim Melhem CLA 2003-03-06 14:31:07 EST
Design time workbench instance: RC1
Target Platform: WSADIE (> 1000 plug-ins)

Number of projects in design time instance: 20.
Each project is referencing 20-280 external jars.

Problem:
When you launch a runtime workbench configuration, the progress monitor does 
not go away until all source lookup locations are resolved.  This takes in the 
order of minutes.  The runtime worbench shows up before the progress monitor in 
the design instance goes away!!!  So in the design instance, you can't do 
anything during all this time while waiting for the progress monitor to finish.
The bottleneck is in two places:
org.eclipse.pde.internal.ui.launcher.WorkbenchSourcePathProvider#resolveClasspat
h and 
org.eclipse.jdt.launching.sourcelookup.JavaSourceLocator#getSourceLocations.

Darin,
Note that source lookup locations are resolved even when we launch in 'run' 
mode, which is very surprising.
Comment 1 Darin Wright CLA 2003-03-06 14:34:54 EST
We still use the source locator in run mode to perform resolutions from stack 
traces in the console (i.e. hyperlinks).
Comment 2 Wassim Melhem CLA 2003-03-06 16:14:10 EST
Darin,
Resolving entries will definitely take time in this instance with this many 
external jars.  However, the main problem impeding productivity is the fact 
that the progress monitor does not go away for several minutes.  Would it 
possible for you to dismiss the progress monitor and resolve the runtime 
classpath entries in the background?
Comment 3 Darin Wright CLA 2003-03-06 16:22:24 EST
In RC2, we have changed the launch code to create the source locator before 
launching the VM (if a source locator ID is specified by a launch config - 
which I bleive is true for Runtime Workbench configs). The reason for this is 
that the source locator is also used to resolve source when performing 
evaluations - potentially for conditional breakpoints. Thus, we need the source 
locator before the VM starts in case a conditional breakpoint is hit. 

Hence, creating the source locator in a background thread does not work well - 
we may need it right away.
Comment 4 Darin Wright CLA 2003-03-06 16:23:39 EST
Why does it take so long to do the resolution? Can this be improved?
Comment 5 Darin Wright CLA 2003-03-06 16:27:46 EST
Also note, that we need the source locator to see source as soon as a 
breakpoint is hit (to display source in the editor). The debugger will not be 
able display source if the locator is not there (and there is no infrastructure 
in place to wait/show progress while the locator is created after-the-fact). 

This will be a problem if a breakpoint is hit early in the launch.
Comment 6 Wassim Melhem CLA 2003-03-06 16:31:01 EST
For every project in the workspace, I grab all package fragment roots, and 
create a runtime classpath entry for every root that represents an external 
archive.  I guess it's taking a great deal of time when we're dealing with 
projects with a large number of package fragment roots.
Note that I can't just look at library entries in the .classpath file of the 
project, as the classpath file might contain classpath container entries. Doing 
it through package fragment roots is the accurate way.
Comment 7 Darin Wright CLA 2003-03-06 16:40:53 EST
Could you use "Optimize-It" to see where the time is spend (I wonder if it's 
the runtime classpath entry, or in the Java model)? Perhaps we can make some 
optimizations.
Comment 8 Wassim Melhem CLA 2003-03-06 16:43:48 EST
Unfortunately, we don't have this tool in the Toronto lab.
Comment 9 Darin Wright CLA 2003-03-06 16:49:45 EST
We have it in the Winnipeg lab. Must be tough times out east :-) I will take a 
look at a regular runtime workbench (since I do not have WSADIE).
Comment 10 Dejan Glozic CLA 2003-03-06 16:54:39 EST
We do now, but I have only one license for it (hence it is on my machine) and I 
need it (the machine) now :-). We can still profile this, but not in time for 
RC2.
Comment 11 Darin Wright CLA 2003-03-06 17:09:13 EST
Created attachment 3890 [details]
Zip of optimize it profile of creating a source locator

Here's a trace for creating a source locator for a runtime workbench.
Comment 12 Darin Wright CLA 2003-03-06 17:10:57 EST
I would not recommend changes for RC2 - this is something we should investigate 
for RC3...

The trace shows that a lot of time is spent getting the package fragement root 
source attachments. In particular, I think it is resolving source roots within 
archives. Adding Philippe as CC.
Comment 13 Wassim Melhem CLA 2003-03-06 17:17:31 EST
Could not ship without a fix.  Raising priority.
Comment 14 Darin Wright CLA 2003-03-12 11:27:07 EST
I am doing some investigation on the "debug" end. Still hoping for a comment 
from Philippe (but I know he is away at a conference currently).
Comment 15 Darin Wright CLA 2003-03-12 13:01:08 EST
For starters, I have improved the performance of classpath entry resolution of 
the "JRE" classpath container. The container was not caching its entries - it 
was always re-computing the default libararies in the JRE which required disk 
access to ensure files existed. In the self hosting workspace example, this 
reduced the source lookup generation time by 26% - since each project 
referencing the same JRE (which is usually all plug-ins), made this call 
indirectly from WorkbenchSourcePathProvider#isJRELibrary().

[nothing released to HEAD yet - still experimenting].
Comment 16 Darin Wright CLA 2003-03-12 14:45:48 EST
It appears that the java model is doing some uneccessary work attempting to 
find a source attachment for archives:

PackageFragmentRoot#getSourceAttachmentPath() and #getSourceAttachmentRootPath
() both make a call to #getSourceAttachmentProperty(). When the source 
attachment property is null, the pkg-frag-root, attempts to find a source 
attachment in #findSourceAttachmentRecommendation(). When no source attchment 
exists, this method is executed over & over, traversing all java projects 
looking for a possible source attachment. Worse yet, if a client makes a call 
to #getSourceAttachmentPath() and then #getSourceAttachmentRootPath() (which we 
do), the java model tries to find a source attachment twice in a row - when 
there is no hope of finding one.

Question: shouldn't the java model cache the fact that there is no source 
attachment for a pkg-frag-root (perhaps in the persistent property)? 
Comment 17 Darin Wright CLA 2003-03-12 17:24:37 EST
Fix for bug 34860 has been released to HEAD. This improves the JRE container 
performance.
Comment 18 Jerome Lanneluc CLA 2003-03-13 03:35:09 EST
I would recommend to use getSource() and getSourceRange() on the IClassFile. 
They internally use the source mapper mechanism that has been optimized.
Comment 19 Jerome Lanneluc CLA 2003-03-13 05:11:24 EST
Also, each IPackageFragmentRoot is being asked twice for its source attachment 
path and twice for its source attachment root path. Asking only once for each 
would cut the time in half.
Comment 20 Philipe Mulet CLA 2003-03-13 11:48:46 EST
Darin's failure caching story would also make sense.
Comment 21 Darin Wright CLA 2003-03-14 10:03:57 EST
*** Bug 34768 has been marked as a duplicate of this bug. ***
Comment 22 Darin Wright CLA 2003-03-14 21:34:01 EST
The workbench source locator could be optimized a little by avoiding asking for 
the "source root path" when the source attachement path is null, in the 
following code of #resolveClasspath(...)

if (roots[j].isArchive() && !isJRELibrary(roots[j])) {
	IRuntimeClasspathEntry rte = JavaRuntime.newArchiveRuntimeClasspathEntry
(roots[j].getPath());
	rte.setSourceAttachmentPath(roots[j].getSourceAttachmentPath());
	rte.setSourceAttachmentRootPath(roots[j].getSourceAttachmentRootPath());
	if (!all.contains(rte))
		all.add(rte);
}
Comment 23 Wassim Melhem CLA 2003-03-18 17:23:52 EST
Using I-20030317, the behavior now is actually worse for some reason.
When I launch, the progress monitor dialog seems frozen for two minutes and 
showing no progress whatsoever.  0 threads show up in the debug view during 
this wait. While waiting, I lost hope at some point, and tried to cancel the 
dialog.  Nothing happened.
After two minutes, the progress monitor dialog started to show progress and 
went away, and the threads started appearing in the debug view.
At this point, I saw the splash screen for the runtime workbench, and I was 
able to start doing work again in my design time workbench.
Although the time of idleness in the design time workbench is down to 2 minutes 
from 4 minutes or so, the fact that no threads are showing in the debug view 
and no progress is showing in the progress monitor dialog makes the situation 
worse in new ways.
Comment 24 Darin Wright CLA 2003-03-18 17:33:27 EST
JCORE is putting a fix into tonights build that should also improve performance.
Comment 25 Wassim Melhem CLA 2003-03-18 19:09:31 EST
For RC3, I made the change suggested by Darin in comment#22.
Comment 26 Wassim Melhem CLA 2003-03-18 20:16:43 EST
JDT Core Team,
will your fixes be in for RC3, or should we mark this defect for RC4?
Comment 27 Darin Wright CLA 2003-03-18 21:22:20 EST
JCORE's fix is in RC3 - bug 35131
Comment 28 Philipe Mulet CLA 2003-03-19 11:09:06 EST
Jdt/core issue got addressed independantly in bug 35131.

Still PDE shouldn't ask the 2 questions in a row. But no longer critical for 2.1
Comment 29 Wassim Melhem CLA 2003-03-20 16:24:55 EST
Nightmare is over.
On the same workspace where source lookup time used to take several minutes, 
source lookup now takes a few seconds in RC3.