Virgo kernel fails to start [message #1734253] |
Mon, 06 June 2016 14:47 |
Bisser P 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 #1737750 is a reply to message #1737274] |
Tue, 12 July 2016 13:12 |
Tony Ganchev 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 #1740792 is a reply to message #1734253] |
Thu, 18 August 2016 14:42 |
Tony Ganchev 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 ) 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 197 times)
|
|
|
|
|
|
|
|
Powered by
FUDForum. Page generated in 0.05085 seconds