Project: http://jenkins.ovirt.org/job/ovirt-system-tests_he-node-ng-suite-4.2/ Build: http://jenkins.ovirt.org/job/ovirt-system-tests_he-node-ng-suite-4.2/285/ Build Number: 285 Build Status: Failure Triggered By: Started by timer ------------------------------------- Changes Since Last Success: ------------------------------------- Changes for Build #285 [Gal Ben Haim] Adding dr suite [Barak Korren] Remove the populate_mock function from mock_runner [Daniel Belenky] mock_runner: store shell cmd in a variable [Barak Korren] mock_runner: Added timeout param [Barak Korren] Make whitelist repo configurable via env vars [Daniel Belenky] stdci_runner: let mock_runner manage timeout [Greg Sheremeta] remove 4.1 change queue from ovirt-engine-nodejs config ----------------- Failed Tests: ----------------- 1 tests failed. FAILED: 010_local_maintenance_cli.local_maintenance Error Message: 143 -------------------- >> begin captured logging << -------------------- root: INFO: * Waiting For System Stability... lago.ssh: DEBUG: start task:c3e22bc1-2785-476e-8ba3-ad975b3823a0:Get ssh client for lago-he-node-ng-suite-4-2-host-1: lago.ssh: DEBUG: end task:c3e22bc1-2785-476e-8ba3-ad975b3823a0:Get ssh client for lago-he-node-ng-suite-4-2-host-1: lago.ssh: DEBUG: Running 4cc65a9e on lago-he-node-ng-suite-4-2-host-1: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 4cc65a9e on lago-he-node-ng-suite-4-2-host-1 returned with 0 lago.ssh: DEBUG: Command 4cc65a9e on lago-he-node-ng-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=4109 (Thu Sep 6 01:43:37 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=4109 (Thu Sep 6 01:43:37 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "044228a8", "local_conf_timestamp": 4109, "host-ts": 4109}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4115 (Thu Sep 6 01:43:42 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4115 (Thu Sep 6 01:43:43 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-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": "8d059996", "local_conf_timestamp": 4115, "host-ts": 4115}, "global_maintenance": false} lago.ssh: DEBUG: start task:7f537510-6e18-4173-b0f5-d5f6a1c6e460:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:7f537510-6e18-4173-b0f5-d5f6a1c6e460:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 4dde7bbe on lago-he-node-ng-suite-4-2-host-0: hosted-engine --set-maintenance --mode=local lago.ssh: DEBUG: Command 4dde7bbe on lago-he-node-ng-suite-4-2-host-0 returned with 0 root: INFO: * Waiting for engine to migrate... lago.ssh: DEBUG: start task:94120632-275d-478f-9cac-0ff1eb6c2e63:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:94120632-275d-478f-9cac-0ff1eb6c2e63:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 4ef81abe on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 4ef81abe on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 4ef81abe on lago-he-node-ng-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=4119 (Thu Sep 6 01:43:47 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=4120 (Thu Sep 6 01:43:47 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8ad483f0", "local_conf_timestamp": 4120, "host-ts": 4119}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4115 (Thu Sep 6 01:43:42 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4115 (Thu Sep 6 01:43:43 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-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": "8d059996", "local_conf_timestamp": 4115, "host-ts": 4115}, "global_maintenance": false} lago.ssh: DEBUG: start task:82d6fe01-3354-4477-9210-df6ac2d4d420:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:82d6fe01-3354-4477-9210-df6ac2d4d420:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 5626eb30 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 5626eb30 on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 5626eb30 on lago-he-node-ng-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=4131 (Thu Sep 6 01:43:58 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4130 (Thu Sep 6 01:43:58 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "65ca1ba5", "local_conf_timestamp": 4130, "host-ts": 4131}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4125 (Thu Sep 6 01:43:53 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4126 (Thu Sep 6 01:43:53 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-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": "18c7c923", "local_conf_timestamp": 4126, "host-ts": 4125}, "global_maintenance": false} lago.ssh: DEBUG: start task:b3211ae7-4af2-469b-92c0-38ab6f07c5c4:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:b3211ae7-4af2-469b-92c0-38ab6f07c5c4:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 59979f1c on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 59979f1c on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 59979f1c on lago-he-node-ng-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=4141 (Thu Sep 6 01:44:09 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4141 (Thu Sep 6 01:44:09 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "49290bc0", "local_conf_timestamp": 4141, "host-ts": 4141}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4135 (Thu Sep 6 01:44:02 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4135 (Thu Sep 6 01:44:02 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-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": "8588679c", "local_conf_timestamp": 4135, "host-ts": 4135}, "global_maintenance": false} lago.ssh: DEBUG: start task:f62305f7-c324-4ee2-ba11-d092ac823600:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:f62305f7-c324-4ee2-ba11-d092ac823600:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 5dfd4692 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 5dfd4692 on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 5dfd4692 on lago-he-node-ng-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=4151 (Thu Sep 6 01:44:18 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4151 (Thu Sep 6 01:44:19 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e71a3502", "local_conf_timestamp": 4151, "host-ts": 4151}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4145 (Thu Sep 6 01:44:13 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4145 (Thu Sep 6 01:44:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "ef65af1f", "local_conf_timestamp": 4145, "host-ts": 4145}, "global_maintenance": false} lago.ssh: DEBUG: start task:a553c343-1311-45f3-9fc3-ed53d93b21d5:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:a553c343-1311-45f3-9fc3-ed53d93b21d5:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 61aded00 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 61aded00 on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 61aded00 on lago-he-node-ng-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=4151 (Thu Sep 6 01:44:18 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4151 (Thu Sep 6 01:44:19 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e71a3502", "local_conf_timestamp": 4151, "host-ts": 4151}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4145 (Thu Sep 6 01:44:13 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4145 (Thu Sep 6 01:44:13 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "ef65af1f", "local_conf_timestamp": 4145, "host-ts": 4145}, "global_maintenance": false} lago.ssh: DEBUG: start task:bb63e900-36b1-47d5-8bd7-b6b67eed6f7e:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:bb63e900-36b1-47d5-8bd7-b6b67eed6f7e:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 64b1136a on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 64b1136a on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 64b1136a on lago-he-node-ng-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=4151 (Thu Sep 6 01:44:18 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4151 (Thu Sep 6 01:44:19 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e71a3502", "local_conf_timestamp": 4151, "host-ts": 4151}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4155 (Thu Sep 6 01:44:22 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4155 (Thu Sep 6 01:44:22 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "eb23501a", "local_conf_timestamp": 4155, "host-ts": 4155}, "global_maintenance": false} lago.ssh: DEBUG: start task:97447141-6b3c-4188-ad5b-a8bbe1cc45db:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:97447141-6b3c-4188-ad5b-a8bbe1cc45db:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 67a5dc18 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 67a5dc18 on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 67a5dc18 on lago-he-node-ng-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=4161 (Thu Sep 6 01:44:29 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4162 (Thu Sep 6 01:44:30 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "573721bf", "local_conf_timestamp": 4162, "host-ts": 4161}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4155 (Thu Sep 6 01:44:22 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4155 (Thu Sep 6 01:44:22 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "eb23501a", "local_conf_timestamp": 4155, "host-ts": 4155}, "global_maintenance": false} lago.ssh: DEBUG: start task:dcbacc88-4c96-4575-a53a-31b073b1e31e:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:dcbacc88-4c96-4575-a53a-31b073b1e31e:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 6ada63f4 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 6ada63f4 on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 6ada63f4 on lago-he-node-ng-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=4171 (Thu Sep 6 01:44:39 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4172 (Thu Sep 6 01:44:39 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9041f7d", "local_conf_timestamp": 4172, "host-ts": 4171}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4165 (Thu Sep 6 01:44:32 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=4165 (Thu Sep 6 01:44:33 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "54cc899b", "local_conf_timestamp": 4165, "host-ts": 4165}, "global_maintenance": false} lago.ssh: DEBUG: start task:90045a52-c293-4837-bfef-33a5a1910dc5:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:90045a52-c293-4837-bfef-33a5a1910dc5:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 6df25e2a on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 6df25e2a on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 6df25e2a on lago-he-node-ng-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=4171 (Thu Sep 6 01:44:39 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4172 (Thu Sep 6 01:44:39 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9041f7d", "local_conf_timestamp": 4172, "host-ts": 4171}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4165 (Thu Sep 6 01:44:32 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=4165 (Thu Sep 6 01:44:33 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "54cc899b", "local_conf_timestamp": 4165, "host-ts": 4165}, "global_maintenance": false} lago.ssh: DEBUG: start task:a7476663-b52b-4275-8cc2-cd9ff3b88a3c:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:a7476663-b52b-4275-8cc2-cd9ff3b88a3c:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 71077262 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 71077262 on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 71077262 on lago-he-node-ng-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=4181 (Thu Sep 6 01:44:48 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4181 (Thu Sep 6 01:44:49 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "edb81fdc", "local_conf_timestamp": 4181, "host-ts": 4181}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4175 (Thu Sep 6 01:44:43 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=4176 (Thu Sep 6 01:44:43 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "c9832724", "local_conf_timestamp": 4176, "host-ts": 4175}, "global_maintenance": false} lago.ssh: DEBUG: start task:42a25e42-c90a-456e-8669-82df79c7507c:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:42a25e42-c90a-456e-8669-82df79c7507c:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 74595c8c on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 74595c8c on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 74595c8c on lago-he-node-ng-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=4181 (Thu Sep 6 01:44:48 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4181 (Thu Sep 6 01:44:49 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineMigratingAway\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "edb81fdc", "local_conf_timestamp": 4181, "host-ts": 4181}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4175 (Thu Sep 6 01:44:43 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=4176 (Thu Sep 6 01:44:43 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "c9832724", "local_conf_timestamp": 4176, "host-ts": 4175}, "global_maintenance": false} lago.ssh: DEBUG: start task:22a966cf-52a3-43b7-98b0-a28f0df8f67e:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:22a966cf-52a3-43b7-98b0-a28f0df8f67e:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 77bc4bdc on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 77bc4bdc on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 77bc4bdc on lago-he-node-ng-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=4191 (Thu Sep 6 01:44:59 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4192 (Thu Sep 6 01:45:00 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "VM migrated away successfully", "health": "bad", "vm": "down", "detail": "Down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "29ba0d11", "local_conf_timestamp": 4192, "host-ts": 4191}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4185 (Thu Sep 6 01:44:52 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=4185 (Thu Sep 6 01:44:52 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "6f6d73ad", "local_conf_timestamp": 4185, "host-ts": 4185}, "global_maintenance": false} lago.ssh: DEBUG: start task:f9fa6fdb-2c5a-41b9-ac58-6ec7a8e8ef3f:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:f9fa6fdb-2c5a-41b9-ac58-6ec7a8e8ef3f:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 78d063fa on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 78d063fa on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 78d063fa on lago-he-node-ng-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=4191 (Thu Sep 6 01:44:59 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4192 (Thu Sep 6 01:45:00 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "VM migrated away successfully", "health": "bad", "vm": "down", "detail": "Down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "29ba0d11", "local_conf_timestamp": 4192, "host-ts": 4191}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4185 (Thu Sep 6 01:44:52 2018)\nhost-id=2\nscore=3000\nvm_conf_refresh_time=4185 (Thu Sep 6 01:44:52 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineDown\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "6f6d73ad", "local_conf_timestamp": 4185, "host-ts": 4185}, "global_maintenance": false} lago.ssh: DEBUG: start task:095cd3ad-d465-46bb-8cd1-fd07a1a124ed:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:095cd3ad-d465-46bb-8cd1-fd07a1a124ed:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 7fdb3a94 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 7fdb3a94 on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 7fdb3a94 on lago-he-node-ng-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=4202 (Thu Sep 6 01:45:10 2018)\nhost-id=1\nscore=0\nvm_conf_refresh_time=4203 (Thu Sep 6 01:45:10 2018)\nconf_on_shared_storage=True\nmaintenance=True\nstate=LocalMaintenance\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 0, "stopped": false, "maintenance": true, "crc32": "8a558591", "local_conf_timestamp": 4203, "host-ts": 4202}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4196 (Thu Sep 6 01:45:03 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4196 (Thu Sep 6 01:45:03 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=EngineUp\nstopped=False\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "a9977fba", "local_conf_timestamp": 4196, "host-ts": 4196}, "global_maintenance": false} root: INFO: * Engine has migrated. root: INFO: * Waiting For System Stability... cli: DEBUG: signal 15 was caught --------------------- >> 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-node-ng-suite-4.2/ovirt-system-tests/he-node-ng-suite-4.2/test-scenarios/010_local_maintenance_cli.py", line 125, in local_maintenance _wait_for_engine_migration(host, he_index, "bad", "Migration Destination") File "/home/jenkins/workspace/ovirt-system-tests_he-node-ng-suite-4.2/ovirt-system-tests/he-node-ng-suite-4.2/test-scenarios/010_local_maintenance_cli.py", line 45, in _wait_for_engine_migration time.sleep(wait_value) File "/usr/lib/python2.7/site-packages/lago/cmd.py", line 922, in exit_handler sys.exit(128 + signum) '143\n-------------------- >> begin captured logging << --------------------\nroot: INFO: * Waiting For System Stability...\nlago.ssh: DEBUG: start task:c3e22bc1-2785-476e-8ba3-ad975b3823a0:Get ssh client for lago-he-node-ng-suite-4-2-host-1:\nlago.ssh: DEBUG: end task:c3e22bc1-2785-476e-8ba3-ad975b3823a0:Get ssh client for lago-he-node-ng-suite-4-2-host-1:\nlago.ssh: DEBUG: Running 4cc65a9e on lago-he-node-ng-suite-4-2-host-1: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 4cc65a9e on lago-he-node-ng-suite-4-2-host-1 returned with 0\nlago.ssh: DEBUG: Command 4cc65a9e on lago-he-node-ng-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=4109 (Thu Sep 6 01:43:37 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=4109 (Thu Sep 6 01:43:37 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "044228a8", "local_conf_timestamp": 4109, "host-ts": 4109}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4115 (Thu Sep 6 01:43:42 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4115 (Thu Sep 6 01:43:43 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-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": "8d059996", "local_conf_timestamp": 4115, "host-ts": 4115}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:7f537510-6e18-4173-b0f5-d5f6a1c6e460:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:7f537510-6e18-4173-b0f5-d5f6a1c6e460:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 4dde7bbe on lago-he-node-ng-suite-4-2-host-0: hosted-engine --set-maintenance --mode=local\nlago.ssh: DEBUG: Command 4dde7bbe on lago-he-node-ng-suite-4-2-host-0 returned with 0\nroot: INFO: * Waiting for engine to migrate...\nlago.ssh: DEBUG: start task:94120632-275d-478f-9cac-0ff1eb6c2e63:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:94120632-275d-478f-9cac-0ff1eb6c2e63:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 4ef81abe on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 4ef81abe on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 4ef81abe on lago-he-node-ng-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=4119 (Thu Sep 6 01:43:47 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=4120 (Thu Sep 6 01:43:47 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "8ad483f0", "local_conf_timestamp": 4120, "host-ts": 4119}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4115 (Thu Sep 6 01:43:42 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4115 (Thu Sep 6 01:43:43 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-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": "8d059996", "local_conf_timestamp": 4115, "host-ts": 4115}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:82d6fe01-3354-4477-9210-df6ac2d4d420:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:82d6fe01-3354-4477-9210-df6ac2d4d420:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 5626eb30 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 5626eb30 on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 5626eb30 on lago-he-node-ng-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=4131 (Thu Sep 6 01:43:58 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4130 (Thu Sep 6 01:43:58 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "65ca1ba5", "local_conf_timestamp": 4130, "host-ts": 4131}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4125 (Thu Sep 6 01:43:53 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4126 (Thu Sep 6 01:43:53 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-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": "18c7c923", "local_conf_timestamp": 4126, "host-ts": 4125}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:b3211ae7-4af2-469b-92c0-38ab6f07c5c4:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:b3211ae7-4af2-469b-92c0-38ab6f07c5c4:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 59979f1c on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 59979f1c on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 59979f1c on lago-he-node-ng-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=4141 (Thu Sep 6 01:44:09 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4141 (Thu Sep 6 01:44:09 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "49290bc0", "local_conf_timestamp": 4141, "host-ts": 4141}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4135 (Thu Sep 6 01:44:02 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4135 (Thu Sep 6 01:44:02 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-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": "8588679c", "local_conf_timestamp": 4135, "host-ts": 4135}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:f62305f7-c324-4ee2-ba11-d092ac823600:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:f62305f7-c324-4ee2-ba11-d092ac823600:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 5dfd4692 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 5dfd4692 on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 5dfd4692 on lago-he-node-ng-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=4151 (Thu Sep 6 01:44:18 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4151 (Thu Sep 6 01:44:19 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e71a3502", "local_conf_timestamp": 4151, "host-ts": 4151}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4145 (Thu Sep 6 01:44:13 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4145 (Thu Sep 6 01:44:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "ef65af1f", "local_conf_timestamp": 4145, "host-ts": 4145}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:a553c343-1311-45f3-9fc3-ed53d93b21d5:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:a553c343-1311-45f3-9fc3-ed53d93b21d5:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 61aded00 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 61aded00 on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 61aded00 on lago-he-node-ng-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=4151 (Thu Sep 6 01:44:18 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4151 (Thu Sep 6 01:44:19 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e71a3502", "local_conf_timestamp": 4151, "host-ts": 4151}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4145 (Thu Sep 6 01:44:13 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4145 (Thu Sep 6 01:44:13 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "ef65af1f", "local_conf_timestamp": 4145, "host-ts": 4145}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:bb63e900-36b1-47d5-8bd7-b6b67eed6f7e:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:bb63e900-36b1-47d5-8bd7-b6b67eed6f7e:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 64b1136a on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 64b1136a on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 64b1136a on lago-he-node-ng-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=4151 (Thu Sep 6 01:44:18 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4151 (Thu Sep 6 01:44:19 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "e71a3502", "local_conf_timestamp": 4151, "host-ts": 4151}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4155 (Thu Sep 6 01:44:22 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4155 (Thu Sep 6 01:44:22 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "eb23501a", "local_conf_timestamp": 4155, "host-ts": 4155}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:97447141-6b3c-4188-ad5b-a8bbe1cc45db:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:97447141-6b3c-4188-ad5b-a8bbe1cc45db:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 67a5dc18 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 67a5dc18 on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 67a5dc18 on lago-he-node-ng-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=4161 (Thu Sep 6 01:44:29 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4162 (Thu Sep 6 01:44:30 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "573721bf", "local_conf_timestamp": 4162, "host-ts": 4161}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4155 (Thu Sep 6 01:44:22 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4155 (Thu Sep 6 01:44:22 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "eb23501a", "local_conf_timestamp": 4155, "host-ts": 4155}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:dcbacc88-4c96-4575-a53a-31b073b1e31e:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:dcbacc88-4c96-4575-a53a-31b073b1e31e:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 6ada63f4 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 6ada63f4 on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 6ada63f4 on lago-he-node-ng-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=4171 (Thu Sep 6 01:44:39 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4172 (Thu Sep 6 01:44:39 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9041f7d", "local_conf_timestamp": 4172, "host-ts": 4171}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4165 (Thu Sep 6 01:44:32 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=4165 (Thu Sep 6 01:44:33 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "54cc899b", "local_conf_timestamp": 4165, "host-ts": 4165}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:90045a52-c293-4837-bfef-33a5a1910dc5:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:90045a52-c293-4837-bfef-33a5a1910dc5:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 6df25e2a on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 6df25e2a on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 6df25e2a on lago-he-node-ng-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=4171 (Thu Sep 6 01:44:39 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4172 (Thu Sep 6 01:44:39 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9041f7d", "local_conf_timestamp": 4172, "host-ts": 4171}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4165 (Thu Sep 6 01:44:32 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=4165 (Thu Sep 6 01:44:33 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "54cc899b", "local_conf_timestamp": 4165, "host-ts": 4165}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:a7476663-b52b-4275-8cc2-cd9ff3b88a3c:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:a7476663-b52b-4275-8cc2-cd9ff3b88a3c:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 71077262 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 71077262 on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 71077262 on lago-he-node-ng-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=4181 (Thu Sep 6 01:44:48 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4181 (Thu Sep 6 01:44:49 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "edb81fdc", "local_conf_timestamp": 4181, "host-ts": 4181}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4175 (Thu Sep 6 01:44:43 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=4176 (Thu Sep 6 01:44:43 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "c9832724", "local_conf_timestamp": 4176, "host-ts": 4175}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:42a25e42-c90a-456e-8669-82df79c7507c:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:42a25e42-c90a-456e-8669-82df79c7507c:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 74595c8c on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 74595c8c on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 74595c8c on lago-he-node-ng-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=4181 (Thu Sep 6 01:44:48 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4181 (Thu Sep 6 01:44:49 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineMigratingAway\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Migration Source"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "edb81fdc", "local_conf_timestamp": 4181, "host-ts": 4181}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4175 (Thu Sep 6 01:44:43 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=4176 (Thu Sep 6 01:44:43 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "c9832724", "local_conf_timestamp": 4176, "host-ts": 4175}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:22a966cf-52a3-43b7-98b0-a28f0df8f67e:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:22a966cf-52a3-43b7-98b0-a28f0df8f67e:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 77bc4bdc on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 77bc4bdc on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 77bc4bdc on lago-he-node-ng-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=4191 (Thu Sep 6 01:44:59 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4192 (Thu Sep 6 01:45:00 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "VM migrated away successfully", "health": "bad", "vm": "down", "detail": "Down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "29ba0d11", "local_conf_timestamp": 4192, "host-ts": 4191}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4185 (Thu Sep 6 01:44:52 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=4185 (Thu Sep 6 01:44:52 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "6f6d73ad", "local_conf_timestamp": 4185, "host-ts": 4185}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:f9fa6fdb-2c5a-41b9-ac58-6ec7a8e8ef3f:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:f9fa6fdb-2c5a-41b9-ac58-6ec7a8e8ef3f:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 78d063fa on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 78d063fa on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 78d063fa on lago-he-node-ng-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=4191 (Thu Sep 6 01:44:59 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4192 (Thu Sep 6 01:45:00 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "VM migrated away successfully", "health": "bad", "vm": "down", "detail": "Down"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "29ba0d11", "local_conf_timestamp": 4192, "host-ts": 4191}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4185 (Thu Sep 6 01:44:52 2018)\\nhost-id=2\\nscore=3000\\nvm_conf_refresh_time=4185 (Thu Sep 6 01:44:52 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineDown\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": "bad vm status", "health": "bad", "vm": "down", "detail": "Migration Destination"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "6f6d73ad", "local_conf_timestamp": 4185, "host-ts": 4185}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:095cd3ad-d465-46bb-8cd1-fd07a1a124ed:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:095cd3ad-d465-46bb-8cd1-fd07a1a124ed:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 7fdb3a94 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 7fdb3a94 on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 7fdb3a94 on lago-he-node-ng-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=4202 (Thu Sep 6 01:45:10 2018)\\nhost-id=1\\nscore=0\\nvm_conf_refresh_time=4203 (Thu Sep 6 01:45:10 2018)\\nconf_on_shared_storage=True\\nmaintenance=True\\nstate=LocalMaintenance\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-0", "host-id": 1, "engine-status": {"reason": "vm not running on this host", "health": "bad", "vm": "down", "detail": "unknown"}, "score": 0, "stopped": false, "maintenance": true, "crc32": "8a558591", "local_conf_timestamp": 4203, "host-ts": 4202}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4196 (Thu Sep 6 01:45:03 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4196 (Thu Sep 6 01:45:03 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=EngineUp\\nstopped=False\\n", "hostname": "lago-he-node-ng-suite-4-2-host-1", "host-id": 2, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3400, "stopped": false, "maintenance": false, "crc32": "a9977fba", "local_conf_timestamp": 4196, "host-ts": 4196}, "global_maintenance": false}\n\nroot: INFO: * Engine has migrated.\nroot: INFO: * Waiting For System Stability...\ncli: DEBUG: signal 15 was caught\n--------------------- >> end captured logging << ---------------------'