[ovirt-users] Failed to start self hosted engine after upgrading oVirt to 4.0

Michal Skrivanek michal.skrivanek at redhat.com
Thu Jun 23 14:26:25 EDT 2016


> On 23 Jun 2016, at 18:36, Stefano Danzi <s.danzi at hawai.it> wrote:
> 
> 
> Hi!
> I've just upgrade oVirt from 3.6 to 4.0 and I'm not able to start the self hosted engine.
> 
> first thing is that the host network lose the degaut gateway configuration. But this is not the problem.
> 
> Logs:
> 
> ==> /var/log/ovirt-hosted-engine-ha/agent.log <==
> MainThread::INFO::2016-06-23 18:28:40,833::hosted_engine::669::ovirt_hosted_engine_ha.agent.hosted_engine.HostedEngine::(_initialize_storage_images) Reloading vm.conf from the shared storage domain
> MainThread::INFO::2016-06-23 18:28:40,833::config::206::ovirt_hosted_engine_ha.agent.hosted_engine.HostedEngine.config::(refresh_local_conf_file) Trying to get a fresher copy of vm configuration from the OVF_STORE
> MainThread::INFO::2016-06-23 18:28:44,535::ovf_store::102::ovirt_hosted_engine_ha.lib.ovf.ovf_store.OVFStore::(scan) Found OVF_STORE: imgUUID:8d07965c-a5c4-4057-912d-901f80cf246c, volUUID:ce3aa63e-e1c4-498e-bdca-9d2e9f47f0f9
> MainThread::INFO::2016-06-23 18:28:44,582::ovf_store::102::ovirt_hosted_engine_ha.lib.ovf.ovf_store.OVFStore::(scan) Found OVF_STORE: imgUUID:bd9aaf0b-8435-4d78-9871-8c7a7f7fa02a, volUUID:3c477b06-063e-4f01-bd05-84c7d467742b
> MainThread::INFO::2016-06-23 18:28:44,674::ovf_store::111::ovirt_hosted_engine_ha.lib.ovf.ovf_store.OVFStore::(getEngineVMOVF) Extracting Engine VM OVF from the OVF_STORE
> MainThread::INFO::2016-06-23 18:28:44,675::ovf_store::118::ovirt_hosted_engine_ha.lib.ovf.ovf_store.OVFStore::(getEngineVMOVF) OVF_STORE volume path: /rhev/data-center/mnt/ovirt01.hawai.lan:_engine/46f55a31-f35f-465c-b3e2-df45c05e06a7/images/bd9aaf0b-8435-4d78-9871-8c7a7f7fa02a/3c477b06-063e-4f01-bd05-84c7d467742b
> MainThread::INFO::2016-06-23 18:28:44,682::config::226::ovirt_hosted_engine_ha.agent.hosted_engine.HostedEngine.config::(refresh_local_conf_file) Found an OVF for HE VM, trying to convert
> MainThread::INFO::2016-06-23 18:28:44,684::config::231::ovirt_hosted_engine_ha.agent.hosted_engine.HostedEngine.config::(refresh_local_conf_file) Got vm.conf from OVF_STORE
> MainThread::INFO::2016-06-23 18:28:44,684::hosted_engine::517::ovirt_hosted_engine_ha.agent.hosted_engine.HostedEngine::(_initialize_broker) Initializing ha-broker connection
> MainThread::INFO::2016-06-23 18:28:44,685::brokerlink::129::ovirt_hosted_engine_ha.lib.brokerlink.BrokerLink::(start_monitor) Starting monitor ping, options {'addr': '192.168.1.254'}
> 
> ==> /var/log/ovirt-hosted-engine-ha/broker.log <==
> Thread-25::ERROR::2016-06-23 18:28:44,697::listener::182::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(handle) Error while serving connection
> Traceback (most recent call last):
>  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/broker/listener.py", line 166, in handle
>    data)
>  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/broker/listener.py", line 299, in _dispatch
>    .set_storage_domain(client, sd_type, **options)
>  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/broker/storage_broker.py", line 66, in set_storage_domain
>    self._backends[client].connect()
>  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/lib/storage_backends.py", line 400, in connect
>    volUUID=volume.volume_uuid
>  File "/usr/lib/python2.7/site-packages/ovirt_hosted_engine_ha/lib/storage_backends.py", line 245, in _get_volume_path
>    volUUID
>  File "/usr/lib64/python2.7/xmlrpclib.py", line 1233, in __call__
>    return self.__send(self.__name, args)
>  File "/usr/lib64/python2.7/xmlrpclib.py", line 1587, in __request
>    verbose=self.__verbose
>  File "/usr/lib64/python2.7/xmlrpclib.py", line 1273, in request
>    return self.single_request(host, handler, request_body, verbose)
>  File "/usr/lib64/python2.7/xmlrpclib.py", line 1301, in single_request
>    self.send_content(h, request_body)
>  File "/usr/lib64/python2.7/xmlrpclib.py", line 1448, in send_content
>    connection.endheaders(request_body)
>  File "/usr/lib64/python2.7/httplib.py", line 975, in endheaders
>    self._send_output(message_body)
>  File "/usr/lib64/python2.7/httplib.py", line 835, in _send_output
>    self.send(msg)
>  File "/usr/lib64/python2.7/httplib.py", line 797, in send
>    self.connect()
>  File "/usr/lib/python2.7/site-packages/vdsm/m2cutils.py", line 203, in connect
>    sock = socket.create_connection((self.host, self.port), self.timeout)
>  File "/usr/lib64/python2.7/socket.py", line 571, in create_connection
>    raise err
> error: [Errno 101] Network is unreachable
> 
> ==> /var/log/ovirt-hosted-engine-ha/agent.log <==
> MainThread::INFO::2016-06-23 18:28:44,697::hosted_engine::602::ovirt_hosted_engine_ha.agent.hosted_engine.HostedEngine::(_initialize_broker) Failed set the storage domain: 'Failed to set storage domain VdsmBackend, options {'hosted-engine.lockspace': '7B22696D6167655F75756964223A202265663131373139322D623564662D346534362D383939622D626666333362663862663135222C202270617468223A206E756C6C2C2022766F6C756D655F75756964223A202230613363393433652D633032392D343134372D623364342D396366353364663161356262227D', 'sp_uuid': '00000000-0000-0000-0000-000000000000', 'dom_type': 'nfs3', 'hosted-engine.metadata': '7B22696D6167655F75756964223A202233353066396361302D363933302D346336342D626438632D613262656631656336383934222C202270617468223A206E756C6C2C2022766F6C756D655F75756964223A202235393335373437392D656664612D343563312D386363392D656131653739633231646561227D', 'sd_uuid': '46f55a31-f35f-465c-b3e2-df45c05e06a7'}: Request failed: <class 'socket.error'>'. Waiting '5's before the next attempt
> 
> ==> /var/log/vdsm/vdsm.log <==
> periodic/3::WARNING::2016-06-23 18:34:41,731::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/2::WARNING::2016-06-23 18:34:43,657::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.BlockjobMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/0::WARNING::2016-06-23 18:34:43,732::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/3::WARNING::2016-06-23 18:34:45,732::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/2::WARNING::2016-06-23 18:34:47,723::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/1::WARNING::2016-06-23 18:34:49,724::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/0::WARNING::2016-06-23 18:34:51,725::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/3::WARNING::2016-06-23 18:34:53,726::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/2::WARNING::2016-06-23 18:34:55,727::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> 
> ==> /var/log/vdsm/mom.log <==
> 2016-06-23 18:34:56,376 - mom.vdsmInterface - ERROR - Cannot connect to VDSM! [Errno 101] Network is unreachable
> 
> ==> /var/log/vdsm/vdsm.log <==
> periodic/1::WARNING::2016-06-23 18:34:57,727::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/2::WARNING::2016-06-23 18:34:58,652::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.BlockjobMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> periodic/2::WARNING::2016-06-23 18:34:59,728::periodic::269::virt.periodic.VmDispatcher::(__call__) could not run <class 'vdsm.virt.periodic.DriveWatermarkMonitor'> on ['b66ae2c5-de0f-4361-953b-f10226da7eb8']
> Reactor thread::INFO::2016-06-23 18:35:00,048::protocoldetector::72::ProtocolDetector.AcceptorImpl::(handle_accept) Accepting connection from ::ffff:192.168.1.50:60604
> Reactor thread::DEBUG::2016-06-23 18:35:00,057::protocoldetector::85::ProtocolDetector.Detector::(__init__) Using required_size=11
> Reactor thread::INFO::2016-06-23 18:35:00,058::protocoldetector::121::ProtocolDetector.Detector::(handle_read) Detected protocol stomp from ::ffff:192.168.1.50:60604
> Reactor thread::INFO::2016-06-23 18:35:00,058::stompreactor::101::Broker.StompAdapter::(_cmd_connect) Processing CONNECT request
> Reactor thread::DEBUG::2016-06-23 18:35:00,059::stompreactor::483::protocoldetector.StompDetector::(handle_socket) Stomp detected from ('::ffff:192.168.1.50', 60604)
> JsonRpc (StompReactor)::INFO::2016-06-23 18:35:00,059::stompreactor::128::Broker.StompAdapter::(_cmd_subscribe) Subscribe command received
> jsonrpc.Executor/2::DEBUG::2016-06-23 18:35:01,688::__init__::522::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'Host.getHardwareInfo' in bridge with {}

can you please post a bit more of vdsm.log, before and after, inclding also time around 18:28 as per the error above in hosted-engine-ha?

> 
> 
> [root at ovirt01 ~]# netstat -lnp
> Active Internet connections (only servers)
> Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
> tcp        0      0 0.0.0.0:111             0.0.0.0:*               LISTEN      985/rpcbind
> tcp        0      0 0.0.0.0:882             0.0.0.0:*               LISTEN      1970/glusterfs
> tcp        0      0 0.0.0.0:54322           0.0.0.0:*               LISTEN      925/python
> tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      1600/sshd
> tcp        0      0 0.0.0.0:49152           0.0.0.0:*               LISTEN      1978/glusterfsd
> tcp        0      0 0.0.0.0:2049            0.0.0.0:*               LISTEN      1970/glusterfs
> tcp        0      0 0.0.0.0:38465           0.0.0.0:*               LISTEN      1970/glusterfs
> tcp        0      0 0.0.0.0:49153           0.0.0.0:*               LISTEN      1963/glusterfsd
> tcp        0      0 0.0.0.0:32802           0.0.0.0:*               LISTEN      2193/rpc.statd
> tcp        0      0 0.0.0.0:38466           0.0.0.0:*               LISTEN      1970/glusterfs
> tcp        0      0 0.0.0.0:16514           0.0.0.0:*               LISTEN      1633/libvirtd
> tcp        0      0 0.0.0.0:38468           0.0.0.0:*               LISTEN      1970/glusterfs
> tcp        0      0 0.0.0.0:38469           0.0.0.0:*               LISTEN      1970/glusterfs
> tcp        0      0 0.0.0.0:24007           0.0.0.0:*               LISTEN      1652/glusterd
> tcp6       0      0 :::54321                :::*                    LISTEN      1921/python
> tcp6       0      0 :::22                   :::*                    LISTEN      1600/sshd
> tcp6       0      0 :::16514                :::*                    LISTEN      1633/libvirtd
> udp        0      0 0.0.0.0:40503           0.0.0.0:*                           937/avahi-daemon: r
> udp        0      0 0.0.0.0:40873           0.0.0.0:*                           2193/rpc.statd
> udp        0      0 0.0.0.0:111             0.0.0.0:*                           985/rpcbind
> udp        0      0 127.0.0.1:323           0.0.0.0:*                           952/chronyd
> udp        0      0 0.0.0.0:694             0.0.0.0:*                           985/rpcbind
> udp        0      0 127.0.0.1:703           0.0.0.0:*                           2193/rpc.statd
> udp        0      0 0.0.0.0:879             0.0.0.0:*                           1970/glusterfs
> udp        0      0 0.0.0.0:5353            0.0.0.0:*                           937/avahi-daemon: r
> udp6       0      0 ::1:323                 :::*                                952/chronyd
> Active UNIX domain sockets (only servers)
> Proto RefCnt Flags       Type       State         I-Node   PID/Program name     Path
> unix  2      [ ACC ]     STREAM     LISTENING     19455    1633/libvirtd        /var/run/libvirt/libvirt-sock
> unix  2      [ ACC ]     STREAM     LISTENING     22529    1633/libvirtd        /var/run/libvirt/libvirt-sock-ro
> unix  2      [ ACC ]     STREAM     LISTENING     16902    1/systemd            /var/run/rpcbind.sock
> unix  2      [ ACC ]     STREAM     LISTENING     24077    1978/glusterfsd      /var/run/gluster/changelog-36d1d6bf77f0ad218a0db9ada4237737.sock
> unix  2      [ ACC ]     STREAM     LISTENING     20494    992/gssproxy         /run/gssproxy.sock
> unix  2      [ ACC ]     STREAM     LISTENING     14641    682/multipathd       @/org/kernel/linux/storage/multipathd
> unix  2      [ ACC ]     STREAM     LISTENING     16914    1/systemd            /var/run/avahi-daemon/socket
> unix  2      [ ACC ]     STREAM     LISTENING     19484    993/sanlock          /var/run/sanlock/sanlock.sock
> unix  2      [ ACC ]     STREAM     LISTENING     24095    1963/glusterfsd      /var/run/gluster/changelog-c54f38f29c5c1e84d2766564ea967b8d.sock
> unix  2      [ ACC ]     STREAM     LISTENING     16929    1/systemd            /var/run/dbus/system_bus_socket
> unix  2      [ ACC ]     STREAM     LISTENING     12093    1/systemd            /run/systemd/private
> unix  2      [ ACC ]     STREAM     LISTENING     16924    1/systemd            @ISCSID_UIP_ABSTRACT_NAMESPACE
> unix  2      [ ACC ]     STREAM     LISTENING     18255    925/python           /var/run/vdsm/ovirt-imageio-daemon.sock
> unix  2      [ ACC ]     STREAM     LISTENING     23905    1963/glusterfsd      /var/run/gluster/b3162364606c81381a4c768484c6f091.socket
> unix  2      [ ACC ]     SEQPACKET  LISTENING     13409    1/systemd            /run/udev/control
> unix  2      [ ACC ]     STREAM     LISTENING     90477    1970/glusterfs       /var/run/gluster/b6606e2cc1634ac3c57dae961f6a6cc3.socket
> unix  2      [ ACC ]     STREAM     LISTENING     13428    1/systemd            /run/lvm/lvmetad.socket
> unix  2      [ ACC ]     STREAM     LISTENING     18302    920/python           /var/run/ovirt-hosted-engine-ha/broker.socket
> unix  2      [ ACC ]     STREAM     LISTENING     23947    1978/glusterfsd      /var/run/gluster/65f923a8c0294836aec3ffce760511cb.socket
> unix  2      [ ACC ]     STREAM     LISTENING     20112    1652/glusterd        /var/run/glusterd.socket
> unix  2      [ ACC ]     STREAM     LISTENING     18321    939/python           /var/run/vdsm/svdsm.sock
> unix  2      [ ACC ]     STREAM     LISTENING     20493    992/gssproxy         /var/lib/gssproxy/default.sock
> unix  2      [ ACC ]     STREAM     LISTENING     13470    1/systemd            /run/lvm/lvmpolld.socket
> unix  2      [ ACC ]     STREAM     LISTENING     16909    1/systemd            @ISCSIADM_ABSTRACT_NAMESPACE
> unix  2      [ ACC ]     STREAM     LISTENING     18160    990/wdmd             /var/run/wdmd/wdmd.sock
> unix  2      [ ACC ]     STREAM     LISTENING     2291     1/systemd            /run/systemd/journal/stdout
> unix  2      [ ACC ]     STREAM     LISTENING     90622    1923/python          /var/run/vdsm/mom-vdsm.sock
> 
> 
> _______________________________________________
> Users mailing list
> Users at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
> 
> 



More information about the Users mailing list