Bug 331294 - [perf] Java Indexer takes more time in adding jars to the index
Summary: [perf] Java Indexer takes more time in adding jars to the index
Status: VERIFIED WORKSFORME
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 3.7   Edit
Hardware: PC Windows XP
: P3 major (vote)
Target Milestone: 3.7 M5   Edit
Assignee: Satyam Kandula CLA
QA Contact:
URL:
Whiteboard:
Keywords: performance
Depends on:
Blocks:
 
Reported: 2010-11-29 00:02 EST by Gaurav Mising name CLA
Modified: 2011-01-25 12:31 EST (History)
9 users (show)

See Also:


Attachments
Contains yourkit snapshots (10.91 MB, application/zip)
2010-11-29 00:18 EST, Gaurav Mising name CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Gaurav Mising name CLA 2010-11-29 00:02:03 EST
Build Identifier: 

I am working with a Adopter product version that adopts Eclipse 3.6 and facing  issues while creating one of our specific project types.

I took some measurements using Yourkit 9.0 and found that Java Indexing takes
more time in current Adopter product based on Eclipse3.6. 

As per the yourkit measurements, the delay occurs because the very first time
Java Indexing takes place for a lot of jar files. Specifically jdt class's
AddJarFileToIndex.execute method is invoked for all the jar files contained in
the runtime(Local server or Stubs). In this case the runtime stub contains
approximately 104 jar files.

In latest version of Adopter product--> AddJarFileToIndex.execute when invoked multiple times took 44% of the total time of the project creation operation. The number of stub jars present were 104. 
In previous versions  --> AddJarFileToIndex.execute when invoked multiple times
took 26% oof the total time of the project creation operation. The number of
stub jars present were 104.

I am attaching the yourkit snapshots with this bug.

There is a similar Bug 323514 but i have been told that it's a different issue than this one.

Information about JDT in the adopter product

Eclipse Java Development Tools
Version: 3.6.2.r362_v20101117-0800-7z8XFUVFLFlmi7dz-0A7AhJ9LVkH
Build id: M20101117-1123

Reproducible: Always
Comment 1 Gaurav Mising name CLA 2010-11-29 00:18:02 EST
Created attachment 184003 [details]
Contains yourkit snapshots
Comment 2 Ayushman Jain CLA 2010-11-29 01:12:42 EST
Satyam, please investigate. Thanks!
Comment 3 Satyam Kandula CLA 2010-11-30 01:26:09 EST
I do see increase in time for many functions that AddJarFileToIndex.execute(). That could probably mean that this function is getting called for more number of times. Are the numbers taken off from a fresh workspace? Is the operation just 'createProject'? 

Can you turn on the jdt.core debug option to find out how many times AddJarFiletoIndex.execute() would have been called? It will be good if we get the output for both 3.4 and 3.6. 
Here are the instructions to add the debug option. 
-----------------------
Create a file called
.options in the eclipse folder with the following lines in it.
######
org.eclipse.jdt.core/debug=true
org.eclipse.jdt.core/debug/indexmanager=true
###########
Then run eclipse as
%eclipsec.exe -debug
Please give the output of the command. Please also attach the file
.metadata/.log located in your workspace.
-----------------------------
Comment 4 Satyam Kandula CLA 2010-11-30 01:36:17 EST
(In reply to comment #3)
You might also have to change the -vm argument in eclipse.ini file to use java.exe instead of javaw.exe.
Comment 5 Dani Megert CLA 2010-11-30 02:53:19 EST
Satyam, please setup a test case that creates a new Java project with 200 JARs (not just simple ones) and compare the performance.

Also, double-check that the changes made for 323514 do not cross this code path.
Comment 6 Satyam Kandula CLA 2010-12-02 04:49:41 EST
(In reply to comment #5)
I have created a performance test where there are 300 jars (RAD plugins)  and tried running with 3.4.2 and 3.6 eclipse and could see a degradation of around 6%. It doesn't confirm to the numbers that Gaurav mentioned. I will try to spend some time trying to understand this degradation. 

With HEAD:  
                  13.78s
                  13.97s
                  13.84s
                  14.09s
                  13.83s
                  14s
                  13.91s
                  13.75s
                  13.61s
                  13.62s
Avg: 13.84

With 3.4.2: 12.95s
                     13.06s
                     13.09s
                     12.95s
                     13.02s
                     13.09s
                     13.14s
                     13.56s
                     13.02s
                     13.32s
Avg: 13.12
Comment 7 Satyam Kandula CLA 2010-12-02 04:59:21 EST
(In reply to comment #1)
> Created an attachment (id=184003) [details]
> Contains yourkit snapshots
Many time consuming functions called by AddJarFileToIndex.execute() have increased propotionately. That could mean the function got called more number of times or an underlying function time has increased. 

Gaurav tells that the same sets of libraries are used in both the cases and in my run with RAD8.1, I could see no duplicate calls to AddJarFiletoIndex.execute(). That could mean that the function should be called the same number of times! 

I couldn't find any underlying function which could have increased in 3.6. 

First, I will investigate more from the data mentioned in comment 6 and come back to this snapshots.
Comment 8 Dani Megert CLA 2010-12-02 05:27:36 EST
>With HEAD:  
Did that already include the fix for bug 323514? If so, please measure again without that fix.
Comment 9 Satyam Kandula CLA 2010-12-02 05:34:59 EST
(In reply to comment #8)
> >With HEAD:  
> Did that already include the fix for bug 323514? If so, please measure again
> without that fix.
No, it didn't include the fix for the bug 323514. I took yesterday's HEAD :(. I don't think this should run into the patch, but I will try runs with the 'HEAD as of today' also.
Comment 10 Satyam Kandula CLA 2010-12-02 06:09:58 EST
(In reply to comment #9)
> (In reply to comment #8)
> > >With HEAD:  
> > Did that already include the fix for bug 323514? If so, please measure again
> > without that fix.
> No, it didn't include the fix for the bug 323514. I took yesterday's HEAD :(. I
> don't think this should run into the patch, but I will try runs with the 'HEAD
> as of today' also.
The numbers look similar!
Comment 11 Olivier Thomann CLA 2010-12-07 11:46:44 EST
So do we really have an issue there ?
Comment 12 Dani Megert CLA 2010-12-27 05:39:22 EST
Gauray, there's nothing we can do without a test case / steps to reproduce.
Comment 13 Dani Megert CLA 2011-01-12 04:45:19 EST
Sorry, nothing we can do without steps/details.
Comment 14 Dani Megert CLA 2011-01-12 04:45:51 EST
Sorry, nothing we can do without steps/details and we already have 3.6.2 RC1 this week.
Comment 15 Gaurav Mising name CLA 2011-01-12 06:25:44 EST
Thanks for the update Dani. There's a defect in the adopter project that is under investigation to determine if this bug is still valid. If that would be the case then this might be reopened. I am fine with the current status as of now.
Comment 16 Olivier Thomann CLA 2011-01-25 12:31:07 EST
Verified.