[oVirt Jenkins] ovirt-system-tests_he-basic-suite-4.2 - Build # 307 - Failure!

Project: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-4.2/ Build: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-suite-4.2/307/ Build Number: 307 Build Status: Failure Triggered By: Started by timer ------------------------------------- Changes Since Last Success: ------------------------------------- Changes for Build #307 [Gal Ben Haim] upgrade_from_release_suite_master Update pre-reposync [Daniel Belenky] Install python-six during global-setup [Barak Korren] Make mock_runner use curl instead of wget [Barak Korren] Fix proxied configuration for FC27 and FC28 [Daniel Belenky] Move project functions to a shared lib [Daniel Belenky] Utilize stdci_project groovy lib in CQ ----------------- Failed Tests: ----------------- 1 tests failed. FAILED: 008_restart_he_vm.restart_he_vm 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=1959 (Wed Jun 20 06:02:22 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=1960 (Wed Jun 20 06:02:23 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "66b6e371", "local_conf_timestamp": 1960, "host-ts": 1959}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1956 (Wed Jun 20 06:02:18 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1956 (Wed Jun 20 06:02:19 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-1", "host-id": 2, "en -------------------- >> begin captured logging << -------------------- lago.ssh: DEBUG: start task:7fa0b63b-1d82-4f26-b3b0-43a232ee42f2:Get ssh client for lago-he-basic-suite-4-2-host-1: lago.ssh: DEBUG: end task:7fa0b63b-1d82-4f26-b3b0-43a232ee42f2:Get ssh client for lago-he-basic-suite-4-2-host-1: lago.ssh: DEBUG: Running a8297fbc on lago-he-basic-suite-4-2-host-1: hosted-engine --vm-status --json lago.ssh: DEBUG: Command a8297fbc on lago-he-basic-suite-4-2-host-1 returned with 0 lago.ssh: DEBUG: Command a8297fbc on lago-he-basic-suite-4-2-host-1 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1797 (Wed Jun 20 05:59:40 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1797 (Wed Jun 20 05:59:40 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8ca7d5c5", "local_conf_timestamp": 1797, "host-ts": 1797}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1796 (Wed Jun 20 05:59:39 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1797 (Wed Jun 20 05:59:40 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "6e153d34", "local_conf_timestamp": 1797, "host-ts": 1796}, "global_maintenance": true} root: INFO: * Shutting down HE VM on host: lago-he-basic-suite-4-2-host-0 lago.ssh: DEBUG: start task:5a3e26ae-7a8e-4aa7-936d-05bac937aebb:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:5a3e26ae-7a8e-4aa7-936d-05bac937aebb:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running a8b75fd0 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-shutdown lago.ssh: DEBUG: Command a8b75fd0 on lago-he-basic-suite-4-2-host-0 returned with 0 root: INFO: * Command succeeded root: INFO: * Waiting for VM to be down... lago.ssh: DEBUG: start task:8798cb39-f09b-4e2e-bc19-6e4b12083bd5:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:8798cb39-f09b-4e2e-bc19-6e4b12083bd5:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running a9444742 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command a9444742 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command a9444742 on lago-he-basic-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=1797 (Wed Jun 20 05:59:40 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1797 (Wed Jun 20 05:59:40 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8ca7d5c5", "local_conf_timestamp": 1797, "host-ts": 1797}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1796 (Wed Jun 20 05:59:39 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1797 (Wed Jun 20 05:59:40 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "6e153d34", "local_conf_timestamp": 1797, "host-ts": 1796}, "global_maintenance": false} lago.ssh: DEBUG: start task:18301a7b-63cf-479c-a7cd-abc56f300691:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:18301a7b-63cf-479c-a7cd-abc56f300691:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running b00ee8e8 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command b00ee8e8 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command b00ee8e8 on lago-he-basic-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=1807 (Wed Jun 20 05:59:51 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1809 (Wed Jun 20 05:59:52 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "e73d4537", "local_conf_timestamp": 1809, "host-ts": 1807}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1806 (Wed Jun 20 05:59:49 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1806 (Wed Jun 20 05:59:49 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "516e6745", "local_conf_timestamp": 1806, "host-ts": 1806}, "global_maintenance": true} lago.ssh: DEBUG: start task:74ea2f58-62fe-48d7-879f-ccaa247d0b69:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:74ea2f58-62fe-48d7-879f-ccaa247d0b69:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running b276bc8c on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command b276bc8c on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command b276bc8c on lago-he-basic-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=1817 (Wed Jun 20 06:00:00 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=1817 (Wed Jun 20 06:00:01 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Powering down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e573deaf", "local_conf_timestamp": 1817, "host-ts": 1817}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1816 (Wed Jun 20 05:59:58 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1816 (Wed Jun 20 05:59:59 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "43127f80", "local_conf_timestamp": 1816, "host-ts": 1816}, "global_maintenance": true} lago.ssh: DEBUG: start task:eafbaa04-76f1-4346-bbf2-f5154b162e05:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:eafbaa04-76f1-4346-bbf2-f5154b162e05:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running b4c932bc on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command b4c932bc on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command b4c932bc on lago-he-basic-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=1817 (Wed Jun 20 06:00:00 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=1817 (Wed Jun 20 06:00:01 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Powering down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e573deaf", "local_conf_timestamp": 1817, "host-ts": 1817}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1816 (Wed Jun 20 05:59:58 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1816 (Wed Jun 20 05:59:59 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "43127f80", "local_conf_timestamp": 1816, "host-ts": 1816}, "global_maintenance": true} lago.ssh: DEBUG: start task:7e37932e-79d8-4fb1-b018-e509c1be2079:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:7e37932e-79d8-4fb1-b018-e509c1be2079:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running b71e9f16 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command b71e9f16 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command b71e9f16 on lago-he-basic-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=1817 (Wed Jun 20 06:00:00 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=1817 (Wed Jun 20 06:00:01 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Powering down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e573deaf", "local_conf_timestamp": 1817, "host-ts": 1817}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1816 (Wed Jun 20 05:59:58 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1816 (Wed Jun 20 05:59:59 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "43127f80", "local_conf_timestamp": 1816, "host-ts": 1816}, "global_maintenance": true} lago.ssh: DEBUG: start task:6721a1b8-c0be-4589-aa6f-06d4593145d7:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:6721a1b8-c0be-4589-aa6f-06d4593145d7:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running b97a0c64 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command b97a0c64 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command b97a0c64 on lago-he-basic-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=1827 (Wed Jun 20 06:00:10 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1827 (Wed Jun 20 06:00:10 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down_unexpected", "detail": "Down"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "82f1748b", "local_conf_timestamp": 1827, "host-ts": 1827}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1826 (Wed Jun 20 06:00:09 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1827 (Wed Jun 20 06:00:09 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "02916659", "local_conf_timestamp": 1827, "host-ts": 1826}, "global_maintenance": true} root: INFO: * VM is down. root: INFO: * Restarting services... lago.ssh: DEBUG: start task:f277519c-ff1c-4145-b766-1529193f9736:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:f277519c-ff1c-4145-b766-1529193f9736:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running ba107a50 on lago-he-basic-suite-4-2-host-0: systemctl restart vdsmd ovirt-ha-broker ovirt-ha-agent lago.ssh: DEBUG: Command ba107a50 on lago-he-basic-suite-4-2-host-0 returned with 0 root: INFO: * Success. root: INFO: * Waiting for agent to be ready... lago.ssh: DEBUG: start task:4720df71-76bb-44f1-b960-8d29c77e7eeb:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:4720df71-76bb-44f1-b960-8d29c77e7eeb:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running c5a97c9a on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command c5a97c9a on lago-he-basic-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command c5a97c9a on lago-he-basic-suite-4-2-host-0 output: The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable. lago.ssh: DEBUG: start task:31ff44a2-deb7-4f53-af62-ada0d3de7814:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:31ff44a2-deb7-4f53-af62-ada0d3de7814:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running cc151d64 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command cc151d64 on lago-he-basic-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command cc151d64 on lago-he-basic-suite-4-2-host-0 output: The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable. lago.ssh: DEBUG: start task:dafa50c4-5878-45d5-baf2-f29137211116:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:dafa50c4-5878-45d5-baf2-f29137211116:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running ce3e3648 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command ce3e3648 on lago-he-basic-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command ce3e3648 on lago-he-basic-suite-4-2-host-0 output: The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable. lago.ssh: DEBUG: start task:c67b6f95-f884-4671-ab08-58e01a0e0ada:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:c67b6f95-f884-4671-ab08-58e01a0e0ada:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running d082176c on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d082176c on lago-he-basic-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d082176c on lago-he-basic-suite-4-2-host-0 output: The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable. lago.ssh: DEBUG: start task:1a9235d2-a03f-445b-b0c0-bc2e74f552a2:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:1a9235d2-a03f-445b-b0c0-bc2e74f552a2:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running d2aad948 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d2aad948 on lago-he-basic-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d2aad948 on lago-he-basic-suite-4-2-host-0 output: The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable. lago.ssh: DEBUG: start task:6b6ea68c-dd38-4096-a0ac-dd38a55e2688:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:6b6ea68c-dd38-4096-a0ac-dd38a55e2688:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running d4d59258 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d4d59258 on lago-he-basic-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d4d59258 on lago-he-basic-suite-4-2-host-0 output: The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable. lago.ssh: DEBUG: start task:b5a78ba3-a0fa-4cdf-ac2d-f1ebd5340516:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:b5a78ba3-a0fa-4cdf-ac2d-f1ebd5340516:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running d710521a on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d710521a on lago-he-basic-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d710521a on lago-he-basic-suite-4-2-host-0 output: The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable. lago.ssh: DEBUG: start task:d74eb21b-e2d0-48af-95a6-6ae0d9c322b2:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:d74eb21b-e2d0-48af-95a6-6ae0d9c322b2:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running d93d74f0 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d93d74f0 on lago-he-basic-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d93d74f0 on lago-he-basic-suite-4-2-host-0 output: The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable. lago.ssh: DEBUG: start task:d5883737-42de-4bd9-b14c-3aa39c8f2dfd:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:d5883737-42de-4bd9-b14c-3aa39c8f2dfd:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running db7573b2 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command db7573b2 on lago-he-basic-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command db7573b2 on lago-he-basic-suite-4-2-host-0 output: The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable. lago.ssh: DEBUG: start task:695e26b3-2326-47f0-81e6-8ba946e0eab9:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:695e26b3-2326-47f0-81e6-8ba946e0eab9:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running dd92f5b6 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command dd92f5b6 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command dd92f5b6 on lago-he-basic-suite-4-2-host-0 output: !! Cluster is in GLOBAL MAINTENANCE mode !! --== Host 1 status ==-- conf_on_shared_storage : True Status up-to-date : True Hostname : lago-he-basic-suite-4-2-host-0.lago.local Host ID : 1 Engine status : {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Down"} Score : 0 stopped : False Local maintenance : False crc32 : 612645ed local_conf_timestamp : 1889 Host timestamp : 1889 Extra metadata (valid at timestamp): metadata_parse_version=1 metadata_feature_version=1 timestamp=1889 (Wed Jun 20 06:01:12 2018) host-id=1 score=0 vm_conf_refresh_time=1889 (Wed Jun 20 06:01:13 2018) conf_on_shared_storage=True maintenance=False state=ReinitializeFSM stopped=False --== Host 2 status ==-- conf_on_shared_storage : True Status up-to-date : False Hostname : lago-he-basic-suite-4-2-host-1 Host ID : 2 Engine status : unknown stale-data Score : 3400 stopped : False Local maintenance : False crc32 : c28ea16d local_conf_timestamp : 1886 Host timestamp : 1886 Extra metadata (valid at timestamp): metadata_parse_version=1 metadata_feature_version=1 timestamp=1886 (Wed Jun 20 06:01:09 2018) host-id=2 score=3400 vm_conf_refresh_time=1886 (Wed Jun 20 06:01:09 2018) conf_on_shared_storage=True maintenance=False state=GlobalMaintenance stopped=False !! Cluster is in GLOBAL MAINTENANCE mode !! root: INFO: * Agent is ready. root: INFO: * Starting VM... lago.ssh: DEBUG: start task:34e67d6d-becb-4934-b953-d59e64f2a55c:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:34e67d6d-becb-4934-b953-d59e64f2a55c:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running de2286cc on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-start lago.ssh: DEBUG: Command de2286cc on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command de2286cc on lago-he-basic-suite-4-2-host-0 output: VM exists and is down, cleaning up and restarting root: INFO: * Command succeeded root: INFO: * Waiting to VM to be UP... lago.ssh: DEBUG: start task:aa25364d-1a02-4256-82d9-50f4799364b3:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:aa25364d-1a02-4256-82d9-50f4799364b3:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running df8a2718 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command df8a2718 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command df8a2718 on lago-he-basic-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=1889 (Wed Jun 20 06:01:12 2018)\nhost-id=1\nscore=0\nvm_conf_refresh_time=1889 (Wed Jun 20 06:01:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=ReinitializeFSM\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Down"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "612645ed", "local_conf_timestamp": 1889, "host-ts": 1889}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1886 (Wed Jun 20 06:01:09 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1886 (Wed Jun 20 06:01:09 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "c28ea16d", "local_conf_timestamp": 1886, "host-ts": 1886}, "global_maintenance": true} lago.ssh: DEBUG: start task:807fa695-4172-4455-961d-5aab46991388:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:807fa695-4172-4455-961d-5aab46991388:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running e611a3a4 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command e611a3a4 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command e611a3a4 on lago-he-basic-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=1899 (Wed Jun 20 06:01:22 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1899 (Wed Jun 20 06:01:22 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "e627649f", "local_conf_timestamp": 1899, "host-ts": 1899}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1896 (Wed Jun 20 06:01:18 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1896 (Wed Jun 20 06:01:19 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "d0f2b9a8", "local_conf_timestamp": 1896, "host-ts": 1896}, "global_maintenance": true} root: INFO: * VM is UP. root: INFO: * Waiting for engine to start ... lago.ssh: DEBUG: start task:dd69f784-ffa7-437e-8146-4b4550768f6f:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:dd69f784-ffa7-437e-8146-4b4550768f6f:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running e69adf3e on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command e69adf3e on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command e69adf3e on lago-he-basic-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=1899 (Wed Jun 20 06:01:22 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1899 (Wed Jun 20 06:01:22 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "e627649f", "local_conf_timestamp": 1899, "host-ts": 1899}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1896 (Wed Jun 20 06:01:18 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1896 (Wed Jun 20 06:01:19 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "d0f2b9a8", "local_conf_timestamp": 1896, "host-ts": 1896}, "global_maintenance": true} lago.ssh: DEBUG: start task:73996669-0bfe-4f86-a81d-ee17c02c5b7c:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:73996669-0bfe-4f86-a81d-ee17c02c5b7c:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running ed261ac6 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command ed261ac6 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command ed261ac6 on lago-he-basic-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=1909 (Wed Jun 20 06:01:32 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1910 (Wed Jun 20 06:01:33 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "06938df0", "local_conf_timestamp": 1910, "host-ts": 1909}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1906 (Wed Jun 20 06:01:29 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1907 (Wed Jun 20 06:01:29 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "cd751df4", "local_conf_timestamp": 1907, "host-ts": 1906}, "global_maintenance": true} lago.ssh: DEBUG: start task:26e4358e-f727-442a-8fbd-36993514b9d5:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:26e4358e-f727-442a-8fbd-36993514b9d5:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running ef740360 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command ef740360 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command ef740360 on lago-he-basic-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=1919 (Wed Jun 20 06:01:42 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1919 (Wed Jun 20 06:01:42 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "c3b9909b", "local_conf_timestamp": 1919, "host-ts": 1919}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1916 (Wed Jun 20 06:01:39 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1916 (Wed Jun 20 06:01:39 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "a80e35a7", "local_conf_timestamp": 1916, "host-ts": 1916}, "global_maintenance": true} lago.ssh: DEBUG: start task:4a3243ab-6ccd-4be3-a655-8798bab86bb0:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:4a3243ab-6ccd-4be3-a655-8798bab86bb0:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running f1c1b338 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f1c1b338 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command f1c1b338 on lago-he-basic-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=1919 (Wed Jun 20 06:01:42 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1919 (Wed Jun 20 06:01:42 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "c3b9909b", "local_conf_timestamp": 1919, "host-ts": 1919}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1916 (Wed Jun 20 06:01:39 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1916 (Wed Jun 20 06:01:39 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "a80e35a7", "local_conf_timestamp": 1916, "host-ts": 1916}, "global_maintenance": true} lago.ssh: DEBUG: start task:c20f8341-7a76-406e-8282-6017f466986e:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:c20f8341-7a76-406e-8282-6017f466986e:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running f41ee826 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f41ee826 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command f41ee826 on lago-he-basic-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=1919 (Wed Jun 20 06:01:42 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1919 (Wed Jun 20 06:01:42 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "c3b9909b", "local_conf_timestamp": 1919, "host-ts": 1919}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1916 (Wed Jun 20 06:01:39 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1916 (Wed Jun 20 06:01:39 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "a80e35a7", "local_conf_timestamp": 1916, "host-ts": 1916}, "global_maintenance": true} lago.ssh: DEBUG: start task:8c8ce52d-b1eb-4286-9c5a-29d8c463d969:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:8c8ce52d-b1eb-4286-9c5a-29d8c463d969:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running f67bcf08 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f67bcf08 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command f67bcf08 on lago-he-basic-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=1929 (Wed Jun 20 06:01:52 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1930 (Wed Jun 20 06:01:53 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "9639a2ad", "local_conf_timestamp": 1930, "host-ts": 1929}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1926 (Wed Jun 20 06:01:48 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1926 (Wed Jun 20 06:01:49 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "9e8a1ce8", "local_conf_timestamp": 1926, "host-ts": 1926}, "global_maintenance": true} lago.ssh: DEBUG: start task:2c53d7d1-716e-4702-9fe3-d023a0b7f9a5:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:2c53d7d1-716e-4702-9fe3-d023a0b7f9a5:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running f8ebef20 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f8ebef20 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command f8ebef20 on lago-he-basic-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=1929 (Wed Jun 20 06:01:52 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1930 (Wed Jun 20 06:01:53 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "9639a2ad", "local_conf_timestamp": 1930, "host-ts": 1929}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1926 (Wed Jun 20 06:01:48 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1926 (Wed Jun 20 06:01:49 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "9e8a1ce8", "local_conf_timestamp": 1926, "host-ts": 1926}, "global_maintenance": true} lago.ssh: DEBUG: start task:1d686ea2-3f31-4bc9-95b6-5da4b56391b5:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:1d686ea2-3f31-4bc9-95b6-5da4b56391b5:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running fbd6f1e4 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command fbd6f1e4 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command fbd6f1e4 on lago-he-basic-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=1939 (Wed Jun 20 06:02:02 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1940 (Wed Jun 20 06:02:03 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "7feae0c2", "local_conf_timestamp": 1940, "host-ts": 1939}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1936 (Wed Jun 20 06:01:59 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1937 (Wed Jun 20 06:02:00 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "fbf134bb", "local_conf_timestamp": 1937, "host-ts": 1936}, "global_maintenance": true} lago.ssh: DEBUG: start task:ae7e23ab-0f2f-4fff-bab0-9dac5441a270:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:ae7e23ab-0f2f-4fff-bab0-9dac5441a270:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running fe5aeca4 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command fe5aeca4 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command fe5aeca4 on lago-he-basic-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=1939 (Wed Jun 20 06:02:02 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1940 (Wed Jun 20 06:02:03 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "7feae0c2", "local_conf_timestamp": 1940, "host-ts": 1939}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1936 (Wed Jun 20 06:01:59 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1937 (Wed Jun 20 06:02:00 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "fbf134bb", "local_conf_timestamp": 1937, "host-ts": 1936}, "global_maintenance": true} lago.ssh: DEBUG: start task:b2c02eb6-7b73-4b62-92de-7a1ebce44d9b:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:b2c02eb6-7b73-4b62-92de-7a1ebce44d9b:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running 00a5f2ce on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 00a5f2ce on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 00a5f2ce on lago-he-basic-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=1939 (Wed Jun 20 06:02:02 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1940 (Wed Jun 20 06:02:03 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "7feae0c2", "local_conf_timestamp": 1940, "host-ts": 1939}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1936 (Wed Jun 20 06:01:59 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1937 (Wed Jun 20 06:02:00 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "fbf134bb", "local_conf_timestamp": 1937, "host-ts": 1936}, "global_maintenance": true} lago.ssh: DEBUG: start task:4e59618c-2adf-4859-ab52-e3a1fd81bff7:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:4e59618c-2adf-4859-ab52-e3a1fd81bff7:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running 033e46a8 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 033e46a8 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 033e46a8 on lago-he-basic-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=1949 (Wed Jun 20 06:02:12 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1950 (Wed Jun 20 06:02:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "56c40d1f", "local_conf_timestamp": 1950, "host-ts": 1949}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1946 (Wed Jun 20 06:02:09 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1946 (Wed Jun 20 06:02:09 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "f3824e76", "local_conf_timestamp": 1946, "host-ts": 1946}, "global_maintenance": true} lago.ssh: DEBUG: start task:4e06eb5d-93a6-43f2-86b5-aa7486225a68:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:4e06eb5d-93a6-43f2-86b5-aa7486225a68:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running 05830c0a on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 05830c0a on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 05830c0a on lago-he-basic-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=1949 (Wed Jun 20 06:02:12 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=1950 (Wed Jun 20 06:02:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "56c40d1f", "local_conf_timestamp": 1950, "host-ts": 1949}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1946 (Wed Jun 20 06:02:09 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1946 (Wed Jun 20 06:02:09 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "f3824e76", "local_conf_timestamp": 1946, "host-ts": 1946}, "global_maintenance": true} lago.ssh: DEBUG: start task:e0bec1c4-518a-4a4c-b0b5-2f3193d32a7d:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:e0bec1c4-518a-4a4c-b0b5-2f3193d32a7d:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running 07deb7ec on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 07deb7ec on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 07deb7ec on lago-he-basic-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=1959 (Wed Jun 20 06:02:22 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=1960 (Wed Jun 20 06:02:23 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "66b6e371", "local_conf_timestamp": 1960, "host-ts": 1959}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1956 (Wed Jun 20 06:02:18 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1956 (Wed Jun 20 06:02:19 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-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": "e1fe56b3", "local_conf_timestamp": 1956, "host-ts": 1956}, "global_maintenance": true} lago.ssh: DEBUG: start task:8edf7531-89c1-4504-9efc-6c58912e1004:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: end task:8edf7531-89c1-4504-9efc-6c58912e1004:Get ssh client for lago-he-basic-suite-4-2-host-0: lago.ssh: DEBUG: Running 0a321da4 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 0a321da4 on lago-he-basic-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 0a321da4 on lago-he-basic-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=1959 (Wed Jun 20 06:02:22 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=1960 (Wed Jun 20 06:02:23 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "66b6e371", "local_conf_timestamp": 1960, "host-ts": 1959}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1956 (Wed Jun 20 06:02:18 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1956 (Wed Jun 20 06:02:19 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-1", "host-id": 2, "en ovirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f578d303398> 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-suite-4.2/ovirt-system-tests/he-basic-suite-4.2/test-scenarios/008_restart_he_vm.py", line 139, in <lambda> for k, v in _get_he_status(host).items() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-suite-4.2/ovirt-system-tests/he-basic-suite-4.2/test-scenarios/008_restart_he_vm.py", line 83, 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=1959 (Wed Jun 20 06:02:22 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=1960 (Wed Jun 20 06:02:23 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "66b6e371", "local_conf_timestamp": 1960, "host-ts": 1959}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=1956 (Wed Jun 20 06:02:18 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=1956 (Wed Jun 20 06:02:19 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-suite-4-2-host-1", "host-id": 2, "en --------------------- >> 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-suite-4.2/ovirt-system-tests/he-basic-suite-4.2/test-scenarios/008_restart_he_vm.py", line 47, in restart_he_vm _wait_for_engine_health(host) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-suite-4.2/ovirt-system-tests/he-basic-suite-4.2/test-scenarios/008_restart_he_vm.py", line 137, in _wait_for_engine_health testlib.assert_true_within_long(lambda: any( 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-suite-4.2/ovirt-system-tests/he-basic-suite-4.2/test-scenarios/008_restart_he_vm.py", line 139, in <lambda> for k, v in _get_he_status(host).items() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-suite-4.2/ovirt-system-tests/he-basic-suite-4.2/test-scenarios/008_restart_he_vm.py", line 83, 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=1959 (Wed Jun 20 06:02:22 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=1960 (Wed Jun 20 06:02:23 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "66b6e371", "local_conf_timestamp": 1960, "host-ts": 1959}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1956 (Wed Jun 20 06:02:18 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1956 (Wed Jun 20 06:02:19 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-1", "host-id": 2, "en\n-------------------- >> begin captured logging << --------------------\nlago.ssh: DEBUG: start task:7fa0b63b-1d82-4f26-b3b0-43a232ee42f2:Get ssh client for lago-he-basic-suite-4-2-host-1:\nlago.ssh: DEBUG: end task:7fa0b63b-1d82-4f26-b3b0-43a232ee42f2:Get ssh client for lago-he-basic-suite-4-2-host-1:\nlago.ssh: DEBUG: Running a8297fbc on lago-he-basic-suite-4-2-host-1: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command a8297fbc on lago-he-basic-suite-4-2-host-1 returned with 0\nlago.ssh: DEBUG: Command a8297fbc on lago-he-basic-suite-4-2-host-1 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1797 (Wed Jun 20 05:59:40 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1797 (Wed Jun 20 05:59:40 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8ca7d5c5", "local_conf_timestamp": 1797, "host-ts": 1797}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1796 (Wed Jun 20 05:59:39 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1797 (Wed Jun 20 05:59:40 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "6e153d34", "local_conf_timestamp": 1797, "host-ts": 1796}, "global_maintenance": true}\n\nroot: INFO: * Shutting down HE VM on host: lago-he-basic-suite-4-2-host-0\nlago.ssh: DEBUG: start task:5a3e26ae-7a8e-4aa7-936d-05bac937aebb:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:5a3e26ae-7a8e-4aa7-936d-05bac937aebb:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running a8b75fd0 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-shutdown\nlago.ssh: DEBUG: Command a8b75fd0 on lago-he-basic-suite-4-2-host-0 returned with 0\nroot: INFO: * Command succeeded\nroot: INFO: * Waiting for VM to be down...\nlago.ssh: DEBUG: start task:8798cb39-f09b-4e2e-bc19-6e4b12083bd5:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:8798cb39-f09b-4e2e-bc19-6e4b12083bd5:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running a9444742 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command a9444742 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command a9444742 on lago-he-basic-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=1797 (Wed Jun 20 05:59:40 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1797 (Wed Jun 20 05:59:40 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8ca7d5c5", "local_conf_timestamp": 1797, "host-ts": 1797}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1796 (Wed Jun 20 05:59:39 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1797 (Wed Jun 20 05:59:40 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "6e153d34", "local_conf_timestamp": 1797, "host-ts": 1796}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:18301a7b-63cf-479c-a7cd-abc56f300691:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:18301a7b-63cf-479c-a7cd-abc56f300691:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running b00ee8e8 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command b00ee8e8 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command b00ee8e8 on lago-he-basic-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=1807 (Wed Jun 20 05:59:51 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1809 (Wed Jun 20 05:59:52 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "e73d4537", "local_conf_timestamp": 1809, "host-ts": 1807}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1806 (Wed Jun 20 05:59:49 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1806 (Wed Jun 20 05:59:49 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "516e6745", "local_conf_timestamp": 1806, "host-ts": 1806}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:74ea2f58-62fe-48d7-879f-ccaa247d0b69:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:74ea2f58-62fe-48d7-879f-ccaa247d0b69:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running b276bc8c on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command b276bc8c on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command b276bc8c on lago-he-basic-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=1817 (Wed Jun 20 06:00:00 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=1817 (Wed Jun 20 06:00:01 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Powering down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e573deaf", "local_conf_timestamp": 1817, "host-ts": 1817}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1816 (Wed Jun 20 05:59:58 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1816 (Wed Jun 20 05:59:59 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "43127f80", "local_conf_timestamp": 1816, "host-ts": 1816}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:eafbaa04-76f1-4346-bbf2-f5154b162e05:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:eafbaa04-76f1-4346-bbf2-f5154b162e05:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running b4c932bc on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command b4c932bc on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command b4c932bc on lago-he-basic-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=1817 (Wed Jun 20 06:00:00 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=1817 (Wed Jun 20 06:00:01 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Powering down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e573deaf", "local_conf_timestamp": 1817, "host-ts": 1817}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1816 (Wed Jun 20 05:59:58 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1816 (Wed Jun 20 05:59:59 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "43127f80", "local_conf_timestamp": 1816, "host-ts": 1816}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:7e37932e-79d8-4fb1-b018-e509c1be2079:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:7e37932e-79d8-4fb1-b018-e509c1be2079:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running b71e9f16 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command b71e9f16 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command b71e9f16 on lago-he-basic-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=1817 (Wed Jun 20 06:00:00 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=1817 (Wed Jun 20 06:00:01 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Powering down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e573deaf", "local_conf_timestamp": 1817, "host-ts": 1817}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1816 (Wed Jun 20 05:59:58 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1816 (Wed Jun 20 05:59:59 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "43127f80", "local_conf_timestamp": 1816, "host-ts": 1816}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:6721a1b8-c0be-4589-aa6f-06d4593145d7:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:6721a1b8-c0be-4589-aa6f-06d4593145d7:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running b97a0c64 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command b97a0c64 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command b97a0c64 on lago-he-basic-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=1827 (Wed Jun 20 06:00:10 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1827 (Wed Jun 20 06:00:10 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down_unexpected", "detail": "Down"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "82f1748b", "local_conf_timestamp": 1827, "host-ts": 1827}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1826 (Wed Jun 20 06:00:09 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1827 (Wed Jun 20 06:00:09 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "02916659", "local_conf_timestamp": 1827, "host-ts": 1826}, "global_maintenance": true}\n\nroot: INFO: * VM is down.\nroot: INFO: * Restarting services...\nlago.ssh: DEBUG: start task:f277519c-ff1c-4145-b766-1529193f9736:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:f277519c-ff1c-4145-b766-1529193f9736:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running ba107a50 on lago-he-basic-suite-4-2-host-0: systemctl restart vdsmd ovirt-ha-broker ovirt-ha-agent\nlago.ssh: DEBUG: Command ba107a50 on lago-he-basic-suite-4-2-host-0 returned with 0\nroot: INFO: * Success.\nroot: INFO: * Waiting for agent to be ready...\nlago.ssh: DEBUG: start task:4720df71-76bb-44f1-b960-8d29c77e7eeb:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:4720df71-76bb-44f1-b960-8d29c77e7eeb:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running c5a97c9a on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command c5a97c9a on lago-he-basic-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command c5a97c9a on lago-he-basic-suite-4-2-host-0 output:\n The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable.\n\nlago.ssh: DEBUG: start task:31ff44a2-deb7-4f53-af62-ada0d3de7814:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:31ff44a2-deb7-4f53-af62-ada0d3de7814:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running cc151d64 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command cc151d64 on lago-he-basic-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command cc151d64 on lago-he-basic-suite-4-2-host-0 output:\n The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable.\n\nlago.ssh: DEBUG: start task:dafa50c4-5878-45d5-baf2-f29137211116:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:dafa50c4-5878-45d5-baf2-f29137211116:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running ce3e3648 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command ce3e3648 on lago-he-basic-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command ce3e3648 on lago-he-basic-suite-4-2-host-0 output:\n The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable.\n\nlago.ssh: DEBUG: start task:c67b6f95-f884-4671-ab08-58e01a0e0ada:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:c67b6f95-f884-4671-ab08-58e01a0e0ada:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d082176c on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d082176c on lago-he-basic-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d082176c on lago-he-basic-suite-4-2-host-0 output:\n The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable.\n\nlago.ssh: DEBUG: start task:1a9235d2-a03f-445b-b0c0-bc2e74f552a2:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:1a9235d2-a03f-445b-b0c0-bc2e74f552a2:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d2aad948 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d2aad948 on lago-he-basic-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d2aad948 on lago-he-basic-suite-4-2-host-0 output:\n The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable.\n\nlago.ssh: DEBUG: start task:6b6ea68c-dd38-4096-a0ac-dd38a55e2688:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:6b6ea68c-dd38-4096-a0ac-dd38a55e2688:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d4d59258 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d4d59258 on lago-he-basic-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d4d59258 on lago-he-basic-suite-4-2-host-0 output:\n The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable.\n\nlago.ssh: DEBUG: start task:b5a78ba3-a0fa-4cdf-ac2d-f1ebd5340516:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:b5a78ba3-a0fa-4cdf-ac2d-f1ebd5340516:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d710521a on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d710521a on lago-he-basic-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d710521a on lago-he-basic-suite-4-2-host-0 output:\n The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable.\n\nlago.ssh: DEBUG: start task:d74eb21b-e2d0-48af-95a6-6ae0d9c322b2:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:d74eb21b-e2d0-48af-95a6-6ae0d9c322b2:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d93d74f0 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d93d74f0 on lago-he-basic-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d93d74f0 on lago-he-basic-suite-4-2-host-0 output:\n The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable.\n\nlago.ssh: DEBUG: start task:d5883737-42de-4bd9-b14c-3aa39c8f2dfd:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:d5883737-42de-4bd9-b14c-3aa39c8f2dfd:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running db7573b2 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command db7573b2 on lago-he-basic-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command db7573b2 on lago-he-basic-suite-4-2-host-0 output:\n The hosted engine configuration has not been retrieved from shared storage. Please ensure that ovirt-ha-agent is running and the storage server is reachable.\n\nlago.ssh: DEBUG: start task:695e26b3-2326-47f0-81e6-8ba946e0eab9:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:695e26b3-2326-47f0-81e6-8ba946e0eab9:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running dd92f5b6 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command dd92f5b6 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command dd92f5b6 on lago-he-basic-suite-4-2-host-0 output:\n \n\n!! Cluster is in GLOBAL MAINTENANCE mode !!\n\n\n\n--== Host 1 status ==--\n\nconf_on_shared_storage : True\nStatus up-to-date : True\nHostname : lago-he-basic-suite-4-2-host-0.lago.local\nHost ID : 1\nEngine status : {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Down"}\nScore : 0\nstopped : False\nLocal maintenance : False\ncrc32 : 612645ed\nlocal_conf_timestamp : 1889\nHost timestamp : 1889\nExtra metadata (valid at timestamp):\n\tmetadata_parse_version=1\n\tmetadata_feature_version=1\n\ttimestamp=1889 (Wed Jun 20 06:01:12 2018)\n\thost-id=1\n\tscore=0\n\tvm_conf_refresh_time=1889 (Wed Jun 20 06:01:13 2018)\n\tconf_on_shared_storage=True\n\tmaintenance=False\n\tstate=ReinitializeFSM\n\tstopped=False\n\n\n--== Host 2 status ==--\n\nconf_on_shared_storage : True\nStatus up-to-date : False\nHostname : lago-he-basic-suite-4-2-host-1\nHost ID : 2\nEngine status : unknown stale-data\nScore : 3400\nstopped : False\nLocal maintenance : False\ncrc32 : c28ea16d\nlocal_conf_timestamp : 1886\nHost timestamp : 1886\nExtra metadata (valid at timestamp):\n\tmetadata_parse_version=1\n\tmetadata_feature_version=1\n\ttimestamp=1886 (Wed Jun 20 06:01:09 2018)\n\thost-id=2\n\tscore=3400\n\tvm_conf_refresh_time=1886 (Wed Jun 20 06:01:09 2018)\n\tconf_on_shared_storage=True\n\tmaintenance=False\n\tstate=GlobalMaintenance\n\tstopped=False\n\n\n!! Cluster is in GLOBAL MAINTENANCE mode !!\n\n\nroot: INFO: * Agent is ready.\nroot: INFO: * Starting VM...\nlago.ssh: DEBUG: start task:34e67d6d-becb-4934-b953-d59e64f2a55c:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:34e67d6d-becb-4934-b953-d59e64f2a55c:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running de2286cc on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-start\nlago.ssh: DEBUG: Command de2286cc on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command de2286cc on lago-he-basic-suite-4-2-host-0 output:\n VM exists and is down, cleaning up and restarting\n\nroot: INFO: * Command succeeded\nroot: INFO: * Waiting to VM to be UP...\nlago.ssh: DEBUG: start task:aa25364d-1a02-4256-82d9-50f4799364b3:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:aa25364d-1a02-4256-82d9-50f4799364b3:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running df8a2718 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command df8a2718 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command df8a2718 on lago-he-basic-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=1889 (Wed Jun 20 06:01:12 2018)\\nhost-id=1\\nscore=0\\nvm_conf_refresh_time=1889 (Wed Jun 20 06:01:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=ReinitializeFSM\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Down"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "612645ed", "local_conf_timestamp": 1889, "host-ts": 1889}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1886 (Wed Jun 20 06:01:09 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1886 (Wed Jun 20 06:01:09 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "c28ea16d", "local_conf_timestamp": 1886, "host-ts": 1886}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:807fa695-4172-4455-961d-5aab46991388:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:807fa695-4172-4455-961d-5aab46991388:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running e611a3a4 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command e611a3a4 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command e611a3a4 on lago-he-basic-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=1899 (Wed Jun 20 06:01:22 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1899 (Wed Jun 20 06:01:22 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "e627649f", "local_conf_timestamp": 1899, "host-ts": 1899}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1896 (Wed Jun 20 06:01:18 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1896 (Wed Jun 20 06:01:19 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "d0f2b9a8", "local_conf_timestamp": 1896, "host-ts": 1896}, "global_maintenance": true}\n\nroot: INFO: * VM is UP.\nroot: INFO: * Waiting for engine to start ...\nlago.ssh: DEBUG: start task:dd69f784-ffa7-437e-8146-4b4550768f6f:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:dd69f784-ffa7-437e-8146-4b4550768f6f:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running e69adf3e on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command e69adf3e on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command e69adf3e on lago-he-basic-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=1899 (Wed Jun 20 06:01:22 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1899 (Wed Jun 20 06:01:22 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "e627649f", "local_conf_timestamp": 1899, "host-ts": 1899}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1896 (Wed Jun 20 06:01:18 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1896 (Wed Jun 20 06:01:19 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "d0f2b9a8", "local_conf_timestamp": 1896, "host-ts": 1896}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:73996669-0bfe-4f86-a81d-ee17c02c5b7c:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:73996669-0bfe-4f86-a81d-ee17c02c5b7c:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running ed261ac6 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command ed261ac6 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command ed261ac6 on lago-he-basic-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=1909 (Wed Jun 20 06:01:32 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1910 (Wed Jun 20 06:01:33 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "06938df0", "local_conf_timestamp": 1910, "host-ts": 1909}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1906 (Wed Jun 20 06:01:29 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1907 (Wed Jun 20 06:01:29 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "cd751df4", "local_conf_timestamp": 1907, "host-ts": 1906}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:26e4358e-f727-442a-8fbd-36993514b9d5:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:26e4358e-f727-442a-8fbd-36993514b9d5:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running ef740360 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command ef740360 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command ef740360 on lago-he-basic-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=1919 (Wed Jun 20 06:01:42 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1919 (Wed Jun 20 06:01:42 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "c3b9909b", "local_conf_timestamp": 1919, "host-ts": 1919}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1916 (Wed Jun 20 06:01:39 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1916 (Wed Jun 20 06:01:39 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "a80e35a7", "local_conf_timestamp": 1916, "host-ts": 1916}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:4a3243ab-6ccd-4be3-a655-8798bab86bb0:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:4a3243ab-6ccd-4be3-a655-8798bab86bb0:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running f1c1b338 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f1c1b338 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command f1c1b338 on lago-he-basic-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=1919 (Wed Jun 20 06:01:42 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1919 (Wed Jun 20 06:01:42 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "c3b9909b", "local_conf_timestamp": 1919, "host-ts": 1919}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1916 (Wed Jun 20 06:01:39 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1916 (Wed Jun 20 06:01:39 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "a80e35a7", "local_conf_timestamp": 1916, "host-ts": 1916}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:c20f8341-7a76-406e-8282-6017f466986e:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:c20f8341-7a76-406e-8282-6017f466986e:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running f41ee826 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f41ee826 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command f41ee826 on lago-he-basic-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=1919 (Wed Jun 20 06:01:42 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1919 (Wed Jun 20 06:01:42 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "c3b9909b", "local_conf_timestamp": 1919, "host-ts": 1919}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1916 (Wed Jun 20 06:01:39 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1916 (Wed Jun 20 06:01:39 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "a80e35a7", "local_conf_timestamp": 1916, "host-ts": 1916}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:8c8ce52d-b1eb-4286-9c5a-29d8c463d969:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:8c8ce52d-b1eb-4286-9c5a-29d8c463d969:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running f67bcf08 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f67bcf08 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command f67bcf08 on lago-he-basic-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=1929 (Wed Jun 20 06:01:52 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1930 (Wed Jun 20 06:01:53 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "9639a2ad", "local_conf_timestamp": 1930, "host-ts": 1929}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1926 (Wed Jun 20 06:01:48 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1926 (Wed Jun 20 06:01:49 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "9e8a1ce8", "local_conf_timestamp": 1926, "host-ts": 1926}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:2c53d7d1-716e-4702-9fe3-d023a0b7f9a5:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:2c53d7d1-716e-4702-9fe3-d023a0b7f9a5:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running f8ebef20 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f8ebef20 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command f8ebef20 on lago-he-basic-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=1929 (Wed Jun 20 06:01:52 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1930 (Wed Jun 20 06:01:53 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "9639a2ad", "local_conf_timestamp": 1930, "host-ts": 1929}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1926 (Wed Jun 20 06:01:48 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1926 (Wed Jun 20 06:01:49 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "9e8a1ce8", "local_conf_timestamp": 1926, "host-ts": 1926}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:1d686ea2-3f31-4bc9-95b6-5da4b56391b5:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:1d686ea2-3f31-4bc9-95b6-5da4b56391b5:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running fbd6f1e4 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command fbd6f1e4 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command fbd6f1e4 on lago-he-basic-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=1939 (Wed Jun 20 06:02:02 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1940 (Wed Jun 20 06:02:03 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "7feae0c2", "local_conf_timestamp": 1940, "host-ts": 1939}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1936 (Wed Jun 20 06:01:59 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1937 (Wed Jun 20 06:02:00 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "fbf134bb", "local_conf_timestamp": 1937, "host-ts": 1936}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:ae7e23ab-0f2f-4fff-bab0-9dac5441a270:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:ae7e23ab-0f2f-4fff-bab0-9dac5441a270:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running fe5aeca4 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command fe5aeca4 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command fe5aeca4 on lago-he-basic-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=1939 (Wed Jun 20 06:02:02 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1940 (Wed Jun 20 06:02:03 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "7feae0c2", "local_conf_timestamp": 1940, "host-ts": 1939}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1936 (Wed Jun 20 06:01:59 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1937 (Wed Jun 20 06:02:00 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "fbf134bb", "local_conf_timestamp": 1937, "host-ts": 1936}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:b2c02eb6-7b73-4b62-92de-7a1ebce44d9b:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:b2c02eb6-7b73-4b62-92de-7a1ebce44d9b:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 00a5f2ce on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 00a5f2ce on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 00a5f2ce on lago-he-basic-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=1939 (Wed Jun 20 06:02:02 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1940 (Wed Jun 20 06:02:03 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "7feae0c2", "local_conf_timestamp": 1940, "host-ts": 1939}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1936 (Wed Jun 20 06:01:59 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1937 (Wed Jun 20 06:02:00 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "fbf134bb", "local_conf_timestamp": 1937, "host-ts": 1936}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:4e59618c-2adf-4859-ab52-e3a1fd81bff7:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:4e59618c-2adf-4859-ab52-e3a1fd81bff7:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 033e46a8 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 033e46a8 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 033e46a8 on lago-he-basic-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=1949 (Wed Jun 20 06:02:12 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1950 (Wed Jun 20 06:02:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "56c40d1f", "local_conf_timestamp": 1950, "host-ts": 1949}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1946 (Wed Jun 20 06:02:09 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1946 (Wed Jun 20 06:02:09 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "f3824e76", "local_conf_timestamp": 1946, "host-ts": 1946}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:4e06eb5d-93a6-43f2-86b5-aa7486225a68:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:4e06eb5d-93a6-43f2-86b5-aa7486225a68:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 05830c0a on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 05830c0a on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 05830c0a on lago-he-basic-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=1949 (Wed Jun 20 06:02:12 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=1950 (Wed Jun 20 06:02:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "56c40d1f", "local_conf_timestamp": 1950, "host-ts": 1949}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1946 (Wed Jun 20 06:02:09 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1946 (Wed Jun 20 06:02:09 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "f3824e76", "local_conf_timestamp": 1946, "host-ts": 1946}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:e0bec1c4-518a-4a4c-b0b5-2f3193d32a7d:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:e0bec1c4-518a-4a4c-b0b5-2f3193d32a7d:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 07deb7ec on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 07deb7ec on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 07deb7ec on lago-he-basic-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=1959 (Wed Jun 20 06:02:22 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=1960 (Wed Jun 20 06:02:23 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "66b6e371", "local_conf_timestamp": 1960, "host-ts": 1959}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1956 (Wed Jun 20 06:02:18 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1956 (Wed Jun 20 06:02:19 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-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": "e1fe56b3", "local_conf_timestamp": 1956, "host-ts": 1956}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:8edf7531-89c1-4504-9efc-6c58912e1004:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:8edf7531-89c1-4504-9efc-6c58912e1004:Get ssh client for lago-he-basic-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 0a321da4 on lago-he-basic-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 0a321da4 on lago-he-basic-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 0a321da4 on lago-he-basic-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=1959 (Wed Jun 20 06:02:22 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=1960 (Wed Jun 20 06:02:23 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "66b6e371", "local_conf_timestamp": 1960, "host-ts": 1959}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1956 (Wed Jun 20 06:02:18 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1956 (Wed Jun 20 06:02:19 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-1", "host-id": 2, "en\novirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f578d303398>\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-suite-4.2/ovirt-system-tests/he-basic-suite-4.2/test-scenarios/008_restart_he_vm.py", line 139, in <lambda>\n for k, v in _get_he_status(host).items()\n File "/home/jenkins/workspace/ovirt-system-tests_he-basic-suite-4.2/ovirt-system-tests/he-basic-suite-4.2/test-scenarios/008_restart_he_vm.py", line 83, 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=1959 (Wed Jun 20 06:02:22 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=1960 (Wed Jun 20 06:02:23 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"reason": "failed liveliness check", "health": "bad", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "66b6e371", "local_conf_timestamp": 1960, "host-ts": 1959}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=1956 (Wed Jun 20 06:02:18 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=1956 (Wed Jun 20 06:02:19 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-suite-4-2-host-1", "host-id": 2, "en\n--------------------- >> end captured logging << ---------------------'