vmware-vcd service fails to start after cell upgrade from 9.1.0.1 to 9.5

[Griamce0385]

Upgraded from 9.1.0.1 to 9.5 on three out of four cell servers. The fourth cell post upgrade errors on service vmware-vcd start with the following errors.

Cell.log

- Bootstrap application: start Fatal exception caught during application bootstrap. Halting application. Message: '/opt/vmware/vcloud-director/etc/global.properties'

Cell-runtime.log

-  2019-01-10 17:05:25,937 | WARN     | Bootstrap Application     | CommonsConfigurationFactory    | Server configuration file not found: /opt/vmware/vcloud-director/etc/global.properties |

org.apache.commons.configuration.ConfigurationException: Unable to load the configuration from the URL file:/opt/vmware/vcloud-director/etc/global.properties

However i can "cat  /opt/vmware/vcloud-director/etc/global.properties" and comparing it to other cells seems correct. See output below.

# Database connection settings

database.jdbcUrl = jdbc:jtds:sqlserver://redacted:1433/vcloud;socketTimeout=90

database.username = redacted

database.password = redacted

# Product display name

product.display_name = VMware vCloud Director

# Maximum number blocking tasks (per cell) to be resumed when expired.

# This property is taken into account only when blocking task's default timeout action is "Resume".

# Uncomment this line and set the desired value. Otherwise, the default value (1000) will be used.

# blockingTasks.timeoutResumeRate = 1000

product.version = 9.5.0.11038232

product.build_date = 2018-11-27T21:25:46-0800

vcloud.cell.ip.primary = redacted

consoleproxy.host.https = redacted

vcloud.ssl.password = redacted

vcloud.ssl.key.password = redacted

vcloud.ssl.truststore.password = redacted

consoleproxy.keystore.password = redacted

consoleproxy.keystore.path = /opt/vmware/vcloud-director/etc/proxycertificates

audit.syslog.host =

audit.syslog.port = 514

system.info = aDYYIDRwlRaU1fLfnqgvgTMzp9YgEesQDALS53T73EM=

system.version = 1

vcloud.cell.uuid = redacted

vcloud.cell.ips = redacted

user.keystore.path = /opt/vmware/vcloud-director/bin/../jre/bin/certificates.ks

user.keystore.password redacted

[paluszekd · Accepted solution]

Could be permissions on the file - did you do a comparison of the chmod permissions between one of the working cells and the inoperable cell? Your vcloud user should have rw permissions along with vcloud:vcloud as the user/group

[Griamce0385]

Thank you for the quick response. The permissions were sit to root:root. I resolved this and the startup of the service did not immediately stop, instead it progressed until it just sits at the following in the cloud.log

Application startup begins: Subsystem 'com.vmware.vcloud.common.core' at 1/11/19 12:54 PM

Application Initialization: 'com.vmware.vcloud.common.core' 4% complete. Subsystem 'com.vmware.vcloud.vcell-runtime-impl' started

Application Initialization: 'com.vmware.vcloud.cloud-proxy-server' 14% complete. Subsystem 'com.vmware.vcloud.vcell-runtime-impl' started

Application startup event: Subsystem 'com.vmware.vcloud.consoleproxy' startup initiated.

Successfully connected to database: jdbc:jtds:sqlserver://redacted:1433/vcloud;socketTimeout=90

Successfully initialized system cryptography

Successfully configured Console Proxy SSL Connector from certificate store: /opt/vmware/vcloud-director/etc/proxycertificates

Application Initialization: 'com.vmware.vcloud.common.core' 8% complete. Subsystem 'com.vmware.vcloud.common-cell-impl' started

Application Initialization: 'com.vmware.vcloud.cloud-proxy-server' 28% complete. Subsystem 'com.vmware.vcloud.common-cell-impl' started

Application Initialization: 'com.vmware.vcloud.networking-server' 20% complete. Subsystem 'com.vmware.vcloud.common-cell-impl' started

Application Initialization: 'com.vmware.vcloud.common.core' 12% complete. Subsystem 'com.vmware.vcloud.common-util' started

Application Initialization: 'com.vmware.vcloud.cloud-proxy-server' 42% complete. Subsystem 'com.vmware.vcloud.common-util' started

Application Initialization: 'com.vmware.vcloud.networking-server' 40% complete. Subsystem 'com.vmware.vcloud.common-util' started

Application shutdown event: Beginning

^C

[paluszekd]

Was that the last message in the cell log?

[Griamce0385]

Yes it was it kind of just stopped mid statement.

It also appears that the cell is appearing healthy and operational inside VCD > Manage & Monitor > Cloud Resources > Cloud Cells. But the /cloud website for that site doesn't work and the vmware-vcd service is definitely not happy.

Might it be best to just rebuild this cell server and use the response file to join it back with the healthy cell?

Some possible interesting entries from other logs.

> /opt/vmware/vcloud-director/logs/vmware-vcd-watchdog.log.last <==

19-01-11 13:55:12 | INFO  | Started vmware-vcd-cell (pid=15241)

2019-01-11 13:55:12 | WARN  | wget failed, return code: 4, will retry in 30 seconds

....

2019-01-11 13:57:42 | ALERT | vmware-vcd-cell is dead but /var/run/vmware-vcd-cell.pid exist s, attempting to restart it

> /opt/vmware/vcloud-director/logs/cell-runtime.log <==

19-01-11 14:33:25,640 | FATAL    | Console Proxy Application | AbstractCellApplication        | Shutting down cell due to exception thrown while starting 'com.vmware.consoleproxy.async.server.ConsoleProxyCellApplication' |

201

> /opt/vmware/vcloud-director/logs/cell-runtime.log <==

19-01-11 14:33:25,639 | ERROR    | Console Proxy Application | AbstractCellApplication        | Application startup event: Unable to start service: 'com.vmware.vcloud.consoleproxy' |

java.lang.IllegalStateException: Unable to bind to 10.42.41.68:443. Permission denied. Is this address available on this machine?

###############I have no idea what that IP is to as its not configured on any of the Cells, doesnt ping and is not in DNS##################

> /opt/vmware/vcloud-director/logs/cell-runtime.log <==

2019-01-11 14:33:26,700 | WARN     | Spring Context: com.vmware.vcloud.cloud-proxy-services | DirectlyConfigurableXmlApplicationContext | Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'persistenceConfigurationData' defined in URL [jar:file:/opt/vmware/vcloud-director/system/com/vmware/vcloud/cloud-proxy-services/1.0.0/cloud-proxy-services-1.0.0.jar!/META-INF/spring/cloud-proxy-services-persistence.xml]: Cannot resolve reference to bean 'configurationService' while setting bean property 'configurationService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'configurationService': Invocation of init method failed; nested exception is java.lang.NullPointerException |

2019-01-11 14:33:26,700 | FATAL    | Spring Context: com.vmware.vcloud.cloud-proxy-services | OsgiBundleSpringContextFactory | Error in module: "com.vmware.vcloud.cloud-proxy-services"; Bean: persistenceConfigurationData, Message: Error creating bean with name 'persistenceConfigurationData' defined in URL [jar:file:/opt/vmware/vcloud-director/system/com/vmware/vcloud/cloud-proxy-services/1.0.0/cloud-proxy-services-1.0.0.jar!/META-INF/spring/cloud-proxy-services-persistence.xml]: Cannot resolve reference to bean 'configurationService' while setting bean property 'configurationService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'configurationService': Invocation of init method failed; nested exception is java.lang.NullPointerException |

org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'persistenceConfigurationData' defined in URL [jar:file:/opt/vmware/vcloud-director/system/com/vmware/vcloud/cloud-proxy-services/1.0.0/cloud-proxy-services-1.0.0.jar!/META-INF/spring/cloud-proxy-services-persistence.xml]: Cannot resolve reference to bean 'configurationService' while setting bean property 'configurationService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'configurationService': Invocation of init method failed; nested exception is java.lang.NullPointerException

[paluszekd]

java.lang.IllegalStateException: Unable to bind to 10.42.41.68:443. Permission denied. Is this address available on this machine?

This error tells me you have something awry with the cell and console IP address. Do you know how it was configured? Check your ifconfig and find out how you guys are configuring console/proxy access - your healthy cells might be good guiding lights.