Hi all,

Tried yesterday to deploy hosted-engine on current master snapshot, it failed during host-deploy. host-deploy log ends with:

2020-01-27 15:25:11 IST - TASK [ovirt-host-deploy-vdsm : Reconfigure vdsm tool] **************************

/var/log/messages on the host has:

Jan 27 15:25:24 didi-centos8-host python3[12352]: detected unhandled Python exception in '/usr/bin/vdsm-tool'

/var/log/httpd/ansible_runner_error_log on the engine has (I have to get used to searching there, grepped all of /var/log to find it):

[Mon Jan 27 15:25:25.692397 2020] [wsgi:error] [pid 30029] cb_event_handler event_data={u'event': u'runner_on_failed', u'uuid': u'874e5fcc-12e8-419c-b010-d958adfc4aec', 'stdout': u'fatal: [d
idi-centos8-host.lab.eng.tlv2.redhat.com]: FAILED! => {"changed": true, "cmd": "vdsm-tool configure --force", "delta": "0:00:15.833532", "end": "2020-01-27 15:25:25.296212", "msg": "non-zero
 return code", "rc": 1, "start": "2020-01-27 15:25:09.462680", "stderr": "Error:  Traceback (most recent call last):\\\\n  File \\\\"/usr/bin/vdsm-tool\\\\", line 209, in main\\\\n    return
 tool_command[cmd][\\\\"command\\\\"](*args)\\\\n  File \\\\"/usr/lib/python3.6/site-packages/vdsm/tool/__init__.py\\\\", line 40, in wrapper\\\\n    func(*args, **kwargs)\\\\n  File \\\\"/u
sr/lib/python3.6/site-packages/vdsm/tool/configurator.py\\\\", line 149, in configure\\\\n    service.service_start(s)\\\\n  File \\\\"/usr/lib/python3.6/site-packages/vdsm/tool/service.py\\
\\", line 193, in service_start\\\\n    return _runAlts(_srvStartAlts, srvName)\\\\n  File \\\\"/usr/lib/python3.6/site-packages/vdsm/tool/service.py\\\\", line 172, in _runAlts\\\\n    \\\\
"%s failed\\\\" % alt.__name__, out, err)\\\\nvdsm.tool.service.ServiceOperationError: <exception str() failed>\\\\n\\\\nDuring handling of the above exception, another exception occurred:\\
\\n\\\\nTraceback (most recent call last):\\\\n  File \\\\"/usr/bin/vdsm-tool\\\\", line 224, in <module>\\\\n    sys.exit(main())\\\\n  File \\\\"/usr/bin/vdsm-tool\\\\", line 214, in main\
\\\n    print(\\'Error: \\', e, \\'\\\\\\\\n\\', file=sys.stderr)\\\\n  File \\\\"/usr/lib/python3.6/site-packages/vdsm/tool/service.py\\\\", line 75, in __str__\\\\n    return \\'\\\\\\\\n\
\'.join(s)\\\\nTypeError: sequence item 1: expected str instance, bytes found", "stderr_lines": ["Error:  Traceback (most recent call last):", "  File \\\\"/usr/bin/vdsm-tool\\\\", line 209,
 in main", "    return tool_command[cmd][\\\\"command\\\\"](*args)", "  File \\\\"/usr/lib/python3.6/site-packages/vdsm/tool/__init__.py\\\\", line 40, in wrapper", "    func(*args, **kwargs
)", "  File \\\\"/usr/lib/python3.6/site-packages/vdsm/tool/configurator.py\\\\", line 149, in configure", "    service.service_start(s)", "  File \\\\"/usr/lib/python3.6/site-packages/vdsm/
tool/service.py\\\\", line 193, in service_start", "    return _runAlts(_srvStartAlts, srvName)", "  File \\\\"/usr/lib/python3.6/site-packages/vdsm/tool/service.py\\\\", line 172, in _runAl
ts", "    \\\\"%s failed\\\\" % alt.__name__, out, err)", "vdsm.tool.service.ServiceOperationError: <exception str() failed>", "", "During handling of the above exception, another exception
occurred:", "", "Traceback (most recent call last):", "  File \\\\"/usr/bin/vdsm-tool\\\\", line 224, in <module>", "    sys.exit(main())", "  File \\\\"/usr/bin/vdsm-tool\\\\", line 214, in
 main", "    print(\\'Error: \\', e, \\'\\\\\\\\n\\', file=sys.stderr)", "  File \\\\"/usr/lib/python3.6/site-packages/vdsm/tool/service.py\\\\", line 75, in __str__", "    return \\'\\\\\\\
\n\\'.join(s)", "TypeError: sequence item 1: expected str instance, bytes found"], "stdout": "\\\\nChecking configuration status...\\\\n\\\\nCurrent revision of multipath.conf detected, pres
erving\\\\nabrt is not configured for vdsm\\\\nlibvirtd socket units status: [{\\'Names\\': \\'libvirtd-tls.socket\\', \\'LoadState\\': \\'loaded\\'}, {\\'Names\\': \\'libvirtd-tcp.socket\\'
, \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-ro.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-admin.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names
\\': \\'libvirtd.socket\\', \\'LoadState\\': \\'masked\\'}]\\\\nlibvirtd doesn\\'t use systemd socket activation - one or more of its socket units have been masked\\\\nlibvirt is not configured for vdsm yet\\\\nFAILED: conflicting vdsm and libvirt-qemu tls configuration.\\\\nvdsm.conf with ssl=True requires the following changes:\\\\nlibvirtd.conf: listen_tcp=0, auth_tcp=\\\\"sasl\\\\", listen_tls=1\\\\nqemu.conf: spice_tls=1.\\\\nlvm is configured for vdsm\\\\nManaged volume database is already configured\\\\n\\\\nRunning configure...\\\\nReconfiguration of passwd is done.\\\\nReconfiguration of abrt is done.\\\\nlibvirtd socket units status: [{\\'Names\\': \\'libvirtd-tls.socket\\', \\'LoadState\\': \\'loaded\\'}, {\\'Names\\': \\'libvirtd-tcp.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-ro.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-admin.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd.socket\\', \\'LoadState\\': \\'masked\\'}]\\\\nlibvirtd doesn\\'t use systemd socket activation - one or more of its socket units have been masked\\\\nlibvirtd socket units status: [{\\'Names\\': \\'libvirtd-tls.socket\\', \\'LoadState\\': \\'loaded\\'}, {\\'Names\\': \\'libvirtd-tcp.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-ro.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-admin.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd.socket\\', \\'LoadState\\': \\'masked\\'}]\\\\nlibvirtd doesn\\'t use systemd socket activation - one or more of its socket units have been masked\\\\nReconfiguration of libvirt is done.", "stdout_lines": ["", "Checking configuration status...", "", "Current revision of multipath.conf detected, preserving", "abrt is not configured for vdsm", "libvirtd socket units status: [{\\'Names\\': \\'libvirtd-tls.socket\\', \\'LoadState\\': \\'loaded\\'}, {\\'Names\\': \\'libvirtd-tcp.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-ro.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-admin.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd.socket\\', \\'LoadState\\': \\'masked\\'}]", "libvirtd doesn\\'t use systemd socket activation - one or more of its socket units have been masked", "libvirt is not configured for vdsm yet", "FAILED: conflicting vdsm and libvirt-qemu tls configuration.", "vdsm.conf with ssl=True requires the following changes:", "libvirtd.conf: listen_tcp=0, auth_tcp=\\\\"sasl\\\\", listen_tls=1", "qemu.conf: spice_tls=1.", "lvm is configured for vdsm", "Managed volume database is already configured", "", "Running configure...", "Reconfiguration of passwd is done.", "Reconfiguration of abrt is done.", "libvirtd socket units status: [{\\'Names\\': \\'libvirtd-tls.socket\\', \\'LoadState\\': \\'loaded\\'}, {\\'Names\\': \\'libvirtd-tcp.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-ro.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-admin.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd.socket\\', \\'LoadState\\': \\'masked\\'}]", "libvirtd doesn\\'t use systemd socket activation - one or more of its socket units have been masked", "libvirtd socket units status: [{\\'Names\\': \\'libvirtd-tls.socket\\', \\'LoadState\\': \\'loaded\\'}, {\\'Names\\': \\'libvirtd-tcp.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-ro.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd-admin.socket\\', \\'LoadState\\': \\'masked\\'}, {\\'Names\\': \\'libvirtd.socket\\', \\'LoadState\\': \\'masked\\'}]", "libvirtd doesn\\'t use systemd socket activation - one or more of its socket units have been masked", "Reconfiguration of libvirt is done."]}', 'counter': 40, u'pid': 31685, u'created': u'2020-01-27T13:25:25.683262', 'end_line': 35, 'runner_ident': '5b95ec42-4108-11ea-8afe-001a4a16027a', 'start_line': 34, u'event_data': {u'play_pattern': u'all', u'play': u'all', u'event_loop': None, u'task_args': u'', u'remote_addr': u'didi-centos8-host.lab.eng.tlv2.redhat.com', u'res': {u'stderr_lines': [u'Error:  Traceback (most recent call last):', u'  File "/usr/bin/vdsm-tool", line 209, in main', u'    return tool_command[cmd]["command"](*args)', u'  File "/usr/lib/python3.6/site-packages/vdsm/tool/__init__.py", line 40, in wrapper', u'    func(*args, **kwargs)', u'  File "/usr/lib/python3.6/site-packages/vdsm/tool/configurator.py", line 149, in configure', u'    service.service_start(s)', u'  File "/usr/lib/python3.6/site-
[Mon Jan 27 15:25:25.693655 2020] [wsgi:error] [pid 30029] cb_event_handler event_data={u'event': u'playbook_on_stats', u'uuid': u'2c8d843c-c1ad-41c0-940e-88354387b725', 'stdout': u'\\r\\nPLAY RECAP *********************************************************************\\r\\ndidi-centos8-host.lab.eng.tlv2.redhat.com : ok=11   changed=0    unreachable=0    failed=1    skipped=1    rescued=0    ignored=0   \\r\\n', 'counter': 41, u'pid': 31685, u'created': u'2020-01-27T13:25:25.688541', 'end_line': 39, 'runner_ident': '5b95ec42-4108-11ea-8afe-001a4a16027a', 'start_line': 35, u'event_data': {u'ignored': {}, u'skipped': {u'didi-centos8-host.lab.eng.tlv2.redhat.com': 1}, u'ok': {u'didi-centos8-host.lab.eng.tlv2.redhat.com': 11}, u'artifact_data': {}, u'rescued': {}, u'changed': {}, u'pid': 31685, u'dark': {}, u'playbook_uuid': u'ff508986-9930-47a2-b17b-61a2f2dae905', u'playbook': u'ovirt-host-deploy.yml', u'failures': {u'didi-centos8-host.lab.eng.tlv2.redhat.com': 1}, u'processed': {u'didi-centos8-host.lab.eng.tlv2.redhat.com': 1}}, u'parent_uuid': u'ff508986-9930-47a2-b17b-61a2f2dae905'}

If I now manually run on the host 'vdsm-tool configure --force', it does not fail.

I am now going to try deploy again after reverting to a snapshot I took before deploy.

Best regards,
--
Didi