[oVirt Jenkins] ovirt-system-tests_he-node-ng-suite-4.2 - Build # 286 - Still Failing!

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/286/ Build Number: 286 Build Status: Still Failing 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 Changes for Build #286 [Gal Ben Haim] Adding dr suite ----------------- 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:73fa5f94-c894-462a-a6ef-b9ebc7cc0119:Get ssh client for lago-he-node-ng-suite-4-2-host-1: lago.ssh: DEBUG: end task:73fa5f94-c894-462a-a6ef-b9ebc7cc0119:Get ssh client for lago-he-node-ng-suite-4-2-host-1: lago.ssh: DEBUG: Running 8e620cda on lago-he-node-ng-suite-4-2-host-1: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 8e620cda on lago-he-node-ng-suite-4-2-host-1 returned with 0 lago.ssh: DEBUG: Command 8e620cda 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=4150 (Thu Sep 6 09:45:11 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=4150 (Thu Sep 6 09:45:12 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": "242f0670", "local_conf_timestamp": 4150, "host-ts": 4150}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4152 (Thu Sep 6 09:45:14 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4153 (Thu Sep 6 09:45:14 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": "8cf42a04", "local_conf_timestamp": 4153, "host-ts": 4152}, "global_maintenance": false} lago.ssh: DEBUG: start task:90e0be1f-91dc-4061-ae75-7f6499a7d220:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:90e0be1f-91dc-4061-ae75-7f6499a7d220:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 8f7dc4e2 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --set-maintenance --mode=local lago.ssh: DEBUG: Command 8f7dc4e2 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:009baaf8-0bcc-416c-a40b-5158836fdd91:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:009baaf8-0bcc-416c-a40b-5158836fdd91:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 9090d7c0 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 9090d7c0 on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 9090d7c0 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=4150 (Thu Sep 6 09:45:11 2018)\nhost-id=1\nscore=3400\nvm_conf_refresh_time=4150 (Thu Sep 6 09:45:12 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": "242f0670", "local_conf_timestamp": 4150, "host-ts": 4150}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4152 (Thu Sep 6 09:45:14 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4153 (Thu Sep 6 09:45:14 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": "8cf42a04", "local_conf_timestamp": 4153, "host-ts": 4152}, "global_maintenance": false} lago.ssh: DEBUG: start task:be4b28ac-98d6-4331-b730-ad8226e99068:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:be4b28ac-98d6-4331-b730-ad8226e99068:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 98502268 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 98502268 on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 98502268 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 09:45:22 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4160 (Thu Sep 6 09:45:22 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": "7ed257e4", "local_conf_timestamp": 4160, "host-ts": 4161}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4152 (Thu Sep 6 09:45:14 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4153 (Thu Sep 6 09:45:14 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": "8cf42a04", "local_conf_timestamp": 4153, "host-ts": 4152}, "global_maintenance": false} lago.ssh: DEBUG: start task:21a75a1e-6a19-44dd-9e03-2b93673c2cf7:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: end task:21a75a1e-6a19-44dd-9e03-2b93673c2cf7:Get ssh client for lago-he-node-ng-suite-4-2-host-0: lago.ssh: DEBUG: Running 9b52ff1c on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json lago.ssh: DEBUG: Command 9b52ff1c on lago-he-node-ng-suite-4-2-host-0 returned with 0 lago.ssh: DEBUG: Command 9b52ff1c 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 09:45:33 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=4171 (Thu Sep 6 09:45:33 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": "600d4ec7", "local_conf_timestamp": 4171, "host-ts": 4171}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=4163 (Thu Sep 6 09:45:24 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=4163 (Thu Sep 6 09:45:25 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": "1ddc3e83", "local_conf_timestamp": 4163, "host-ts": 4163}, "global_maintenance": false} 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 36, in _wait_for_engine_migration testlib.assert_true_within_long(lambda: _get_he_status(host) File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 286, in assert_true_within_long assert_equals_within_long(func, True, allowed_exceptions) File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 273, in assert_equals_within_long func, value, LONG_TIMEOUT, allowed_exceptions=allowed_exceptions File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 246, in assert_equals_within time.sleep(3) 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:73fa5f94-c894-462a-a6ef-b9ebc7cc0119:Get ssh client for lago-he-node-ng-suite-4-2-host-1:\nlago.ssh: DEBUG: end task:73fa5f94-c894-462a-a6ef-b9ebc7cc0119:Get ssh client for lago-he-node-ng-suite-4-2-host-1:\nlago.ssh: DEBUG: Running 8e620cda on lago-he-node-ng-suite-4-2-host-1: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 8e620cda on lago-he-node-ng-suite-4-2-host-1 returned with 0\nlago.ssh: DEBUG: Command 8e620cda 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=4150 (Thu Sep 6 09:45:11 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=4150 (Thu Sep 6 09:45:12 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": "242f0670", "local_conf_timestamp": 4150, "host-ts": 4150}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4152 (Thu Sep 6 09:45:14 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4153 (Thu Sep 6 09:45:14 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": "8cf42a04", "local_conf_timestamp": 4153, "host-ts": 4152}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:90e0be1f-91dc-4061-ae75-7f6499a7d220:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:90e0be1f-91dc-4061-ae75-7f6499a7d220:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 8f7dc4e2 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --set-maintenance --mode=local\nlago.ssh: DEBUG: Command 8f7dc4e2 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:009baaf8-0bcc-416c-a40b-5158836fdd91:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:009baaf8-0bcc-416c-a40b-5158836fdd91:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 9090d7c0 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 9090d7c0 on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 9090d7c0 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=4150 (Thu Sep 6 09:45:11 2018)\\nhost-id=1\\nscore=3400\\nvm_conf_refresh_time=4150 (Thu Sep 6 09:45:12 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": "242f0670", "local_conf_timestamp": 4150, "host-ts": 4150}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4152 (Thu Sep 6 09:45:14 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4153 (Thu Sep 6 09:45:14 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": "8cf42a04", "local_conf_timestamp": 4153, "host-ts": 4152}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:be4b28ac-98d6-4331-b730-ad8226e99068:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:be4b28ac-98d6-4331-b730-ad8226e99068:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 98502268 on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 98502268 on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 98502268 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 09:45:22 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4160 (Thu Sep 6 09:45:22 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": "7ed257e4", "local_conf_timestamp": 4160, "host-ts": 4161}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4152 (Thu Sep 6 09:45:14 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4153 (Thu Sep 6 09:45:14 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": "8cf42a04", "local_conf_timestamp": 4153, "host-ts": 4152}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:21a75a1e-6a19-44dd-9e03-2b93673c2cf7:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: end task:21a75a1e-6a19-44dd-9e03-2b93673c2cf7:Get ssh client for lago-he-node-ng-suite-4-2-host-0:\nlago.ssh: DEBUG: Running 9b52ff1c on lago-he-node-ng-suite-4-2-host-0: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command 9b52ff1c on lago-he-node-ng-suite-4-2-host-0 returned with 0\nlago.ssh: DEBUG: Command 9b52ff1c 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 09:45:33 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=4171 (Thu Sep 6 09:45:33 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": "600d4ec7", "local_conf_timestamp": 4171, "host-ts": 4171}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=4163 (Thu Sep 6 09:45:24 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=4163 (Thu Sep 6 09:45:25 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": "1ddc3e83", "local_conf_timestamp": 4163, "host-ts": 4163}, "global_maintenance": false}\n\ncli: DEBUG: signal 15 was caught\n--------------------- >> end captured logging << ---------------------'