[oVirt Jenkins] ovirt-system-tests_he-basic-ansible-suite-master - Build # 621 - Still Failing!

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: 621 Build Status: Still Failing Triggered By: Started by timer ------------------------------------- Changes Since Last Success: ------------------------------------- Changes for Build #604 [Gal Ben Haim] Adding dr suite [Barak Korren] Remove the populate_mock function from mock_runner [Daniel Belenky] mock_runner: store shell cmd in a variable [Barak Korren] mock_runner: Added timeout param [Barak Korren] Make whitelist repo configurable via env vars [Daniel Belenky] stdci_runner: let mock_runner manage timeout [Greg Sheremeta] remove 4.1 change queue from ovirt-engine-nodejs config Changes for Build #605 [Gal Ben Haim] Adding dr suite Changes for Build #606 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file [Barak Korren] Enable CI for kubevirt/client-python [Daniel Belenky] Add timeout config to stdci dsl [Daniel Belenky] stdci_runner.groovy: utilize DSL's timeout cfg Changes for Build #607 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #608 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #609 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #610 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #611 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #612 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #613 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #614 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #615 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #616 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #617 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #618 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file [Yuval Turgeman] ovirt-node-ng: remove nightly master build [Sandro Bonazzola] ovirt-iso-uploader: drop 4.1 jobs Changes for Build #619 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #620 [Ehud Yonasi] ovirt-master.repo: Added new packages to repo file Changes for Build #621 [Miguel Duarte Barroso] Repos: add python2-ovsdbapp to the reposync config [Sandro Bonazzola] ovirt-iso-uploader: branched for 4.2 ----------------- Failed Tests: ----------------- 1 tests failed. FAILED: 010_local_maintenance_cli.local_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=3236 (Tue Sep 11 11:04:10 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {" -------------------- >> begin captured logging << -------------------- root: INFO: * Waiting For System Stability... lago.ssh: DEBUG: start task:259b0c73-be7f-4576-8bdd-e856a6ad648e:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:259b0c73-be7f-4576-8bdd-e856a6ad648e:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running e96f0894 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command e96f0894 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command e96f0894 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=3216 (Tue Sep 11 11:03:50 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=3216 (Tue Sep 11 11:03:50 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": "44316020", "local_conf_timestamp": 3216, "host-ts": 3216}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3209 (Tue Sep 11 11:03:43 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=3209 (Tue Sep 11 11:03:43 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\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": 3000, "stopped": false, "maintenance": false, "crc32": "451318ef", "local_conf_timestamp": 3209, "host-ts": 3209}, "global_maintenance": false} lago.ssh: DEBUG: start task:aa1ffebb-8d9d-4e12-a497-b14a4cfce32b:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:aa1ffebb-8d9d-4e12-a497-b14a4cfce32b:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running e9de0d3e on lago-he-basic-ansible-suite-master-host-0: hosted-engine --set-maintenance --mode=local lago.ssh: DEBUG: Command e9de0d3e on lago-he-basic-ansible-suite-master-host-0 returned with 0 root: INFO: * Waiting for engine to migrate... lago.ssh: DEBUG: start task:cdb4603c-a16c-4607-a94c-9403deb51456:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:cdb4603c-a16c-4607-a94c-9403deb51456:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running ea6a152c on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command ea6a152c on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command ea6a152c 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=3226 (Tue Sep 11 11:04:00 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3226 (Tue Sep 11 11:04:00 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\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": "fe67372c", "local_conf_timestamp": 3226, "host-ts": 3226}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3219 (Tue Sep 11 11:03:53 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=3219 (Tue Sep 11 11:03:53 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\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": 3000, "stopped": false, "maintenance": false, "crc32": "4d10b792", "local_conf_timestamp": 3219, "host-ts": 3219}, "global_maintenance": false} lago.ssh: DEBUG: start task:a5d9b5b4-0f8d-40a3-9e05-f280911e9e7c:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:a5d9b5b4-0f8d-40a3-9e05-f280911e9e7c:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running f0eb2846 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f0eb2846 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command f0eb2846 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=3236 (Tue Sep 11 11:04:10 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\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": 3000, "stopped": false, "maintenance": false, "crc32": "55144615", "local_conf_timestamp": 3229, "host-ts": 3229}, "global_maintenance": false} lago.ssh: DEBUG: start task:ac9e7cbf-4f2d-4af5-9131-db6a31ca99a2:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:ac9e7cbf-4f2d-4af5-9131-db6a31ca99a2:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running f353dfd8 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f353dfd8 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command f353dfd8 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=3236 (Tue Sep 11 11:04:10 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\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": 3000, "stopped": false, "maintenance": false, "crc32": "55144615", "local_conf_timestamp": 3229, "host-ts": 3229}, "global_maintenance": false} lago.ssh: DEBUG: start task:c43ce49d-f9c4-4879-88d2-ba1071c5cfab:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: end task:c43ce49d-f9c4-4879-88d2-ba1071c5cfab:Get ssh client for lago-he-basic-ansible-suite-master-host-0: lago.ssh: DEBUG: Running f59e60c4 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f59e60c4 on lago-he-basic-ansible-suite-master-host-0 returned with 0 lago.ssh: DEBUG: Command f59e60c4 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=3236 (Tue Sep 11 11:04:10 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {" ovirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f10d8c6e668> 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/010_local_maintenance_cli.py", line 36, in <lambda> testlib.assert_true_within_long(lambda: _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/010_local_maintenance_cli.py", line 98, 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=3236 (Tue Sep 11 11:04:10 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {" --------------------- >> 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/010_local_maintenance_cli.py", line 125, in local_maintenance _wait_for_engine_migration(host, he_index, "bad", "Migration Destination") File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-master/ovirt-system-tests/he-basic-ansible-suite-master/test-scenarios/010_local_maintenance_cli.py", line 36, in _wait_for_engine_migration testlib.assert_true_within_long(lambda: _get_he_status(host) 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/010_local_maintenance_cli.py", line 36, in <lambda> testlib.assert_true_within_long(lambda: _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/010_local_maintenance_cli.py", line 98, 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=3236 (Tue Sep 11 11:04:10 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"\n-------------------- >> begin captured logging << --------------------\nroot: INFO: * Waiting For System Stability...\nlago.ssh: DEBUG: start task:259b0c73-be7f-4576-8bdd-e856a6ad648e:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:259b0c73-be7f-4576-8bdd-e856a6ad648e:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running e96f0894 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command e96f0894 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command e96f0894 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=3216 (Tue Sep 11 11:03:50 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=3216 (Tue Sep 11 11:03:50 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": "44316020", "local_conf_timestamp": 3216, "host-ts": 3216}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3209 (Tue Sep 11 11:03:43 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=3209 (Tue Sep 11 11:03:43 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\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": 3000, "stopped": false, "maintenance": false, "crc32": "451318ef", "local_conf_timestamp": 3209, "host-ts": 3209}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:aa1ffebb-8d9d-4e12-a497-b14a4cfce32b:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:aa1ffebb-8d9d-4e12-a497-b14a4cfce32b:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running e9de0d3e on lago-he-basic-ansible-suite-master-host-0: hosted-engine --set-maintenance --mode=local\nlago.ssh: DEBUG: Command e9de0d3e on lago-he-basic-ansible-suite-master-host-0 returned with 0\nroot: INFO: * Waiting for engine to migrate...\nlago.ssh: DEBUG: start task:cdb4603c-a16c-4607-a94c-9403deb51456:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:cdb4603c-a16c-4607-a94c-9403deb51456:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running ea6a152c on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command ea6a152c on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command ea6a152c 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=3226 (Tue Sep 11 11:04:00 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3226 (Tue Sep 11 11:04:00 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\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": "fe67372c", "local_conf_timestamp": 3226, "host-ts": 3226}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3219 (Tue Sep 11 11:03:53 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=3219 (Tue Sep 11 11:03:53 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\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": 3000, "stopped": false, "maintenance": false, "crc32": "4d10b792", "local_conf_timestamp": 3219, "host-ts": 3219}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:a5d9b5b4-0f8d-40a3-9e05-f280911e9e7c:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:a5d9b5b4-0f8d-40a3-9e05-f280911e9e7c:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running f0eb2846 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f0eb2846 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command f0eb2846 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=3236 (Tue Sep 11 11:04:10 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\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": 3000, "stopped": false, "maintenance": false, "crc32": "55144615", "local_conf_timestamp": 3229, "host-ts": 3229}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:ac9e7cbf-4f2d-4af5-9131-db6a31ca99a2:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:ac9e7cbf-4f2d-4af5-9131-db6a31ca99a2:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running f353dfd8 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f353dfd8 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command f353dfd8 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=3236 (Tue Sep 11 11:04:10 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\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": 3000, "stopped": false, "maintenance": false, "crc32": "55144615", "local_conf_timestamp": 3229, "host-ts": 3229}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:c43ce49d-f9c4-4879-88d2-ba1071c5cfab:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: end task:c43ce49d-f9c4-4879-88d2-ba1071c5cfab:Get ssh client for lago-he-basic-ansible-suite-master-host-0:\nlago.ssh: DEBUG: Running f59e60c4 on lago-he-basic-ansible-suite-master-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f59e60c4 on lago-he-basic-ansible-suite-master-host-0 returned with 0\nlago.ssh: DEBUG: Command f59e60c4 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=3236 (Tue Sep 11 11:04:10 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"\novirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f10d8c6e668>\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/010_local_maintenance_cli.py", line 36, in <lambda>\n testlib.assert_true_within_long(lambda: _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/010_local_maintenance_cli.py", line 98, 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=3236 (Tue Sep 11 11:04:10 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3237 (Tue Sep 11 11:04:11 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "bf35865f", "local_conf_timestamp": 3237, "host-ts": 3236}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3229 (Tue Sep 11 11:04:04 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=3229 (Tue Sep 11 11:04:04 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-master-host-1", "host-id": 2, "engine-status": {"\n--------------------- >> end captured logging << ---------------------'