Bug 1410046 - Multiple attempts made to delete iSCSI multipath path devices
Summary: Multiple attempts made to delete iSCSI multipath path devices
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-nova
Version: 7.0 (Kilo)
Hardware: x86_64
OS: Linux
high
high
Target Milestone: async
: 7.0 (Kilo)
Assignee: Lee Yarwood
QA Contact: Prasanth Anbalagan
URL:
Whiteboard:
: 1278209 (view as bug list)
Depends On:
Blocks: 1290377
TreeView+ depends on / blocked
 
Reported: 2017-01-04 10:32 UTC by Lee Yarwood
Modified: 2022-07-09 08:46 UTC (History)
12 users (show)

Fixed In Version: openstack-nova-2015.1.4-27.el7ost
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-02-15 23:00:32 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker OSP-16821 0 None None None 2022-07-09 08:46:39 UTC
Red Hat Product Errata RHSA-2017:0282 0 normal SHIPPED_LIVE Moderate: openstack-cinder, openstack-glance, and openstack-nova security update 2017-02-16 03:52:44 UTC

Description Lee Yarwood 2017-01-04 10:32:00 UTC 
Description of problem:

Multiple attempts are currently made to delete iSCSI multipath path devices when diconnecting iSCSI volumes backed by multipath.

These attempts are the result of lookup code within _delete_mpath incorrectly matching multiple host devices with a given IQN and LUN id on some hosts.

For example the following shows a race between two _delete_device calls with the latter call finding no /sys/block/sdi/device/delete file :

  2016-12-20 18:38:01.726 2515 ERROR oslo_messaging.rpc.dispatcher [req-eb6be5e8-3cf3-4b2d-a2e8-6c63adfc93fb 8395d7bfaf1a4ccb9f50715715addb98 1a62694ef28744cca1411497daf8aadc - - -] Exception during message handling: Unexpected error while running command.
  Command: sudo nova-rootwrap /etc/nova/rootwrap.conf cp /dev/stdin /sys/block/sdi/device/delete
  Exit code: 1
  Stdout: u''
  Stderr: '/bin/cp: cannot create regular file \xe2\x80\x98/sys/block/sdi/device/delete\xe2\x80\x99: No such file or directory\n'
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last):
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     executor_callback))
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     executor_callback)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     result = func(ctxt, **new_args)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6818, in detach_volume
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     return self.manager.detach_volume(ctxt, volume_id, instance=instance)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 461, in decorated_function
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     payload)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     return f(self, context, *args, **kw)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 341, in decorated_function
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     LOG.warning(msg, e, instance_uuid=instance_uuid)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 312, in decorated_function
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 369, in decorated_function
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     kwargs['instance'], e, sys.exc_info())
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 357, in decorated_function
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 5010, in detach_volume
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     self._detach_volume(context, volume_id, instance)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 4991, in _detach_volume
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     self._driver_detach_volume(context, instance, bdm)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 4954, in _driver_detach_volume
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     self.volume_api.roll_detaching(context, volume_id)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 4942, in _driver_detach_volume
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     encryption=encryption)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 1364, in detach_volume
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     self._disconnect_volume(connection_info, disk_dev)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 1073, in _disconnect_volume
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     return driver.disconnect_volume(connection_info, disk_dev)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 445, in inner
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     return f(*args, **kwargs)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/volume.py", line 617, in disconnect_volume
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     multipath_device)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/volume.py", line 731, in _disconnect_volume_multipath_iscsi
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     self._delete_mpath(iscsi_properties, multipath_device, ips_iqns)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/volume.py", line 866, in _delete_mpath
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     self._delete_device(dev)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/volume.py", line 671, in _delete_device
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     process_input='1', run_as_root=True)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/utils.py", line 214, in execute
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     return processutils.execute(*cmd, **kwargs)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_concurrency/processutils.py", line 333, in execute
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher     cmd=sanitized_cmd)
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher Command: sudo nova-rootwrap /etc/nova/rootwrap.conf cp /dev/stdin /sys/block/sdi/device/delete
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher Exit code: 1
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher Stdout: u''
  2016-12-20 18:38:01.726 2515 TRACE oslo_messaging.rpc.dispatcher Stderr: '/bin/cp: cannot create regular file \xe2\x80\x98/sys/block/sdi/device/delete\xe2\x80\x99: No such file or directory\n'

The duplicate calls can also result in the following warning if the os.path.exists() check fails in _delete_device : 

  2016-12-20 19:03:21.870 2515 WARNING nova.virt.libvirt.volume [req-2d93f5c5-888b-4ec5-bdea-78beaf78129e 8395d7bfaf1a4ccb9f50715715addb98 1a62694ef28744cca1411497daf8aadc - - -] Unable to delete volume device sdi

Version-Release number of selected component (if applicable):
openstack-nova-2015.1.4-22.el7ost

How reproducible:
Always

Steps to Reproduce:
1. Using a multipath enabled iSCSI backend attach and detach volumes from an instance.

Actual results:
Multiple calls are made to delete each path device making up the overall multipath device.

Expected results:
Only a single call to delete each path device is made.

Additional info:
Comment 9 Lee Yarwood 2017-01-20 20:46:03 UTC 
*** Bug 1278209 has been marked as a duplicate of this bug. ***
Comment 14 errata-xmlrpc 2017-02-15 23:00:32 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHSA-2017-0282.html
Note You need to log in before you can comment on or make changes to this bug.