Bug 9185 - Severe shutdown performance problem
Summary: Severe shutdown performance problem
Status: RESOLVED FIXED
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 2.0   Edit
Hardware: PC Windows 2000
: P1 major (vote)
Target Milestone: 2.0 M3   Edit
Assignee: Jerome Lanneluc CLA
QA Contact:
URL:
Whiteboard:
Keywords:
: 6167 (view as bug list)
Depends on:
Blocks:
 
Reported: 2002-02-06 13:06 EST by John Arthorne CLA
Modified: 2002-02-12 07:51 EST (History)
1 user (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description John Arthorne CLA 2002-02-06 13:06:10 EST
Build 20020205

I have experienced severely slow shutdown times with the latest build.  I added 
some tracing in the plugin registry shutdown, and found that shutting down the 
jdt.core plugin is the culprit. 

Test case:

1) Open a brand new workbench
2) Create a java project
3) Immediately shutdown

The following trace information is displayed:

Shutting down plugin: org.eclipse.jdt.core
Finished plugin shutdown for org.eclipse.jdt.core time: 311869ms

That's over 5 minutes!  I hope to make these trace options available in a build 
soon.  In this case it looks like it was indexing rt.jar, and the shutdown() 
method was waiting on the index manager thread.
Comment 1 Philipe Mulet CLA 2002-02-07 07:39:42 EST
When shutting down, we attempt to flush all our queued indexing jobs, except 
for the current one in process.

Need to investigate... where you leaving your workspace up for some time, or 
simply entering/exiting ?
Comment 2 John Arthorne CLA 2002-02-07 09:56:38 EST
The absolute worst case is the one described below, where you immediately exit 
after creating a project in a new workspace.  This is mostly experienced in test 
workspaces that are changing alot and being started/shutdown often.  It's very 
typical when I'm trying to reproduce a PR that I open a new workspace, create a 
bunch of projects/resources, then immediately shutdown.  I find it surprising, 
because I thought even rt.jar shouldn't take several minutes to index.  This is 
behaviour I've only noticed recently.
Comment 3 Jerome Lanneluc CLA 2002-02-07 12:43:21 EST
For me, the shutdown time seems acceptable (around 15s).

Could you please add a .options file that contains the following lines:
org.eclipse.jdt.core/debug=true
org.eclipse.jdt.core/debug/indexmanager=true

and start your workspace in debug mode.

Here is what I'm getting when I follow your scenario:
-> requesting job (Thread[main,5,main]): indexing D:\JDK1.3.1\jre\lib\rt.jar
-> requesting job (Thread[main,5,main]): indexing project /Test
STARTING (Thread[Java indexing,5,main]) - ensuring consistency
-> requesting job (Thread[Java indexing,5,main]): indexing project /Test
DONE (Thread[Java indexing,5,main]) - ensuring consistency
-> executing (Thread[Java indexing,5,main]): indexing D:\JDK1.3.1\jre\lib\rt.jar
        3 awaiting jobs.
 index name: D:\JDK1.3.1\jre\lib\rt.jar <----> 3932063872.index
INDEX (Thread[Java indexing,5,main]): D:\JDK1.3.1\jre\lib\rt.jar
 index name: D:\JDK1.3.1\jre\lib\rt.jar <----> 3932063872.index
 index name: \Test <----> 1657330681.index
INDEX : D:\JDK1.3.1\jre\lib\rt.jar COMPLETE in 12768 ms
Comment 4 John Arthorne CLA 2002-02-07 16:08:06 EST
Below is my exact console output after running the original test case (create 
project then immediately close).  Some more notes:

- this is from running a second instance of Eclipse in debug mode using the self 
hosting launcher (Debug With -> Eclipse).  My first workspace is a standard 
self-hosting setup with core projects as source and all other projects as 
binary.  My machine is a newish PIII 1.4GHZ with 512MB RAM.


Install URL: file:/D:/1target/
Debug-Options: file:/D:/1target/.options
STARTING (Thread[Java indexing,5,main]) - ensuring consistency
DONE (Thread[Java indexing,5,main]) - ensuring consistency
-> requesting job (Thread[main,5,main]): indexing D:\jre\lib\rt.jar
-> executing (Thread[Java indexing,5,main]): indexing D:\jre\lib\rt.jar
	1 awaiting jobs.
 index name: D:\jre\lib\rt.jar <----> 2938702037.index
INDEX (Thread[Java indexing,5,main]): D:\jre\lib\rt.jar
 index name: D:\jre\lib\rt.jar <----> 2938702037.index
-> requesting job (Thread[main,5,main]): indexing project /f
 index name: \f <----> 4077307082.index
INDEX : D:\jre\lib\rt.jar COMPLETE in 349122 ms
-> merging index : 
d:\eclipse\test\.metadata\.plugins\org.eclipse.jdt.core\2938702037.index
Comment 5 Jerome Lanneluc CLA 2002-02-07 17:58:22 EST
I got this kind of number (i.e. several minutes to shutdown the workspace) only 
when I used Sun's JDK1.3 under debug. This VM is known for its slowness under 
debug. When running under Sun's JDK1.3.1 or 1.4, I got numbers around 30s.
By any chance, are you running Sun's JDK1.3 as the target VM?
Comment 6 John Arthorne CLA 2002-02-08 09:36:14 EST
I'm using IBM JRE 1.3.0 (cn130-20010502).  I think this is the one that 
shipped with Eclipse 1.0.  I'll try upgrading to a new IBM JRE and see how it 
performs.
Comment 7 Jerome Lanneluc CLA 2002-02-11 13:18:32 EST
Fixed by cancelling the current job when shuting down. The index will be 
recomputed on next startup.
Comment 8 Philipe Mulet CLA 2002-02-12 07:51:42 EST
*** Bug 6167 has been marked as a duplicate of this bug. ***