tempest test_extend_share fails due to concurrency issues

[Valeriy Ponomaryov]

Tempest test "test_extend_share" fails in our gates dues to concurrency issues with following trace:

http://logs.openstack.org/43/190043/1/gate/gate-manila-tempest-dsvm-neutron-multibackend/025fffa/logs/screen-m-shr.txt.gz#_2015-06-10_08_34_04_367

Or raw text:

2015-06-10 08:34:04.367 11161 ERROR manila.share.manager [req-2c1d1269-fe5c-4e85-9dcf-942f1c3d7930 ] Extend share failed.
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager Traceback (most recent call last):
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/opt/stack/new/manila/manila/share/manager.py", line 863, in extend_share
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager share, new_size, share_server=share_server)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/opt/stack/new/manila/manila/share/drivers/generic.py", line 119, in wrap
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager return f(self, *args, **kwargs)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/opt/stack/new/manila/manila/share/drivers/generic.py", line 558, in extend_share
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager volume)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/opt/stack/new/manila/manila/share/drivers/generic.py", line 360, in _attach_volume
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager return do_attach(volume)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 445, in inner
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager return f(*args, **kwargs)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/opt/stack/new/manila/manila/share/drivers/generic.py", line 345, in do_attach
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager volume['id'],
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/opt/stack/new/manila/manila/compute/nova.py", line 154, in wrapper
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager res = method(self, ctx, instance_id, *args, **kwargs)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/opt/stack/new/manila/manila/compute/nova.py", line 253, in instance_volume_attach
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager device)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/usr/local/lib/python2.7/dist-packages/novaclient/v2/volumes.py", line 146, in create_server_volume
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager body, "volumeAttachment")
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/usr/local/lib/python2.7/dist-packages/novaclient/base.py", line 161, in _create
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager _resp, body = self.api.client.post(url, body=body)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 454, in post
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager return self._cs_request(url, 'POST', **kwargs)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 429, in _cs_request
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager resp, body = self._time_request(url, method, **kwargs)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 402, in _time_request
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager resp, body = self.request(url, method, **kwargs)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager File "/usr/local/lib/python2.7/dist-packages/novaclient/client.py", line 396, in request
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager raise exceptions.from_response(resp, body, url, method)
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager InvalidInput: Invalid input received: Invalid volume: volume 'b789a687-8ca1-4942-ad8d-67ac1b5285bf' status must be 'available'. Currently in 'extending'.
2015-06-10 08:34:04.367 11161 ERROR manila.share.manager
2015-06-10 08:34:04.401 11161 DEBUG manila.quota [req-2c1d1269-fe5c-4e85-9dcf-942f1c3d7930 ] Rolled back reservations [u'a85c2738-9451-4d9a-bdfc-1c1d93768d9e'] rollback /opt/stack/new/manila/manila/quota.py:1012
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher [req-2c1d1269-fe5c-4e85-9dcf-942f1c3d7930 ] Exception during message handling: Share 3f60f121-6663-44cb-aa71-bd8a1b57ce52 could not be extended due to error in the driver: Invalid input received: Invalid volume: volume 'b789a687-8ca1-4942-ad8d-67ac1b5285bf' status must be 'available'. Currently in 'extending'.
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher executor_callback))
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher executor_callback)
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args)
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher File "/opt/stack/new/manila/manila/share/manager.py", line 873, in extend_share
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher reason=six.text_type(e), share_id=share_id)
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher ShareExtendingError: Share 3f60f121-6663-44cb-aa71-bd8a1b57ce52 could not be extended due to error in the driver: Invalid input received: Invalid volume: volume 'b789a687-8ca1-4942-ad8d-67ac1b5285bf' status must be 'available'. Currently in 'extending'.
2015-06-10 08:34:04.403 11161 ERROR oslo_messaging.rpc.dispatcher

[Valeriy Ponomaryov (vponomaryov)]

Set "high" priority due to influence on gates.

[Igor Malinovskiy (imalinovskiy)]

It's Cinder concurrency issue. Cinder returns volume with status 'active' to Manila and then returns volume with 'extending' status to Nova. The best what we could do in Manila - add sleep() before https://github.com/openstack/manila/blob/a38d5d03fa99bfd14ff2a79e232873693dc1bba7/manila/share/drivers/generic.py#L553

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/190969

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/190969
Committed: https://git.openstack.org/cgit/openstack/manila/commit/?id=0902169ad736d49dd6991d0f451b6b505e39a4b8
Submitter: Jenkins
Branch: master

commit 0902169ad736d49dd6991d0f451b6b505e39a4b8
Author: Igor Malinovskiy <email address hidden>
Date: Tue Jun 16 15:40:13 2015 +0300

    Add retry on volume attach error in Generic driver

    Change-Id: I9937de261f4e7de910cdf1fd0d68fac46016ea5d
    Closes-Bug: #1463718