In testrun https://solutions.qa.canonical.com/testruns/testRun/7f8576a7-d016-4ed2-b944-3c9fbd1ec16b, the Tempest test https://oil-jenkins.canonical.com/artifacts/7f8576a7-d016-4ed2-b944-3c9fbd1ec16b/generated/generated/openstack/tempest_result.html fails with:
```
Traceback (most recent call last):
File "/home/ubuntu/snap/fcbtest/34/.rally/verification/verifier-cfd99e55-d45b-41e9-8aea-baf8aeaaf4ed/repo/tempest/api/compute/images/test_images.py", line 87, in test_create_image_from_stopped_server
image = self.create_image_from_server(server['id'],
File "/home/ubuntu/snap/fcbtest/34/.rally/verification/verifier-cfd99e55-d45b-41e9-8aea-baf8aeaaf4ed/repo/tempest/api/compute/base.py", line 386, in create_image_from_server
waiters.wait_for_image_status(client, image_id, wait_until)
File "/home/ubuntu/snap/fcbtest/34/.rally/verification/verifier-cfd99e55-d45b-41e9-8aea-baf8aeaaf4ed/repo/tempest/common/waiters.py", line 198, in wait_for_image_status
raise lib_exc.TimeoutException(message)
tempest.lib.exceptions.TimeoutException: Request timed out
Details: (ImagesTestJSON:test_create_image_from_stopped_server) Image 1f54570f-1e5d-4831-9249-8982cfeed544 failed to reach ACTIVE state (current state SAVING) within the required time (600 s).
```
10 min should be plenty to save the image, we have already doubled the timeout from the default 5 min to compensate for the slow machines.
In the logs I see some errors from glance:
```
21:03:42.185 189949 ERROR glance.api.v2.image_data Traceback (most recent call last):
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/api/v2/image_data.py", line 163, in upload
21:03:42.185 189949 ERROR glance.api.v2.image_data image.set_data(data, size, backend=backend)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/notifier.py", line 497, in set_data
21:03:42.185 189949 ERROR glance.api.v2.image_data _send_notification(notify_error, 'image.upload', msg)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
21:03:42.185 189949 ERROR glance.api.v2.image_data self.force_reraise()
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
21:03:42.185 189949 ERROR glance.api.v2.image_data raise self.value
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/notifier.py", line 443, in set_data
21:03:42.185 189949 ERROR glance.api.v2.image_data self.repo.set_data(data, size, backend=backend,
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/quota/__init__.py", line 322, in set_data
21:03:42.185 189949 ERROR glance.api.v2.image_data self.image.set_data(data, size=size, backend=backend,
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/location.py", line 585, in set_data
21:03:42.185 189949 ERROR glance.api.v2.image_data self._upload_to_store(data, verifier, backend, size)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/location.py", line 476, in _upload_to_store
21:03:42.185 189949 ERROR glance.api.v2.image_data multihash, loc_meta) = self.store_api.add_with_multihash(
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance_store/multi_backend.py", line 398, in add_with_multihash
21:03:42.185 189949 ERROR glance.api.v2.image_data return store_add_to_backend_with_multihash(
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance_store/multi_backend.py", line 480, in store_add_to_backend_with_multihash 21:03:42.185 189949 ERROR glance.api.v2.image_data (location, size, checksum, multihash, metadata) = store.add(
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance_store/driver.py", line 279, in add_adapter
21:03:42.185 189949 ERROR glance.api.v2.image_data metadata_dict) = store_add_fun(*args, **kwargs)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance_store/capabilities.py", line 176, in op_checker
21:03:42.185 189949 ERROR glance.api.v2.image_data return store_op_fun(store, *args, **kwargs)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance_store/_drivers/rbd.py", line 645, in add
21:03:42.185 189949 ERROR glance.api.v2.image_data raise exc
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance_store/_drivers/rbd.py", line 590, in add
21:03:42.185 189949 ERROR glance.api.v2.image_data for chunk in chunks:
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance_store/common/utils.py", line 73, in chunkiter
21:03:42.185 189949 ERROR glance.api.v2.image_data chunk = fp.read(chunk_size)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/common/utils.py", line 293, in read
21:03:42.185 189949 ERROR glance.api.v2.image_data result = self.data.read(i)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/common/utils.py", line 120, in readfn
21:03:42.185 189949 ERROR glance.api.v2.image_data result = fd.read(*args)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/common/format_inspector.py", line 658, in read
21:03:42.185 189949 ERROR glance.api.v2.image_data chunk = self._source.read(size)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/eventlet/wsgi.py", line 221, in read
21:03:42.185 189949 ERROR glance.api.v2.image_data return self._chunked_read(self.rfile, length)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/eventlet/wsgi.py", line 192, in _chunked_read
21:03:42.185 189949 ERROR glance.api.v2.image_data raise IOError("unexpected end of file while parsing chunked data")
21:03:42.185 189949 ERROR glance.api.v2.image_data OSError: unexpected end of file while parsing chunked data
21:03:42.185 189949 ERROR glance.api.v2.image_data
21:03:42.185 189949 ERROR glance.api.v2.image_data During handling of the above exception, another exception occurred:
21:03:42.185 189949 ERROR glance.api.v2.image_data
21:03:42.185 189949 ERROR glance.api.v2.image_data Traceback (most recent call last):
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/api/v2/image_data.py", line 66, in _restore
21:03:42.185 189949 ERROR glance.api.v2.image_data image_repo.save(image)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/notifier.py", line 530, in save
21:03:42.185 189949 ERROR glance.api.v2.image_data super(ImageRepoProxy, self).save(image, from_state=from_state)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/domain/proxy.py", line 99, in save
21:03:42.185 189949 ERROR glance.api.v2.image_data result = self.base.save(base_item, from_state=from_state)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/quota/__init__.py", line 121, in save
21:03:42.185 189949 ERROR glance.api.v2.image_data return super(ImageRepoProxy, self).save(image, from_state=from_state)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/domain/proxy.py", line 99, in save
21:03:42.185 189949 ERROR glance.api.v2.image_data result = self.base.save(base_item, from_state=from_state)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/location.py", line 82, in save
21:03:42.185 189949 ERROR glance.api.v2.image_data result = super(ImageRepoProxy, self).save(image, from_state=from_state)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/domain/proxy.py", line 99, in save
21:03:42.185 189949 ERROR glance.api.v2.image_data result = self.base.save(base_item, from_state=from_state)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/db/__init__.py", line 198, in save
21:03:42.185 189949 ERROR glance.api.v2.image_data new_values = self.db_api.image_update(self.context,
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/db/sqlalchemy/api.py", line 158, in image_update
21:03:42.185 189949 ERROR glance.api.v2.image_data image = _image_update(context, values, image_id, purge_props,
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/retrying.py", line 49, in wrapped_f
21:03:42.185 189949 ERROR glance.api.v2.image_data return Retrying(*dargs, **dkw).call(f, *args, **kw)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/retrying.py", line 206, in call
21:03:42.185 189949 ERROR glance.api.v2.image_data return attempt.get(self._wrap_exception)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/retrying.py", line 247, in get
21:03:42.185 189949 ERROR glance.api.v2.image_data six.reraise(self.value[0], self.value[1], self.value[2])
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/six.py", line 703, in reraise
21:03:42.185 189949 ERROR glance.api.v2.image_data raise value
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/retrying.py", line 200, in call
21:03:42.185 189949 ERROR glance.api.v2.image_data attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/common/utils.py", line 545, in wrapper
21:03:42.185 189949 ERROR glance.api.v2.image_data return f(*args, **kwargs)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/db/sqlalchemy/api.py", line 968, in _image_update
21:03:42.185 189949 ERROR glance.api.v2.image_data image_ref = _image_get(context, image_id, session=session)
21:03:42.185 189949 ERROR glance.api.v2.image_data File "/usr/lib/python3/dist-packages/glance/db/sqlalchemy/api.py", line 281, in _image_get
21:03:42.185 189949 ERROR glance.api.v2.image_data raise exception.ImageNotFound(msg)
21:03:42.185 189949 ERROR glance.api.v2.image_data glance.common.exception.ImageNotFound: No image found with ID 1f54570f-1e5d-4831-9249-8982cfeed544
```
It looks like the image may have been corrupted. These logs are a few min after the tempest test failure though.
Link to crashdumps:
https://oil-jenkins.canonical.com/artifacts/7f8576a7-d016-4ed2-b944-3c9fbd1ec16b/index.html
Hi Bas,
Are you still hitting this? If the image is corrupted I don't think it would be a charm bug.
If you hit this again some details from glance logs would likely be useful. I tried the first link but it looks like it's empty.
Thanks,
Corey