Project: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-ansible-suite-4.2/ Build: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-ansible-suite-4.... Build Number: 374 Build Status: Failure Triggered By: Started by timer ------------------------------------- Changes Since Last Success: ------------------------------------- Changes for Build #374 [Gal Ben Haim] Adding 1GB of ram to hosts in HE suites ----------------- Failed Tests: ----------------- 1 tests failed. FAILED: 010_local_mainentance.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=2413 (Sat Jul 14 04:05:24 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=2413 (Sat Jul 14 04:05:24 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "fbe19d82", "local_conf_timestamp": 2413, "host-ts": 2413}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2406 (Sat Jul 14 04:05:17 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2406 (Sat Jul 14 04:05:17 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason -------------------- >> begin captured logging << -------------------- lago.ssh: DEBUG: start task:20e58b83-75f8-4b3d-8f26-1c5b014b4eb7:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:20e58b83-75f8-4b3d-8f26-1c5b014b4eb7:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running 9d5832ca on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 9d5832ca on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 9d5832ca on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2383 (Sat Jul 14 04:04:53 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=2383 (Sat Jul 14 04:04:54 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "f2c58547", "local_conf_timestamp": 2383, "host-ts": 2383}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2385 (Sat Jul 14 04:04:56 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2385 (Sat Jul 14 04:04:56 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "920e0845", "local_conf_timestamp": 2385, "host-ts": 2385}, "global_maintenance": false} lago.ssh: DEBUG: start task:82905888-0e48-4556-aa63-8bf44d0ab81a:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:82905888-0e48-4556-aa63-8bf44d0ab81a:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running 9dd5f336 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --set-maintenance --mode=local lago.ssh: DEBUG: Command 9dd5f336 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 root: INFO: * Waiting for engine to migrate... lago.ssh: DEBUG: start task:8d6f88dd-96c6-407e-98a2-f970dd23dbde:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:8d6f88dd-96c6-407e-98a2-f970dd23dbde:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running 9e567c18 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 9e567c18 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 9e567c18 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2393 (Sat Jul 14 04:05:04 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=2393 (Sat Jul 14 04:05:04 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "a8c95a47", "local_conf_timestamp": 2393, "host-ts": 2393}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2385 (Sat Jul 14 04:04:56 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2385 (Sat Jul 14 04:04:56 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "920e0845", "local_conf_timestamp": 2385, "host-ts": 2385}, "global_maintenance": false} lago.ssh: DEBUG: start task:6c85f2c8-fdb8-4ba0-844a-f0f3cea8338d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:6c85f2c8-fdb8-4ba0-844a-f0f3cea8338d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running a5189694 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command a5189694 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command a5189694 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2403 (Sat Jul 14 04:05:13 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=2403 (Sat Jul 14 04:05:14 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "eda598e3", "local_conf_timestamp": 2403, "host-ts": 2403}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2395 (Sat Jul 14 04:05:06 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2396 (Sat Jul 14 04:05:07 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "cd8c1d29", "local_conf_timestamp": 2396, "host-ts": 2395}, "global_maintenance": false} lago.ssh: DEBUG: start task:6fef0ac9-ea00-409b-a8e3-53e4a88f8fb9:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:6fef0ac9-ea00-409b-a8e3-53e4a88f8fb9:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running a77272c0 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command a77272c0 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command a77272c0 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2403 (Sat Jul 14 04:05:13 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=2403 (Sat Jul 14 04:05:14 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "eda598e3", "local_conf_timestamp": 2403, "host-ts": 2403}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2395 (Sat Jul 14 04:05:06 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2396 (Sat Jul 14 04:05:07 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "cd8c1d29", "local_conf_timestamp": 2396, "host-ts": 2395}, "global_maintenance": false} lago.ssh: DEBUG: start task:49db91cd-c792-4946-a91c-2fc015efcdbd:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:49db91cd-c792-4946-a91c-2fc015efcdbd:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running a9bd1d8c on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command a9bd1d8c on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command a9bd1d8c on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2413 (Sat Jul 14 04:05:24 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=2413 (Sat Jul 14 04:05:24 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "fbe19d82", "local_conf_timestamp": 2413, "host-ts": 2413}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2406 (Sat Jul 14 04:05:17 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2406 (Sat Jul 14 04:05:17 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "94066a85", "local_conf_timestamp": 2406, "host-ts": 2406}, "global_maintenance": false} lago.ssh: DEBUG: start task:ac48cebc-2a4e-4580-9aee-13bf372d88f5:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:ac48cebc-2a4e-4580-9aee-13bf372d88f5:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running ac15ac20 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command ac15ac20 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command ac15ac20 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2413 (Sat Jul 14 04:05:24 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=2413 (Sat Jul 14 04:05:24 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "fbe19d82", "local_conf_timestamp": 2413, "host-ts": 2413}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2406 (Sat Jul 14 04:05:17 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2406 (Sat Jul 14 04:05:17 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason ovirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f1ba9da3f50> Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 219, in assert_equals_within res = func() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/010_local_mainentance.py", line 35, in <lambda> testlib.assert_true_within_long(lambda: _get_he_status(host) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/010_local_mainentance.py", line 94, 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=2413 (Sat Jul 14 04:05:24 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=2413 (Sat Jul 14 04:05:24 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "fbe19d82", "local_conf_timestamp": 2413, "host-ts": 2413}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2406 (Sat Jul 14 04:05:17 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2406 (Sat Jul 14 04:05:17 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason --------------------- >> 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 129, in wrapped_test test() File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 59, in wrapper return func(get_test_prefix(), *args, **kwargs) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/010_local_mainentance.py", line 118, in local_maintenance _wait_for_engine_migration(host, he_index, "bad", "Migration Destination") File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/010_local_mainentance.py", line 35, 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 271, in assert_true_within_long assert_equals_within_long(func, True, allowed_exceptions) File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 258, in assert_equals_within_long func, value, LONG_TIMEOUT, allowed_exceptions=allowed_exceptions File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 219, in assert_equals_within res = func() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/010_local_mainentance.py", line 35, in <lambda> testlib.assert_true_within_long(lambda: _get_he_status(host) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/010_local_mainentance.py", line 94, 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=2413 (Sat Jul 14 04:05:24 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=2413 (Sat Jul 14 04:05:24 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "fbe19d82", "local_conf_timestamp": 2413, "host-ts": 2413}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2406 (Sat Jul 14 04:05:17 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2406 (Sat Jul 14 04:05:17 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason\n-------------------- >> begin captured logging << --------------------\nlago.ssh: DEBUG: start task:20e58b83-75f8-4b3d-8f26-1c5b014b4eb7:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:20e58b83-75f8-4b3d-8f26-1c5b014b4eb7:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 9d5832ca on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 9d5832ca on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 9d5832ca on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2383 (Sat Jul 14 04:04:53 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=2383 (Sat Jul 14 04:04:54 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "f2c58547", "local_conf_timestamp": 2383, "host-ts": 2383}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2385 (Sat Jul 14 04:04:56 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2385 (Sat Jul 14 04:04:56 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "920e0845", "local_conf_timestamp": 2385, "host-ts": 2385}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:82905888-0e48-4556-aa63-8bf44d0ab81a:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:82905888-0e48-4556-aa63-8bf44d0ab81a:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 9dd5f336 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --set-maintenance --mode=local\nlago.ssh: DEBUG: Command 9dd5f336 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nroot: INFO: * Waiting for engine to migrate...\nlago.ssh: DEBUG: start task:8d6f88dd-96c6-407e-98a2-f970dd23dbde:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:8d6f88dd-96c6-407e-98a2-f970dd23dbde:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 9e567c18 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 9e567c18 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 9e567c18 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2393 (Sat Jul 14 04:05:04 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=2393 (Sat Jul 14 04:05:04 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "a8c95a47", "local_conf_timestamp": 2393, "host-ts": 2393}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2385 (Sat Jul 14 04:04:56 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2385 (Sat Jul 14 04:04:56 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "920e0845", "local_conf_timestamp": 2385, "host-ts": 2385}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:6c85f2c8-fdb8-4ba0-844a-f0f3cea8338d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:6c85f2c8-fdb8-4ba0-844a-f0f3cea8338d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running a5189694 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command a5189694 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command a5189694 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2403 (Sat Jul 14 04:05:13 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=2403 (Sat Jul 14 04:05:14 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "eda598e3", "local_conf_timestamp": 2403, "host-ts": 2403}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2395 (Sat Jul 14 04:05:06 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2396 (Sat Jul 14 04:05:07 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "cd8c1d29", "local_conf_timestamp": 2396, "host-ts": 2395}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:6fef0ac9-ea00-409b-a8e3-53e4a88f8fb9:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:6fef0ac9-ea00-409b-a8e3-53e4a88f8fb9:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running a77272c0 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command a77272c0 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command a77272c0 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2403 (Sat Jul 14 04:05:13 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=2403 (Sat Jul 14 04:05:14 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "eda598e3", "local_conf_timestamp": 2403, "host-ts": 2403}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2395 (Sat Jul 14 04:05:06 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2396 (Sat Jul 14 04:05:07 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "cd8c1d29", "local_conf_timestamp": 2396, "host-ts": 2395}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:49db91cd-c792-4946-a91c-2fc015efcdbd:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:49db91cd-c792-4946-a91c-2fc015efcdbd:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running a9bd1d8c on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command a9bd1d8c on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command a9bd1d8c on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2413 (Sat Jul 14 04:05:24 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=2413 (Sat Jul 14 04:05:24 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "fbe19d82", "local_conf_timestamp": 2413, "host-ts": 2413}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2406 (Sat Jul 14 04:05:17 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2406 (Sat Jul 14 04:05:17 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down_unexpected", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "94066a85", "local_conf_timestamp": 2406, "host-ts": 2406}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:ac48cebc-2a4e-4580-9aee-13bf372d88f5:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:ac48cebc-2a4e-4580-9aee-13bf372d88f5:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running ac15ac20 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command ac15ac20 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command ac15ac20 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2413 (Sat Jul 14 04:05:24 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=2413 (Sat Jul 14 04:05:24 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "fbe19d82", "local_conf_timestamp": 2413, "host-ts": 2413}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2406 (Sat Jul 14 04:05:17 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2406 (Sat Jul 14 04:05:17 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason\novirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f1ba9da3f50>\nTraceback (most recent call last):\n File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 219, in assert_equals_within\n res = func()\n File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/010_local_mainentance.py", line 35, 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-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/010_local_mainentance.py", line 94, 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=2413 (Sat Jul 14 04:05:24 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=2413 (Sat Jul 14 04:05:24 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "fbe19d82", "local_conf_timestamp": 2413, "host-ts": 2413}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2406 (Sat Jul 14 04:05:17 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2406 (Sat Jul 14 04:05:17 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason\n--------------------- >> end captured logging << ---------------------'