[ovirt-users] Second host fail to activate (hosted-engine)

9 Apr 2019


      After installing the second host via the web gui (4.3.2.1-1.el7), it fails to activate telling that wasn't possible to connect to the storage pool default (glusterfs). Those are the logs:

vdsm.log

2019-04-09 15:54:07,409-0400 INFO  (Reactor thread) [ProtocolDetector.AcceptorImpl] Accepted connection from ::1:58130 (protocoldetector:61)
2019-04-09 15:54:07,419-0400 INFO  (Reactor thread) [ProtocolDetector.Detector] Detected protocol stomp from ::1:58130 (protocoldetector:125)
2019-04-09 15:54:07,419-0400 INFO  (Reactor thread) [Broker.StompAdapter] Processing CONNECT request (stompserver:95)
2019-04-09 15:54:07,420-0400 INFO  (JsonRpc (StompReactor)) [Broker.StompAdapter] Subscribe command received (stompserver:124)
2019-04-09 15:54:07,461-0400 INFO  (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call Host.ping2 succeeded in 0.00 seconds (__init__:312)
2019-04-09 15:54:07,466-0400 INFO  (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call Host.ping2 succeeded in 0.00 seconds (__init__:312)
2019-04-09 15:54:07,469-0400 INFO  (jsonrpc/0) [vdsm.api] START getStorageDomainInfo(sdUUID=u'd99fb087-66d5-4adf-9c0c-80e60de17917', options=None) from=::1,58130, task_id=00c843c2-ab43-4813-9ded-29f6742c33b2 (api:48)
2019-04-09 15:54:07,484-0400 INFO  (jsonrpc/0) [vdsm.api] FINISH getStorageDomainInfo error='VERSION' from=::1,58130, task_id=00c843c2-ab43-4813-9ded-29f6742c33b2 (api:52)
2019-04-09 15:54:07,484-0400 ERROR (jsonrpc/0) [storage.TaskManager.Task] (Task='00c843c2-ab43-4813-9ded-29f6742c33b2') Unexpected error (task:875)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run
    return fn(*args, **kargs)
  File "<string>", line 2, in getStorageDomainInfo
  File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 50, in method
    ret = func(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 2741, in getStorageDomainInfo
    dom = self.validateSdUUID(sdUUID)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 305, in validateSdUUID
    sdDom = sdCache.produce(sdUUID=sdUUID)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sdc.py", line 110, in produce
    domain.getRealDomain()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sdc.py", line 51, in getRealDomain
    return self._cache._realProduce(self._sdUUID)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sdc.py", line 134, in _realProduce
    domain = self._findDomain(sdUUID)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sdc.py", line 151, in _findDomain
    return findMethod(sdUUID)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/glusterSD.py", line 56, in findDomain
    return GlusterStorageDomain(GlusterStorageDomain.findDomainPath(sdUUID))
  File "/usr/lib/python2.7/site-packages/vdsm/storage/fileSD.py", line 394, in __init__
    manifest = self.manifestClass(domainPath)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/fileSD.py", line 179, in __init__
    sd.StorageDomainManifest.__init__(self, sdUUID, domaindir, metadata)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sd.py", line 332, in __init__
    self._domainLock = self._makeDomainLock()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sd.py", line 553, in _makeDomainLock
    domVersion = self.getVersion()
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sd.py", line 424, in getVersion
    return self.getMetaParam(DMDK_VERSION)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/sd.py", line 421, in getMetaParam
    return self._metadata[key]
  File "/usr/lib/python2.7/site-packages/vdsm/storage/persistent.py", line 91, in __getitem__
    return dec(self._dict[key])
  File "/usr/lib/python2.7/site-packages/vdsm/storage/persistent.py", line 202, in __getitem__
    return self._metadata[key]
KeyError: 'VERSION'
2019-04-09 15:54:07,484-0400 INFO  (jsonrpc/0) [storage.TaskManager.Task] (Task='00c843c2-ab43-4813-9ded-29f6742c33b2') aborting: Task is aborted: u"'VERSION'" - code 100 (task:1181)
2019-04-09 15:54:07,484-0400 ERROR (jsonrpc/0) [storage.Dispatcher] FINISH getStorageDomainInfo error='VERSION' (dispatcher:87)
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/storage/dispatcher.py", line 74, in wrapper
    result = ctask.prepare(func, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 108, in wrapper
    return m(self, *a, **kw)
  File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1189, in prepare
    raise self.error
KeyError: 'VERSION'
2019-04-09 15:54:07,484-0400 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call StorageDomain.getInfo failed (error 350) in 0.01 seconds (__init__:312)
2019-04-09 15:54:07,502-0400 INFO  (jsonrpc/3) [vdsm.api] START connectStorageServer(domType=7, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'id': u'e29cf818-5ee5-46e1-85c1-8aeefa33e95d', u'vfs_type': u'glusterfs', u'connection': u'poseidon:/engine', u'user': u'kvm'}], options=None) from=::1,58130, task_id=d71268fe-0088-44e1-99e8-7bcc868b3b2e (api:48)
2019-04-09 15:54:07,521-0400 INFO  (jsonrpc/3) [vdsm.api] FINISH connectStorageServer return={'statuslist': [{'status': 0, 'id': u'e29cf818-5ee5-46e1-85c1-8aeefa33e95d'}]} from=::1,58130, task_id=d71268fe-0088-44e1-99e8-7bcc868b3b2e (api:54)
2019-04-09 15:54:07,521-0400 INFO  (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call StoragePool.connectStorageServer succeeded in 0.02 seconds (__init__:312)
2019-04-09 15:54:07,533-0400 INFO  (jsonrpc/4) [vdsm.api] START getStorageDomainStats(sdUUID=u'd99fb087-66d5-4adf-9c0c-80e60de17917', options=None) from=::1,58130, task_id=47c23532-80c9-4186-948b-be9ed264bfbf (api:48)


agent.log
MainThread::INFO::2019-04-09 16:07:23,647::agent::67::ovirt_hosted_engine_ha.agent.agent.Agent::(run) ovirt-hosted-engine-ha agent 2.3.1 started
MainThread::INFO::2019-04-09 16:07:23,699::hosted_engine::244::ovirt_hosted_engine_ha.agent.hosted_engine.HostedEngine::(_get_hostname) Found certificate common name: potential.o2pos.com.br
MainThread::INFO::2019-04-09 16:07:23,825::hosted_engine::524::ovirt_hosted_engine_ha.agent.hosted_engine.HostedEngine::(_initialize_broker) Initializing ha-broker connection
MainThread::INFO::2019-04-09 16:07:23,827::brokerlink::77::ovirt_hosted_engine_ha.lib.brokerlink.BrokerLink::(start_monitor) Starting monitor ping, options {'addr': '192.168.8.1'}
MainThread::ERROR::2019-04-09 16:07:23,828::hosted_engine::540::ovirt_hosted_engine_ha.agent.hosted_engine.HostedEngine::(_initialize_broker) Failed to start necessary monitors
MainThread::ERROR::2019-04-09 16:07:23,828::agent::144::ovirt_hosted_engine_ha.agent.agent.Agent::(_run_agent) Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/agent/agent.py", line 131, in _run_agent
    return action(he)
  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/agent/agent.py", line 55, in action_proper
    return he.start_monitoring()
  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/agent/hosted_engine.py", line 413, in start_monitoring
    self._initialize_broker()
  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/agent/hosted_engine.py", line 537, in _initialize_broker
    m.get('options', {}))
  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/lib/brokerlink.py", line 86, in start_monitor
    ).format(t=type, o=options, e=e)
RequestError: brokerlink - failed to start monitor via ovirt-ha-broker: [Errno 2] No such file or directory, [monitor: 'ping', options: {'addr': '192.168.8.1'}]

MainThread::ERROR::2019-04-09 16:07:23,829::agent::145::ovirt_hosted_engine_ha.agent.agent.Agent::(_run_agent) Trying to restart agent
MainThread::INFO::2019-04-09 16:07:23,829::agent::89::ovirt_hosted_engine_ha.agent.agent.Agent::(run) Agent shutting down

brocker.log

MainThread::INFO::2019-04-09 16:08:00,892::broker::47::ovirt_hosted_engine_ha.broker.broker.Broker::(run) ovirt-hosted-engine-ha broker 2.3.1 started
MainThread::INFO::2019-04-09 16:08:00,892::monitor::40::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Searching for submonitors in /usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/broker/submonitors
MainThread::INFO::2019-04-09 16:08:00,893::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor cpu-load
MainThread::INFO::2019-04-09 16:08:00,895::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor cpu-load-no-engine
MainThread::INFO::2019-04-09 16:08:00,895::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor engine-health
MainThread::INFO::2019-04-09 16:08:00,896::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor mem-free
MainThread::INFO::2019-04-09 16:08:00,896::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor mem-load
MainThread::INFO::2019-04-09 16:08:00,896::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor mgmt-bridge
MainThread::INFO::2019-04-09 16:08:00,897::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor ping
MainThread::INFO::2019-04-09 16:08:00,897::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor storage-domain
MainThread::INFO::2019-04-09 16:08:00,897::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor cpu-load
MainThread::INFO::2019-04-09 16:08:00,898::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor cpu-load-no-engine
MainThread::INFO::2019-04-09 16:08:00,898::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor engine-health
MainThread::INFO::2019-04-09 16:08:00,899::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor mem-free
MainThread::INFO::2019-04-09 16:08:00,899::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor mem-load
MainThread::INFO::2019-04-09 16:08:00,899::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor mgmt-bridge
MainThread::INFO::2019-04-09 16:08:00,900::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor ping
MainThread::INFO::2019-04-09 16:08:00,900::monitor::49::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Loaded submonitor storage-domain
MainThread::INFO::2019-04-09 16:08:00,900::monitor::50::ovirt_hosted_engine_ha.broker.monitor.Monitor::(_discover_submonitors) Finished loading submonitors
MainThread::INFO::2019-04-09 16:08:00,957::storage_backends::345::ovirt_hosted_engine_ha.lib.storage_backends::(connect) Connecting the storage
MainThread::INFO::2019-04-09 16:08:00,958::storage_server::349::ovirt_hosted_engine_ha.lib.storage_server.StorageServer::(connect_storage_server) Connecting storage server
MainThread::INFO::2019-04-09 16:08:00,993::storage_server::356::ovirt_hosted_engine_ha.lib.storage_server.StorageServer::(connect_storage_server) Connecting storage server
MainThread::INFO::2019-04-09 16:08:01,025::storage_server::413::ovirt_hosted_engine_ha.lib.storage_server.StorageServer::(connect_storage_server) Refreshing the storage domain
MainThread::WARNING::2019-04-09 16:08:01,322::storage_broker::97::ovirt_hosted_engine_ha.broker.storage_broker.StorageBroker::(__init__) Can't connect vdsm storage: Command Image.prepare with args {'imageID': 'e525f96e-ffa3-43a8-a368-d473f064944a', 'storagepoolID': '00000000-0000-0000-0000-000000000000', 'volumeID': '12c2075c-4796-4185-b7f3-ed9f366d95ef', 'storagedomainID': 'd99fb087-66d5-4adf-9c0c-80e60de17917'} failed:
(code=100, message='VERSION')

[ovirt-users] Second host fail to activate (hosted-engine)

Ricardo Alonso