[ostf] test 'Launch instance, create snapshot' is failed with no message

[Aleksey Kasatkin]

VBox, 5.0-26 upgraded to 5.1

"build_id": "2014-07-30_10-31-34", "ostf_sha": "9c0454b2197756051fc9cee3cfd856cf2a4f0875", "build_number": "374", "auth_required": true, "api": "1.0", "nailgun_sha": "8cf375f7687d7d0797e7f085a909df8087fc82a6", "production": "docker", "fuelmain_sha": "60669ce22d201b2cbcfd147286230e4eaed2850b", "astute_sha": "b16efcec6b4af1fb8669055c053fbabe188afa67", "feature_groups": ["mirantis"], "release": "5.1", "fuellib_sha": "8980a11e23242e0b0f331a8b899e18ac89f441be"

1. deploy env: ubuntu, simple, ceilometer, 1 ctrl + 1 mongo + 1 comp
2. run osft: test "Launch instance, create snapshot, launch instance from snapshot" has failed w/o a message (see attachment)

Same result on second run.

[Tatyanka (tatyana-leontovich)]

could you attach snapshot with logs please

[Tatyanka (tatyana-leontovich)]

I believe we should provide env to the UI team according to ostf return message in right format and step 3 should be displayed as errored with message
AssertionError: Step 3 failed: Timed out waiting to become ACTIVE Please refer to OpenStack logs for more details.

[Aleksey Kasatkin (alekseyk-ru)]

OSFT exposed two tracebacks in a row:

2014-07-31 12:16:37 ERROR (nose_storage_plugin) fuel_health.tests.smoke.test_nova_image_actions.TestImageAction.test_snapshot
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/unittest2/case.py", line 340, in run
    testMethod()
  File "/usr/lib/python2.6/site-packages/fuel_health/tests/smoke/test_nova_image_actions.py", line 157, in test_snapshot
    server)
  File "/usr/lib/python2.6/site-packages/fuel_health/common/test_mixins.py", line 192, in verify
    " Please refer to OpenStack logs for more details.")
  File "/usr/lib/python2.6/site-packages/unittest2/case.py", line 415, in fail
    raise self.failureException(msg)
AssertionError: Step 3 failed: Timed out waiting to become ACTIVE Please refer to OpenStack logs for more details.

.....

2014-07-31 12:16:37 ERROR (nose_storage_plugin) fuel_health.tests.smoke.test_nova_image_actions.TestImageAction.test_snapshot
Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/unittest2/case.py", line 391, in doCleanups
    function(*args, **kwargs)
  File "/usr/lib/python2.6/site-packages/novaclient/v1_1/images.py", line 80, in delete
    self._delete("/images/%s" % base.getid(image))
  File "/usr/lib/python2.6/site-packages/novaclient/base.py", line 161, in _delete
    _resp, _body = self.api.client.delete(url)
  File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 292, in delete
    return self._cs_request(url, 'DELETE', **kwargs)
  File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 260, in _cs_request
    **kwargs)
  File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 242, in _time_request
    resp, body = self.request(url, method, **kwargs)
  File "/usr/lib/python2.6/site-packages/novaclient/client.py", line 236, in request
    raise exceptions.from_response(resp, body, url, method)
NotFound: Image not found. (HTTP 404) (Request-ID: req-47c5993f-bccc-4f6e-a922-b24ca86479eb)

.....

In addition, there are two nested blocks of captured logs after second traceback:

-------------------- >> begin captured logging << --------------------

....

fuel_health.common.test_mixins: DEBUG: Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/fuel_health/common/test_mixins.py", line 186, in verify
    result = func(*args, **kwargs)
  File "/usr/lib/python2.6/site-packages/fuel_health/tests/smoke/test_nova_image_actions.py", line 122, in _create_image
    self._wait_for_image_status(image_id, 'ACTIVE')
  File "/usr/lib/python2.6/site-packages/fuel_health/tests/smoke/test_nova_image_actions.py", line 60, in _wait_for_image_status
    self.status_timeout(self.compute_client.images, image_id, status)
  File "/usr/lib/python2.6/site-packages/fuel_health/test.py", line 133, in status_timeout
    % expected_status)
  File "/usr/lib/python2.6/site-packages/unittest2/case.py", line 415, in fail
    raise self.failureException(msg)
AssertionError: Timed out waiting to become ACTIVE

fuel_plugin.ostf_adapter.nose_plugin.nose_storage_plugin: ERROR: fuel_health.tests.smoke.test_nova_image_actions.TestImageAction.test_snapshot
Traceback (most recent call last):
  Fil...

[Aleksey Kasatkin (alekseyk-ru)]

Nested logs - looks like a possible problem in OSTF.

[Aleksey Kasatkin (alekseyk-ru)]

+ two tracebacks for the same test.

[Aleksey Kasatkin (alekseyk-ru)]

Reproduced on #376.

[Aleksey Kasatkin (alekseyk-ru)]

Env: ubuntu, simple, ceilometer, 1 ctrl/mongo + 1 comp

[Aleksey Kasatkin (alekseyk-ru)]

Env: ubuntu, simple, ceilometer, 1 ctrl/mongo + 1 cind/comp

[Dima Shulyak (dshulyak)]

Nested traceback should not affect error message

  https://github.com/stackforge/fuel-ostf/blob/master/fuel_health/common/test_mixins.py#L188

But i cant reproduce issue with no message available anyway, lets take a look at your env if it will rise again.

As for sporadic failures of this test - i see that image goes to deleted status, after it tried to got saved. And probably the root cause of it is that storage is shared between /var/lib/glance and /var/lib/mongo