Bug 308352 - Classpath resolution taking significantly longer
Summary: Classpath resolution taking significantly longer
Status: VERIFIED FIXED
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 3.6   Edit
Hardware: PC Windows XP
: P3 major (vote)
Target Milestone: 3.6 M7   Edit
Assignee: Jay Arthanareeswaran CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2010-04-07 11:41 EDT by Nick Sandonato CLA
Modified: 2010-04-28 02:51 EDT (History)
6 users (show)

See Also:


Attachments
profile (38.55 KB, text/plain)
2010-04-07 11:41 EDT, Nick Sandonato CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Nick Sandonato CLA 2010-04-07 11:41:35 EDT
Created attachment 164080 [details]
profile

We have a workspace with ~80 Dynamic Web Projects and ~40 EJB Projects. We've noticed since 3.6 that our JSP Validation is taking significantly longer (JSPDirectiveValidator#performValidation used to take about 15.5s and it's now taking about 254.7s).

I've included the portion of the Yourkit profile that I think might be of assistance (if you need the whole file, please let me know). But what I found is that it looks like JavaProject#getResolvedClasspath(boolean) is taking 251.5s where it only used to take about 12s before for the same number of invocations. 

Thanks.
Comment 1 Olivier Thomann CLA 2010-04-07 11:57:12 EDT
Jay, please investigate.
Comment 2 Olivier Thomann CLA 2010-04-07 11:58:28 EDT
Note that we need to check if each manifest has referenced jars, but I don't think this should take so long.
Comment 3 Jay Arthanareeswaran CLA 2010-04-08 03:04:39 EDT
(In reply to comment #0)
> Created an attachment (id=164080) [details]
> profile
> 
> We have a workspace with ~80 Dynamic Web Projects and ~40 EJB Projects. We've
> noticed since 3.6 that our JSP Validation is taking significantly longer
> (JSPDirectiveValidator#performValidation used to take about 15.5s and it's now
> taking about 254.7s).

Would it be possible to attach the pre-3.6 profiling data, if you still have them at hand. In fact, complete profiling file for both before and after 3.6 would help. Looking at the attachment, ClasspathEntry#resolvedChainedLibraries and ClasspathEntry#getCalledFileNames are taking majority of the time. Interestingly nothing big has changed in those methods in 3.6. Could you please confirm that the test case and test projects have not changed between runs?
Comment 4 Jay Arthanareeswaran CLA 2010-04-09 00:20:09 EDT
Thanks for the snapshots, Nick. 

This is what I found after a close look at them - most of the time used by the concerned methods seems to be spent in JAR file read operations. For instance, three invocation of java.util.zip.ZipFile.<init>(File) takes 101,765, 28,750 and 14,656 ms respectively. Also, looking at org.eclipse.jdt.internal.core.ExternalFoldersManager.isExternalFolderPath(IPath), most of the 21,906 ms is spent in file operations.

Just wondering if anything has changed in the test files or the environment.
Comment 5 Nick Sandonato CLA 2010-04-09 08:58:40 EDT
Hey Jay,

Nothing's changed as far as I can tell. Is there something in particular I could look out for or might be indicative of an increase in time spent in file operations?
Comment 6 Jay Arthanareeswaran CLA 2010-04-19 03:08:19 EDT
So, according to Nick, there may have been quite a few number of web app containers in the test environment. The delay seem to be in resolving the referenced JAR entries contained by the web container. As stated in bug 305037, we don't want to resolve the chained (referenced) library entries that come from the container. That should address this particular performance issue.

It remains to be discussed whether we want to make the resolution of referenced libraries an optional feature by proving a preference setting.
Comment 7 Jay Arthanareeswaran CLA 2010-04-22 02:32:50 EDT
As stated in comment #6, this should be taken care of by the fix to bug 305037. 
Nick, if you see this problem with build I20100420-0800 or later, please reopen the bug.
Comment 8 Nick Sandonato CLA 2010-04-22 10:34:47 EDT
(In reply to comment #7)
> As stated in comment #6, this should be taken care of by the fix to bug 305037. 
> Nick, if you see this problem with build I20100420-0800 or later, please reopen
> the bug.

Thanks for your investigation, Jay! I'll be sure to verify.
Comment 9 Satyam Kandula CLA 2010-04-27 07:12:12 EDT
Though I cannot verify by running, some of the calls that were shown up in the profile are removed and hence, I believe the performance should be better. 

Verified for 3.6M7 using build I20100424-2000
Comment 10 Srikanth Sankaran CLA 2010-04-28 02:51:26 EDT
Verified.