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
9:14 a.m.
On Tue, Jan 28, 2020 at 9:58 AM Yedidyah Bar David <didi(a)redhat.com> wrote:
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-
The exception seems to be cut somehow, but anyway Marcin, could you please
take a look?
[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
_______________________________________________
Devel mailing list -- devel(a)ovirt.org
To unsubscribe send an email to devel-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/devel@ovirt.org/message/Q2VEW5NXQPV...
--
Martin Perina
Manager, Software Engineering
Red Hat Czech s.r.o.
10:11 a.m.
On 28 Jan 2020, at 16:14, Martin Perina <mperina(a)redhat.com> wrote:
On Tue, Jan 28, 2020 at 9:58 AM Yedidyah Bar David <didi(a)redhat.com> wrote:
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
This is untrue now, *if* you are sure you’re using advanced virt repo and
installed libvirt/qemu from there. Can you confirm? Also, the
detection/handling is only fixed in vdsm since last Thu, not in any build
(only the tag from today has it, or nightly)
Can you confirm?
- 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-
The exception seems to be cut somehow, but anyway Marcin, could you please
take a look?
[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
_______________________________________________
Devel mailing list -- devel(a)ovirt.org
To unsubscribe send an email to devel-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/devel@ovirt.org/message/Q2VEW5NXQPV...
--
Martin Perina
Manager, Software Engineering
Red Hat Czech s.r.o.
_______________________________________________
Devel mailing list -- devel(a)ovirt.org
To unsubscribe send an email to devel-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/devel@ovirt.org/message/A44YHUFU54H...
2:28 a.m.
On 1/28/20 5:11 PM, Michal Skrivanek wrote:
On 28 Jan 2020, at 16:14, Martin Perina <mperina(a)redhat.com
<mailto:mperina@redhat.com>> wrote:
>
>
> On Tue, Jan 28, 2020 at 9:58 AM Yedidyah Bar David <didi(a)redhat.com
> <mailto:didi@redhat.com>> wrote:
>
> 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
> <http://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
>
This is untrue now, *if* you are sure you’re using advanced virt repo
and installed libvirt/qemu from there. Can you confirm? Also, the
detection/handling is only fixed in vdsm since last Thu, not in any
build (only the tag from today has it, or nightly)
Can you confirm?
+1 with Michal here - this should never happen in real life
scenarios.
The most important thing to notice in the log is this part:
libvirtd doesn\\'t use systemd socket activation - one or more of its socket units
have been masked
As you rightly noticed in the other devel thread ("Task Start and enable
services failed to execute"),
libvirt's socket units are masked by libvirt itself in an upgrade scenario:
- you have old libvirt and vdsm installed
- vdsm configures libvirt to pass the "--listen" flag to the daemon
- you upgrade libvirt and vdsm to a version that uses socket activation
- libvirt installation scripts notice the "--listen" flag and respect it
by disabling
its own socket activation mechanism, which is done by masking sockets
- new vdsm version is lost - it sees that there's a new libvirt version that
uses socket activation (because the socket units are there), but they've
been masked in the meantime
We don't support upgrade path by design.
Current vdsm versions require libvirt >= 5.6 - versions that have socket
activation [1].
There are indeed some leftovers in 'vdsm-tool' that were trying to
handle both scenarios,
but again - no upgrade paths. 'vdsm-tool' should work for fresh
installations without any issues.
[1]
https://github.com/oVirt/vdsm/blob/c2735bec16586e1ad2d0ac0242839bfa0e35b4...
> - 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
> <http://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-
>
>
> The exception seems to be cut somehow, but anyway Marcin, could you
> please take a look?
>
> [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
> <http://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
> <http://didi-centos8-host.lab.eng.tlv2.redhat.com>';: 1},
u'ok':
> {u'didi-centos8-host.lab.eng.tlv2.redhat.com
> <http://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
> <http://didi-centos8-host.lab.eng.tlv2.redhat.com>';: 1},
> u'processed': {u'didi-centos8-host.lab.eng.tlv2.redhat.com
> <http://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
> _______________________________________________
> Devel mailing list -- devel(a)ovirt.org <mailto:devel@ovirt.org>
> To unsubscribe send an email to devel-leave(a)ovirt.org
> <mailto:devel-leave@ovirt.org>
> Privacy Statement: https://www.ovirt.org/site/privacy-policy/
> oVirt Code of Conduct:
> https://www.ovirt.org/community/about/community-guidelines/
> List Archives:
>
https://lists.ovirt.org/archives/list/devel@ovirt.org/message/Q2VEW5NXQPV...
>
>
>
> --
> Martin Perina
> Manager, Software Engineering
> Red Hat Czech s.r.o.
> _______________________________________________
> Devel mailing list -- devel(a)ovirt.org <mailto:devel@ovirt.org>
> To unsubscribe send an email to devel-leave(a)ovirt.org
> <mailto:devel-leave@ovirt.org>
> Privacy Statement: https://www.ovirt.org/site/privacy-policy/
> oVirt Code of Conduct:
> https://www.ovirt.org/community/about/community-guidelines/
> List Archives:
>
https://lists.ovirt.org/archives/list/devel@ovirt.org/message/A44YHUFU54H...
2:48 a.m.
On Wed, Jan 29, 2020 at 10:28 AM Marcin Sobczyk <msobczyk(a)redhat.com> wrote:
On 1/28/20 5:11 PM, Michal Skrivanek wrote:
On 28 Jan 2020, at 16:14, Martin Perina <mperina(a)redhat.com> wrote:
On Tue, Jan 28, 2020 at 9:58 AM Yedidyah Bar David <didi(a)redhat.com>
wrote:
> 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
>
This is untrue now, *if* you are sure you’re using advanced virt repo and
installed libvirt/qemu from there. Can you confirm? Also, the
detection/handling is only fixed in vdsm since last Thu, not in any build
(only the tag from today has it, or nightly)
Can you confirm?
+1 with Michal here - this should never happen in real life scenarios.
The most important thing to notice in the log is this part:
libvirtd doesn\\'t use systemd socket activation - one or more of its socket units
have been masked
As you rightly noticed in the other devel thread ("Task Start and enable
services failed to execute"),
libvirt's socket units are masked by libvirt itself in an upgrade scenario:
- you have old libvirt and vdsm installed
- vdsm configures libvirt to pass the "--listen" flag to the daemon
- you upgrade libvirt and vdsm to a version that uses socket activation
- libvirt installation scripts notice the "--listen" flag and respect it
by disabling
its own socket activation mechanism, which is done by masking sockets
- new vdsm version is lost - it sees that there's a new libvirt version
that
uses socket activation (because the socket units are there), but they've
been masked in the meantime
We don't support upgrade path by design.
Not sure what you mean here exactly. Upgrade from what to what? Is this
documented somewhere? Enforced somehow?
Current vdsm versions require libvirt >= 5.6 - versions that have
socket
activation [1].
There are indeed some leftovers in 'vdsm-tool' that were trying to handle
both scenarios,
but again - no upgrade paths. 'vdsm-tool' should work for fresh
installations without any issues.
OK.
I was just wondering, see the other thread, "Why is vdsm enabled by
default?".
I'd clarify my current behavior as a developer. I have a VM I use for
hosted-engine testing. I take snapshots of it after installing or upgrading
packages, but before '--deploy'. Then I try deploy, play with stuff etc.,
and eventually revert to the latest snapshot, 'dnf update', and take
another snapshot, before trying deploy again.
My problem is that on the boot after reversion to a snapshot, vdsm starts
and configures stuff, before I try deploy. As you explained, this is
currently broken.
I now did above again, but reverted to a snapshot from before installing
vdsm. Indeed, now I pass the point that failed above.
I guess a workaround for my own flow above is to disable vdsmd before
taking the snapshot...
Thanks, anyway, and sorry for the noise!
Best regards,
[1]
https://github.com/oVirt/vdsm/blob/c2735bec16586e1ad2d0ac0242839bfa0e35b4...
- 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-
>
The exception seems to be cut somehow, but anyway Marcin, could you please
take a look?
> [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
> _______________________________________________
> Devel mailing list -- devel(a)ovirt.org
> To unsubscribe send an email to devel-leave(a)ovirt.org
> Privacy Statement: https://www.ovirt.org/site/privacy-policy/
> oVirt Code of Conduct:
> https://www.ovirt.org/community/about/community-guidelines/
> List Archives:
>
https://lists.ovirt.org/archives/list/devel@ovirt.org/message/Q2VEW5NXQPV...
>
--
Martin Perina
Manager, Software Engineering
Red Hat Czech s.r.o.
_______________________________________________
Devel mailing list -- devel(a)ovirt.org
To unsubscribe send an email to devel-leave(a)ovirt.org
Privacy Statement: https://www.ovirt.org/site/privacy-policy/
oVirt Code of Conduct:
https://www.ovirt.org/community/about/community-guidelines/
List Archives:
https://lists.ovirt.org/archives/list/devel@ovirt.org/message/A44YHUFU54H...
--
Didi
3:17 a.m.
On 1/29/20 9:48 AM, Yedidyah Bar David wrote:
On Wed, Jan 29, 2020 at 10:28 AM Marcin Sobczyk
<msobczyk(a)redhat.com
<mailto:msobczyk@redhat.com>> wrote:
On 1/28/20 5:11 PM, Michal Skrivanek wrote:
>
>
> On 28 Jan 2020, at 16:14, Martin Perina <mperina(a)redhat.com
> <mailto:mperina@redhat.com>> wrote:
>
>>
>>
>> On Tue, Jan 28, 2020 at 9:58 AM Yedidyah Bar David
>> <didi(a)redhat.com <mailto:didi@redhat.com>> wrote:
>>
>> 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
>> <http://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
>>
>
> This is untrue now, *if* you are sure you’re using advanced virt
> repo and installed libvirt/qemu from there. Can you confirm?
> Also, the detection/handling is only fixed in vdsm since last
> Thu, not in any build (only the tag from today has it, or nightly)
> Can you confirm?
+1 with Michal here - this should never happen in real life scenarios.
The most important thing to notice in the log is this part:
libvirtd doesn\\'t use systemd socket activation - one or more of its socket
units have been masked
As you rightly noticed in the other devel thread ("Task Start and
enable services failed to execute"),
libvirt's socket units are masked by libvirt itself in an upgrade
scenario:
- you have old libvirt and vdsm installed
- vdsm configures libvirt to pass the "--listen" flag to the daemon
- you upgrade libvirt and vdsm to a version that uses socket
activation
- libvirt installation scripts notice the "--listen" flag and
respect it by disabling
its own socket activation mechanism, which is done by masking
sockets
- new vdsm version is lost - it sees that there's a new libvirt
version that
uses socket activation (because the socket units are there), but
they've
been masked in the meantime
We don't support upgrade path by design.
Not sure what you mean here exactly. Upgrade from what to what? Is
this documented somewhere? Enforced somehow?
In general, I meant upgrade from 4.3
to 4.4. In this specific case it
covers upgrading libvirt+vdsm from versions
that don't support socket activation to ones that do.
Current vdsm versions require libvirt >= 5.6 - versions that
have
socket activation [1].
There are indeed some leftovers in 'vdsm-tool' that were trying to
handle both scenarios,
but again - no upgrade paths. 'vdsm-tool' should work for fresh
installations without any issues.
OK.
I was just wondering, see the other thread, "Why is vdsm enabled by
default?".
I'd clarify my current behavior as a developer. I have a VM I use for
hosted-engine testing. I take snapshots of it after installing or
upgrading packages, but before '--deploy'. Then I try deploy, play
with stuff etc., and eventually revert to the latest snapshot, 'dnf
update', and take another snapshot, before trying deploy again.
My problem is that on the boot after reversion to a snapshot, vdsm
starts and configures stuff, before I try deploy. As you explained,
this is currently broken.
I now did above again, but reverted to a snapshot from before
installing vdsm. Indeed, now I pass the point that failed above.
I guess a workaround for my own flow above is to disable vdsmd before
taking the snapshot...
I think that you should simply start with a brand new VM,
adding AV repo
and installing vdsm.
If you use something like this as your new base snapshot everything
should work fine for you.
Thanks, anyway, and sorry for the noise!
Happy to help!
Regards, Marcin
Best regards,
[1]
https://github.com/oVirt/vdsm/blob/c2735bec16586e1ad2d0ac0242839bfa0e35b4...
>
>> - 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
>> <http://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-
>>
>>
>> The exception seems to be cut somehow, but anyway Marcin, could
>> you please take a look?
>>
>> [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
>> <http://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
>> <http://didi-centos8-host.lab.eng.tlv2.redhat.com>';: 1},
>> u'ok': {u'didi-centos8-host.lab.eng.tlv2.redhat.com
>> <http://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
>> <http://didi-centos8-host.lab.eng.tlv2.redhat.com>';: 1},
>> u'processed': {u'didi-centos8-host.lab.eng.tlv2.redhat.com
>> <http://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
>> _______________________________________________
>> Devel mailing list -- devel(a)ovirt.org <mailto:devel@ovirt.org>
>> To unsubscribe send an email to devel-leave(a)ovirt.org
>> <mailto:devel-leave@ovirt.org>
>> Privacy Statement: https://www.ovirt.org/site/privacy-policy/
>> oVirt Code of Conduct:
>> https://www.ovirt.org/community/about/community-guidelines/
>> List Archives:
>>
https://lists.ovirt.org/archives/list/devel@ovirt.org/message/Q2VEW5NXQPV...
>>
>>
>>
>> --
>> Martin Perina
>> Manager, Software Engineering
>> Red Hat Czech s.r.o.
>> _______________________________________________
>> Devel mailing list -- devel(a)ovirt.org <mailto:devel@ovirt.org>
>> To unsubscribe send an email to devel-leave(a)ovirt.org
>> <mailto:devel-leave@ovirt.org>
>> Privacy Statement: https://www.ovirt.org/site/privacy-policy/
>> oVirt Code of Conduct:
>> https://www.ovirt.org/community/about/community-guidelines/
>> List Archives:
>>
https://lists.ovirt.org/archives/list/devel@ovirt.org/message/A44YHUFU54H...
--
Didi
1556
days inactive
1557
days old
5 comments
4 participants
participants (4)
-
Marcin Sobczyk -
Martin Perina -
Michal Skrivanek -
Yedidyah Bar David