tempest.api.volume.test_volumes_get.VolumesGetTest.test_volume_create_get_update_delete fails in gate

[Peter Portante]

See: http://logs.openstack.org/57/85457/1/check/check-grenade-dsvm/145a320/console.html
http://logs.openstack.org/57/85457/1/check/check-grenade-dsvm/145a320/logs/new/screen-c-vol.txt.gz

2014-04-07 22:25:08.253 19916 ERROR oslo.messaging.rpc.dispatcher [req-73545fcd-80bd-490e-84d0-1e72236da083 4af4d5123644420ca7b05c04f160c0dd c797028d5542478fa2e7b2d5b73bd24d - - -] Exception during message handling: Unexpected error while running command.
Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf lvremove -f stack-volumes/volume-bb1cafb5-7b76-458e-91e4-787569baf68a
Exit code: 5
Stdout: ''
Stderr: ' Can\'t remove open logical volume "volume-bb1cafb5-7b76-458e-91e4-787569baf68a"\n'
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/old/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher incoming.message))
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/old/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/old/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/volume/manager.py", line 144, in lvo_inner1
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher return lvo_inner2(inst, context, volume_id, **kwargs)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/openstack/common/lockutils.py", line 233, in inner
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher retval = f(*args, **kwargs)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/volume/manager.py", line 143, in lvo_inner2
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher return f(*_args, **_kwargs)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/volume/manager.py", line 416, in delete_volume
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher {'status': 'error_deleting'})
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/openstack/common/excutils.py", line 68, in __exit__
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/volume/manager.py", line 405, in delete_volume
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher self.driver.delete_volume(volume_ref)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/volume/drivers/lvm.py", line 233, in delete_volume
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher self._delete_volume(volume)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/volume/drivers/lvm.py", line 133, in _delete_volume
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher self.vg.delete(name)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/brick/local_dev/lvm.py", line 610, in delete
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher root_helper=self._root_helper, run_as_root=True)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/utils.py", line 136, in execute
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher return processutils.execute(*cmd, **kwargs)
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/cinder/cinder/openstack/common/processutils.py", line 173, in execute
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher cmd=' '.join(cmd))
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf lvremove -f stack-volumes/volume-bb1cafb5-7b76-458e-91e4-787569baf68a
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher Exit code: 5
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher Stdout: ''
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher Stderr: ' Can\'t remove open logical volume "volume-bb1cafb5-7b76-458e-91e4-787569baf68a"\n'
2014-04-07 22:25:08.253 19916 TRACE oslo.messaging.rpc.dispatcher
2014-04-07 22:25:08.257 19916 ERROR oslo.messaging._drivers.common [req-73545fcd-80bd-490e-84d0-1e72236da083 4af4d5123644420ca7b05c04f160c0dd c797028d5542478fa2e7b2d5b73bd24d - - -] Returning exception Unexpected error while running command.
Command: sudo cinder-rootwrap /etc/cinder/rootwrap.conf lvremove -f stack-volumes/volume-bb1cafb5-7b76-458e-91e4-787569baf68a
Exit code: 5
Stdout: ''
Stderr: ' Can\'t remove open logical volume "volume-bb1cafb5-7b76-458e-91e4-787569baf68a"\n' to caller
2014-04-07 22:25:08.257 19916 ERROR oslo.messaging._drivers.common [req-73545fcd-80bd-490e-84d0-1e72236da083 4af4d5123644420ca7b05c04f160c0dd c797028d5542478fa2e7b2d5b73bd24d - - -] ['Traceback (most recent call last):\n', ' File "/opt/stack/old/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply\n incoming.message))\n', ' File "/opt/stack/old/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch\n return self._do_dispatch(endpoint, method, ctxt, args)\n', ' File "/opt/stack/old/oslo.messaging/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch\n result = getattr(endpoint, method)(ctxt, **new_args)\n', ' File "/opt/stack/new/cinder/cinder/volume/manager.py", line 144, in lvo_inner1\n return lvo_inner2(inst, context, volume_id, **kwargs)\n', ' File "/opt/stack/new/cinder/cinder/openstack/common/lockutils.py", line 233, in inner\n retval = f(*args, **kwargs)\n', ' File "/opt/stack/new/cinder/cinder/volume/manager.py", line 143, in lvo_inner2\n return f(*_args, **_kwargs)\n', ' File "/opt/stack/new/cinder/cinder/volume/manager.py", line 416, in delete_volume\n {\'status\': \'error_deleting\'})\n', ' File "/opt/stack/new/cinder/cinder/openstack/common/excutils.py", line 68, in __exit__\n six.reraise(self.type_, self.value, self.tb)\n', ' File "/opt/stack/new/cinder/cinder/volume/manager.py", line 405, in delete_volume\n self.driver.delete_volume(volume_ref)\n', ' File "/opt/stack/new/cinder/cinder/volume/drivers/lvm.py", line 233, in delete_volume\n self._delete_volume(volume)\n', ' File "/opt/stack/new/cinder/cinder/volume/drivers/lvm.py", line 133, in _delete_volume\n self.vg.delete(name)\n', ' File "/opt/stack/new/cinder/cinder/brick/local_dev/lvm.py", line 610, in delete\n root_helper=self._root_helper, run_as_root=True)\n', ' File "/opt/stack/new/cinder/cinder/utils.py", line 136, in execute\n return processutils.execute(*cmd, **kwargs)\n', ' File "/opt/stack/new/cinder/cinder/openstack/common/processutils.py", line 173, in execute\n cmd=\' \'.join(cmd))\n', 'ProcessExecutionError: Unexpected error while running command.\nCommand: sudo cinder-rootwrap /etc/cinder/rootwrap.conf lvremove -f stack-volumes/volume-bb1cafb5-7b76-458e-91e4-787569baf68a\nExit code: 5\nStdout: \'\'\nStderr: \' Can\\\'t remove open logical volume "volume-bb1cafb5-7b76-458e-91e4-787569baf68a"\\n\'\n']

[John Griffith (john-griffith)]

It looks like this was introduced here: Change-Id: I4703133180567090878ea5047dd29d9f97ad85ab

Trying to track down the problem.

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/86480
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=f9519182f4a6e6573513d8dbc9438702fc7b8644
Submitter: Jenkins
Branch: master

commit f9519182f4a6e6573513d8dbc9438702fc7b8644
Author: John Griffith <email address hidden>
Date: Thu Apr 10 00:10:08 2014 +0000

    Check for silent failure of tgtadm remove

    In order to work around a failure to remove targets that
    had a reconnect the force flag was added to the tgt delete cmd.
        (https://bugs.launchpad.net/cinder/+bug/1159948)

    It turns out there's a bug in tgt where some versions will
    sometimes silently fail when using the force flag.
        (https://bugs.launchpad.net/ubuntu/+source/tgt/+bug/1305343)

    The problem is that in the gates since we merged the force change
    there's a very high number of cases where lvremove fails because
    the device is still active. It appears that this is a result of
    the silent force failures in target.

    This patch adds a simple check after the force target removal,
    if it detects the target is still present it reverts back to the old
    non-force method to catch the cases that don't actually need the
    force option.

    This is a work-around until the version of target in the distros
    is updated and can be used reliably, but closes the gate issue
    bug that was reported.

    Change-Id: I9150669040815e4831bd570964d12676b83ecbc9
    Close-Bug: #1304122

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: milestone-proposed
Review: https://review.openstack.org/87361

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/87361
Committed: https://git.openstack.org/cgit/openstack/cinder/commit/?id=e5c45bf88448b231a3252aa2628d6cf5bd9aa730
Submitter: Jenkins
Branch: milestone-proposed

commit e5c45bf88448b231a3252aa2628d6cf5bd9aa730
Author: John Griffith <email address hidden>
Date: Thu Apr 10 00:10:08 2014 +0000

    Check for silent failure of tgtadm remove

    In order to work around a failure to remove targets that
    had a reconnect the force flag was added to the tgt delete cmd.
        (https://bugs.launchpad.net/cinder/+bug/1159948)

    It turns out there's a bug in tgt where some versions will
    sometimes silently fail when using the force flag.
        (https://bugs.launchpad.net/ubuntu/+source/tgt/+bug/1305343)

    The problem is that in the gates since we merged the force change
    there's a very high number of cases where lvremove fails because
    the device is still active. It appears that this is a result of
    the silent force failures in target.

    This patch adds a simple check after the force target removal,
    if it detects the target is still present it reverts back to the old
    non-force method to catch the cases that don't actually need the
    force option.

    This is a work-around until the version of target in the distros
    is updated and can be used reliably, but closes the gate issue
    bug that was reported.

    Change-Id: I9150669040815e4831bd570964d12676b83ecbc9
    Close-Bug: #1304122
    (cherry picked from commit f9519182f4a6e6573513d8dbc9438702fc7b8644)