Project: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-ansible-suite-4.2/ Build: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-ansible-suite-4.... Build Number: 730 Build Status: Failure Triggered By: Started by timer ------------------------------------- Changes Since Last Success: ------------------------------------- Changes for Build #730 [Roy Golan] Add README to openshift-on-ovirt suite ----------------- 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=2675 (Thu Nov 8 03:19:13 2018)\nhost-id=1\nscore=3111\nvm_conf_refresh_time=2675 (Thu Nov 8 03:19:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "be3d40a1", "local_conf_timestamp": 2675, "host-ts": 2675}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2673 (Thu Nov 8 03:19:12 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2673 (Thu Nov 8 03:19:12 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2 -------------------- >> begin captured logging << -------------------- lago.ssh: DEBUG: start task:053eb136-48b1-45d4-a8b7-1b6f74536f40:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:053eb136-48b1-45d4-a8b7-1b6f74536f40:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running b6cf4628 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command b6cf4628 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command b6cf4628 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2555 (Thu Nov 8 03:17:13 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=2555 (Thu Nov 8 03:17:14 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "91a2a003", "local_conf_timestamp": 2555, "host-ts": 2555}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2553 (Thu Nov 8 03:17:12 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2553 (Thu Nov 8 03:17:12 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "a7e651e6", "local_conf_timestamp": 2553, "host-ts": 2553}, "global_maintenance": true} root: INFO: * Shutting down HE VM on host: lago-he-basic-ansible-suite-4-2-host-0 lago.ssh: DEBUG: start task:48e52f8d-78cd-4c3e-9bdb-f862ac50a1e5:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:48e52f8d-78cd-4c3e-9bdb-f862ac50a1e5:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running b7683c5c on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-shutdown lago.ssh: DEBUG: Command b7683c5c on lago-he-basic-ansible-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:b8b1cea3-0cce-43d1-8872-84dc6282c96d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:b8b1cea3-0cce-43d1-8872-84dc6282c96d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running b83d8ef2 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command b83d8ef2 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command b83d8ef2 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2555 (Thu Nov 8 03:17:13 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=2555 (Thu Nov 8 03:17:14 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "91a2a003", "local_conf_timestamp": 2555, "host-ts": 2555}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2553 (Thu Nov 8 03:17:12 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2553 (Thu Nov 8 03:17:12 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "a7e651e6", "local_conf_timestamp": 2553, "host-ts": 2553}, "global_maintenance": true} lago.ssh: DEBUG: start task:e6d043c5-156b-4288-a7a3-f24161654e22:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:e6d043c5-156b-4288-a7a3-f24161654e22:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running bed30274 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command bed30274 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command bed30274 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2575 (Thu Nov 8 03:17:33 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=2575 (Thu Nov 8 03:17:33 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down_unexpected", "detail": "Down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "73a2b866", "local_conf_timestamp": 2575, "host-ts": 2575}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2573 (Thu Nov 8 03:17:31 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2573 (Thu Nov 8 03:17:32 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "904ac61d", "local_conf_timestamp": 2573, "host-ts": 2573}, "global_maintenance": true} root: INFO: * VM is down. root: INFO: * Stopping services... lago.ssh: DEBUG: start task:4d492e84-b98f-410a-9186-9da4ad96953b:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:4d492e84-b98f-410a-9186-9da4ad96953b:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running bf583408 on lago-he-basic-ansible-suite-4-2-host-0: systemctl stop vdsmd ovirt-ha-broker ovirt-ha-agent lago.ssh: DEBUG: Command bf583408 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 root: INFO: * Starting services... lago.ssh: DEBUG: start task:570131db-44f3-4f33-9b1c-1ca470f7db23:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:570131db-44f3-4f33-9b1c-1ca470f7db23:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running c7ea8f58 on lago-he-basic-ansible-suite-4-2-host-0: systemctl start vdsmd ovirt-ha-broker ovirt-ha-agent lago.ssh: DEBUG: Command c7ea8f58 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 root: INFO: * Waiting for agent to be ready... lago.ssh: DEBUG: start task:15866098-59b0-4b3e-aca7-9f87b0faaa09:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:15866098-59b0-4b3e-aca7-9f87b0faaa09:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running ca1f0a7e on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command ca1f0a7e on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command ca1f0a7e on lago-he-basic-ansible-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:9d69a85b-cf95-4cd5-acf7-849b3eef94ae:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:9d69a85b-cf95-4cd5-acf7-849b3eef94ae:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running d06eaa7e on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d06eaa7e on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d06eaa7e on lago-he-basic-ansible-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:f122fda8-a80e-420d-8427-bd667eaf09c3:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:f122fda8-a80e-420d-8427-bd667eaf09c3:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running d2bcad8a on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d2bcad8a on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d2bcad8a on lago-he-basic-ansible-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:4f32a250-ab55-46c5-b228-a5ec3477a39c:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:4f32a250-ab55-46c5-b228-a5ec3477a39c:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running d4e22d24 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d4e22d24 on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d4e22d24 on lago-he-basic-ansible-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:fa589610-73ae-4944-9b08-cfcc0c7a3256:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:fa589610-73ae-4944-9b08-cfcc0c7a3256:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running d708a61e on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d708a61e on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d708a61e on lago-he-basic-ansible-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:31625e1e-23bb-43b9-9ab7-910a7dafc5ed:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:31625e1e-23bb-43b9-9ab7-910a7dafc5ed:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running d93645ae on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command d93645ae on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command d93645ae on lago-he-basic-ansible-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:6077407c-ae81-4203-bfe4-007bae8817fb:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:6077407c-ae81-4203-bfe4-007bae8817fb:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running db5f2030 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command db5f2030 on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command db5f2030 on lago-he-basic-ansible-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:77846988-89e4-45f0-8aba-cacb985bf1b9:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:77846988-89e4-45f0-8aba-cacb985bf1b9:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running dd889382 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command dd889382 on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command dd889382 on lago-he-basic-ansible-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:f1925127-d380-43cc-86ea-4f90bcb5b63d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:f1925127-d380-43cc-86ea-4f90bcb5b63d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running dfb22bbe on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command dfb22bbe on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command dfb22bbe on lago-he-basic-ansible-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:4edc99b2-4a65-4147-b24d-56bbc8046b66:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:4edc99b2-4a65-4147-b24d-56bbc8046b66:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running e1d9e5e4 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command e1d9e5e4 on lago-he-basic-ansible-suite-4-2-host-0 returned with 1 lago.ssh: DEBUG: Command e1d9e5e4 on lago-he-basic-ansible-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:70bfaba1-ad03-4f96-918f-1e2793ee7427:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:70bfaba1-ad03-4f96-918f-1e2793ee7427:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running e40a02a4 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status lago.ssh: DEBUG: Command e40a02a4 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command e40a02a4 on lago-he-basic-ansible-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-ansible-suite-4-2-host-0 Host ID : 1 Engine status : {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Down"} Score : 0 stopped : False Local maintenance : False crc32 : 36bd3d62 local_conf_timestamp : 2635 Host timestamp : 2635 Extra metadata (valid at timestamp): metadata_parse_version=1 metadata_feature_version=1 timestamp=2635 (Thu Nov 8 03:18:33 2018) host-id=1 score=0 vm_conf_refresh_time=2635 (Thu Nov 8 03:18:33 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-ansible-suite-4-2-host-1 Host ID : 2 Engine status : unknown stale-data Score : 3400 stopped : False Local maintenance : False crc32 : 2ddfae49 local_conf_timestamp : 2633 Host timestamp : 2633 Extra metadata (valid at timestamp): metadata_parse_version=1 metadata_feature_version=1 timestamp=2633 (Thu Nov 8 03:18:32 2018) host-id=2 score=3400 vm_conf_refresh_time=2633 (Thu Nov 8 03:18:32 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:ff98dc0f-e7fc-4cb8-b035-7af590da59dd:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:ff98dc0f-e7fc-4cb8-b035-7af590da59dd:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running e4911c3a on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-start lago.ssh: DEBUG: Command e4911c3a on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command e4911c3a on lago-he-basic-ansible-suite-4-2-host-0 output: VM exists and is down, cleaning up and restarting root: INFO: * Command succeeded root: INFO: * Waiting for VM to be UP... lago.ssh: DEBUG: start task:acf835ef-f2f1-4150-9e4a-69f3b18687fa:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:acf835ef-f2f1-4150-9e4a-69f3b18687fa:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running e5c3aa46 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command e5c3aa46 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command e5c3aa46 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2635 (Thu Nov 8 03:18:33 2018)\nhost-id=1\nscore=0\nvm_conf_refresh_time=2635 (Thu Nov 8 03:18:33 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=ReinitializeFSM\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Down"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "36bd3d62", "local_conf_timestamp": 2635, "host-ts": 2635}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2633 (Thu Nov 8 03:18:32 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2633 (Thu Nov 8 03:18:32 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "2ddfae49", "local_conf_timestamp": 2633, "host-ts": 2633}, "global_maintenance": true} lago.ssh: DEBUG: start task:eb7dba65-0edb-4c63-9c01-22e619db3e60:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:eb7dba65-0edb-4c63-9c01-22e619db3e60:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running ec372e3e on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command ec372e3e on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command ec372e3e on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2645 (Thu Nov 8 03:18:44 2018)\nhost-id=1\nscore=3111\nvm_conf_refresh_time=2645 (Thu Nov 8 03:18:44 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "0df3ca26", "local_conf_timestamp": 2645, "host-ts": 2645}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2643 (Thu Nov 8 03:18:42 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2643 (Thu Nov 8 03:18:42 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8344de99", "local_conf_timestamp": 2643, "host-ts": 2643}, "global_maintenance": true} root: INFO: * VM is UP. root: INFO: * Waiting for engine to start... lago.ssh: DEBUG: start task:8bf6658f-e1f4-4aa8-a773-b2d92f60e02a:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:8bf6658f-e1f4-4aa8-a773-b2d92f60e02a:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running ecaca8ee on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command ecaca8ee on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command ecaca8ee on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2645 (Thu Nov 8 03:18:44 2018)\nhost-id=1\nscore=3111\nvm_conf_refresh_time=2645 (Thu Nov 8 03:18:44 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "0df3ca26", "local_conf_timestamp": 2645, "host-ts": 2645}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2643 (Thu Nov 8 03:18:42 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2643 (Thu Nov 8 03:18:42 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8344de99", "local_conf_timestamp": 2643, "host-ts": 2643}, "global_maintenance": true} lago.ssh: DEBUG: start task:71c5108d-271c-4aad-8aec-0a8b7337f359:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:71c5108d-271c-4aad-8aec-0a8b7337f359:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running f330d5aa on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f330d5aa on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command f330d5aa on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2655 (Thu Nov 8 03:18:54 2018)\nhost-id=1\nscore=3111\nvm_conf_refresh_time=2656 (Thu Nov 8 03:18:54 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "4c901fde", "local_conf_timestamp": 2656, "host-ts": 2655}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2653 (Thu Nov 8 03:18:51 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2653 (Thu Nov 8 03:18:52 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "752a1644", "local_conf_timestamp": 2653, "host-ts": 2653}, "global_maintenance": true} lago.ssh: DEBUG: start task:e68357ea-ea52-44f4-b67e-e22f47d6a2ac:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:e68357ea-ea52-44f4-b67e-e22f47d6a2ac:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running f5a2235c on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f5a2235c on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command f5a2235c on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2665 (Thu Nov 8 03:19:03 2018)\nhost-id=1\nscore=3111\nvm_conf_refresh_time=2665 (Thu Nov 8 03:19:03 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "6657c4e3", "local_conf_timestamp": 2665, "host-ts": 2665}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2663 (Thu Nov 8 03:19:02 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2663 (Thu Nov 8 03:19:02 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "b4e84962", "local_conf_timestamp": 2663, "host-ts": 2663}, "global_maintenance": true} lago.ssh: DEBUG: start task:436dfa11-97d6-4095-804e-566329a5fdee:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:436dfa11-97d6-4095-804e-566329a5fdee:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running f7ff723a on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command f7ff723a on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command f7ff723a on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2665 (Thu Nov 8 03:19:03 2018)\nhost-id=1\nscore=3111\nvm_conf_refresh_time=2665 (Thu Nov 8 03:19:03 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "6657c4e3", "local_conf_timestamp": 2665, "host-ts": 2665}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2663 (Thu Nov 8 03:19:02 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2663 (Thu Nov 8 03:19:02 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "b4e84962", "local_conf_timestamp": 2663, "host-ts": 2663}, "global_maintenance": true} lago.ssh: DEBUG: start task:de0e96fe-575e-4a46-82f8-4e3d5a85ca1f:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:de0e96fe-575e-4a46-82f8-4e3d5a85ca1f:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running fa442a36 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command fa442a36 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command fa442a36 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2675 (Thu Nov 8 03:19:13 2018)\nhost-id=1\nscore=3111\nvm_conf_refresh_time=2675 (Thu Nov 8 03:19:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "be3d40a1", "local_conf_timestamp": 2675, "host-ts": 2675}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2673 (Thu Nov 8 03:19:12 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2673 (Thu Nov 8 03:19:12 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "428681bf", "local_conf_timestamp": 2673, "host-ts": 2673}, "global_maintenance": true} lago.ssh: DEBUG: start task:97f350dc-f503-4726-84cb-61ad3b8166bc:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: end task:97f350dc-f503-4726-84cb-61ad3b8166bc:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0: lago.ssh: DEBUG: Running fc9a48b0 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command fc9a48b0 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command fc9a48b0 on lago-he-basic-ansible-suite-4-2-host-0 output: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2675 (Thu Nov 8 03:19:13 2018)\nhost-id=1\nscore=3111\nvm_conf_refresh_time=2675 (Thu Nov 8 03:19:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "be3d40a1", "local_conf_timestamp": 2675, "host-ts": 2675}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2673 (Thu Nov 8 03:19:12 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2673 (Thu Nov 8 03:19:12 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2 ovirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f1389d43e60> Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 234, in assert_equals_within res = func() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/008_restart_he_vm.py", line 187, in <lambda> for k, v in _get_he_status(host).items() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/008_restart_he_vm.py", line 128, in _get_he_status raise RuntimeError('could not parse JSON: %s' % ret.out) RuntimeError: could not parse JSON: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2675 (Thu Nov 8 03:19:13 2018)\nhost-id=1\nscore=3111\nvm_conf_refresh_time=2675 (Thu Nov 8 03:19:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "be3d40a1", "local_conf_timestamp": 2675, "host-ts": 2675}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=2673 (Thu Nov 8 03:19:12 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=2673 (Thu Nov 8 03:19:12 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2 --------------------- >> end captured logging << --------------------- Stack Trace: File "/usr/lib64/python2.7/unittest/case.py", line 369, in run testMethod() File "/usr/lib/python2.7/site-packages/nose/case.py", line 197, in runTest self.test(*self.arg) File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 142, in wrapped_test test() File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 60, in wrapper return func(get_test_prefix(), *args, **kwargs) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/008_restart_he_vm.py", line 53, in restart_he_vm _wait_for_engine_health(host) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/008_restart_he_vm.py", line 185, in _wait_for_engine_health testlib.assert_true_within_long(lambda: any( File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 286, in assert_true_within_long assert_equals_within_long(func, True, allowed_exceptions) File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 273, in assert_equals_within_long func, value, LONG_TIMEOUT, allowed_exceptions=allowed_exceptions File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 234, in assert_equals_within res = func() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/008_restart_he_vm.py", line 187, in <lambda> for k, v in _get_he_status(host).items() File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/008_restart_he_vm.py", line 128, in _get_he_status raise RuntimeError('could not parse JSON: %s' % ret.out) 'could not parse JSON: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2675 (Thu Nov 8 03:19:13 2018)\\nhost-id=1\\nscore=3111\\nvm_conf_refresh_time=2675 (Thu Nov 8 03:19:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "be3d40a1", "local_conf_timestamp": 2675, "host-ts": 2675}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2673 (Thu Nov 8 03:19:12 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2673 (Thu Nov 8 03:19:12 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2\n-------------------- >> begin captured logging << --------------------\nlago.ssh: DEBUG: start task:053eb136-48b1-45d4-a8b7-1b6f74536f40:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:053eb136-48b1-45d4-a8b7-1b6f74536f40:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running b6cf4628 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command b6cf4628 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command b6cf4628 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2555 (Thu Nov 8 03:17:13 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=2555 (Thu Nov 8 03:17:14 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "91a2a003", "local_conf_timestamp": 2555, "host-ts": 2555}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2553 (Thu Nov 8 03:17:12 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2553 (Thu Nov 8 03:17:12 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "a7e651e6", "local_conf_timestamp": 2553, "host-ts": 2553}, "global_maintenance": true}\n\nroot: INFO: * Shutting down HE VM on host: lago-he-basic-ansible-suite-4-2-host-0\nlago.ssh: DEBUG: start task:48e52f8d-78cd-4c3e-9bdb-f862ac50a1e5:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:48e52f8d-78cd-4c3e-9bdb-f862ac50a1e5:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running b7683c5c on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-shutdown\nlago.ssh: DEBUG: Command b7683c5c on lago-he-basic-ansible-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:b8b1cea3-0cce-43d1-8872-84dc6282c96d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:b8b1cea3-0cce-43d1-8872-84dc6282c96d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running b83d8ef2 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command b83d8ef2 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command b83d8ef2 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2555 (Thu Nov 8 03:17:13 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=2555 (Thu Nov 8 03:17:14 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "91a2a003", "local_conf_timestamp": 2555, "host-ts": 2555}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2553 (Thu Nov 8 03:17:12 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2553 (Thu Nov 8 03:17:12 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "a7e651e6", "local_conf_timestamp": 2553, "host-ts": 2553}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:e6d043c5-156b-4288-a7a3-f24161654e22:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:e6d043c5-156b-4288-a7a3-f24161654e22:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running bed30274 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command bed30274 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command bed30274 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2575 (Thu Nov 8 03:17:33 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=2575 (Thu Nov 8 03:17:33 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down_unexpected", "detail": "Down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "73a2b866", "local_conf_timestamp": 2575, "host-ts": 2575}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2573 (Thu Nov 8 03:17:31 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2573 (Thu Nov 8 03:17:32 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "904ac61d", "local_conf_timestamp": 2573, "host-ts": 2573}, "global_maintenance": true}\n\nroot: INFO: * VM is down.\nroot: INFO: * Stopping services...\nlago.ssh: DEBUG: start task:4d492e84-b98f-410a-9186-9da4ad96953b:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:4d492e84-b98f-410a-9186-9da4ad96953b:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running bf583408 on lago-he-basic-ansible-suite-4-2-host-0: systemctl stop vdsmd ovirt-ha-broker ovirt-ha-agent\nlago.ssh: DEBUG: Command bf583408 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nroot: INFO: * Starting services...\nlago.ssh: DEBUG: start task:570131db-44f3-4f33-9b1c-1ca470f7db23:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:570131db-44f3-4f33-9b1c-1ca470f7db23:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running c7ea8f58 on lago-he-basic-ansible-suite-4-2-host-0: systemctl start vdsmd ovirt-ha-broker ovirt-ha-agent\nlago.ssh: DEBUG: Command c7ea8f58 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nroot: INFO: * Waiting for agent to be ready...\nlago.ssh: DEBUG: start task:15866098-59b0-4b3e-aca7-9f87b0faaa09:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:15866098-59b0-4b3e-aca7-9f87b0faaa09:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running ca1f0a7e on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command ca1f0a7e on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command ca1f0a7e on lago-he-basic-ansible-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:9d69a85b-cf95-4cd5-acf7-849b3eef94ae:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:9d69a85b-cf95-4cd5-acf7-849b3eef94ae:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d06eaa7e on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d06eaa7e on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d06eaa7e on lago-he-basic-ansible-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:f122fda8-a80e-420d-8427-bd667eaf09c3:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:f122fda8-a80e-420d-8427-bd667eaf09c3:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d2bcad8a on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d2bcad8a on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d2bcad8a on lago-he-basic-ansible-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:4f32a250-ab55-46c5-b228-a5ec3477a39c:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:4f32a250-ab55-46c5-b228-a5ec3477a39c:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d4e22d24 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d4e22d24 on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d4e22d24 on lago-he-basic-ansible-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:fa589610-73ae-4944-9b08-cfcc0c7a3256:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:fa589610-73ae-4944-9b08-cfcc0c7a3256:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d708a61e on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d708a61e on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d708a61e on lago-he-basic-ansible-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:31625e1e-23bb-43b9-9ab7-910a7dafc5ed:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:31625e1e-23bb-43b9-9ab7-910a7dafc5ed:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running d93645ae on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command d93645ae on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command d93645ae on lago-he-basic-ansible-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:6077407c-ae81-4203-bfe4-007bae8817fb:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:6077407c-ae81-4203-bfe4-007bae8817fb:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running db5f2030 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command db5f2030 on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command db5f2030 on lago-he-basic-ansible-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:77846988-89e4-45f0-8aba-cacb985bf1b9:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:77846988-89e4-45f0-8aba-cacb985bf1b9:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running dd889382 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command dd889382 on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command dd889382 on lago-he-basic-ansible-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:f1925127-d380-43cc-86ea-4f90bcb5b63d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:f1925127-d380-43cc-86ea-4f90bcb5b63d:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running dfb22bbe on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command dfb22bbe on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command dfb22bbe on lago-he-basic-ansible-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:4edc99b2-4a65-4147-b24d-56bbc8046b66:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:4edc99b2-4a65-4147-b24d-56bbc8046b66:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running e1d9e5e4 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command e1d9e5e4 on lago-he-basic-ansible-suite-4-2-host-0 returned with 1\nlago.ssh: DEBUG: Command e1d9e5e4 on lago-he-basic-ansible-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:70bfaba1-ad03-4f96-918f-1e2793ee7427:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:70bfaba1-ad03-4f96-918f-1e2793ee7427:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running e40a02a4 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status\nlago.ssh: DEBUG: Command e40a02a4 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command e40a02a4 on lago-he-basic-ansible-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-ansible-suite-4-2-host-0\nHost ID : 1\nEngine status : {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Down"}\nScore : 0\nstopped : False\nLocal maintenance : False\ncrc32 : 36bd3d62\nlocal_conf_timestamp : 2635\nHost timestamp : 2635\nExtra metadata (valid at timestamp):\n\tmetadata_parse_version=1\n\tmetadata_feature_version=1\n\ttimestamp=2635 (Thu Nov 8 03:18:33 2018)\n\thost-id=1\n\tscore=0\n\tvm_conf_refresh_time=2635 (Thu Nov 8 03:18:33 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-ansible-suite-4-2-host-1\nHost ID : 2\nEngine status : unknown stale-data\nScore : 3400\nstopped : False\nLocal maintenance : False\ncrc32 : 2ddfae49\nlocal_conf_timestamp : 2633\nHost timestamp : 2633\nExtra metadata (valid at timestamp):\n\tmetadata_parse_version=1\n\tmetadata_feature_version=1\n\ttimestamp=2633 (Thu Nov 8 03:18:32 2018)\n\thost-id=2\n\tscore=3400\n\tvm_conf_refresh_time=2633 (Thu Nov 8 03:18:32 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:ff98dc0f-e7fc-4cb8-b035-7af590da59dd:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:ff98dc0f-e7fc-4cb8-b035-7af590da59dd:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running e4911c3a on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-start\nlago.ssh: DEBUG: Command e4911c3a on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command e4911c3a on lago-he-basic-ansible-suite-4-2-host-0 output:\n VM exists and is down, cleaning up and restarting\n\nroot: INFO: * Command succeeded\nroot: INFO: * Waiting for VM to be UP...\nlago.ssh: DEBUG: start task:acf835ef-f2f1-4150-9e4a-69f3b18687fa:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:acf835ef-f2f1-4150-9e4a-69f3b18687fa:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running e5c3aa46 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command e5c3aa46 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command e5c3aa46 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2635 (Thu Nov 8 03:18:33 2018)\\nhost-id=1\\nscore=0\\nvm_conf_refresh_time=2635 (Thu Nov 8 03:18:33 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=ReinitializeFSM\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Down"}, "score": 0, "stopped": false, "maintenance": false, "crc32": "36bd3d62", "local_conf_timestamp": 2635, "host-ts": 2635}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2633 (Thu Nov 8 03:18:32 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2633 (Thu Nov 8 03:18:32 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "2ddfae49", "local_conf_timestamp": 2633, "host-ts": 2633}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:eb7dba65-0edb-4c63-9c01-22e619db3e60:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:eb7dba65-0edb-4c63-9c01-22e619db3e60:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running ec372e3e on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command ec372e3e on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command ec372e3e on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2645 (Thu Nov 8 03:18:44 2018)\\nhost-id=1\\nscore=3111\\nvm_conf_refresh_time=2645 (Thu Nov 8 03:18:44 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "0df3ca26", "local_conf_timestamp": 2645, "host-ts": 2645}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2643 (Thu Nov 8 03:18:42 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2643 (Thu Nov 8 03:18:42 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8344de99", "local_conf_timestamp": 2643, "host-ts": 2643}, "global_maintenance": true}\n\nroot: INFO: * VM is UP.\nroot: INFO: * Waiting for engine to start...\nlago.ssh: DEBUG: start task:8bf6658f-e1f4-4aa8-a773-b2d92f60e02a:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:8bf6658f-e1f4-4aa8-a773-b2d92f60e02a:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running ecaca8ee on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command ecaca8ee on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command ecaca8ee on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2645 (Thu Nov 8 03:18:44 2018)\\nhost-id=1\\nscore=3111\\nvm_conf_refresh_time=2645 (Thu Nov 8 03:18:44 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "0df3ca26", "local_conf_timestamp": 2645, "host-ts": 2645}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2643 (Thu Nov 8 03:18:42 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2643 (Thu Nov 8 03:18:42 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8344de99", "local_conf_timestamp": 2643, "host-ts": 2643}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:71c5108d-271c-4aad-8aec-0a8b7337f359:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:71c5108d-271c-4aad-8aec-0a8b7337f359:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running f330d5aa on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f330d5aa on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command f330d5aa on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2655 (Thu Nov 8 03:18:54 2018)\\nhost-id=1\\nscore=3111\\nvm_conf_refresh_time=2656 (Thu Nov 8 03:18:54 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "4c901fde", "local_conf_timestamp": 2656, "host-ts": 2655}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2653 (Thu Nov 8 03:18:51 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2653 (Thu Nov 8 03:18:52 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "752a1644", "local_conf_timestamp": 2653, "host-ts": 2653}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:e68357ea-ea52-44f4-b67e-e22f47d6a2ac:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:e68357ea-ea52-44f4-b67e-e22f47d6a2ac:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running f5a2235c on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f5a2235c on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command f5a2235c on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2665 (Thu Nov 8 03:19:03 2018)\\nhost-id=1\\nscore=3111\\nvm_conf_refresh_time=2665 (Thu Nov 8 03:19:03 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "6657c4e3", "local_conf_timestamp": 2665, "host-ts": 2665}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2663 (Thu Nov 8 03:19:02 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2663 (Thu Nov 8 03:19:02 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "b4e84962", "local_conf_timestamp": 2663, "host-ts": 2663}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:436dfa11-97d6-4095-804e-566329a5fdee:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:436dfa11-97d6-4095-804e-566329a5fdee:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running f7ff723a on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command f7ff723a on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command f7ff723a on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2665 (Thu Nov 8 03:19:03 2018)\\nhost-id=1\\nscore=3111\\nvm_conf_refresh_time=2665 (Thu Nov 8 03:19:03 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "6657c4e3", "local_conf_timestamp": 2665, "host-ts": 2665}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2663 (Thu Nov 8 03:19:02 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2663 (Thu Nov 8 03:19:02 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "b4e84962", "local_conf_timestamp": 2663, "host-ts": 2663}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:de0e96fe-575e-4a46-82f8-4e3d5a85ca1f:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:de0e96fe-575e-4a46-82f8-4e3d5a85ca1f:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running fa442a36 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command fa442a36 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command fa442a36 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2675 (Thu Nov 8 03:19:13 2018)\\nhost-id=1\\nscore=3111\\nvm_conf_refresh_time=2675 (Thu Nov 8 03:19:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "be3d40a1", "local_conf_timestamp": 2675, "host-ts": 2675}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2673 (Thu Nov 8 03:19:12 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2673 (Thu Nov 8 03:19:12 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "428681bf", "local_conf_timestamp": 2673, "host-ts": 2673}, "global_maintenance": true}\n\nlago.ssh: DEBUG: start task:97f350dc-f503-4726-84cb-61ad3b8166bc:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:97f350dc-f503-4726-84cb-61ad3b8166bc:Get ssh client for lago-he-basic-ansible-suite-4-2-host-0:\nlago.ssh: DEBUG: Running fc9a48b0 on lago-he-basic-ansible-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command fc9a48b0 on lago-he-basic-ansible-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command fc9a48b0 on lago-he-basic-ansible-suite-4-2-host-0 output:\n {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2675 (Thu Nov 8 03:19:13 2018)\\nhost-id=1\\nscore=3111\\nvm_conf_refresh_time=2675 (Thu Nov 8 03:19:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "be3d40a1", "local_conf_timestamp": 2675, "host-ts": 2675}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2673 (Thu Nov 8 03:19:12 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2673 (Thu Nov 8 03:19:12 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2\novirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f1389d43e60>\nTraceback (most recent call last):\n File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 234, in assert_equals_within\n res = func()\n File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/008_restart_he_vm.py", line 187, in <lambda>\n for k, v in _get_he_status(host).items()\n File "/home/jenkins/workspace/ovirt-system-tests_he-basic-ansible-suite-4.2/ovirt-system-tests/he-basic-ansible-suite-4.2/test-scenarios/008_restart_he_vm.py", line 128, in _get_he_status\n raise RuntimeError(\'could not parse JSON: %s\' % ret.out)\nRuntimeError: could not parse JSON: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2675 (Thu Nov 8 03:19:13 2018)\\nhost-id=1\\nscore=3111\\nvm_conf_refresh_time=2675 (Thu Nov 8 03:19:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "up", "detail": "Powering up"}, "score": 3111, "stopped": false, "maintenance": false, "crc32": "be3d40a1", "local_conf_timestamp": 2675, "host-ts": 2675}, "2": {"conf_on_shared_storage": true, "live-data": false, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=2673 (Thu Nov 8 03:19:12 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=2673 (Thu Nov 8 03:19:12 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-ansible-suite-4-2-host-1", "host-id": 2\n--------------------- >> end captured logging << ---------------------'