vCenter Web Client service starts then stops after vCenter server reboot - Immediate shutdown initiated

[Bill_Oyler]

Since updating a Windows-based vCenter from 6.0U1 to 6.0U2, I've noticed that the vSphere Web Client service starts for about 5-7 minutes upon server reboot, then dies.  This happens every reboot.  The solution is simple: manually re-start the Web Client service, and everything is fine.  But it's annoying to need to perform a manual step every time the vCenter is rebooted.  I've tried setting the Web Client service to "Delayed Start", but the same problem occurs.  The VM has plenty of resources (2 vCPU, 24 GB RAM, Win2012 R2, fairly recent CPUs, ESXi host only about 40% utilized).  This particular vCenter has a rather large inventory (20-30 ESXi hosts, several hundred VMs).  The vCenter database is on SQL 2014.  Other vCenters in this infrastructure with smaller inventories do not seem to experience this problem.

The underlying error seems to be a Virgo error, "Kernel failed to start."  Apparently Virgo gives up after 5 minutes, if it can't load all of the Virgo base runtime dependencies.  It then says simply, "Immediate shutdown initiated."  It claims to be dumping something to the "dump" folder, but this folder contains lots of empty folders - one for each reboot, when Virgo crashes.  Below are some snippets from the Virgo (Web Client) event log file:

C:\ProgramData\VMware\vCenterServer\logs\vsphere-client\logs\eventlog.log

[2016-10-10T15:04:27.999-05:00] [INFO ] startup-tracker              <KE0001I> Kernel starting.

[2016-10-10T15:04:34.239-05:00] [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-10-10T15:04:35.838-05:00] [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-10-10T15:04:35.839-05:00] [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-10-10T15:04:35.840-05:00] [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-10-10T15:04:35.841-05:00] [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-10-10T15:04:35.842-05:00] [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-10-10T15:04:36.240-05:00] [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-10-10T15:04:36.241-05:00] [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-10-10T15:04:36.242-05:00] [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-10-10T15:04:36.243-05:00] [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-10-10T15:04:36.244-05:00] [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-10-10T15:04:38.125-05:00] [INFO ] kernel-dm-4                  <KE0101I> Reference '&importExpander' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' was satisfied by service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.ImportExpander)'.

[2016-10-10T15:04:38.133-05:00] [INFO ] kernel-dm-4                  <KE0101I> Reference '&osgiFramework' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' was satisfied by service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.OsgiFramework)'.

[2016-10-10T15:04:38.140-05:00] [INFO ] kernel-dm-4                  <KE0101I> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' was satisfied by service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'.

[2016-10-10T15:04:38.143-05:00] [INFO ] kernel-dm-4                  <KE0101I> Reference '&quasiFrameworkFactory' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' was satisfied by service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.quasi.QuasiFrameworkFactory)'.

[2016-10-10T15:04:38.149-05:00] [INFO ] kernel-dm-4                  <KE0101I> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' was satisfied by service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'.

[2016-10-10T15:04:38.152-05:00] [INFO ] kernel-dm-4                  <KE0101I> Reference '&packageAdminUtil' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' was satisfied by service with filter '(objectClass=org.eclipse.virgo.kernel.osgi.framework.PackageAdminUtil)'.

[2016-10-10T15:04:41.149-05:00] [INFO ] kernel-dm-4                  <KE0101I> Reference '&userRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' was satisfied by service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=org.eclipse.virgo.region.user))'.

[2016-10-10T15:04:41.152-05:00] [INFO ] kernel-dm-4                  <KE0101I> Reference '&userBundleContext' in bundle 'org.eclipse.virgo.kernel.deployer' version '3.6.3.RELEASE' was satisfied by service with filter '(&(objectClass=org.osgi.framework.BundleContext)(org.eclipse.virgo.kernel.regionContext=true))'.

[2016-10-10T15:04:41.900-05:00] [INFO ] kernel-dm-4                  <KE0101I> Reference '&repository' in bundle 'org.eclipse.virgo.kernel.osgi' version '3.6.3.RELEASE' was satisfied by service with filter '(objectClass=org.eclipse.virgo.repository.Repository)'.

[2016-10-10T15:04:42.558-05:00] [INFO ] kernel-dm-6                  <KE0101I> Reference '&globalRegion' in bundle 'org.eclipse.virgo.kernel.model' version '3.6.3.RELEASE' was satisfied by service with filter '(&(objectClass=org.eclipse.equinox.region.Region)(org.eclipse.virgo.kernel.region.name=global))'.

[2016-10-10T15:04:51.093-05:00] [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-10-10T15:05:37.066-05:00] [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-10-10T15:06:37.067-05:00] [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-10-10T15:07:37.207-05:00] [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-10-10T15:08:37.210-05:00] [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-10-10T15:09:30.282-05:00] [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.deployer.model.RuntimeArtifactModel)

  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-10-10T15:10:54.502-05:00] [ERROR] startup-tracker              <KE0003E> Kernel failed to start. org.springframework.context.ApplicationContextException: Application context initialization for 'org.eclipse.virgo.kernel.model' has timed out waiting for (objectClass=org.eclipse.virgo.kernel.deployer.model.RuntimeArtifactModel)

  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-10-10T15:10:54.510-05:00] [INFO ] startup-tracker              <ME0003I> Dump 'C:\PROGRA~1\VMware\VCENTE~1\WEBCLI~1\server\serviceability\dump\2016-10-10-15-10-504' generated

[2016-10-10T15:10:54.511-05:00] [INFO ] startup-tracker              <KE0011I> Immediate shutdown initiated.

Upon starting the service manually, it fires right up in just a few seconds, with absolutely no issue whatsoever:

[2016-10-10T15:17:45.390-05:00] [INFO ] startup-tracker              <KE0001I> Kernel starting.

[2016-10-10T15:17:50.441-05:00] [INFO ] startup-tracker              <KE0002I> Kernel started.

I am curious if this is simply a known bug with the Eclipse Virgo product.  It looks like a bug report as filed recently on the Eclipse project site, with the exact same sequence of events:

https://bugs.eclipse.org/bugs/show_bug.cgi?id=500758

Has anyone else run into this issue?  Any work-arounds?

[alex122]

Hi Bill,

I had the same problem running 6.0 U2 with the same log messages. VMware support told me it is not an error. This is why the manual service start follows no self-shutdown. Web Client is waiting for 'something' which is not loaded yet. I'd already set the service to 'Automatic (Delayed start)' so we delayed the service start even more.

Create a new key 'AutoStartDelay' (DWORD (32-bit) under HKLM\SYSTEM\CurrentControlSet\services\vspherewebclientsvc and set it to decimal 300. Default delay is 120 seconds. Oh and you should check the key 'DelayedAutostart' that it is set to 1.

With 300 seconds start up delay the problem didn't occur anymore. Hope it helps!

Alex