Project: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-iscsi-suite-4.2/ Build: http://jenkins.ovirt.org/job/ovirt-system-tests_he-basic-iscsi-suite-4.2/267... Build Number: 267 Build Status: Failure Triggered By: Started by timer ------------------------------------- Changes Since Last Success: ------------------------------------- Changes for Build #267 [Milan Zamazal] ovf_import test ----------------- Failed Tests: ----------------- 1 tests failed. FAILED: 008_restart_he_vm.clear_global_maintenance Error Message: could not parse JSON: {"1": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3471 (Fri Aug 31 00:03:54 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3472 (Fri Aug 31 00:03:56 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9976f21", "local_conf_timestamp": 3472, "host-ts": 3471}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3474 (Fri Aug 31 00:03:57 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=3475 (Fri Aug 31 00:03:59 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": -------------------- >> begin captured logging << -------------------- root: INFO: * Waiting For System Stability... lago.ssh: DEBUG: start task:8e5f0870-b553-4b5e-800a-b52bcf9bd6f2:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1: lago.ssh: DEBUG: end task:8e5f0870-b553-4b5e-800a-b52bcf9bd6f2:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1: lago.ssh: DEBUG: Running e2898e46 on lago-he-basic-iscsi-suite-4-2-host-1: hosted-engine --set-maintenance --mode=none lago.ssh: DEBUG: Command e2898e46 on lago-he-basic-iscsi-suite-4-2-host-1 returned with 0 lago.ssh: DEBUG: start task:fe224927-909a-4f8d-b6e1-df23323f1c23:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1: lago.ssh: DEBUG: end task:fe224927-909a-4f8d-b6e1-df23323f1c23:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1: lago.ssh: DEBUG: Running e31c25b2 on lago-he-basic-iscsi-suite-4-2-host-1: hosted-engine --vm-status --json lago.ssh: DEBUG: Command e31c25b2 on lago-he-basic-iscsi-suite-4-2-host-1 returned with 0 lago.ssh: DEBUG: Command e31c25b2 on lago-he-basic-iscsi-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=3471 (Fri Aug 31 00:03:54 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3472 (Fri Aug 31 00:03:56 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9976f21", "local_conf_timestamp": 3472, "host-ts": 3471}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3464 (Fri Aug 31 00:03:47 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=3465 (Fri Aug 31 00:03:48 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-iscsi-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": "67aeaffc", "local_conf_timestamp": 3465, "host-ts": 3464}, "global_maintenance": false} lago.ssh: DEBUG: start task:67f9cd03-8ec1-47be-84dc-f2b9197ea24d:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1: lago.ssh: DEBUG: end task:67f9cd03-8ec1-47be-84dc-f2b9197ea24d:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1: lago.ssh: DEBUG: Running e3a8b2d4 on lago-he-basic-iscsi-suite-4-2-host-1: hosted-engine --vm-status --json lago.ssh: DEBUG: Command e3a8b2d4 on lago-he-basic-iscsi-suite-4-2-host-1 returned with 0 lago.ssh: DEBUG: Command e3a8b2d4 on lago-he-basic-iscsi-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=3471 (Fri Aug 31 00:03:54 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3472 (Fri Aug 31 00:03:56 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9976f21", "local_conf_timestamp": 3472, "host-ts": 3471}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3474 (Fri Aug 31 00:03:57 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=3475 (Fri Aug 31 00:03:59 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": ovirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f5f87df1050> 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-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-suite-4.2/test-scenarios/008_restart_he_vm.py", line 85, in <lambda> lambda: _is_state_maintenance(host, "GlobalMaintenance") is False File "/home/jenkins/workspace/ovirt-system-tests_he-basic-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-suite-4.2/test-scenarios/008_restart_he_vm.py", line 58, in _is_state_maintenance status = _get_he_status(host) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-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=3471 (Fri Aug 31 00:03:54 2018)\nhost-id=1\nscore=3000\nvm_conf_refresh_time=3472 (Fri Aug 31 00:03:56 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9976f21", "local_conf_timestamp": 3472, "host-ts": 3471}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\nmetadata_feature_version=1\ntimestamp=3474 (Fri Aug 31 00:03:57 2018)\nhost-id=2\nscore=3400\nvm_conf_refresh_time=3475 (Fri Aug 31 00:03:59 2018)\nconf_on_shared_storage=True\nmaintenance=False\nstate=GlobalMaintenance\nstopped=False\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason": --------------------- >> end captured logging << --------------------- Stack Trace: File "/usr/lib64/python2.7/unittest/case.py", line 369, in run testMethod() File "/usr/lib/python2.7/site-packages/nose/case.py", line 197, in runTest self.test(*self.arg) File "/usr/lib/python2.7/site-packages/ovirtlago/testlib.py", line 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-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-suite-4.2/test-scenarios/008_restart_he_vm.py", line 85, in clear_global_maintenance lambda: _is_state_maintenance(host, "GlobalMaintenance") is False 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-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-suite-4.2/test-scenarios/008_restart_he_vm.py", line 85, in <lambda> lambda: _is_state_maintenance(host, "GlobalMaintenance") is False File "/home/jenkins/workspace/ovirt-system-tests_he-basic-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-suite-4.2/test-scenarios/008_restart_he_vm.py", line 58, in _is_state_maintenance status = _get_he_status(host) File "/home/jenkins/workspace/ovirt-system-tests_he-basic-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-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=3471 (Fri Aug 31 00:03:54 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3472 (Fri Aug 31 00:03:56 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9976f21", "local_conf_timestamp": 3472, "host-ts": 3471}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3474 (Fri Aug 31 00:03:57 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=3475 (Fri Aug 31 00:03:59 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason":\n-------------------- >> begin captured logging << --------------------\nroot: INFO: * Waiting For System Stability...\nlago.ssh: DEBUG: start task:8e5f0870-b553-4b5e-800a-b52bcf9bd6f2:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1:\nlago.ssh: DEBUG: end task:8e5f0870-b553-4b5e-800a-b52bcf9bd6f2:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1:\nlago.ssh: DEBUG: Running e2898e46 on lago-he-basic-iscsi-suite-4-2-host-1: hosted-engine --set-maintenance --mode=none\nlago.ssh: DEBUG: Command e2898e46 on lago-he-basic-iscsi-suite-4-2-host-1 returned with 0\nlago.ssh: DEBUG: start task:fe224927-909a-4f8d-b6e1-df23323f1c23:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1:\nlago.ssh: DEBUG: end task:fe224927-909a-4f8d-b6e1-df23323f1c23:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1:\nlago.ssh: DEBUG: Running e31c25b2 on lago-he-basic-iscsi-suite-4-2-host-1: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command e31c25b2 on lago-he-basic-iscsi-suite-4-2-host-1 returned with 0\nlago.ssh: DEBUG: Command e31c25b2 on lago-he-basic-iscsi-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=3471 (Fri Aug 31 00:03:54 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3472 (Fri Aug 31 00:03:56 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9976f21", "local_conf_timestamp": 3472, "host-ts": 3471}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3464 (Fri Aug 31 00:03:47 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=3465 (Fri Aug 31 00:03:48 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-iscsi-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": "67aeaffc", "local_conf_timestamp": 3465, "host-ts": 3464}, "global_maintenance": false}\n\nlago.ssh: DEBUG: start task:67f9cd03-8ec1-47be-84dc-f2b9197ea24d:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1:\nlago.ssh: DEBUG: end task:67f9cd03-8ec1-47be-84dc-f2b9197ea24d:Get ssh client for lago-he-basic-iscsi-suite-4-2-host-1:\nlago.ssh: DEBUG: Running e3a8b2d4 on lago-he-basic-iscsi-suite-4-2-host-1: hosted-engine --vm-status --json\nlago.ssh: DEBUG: Command e3a8b2d4 on lago-he-basic-iscsi-suite-4-2-host-1 returned with 0\nlago.ssh: DEBUG: Command e3a8b2d4 on lago-he-basic-iscsi-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=3471 (Fri Aug 31 00:03:54 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3472 (Fri Aug 31 00:03:56 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9976f21", "local_conf_timestamp": 3472, "host-ts": 3471}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3474 (Fri Aug 31 00:03:57 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=3475 (Fri Aug 31 00:03:59 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason":\novirtlago.testlib: ERROR: * Unhandled exception in <function <lambda> at 0x7f5f87df1050>\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-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-suite-4.2/test-scenarios/008_restart_he_vm.py", line 85, in <lambda>\n lambda: _is_state_maintenance(host, "GlobalMaintenance") is False\n File "/home/jenkins/workspace/ovirt-system-tests_he-basic-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-suite-4.2/test-scenarios/008_restart_he_vm.py", line 58, in _is_state_maintenance\n status = _get_he_status(host)\n File "/home/jenkins/workspace/ovirt-system-tests_he-basic-iscsi-suite-4.2/ovirt-system-tests/he-basic-iscsi-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=3471 (Fri Aug 31 00:03:54 2018)\\nhost-id=1\\nscore=3000\\nvm_conf_refresh_time=3472 (Fri Aug 31 00:03:56 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-0.lago.local", "host-id": 1, "engine-status": {"health": "good", "vm": "up", "detail": "Up"}, "score": 3000, "stopped": false, "maintenance": false, "crc32": "f9976f21", "local_conf_timestamp": 3472, "host-ts": 3471}, "2": {"conf_on_shared_storage": true, "live-data": true, "extra": "metadata_parse_version=1\\nmetadata_feature_version=1\\ntimestamp=3474 (Fri Aug 31 00:03:57 2018)\\nhost-id=2\\nscore=3400\\nvm_conf_refresh_time=3475 (Fri Aug 31 00:03:59 2018)\\nconf_on_shared_storage=True\\nmaintenance=False\\nstate=GlobalMaintenance\\nstopped=False\\n", "hostname": "lago-he-basic-iscsi-suite-4-2-host-1", "host-id": 2, "engine-status": {"reason":\n--------------------- >> end captured logging << ---------------------'