TestVolumeSwap.test_volume_swap fails in cells v1 job waiting for first volume to detach

[Matt Riedemann]

Ever since https://review.openstack.org/#/c/374373/ and https://review.openstack.org/#/c/399735/ merged today I've seen at least two changes in the gate get bumped out due to the swap volume test failing in the cells v1 job, seen here:

http://logs.openstack.org/06/425806/8/check/gate-tempest-dsvm-cells-ubuntu-xenial/ab0bba2/console.html#_2017-01-31_01_48_47_209159

2017-01-31 01:48:47.209256 | Captured traceback:
2017-01-31 01:48:47.209267 | ~~~~~~~~~~~~~~~~~~~
2017-01-31 01:48:47.209316 | Traceback (most recent call last):
2017-01-31 01:48:47.209350 | File "tempest/test.py", line 99, in wrapper
2017-01-31 01:48:47.209375 | return f(self, *func_args, **func_kwargs)
2017-01-31 01:48:47.209404 | File "tempest/api/compute/admin/test_volume_swap.py", line 64, in test_volume_swap
2017-01-31 01:48:47.209420 | volume1['id'], 'available')
2017-01-31 01:48:47.209445 | File "tempest/common/waiters.py", line 189, in wait_for_volume_status
2017-01-31 01:48:47.209465 | raise lib_exc.TimeoutException(message)
2017-01-31 01:48:47.209486 | tempest.lib.exceptions.TimeoutException: Request timed out
2017-01-31 01:48:47.209530 | Details: Volume e4fede42-0453-45b0-88c4-5285ca1fbf11 failed to reach available status (current detaching) within the required time (196 s).

It looks like it's also hitting the ceph job:

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Details%3A%20Volume%5C%22%20AND%20message%3A%5C%22failed%20to%20reach%20available%20status%20(current%20detaching)%20within%20the%20required%20time%5C%22%20AND%20tags%3A%5C%22console%5C%22%20AND%20voting%3A1&from=7d

Note that the devstack change to enable the test does not run the ceph or cells v1 job in the check queue, so we were likely not going to see the failure until AFTER the nova and devstack patches all merged.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Change abandoned by Matt Riedemann (<email address hidden>) on branch: master
Review: https://review.openstack.org/427013
Reason: Don't need this now since the devstack patch is approved:

https://review.openstack.org/#/c/427009/

[Matt Riedemann (mriedem)]

Here is the pretty obvious failure in the cells v1 logs:

http://logs.openstack.org/06/425806/8/check/gate-tempest-dsvm-cells-ubuntu-xenial/ab0bba2/logs/screen-n-cell-child.txt.gz?level=TRACE#_2017-01-31_01_25_10_115

2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging [req-a820f01f-ff4d-4c62-8a71-ba509d2061aa tempest-TestVolumeSwap-893937839 tempest-TestVolumeSwap-893937839] Error processing message locally
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging Traceback (most recent call last):
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/cells/messaging.py", line 188, in _process_locally
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging resp_value = self.msg_runner._process_message_locally(self)
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/cells/messaging.py", line 1275, in _process_message_locally
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging return fn(message, **message.method_kwargs)
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/cells/messaging.py", line 677, in run_compute_api_method
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging return fn(message.ctxt, *args, **method_info['method_kwargs'])
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/compute/api.py", line 170, in inner
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging return function(self, context, instance, *args, **kwargs)
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/compute/api.py", line 151, in inner
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging return f(self, context, instance, *args, **kw)
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/compute/api.py", line 3697, in detach_volume
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging self._detach_volume(context, instance, volume)
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/compute/api.py", line 3665, in _detach_volume
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging self._check_and_begin_detach(context, volume, instance)
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/compute/api.py", line 3657, in _check_and_begin_detach
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging self.volume_api.begin_detaching(context, volume['id'])
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/volume/cinder.py", line 176, in wrapper
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging _reraise(exception.InvalidInput(reason=err_msg))
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/volume/cinder.py", line 226, in _reraise
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging six.reraise(type(desired_exc), desired_exc, sys.exc_info()[2])
2017-01-31 01:25:10.115 25247 ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/volume/cinder.py", line 168, in wrapper
2017-01-31 01:25:10.115 25247 ERROR nova.c...

[Matt Riedemann (mriedem)]

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22TestVolumeSwap%5C%22%20AND%20message%3A%5C%22Error%20processing%20message%20locally%5C%22%20AND%20message%3A%5C%22_check_and_begin_detach%5C%22%20AND%20message%3A%5C%22Invalid%20volume%3A%20Unable%20to%20detach%20volume.%20Volume%20status%20must%20be%20'in-use'%20and%20attach_status%20must%20be%20'attached'%20to%20detach.%5C%22%20AND%20tags%3A%5C%22screen-n-cell-child.txt%5C%22&from=7d

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/427009
Committed: https://git.openstack.org/cgit/openstack-dev/devstack/commit/?id=e9a9fbef8fc29437d1f69727e2ab73c31e957488
Submitter: Jenkins
Branch: master

commit e9a9fbef8fc29437d1f69727e2ab73c31e957488
Author: Matt Riedemann <email address hidden>
Date: Mon Jan 30 22:22:43 2017 -0500

    Don't run swap_volume tests in Tempest if cells v1 is enabled

    Cells v1 apparently doesn't support the swap volume API which
    was recently enabled for testing in change:

    92575baa6b010ec09fea3e715030da8be61c0c64

    Rather than revert that change, we should just handle the cells
    v1 case and not enable that test in that environment.

    Change-Id: I80f52e8299641098d90d3c374a80770fc45b8122
    Closes-Bug: #1660511

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/newton
Review: https://review.openstack.org/442548

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/442548
Committed: https://git.openstack.org/cgit/openstack-dev/devstack/commit/?id=a0c2fe25cbeae1ee6a386a1a43b54d97098dbfd1
Submitter: Jenkins
Branch: stable/newton

commit a0c2fe25cbeae1ee6a386a1a43b54d97098dbfd1
Author: Matt Riedemann <email address hidden>
Date: Mon Jan 30 22:22:43 2017 -0500

    Don't run swap_volume tests in Tempest if cells v1 is enabled

    Cells v1 apparently doesn't support the swap volume API which
    was recently enabled for testing in change:

    92575baa6b010ec09fea3e715030da8be61c0c64

    Rather than revert that change, we should just handle the cells
    v1 case and not enable that test in that environment.

    Change-Id: I80f52e8299641098d90d3c374a80770fc45b8122
    Closes-Bug: #1660511
    (cherry picked from commit e9a9fbef8fc29437d1f69727e2ab73c31e957488)