Howdy Folks,
I am currently deploying VCAV in my lab and I am stuck at point where I am unable to configure vSphere Replication Cloud Service Appliance
From VCAV root console I fired below command:
vcav hcs wait-for-extension --hcs-address=$HCS01_ADDRESS --vcd-address=$VCD_ADDRESS1 --vcd-user=$VCD_USER --vcd-password-file=~/.ssh/.vcd --sso-user=$SSO_USER --sso-password-file=~/.ssh/.sso --debug
Note: I have multi-cell vcd in my lab and IP address of the 2 vCD appliance are 192.168.109.30 and 192.168.109.31. I have not configured public address in vCD.
Log snippet below
-------------------------------------------------------
INFO - Load registry from /root/.vcav/registry
INFO - Run /opt/vmware/vcav-installer/vcav hcs wait-for-extension --hcs-address=mgmt-vrcs01.alex.local --vcd-address=192.168.109.30 --vcd-user=admin --vcd-password-file=~/.ssh/.vcd --sso-user=administrator@alex.lab --sso-password-file=~/.ssh/.sso --debug
DEBUG - Check for ovftool in /usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/java/jre-vmware/bin:/opt/vmware/vcav-installer:/opt/vmware/bin
INFO - Run `which ovftool`
DEBUG - Build a command for `hcs wait-for-extension`
DEBUG - Unable to load trusted CAs from Certifi
DEBUG - Unable to validate the certificate from 192.168.109.30:443
DEBUG - [('SSL routines', 'ssl3_get_server_certificate', 'certificate verify failed')]
Traceback (most recent call last):
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 336, in hasValidCertificate
cert = get_x509(address, port, SSL.SSLv23_METHOD, disable_validation=False)
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 250, in get_x509
return get_x509_for_context(address, port, context)
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 259, in get_x509_for_context
ssl_sock.do_handshake()
File "/usr/lib/python3.5/site-packages/OpenSSL/SSL.py", line 1426, in do_handshake
self._raise_ssl_error(self._ssl, result)
File "/usr/lib/python3.5/site-packages/OpenSSL/SSL.py", line 1174, in _raise_ssl_error
_raise_current_error()
File "/usr/lib/python3.5/site-packages/OpenSSL/_util.py", line 48, in exception_from_error_queue
raise exception_type(errors)
OpenSSL.SSL.Error: [('SSL routines', 'ssl3_get_server_certificate', 'certificate verify failed')]
DEBUG - Get SSLv23 certificate for 192.168.109.30:443
DEBUG - Get SSLv23 certificate for 192.168.109.30:443
DEBUG - Starting new HTTPS connection (1): 192.168.109.30
DEBUG - https://192.168.109.30:443 "GET /api/versions HTTP/1.1" 200 9593
DEBUG - https://192.168.109.30:443 "POST /api/sessions HTTP/1.1" 200 1989
DEBUG - Assert HCS mgmt-vrcs01.alex.local is trusted
INFO - Run `None` on mgmt-vrcs01.alex.local
INFO - Run `grep deployment_scenario /opt/vmware/etc/vami/ovfEnv.xml` on mgmt-vrcs01.alex.local
DEBUG - RC: 0
DEBUG - STDOUT:
DEBUG - <Property oe:key="deployment_scenario" oe:value="VRCS"/>
DEBUG - STDERR:
DEBUG -
DEBUG - Assert HCS mgmt-vrcs01.alex.local has VCD
DEBUG - Unable to load trusted CAs from Certifi
DEBUG - Unable to validate the certificate from 192.168.109.30:443
DEBUG - [('SSL routines', 'ssl3_get_server_certificate', 'certificate verify failed')]
Traceback (most recent call last):
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 336, in hasValidCertificate
cert = get_x509(address, port, SSL.SSLv23_METHOD, disable_validation=False)
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 250, in get_x509
return get_x509_for_context(address, port, context)
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 259, in get_x509_for_context
ssl_sock.do_handshake()
File "/usr/lib/python3.5/site-packages/OpenSSL/SSL.py", line 1426, in do_handshake
self._raise_ssl_error(self._ssl, result)
File "/usr/lib/python3.5/site-packages/OpenSSL/SSL.py", line 1174, in _raise_ssl_error
_raise_current_error()
File "/usr/lib/python3.5/site-packages/OpenSSL/_util.py", line 48, in exception_from_error_queue
raise exception_type(errors)
OpenSSL.SSL.Error: [('SSL routines', 'ssl3_get_server_certificate', 'certificate verify failed')]
DEBUG - Get SSLv23 certificate for 192.168.109.30:443
DEBUG - Unable to load trusted CAs from Certifi
DEBUG - Unable to validate the certificate from 192.168.109.30:443
DEBUG - [('SSL routines', 'ssl3_get_server_certificate', 'certificate verify failed')]
Traceback (most recent call last):
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 336, in hasValidCertificate
cert = get_x509(address, port, SSL.SSLv23_METHOD, disable_validation=False)
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 250, in get_x509
return get_x509_for_context(address, port, context)
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 259, in get_x509_for_context
ssl_sock.do_handshake()
File "/usr/lib/python3.5/site-packages/OpenSSL/SSL.py", line 1426, in do_handshake
self._raise_ssl_error(self._ssl, result)
File "/usr/lib/python3.5/site-packages/OpenSSL/SSL.py", line 1174, in _raise_ssl_error
_raise_current_error()
File "/usr/lib/python3.5/site-packages/OpenSSL/_util.py", line 48, in exception_from_error_queue
raise exception_type(errors)
OpenSSL.SSL.Error: [('SSL routines', 'ssl3_get_server_certificate', 'certificate verify failed')]
DEBUG - Get SSLv23 certificate for 192.168.109.30:443
DEBUG - Get SSLv23 certificate for 192.168.109.30:443
DEBUG - Starting new HTTPS connection (1): 192.168.109.30
DEBUG - https://192.168.109.30:443 "GET /api/versions HTTP/1.1" 200 9593
DEBUG - https://192.168.109.30:443 "POST /api/sessions HTTP/1.1" 200 1989
DEBUG - https://192.168.109.30:443 "GET /api/admin HTTP/1.1" 200 8537
DEBUG - https://192.168.109.30:443 "GET /api/admin/org/a93c9db9-7471-3192-8d09-a8f7eeda85f9 HTTP/1.1" 200 4537
DEBUG - https://192.168.109.30:443 "GET /api/admin/org/a93c9db9-7471-3192-8d09-a8f7eeda85f9/settings/federation HTTP/1.1" 200 3222
DEBUG - Get SSLv23 certificate for compute-vc01.alex.local:443
DEBUG - Assert HCS mgmt-vrcs01.alex.local is configured
INFO - Run `None` on mgmt-vrcs01.alex.local
INFO - Run `grep deployment_scenario /opt/vmware/etc/vami/ovfEnv.xml` on mgmt-vrcs01.alex.local
DEBUG - RC: 0
DEBUG - STDOUT:
DEBUG - <Property oe:key="deployment_scenario" oe:value="VRCS"/>
DEBUG - STDERR:
DEBUG -
INFO - Run `test -f ~/.vcav.configured` on mgmt-vrcs01.alex.local
DEBUG - RC: 0
DEBUG - STDOUT:
DEBUG -
DEBUG - STDERR:
DEBUG -
DEBUG - Start F4M782ZY timeout for 1200
INFO - Run `grep deployment_scenario /opt/vmware/etc/vami/ovfEnv.xml` on mgmt-vrcs01.alex.local
DEBUG - RC: 0
DEBUG - STDOUT:
DEBUG - <Property oe:key="deployment_scenario" oe:value="VRCS"/>
DEBUG - STDERR:
DEBUG -
INFO - Run `test -f ~/.vcav.configured` on mgmt-vrcs01.alex.local
DEBUG - RC: 0
DEBUG - STDOUT:
DEBUG -
DEBUG - STDERR:
DEBUG -
DEBUG - Assert VCD has a registered HCS extension
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension HTTP/1.1" 200 728
DEBUG - Get SSLv23 certificate for compute-vc01.alex.local:443
INFO - Run `None` on mgmt-vrcs01.alex.local
INFO - Run `scp -oUserKnownHostsFile=/root/.vcav/.ssh_known_hosts -i /root/.ssh/id_rsa /opt/vmware/vcav-installer/vm-scripts/validate_hcs.py root@mgmt-vrcs01.alex.local:/root/vcav-installer-scripts/`
DEBUG - Transfer /tmp/tmpcs12qsew to mgmt-vrcs01.alex.local:/tmp/.YY1JJA0F
DEBUG - write() argument must be str, not None
Traceback (most recent call last):
File "/opt/vmware/vcav-installer/pyvcav/remotevmscript.py", line 120, in prepare_remote_files
f.write(value)
File "/usr/lib/python3.5/tempfile.py", line 483, in func_wrapper
return func(*args, **kwargs)
TypeError: write() argument must be str, not None
INFO - Run `rm -f /tmp/.YY1JJA0F` on mgmt-vrcs01.alex.local
DEBUG - RC: 0
DEBUG - STDOUT:
DEBUG -
DEBUG - STDERR:
DEBUG -
INFO - Run `rm -f /tmp/.GTKG04W9` on mgmt-vrcs01.alex.local
DEBUG - RC: 0
DEBUG - STDOUT:
DEBUG -
DEBUG - STDERR:
DEBUG -
DEBUG - Unable to write password for --sso-password-file to remote server
Traceback (most recent call last):
File "/opt/vmware/vcav-installer/pyvcav/remotevmscript.py", line 120, in prepare_remote_files
f.write(value)
File "/usr/lib/python3.5/tempfile.py", line 483, in func_wrapper
return func(*args, **kwargs)
TypeError: write() argument must be str, not None
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 172, in wait
result = callback(*callback_args)
File "/opt/vmware/vcav-installer/pyvcav/endpoints/hcs.py", line 53, in check
self._check_hcs_server()
File "/opt/vmware/vcav-installer/pyvcav/endpoints/hcs.py", line 74, in _check_hcs_server
rs.run()
File "/opt/vmware/vcav-installer/pyvcav/remotevmscript.py", line 86, in run
raise ce
File "/opt/vmware/vcav-installer/pyvcav/remotevmscript.py", line 79, in run
self.prepare_remote_files()
File "/opt/vmware/vcav-installer/pyvcav/remotevmscript.py", line 133, in prepare_remote_files
"remote server" % key)
pyvcav.errors.CommandError: Unable to write password for --sso-password-file to remote server
Can someone help me in fixing this.
Before running this command I ran:
vcav hcs configure --hcs-address=$HCS01_ADDRESS --amqp-password-file=~/.ssh/.amqp --cassandra-replication-factor=1 --vcd-address=$VCD_ADDRESS1 --vcd-user=$VCD_USER --vcd-password-file=~/.ssh/.vcd --sso-user=$SSO_USER --sso-password-file=~/.ssh/.sso
and It returned an OK message.
and the hcs.log on vrcs did not ahd any exceptions
hcs log snippet
===========================
2018-09-14 11:06:59.506 INFO com.vmware.hcs.Main [main] (..vmware.hcs.Main) {} | Configured amqp.extension.queue = [systemExchange-hcs.api.extension]
2018-09-14 11:06:59.511 INFO com.vmware.hcs.Main [main] (..vmware.hcs.Main) {} | Configured amqp.tunnelingApp.queue = [systemExchange-hcs.tunnel.resolver]
2018-09-14 11:06:59.511 INFO com.vmware.hcs.Main [main] (..vmware.hcs.Main) {} | Configured amqp.notification.queue = [systemExchange-hcs.vcd.notifications]
2018-09-14 11:07:03.968 WARN com.vmware.vim.vmomi.client.http.impl.HttpConfigurationCompilerBase$ConnectionMonitorThreadBase [main] (..http.impl.HttpConfigurationCompilerBase$ConnectionMonitorThreadBase) {} | Shutting down the connection monitor.
2018-09-14 11:07:03.969 WARN com.vmware.vim.vmomi.client.http.impl.HttpConfigurationCompilerBase$ConnectionMonitorThreadBase [VLSI-client-connection-monitor-0] (..http.impl.HttpConfigurationCompilerBase$ConnectionMonitorThreadBase) {} | Interrupted, no more connection pool cleanups will be performed.
2018-09-14 11:07:04.610 INFO com.datastax.driver.core.GuavaCompatibility [main] (..driver.core.GuavaCompatibility) {} | Detected Guava < 19 in the classpath, using legacy compatibility layer
2018-09-14 11:07:05.962 INFO com.datastax.driver.core.policies.DCAwareRoundRobinPolicy [main] (..core.policies.DCAwareRoundRobinPolicy) {} | Using data-center name 'dc1' for DCAwareRoundRobinPolicy (if this is incorrect, please provide the correct datacenter name with DCAwareRoundRobinPolicy constructor)
2018-09-14 11:07:05.963 INFO com.datastax.driver.core.Cluster [main] (..driver.core.Cluster$Manager) {} | New Cassandra host mgmt-cass-b.alex.local/192.168.109.37:9042 added
2018-09-14 11:07:06.294 INFO org.eclipse.jetty.util.log [main] (..util.log.Log) {} | Logging initialized @7126ms to org.eclipse.jetty.util.log.Slf4jLog
2018-09-14 11:07:10.583 INFO com.vmware.hcs.domainmodel.support.workflow.impl.WorkflowEngineImpl [main] (..workflow.impl.WorkflowEngineImpl) {} | WorkflowEngine started (maxWorkflowEngineExecutorCapacity:300; preventRebalanceDuringExecution:true; workflowPreventRebalanceTimeMillis:60000)
2018-09-14 11:07:10.616 WARN com.vmware.hcs.gateway.vcd.VcdGatewayProperties [main] (..gateway.vcd.VcdGatewayProperties) {} | Couldn't find a property 'vcd-task-polling-admin-query'. Using the default.
2018-09-14 11:07:10.617 WARN com.vmware.hcs.gateway.vcd.VcdGatewayProperties [main] (..gateway.vcd.VcdGatewayProperties) {} | Couldn't find a property 'vcd-client-connect-timeout'. Using the default.
2018-09-14 11:07:10.618 WARN com.vmware.hcs.gateway.vcd.VcdGatewayProperties [main] (..gateway.vcd.VcdGatewayProperties) {} | Couldn't find a property 'vcd-client-read-timeout'. Using the default.
2018-09-14 11:07:10.766 INFO com.vmware.identity.token.impl.Util [main] (..token.impl.Util$ClassResourceProvider) {} | Reading resources from zip file path=[/opt/vmware/hms/libs/sso-wst-client-6.5.0.jar]
2018-09-14 11:07:10.766 INFO com.vmware.identity.token.impl.Util [main] (..token.impl.Util$ClassResourceProvider) {} | Reading resources from decoded zip file path=[/opt/vmware/hms/libs/sso-wst-client-6.5.0.jar]
2018-09-14 11:07:11.166 INFO com.vmware.identity.token.impl.Util [main] (..token.impl.Util$ClassResourceProvider) {} | Reading resources from zip file path=[/opt/vmware/hms/libs/sso-saml-token-6.5.0.jar]
2018-09-14 11:07:11.166 INFO com.vmware.identity.token.impl.Util [main] (..token.impl.Util$ClassResourceProvider) {} | Reading resources from decoded zip file path=[/opt/vmware/hms/libs/sso-saml-token-6.5.0.jar]
2018-09-14 11:07:11.207 INFO com.vmware.identity.token.impl.SamlTokenImpl [main] (..token.impl.SamlTokenImpl) {} | SAML token for SubjectNameId [value=com.vmware.vr-1c865183-4036-4280-a6ed-6a3bf59ec21a@alex.lab, format=http://schemas.xmlsoap.org/claims/UPN] successfully parsed from Element
2018-09-14 11:07:17.002 INFO com.vmware.identity.token.impl.SamlTokenImpl [main] (..token.impl.SamlTokenImpl) {} | SAML token for SubjectNameId [value=com.vmware.vr-1c865183-4036-4280-a6ed-6a3bf59ec21a@alex.lab, format=http://schemas.xmlsoap.org/claims/UPN] successfully parsed from Element
2018-09-14 11:07:17.487 INFO com.vmware.hcs.domainmodel.support.workflow.impl.WorkflowMonitor [main] (..workflow.impl.WorkflowMonitor) {} | interested in [com.vmware.hcs.repository.impl.cassandra.VdcCassandraRepositoryImpl@1934a7c1, com.vmware.hcs.repository.impl.cassandra.OrgCassandraRepositoryImpl@5f31385e, com.vmware.hcs.repository.impl.cassandra.ReplicationGroupCassandraRepositoryImpl@16cc5e51, com.vmware.hcs.repository.impl.cassandra.WorkflowCassandraRepositoryImpl@18dda2e1, com.vmware.hcs.repository.impl.cassandra.EventStreamCassandraRepositoryImpl@deb0c0e]
2018-09-14 11:07:17.492 INFO com.vmware.hcs.domainmodel.cluster.HcsNodeDaemon [main] (..domainmodel.cluster.HcsNodeDaemon) {} | init: heartBeatPeriod=15 sec
2018-09-14 11:07:17.493 INFO com.vmware.hcs.HcsService [main] (..vmware.hcs.HcsService) {} | starting...
2018-09-14 11:07:18.120 INFO org.eclipse.jetty.server.Server [main] (..jetty.server.Server) {} | jetty-9.4.6.v20170531
2018-09-14 11:07:18.174 INFO org.eclipse.jetty.server.session [main] (..server.session.DefaultSessionIdManager) {} | DefaultSessionIdManager workerName=node0
2018-09-14 11:07:18.174 INFO org.eclipse.jetty.server.session [main] (..server.session.DefaultSessionIdManager) {} | No SessionScavenger set, using defaults
2018-09-14 11:07:18.177 INFO org.eclipse.jetty.server.session [main] (..server.session.HouseKeeper) {} | Scavenging every 600000ms
2018-09-14 11:07:18.183 INFO org.eclipse.jetty.server.handler.ContextHandler.api [main] (..server.handler.ContextHandler$Context) {} | Initializing Spring FrameworkServlet 'rest-servlet'
2018-09-14 11:07:18.210 INFO org.eclipse.jetty.server.handler.ContextHandler [main] (..server.handler.ContextHandler) {} | Started o.e.j.s.ServletContextHandler@47864b2e{/api,null,AVAILABLE}
2018-09-14 11:07:18.212 INFO org.eclipse.jetty.server.Server [main] (..jetty.server.Server) {} | Started @19043ms
2018-09-14 11:07:28.071 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Registered service.
href: https://192.168.109.31/api/admin/extension/service/1f55ca6f-4ed0-4afd-b7bc-aeeb5aa37f77
2018-09-14 11:07:28.706 DEBUG com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | registered right:
name: {com.vmware.vr}:ManageRight href: https://192.168.109.31/api/admin/right/82d25b61-b0db-474c-bb73-9a2d3710f84d
2018-09-14 11:07:29.279 DEBUG com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | registered right:
name: {com.vmware.vr}:ViewRight href: https://192.168.109.31/api/admin/right/ee3016a5-8526-406a-a7b4-fc7f22d735cc
2018-09-14 11:07:29.279 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Registered rights.
2018-09-14 11:07:31.497 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Authorization enabled.
2018-09-14 11:07:31.959 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Creating new role with name: vSphere Replication Role
2018-09-14 11:07:31.960 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Adding right with name: {com.vmware.vr}:ViewRight
2018-09-14 11:07:31.960 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Adding right with name: {com.vmware.vr}:ManageRight
2018-09-14 11:07:31.960 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Adding right with name: Organization vDC: View
2018-09-14 11:07:31.960 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Adding right with name: Organization Network: View
2018-09-14 11:07:31.961 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Adding right with name: Organization: View
2018-09-14 11:07:32.446 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Creating new role with name: vSphere Replication Role...OK
2018-09-14 11:07:33.025 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Replication User cached right name: {com.vmware.vr}:ViewRight id: ee3016a5-8526-406a-a7b4-fc7f22d735cc
2018-09-14 11:07:33.026 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Replication User cached right name: {com.vmware.vr}:ManageRight id: 82d25b61-b0db-474c-bb73-9a2d3710f84d
2018-09-14 11:07:33.098 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Registered tunneling app: urn:vcloud:tunnelingApplication:a840bf6d-671b-4cd8-9aad-236ea44e9808
2018-09-14 11:07:33.100 INFO com.vmware.hcs.domainmodel.cluster.HcsNodeDaemon [main] (..domainmodel.cluster.HcsNodeDaemon) {} | started
2018-09-14 11:07:33.110 INFO com.vmware.hcs.domainmodel.support.workflow.impl.WorkflowMonitor [main] (..workflow.impl.WorkflowMonitor) {} | started
2018-09-14 11:07:33.382 INFO com.vmware.hcs.HcsService [main] (..vmware.hcs.HcsService) {} | starting...OK
TomasFojta vMarkusK1985 jonathanw IamTHEvilONE
Check hcs.log on your vRCS appliance to see if the hcs service is starting up properly.
T.
Hi TomasFojta
HCS service did started up fine when I invoked vcav hcs configure command.
Last line of logs when I ran above command
2018-09-14 11:07:33.098 INFO com.vmware.hcs.gateway.vcd.impl.VcdExtensionServiceImpl [main] (..vcd.impl.VcdExtensionServiceImpl) {} | Registered tunneling app: urn:vcloud:tunnelingApplication:a840bf6d-671b-4cd8-9aad-236ea44e9808
2018-09-14 11:07:33.100 INFO com.vmware.hcs.domainmodel.cluster.HcsNodeDaemon [main] (..domainmodel.cluster.HcsNodeDaemon) {} | started
2018-09-14 11:07:33.110 INFO com.vmware.hcs.domainmodel.support.workflow.impl.WorkflowMonitor [main] (..workflow.impl.WorkflowMonitor) {} | started
2018-09-14 11:07:33.382 INFO com.vmware.hcs.HcsService [main] (..vmware.hcs.HcsService) {} | starting...OK
But when I ran vcav hcs wait-for-extension command, there was no activity in hcs.log. And the error for this command I already posted above.
On vCD appliances I am not using certificates in pkcs12 format. Do you think this can be the reason? Below error I am seeing when i append --debug to vcav hcs wait-for-extension command
DEBUG - Unable to validate the certificate from 192.168.109.30:443
DEBUG - [('SSL routines', 'ssl3_get_server_certificate', 'certificate verify failed')]
Traceback (most recent call last):
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 336, in hasValidCertificate
cert = get_x509(address, port, SSL.SSLv23_METHOD, disable_validation=False)
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 250, in get_x509
return get_x509_for_context(address, port, context)
File "/opt/vmware/vcav-installer/pyvcav/__init__.py", line 259, in get_x509_for_context
ssl_sock.do_handshake()
File "/usr/lib/python3.5/site-packages/OpenSSL/SSL.py", line 1426, in do_handshake
self._raise_ssl_error(self._ssl, result)
File "/usr/lib/python3.5/site-packages/OpenSSL/SSL.py", line 1174, in _raise_ssl_error
_raise_current_error()
File "/usr/lib/python3.5/site-packages/OpenSSL/_util.py", line 48, in exception_from_error_queue
raise exception_type(errors)
OpenSSL.SSL.Error: [('SSL routines', 'ssl3_get_server_certificate', 'certificate verify failed')]
wait-for-extension is just script that waits for vRCS to finish starting up the hcs service. It looks like in your case hcs starts up properly, so you should be ready for next steps.
As next step I ran below command
vcav hbr configure --hbr-address=$HBR_ADDRESS --vsphere-address=$VSPHERE01_ADDRESS --vsphere-user=$SSO_USER --vsphere-password-file=~/.ssh/.sso --vcd-address=$VCD_ADDRESS1 --vcd-user=$VCD_USER --vcd-password-file=~/.ssh/.vcd --debug
which failed with error
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension/vimServerReferences HTTP/1.1" 200 487
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension/vimServerReferences HTTP/1.1" 200 487
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension/vimServer/b95c1827-2a0b-4058-a15d-7801d5331c62 HTTP/1.1" 200 1021
DEBUG - Compare compute-vc01.alex.local to compute-vc01.alex.local
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension/vimServer/b95c1827-2a0b-4058-a15d-7801d5331c62 HTTP/1.1" 200 1021
DEBUG - Ending F94ESMTK timeout
DEBUG - Start 3R1W7PO4 timeout for 30
DEBUG - Find VIM for compute-vc01.alex.local
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension/vimServerReferences HTTP/1.1" 200 487
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension/vimServerReferences HTTP/1.1" 200 487
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension/vimServer/b95c1827-2a0b-4058-a15d-7801d5331c62 HTTP/1.1" 200 1021
DEBUG - Compare compute-vc01.alex.local to compute-vc01.alex.local
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension/vimServer/b95c1827-2a0b-4058-a15d-7801d5331c62 HTTP/1.1" 200 1021
DEBUG - Ending 3R1W7PO4 timeout
DEBUG - Start 7E9D6IHK timeout for 60
DEBUG - Retrive VR Server for vSphere compute-vc01.alex.local
DEBUG - https://192.168.109.30:443 "GET /api/admin/extension/vimServer/b95c1827-2a0b-4058-a15d-7801d5331c62/vrmServer HTTP/1.1" 200 500
DEBUG - Ending 7E9D6IHK timeout
ERROR - The VR server for compute-vc01.alex.local is not connected
Checked hbrsrv.log on vrs appliance and found following log entries (Not sure if its a problem or generic message)
2018-09-14T07:41:44.277Z info hbrsrv[7FF941B91780] [Originator@6876 sub=Main] Listening on 8123 (with SSL) for VMODL connections
2018-09-14T07:41:44.280Z verbose hbrsrv[7FF941B91780] [Originator@6876 sub=SSL] Refreshing guest-info SSL keys (potentially) updated by HMS.
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=Main] HbrError stack:
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=Main] [0] Could not get key guestinfo.hbr.hbrsrv-certificate-revoked: No value found
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=Main] [1] Ignored error.
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=Main] HbrError stack:
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=Main] [0] Database object not found
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=Main] [1] Looking up global key in the database guestinfo.hbr.hbrsrv-certificate-revoked/guestinfo-cache
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=Main] [2] Couldn't read cached value for key guestinfo.hbr.hbrsrv-certificate-revoked
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=Main] [3] Ignored error.
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=SSL] private key file exists
2018-09-14T07:41:44.280Z info hbrsrv[7FF941B91780] [Originator@6876 sub=SSL] cert key file exists
Errors in hcs.log
2018-09-14 11:30:38.349 DEBUG com.vmware.hcs.gateway.hms.impl.HmsLoginByTokenAuthStrategy [pool-6-thread-1] (..hms.impl.HmsLoginByTokenAuthStrategy) {{operationId,HCS-5195c923-1157-4480-a44a-366b31e874a2}} | acquire delegated token for "com.vmware.vr-493ed79a-a687-4561-88c5-c0140481fffd"...OK (_4bfa17be-0348-429f-b7b1-44290f70234d)
2018-09-14 11:30:38.350 DEBUG com.vmware.hcs.gateway.hms.impl.HmsLoginByTokenAuthStrategy [pool-6-thread-1] (..hms.impl.HmsLoginByTokenAuthStrategy) {{operationId,HCS-5195c923-1157-4480-a44a-366b31e874a2}} | loginByToken...
2018-09-14 11:30:38.458 WARN com.vmware.hcs.gateway.hms.impl.HmsGatewayFactoryImpl [pool-6-thread-1] (..hms.impl.HmsGatewayFactoryImpl$2) {{operationId,HCS-5195c923-1157-4480-a44a-366b31e874a2}} | Cannot handle server error:
(hms.fault.HmsRuntimeFault) {
faultCause = (hms.fault.HmsRuntimeFault) {
faultCause = null,
faultMessage = null,
originalMessage = Invalid message timestamp: created time is in the future.
},
faultMessage = null,
originalMessage = Invalid message timestamp: created time is in the future.
}
I am totally lost at this point of time
Previous issue resolved by fixing the time..Now I am getting this error on invoking vcav hbr configure command
2018-09-14 14:08:06.584 ERROR com.vmware.hcs.facade.rest.httpbridge.impl.direct.DirectHttpRequestBridge [pool-6-thread-6] (..impl.direct.DirectHttpRequestBridge) {{operationId,HCS-2a6403c3-4eeb-40d5-bbd5-34efd9062dca}} | onException
org.springframework.web.util.NestedServletException: Request processing failed; nested exception is com.vmware.hcs.gateway.vcd.VcdGatewayException: Failed to get system organization id