Bug 188712 - Initializing Java Tooling blocks user operations
Summary: Initializing Java Tooling blocks user operations
Status: VERIFIED WORKSFORME
Alias: None
Product: JDT
Classification: Eclipse Project
Component: Core (show other bugs)
Version: 3.3   Edit
Hardware: PC Windows XP
: P3 normal (vote)
Target Milestone: 3.4 M3   Edit
Assignee: Eric Jodet CLA
QA Contact:
URL:
Whiteboard:
Keywords: needinfo, performance
Depends on:
Blocks:
 
Reported: 2007-05-23 14:19 EDT by Pascal Rapicault CLA
Modified: 2009-03-19 09:01 EDT (History)
10 users (show)

See Also:


Attachments
JDT related exceptions generated (36.18 KB, text/plain)
2007-10-04 15:02 EDT, Pete Ellis CLA
no flags Details
Thread dump during stall of Init Java Tooling task (11.04 KB, text/plain)
2007-10-05 07:33 EDT, Pete Ellis CLA
no flags Details
3 dumps of a slow initialization (74.29 KB, text/plain)
2007-10-08 03:55 EDT, Philipe Mulet CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Pascal Rapicault CLA 2007-05-23 14:19:31 EDT
Eclipse went great length to improve the perceived startup time (ie faster splash screen, background work, etc.), however for someone java/plug-in development this is kind of fake since before anything interesting can be done the java model has to be initialized which can take a non trivial amount of time...
Is there a way that the java model could be loaded progressively to allow the user to start working as soon as the workbench is open?
Comment 1 Jerome Lanneluc CLA 2007-05-24 06:19:23 EDT
In theory, you can start working with the Java model before the "Initializing Java Tooling" job has finished. What 'interesting' thing are you trying to do that requires this job to complete first ?

Also this job should not take more than a couple of seconds. It should now indicate what steps it is doing (for example "configuring Plug-in Dependencies" indicates that the PDE container is running). So if you find that these "configuring" steps take too long, you should enter a bug against the corresponding component. To find out which component is running, simply take a thread dump and look at the top of the stack for the thread that is initializing the classpath container.
Comment 2 Philipe Mulet CLA 2007-05-25 05:06:42 EDT
This really is background processing, and unfortunately the code at work is calling out in 3rd party extensions (classpath initializers) such as Debug (JRE container) or PDE (prereq plug-ins container). 

As Jerome said, expectation is that the job should complete within seconds (<10s). Now, since it needs a few rsc locks, if another job is preventing it to make progress, this can become problematic (we've seen instances of these in the past). 
Comment 3 Pascal Rapicault CLA 2007-05-25 10:14:31 EDT
The interesting thing I'm trying to do is open a type using "ctrl+sht+T".
Comment 4 Jerome Lanneluc CLA 2007-06-11 12:59:04 EDT
Reproduced under the debugger:
1. Put a breakpoint at line 177 of org.eclipse.jdt.internal.core.search.processing.JobManager
2. Start an existing runtime workbench under debug
3. Wait for the breakpoint to be hit
4. Disable the breakpoint but don't resume the 'Initializing Java Tooling' job
5. Ctrl+Shift+T
6. Start typing the name of the class you want to open
Observe: The 'Open Type in Hierarchy' dialog doesn't update.

I verified that the searchAllTypeName query resulting from step 6 correctly returns the requested type. It looks like a UI problem.

Moving to JDT/UI
Comment 5 Olivier Thomann CLA 2007-06-11 13:04:03 EDT
On my "slow" laptop, the initialization time is clearly above 10s
Comment 6 Martin Aeschlimann CLA 2007-06-12 04:16:05 EDT
I filed bug 192112 to investigate why the open type dialog doesn't show results before the initialize job is finished. I think it probably has to do with our code that tries to find out if the history elements still exist.

Jerome, how can the search engine bring results without knowing the full class paths? Shall we better use the search engine for 'exist' tests of history elements?

As this bugs title is about the Java model initial initialization performance, and most comments are about this topic, I suggest to keep this bug for the initialization performance, and the new bug for the open type dialog behavior. 

Comment 7 Jerome Lanneluc CLA 2007-06-12 05:07:12 EDT
(In reply to comment #6)
> Jerome, how can the search engine bring results without knowing the full class
> paths? Shall we better use the search engine for 'exist' tests of history
> elements?
Sorry, I don't understand your question. Is it about bug 192112 ?

> As this bugs title is about the Java model initial initialization performance,
> and most comments are about this topic, I suggest to keep this bug for the
> initialization performance, and the new bug for the open type dialog behavior. 
Pascal, are they other "interesting things" that you are trying to do and that are blocked by the "Initializing Java Tooling" job ?

Comment 8 Martin Aeschlimann CLA 2007-06-12 05:11:43 EDT
>> Jerome, how can the search engine bring results without knowing the full class
>> paths? Shall we better use the search engine for 'exist' tests of history
>> elements?
> Sorry, I don't understand your question. Is it about bug 192112 ?

Yes, this question is relevant for bug 192112, so we can have the discussion in bug 192112. I will ask it again there.
Comment 9 Pete Ellis CLA 2007-10-04 15:02:50 EDT
Created attachment 79764 [details]
JDT related exceptions generated

I'm seeing a periodic stall of the "Initialize Java Tooling" task at which it seems to halt at 60% complete for perhaps 10 to 15 seconds and then continues to completion.  I've described this in the following newsgroup post:

http://dev.eclipse.org/newslists/news.eclipse.platform/msg68918.html

I've attached the content of the .log file from the workspace on which I launch test workbench sessions.  The odd thing here is that the warnings are generated in the test workbench session *after* the test workbench session in which I see the Initialize Java Tooling task stall temporarily (or perhaps they are generated when I shut down the test workbench session in which the stall occurs... difficult to tell).

Hope this helps, -Pete
Comment 10 Pete Ellis CLA 2007-10-04 15:07:15 EDT
Another quick follow-up on this:  The test workbench that experiences the stall is running with a workspace that contains no Java projects or Java source code files of any kind.  Thus, I'm not sure what in the workspace (or what action I take) would trigger the initialization of java tooling to begin with.
Comment 11 Jerome Lanneluc CLA 2007-10-05 05:01:23 EDT
(In reply to comment #9)
> Created an attachment (id=79764) [details]
> JDT related exceptions generated
These exceptions are not related to the "Initializing Java Tooling" job. They indicate that there was a problem during class loading. I would suggest to enter a separate bug against Platform/Runtime.

> I'm seeing a periodic stall of the "Initialize Java Tooling" task at which it
> seems to halt at 60% complete for perhaps 10 to 15 seconds and then continues
> to completion. 
Could you please take thread-dumps (kill -3 <pid>) during the 10-15 seconds delay and attach them to this bug ?
Comment 12 Pete Ellis CLA 2007-10-05 07:33:57 EDT
Created attachment 79796 [details]
Thread dump during stall of Init Java Tooling task

I've attached a thread dump.  I was able to consistently obtain similar thread dumps multiple times, so this should be a good indication of activities at the time of the stall.  I was able to trigger the Initialize Java Tooling task consistently by opening a text editor on a workspace project's .project file.

I'll hold off on creating a new bug until this thread dump is examined.  There are some similarities in content between the thread dump and the exception traces (specifically, references to the "org.eclipse.jface.text.reconciler.MonoReconciler ").
Comment 13 Philipe Mulet CLA 2007-10-07 06:28:04 EDT
Eric - pls investigate
Comment 14 Philipe Mulet CLA 2007-10-08 03:55:09 EDT
Created attachment 79876 [details]
3 dumps of a slow initialization

Maybe a different issue (?)
I noticed a very slow startup situation, where the Java init job stood at 0% for couple minutes. I took 3 dumps in a row.
Comment 15 Jerome Lanneluc CLA 2007-10-08 04:25:02 EDT
(In reply to comment #12)
> Created an attachment (id=79796) [details]
> Thread dump during stall of Init Java Tooling task
As suspected, this thread dump shows a problem during class loading. Please open a separate bug report.
Comment 16 Jerome Lanneluc CLA 2007-10-08 04:26:51 EDT
(In reply to comment #14)
> Created an attachment (id=79876) [details]
> 3 dumps of a slow initialization
> 
> Maybe a different issue (?)
The 3 dumps show that the "Initializing Java tooling" job is running the PDE class path initializer.
Comment 17 Philipe Mulet CLA 2007-10-08 04:30:57 EDT
Re: comment 14
Forgot to mention this occurred with 3.4 build I20071002-1342
Comment 18 Jerome Lanneluc CLA 2007-10-08 06:03:10 EDT
(In reply to comment #16)
> (In reply to comment #14)
> > Created an attachment (id=79876) [details] [details]
> > 3 dumps of a slow initialization
> > 
> > Maybe a different issue (?)
> The 3 dumps show that the "Initializing Java tooling" job is running the PDE
> class path initializer.
> 
Entered bug 205705 to track this down.

Renaming this bug from "Initialization of java model takes a long time" to "Initializing Java Tooling blocks user operations" to reflect what Pascal reported.

Pascal please reopen if you have more information. So far we have not been able to find a case where "anything interesting" can't be done while this job is running.
Comment 19 David Audel CLA 2007-10-29 08:40:35 EDT
Verified for 3.4M3 using I20071029-0010 build.
Comment 20 Tim MacEachern CLA 2009-03-19 08:58:47 EDT
I've had a similar complete hang, multiple times at startup at 1% completion.  Eclipse 3.4.2.  In my system I had both a 1.5 JDK installed and a 1.6 JRE.  JAVA_HOME was pointing to the JDK.  I was able to resolve the problem by revising JAVA_HOME to point to the JRE.
Comment 21 Tim MacEachern CLA 2009-03-19 09:01:17 EDT
Follow-up to my last comment -- the 1.6 JRE was installed before the 1.5 JDK, but I reinstalled the JRE before changing the JAVA_HOME setting.  Installation order may matter.  This was on Windows XP.