Created attachment 964633 [details] logs and etc Description of problem: Running automation , RHEL 7 with rhos6 , Here are tempest failed tests : tempest.api.volume.test_volumes_actions.VolumesV1ActionsTest.test_volume_upload[gate,image] 10 min 3 tempest.api.volume.test_volumes_actions.VolumesV2ActionsTest.test_volume_upload[gate,image] 10 min 3 tempest.scenario.test_encrypted_cinder_volumes.TestEncryptedCinderVolumes.test_encrypted_cinder_volumes_cryptsetup[compute,image,volume] 4 min 17 sec 3 tempest.scenario.test_encrypted_cinder_volumes.TestEncryptedCinderVolumes.test_encrypted_cinder_volumes_luks[compute,image,volume] 3 min 13 sec 3 tempest.scenario.test_snapshot_pattern.TestSnapshotPattern.test_snapshot_pattern[compute,image,network] from the glance.conf log we see : 2014-12-04 04:25:40.122 30692 DEBUG glance.common.client [c3aa3c1d-5b68-445c-bed7-1c8ab0d1dd3b bbc80770262b4e2e9a041335e40dae6c b3650dee8f084cb1bd1d67a9f7677581 - - -] Constructed URL: http://0.0.0.0:9191/images/d143565b-5ab8-424a-bbe2-9883da7fb279 _construct_url /usr/lib/python2.7/site-packages/glance/common/client.py:413 2014-12-04 04:25:40.149 30693 DEBUG glance_store._drivers.rbd [0cb5f4e1-2ca6-41bf-a8f7-88c11179efa9 bbc80770262b4e2e9a041335e40dae6c b3650dee8f084cb1bd1d67a9f7677581 - - -] writing chunk at offset 409694112 add /usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py:365 2014-12-04 04:25:40.167 30693 DEBUG glance_store._drivers.rbd [0cb5f4e1-2ca6-41bf-a8f7-88c11179efa9 bbc80770262b4e2e9a041335e40dae6c b3650dee8f084cb1bd1d67a9f7677581 - - -] writing chunk at offset 409702320 add /usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py:365 2014-12-04 04:25:40.198 30692 DEBUG glance.common.client [c3aa3c1d-5b68-445c-bed7-1c8ab0d1dd3b bbc80770262b4e2e9a041335e40dae6c b3650dee8f084cb1bd1d67a9f7677581 - - -] Constructed URL: http://0.0.0.0:9191/images/d143565b-5ab8-424a-bbe2-9883da7fb279 _construct_url /usr/lib/python2.7/site-packages/glance/common/client.py:413 2014-12-04 04:25:40.203 30692 INFO glance.registry.client.v1.client [c3aa3c1d-5b68-445c-bed7-1c8ab0d1dd3b bbc80770262b4e2e9a041335e40dae6c b3650dee8f084cb1bd1d67a9f7677581 - - -] Registry client request PUT /images/d143565b-5ab8-424a-bbe2-9883da7fb279 raised NotAuthenticated 2014-12-04 04:25:40.214 30693 DEBUG glance_store._drivers.rbd [0cb5f4e1-2ca6-41bf-a8f7-88c11179efa9 bbc80770262b4e2e9a041335e40dae6c b3650dee8f084cb1bd1d67a9f7677581 - - -] writing chunk at offset 409710528 add /usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py:365 2014-12-04 04:25:40.245 30693 DEBUG glance_store._drivers.rbd [0cb5f4e1-2ca6-41bf-a8f7-88c11179efa9 bbc80770262b4e2e9a041335e40dae6c b3650dee8f084cb1bd1d67a9f7677581 - - -] writing chunk at offset 409718736 add /usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py:365 2014-12-04 04:25:40.203 30692 ERROR glance.api.v1.upload_utils [c3aa3c1d-5b68-445c-bed7-1c8ab0d1dd3b bbc80770262b4e2e9a041335e40dae6c b3650dee8f084cb1bd1d67a9f7677581 - - -] Failed to upload image d143565b-5ab8-424a-bbe2-9883da7fb279 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils Traceback (most recent call last): 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/api/v1/upload_utils.py", line 158, in upload_data_to_store 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils from_state='saving') 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/registry/client/v1/api.py", line 169, in update_image_metadata 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils from_state=from_state) 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/registry/client/v1/client.py", line 198, in update_image 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils headers=headers) 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/registry/client/v1/client.py", line 130, in do_request 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils 'exc_name': exc_name}) 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/openstack/common/excutils.py", line 82, in __exit__ 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils six.reraise(self.type_, self.value, self.tb) 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/registry/client/v1/client.py", line 115, in do_request 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils **kwargs) 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/common/client.py", line 71, in wrapped 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils return func(self, *args, **kwargs) 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/common/client.py", line 388, in do_request 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils headers=copy.deepcopy(headers)) 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/common/client.py", line 85, in wrapped 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils return func(self, method, url, body, headers) 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils File "/usr/lib/python2.7/site-packages/glance/common/client.py", line 531, in _do_request 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils raise exception.NotAuthenticated(res.read()) 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils NotAuthenticated: Authentication required 2014-12-04 04:25:40.203 30692 TRACE glance.api.v1.upload_utils 2014-12-04 04:25:40.255 30692 DEBUG glance.registry.client.v1.api [c3aa3c1d-5b68-445c-bed7-1c8ab0d1dd3b bbc80770262b4e2e9a041335e40dae6c b3650dee8f084cb1bd1d67a9f7677581 - - -] Updating image metadata for image d143565b-5ab8-424a-bbe2-9883da7fb279... update_image_metadata /usr/lib/python2.7/site-packages/glance/registry/client/v1/api.py:166 Attaching tag.gz log files - /etc and /var/log . Version-Release number of selected component (if applicable): How reproducible: Steps to Reproduce: 1. 2. 3. Actual results: Expected results: Additional info:
Is the test re-using the keystone token? Are we sure the token is still valid? The expiration time in keystone is set to the default value `3600` and the registry service is raising a token validation error but this doesn't happen every time. Can this issue be reproduced deterministically? Are these the tests that fail all the time with the same error?
Run automation again , it was reproduced. http://storage-jenkins.scl.lab.tlv.redhat.com:8080/view/RHOS-6.0-RHEL-7.0/job/rhos-6-rdo-rhel-7.0-cinder-ceph-benny/8/ You can download the logs : http://storage-jenkins.scl.lab.tlv.redhat.com:8080/view/RHOS-6.0-RHEL-7.0/job/rhos-6-rdo-rhel-7.0-cinder-ceph-benny/8/artifact/log_cinder-ceph-OS-7.0-RHOS-6-BUILD-8.tar.gz Benny
I had the same issue & fixed by changing the expiration value in keystone.conf to a much higher value.
Hi Tyler , Is it really fixing the problem ? What happens when you set higher value ? Benny
Benny, The links to the logs have expired :( By increasing the expiration time, the token will last longer which is advisable when uploads may take a long time (big big files, not enough bandwidth, etc). This is a workaround for a known issue (lacking feature) in the client library. See [0] for more info. [0] https://bugzilla.redhat.com/show_bug.cgi?id=1132634 Benny, can you confirm/deny the token expiration is the cause of your issue? I tried running tempest tests in a fresh devstack deployment and it worked.
close base on comment #6 and chat with Benny.
The needinfo request[s] on this closed bug have been removed as they have been unresolved for 1000 days