2:56 a.m.
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