[ovirt-devel] oVirt system tests currently failing to AddHost on master

Fri Dec 23 18:25:03 UTC 2016

On Fri, Dec 23, 2016 at 6:20 PM, Barak Korren <bkorren at redhat.com> wrote:
> On 22 December 2016 at 21:56, Nir Soffer <nsoffer at redhat.com> wrote:
>> On Thu, Dec 22, 2016 at 9:12 PM, Fred Rolland <frolland at redhat.com> wrote:
>>> SuperVdsm fails to starts :
>>>
>>> MainThread::ERROR::2016-12-22
>>> 12:42:08,699::supervdsmServer::317::SuperVdsm.Server::(main) Could not start
>>> Super Vdsm
>>> Traceback (most recent call last):
>>>   File "/usr/share/vdsm/supervdsmServer", line 297, in main
>>>     server = manager.get_server()
>>>   File "/usr/lib64/python2.7/multiprocessing/managers.py", line 493, in
>>> get_server
>>>     self._authkey, self._serializer)
>>>   File "/usr/lib64/python2.7/multiprocessing/managers.py", line 162, in
>>> __init__
>>>     self.listener = Listener(address=address, backlog=16)
>>>   File "/usr/lib64/python2.7/multiprocessing/connection.py", line 136, in
>>> __init__
>>>     self._listener = SocketListener(address, family, backlog)
>>>   File "/usr/lib64/python2.7/multiprocessing/connection.py", line 260, in
>>> __init__
>>>     self._socket.bind(address)
>>>   File "/usr/lib64/python2.7/socket.py", line 224, in meth
>>>     return getattr(self._sock,name)(*args)
>>> error: [Errno 2] No such file or directory
>>>
>>>
>>> On Thu, Dec 22, 2016 at 7:54 PM, Barak Korren <bkorren at redhat.com> wrote:
>>>>
>>>> It hard to tell currently when did this start b/c we had so package
>>>> issues that made the tests fail before reaching that point most of the
>>>> day.
>>>>
>>>> Since we currently have an issue in Lago with collecting AddHost logs
>>>> (Hopefully we'll resolve this in the next release early next week),
>>>> I`ve ran the tests locally and attached the bundle of generated logs
>>>> to this message.
>>>>
>>>> Included in the attached file are engine logs, host-deploy logs and
>>>> VDSM logs for both test hosts.
>>>>
>>>> From a quick look inside it seems the issue is with VDSM failing to start.
>>
>> From host-deploy/ovirt-host-deploy-20161222124209-192.168.203.4-604a4799.log:
>>
>> 2016-12-22 12:42:05 DEBUG otopi.plugins.otopi.services.systemd
>> plugin.executeRaw:813 execute: ('/bin/systemctl', 'start',
>> 'vdsmd.service'), executable='None', cwd='None', env=None
>> 2016-12-22 12:42:09 DEBUG otopi.plugins.otopi.services.systemd
>> plugin.executeRaw:863 execute-result: ('/bin/systemctl', 'start',
>> 'vdsmd.service'), rc=1
>> 2016-12-22 12:42:09 DEBUG otopi.plugins.otopi.services.systemd
>> plugin.execute:921 execute-output: ('/bin/systemctl', 'start',
>> 'vdsmd.service') stdout:
>>
>>
>> 2016-12-22 12:42:09 DEBUG otopi.plugins.otopi.services.systemd
>> plugin.execute:926 execute-output: ('/bin/systemctl', 'start',
>> 'vdsmd.service') stderr:
>> A dependency job for vdsmd.service failed. See 'journalctl -xe' for details.
>>
>> This means that one of the services vdsm depends on could not start.
>>
>> 2016-12-22 12:42:09 DEBUG otopi.context context._executeMethod:142
>> method exception
>> Traceback (most recent call last):
>>   File "/tmp/ovirt-bUCuRxXXzU/pythonlib/otopi/context.py", line 132,
>> in _executeMethod
>>     method['method']()
>>   File "/tmp/ovirt-bUCuRxXXzU/otopi-plugins/ovirt-host-deploy/vdsm/packages.py",
>> line 209, in _start
>>     self.services.state('vdsmd', True)
>>   File "/tmp/ovirt-bUCuRxXXzU/otopi-plugins/otopi/services/systemd.py",
>> line 141, in state
>>     service=name,
>> RuntimeError: Failed to start service 'vdsmd'
>>
>> This error is not very useful for anyone. What we need in otopi log is
>> the output of
>> journalctl -xe (suggested by systemctl).
>>
>> Didi, can we collect this info when starting a service fail?
>>
>> Barak, can you log in to the host with this error and collect the output?
>>
> By the time I looged in to the host, all IP addresses are gone (I'm
> guessing the setup process killed dhclient), so I'm having to work via
> the serial console)
>
> 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN
>     link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
>     inet 127.0.0.1/8 scope host lo
>        valid_lft forever preferred_lft forever
>     inet6 ::1/128 scope host
>        valid_lft forever preferred_lft forever
> 2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast
> state UP qlen 1000
>     link/ether 54:52:c0:a8:cb:02 brd ff:ff:ff:ff:ff:ff
>     inet6 fe80::5652:c0ff:fea8:cb02/64 scope link
>        valid_lft forever preferred_lft forever
> 3: eth1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast
> state UP qlen 1000
>     link/ether 54:52:c0:a8:cc:02 brd ff:ff:ff:ff:ff:ff
>     inet6 fe80::5652:c0ff:fea8:cc02/64 scope link
>        valid_lft forever preferred_lft forever
> 4: eth2: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast
> state UP qlen 1000
>     link/ether 54:52:c0:a8:cc:03 brd ff:ff:ff:ff:ff:ff
>     inet6 fe80::5652:c0ff:fea8:cc03/64 scope link
>        valid_lft forever preferred_lft forever
> 5: eth3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast
> state UP qlen 1000
>     link/ether 54:52:c0:a8:ca:02 brd ff:ff:ff:ff:ff:ff
>     inet6 fe80::5652:c0ff:fea8:ca02/64 scope link
>        valid_lft forever preferred_lft forever
>
>
> Here is the interesting stuff I can gather from journalctl:
>
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: Traceback (most recent call last):
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: File "/usr/bin/ovirt-imageio-daemon", line
> 14, in <module>
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: server.main(sys.argv)
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py",
> line 51, in main
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: configure_logger()
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py",
> line 69, in configure_logger
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: logging.config.fileConfig(conf,
> disable_existing_loggers=False)
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: File
> "/usr/lib64/python2.7/logging/config.py", line 78, in fileConfig
> Dec 22 12:42:06 lago-basic-suite-master-host0 iscsid[5043]: iSCSI
> daemon with pid=5044 started!
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: handlers = _install_handlers(cp,
> formatters)
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: File
> "/usr/lib64/python2.7/logging/config.py", line 156, in
> _install_handlers
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: h = klass(*args)
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: File
> "/usr/lib64/python2.7/logging/handlers.py", line 117, in __init__
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: BaseRotatingHandler.__init__(self,
> filename, mode, encoding, delay)
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: File
> "/usr/lib64/python2.7/logging/handlers.py", line 64, in __init__
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: logging.FileHandler.__init__(self,
> filename, mode, encoding, delay)
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: File
> "/usr/lib64/python2.7/logging/__init__.py", line 902, in __init__
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: StreamHandler.__init__(self, self._open())
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: File
> "/usr/lib64/python2.7/logging/__init__.py", line 925, in _open
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: stream = open(self.baseFilename,
> self.mode)
> Dec 22 12:42:06 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5007]: IOError: [Errno 13] Permission denied:
> '/var/log/ovirt-imageio-daemon/daemon.log'

This smells like https://bugzilla.redhat.com/1401901

Can you share the output of:

    ls -ld /var/log/ovirt-imageio-daemon
    ls -l /var/log/ovirt-imageio-daemon/

> Dec 22 12:42:06 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service: main process exited, code=exited,
> status=1/FAILURE
> Dec 22 12:42:06 lago-basic-suite-master-host0 systemd[1]: Failed to
> start oVirt ImageIO Daemon.
> -- Subject: Unit ovirt-imageio-daemon.service has failed
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ovirt-imageio-daemon.service has failed.
> --
> -- The result is failed.
> Dec 22 12:42:06 lago-basic-suite-master-host0 systemd[1]: Unit
> ovirt-imageio-daemon.service entered failed state.
> Dec 22 12:42:06 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service failed.
> Dec 22 12:42:06 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service: main process exited, code=exited, status=1/FAILURE
> Dec 22 12:42:06 lago-basic-suite-master-host0 systemd[1]: Unit
> supervdsmd.service entered failed state.
> Dec 22 12:42:06 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service failed.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Started
> Virtualization daemon.
> -- Subject: Unit libvirtd.service has finished start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit libvirtd.service has finished starting up.
> --
> -- The start-up result is done.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service holdoff time over, scheduling restart.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service holdoff time over, scheduling restart.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Starting
> oVirt ImageIO Daemon...
> -- Subject: Unit ovirt-imageio-daemon.service has begun start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ovirt-imageio-daemon.service has begun starting up.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Started
> Auxiliary vdsm service for running helper functions as root.
> -- Subject: Unit supervdsmd.service has finished start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit supervdsmd.service has finished starting up.
> --
> -- The start-up result is done.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Starting
> Auxiliary vdsm service for running helper functions as root...
> -- Subject: Unit supervdsmd.service has begun start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit supervdsmd.service has begun starting up.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Starting
> Virtual Desktop Server Manager network restoration...
> -- Subject: Unit vdsm-network.service has begun start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit vdsm-network.service has begun starting up.
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: Traceback (most recent call last):
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: File "/usr/bin/ovirt-imageio-daemon", line
> 14, in <module>
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: server.main(sys.argv)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py",
> line 51, in main
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: configure_logger()
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py",
> line 69, in configure_logger
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: logging.config.fileConfig(conf,
> disable_existing_loggers=False)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: File
> "/usr/lib64/python2.7/logging/config.py", line 78, in fileConfig
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: handlers = _install_handlers(cp,
> formatters)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: File
> "/usr/lib64/python2.7/logging/config.py", line 156, in
> _install_handlers
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: h = klass(*args)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: File
> "/usr/lib64/python2.7/logging/handlers.py", line 117, in __init__
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: BaseRotatingHandler.__init__(self,
> filename, mode, encoding, delay)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: File
> "/usr/lib64/python2.7/logging/handlers.py", line 64, in __init__
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: logging.FileHandler.__init__(self,
> filename, mode, encoding, delay)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: File
> "/usr/lib64/python2.7/logging/__init__.py", line 902, in __init__
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: StreamHandler.__init__(self, self._open())
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: File
> "/usr/lib64/python2.7/logging/__init__.py", line 925, in _open
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: stream = open(self.baseFilename,
> self.mode)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5082]: IOError: [Errno 13] Permission denied:
> '/var/log/ovirt-imageio-daemon/daemon.log'
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service: main process exited, code=exited,
> status=1/FAILURE
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Failed to
> start oVirt ImageIO Daemon.
> -- Subject: Unit ovirt-imageio-daemon.service has failed
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ovirt-imageio-daemon.service has failed.
> --
> -- The result is failed.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Unit
> ovirt-imageio-daemon.service entered failed state.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service failed.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service: main process exited, code=exited, status=1/FAILURE
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Unit
> supervdsmd.service entered failed state.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service failed.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service holdoff time over, scheduling restart.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service holdoff time over, scheduling restart.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Started
> Auxiliary vdsm service for running helper functions as root.
> -- Subject: Unit supervdsmd.service has finished start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit supervdsmd.service has finished starting up.
> --
> -- The start-up result is done.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Starting
> Auxiliary vdsm service for running helper functions as root...
> -- Subject: Unit supervdsmd.service has begun start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit supervdsmd.service has begun starting up.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Starting
> oVirt ImageIO Daemon...
> -- Subject: Unit ovirt-imageio-daemon.service has begun start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ovirt-imageio-daemon.service has begun starting up.
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: Traceback (most recent call last):
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: File "/usr/bin/ovirt-imageio-daemon", line
> 14, in <module>
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: server.main(sys.argv)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py",
> line 51, in main
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: configure_logger()
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py",
> line 69, in configure_logger
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: logging.config.fileConfig(conf,
> disable_existing_loggers=False)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: File
> "/usr/lib64/python2.7/logging/config.py", line 78, in fileConfig
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: handlers = _install_handlers(cp,
> formatters)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: File
> "/usr/lib64/python2.7/logging/config.py", line 156, in
> _install_handlers
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: h = klass(*args)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: File
> "/usr/lib64/python2.7/logging/handlers.py", line 117, in __init__
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: BaseRotatingHandler.__init__(self,
> filename, mode, encoding, delay)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: File
> "/usr/lib64/python2.7/logging/handlers.py", line 64, in __init__
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: logging.FileHandler.__init__(self,
> filename, mode, encoding, delay)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: File
> "/usr/lib64/python2.7/logging/__init__.py", line 902, in __init__
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: StreamHandler.__init__(self, self._open())
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: File
> "/usr/lib64/python2.7/logging/__init__.py", line 925, in _open
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: stream = open(self.baseFilename,
> self.mode)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5110]: IOError: [Errno 13] Permission denied:
> '/var/log/ovirt-imageio-daemon/daemon.log'
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service: main process exited, code=exited,
> status=1/FAILURE
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Failed to
> start oVirt ImageIO Daemon.
> -- Subject: Unit ovirt-imageio-daemon.service has failed
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ovirt-imageio-daemon.service has failed.
> --
> -- The result is failed.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Unit
> ovirt-imageio-daemon.service entered failed state.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service failed.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service: main process exited, code=exited, status=1/FAILURE
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Unit
> supervdsmd.service entered failed state.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service failed.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service holdoff time over, scheduling restart.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Starting
> oVirt ImageIO Daemon...
> -- Subject: Unit ovirt-imageio-daemon.service has begun start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ovirt-imageio-daemon.service has begun starting up.
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: Traceback (most recent call last):
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: File "/usr/bin/ovirt-imageio-daemon", line
> 14, in <module>
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: server.main(sys.argv)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py",
> line 51, in main
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: configure_logger()
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: File
> "/usr/lib/python2.7/site-packages/ovirt_imageio_daemon/server.py",
> line 69, in configure_logger
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: logging.config.fileConfig(conf,
> disable_existing_loggers=False)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: File
> "/usr/lib64/python2.7/logging/config.py", line 78, in fileConfig
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: handlers = _install_handlers(cp,
> formatters)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: File
> "/usr/lib64/python2.7/logging/config.py", line 156, in
> _install_handlers
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: h = klass(*args)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: File
> "/usr/lib64/python2.7/logging/handlers.py", line 117, in __init__
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: BaseRotatingHandler.__init__(self,
> filename, mode, encoding, delay)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: File
> "/usr/lib64/python2.7/logging/handlers.py", line 64, in __init__
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: logging.FileHandler.__init__(self,
> filename, mode, encoding, delay)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: File
> "/usr/lib64/python2.7/logging/__init__.py", line 902, in __init__
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: StreamHandler.__init__(self, self._open())
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: File
> "/usr/lib64/python2.7/logging/__init__.py", line 925, in _open
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: stream = open(self.baseFilename,
> self.mode)
> Dec 22 12:42:07 lago-basic-suite-master-host0
> ovirt-imageio-daemon[5125]: IOError: [Errno 13] Permission denied:
> '/var/log/ovirt-imageio-daemon/daemon.log'
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service: main process exited, code=exited,
> status=1/FAILURE
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Failed to
> start oVirt ImageIO Daemon.
> -- Subject: Unit ovirt-imageio-daemon.service has failed
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ovirt-imageio-daemon.service has failed.
> --
> -- The result is failed.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]: Unit
> ovirt-imageio-daemon.service entered failed state.
> Dec 22 12:42:07 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service failed.
> Dec 22 12:42:08 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service holdoff time over, scheduling restart.
> Dec 22 12:42:08 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service holdoff time over, scheduling restart.
> Dec 22 12:42:08 lago-basic-suite-master-host0 systemd[1]: Started
> Auxiliary vdsm service for running helper functions as root.
> -- Subject: Unit supervdsmd.service has finished start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit supervdsmd.service has finished starting up.
> --
> -- The start-up result is done.
> Dec 22 12:42:08 lago-basic-suite-master-host0 systemd[1]: Starting
> Auxiliary vdsm service for running helper functions as root...
> -- Subject: Unit supervdsmd.service has begun start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit supervdsmd.service has begun starting up.
> Dec 22 12:42:08 lago-basic-suite-master-host0 systemd[1]: Starting
> oVirt ImageIO Daemon...
> -- Subject: Unit ovirt-imageio-daemon.service has begun start-up
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ovirt-imageio-daemon.service has begun starting up.
> Dec 22 12:42:08 lago-basic-suite-master-host0 systemd[1]:
> ovirt-imageio-daemon.service: main process exited, code=exited,
> status=1/FAILURE
> Dec 22 12:42:08 lago-basic-suite-master-host0 systemd[1]: Failed to
> start oVirt ImageIO Daemon.
> -- Subject: Unit ovirt-imageio-daemon.service has failed
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit ovirt-imageio-daemon.service has failed.
> --
> -- The result is failed.
>
>
> ...  snip ... keeps repeating ....
>
>
>
> Dec 22 12:42:09 lago-basic-suite-master-host0 systemd[1]: start
> request repeated too quickly for supervdsmd.service
> Dec 22 12:42:09 lago-basic-suite-master-host0 systemd[1]: Failed to
> start Auxiliary vdsm service for running helper functions as root.
> -- Subject: Unit supervdsmd.service has failed
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit supervdsmd.service has failed.
> --
> -- The result is failed.
> Dec 22 12:42:09 lago-basic-suite-master-host0 systemd[1]: Dependency
> failed for Virtual Desktop Server Manager.
> -- Subject: Unit vdsmd.service has failed
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit vdsmd.service has failed.
> --
> -- The result is dependency.
> Dec 22 12:42:09 lago-basic-suite-master-host0 systemd[1]: Dependency
> failed for MOM instance configured for VDSM purposes.
> -- Subject: Unit mom-vdsm.service has failed
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit mom-vdsm.service has failed.
> --
> -- The result is dependency.
> Dec 22 12:42:09 lago-basic-suite-master-host0 systemd[1]: Job
> mom-vdsm.service/start failed with result 'dependency'.
> Dec 22 12:42:09 lago-basic-suite-master-host0 systemd[1]: Job
> vdsmd.service/start failed with result 'dependency'.
> Dec 22 12:42:09 lago-basic-suite-master-host0 systemd[1]: Unit
> supervdsmd.service entered failed state.
> Dec 22 12:42:09 lago-basic-suite-master-host0 systemd[1]:
> supervdsmd.service failed.
>
>
>
> ...  snip ... unrelated stuff ....
>
>
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]:
> Traceback (most recent call last):
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: File
> "/usr/share/vdsm/vdsm-restore-net-config", line 482, in <module>
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: restore(args)
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: File
> "/usr/share/vdsm/vdsm-restore-net-config", line 455, in restore
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]:
> touch_file(NETS_RESTORED_MARK)
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: File
> "/usr/share/vdsm/vdsm-restore-net-config", line 431, in touch_file
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: with
> open(file_path, 'a'):
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]:
> IOError: [Errno 2] No such file or directory:
> '/var/run/vdsm/nets_restored'
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]:
> Traceback (most recent call last):
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: File
> "/usr/bin/vdsm-tool", line 219, in main
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: return
> tool_command[cmd]["command"](*args)
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: File
> "/usr/lib/python2.7/site-packages/vdsm/tool/restore_nets.py", line 41,
> in restore_command
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: exec_restore(cmd)
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: File
> "/usr/lib/python2.7/site-packages/vdsm/tool/restore_nets.py", line 54,
> in exec_restore
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]: raise
> EnvironmentError('Failed to restore the persisted networks')
> Dec 22 12:42:11 lago-basic-suite-master-host0 vdsm-tool[5175]:
> EnvironmentError: Failed to restore the persisted networks
> Dec 22 12:42:11 lago-basic-suite-master-host0 systemd[1]:
> vdsm-network.service: main process exited, code=exited,
> status=1/FAILURE
> Dec 22 12:42:11 lago-basic-suite-master-host0 systemd[1]: Failed to
> start Virtual Desktop Server Manager network restoration.
> -- Subject: Unit vdsm-network.service has failed
> -- Defined-By: systemd
> -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
> --
> -- Unit vdsm-network.service has failed.
> --
> -- The result is failed.
> Dec 22 12:42:11 lago-basic-suite-master-host0 systemd[1]: Unit
> vdsm-network.service entered failed state.
> Dec 22 12:42:11 lago-basic-suite-master-host0 systemd[1]:
> vdsm-network.service failed.
>
>
> HTH,
> Barak.
>
>
> --
> Barak Korren
> bkorren at redhat.com
> RHCE, RHCi, RHV-DevOps Team
> https://ifireball.wordpress.com/