Skip to main content


Eclipse Community Forums
Forum Search:

Search      Help    Register    Login    Home
Home » Eclipse Projects » Virgo » Virgo kernel fails to start(Kernel failed to start within XXX seconds.)
Virgo kernel fails to start [message #1734253] Mon, 06 June 2016 14:47 Go to next message
Bisser P is currently offline Bisser PFriend
Messages: 3
Registered: May 2012
Junior Member
Hello,

We experience an intermittent problem -- the Virgo kernel fails to start. After 10 minutes, it fails with:

Quote:
[ERROR] startup-tracker <KE0004E> Kernel failed to start within 600 seconds.


We use Virgo 3.6.4_b.RELEASE.

Initially, we thought that the problem might be caused by our infrastructure being too slow, but it seems it's not that. The thread dump doesn't indicate such problems. Instead, it seems to indicate that all threads are thinking that their work is complete and are waiting for a signal for more work. I have attached the thread dump in case anybody is interested.

The log contains the following errors, logged once each minute:

Quote:
[2016-06-01T04:16:18.355Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&repository' in bundle 'org.eclipse.virgo.kernel.osgi' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'.
[2016-06-01T04:16:18.396Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&globalRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.4.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=global))'.
[2016-06-01T04:16:18.398Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'.
[2016-06-01T04:16:18.400Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'.
[2016-06-01T04:16:18.409Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&runtimeArtifactModel' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.deployer.model.RuntimeArtifactModel)'.
[2016-06-01T04:16:18.411Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&userRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.4.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=org.eclipse.virgo.region.user))'.
[2016-06-01T04:16:18.811Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&repository' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'.
[2016-06-01T04:16:19.024Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'.
[2016-06-01T04:16:19.027Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&importExpander' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)'.
[2016-06-01T04:16:19.030Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&osgiFramework' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)'.
[2016-06-01T04:16:19.036Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'.
[2016-06-01T04:16:19.037Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&userBundleContext' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.4.RELEASE' is waiting for service with filter '(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))'.
[2016-06-01T04:16:19.039Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference 'artifactBridges#org.eclipse.gemini.blueprint.service.importer.support.OsgiServiceCollectionProxyFactoryBean#0' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.ArtifactBridge)'.
[2016-06-01T04:16:19.040Z] [WARN ] service-monitor-thread-1 org.eclipse.virgo.medic.eventlog.default KE0100W Reference '&workArea' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.4.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.services.work.WorkArea)'.


Given all the bundle/service dependencies, it all boils down to bundle org.eclipse.virgo.kernel.services_3.6.4.RELEASE which hasn't published its services.

Can anyone of you, guys, figure out what might be wrong? Can there be some subtle concurrency/liveness issues in the Virgo kernel?

I have also attached the log file under the name 'serviceability.zip'.
Re: Virgo kernel fails to start [message #1737274 is a reply to message #1734253] Wed, 06 July 2016 18:56 Go to previous messageGo to next message
daniel marthaler is currently offline daniel marthalerFriend
Messages: 77
Registered: April 2012
Location: Zürich
Member
Have you found the solution to your problem? If not could you please provide more information about the OS and machine you try to start Virgo Kernel.

Regards,
Dani
Re: Virgo kernel fails to start [message #1737750 is a reply to message #1737274] Tue, 12 July 2016 13:12 Go to previous messageGo to next message
Tony Ganchev is currently offline Tony GanchevFriend
Messages: 7
Registered: July 2016
Junior Member
Thanks a lot for the follow-up, Daniel!

Unfortunately we (I work with Bisser) haven't yet found a solution.

The issue is predominantly hit on Windows Server 2008/2012 and Photon OS and previously on SUSE Linux Enterprise Server, all of them 64 bit.

Let me give you more info on the chronology of the issues that we hit and the changes we tried and our current theory.

1) Unmodified Virgo
Sometimes kernel deployment failed with the following error:

[2016-02-01T20:03:02.042Z] [INFO ] startup-tracker               <KE0001I> Kernel starting. 
[2016-02-01T20:03:08.705Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.osgi' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:03:08.881Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&globalRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=global))'. 
[2016-02-01T20:03:08.882Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=org.eclipse.virgo.region.user))'. 
[2016-02-01T20:03:08.883Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&runtimeArtifactModel' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.deployer.model.RuntimeArtifactModel)'. 
[2016-02-01T20:03:08.973Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:03:08.991Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:03:11.895Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&osgiFramework' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)'. 
[2016-02-01T20:03:11.904Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:03:11.908Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&workArea' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.services.work.WorkArea)'. 
[2016-02-01T20:03:11.922Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:03:11.926Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userBundleContext' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))'. 
[2016-02-01T20:03:11.927Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference 'artifactBridges#org.eclipse.gemini.blueprint.service.importer.support.OsgiServiceCollectionProxyFactoryBean#0' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.ArtifactBridge)'. 
[2016-02-01T20:03:11.947Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:03:11.956Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&importExpander' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)'. 
[2016-02-01T20:03:23.774Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.osgi' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:03:23.882Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&globalRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=global))'. 
[2016-02-01T20:03:23.883Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=org.eclipse.virgo.region.user))'. 
[2016-02-01T20:03:23.884Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&runtimeArtifactModel' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.deployer.model.RuntimeArtifactModel)'. 
[2016-02-01T20:03:23.965Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:03:23.991Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:03:27.011Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&osgiFramework' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)'. 
[2016-02-01T20:03:27.017Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:03:27.027Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&workArea' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.services.work.WorkArea)'. 
[2016-02-01T20:03:27.033Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:03:27.038Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userBundleContext' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))'. 
[2016-02-01T20:03:27.044Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference 'artifactBridges#org.eclipse.gemini.blueprint.service.importer.support.OsgiServiceCollectionProxyFactoryBean#0' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.ArtifactBridge)'. 
[2016-02-01T20:03:27.045Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:03:27.045Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&importExpander' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)'. 
[2016-02-01T20:04:08.879Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.osgi' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:04:08.886Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&globalRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=global))'. 
[2016-02-01T20:04:08.890Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=org.eclipse.virgo.region.user))'. 
[2016-02-01T20:04:08.890Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&runtimeArtifactModel' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.deployer.model.RuntimeArtifactModel)'. 
[2016-02-01T20:04:09.027Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:04:09.029Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:04:12.010Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&osgiFramework' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)'. 
[2016-02-01T20:04:12.017Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:04:12.022Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&workArea' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.services.work.WorkArea)'. 
[2016-02-01T20:04:12.029Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:04:12.037Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userBundleContext' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))'. 
[2016-02-01T20:04:12.045Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference 'artifactBridges#org.eclipse.gemini.blueprint.service.importer.support.OsgiServiceCollectionProxyFactoryBean#0' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.ArtifactBridge)'. 
[2016-02-01T20:04:12.046Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:04:12.046Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&importExpander' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)'. 
[2016-02-01T20:05:08.788Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.osgi' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:05:08.886Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&globalRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=global))'. 
[2016-02-01T20:05:08.890Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=org.eclipse.virgo.region.user))'. 
[2016-02-01T20:05:08.892Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&runtimeArtifactModel' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.deployer.model.RuntimeArtifactModel)'. 
[2016-02-01T20:05:09.027Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:05:09.030Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:05:12.011Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&osgiFramework' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)'. 
[2016-02-01T20:05:12.023Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:05:12.025Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&workArea' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.services.work.WorkArea)'. 
[2016-02-01T20:05:12.031Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:05:12.038Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userBundleContext' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))'. 
[2016-02-01T20:05:12.046Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference 'artifactBridges#org.eclipse.gemini.blueprint.service.importer.support.OsgiServiceCollectionProxyFactoryBean#0' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.ArtifactBridge)'. 
[2016-02-01T20:05:12.047Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:05:12.048Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&importExpander' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)'. 
[2016-02-01T20:06:08.790Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.osgi' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:06:08.886Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&globalRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=global))'. 
[2016-02-01T20:06:08.891Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=org.eclipse.virgo.region.user))'. 
[2016-02-01T20:06:08.892Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&runtimeArtifactModel' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.deployer.model.RuntimeArtifactModel)'. 
[2016-02-01T20:06:09.029Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:06:09.031Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:06:12.012Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&osgiFramework' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)'. 
[2016-02-01T20:06:12.022Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:06:12.026Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&workArea' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.services.work.WorkArea)'. 
[2016-02-01T20:06:12.031Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:06:12.039Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userBundleContext' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))'. 
[2016-02-01T20:06:12.046Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference 'artifactBridges#org.eclipse.gemini.blueprint.service.importer.support.OsgiServiceCollectionProxyFactoryBean#0' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.ArtifactBridge)'. 
[2016-02-01T20:06:12.047Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:06:12.053Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&importExpander' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)'. 
[2016-02-01T20:07:08.790Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.osgi' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:07:08.886Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&globalRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=global))'. 
[2016-02-01T20:07:08.891Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=org.eclipse.virgo.region.user))'. 
[2016-02-01T20:07:08.892Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&runtimeArtifactModel' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.deployer.model.RuntimeArtifactModel)'. 
[2016-02-01T20:07:09.029Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:07:09.034Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:07:12.013Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&osgiFramework' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)'. 
[2016-02-01T20:07:12.029Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'. 
[2016-02-01T20:07:12.032Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&workArea' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.services.work.WorkArea)'. 
[2016-02-01T20:07:12.035Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'. 
[2016-02-01T20:07:12.040Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&userBundleContext' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))'. 
[2016-02-01T20:07:12.046Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference 'artifactBridges#org.eclipse.gemini.blueprint.service.importer.support.OsgiServiceCollectionProxyFactoryBean#0' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.repository.ArtifactBridge)'. 
[2016-02-01T20:07:12.051Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'. 
[2016-02-01T20:07:12.053Z] [WARN ] service-monitor-thread-1      <KE0100W> Reference '&importExpander' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' is waiting for service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)'. 
[2016-02-01T20:08:03.810Z] [ERROR] ng DM Context Creation Timer  <AG0000E> Application context creation failure for bundle 'org.eclipse.virgo.kernel.osgi' version '3.6.3.RELEASE'. org.springframework.context.ApplicationContextException: Application context initialization for 'org.eclipse.virgo.kernel.osgi' has timed out waiting for (objectClass=org.eclipse.virgo.repository.Repository)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.timeout(DependencyWaiterApplicationContextExecutor.java:489)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.access$000(DependencyWaiterApplicationContextExecutor.java:54)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor$WatchDogTask.run(DependencyWaiterApplicationContextExecutor.java:109)
	at java.util.TimerThread.mainLoop(Timer.java:555)
	at java.util.TimerThread.run(Timer.java:505)

[2016-02-01T20:08:03.838Z] [ERROR] ng DM Context Creation Timer  <AG0000E> Application context creation failure for bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE'. org.springframework.context.ApplicationContextException: Application context initialization for 'org.eclipse.virgo.kernel.model' has timed out waiting for (|(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)(objectClass=org.eclipse.virgo.kernel.deployer.model.RuntimeArtifactModel)(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=global))(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=org.eclipse.virgo.region.user)))
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.timeout(DependencyWaiterApplicationContextExecutor.java:489)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.access$000(DependencyWaiterApplicationContextExecutor.java:54)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor$WatchDogTask.run(DependencyWaiterApplicationContextExecutor.java:109)
	at java.util.TimerThread.mainLoop(Timer.java:555)
	at java.util.TimerThread.run(Timer.java:505)

[2016-02-01T20:08:06.483Z] [ERROR] kernel-dm-4                   <AG0000E> Application context creation failure for bundle 'org.eclipse.virgo.kernel.services' version '3.6.3.RELEASE'. org.springframework.beans.factory.BeanExpressionException: Expression parsing failed; nested exception is org.eclipse.gemini.blueprint.service.ServiceUnavailableException: service matching filter=[(objectClass=org.eclipse.virgo.nano.core.KernelConfig)] unavailable
	at org.springframework.context.expression.StandardBeanExpressionResolver.evaluate(StandardBeanExpressionResolver.java:142)
	at org.springframework.beans.factory.support.AbstractBeanFactory.evaluateBeanDefinitionString(AbstractBeanFactory.java:1299)
	at org.springframework.beans.factory.support.BeanDefinitionValueResolver.evaluate(BeanDefinitionValueResolver.java:210)
	at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:182)
	at org.springframework.beans.factory.support.ConstructorResolver.resolveConstructorArguments(ConstructorResolver.java:630)
	at org.springframework.beans.factory.support.ConstructorResolver.autowireConstructor(ConstructorResolver.java:148)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.autowireConstructor(AbstractAutowireCapableBeanFactory.java:1035)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:939)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:485)
	at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:456)
	at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:294)
	at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:225)
	at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:291)
	at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:193)
	at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:585)
	at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:913)
	at org.eclipse.gemini.blueprint.context.support.AbstractDelegatedExecutionApplicationContext.access$1600(AbstractDelegatedExecutionApplicationContext.java:60)
	at org.eclipse.gemini.blueprint.context.support.AbstractDelegatedExecutionApplicationContext$4.run(AbstractDelegatedExecutionApplicationContext.java:325)
	at org.eclipse.gemini.blueprint.util.internal.PrivilegedUtils.executeWithCustomTCCL(PrivilegedUtils.java:85)
	at org.eclipse.gemini.blueprint.context.support.AbstractDelegatedExecutionApplicationContext.completeRefresh(AbstractDelegatedExecutionApplicationContext.java:290)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor$CompleteRefreshTask.run(DependencyWaiterApplicationContextExecutor.java:137)
	at org.eclipse.virgo.kernel.agent.dm.ContextPropagatingTaskExecutor$2.run(ContextPropagatingTaskExecutor.java:95)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.eclipse.gemini.blueprint.service.ServiceUnavailableException: service matching filter=[(objectClass=org.eclipse.virgo.nano.core.KernelConfig)] unavailable
	at org.eclipse.gemini.blueprint.service.importer.support.internal.aop.ServiceDynamicInterceptor.getTarget(ServiceDynamicInterceptor.java:404)
	at org.eclipse.gemini.blueprint.service.importer.support.internal.aop.ServiceInvoker.invoke(ServiceInvoker.java:60)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
	at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.eclipse.gemini.blueprint.service.util.internal.aop.ServiceTCCLInterceptor.invokeUnprivileged(ServiceTCCLInterceptor.java:70)
	at org.eclipse.gemini.blueprint.service.util.internal.aop.ServiceTCCLInterceptor.invoke(ServiceTCCLInterceptor.java:53)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.eclipse.gemini.blueprint.service.importer.support.LocalBundleContextAdvice.invoke(LocalBundleContextAdvice.java:57)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:131)
	at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:119)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
	at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
	at com.sun.proxy.$Proxy11.getProperty(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.springframework.expression.spel.support.ReflectiveMethodExecutor.execute(ReflectiveMethodExecutor.java:69)
	at org.springframework.expression.spel.ast.MethodReference.getValueInternal(MethodReference.java:109)
	at org.springframework.expression.spel.ast.CompoundExpression.getValueInternal(CompoundExpression.java:57)
	at org.springframework.expression.spel.ast.SpelNodeImpl.getValue(SpelNodeImpl.java:93)
	at org.springframework.expression.spel.standard.SpelExpression.getValue(SpelExpression.java:88)
	at org.springframework.context.expression.StandardBeanExpressionResolver.evaluate(StandardBeanExpressionResolver.java:139)
	... 24 common frames omitted

[2016-02-01T20:08:06.930Z] [ERROR] startup-tracker               <KE0003E> Kernel failed to start. org.springframework.context.ApplicationContextException: Application context initialization for 'org.eclipse.virgo.kernel.deployer' has timed out waiting for (|(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))(objectClass=org.eclipse.virgo.repository.Repository)(objectClass=org.eclipse.virgo.kernel.services.work.WorkArea)(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)(objectClass=org.eclipse.virgo.repository.ArtifactBridge))
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.timeout(DependencyWaiterApplicationContextExecutor.java:489)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.access$000(DependencyWaiterApplicationContextExecutor.java:54)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor$WatchDogTask.run(DependencyWaiterApplicationContextExecutor.java:109)
	at java.util.TimerThread.mainLoop(Timer.java:555)
	at java.util.TimerThread.run(Timer.java:505)

[2016-02-01T20:08:06.931Z] [ERROR] ng DM Context Creation Timer  <AG0000E> Application context creation failure for bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE'. org.springframework.context.ApplicationContextException: Application context initialization for 'org.eclipse.virgo.kernel.deployer' has timed out waiting for (|(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))(objectClass=org.eclipse.virgo.repository.Repository)(objectClass=org.eclipse.virgo.kernel.services.work.WorkArea)(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)(objectClass=org.eclipse.virgo.repository.ArtifactBridge))
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.timeout(DependencyWaiterApplicationContextExecutor.java:489)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor.access$000(DependencyWaiterApplicationContextExecutor.java:54)
	at org.eclipse.gemini.blueprint.extender.internal.dependencies.startup.DependencyWaiterApplicationContextExecutor$WatchDogTask.run(DependencyWaiterApplicationContextExecutor.java:109)
	at java.util.TimerThread.mainLoop(Timer.java:555)
	at java.util.TimerThread.run(Timer.java:505)

[2016-02-01T20:08:06.951Z] [INFO ] startup-tracker               <ME0003I> Dump '/usr/lib/vmware-vsphere-client/server/serviceability/dump/2016-02-01-20-08-943' generated 
[2016-02-01T20:08:06.953Z] [INFO ] startup-tracker               <KE0011I> Immediate shutdown initiated. 



We started looking into what services implemented the Repository interface (org.eclipse.virgo.kernel.services.repository.internal.RepositoryFactoryBean). We tested if the issue could be caused if the server ran on a slow (throttled) storage when the bundles in the repository chain are not yet indexed in work/*.index. Under 3.5 Mbps storage I/O bandwidth we could reproduce the timeout waiting for Repository implementation. We did a patch to org.eclipse.gemini.blueprint.extender_1.0.2 .jar (org.eclipse.gemini.blueprint.extender.support.internal.ConfigUtils) and org.eclipse.gemini.blueprint.core_1.0.2 (org.eclipse.gemini.blueprint.blueprint.config.internal.BlueprintDefaultsDefinition) that allowed the 5 minute timeout to be customized through java system property and set it to 15 minutes. This replaced the error we hit with...

2) Kernel timeout after 10 minutes.

... essentially the problem Bisser posted initially.

From the stack trace and the heap dump we see that the RepositoryFactoryBean is not created at all. The interesting parts I saw initially is that:

In the failed kernel deployment, only a small number of bundles registered services, namely:
org.apache.felix.gogo.command_0.10.0.v201209301215
org.apache.felix.gogo.runtime_0.10.0.v201209301036
org.apache.felix.gogo.shell_0.10.0.v201211091412
org.eclipse.equinox.cm_1.0.400.v20120319-2029
org.eclipse.equinox.common_3.6.100.v20120509-1351
org.eclipse.equinox.console_1.0.100.v20121001-124408
org.eclipse.equinox.console.ssh_1.0.0.v20120430-1356
org.eclipse.equinox.util_1.0.300.v20111010-1614
org.eclipse.equinox.event_1.2.100.v20111010-1614
org.eclipse.equinox.region_1.1.0.v20120319-1602
org.eclipse.gemini.blueprint.extender_1.0.2.RELEASE
org.eclipse.virgo.kernel.agent.dm_3.6.4.RELEASE
org.eclipse.virgo.medic.core_3.6.4.RELEASE
org.eclipse.virgo.nano.core_3.6.4.RELEASE
org.eclipse.virgo.nano.management_3.6.4.RELEASE
org.eclipse.virgo.repository_3.6.4.RELEASE

Looking into the dependencies of RepositoryFactoryBean I saw that a SPEL invocation of kernelConfig.getProperty() was made - see /org.eclipse.virgo.kernel.services/src/main/resources/META-INF/spring/repository-context.xml line 16, 3.6.4 .RELEASE codebase.

I did a search into the virgo codebase and the thing that caught my attention was that all SPEL references to kernelConfig.getProperty() were done from bundles that were not deployed. Furthermore, when enabling the DEBUG output for org.eclipse, I saw that There were no calls kernelConfig.getProperty() in the failed deployment. The thread dump showed that kernel-dm-4 was waiting on the org.eclipse.gemini.blueprint.service.importer.support.internal.support.RetryTemplate.execute()'s notificationLock monitor (line 104):

"kernel-dm-4" Id=41 RUNNABLE (suspended)
	at org.eclipse.virgo.nano.config.internal.StandardKernelConfig.getProperty(StandardKernelConfig.java:47)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)
	at org.eclipse.gemini.blueprint.service.importer.support.internal.aop.ServiceInvoker.doInvoke(ServiceInvoker.java:56)
...


Inspecting the code of RetryTemplate, I see an opportunity to have ServiceDynamicInterceptor to call lock.notifyAll() while the execution of the thread executing RetryTemplate.execute() is after line 80 and before line 103:

/* 80 */		T result = callback.doWithRetry();

			if (callback.isComplete(result)) {
				if (startWaiting) {
					callbackSucceeded(stop);
				}
				return result;
			}

			if (!startWaiting) {
				startWaiting = true;
				onMissingTarget();
				// initial wait
				initialStart = System.currentTimeMillis();
			}

			if (waitLeft > 0) {
				try {
					start = System.currentTimeMillis();
					synchronized (notificationLock) {
						// Do NOT use Thread.sleep() here - it does not release
						// locks.
/* 104 */					notificationLock.wait(waitTime);


So if there are no further notifications on notificationLock by ServiceDynamicinterceptor, the wait() on line 104 will timeout after 15 minutes (our customized value) ... that is if the kernel timeout didn't kill us before that.

I can revert the customized timeout but then I'd have the kernel deploy (probably, if I am right) in 5 minutes (instead of the average of 15 seconds). It will also not fix the initial issue listed in step 1)
Re: Virgo kernel fails to start [message #1737752 is a reply to message #1737274] Tue, 12 July 2016 13:23 Go to previous messageGo to next message
Tony Ganchev is currently offline Tony GanchevFriend
Messages: 7
Registered: July 2016
Junior Member
Attached are the collected dump and logs for the current issue.

Forgot to mention that I've ensured from the heap dump that the StandardKernelConfig is available.
Re: Virgo kernel fails to start [message #1737943 is a reply to message #1737752] Thu, 14 July 2016 09:52 Go to previous messageGo to next message
daniel marthaler is currently offline daniel marthalerFriend
Messages: 77
Registered: April 2012
Location: Zürich
Member
Hi Tony

Thank you for the detailed explanations. In order to be able to reproduce this behavior in a similar environment, I would like to know if you experience this timeout issues only on virtual machines (VMWare) or on bare metal hosts as well? Additionally, I would like to know how many CPUs, Memory, Disk space you assign to those hosts running Virgo Kernel.

Regards,
Dani
Re: Virgo kernel fails to start [message #1738506 is a reply to message #1737943] Wed, 20 July 2016 12:47 Go to previous messageGo to next message
Tony Ganchev is currently offline Tony GanchevFriend
Messages: 7
Registered: July 2016
Junior Member
We are experiencing the issue on VMs only. We've not reproduced the issue in physical environment. Unfortunately we're building an appliance around Virgo and few other services.

The VMs on which the latest failure took place are:
Mem: 8GB
vCPUs: 2
Root partition (hosting virgo, work/, repositories and pivckup/ dir): 5 GB free
Logs partition (server/servicability is redirected there): 9 GB free

I'll try to provide info about the physical hardware and storage we run on. but we've not seen any resource spikes exhausting the physical hardware - CPU, memory and disk latency are steady.

Two additional things to note:
- the work/ does no hold any signifant errors coming from equinox (apart from some SCR errors on shutdown).
- the ext and usr.index files in work/ have sizes of 1MB and 2.5MB respectively. The modification difference between the two in normal virgo restart (one that doesn't fail with kernel timeout) is 5 seconds.

Re: Virgo kernel fails to start [message #1738519 is a reply to message #1738506] Wed, 20 July 2016 13:45 Go to previous messageGo to next message
Tony Ganchev is currently offline Tony GanchevFriend
Messages: 7
Registered: July 2016
Junior Member
Dani, we have run tests with appliance reboots and increased logging and it has proven impossible to reproduce the issue. The problem occurs only after multiple/various test runs on virtual environments. It looks like a prime example of a Heisenbug and I am not sure if trying to reproduce it won't prove a waste of time.

We can add more instrumentation and increased logging to the Virgo kernel we patch if you have any leads on the potential source of the error. I already applied the change to RetryTemplate line 104 that sets a timeout of 10s rather than the total timeout of 5min (15 minutes after my previous patch). A recent failure seems to indicate that this has not fixed the issue but I'm yet to confirm this.
Re: Virgo kernel fails to start [message #1740792 is a reply to message #1734253] Thu, 18 August 2016 14:42 Go to previous messageGo to next message
Tony Ganchev is currently offline Tony GanchevFriend
Messages: 7
Registered: July 2016
Junior Member
We finally got more results from failing test runs.

The attached osgi.log file captures calls to RetryTemplate (in addition to most of org.eclipse and org.springframework bundles but ironically not OSGi Smile ) As discussed before, I reduced thee timeout of the wait in RetryTemplate.execute(), line 104 from 5 / 15 minutes to mere 10 seconds.

What I notice from the logs is that a service implementing KernelConfig is not available in the ServiceDynamicInterceptor/RetryTemplate (the ReferenceHolder.getService() delegates to BundleContext.getService() which in turn returns null).

I didn't get a heap dump in this case - i'll need to wait for another run.

Here's an excerpt from the log showing the moment when the waiting for kernelConfig starts:

...
[2016-08-17T20:40:16.816-07:00] [DEBUG] kernel-dm-1                   o.e.g.b.e.i.d.startup.DependencyWaiterApplicationContextExecutor  Asynch wait-for-dependencies started... 
[2016-08-17T20:40:16.816-07:00] [DEBUG] kernel-dm-1                   o.eclipse.virgo.kernel.agent.dm.ContextPropagatingTaskExecutor$2  < public void org.eclipse.virgo.kernel.agent.dm.ContextPropagatingTaskExecutor.2.run() 
[2016-08-17T20:40:16.835-07:00] [DEBUG] kernel-dm-4                   o.s.beans.factory.support.DefaultListableBeanFactory              Returning cached instance of singleton bean 'kernelConfig' 
[2016-08-17T20:40:17.126-07:00] [DEBUG] kernel-dm-4                   o.e.g.b.service.importer.support.internal.aop.ReferenceHolder     Returning instance of {org.eclipse.virgo.nano.core.KernelConfig}={service.pid=org.eclipse.virgo.kernel, deployer.unpackBundles=true, component.name=org.eclipse.virgo.kernel, work.directory=C:\ProgramData\VMware\vCenterServer\runtime\vsphere-client\server\work, domain=org.eclipse.virgo.kernel, deployer.timeout=0, component.id=6, home.directory=C:\ProgramData\VMware\vCenterServer\runtime\vsphere-client\server, deployer.scanIntervalMillis=1000, deployer.pickupDirectory=C:/PROGRA~3/VMware/VCENTE~1//runtime/VSPHER~1/server/pickup, org.eclipse.virgo.kernel.startup.wait.limit=600, service.id=111} null 
[2016-08-17T20:40:17.127-07:00] [DEBUG] kernel-dm-4                   o.e.g.b.service.importer.support.OsgiServiceProxyFactoryBean      Service dependency satisfaction missed target. Start waiting ... 
[2016-08-17T20:40:17.127-07:00] [DEBUG] kernel-dm-4                   o.e.g.b.service.importer.support.internal.support.RetryTemplate   Waiting for service dependency to be satisfied. 
...
  • Attachment: osgi.log
    (Size: 836.06KB, Downloaded 178 times)
Re: Virgo kernel fails to start [message #1741899 is a reply to message #1740792] Tue, 30 August 2016 14:00 Go to previous messageGo to next message
daniel marthaler is currently offline daniel marthalerFriend
Messages: 77
Registered: April 2012
Location: Zürich
Member
Hi Tony,

Can you please create a bug for this issue?

Regards,
Dani
Re: Virgo kernel fails to start [message #1742516 is a reply to message #1741899] Fri, 02 September 2016 15:04 Go to previous messageGo to next message
Tony Ganchev is currently offline Tony GanchevFriend
Messages: 7
Registered: July 2016
Junior Member
Done: https://bugs.eclipse.org/bugs/show_bug.cgi?id=500758

I also provided full dump for the latest recurrence of the issue.
Re: Virgo kernel fails to start [message #1742605 is a reply to message #1742516] Tue, 06 September 2016 07:05 Go to previous messageGo to next message
GianMaria Romanato is currently offline GianMaria RomanatoFriend
Messages: 57
Registered: November 2015
Member
Hi Tony,

Daniel is not in the office this week, so he won't be able to look into that bugzilla entry before next week.
Meanwhile thank you for the detailed report.

GianMaria.
Re: Virgo kernel fails to start [message #1743146 is a reply to message #1742516] Mon, 12 September 2016 15:53 Go to previous messageGo to next message
daniel marthaler is currently offline daniel marthalerFriend
Messages: 77
Registered: April 2012
Location: Zürich
Member
Tony Ganchev wrote on Fri, 02 September 2016 17:04
Done: https://bugs.eclipse.org/bugs/show_bug.cgi?id=500758

I also provided full dump for the latest recurrence of the issue.


Thank you Tony for creating the Bug, I will post my investigation results directly on 500758.

Regards,
Dani
Re: Virgo kernel fails to start [message #1743422 is a reply to message #1743146] Thu, 15 September 2016 10:21 Go to previous message
Tony Ganchev is currently offline Tony GanchevFriend
Messages: 7
Registered: July 2016
Junior Member
Thanks, Dani!

We continue hitting the issue, but most cases are on release builds for which I have turned off the additional logging and dumps.

Tony
Previous Topic:Cannot find plan 'org.eclipse.virgo.kernel.userregion.blueprint' on startup
Next Topic:virgo Package uses conflict
Goto Forum:
  


Current Time: Fri Apr 19 17:10:01 GMT 2024

Powered by FUDForum. Page generated in 0.02559 seconds
.:: Contact :: Home ::.

Powered by: FUDforum 3.0.2.
Copyright ©2001-2010 FUDforum Bulletin Board Software

Back to the top