[oVirt Jenkins] ovirt-system-tests_he-basic-ansible-suite-master - Build # 778 - Failure!

Project: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-ansible-suite-ma... Build: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-ansible-suite-ma... Build Number: 778 Build Status: Failure Triggered By: Started by timer ------------------------------------- Changes Since Last Success: ------------------------------------- Changes for Build #778 [Martin Perina] Fix notifier check in master and 4.2 ----------------- Failed Tests: ----------------- 1 tests failed. FAILED: 008_restart_he_vm.clear_global_maintenance Error Message: could not parse JSON: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\nhost-id=2\nscore=0\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=ReinitializeFSM\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not runnin -------------------- >> begin captured logging << -------------------- root: INFO: * Waiting For System Stability... lago.ssh: DEBUG: start task:0c0547e8-8d97-46b2-8baf-324de01e613a:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:0c0547e8-8d97-46b2-8baf-324de01e613a:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running 99dca43c on lago-he-basic-ansible-suite-master-host-0: hosted-engine --set-maintenance --mode=none lago.ssh: DEBUG: Command 99dca43c on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: start task:ed30e092-2a34-45b3-a264-33553f979604:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:ed30e092-2a34-45b3-a264-33553f979604:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running 9a68a338 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 9a68a338 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command 9a68a338 on lago-he-basic-ansible-suite-master-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3255 (Fri Nov 2 19:04:03 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3255 (Fri Nov 2 19:04:03 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "9f6ed413", "local_conf_timestamp": 3255, "host-ts": 3255}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3253 (Fri Nov 2 19:04:01 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=3253 (Fri Nov 2 19:04:01 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "ae89ee36", "local_conf_timestamp": 3253, "host-ts": 3253}, "global_maintenance": false} lago.ssh: DEBUG: start task:1804e051-e73b-494a-8813-35750dc4ad59:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:1804e051-e73b-494a-8813-35750dc4ad59:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running 9b2796b2 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 9b2796b2 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command 9b2796b2 on lago-he-basic-ansible-suite-master-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3255 (Fri Nov 2 19:04:03 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3255 (Fri Nov 2 19:04:03 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "9f6ed413", "local_conf_timestamp": 3255, "host-ts": 3255}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3253 (Fri Nov 2 19:04:01 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=3253 (Fri Nov 2 19:04:01 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "ae89ee36", "local_conf_timestamp": 3253, "host-ts": 3253}, "global_maintenance": false} lago.ssh: DEBUG: start task:9f4e78c0-cc0d-49a0-ba9b-55240f32537b:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:9f4e78c0-cc0d-49a0-ba9b-55240f32537b:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running a1a70400 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command a1a70400 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command a1a70400 on lago-he-basic-ansible-suite-master-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3265 (Fri Nov 2 19:04:13 2018)\nhost-id=1\nscore=0\nvm_conf_refresh_time=3266 (Fri Nov 2 19:04:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=ReinitializeFSM\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "0a390014", "local_conf_timestamp": 3266, "host-ts": 3265}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3263 (Fri Nov 2 19:04:11 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=3263 (Fri Nov 2 19:04:11 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "b68d1fb1", "local_conf_timestamp": 3263, "host-ts": 3263}, "global_maintenance": false} lago.ssh: DEBUG: start task:ea0f0ccd-77fe-4ff8-aba9-b8a99449aa74:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:ea0f0ccd-77fe-4ff8-aba9-b8a99449aa74:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running a3f05c48 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command a3f05c48 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command a3f05c48 on lago-he-basic-ansible-suite-master-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\nhost-id=2\nscore=0\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=ReinitializeFSM\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "271d3e26", "local_conf_timestamp": 3274, "host-ts": 3273}, "global_maintenance": false} lago.ssh: DEBUG: start task:97401d7d-20a1-460b-b997-60e93c926d9b:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:97401d7d-20a1-460b-b997-60e93c926d9b:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running a63bf228 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command a63bf228 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command a63bf228 on lago-he-basic-ansible-suite-master-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\nhost-id=2\nscore=0\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=ReinitializeFSM\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "271d3e26", "local_conf_timestamp": 3274, "host-ts": 3273}, "global_maintenance": false} lago.ssh: DEBUG: start task:643e3d97-fb3d-49ad-8f92-3caf6158aa25:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:643e3d97-fb3d-49ad-8f92-3caf6158aa25:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running a88867b4 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command a88867b4 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command a88867b4 on lago-he-basic-ansible-suite-master-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\nhost-id=2\nscore=0\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=ReinitializeFSM\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not runnin ovirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f7cd1ef4050> Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 234, in assert_equals_within res = func() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 85, in <lambda> lambda: _is_state_maintenance(host, "GlobalMaintenance") is False File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 58, in _is_state_maintenance status = _get_he_status(host) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 128, in _get_he_status raise RuntimeError('could not parse JSON: %s' % ret.out) RuntimeError: could not parse JSON: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\nhost-id=2\nscore=0\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=ReinitializeFSM\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not runnin --------------------- >> end captured logging << --------------------- Stack Trace: File "/usr/lib64/python2.7/unittest/case.py", line 369, in run testMethod() File "/usr/lib/python2.7/site-packages/nose/case.py", line 197, in runTest self.test(*self.arg) File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 142, in wrapped_test test() File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 60, in wrapper return func(get_test_prefix(), *args, **kwargs) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 85, in clear_global_maintenance lambda: _is_state_maintenance(host, "GlobalMaintenance") is False File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 286, in assert_true_within_long assert_equals_within_long(func, True, allowed_exceptions) File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 273, in assert_equals_within_long func, value, LONG_TIMEOUT, allowed_exceptions=allowed_exceptions File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 234, in assert_equals_within res = func() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 85, in <lambda> lambda: _is_state_maintenance(host, "GlobalMaintenance") is False File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 58, in _is_state_maintenance status = _get_he_status(host) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 128, in _get_he_status raise RuntimeError('could not parse JSON: %s' % ret.out) 'could not parse JSON: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\\nhost-id=2\\nscore=0\\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=ReinitializeFSM\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not runnin\n-------------------- >> begin captured logging << --------------------\nroot: INFO: * Waiting For System Stability...\nlago.ssh: DEBUG: start task:0c0547e8-8d97-46b2-8baf-324de01e613a:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:0c0547e8-8d97-46b2-8baf-324de01e613a:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running 99dca43c on lago-he-basic-ansible-suite-master-host-0: hosted-engine --set-maintenance --mode=none\nlago.ssh: DEBUG: Command 99dca43c on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: start task:ed30e092-2a34-45b3-a264-33553f979604:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:ed30e092-2a34-45b3-a264-33553f979604:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running 9a68a338 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 9a68a338 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command 9a68a338 on lago-he-basic-ansible-suite-master-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3255 (Fri Nov 2 19:04:03 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3255 (Fri Nov 2 19:04:03 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "9f6ed413", "local_conf_timestamp": 3255, "host-ts": 3255}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3253 (Fri Nov 2 19:04:01 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=3253 (Fri Nov 2 19:04:01 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "ae89ee36", "local_conf_timestamp": 3253, "host-ts": 3253}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:1804e051-e73b-494a-8813-35750dc4ad59:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:1804e051-e73b-494a-8813-35750dc4ad59:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running 9b2796b2 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 9b2796b2 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command 9b2796b2 on lago-he-basic-ansible-suite-master-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3255 (Fri Nov 2 19:04:03 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3255 (Fri Nov 2 19:04:03 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "9f6ed413", "local_conf_timestamp": 3255, "host-ts": 3255}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3253 (Fri Nov 2 19:04:01 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=3253 (Fri Nov 2 19:04:01 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "ae89ee36", "local_conf_timestamp": 3253, "host-ts": 3253}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:9f4e78c0-cc0d-49a0-ba9b-55240f32537b:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:9f4e78c0-cc0d-49a0-ba9b-55240f32537b:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running a1a70400 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command a1a70400 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command a1a70400 on lago-he-basic-ansible-suite-master-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3265 (Fri Nov 2 19:04:13 2018)\\nhost-id=1\\nscore=0\\nvm_conf_refresh_time=3266 (Fri Nov 2 19:04:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=ReinitializeFSM\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "0a390014", "local_conf_timestamp": 3266, "host-ts": 3265}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3263 (Fri Nov 2 19:04:11 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=3263 (Fri Nov 2 19:04:11 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "b68d1fb1", "local_conf_timestamp": 3263, "host-ts": 3263}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:ea0f0ccd-77fe-4ff8-aba9-b8a99449aa74:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:ea0f0ccd-77fe-4ff8-aba9-b8a99449aa74:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running a3f05c48 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command a3f05c48 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command a3f05c48 on lago-he-basic-ansible-suite-master-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\\nhost-id=2\\nscore=0\\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=ReinitializeFSM\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "271d3e26", "local_conf_timestamp": 3274, "host-ts": 3273}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:97401d7d-20a1-460b-b997-60e93c926d9b:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:97401d7d-20a1-460b-b997-60e93c926d9b:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running a63bf228 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command a63bf228 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command a63bf228 on lago-he-basic-ansible-suite-master-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\\nhost-id=2\\nscore=0\\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=ReinitializeFSM\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "271d3e26", "local_conf_timestamp": 3274, "host-ts": 3273}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:643e3d97-fb3d-49ad-8f92-3caf6158aa25:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:643e3d97-fb3d-49ad-8f92-3caf6158aa25:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running a88867b4 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command a88867b4 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command a88867b4 on lago-he-basic-ansible-suite-master-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\\nhost-id=2\\nscore=0\\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=ReinitializeFSM\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not runnin\novirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f7cd1ef4050>\nTraceback (most recent call last):\n File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 234, in assert_equals_within\n res = func()\n File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 85, in <lambda>\n lambda: _is_state_maintenance(host, "GlobalMaintenance") is False\n File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 58, in _is_state_maintenance\n status = _get_he_status(host)\n File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/008_restart_he_vm.py", line 128, in _get_he_status\n raise RuntimeError(\'could not parse JSON: %s\' % ret.out)\nRuntimeError: could not parse JSON: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3275 (Fri Nov 2 19:04:22 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=3275 (Fri Nov 2 19:04:23 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "0e550e4f", "local_conf_timestamp": 3275, "host-ts": 3275}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3273 (Fri Nov 2 19:04:21 2018)\\nhost-id=2\\nscore=0\\nvm_conf_refresh_time=3274 (Fri Nov 2 19:04:21 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=ReinitializeFSM\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"reason": "vm not runnin\n--------------------- >> end captured logging << ---------------------'