How to fix VCD 10.2.2 not starting anymore after reboot

Introduction

It’s been a while since I’ve posted a blog. We’ve been extremely busy on our day to day jobs, but that does not mean that we are losing focus or that we don’t have anything to write about! Today I got another great quick blog for you guys surrounding yet another VMware Cloud Director 10.2.2 bug. Now let’s jump into this thing!

The Issue

We have been having intermittent issues on one of our VCD environments. This has ultimately led us to believe that there might be something wrong with the resources that were configured on the VCD Cells. It seemed that after the 10.2.2. upgrade we did earlier this year the recommended number of resources changes and we forgot to assign these. So now that we found this out we decided to shutdown the VCD environment and edit the resources to their recommended sizes.

Once we did that and restarted the environment, it seemed that VCD didn’t want to come back online. The postgres database and it’s cluster functions were thankfully all working like they should without any issues. Looking at the vmware-vcd service status we noticed that the Cell services weren’t starting and were hanging on this step of the process:

Bootstrap application: start
All required system properties are present
Actual Java version (1.8.0_281) matches expected version (1.8.0_281)
All required local configuration properties are present
Successfully bound network port: 80 on host address: XXXX
Successfully bound network port: 443 on host address: XXXX
Successfully bound network port: 8999 on host address: XXXX
All required local configuration properties are present
Successfully initialized system cryptography
Successfully configured HTTP SSL Connector from certificate store
Current locale "en" verified successfully.
Bootstrap application: complete in 4,620ms
Application startup event: Waiting for subsystem 'Cloud Proxy Cell Application'
Application startup event: Waiting for subsystem 'Networking Cell Application'
Application startup event: Waiting for subsystem 'Legacy Cell Application'
Application startup event: Waiting for subsystem 'Console Proxy Cell Application'
Application startup event: Waiting for subsystem 'Autoscale Cell Application'
Application startup event: Waiting for subsystem 'CarePackage Cell Application'
Application startup event: Subsystem 'Networking Cell Application' startup initiated.
Application startup event: Subsystem 'Cloud Proxy Cell Application' startup initiated.

After some digging in the logs that are located in /opt/vmware/vcloud-director/logs/cell-runtime.log we noticed the following:

2021-11-17 09:19:29,656 | WARN     | Module: HTML5 Cell Application | DirectlyConfigurableXmlApplicationContext | Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'vcdSecuredWebappConfiguration': Unsatisfied dependency expressed through field 'validationFilter'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'validationFilter' defined in class path resource [META-INF/spring/h5-cellapp-security-context.xml]: Cannot resolve reference to bean 'filterConfigurationService' while setting bean property 'filterConfigurationService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'filterConfigurationService': FactoryBean threw
exception on object creation; nested exception is java.util.concurrent.TimeoutException: Timed out waiting for service: 'filterConfigurationService', objectClasses='[interface com.vmware.vcloud.security.filters.FilterConfigurationService]', filter='(objectClass=com.vmware.vcloud.security.filters.FilterConfigurationService)' |
2021-11-17 09:19:29,661 | FATAL    | Module: HTML5 Cell Application | ModuleRegistry                 | Error in module: "HTML5 Cell Application"; Bean: vcdSecuredWebappConfiguration, Message: Error creating bean with name 'vcdSecuredWebappConfiguration': Unsatisfied dependency expressed through field 'validationFilter'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'validationFilter' defined in class path resource [META-INF/spring/h5-cellapp-security-context.xml]: Cannot resolve reference to bean 'filterConfigurationService' while setting bean property 'filterConfigurationService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'filterConfigurationService': FactoryBean threw exception on object creation; nested exception is java.util.concurrent.TimeoutException: Timed out waiting for service: 'filterConfigurationService', objectClasses='[interface com.vmware.vcloud.security.filters.FilterConfigurationService]', filter='(objectClass=com.vmware.vcloud.security.filters.FilterConfigurationService)' |
org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'vcdSecuredWebappConfiguration': Unsatisfied dependency expressed through field 'validationFilter'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'validationFilter' defined in class path resource [META-INF/spring/h5-cellapp-security-context.xml]: Cannot resolve reference to bean 'filterConfigurationService' while setting bean property 'filterConfigurationService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'filterConfigurationService': FactoryBean threw exception on object creation; nested exception is java.util.concurrent.TimeoutException: Timed out waiting for service: 'filterConfigurationService', objectClasses='[interface com.vmware.vcloud.security.filters.FilterConfigurationService]', filter='(objectClass=com.vmware.vcloud.security.filters.FilterConfigurationService)'
        at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:586)
        at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:87)
        at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessPropertyValues(AutowiredAnnotationBeanPostProcessor.java:364)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1268)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:551)
        at com.vmware.vcloud.common.main.bootstrap.DirectlyConfigurableXmlApplicationContext$LoggingBeanFactory.doCreateBean(DirectlyConfigurableXmlApplicationContext.java:54)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:481)
        at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:756)
        at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:867)
        at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:542)
        at com.vmware.vcloud.common.main.bootstrap.DirectlyConfigurableXmlApplicationContext.refresh(DirectlyConfigurableXmlApplicationContext.java:151)
        at com.vmware.vcloud.common.main.ModuleRegistry$3.call(ModuleRegistry.java:90)
        at com.vmware.vcloud.common.main.ModuleRegistry$3.call(ModuleRegistry.java:70)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'validationFilter' defined in class path resource [META-INF/spring/h5-cellapp-security-context.xml]: Cannot resolve reference to bean 'filterConfigurationService' while setting bean property 'filterConfigurationService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'filterConfigurationService': FactoryBean threw exception on object creation; nested exception is java.util.concurrent.TimeoutException: Timed out waiting for service: 'filterConfigurationService', objectClasses='[interface com.vmware.vcloud.security.filters.FilterConfigurationService]', filter='(objectClass=com.vmware.vcloud.security.filters.FilterConfigurationService)'
        at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:359)
        at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:108)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1533)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1280)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:551)
        at com.vmware.vcloud.common.main.bootstrap.DirectlyConfigurableXmlApplicationContext$LoggingBeanFactory.doCreateBean(DirectlyConfigurableXmlApplicationContext.java:54)
        at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:481)
        at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:312)
        at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:308)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
        at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:211)
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1131)
        at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1059)
        at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:583)
        ... 20 more
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'filterConfigurationService': FactoryBean threw exception on object creation; nested exception is java.util.concurrent.TimeoutException: Timed out waiting for service: 'filterConfigurationService', objectClasses='[interface com.vmware.vcloud.security.filters.FilterConfigurationService]', filter='(objectClass=com.vmware.vcloud.security.filters.FilterConfigurationService)'
        at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.doGetObjectFromFactoryBean(FactoryBeanRegistrySupport.java:185)
        at org.springframework.beans.factory.support.FactoryBeanRegistrySupport.getObjectFromFactoryBean(FactoryBeanRegistrySupport.java:137)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getObjectForBeanInstance(AbstractBeanFactory.java:1646)
        at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:254)
        at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
        at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:351)
        ... 34 more

This however did not point us to anything useful at all. None of the others logs had anything else that we could use to troubleshoot and in the mean time the entire VCD platform (all three cells) were down. This was during a very busy morning so we figured we create a case with VMware.

The resolution

Not long after creating this case we got ourselfes a hold of a very good engineer that had a quick look through the files we already looked at and he remembered that he had seen this issue before, but only on VCD 10.2.2.1.x and not on 10.2.2. The issue itself turned out to be that in spontaneous situations in VCD 10.2.2.x the “jms.user.system.password” was missing in the database. There wasn’t really a reason for this to happen that I have been told, but this isn’t something that was present in a publicly available KB article. So I figured I write this down for everybody. You can check if you are having this issue by doing the following:

root@vcd-cell01 [ ~ ]# sudo -u postgres psql vcloud
psql.bin (10.12 (VMware Postgres 10.12.0-15722029 release))
Type "help" for help.sudo -u postgres psql vcloud

vcloud=# select * from config where name like '%jms%';
config_id |  cat   |      name       | value | sortorder
-----------+--------+-----------------+-------+-----------
      1749 | vcloud | jms.ssl.enabled | true  |         0
(1 row)

This usually should return two entries. The output below is from a working environment (Obviously the password is blanked in this example):

root@vcd-cell02 [ ~ ]# sudo -u postgres psql vcloud
psql.bin (10.12 (VMware Postgres 10.12.0-15722029 release))
Type "help" for help.

vcloud=# select * from config where name like '%jms%';
config_id |  cat   |           name           |                              value                               | sortorder
-----------+--------+--------------------------+------------------------------------------------------------------+-----------
      1749 | vcloud | jms.ssl.enabled          | true                                                             |         0
      1808 | vcloud | jms.user.system.password | XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX |         0
(2 rows)

Now that we have established that I am having this issue, we can now fix the issue. Be aware that if you do not like to mess around in the postgresql database, you should create a case with VMware support so that they can do this for you! The following steps need to be followed to fix the issue:

1. Go and download a previous backup of the environment. Most of the time this can be found in /opt/vmware/vcloud-director/data/transfer/backups (in 10.3.x) and in /opt/vmware/vcloud-director/data/transfer/vmware-vcd-support (Pre 10.3.x).
2. Open up the vmware-vcd-support-xxxx-xx-xx.xxxx.tgz file with 7-Zip.
3. Open up the export_db_xxx-xx-xx-xx-xx-xx.tar file with and the file within with 7-Zip.
4. Find a file named config.dat and open this file.
5. Look for the config key named jms.user.system.password. You should find it in this file. If you don’t, use an older backup and try again.
   1. Now extract the complete line into Notepad++ or anything similar.

1804 vcloud jms.user.system.password XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX 0

6. Use the first 4 digits as the config_id and the 4th entry as the password. Note these down and formulate the following sql query (Note, these can be different in each environment):

vcloud=# insert into config (config_id,cat,name,value,sortorder) values ('1804','vcloud','jms.user.system.password','XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX','0');
INSERT 0 1

7. If you enter this query in the database you will essentially re-enter the jms.user.system.password property back into the database.
8. Now that we have done this we can check this by re-entering the following command, which will now get two results:

vcloud=# select * from config where name like '%jms%';
config_id |  cat   |           name           |                              value                               | sortorder
-----------+--------+--------------------------+------------------------------------------------------------------+-----------
      1749 | vcloud | jms.ssl.enabled          | true                                                             |         0
      1804 | vcloud | jms.user.system.password | XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX |         0
(2 rows)

At this point we can go ahead and restart the vmware-vcd service with the following command: service vmware-vcd stop followed by a service vmware-vcd start. This should now start the vmware-vcd service without any issues. This is also persistent with all following reboots.

There you have it! Unfortunately this is another bug in the VCD 10.2.x branch, however this bug is fixed within the 10.3.x branch of VCD. If you happen to come across this issue, you can now just follow this guide and you will be up and running within minutes. If you do not have any recent backups on the VCD Cells, you could also use a recent postgresql backup. If you also don’t have this, you should contact VMware through a support case so that the password for the user can be regenerated.