Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1441066

Summary:	[RHOSP10] An instance failed to reboot even if only one path of the multipath was failed.
Product:	Red Hat OpenStack	Reporter:	weiguo fan <fan-wxa>
Component:	python-os-brick	Assignee:	Gorka Eguileor <geguileo>
Status:	CLOSED ERRATA	QA Contact:	Avi Avraham <aavraham>
Severity:	high	Docs Contact:
Priority:	high
Version:	10.0 (Newton)	CC:	acanan, berrange, cchen, dasmith, eglynn, eharney, geguileo, hfukumot, kchamart, knoha, lhh, lyarwood, mas-hatada, mwitt, panbalag, pgrist, redhat-bz, rhel-osp-bz, sbauza, sferdjao, sgordon, sputhenp, srevivo, vaggarwa, vromanso, ykawada
Target Milestone:	z5	Keywords:	Triaged, ZStream
Target Release:	10.0 (Newton)
Hardware:	x86_64
OS:	Linux
Whiteboard:
Fixed In Version:	python-os-brick-1.6.1-5.el7ost	Doc Type:	Bug Fix
Doc Text:	Complete refactoring of the iSCSI connection mechanism for improved reliability. For optimum results, use with openstack-cinder version 9.1.4-7 or higher and iscsi-initiator-utils version 6.2.0.874-2 or higher.	Story Points:	---
Clone Of:	1436116	Environment:
Last Closed:	2017-09-28 16:35:22 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:	1422941
Bug Blocks:	1389374, 1428662, 1442637, 1501950, 1502013

Description weiguo fan 2017-04-11 07:01:34 UTC

1. Bug Overview:
a) Description of bug report: 

  [RHOSP10] An instance failed to reboot even if only one path of the multipath was failed.

b) Bug Description:
 We report CASE#01818466 and BZ#1436116 against RHEL-OSP7.
 After that we found the similar problem also exists on RHOSP10.

 In RHOSP10 environment with iSCSI multipath cinder backend, if the connection of the first path in 
 connection_info (by 'target_portals','target_iqns') which was passed from cinder was failed, instance 
 with volume attached would failed during hard reboot with the following error messages outputted from 
 nova-compute.log.

 ================================================
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server [req-20a24305-2671-4bc4-93f3-a27d821eb2f0 dbcaea1aaa0f45238d41ce92bc7edc85 740b0875d34e41b98f8402dca3aef1db - - -] Exception during message handling
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 133, in _process_incoming
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 150, in dispatch
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 121, in _do_dispatch
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 75, in wrapped
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     function_name, call_dict, binary)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     self.force_reraise()
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     six.reraise(self.type_, self.value, self.tb)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 66, in wrapped
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     return f(self, context, *args, **kw)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 188, in decorated_function
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     LOG.warning(msg, e, instance=instance)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     self.force_reraise()
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     six.reraise(self.type_, self.value, self.tb)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 157, in decorated_function
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     return function(self, context, *args, **kwargs)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/utils.py", line 613, in decorated_function
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     return function(self, context, *args, **kwargs)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 216, in decorated_function
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     kwargs['instance'], e, sys.exc_info())
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     self.force_reraise()
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     six.reraise(self.type_, self.value, self.tb)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 204, in decorated_function
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     return function(self, context, *args, **kwargs)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2973, in reboot_instance
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     self._set_instance_obj_error_state(context, instance)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     self.force_reraise()
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     six.reraise(self.type_, self.value, self.tb)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2954, in reboot_instance
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     bad_volumes_callback=bad_volumes_callback)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2223, in reboot
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     block_device_info)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2307, in _hard_reboot
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     block_device_info=block_device_info)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4681, in _get_guest_xml
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     context)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4509, in _get_guest_config
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     flavor, guest.os_type)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3524, in _get_guest_storage_config
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     self._connect_volume(connection_info, info)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 1099, in _connect_volume
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     vol_driver.connect_volume(connection_info, disk_info)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/volume/iscsi.py", line 64, in connect_volume
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     device_info = self.connector.connect_volume(connection_info['data'])
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/os_brick/utils.py", line 145, in trace_logging_wrapper
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     result = f(*args, **kwargs)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 271, in inner
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     return f(*args, **kwargs)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/os_brick/initiator/connectors/iscsi.py", line 437, in connect_volume
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     device_wwn = self._linuxscsi.get_scsi_wwn(host_device)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py", line 112, in get_scsi_wwn
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     root_helper=self._root_helper)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/os_brick/executor.py", line 49, in _execute
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     result = self.__execute(*args, **kwargs)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/os_brick/privileged/rootwrap.py", line 57, in execute
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     return execute_root(*cmd, **kwargs)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_privsep/priv_context.py", line 204, in _wrap
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     return self.channel.remote_call(name, args, kwargs)
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_privsep/daemon.py", line 187, in remote_call
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server     raise exc_type(*result[2])
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server ProcessExecutionError: Unexpected error while running command.
 2017-03-24 10:12:19.950 7925 ERROR oslo_messaging.rpc.server Command: /lib/udev/scsi_id --page 0x83 --whitelisted /dev/disk/by-path/ip-192.168.2.5:3260-iscsi-iqn.2010-10.org.openstack:volume-634d01ac-a027-43bf-a5ab-d067930eab2a-lun-0
 ================================================

 According to our investigating, it seems these are some problems with ISCSIConnector in os-brick.

 To reconnect a sessions already existing multipathed volume to a existing instance, nova calls connect_volume()
 of ISCSIConnector in os-brick. It only trys to get the multipath_id with the device of the first path by using
 "scsi_id" command. If the connection of the first path failed, "scsi_id" command can't get the multipath_id with
 its device.
 ================================================
 # multipath -l
 36001405845964145caf4500a8f4e434e dm-0 LIO-ORG ,IBLOCK
 size=1.0G features='0' hwhandler='0' wp=rw
 |-+- policy='service-time 0' prio=0 status=enabled
 | `- 21:0:0:0 sda 8:0  failed faulty running <-- this path was failed.
 `-+- policy='service-time 0' prio=0 status=active
   `- 22:0:0:0 sdb 8:16 active undef  running

 # ls -l /dev/disk/by-path/ip-192.168.*
 lrwxrwxrwx. 1 root root 9 Mar 27 13:35 /dev/disk/by-path/ip-192.168.1.18:3260-iscsi-iqn.2010-10.org.openstack:volume-634d01ac-a027-43bf-a5ab-d067930eab2a-lun-0 -> ../../sdb
 lrwxrwxrwx. 1 root root 9 Mar 27 13:35 /dev/disk/by-path/ip-192.168.2.5:3260-iscsi-iqn.2010-10.org.openstack:volume-634d01ac-a027-43bf-a5ab-d067930eab2a-lun-0 -> ../../sda

 # /lib/udev/scsi_id --page 0x83 --whitelisted /dev/disk/by-path/ip-192.168.2.5\:3260-iscsi-iqn.2010-10.org.openstack\:volume-634d01ac-a027-43bf-a5ab-d067930eab2a-lun-0
   <-- "scsi_id" command can't get multipath_id with failed path.
 # /lib/udev/scsi_id --page 0x83 --whitelisted /dev/disk/by-path/ip-192.168.1.18\:3260-iscsi-iqn.2010-10.org.openstack\:volume-634d01ac-a027-43bf-a5ab-d067930eab2a-lun-0
 36001405845964145caf4500a8f4e434e   <-- "scsi_id" command can get multipath_id with the conneting well path.
 ================================================

 connect_volume() of ISCSIConnector in os-brick doesn't have exception for execution of "scsi_id" command,
 and doesn't try to get multipath_id with the left paths' device when the connection of the first path failed. 
 So, when the connection of the first path failed, a exception occurs during connect_volume() tring to get
 multipath_id. As a resault the instance failed to boot up.

    ------------nova/virt/libvirt/volume/iscsi.py-------------------------
    def connect_volume(self, connection_info, disk_info):
        """Attach the volume to instance_name.""" 

        LOG.debug("Calling os-brick to attach iSCSI Volume")
        device_info = self.connector.connect_volume(connection_info['data']) <-- Nova calls connect_volume() os os-brick.
        LOG.debug("Attached iSCSI volume %s", device_info)

        connection_info['data']['device_path'] = device_info['path']

    ------------------os_brick/initiator/connectors/iscsi.py--------------
    @utils.trace
    @synchronized('connect_volume')
    def connect_volume(self, connection_properties):
        ....
        # Choose an accessible host device
        host_device = next(dev for dev in host_devices if os.path.exists(dev))
          <-- Specify the first path to host_device.
        # find out the WWN of the device
        device_wwn = self._linuxscsi.get_scsi_wwn(host_device)
          <-- Try to get multipath_id with the first path using "scsi_id" command
          <-- No exception handle here. The processing will break up here when the connection of the first path was cut.
        LOG.debug("Device WWN = '%(wwn)s'", {'wwn': device_wwn})
        device_info['scsi_wwn'] = device_wwn

        if self.use_multipath:
            (host_device, multipath_id) = (super(
                ISCSIConnector, self)._discover_mpath_device(
                device_wwn, connection_properties, host_device))

            if multipath_id:
                device_info['multipath_id'] = multipath_id

        device_info['path'] = host_device

        LOG.debug("connect_volume returning %s", device_info)
        return device_info

    -------------os_brick/initiator/linuxscsi.py--------------------------
    def get_scsi_wwn(self, path):
        """Read the WWN from page 0x83 value for a SCSI device.""" 

        (out, _err) = self._execute('/lib/udev/scsi_id', '--page', '0x83',
                                    '--whitelisted', path,
                                    run_as_root=True,
                                    root_helper=self._root_helper)
              <-- Run "scsi_id" command to get multipath_id. It can't get multipath_id with the failed path
        return out.strip()

 I think connect_volume() of ISCSIConnector in os-brick should have a exception handle for 
 "device_wwn = self._linuxscsi.get_scsi_wwn(host_device)" line, and it should try all the paths
 to get multipath_id.

 When I modified the connect_volume() of ISCSIConnector in os-brick as follows, 
 the problem can be fixed on our environment.
  ========================================
  --- a/initiator/connectors/iscsi.py
  +++ b/initiator/connectors/iscsi.py
  @@ -434,7 +434,17 @@ class ISCSIConnector(base.BaseLinuxConnector, base_iscsi.BaseISCSIConnector):
           host_device = next(dev for dev in host_devices if os.path.exists(dev))

           # find out the WWN of the device
  -        device_wwn = self._linuxscsi.get_scsi_wwn(host_device)
  +        for dev in host_devices:
  +            if not os.path.exists(dev):
  +                continue
  +
  +            try:
  +                device_wwn = self._linuxscsi.get_scsi_wwn(dev)
  +                if device_wwn:
  +                    break
  +            except:
  +                LOG.warning("Failed to get scsi wwn with %s", dev)
  +
           LOG.debug("Device WWN = '%(wwn)s'", {'wwn': device_wwn})
           device_info['scsi_wwn'] = device_wwn
  =======================================

 It has a big business impact for users who use iSCSI multipath for their cinder backend.
 Could Red Hat fix this problem for RHOSP10?

 I encountered this problem in RHOSP10, but I think it also could be reproduced in the older versions.

    Version-Release number of selected component:
       openstack-nova-common-14.0.3-8.el7ost.noarch
       openstack-nova-compute-14.0.3-8.el7ost.noarch
       python-nova-14.0.3-8.el7ost.noarch
       python-os-brick-1.6.1-4.el7ost.noarch

Comment 1 Red Hat Bugzilla Rules Engine 2017-04-11 07:01:50 UTC

This bugzilla has been removed from the release and needs to be reviewed and Triaged for another Target Release.

Comment 2 Red Hat Bugzilla Rules Engine 2017-04-25 12:29:48 UTC

This bugzilla has been removed from the release and needs to be reviewed and Triaged for another Target Release.

Comment 7 Gorka Eguileor 2017-08-21 11:59:18 UTC

*** Bug 1482846 has been marked as a duplicate of this bug. ***

Comment 11 Avi Avraham 2017-09-27 12:17:13 UTC

verified 
installed RPM: 
[root@compute-1 ~]# rpm -qa |grep os-brick
python-os-brick-1.6.1-6.el7ost.noarch

1) create instance 
2) attached volume 
3) block in compute node using iptables drop command one ISCSI path 
4) run the following command : openstack server reboot --hard inst
5) test instance availability after reboot and volume attachment 
Due to Kaminario our ISCSI backend storage limitations we can not rerun this scenario blocking the other ISCSI interface

Comment 13 errata-xmlrpc 2017-09-28 16:35:22 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://access.redhat.com/errata/RHBA-2017:2825

Comment 14 Lee Yarwood 2018-01-08 10:12:36 UTC

*** Bug 1416641 has been marked as a duplicate of this bug. ***