Bug 187202 - [europa]: startup - number of loaded plugins varies
Summary: [europa]: startup - number of loaded plugins varies
Status: RESOLVED INVALID
Alias: None
Product: Community
Classification: Eclipse Foundation
Component: Cross-Project (show other bugs)
Version: unspecified   Edit
Hardware: PC Windows XP
: P3 major (vote)
Target Milestone: ---   Edit
Assignee: Cross-Project issues CLA
QA Contact:
URL:
Whiteboard:
Keywords: performance
Depends on:
Blocks:
 
Reported: 2007-05-16 04:20 EDT by Eric Jodet CLA
Modified: 2007-08-10 02:50 EDT (History)
6 users (show)

See Also:


Attachments
[screen shot] plugins that fail to load (97.76 KB, image/jpeg)
2007-05-16 04:21 EDT, Eric Jodet CLA
no flags Details
[file] .log file (10.83 KB, application/x-zip-compressed)
2007-05-16 04:22 EDT, Eric Jodet CLA
no flags Details
[file] plugin activation trace files (5.46 KB, application/x-zip-compressed)
2007-05-16 04:23 EDT, Eric Jodet CLA
no flags Details
[file] plugin activation trace file (5.33 KB, application/octet-stream)
2007-05-16 09:25 EDT, Eric Jodet CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Eric Jodet CLA 2007-05-16 04:20:13 EDT
Version: 3.3.0
Build id: I20070323-1616
Europa: all but 3 projects / features

context:
- workspace contains all WID plugins (1600+ projects)
- activating Resources perspective only (no other active perspective)
- use instrumented core.runtime to monitor plugin activation

test:
- start europa, and wait until jdt tool initialization is complete
- do nothing else

From the (to_be_attached) resulting trace files, starting europa against the same wks using the very same perspective sometimes activates 63 plugins, sometimes 83.
--> do we expect 63 or 83 plugins to load?
--> note that when "only" loading 63 plugins, we gain 3 sec on startup times.
Note that base M6 Eclipse is stable, activating 32 plugins

I'll attach some files (trace, .log, diff screen shot)

From the .log, it sounds like Mylar is having some troubles.
Comment 1 Eric Jodet CLA 2007-05-16 04:21:57 EDT
Created attachment 67363 [details]
[screen shot] plugins that fail to load
Comment 2 Eric Jodet CLA 2007-05-16 04:22:25 EDT
Created attachment 67364 [details]
[file] .log file
Comment 3 Eric Jodet CLA 2007-05-16 04:23:39 EDT
Created attachment 67365 [details]
[file] plugin activation trace files
Comment 4 Eric Jodet CLA 2007-05-16 04:25:08 EDT
Also note that I performed similar tests using the Java and PDE perspectives, and did not encounter the same issue: the number of activated plugins was stable - 68)
Comment 5 Dani Megert CLA 2007-05-16 04:39:17 EDT
Added Mik, since one of the causes for some plug-ins not being loaded is the timeout from Mylar:
!MESSAGE While loading class "org.eclipse.mylar.context.core.ContextCorePlugin", thread "Thread[main,6,main]" timed out waiting (5000ms) for thread "Thread[Worker-2,5,main]" to finish starting bundle "update@plugins/org.eclipse.mylar.context.core_2.0.0.v20070403-1300.jar [569]". To avoid deadlock, thread "Thread[main,6,main]" is proceeding but "org.eclipse.mylar.context.core.ContextCorePlugin" may not be fully initialized.

So, I guess the higher number would be the "normal" state. Remains the question why that many plug-ins need to be activated in this scenario.
Comment 6 Eric Jodet CLA 2007-05-16 09:25:26 EDT
Created attachment 67398 [details]
[file] plugin activation trace file

Another trace file (same startup scenario) - this time 96 plugins were loaded
Comment 7 Mik Kersten CLA 2007-05-16 10:50:57 EDT
I will try to replicate this for Mylar and have seen those message a while back, though they don't typically cause failures.  However, note that the version is 2.0.0.v20070403 and I'll be trying it with the current 2.0.0.v20070514.  
Comment 8 Dani Megert CLA 2007-05-21 09:10:53 EDT
Mik, I guess the fixed state will be that the Mylar and those referenced by it will be loaded, right? If so, could you rewrite your code to not activate all those plug-ins until those that you want to hook into are loaded through user interaction? This can be done by registering a bundle listener in a base Mylar plug-in's start() method.
Comment 9 Jeff McAffer CLA 2007-05-22 09:38:57 EDT
The messages in comment 5 happen when two bundles are trying to start another bundle.  This in turn happens typically when the bundle being started takes too long in its activator.  The way to solve this (and improve performance) is to stop doing so much work in the activator.
Comment 10 Mik Kersten CLA 2007-05-22 22:16:57 EDT
Jeff: the thing that I don't get about this problem (also reported on bug 188524) is that we have only noticed it happen on the first restart via the update manager, and not subsequently.  Also, I am not aware of bad behavior that it causes.  The Update Manager connection made me suspect that this is a result of the shell being killed (bug 107280) in case some OSGi registry is expecting SellListener.shellClosed() or some other event to be fired.  Or perhaps it is just that the first start of our bundles is slower?

Due to startup failures that Mylar used to have around 1.0 we have tried to move a bunch of work from happening synchronously in the activator.  However, our current architecture requires Mylar Connectors (e.g. Bugzilla) to be loaded before the Task List is read.  And since in our UI design the Task List contents are as important to show on startup as Workspace resource contents and task editors need to be restored, we cause connector plug-ins to be initialized on startup.  So far we have been successful at minimizing the effects of this.  Since we are likely stuck with this architecture for 2.0 I will investigate whether we can minimize what happens on activation (via bug 188524).
Comment 11 Jeff McAffer CLA 2007-05-22 23:06:43 EDT
ok. I don't have any particular insight here.  I would observe however that a common approach for avoiding things like task list population on activation is to defer the work and do it incrementally in a different thread (or some such).  this allows the UI to paint and the system to continue starting while the content is incrementally filled in.  Another option is to move the initialization of whatever structures are being initialized to be done lazily on access rather than aggressively on activation.  That way the it is the first accessor's thread that pays for the work not the Main thread at startup.

Anyway, my intention was not to get into the details here but rather just point out the underlying issue at play.
Comment 12 Eric Jodet CLA 2007-05-23 01:16:42 EDT
(In reply to comment #10)
(...)
" is that we have only noticed it happen on the first restart via the
update manager, and not subsequently. "
(...)

Mik,
I noticed this issue while taking europa startup measures: my europa config was 'long' installed and was not in the case of a re-start after install
Comment 13 Mik Kersten CLA 2007-05-23 10:17:48 EDT
(In reply to comment #11)
> That way the it is the first accessor's thread that pays for the work not the Main thread at startup.

Thanks Jeff.  We already do the bulk of the work asynchronously in another thread and I will investigate whether I can push any more of it off.

 (In reply to comment #12)
> I noticed this issue while taking europa startup measures: my europa config was
> 'long' installed and was not in the case of a re-start after install

I'm not sure I know what you mean by 'long' installed?  
Comment 14 Jeff McAffer CLA 2007-05-23 11:50:07 EDT
I suspect that he means it was installed along time ago, not just installed using update.
Comment 15 Eric Jodet CLA 2007-05-23 13:23:34 EDT
(In reply to comment #14)
by 'long' I was meaning that I had started / stopped europa many times,
and the problem did not occur right after the update part of the install.
Typical scenario is:
- unzip base eclipse (M6)
- start eclipse, go to the update site and install all installable features
- re-boot as requested
- stop europa
- re-start and observe
Comment 16 Mik Kersten CLA 2007-05-23 16:13:22 EDT
Jeff: could there be a bad interaction between the plug-in registry/launching and Update-based restart (which does not close the workbench normally, bug 107280)?

Eric: next time you're testing you could try saying "No" to the Update Manager's restart recommendation and restart the workbench as usual.  But given the latest comments on bug 107280 I think that we're stuck with the current behavior.
Comment 17 Jeff McAffer CLA 2007-05-23 22:48:28 EDT
certainly if you shutdown incorrectly then on restart various recovery strategies may get triggered resulting in more code loaded and plugins activated.  
Comment 18 Eric Jodet CLA 2007-05-28 09:07:11 EDT
(In reply to comment #16)
While performing some europa install tests at M7 level (the was opened at M6 level), performed some install variation (reply no to the restart request after feature install).
Sounds like this was a transient issue as the number of activated plugins is now stable (88).
As I cannot reproduce the issue anymore, please feel free to close this bug.
Comment 19 Mik Kersten CLA 2007-05-29 08:35:16 EDT
I'm still somewhat concerned about this, but will explore my concerns on Mylar bug 188524 where I will try to figure out if there is anything that we could be doing to avoid the warnings other than starting faster.  Whenever we have had this happen or had it reported happen the problem has happened on Update Manager based restart, has not caused any problems, and has been transient.  We did just hear about a possible deadlock (Mylar bug 189054) which I'm investigating but it's not clear that's related.
Comment 20 Bjorn Freeman-Benson CLA 2007-08-10 02:50:33 EDT
I'm closing this bug as Europa has shipped. If there continue to be issues, please reopen this bug or, better yet, with the individual projects involved.