Nova-compute try to flush wrong device mapper when live migrate VM

[Ha Manh Dong]

Description
===========

When I live-migrate a VM boot from volume on 3par storage (we're using multipath for redundancy), it failed because of nova-compute calling os-brick to flush wrong device mapper, that device mapper is belong to the volume of another VM that lie on the same compute host.

Environment
===========

OpenStack version Rocky

Hypervisors: Libvirt + KVM

Multipath version 0.4.9-123.el7.x86_64

Storage: 3par8440

Networking: Neutron with OpenVSwitch

compute_server_1 have 10 VMs, 2 of them is

VM-1 with UUID 35940aef-cf19-465a-84e7-8aa14da7fe28,
  - boots from volume /dev/vda with wwn 360002ac0000000000000031a0002107b
  - has a volume attached to /dev/vdb with wwn 360002ac000000000000003190002107b

VM-2 with UUID b2c3f475-b916-4811-9614-2c81a79868e8,
  - boots from volume /dev/vda with wwn 360002ac000000000000003130002107b
  - has a volume attached to /dev/vdb with wwn 360002ac000000000000001ac0002107b

Try to live-migrate VM-1 to anther compute host but it's failed because os-brick try to flush device mapper with wwn 360002ac000000000000001ac0002107b of VM-2

I also tried to live migrate some other VMs on this compute_server_1 but all of that is ok.

Expected result
===============
OS-brick flush the right device mapper of the VM.

Actual result
=============
OS-brick flush the wrong device mapper of another VM that lied on the same compute host of VM live-migrating.

Logs of nova-compute
======================

2019-07-30 14:16:09.293 6 INFO nova.virt.libvirt.driver [-] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Migration running for 30 secs, memory 0% remaining; (bytes processed=20294869659, remaining=298622976, total=34377375744)
2019-07-30 14:16:09.628 6 INFO nova.compute.manager [-] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] VM Migration completed (Lifecycle Event)
2019-07-30 14:16:09.760 6 INFO nova.compute.manager [req-99b22dd0-8cb2-45d8-b7b7-4241e1ffcfe0 - - - - -] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] During sync_power_state the instance has a pending task (migrating). Skip.
2019-07-30 14:16:10.521 6 WARNING nova.compute.manager [req-ea4ac52f-9cac-4d1f-b282-d9e99d76f3d7 f295657702674882b2aab02bd9b15b42 c7fe4b7c1a824f738fe12e32b31c1650 - default default] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Received unexpected event network-vif-unplugged-883d1c97-164f-4c73-a423-afdd8b6ee0f6 for instance with vm_state active and task_state migrating.
2019-07-30 14:16:11.254 6 INFO nova.virt.libvirt.driver [-] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Migration operation has completed
2019-07-30 14:16:11.254 6 INFO nova.compute.manager [-] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] _post_live_migration() is started..
2019-07-30 14:16:11.319 6 INFO oslo.privsep.daemon [-] Running privsep helper: ['sudo', 'nova-rootwrap', '/etc/nova/rootwrap.conf', 'privsep-helper', '--config-file', '/usr/share/nova/nova-dist.conf', '--config-file', '/etc/nova/nova.conf', '--privsep_context', 'os_brick.privileged.default', '--privsep_sock_path', '/tmp/tmpzyR_mV/privsep.sock']
2019-07-30 14:16:12.131 6 INFO oslo.privsep.daemon [-] Spawned new privsep daemon via rootwrap
2019-07-30 14:16:12.050 260 INFO oslo.privsep.daemon [-] privsep daemon starting
2019-07-30 14:16:12.054 260 INFO oslo.privsep.daemon [-] privsep process running with uid/gid: 0/0
2019-07-30 14:16:12.056 260 INFO oslo.privsep.daemon [-] privsep process running with capabilities (eff/prm/inh): CAP_SYS_ADMIN/CAP_SYS_ADMIN/none
2019-07-30 14:16:12.057 260 INFO oslo.privsep.daemon [-] privsep daemon running as pid 260
2019-07-30 14:16:12.575 6 INFO os_brick.initiator.linuxscsi [-] Find Multipath device file for volume WWN 360002ac000000000000001ac0002107b
2019-07-30 14:16:14.065 6 WARNING nova.compute.manager [req-e1ecb028-7af8-4d2c-8a3c-10ecbd627337 f295657702674882b2aab02bd9b15b42 c7fe4b7c1a824f738fe12e32b31c1650 - default default] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Received unexpected event network-vif-plugged-883d1c97-164f-4c73-a423-afdd8b6ee0f6 for instance with vm_state active and task_state migrating.
2019-07-30 14:16:26.253 6 INFO nova.compute.manager [-] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] VM Stopped (Lifecycle Event)
2019-07-30 14:16:37.851 6 INFO nova.virt.libvirt.driver [req-b6739a3b-c930-428c-8ba0-ea05e6cf7063 - - - - -] Libvirt baseline CPU <cpu>
  <arch>x86_64</arch>
  <model>Skylake-Server</model>
  <vendor>Intel</vendor>
  <topology sockets="1" cores="12" threads="2"/>
</cpu>

2019-07-30 14:16:38.049 6 WARNING nova.compute.resource_tracker [req-b6739a3b-c930-428c-8ba0-ea05e6cf7063 - - - - -] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Instance not resizing, skipping migration.
2019-07-30 14:16:38.133 6 INFO nova.compute.resource_tracker [req-b6739a3b-c930-428c-8ba0-ea05e6cf7063 - - - - -] Instance 7ad6610a-7652-4f5e-a868-9a27b0de105b has allocations against this compute host but is not found in the database.
2019-07-30 14:16:38.133 6 INFO nova.compute.resource_tracker [req-b6739a3b-c930-428c-8ba0-ea05e6cf7063 - - - - -] Final resource view: name=hlc6fcom-38 phys_ram=261812MB used_ram=219648MB phys_disk=702689GB used_disk=50GB total_vcpus=48 used_vcpus=117 pci_stats=[]
2019-07-30 14:16:38.369 6 INFO nova.virt.libvirt.driver [req-b6739a3b-c930-428c-8ba0-ea05e6cf7063 - - - - -] Libvirt baseline CPU <cpu>
  <arch>x86_64</arch>
  <model>Skylake-Server</model>
  <vendor>Intel</vendor>
  <topology sockets="1" cores="12" threads="2"/>
</cpu>
2019-07-30 14:17:12.832 6 WARNING nova.virt.libvirt.driver [-] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Error monitoring migration: Unexpected error while running command.
Command: multipath -f /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b
Exit code: 1
Stdout: u'Jul 30 14:16:32 | /etc/multipath.conf does not exist, blacklisting all devices.\nJul 30 14:16:32 | A default multipath.conf file is located at\nJul 30 14:16:32 | /usr/share/doc/device-mapper-multipath-0.4.9/multipath.conf\nJul 30 14:16:32 | You can run /sbin/mpathconf to create or modify /etc/multipath.conf\nJul 30 14:16:32 | /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b: map in use\nJul 30 14:16:32 | failed to remove multipath map /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b\n'
Stderr: u'': ProcessExecutionError: Unexpected error while running command.
Command: multipath -f /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b
Exit code: 1
Stdout: u'Jul 30 14:16:32 | /etc/multipath.conf does not exist, blacklisting all devices.\nJul 30 14:16:32 | A default multipath.conf file is located at\nJul 30 14:16:32 | /usr/share/doc/device-mapper-multipath-0.4.9/multipath.conf\nJul 30 14:16:32 | You can run /sbin/mpathconf to create or modify /etc/multipath.conf\nJul 30 14:16:32 | /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b: map in use\nJul 30 14:16:32 | failed to remove multipath map /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b\n'
Stderr: u''
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Traceback (most recent call last):
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 7491, in _live_migration
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] finish_event, disk_paths)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 7402, in _live_migration_monitor
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] migrate_data)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 79, in wrapped
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] function_name, call_dict, binary, tb)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] self.force_reraise()
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] six.reraise(self.type_, self.value, self.tb)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 69, in wrapped
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return f(self, context, *args, **kw)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 216, in decorated_function
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] kwargs['instance'], e, sys.exc_info())
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] self.force_reraise()
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] six.reraise(self.type_, self.value, self.tb)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 204, in decorated_function
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return function(self, context, *args, **kwargs)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6563, in _post_live_migration
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] migrate_data)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 7894, in post_live_migration
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] self._disconnect_volume(context, connection_info, instance)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 1262, in _disconnect_volume
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] vol_driver.disconnect_volume(connection_info, instance)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/volume/fibrechannel.py", line 72, in disconnect_volume
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] connection_info['data'])
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/utils.py", line 137, in trace_logging_wrapper
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return f(*args, **kwargs)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 274, in inner
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return f(*args, **kwargs)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/initiator/connectors/fibre_channel.py", line 331, in disconnect_volume
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] self._linuxscsi.flush_multipath_device(mpath_path)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py", line 275, in flush_multipath_device
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] root_helper=self._root_helper)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/executor.py", line 52, in _execute
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] result = self.__execute(*args, **kwargs)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/privileged/rootwrap.py", line 169, in execute
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return execute_root(*cmd, **kwargs)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_privsep/priv_context.py", line 207, in _wrap
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return self.channel.remote_call(name, args, kwargs)
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_privsep/daemon.py", line 202, in remote_call
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] raise exc_type(*result[2])
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] ProcessExecutionError: Unexpected error while running command.
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Command: multipath -f /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Exit code: 1
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Stdout: u'Jul 30 14:16:32 | /etc/multipath.conf does not exist, blacklisting all devices.\nJul 30 14:16:32 | A default multipath.conf file is located at\nJul 30 14:16:32 | /usr/share/doc/device-mapper-multipath-0.4.9/multipath.conf\nJul 30 14:16:32 | You can run /sbin/mpathconf to create or modify /etc/multipath.conf\nJul 30 14:16:32 | /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b: map in use\nJul 30 14:16:32 | failed to remove multipath map /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b\n'
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Stderr: u''
2019-07-30 14:17:12.832 6 ERROR nova.virt.libvirt.driver [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28]
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [-] [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Live migration failed.: ProcessExecutionError: Unexpected error while running command.
Command: multipath -f /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b
Exit code: 1
Stdout: u'Jul 30 14:16:32 | /etc/multipath.conf does not exist, blacklisting all devices.\nJul 30 14:16:32 | A default multipath.conf file is located at\nJul 30 14:16:32 | /usr/share/doc/device-mapper-multipath-0.4.9/multipath.conf\nJul 30 14:16:32 | You can run /sbin/mpathconf to create or modify /etc/multipath.conf\nJul 30 14:16:32 | /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b: map in use\nJul 30 14:16:32 | failed to remove multipath map /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b\n'
Stderr: u''
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Traceback (most recent call last):
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6362, in _do_live_migration
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] block_migration, migrate_data)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 6988, in live_migration
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] migrate_data)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 7491, in _live_migration
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] finish_event, disk_paths)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 7402, in _live_migration_monitor
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] migrate_data)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 79, in wrapped
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] function_name, call_dict, binary, tb)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] self.force_reraise()
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] six.reraise(self.type_, self.value, self.tb)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 69, in wrapped
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return f(self, context, *args, **kw)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 216, in decorated_function
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] kwargs['instance'], e, sys.exc_info())
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] self.force_reraise()
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] six.reraise(self.type_, self.value, self.tb)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 204, in decorated_function
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return function(self, context, *args, **kwargs)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 6563, in _post_live_migration
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] migrate_data)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 7894, in post_live_migration
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] self._disconnect_volume(context, connection_info, instance)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 1262, in _disconnect_volume
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] vol_driver.disconnect_volume(connection_info, instance)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/volume/fibrechannel.py", line 72, in disconnect_volume
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] connection_info['data'])
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/utils.py", line 137, in trace_logging_wrapper
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return f(*args, **kwargs)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py", line 274, in inner
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return f(*args, **kwargs)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/initiator/connectors/fibre_channel.py", line 331, in disconnect_volume
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] self._linuxscsi.flush_multipath_device(mpath_path)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/initiator/linuxscsi.py", line 275, in flush_multipath_device
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] root_helper=self._root_helper)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/executor.py", line 52, in _execute
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] result = self.__execute(*args, **kwargs)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/os_brick/privileged/rootwrap.py", line 169, in execute
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return execute_root(*cmd, **kwargs)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_privsep/priv_context.py", line 207, in _wrap
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] return self.channel.remote_call(name, args, kwargs)
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] File "/usr/lib/python2.7/site-packages/oslo_privsep/daemon.py", line 202, in remote_call
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] raise exc_type(*result[2])
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] ProcessExecutionError: Unexpected error while running command.
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Command: multipath -f /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Exit code: 1
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Stdout: u'Jul 30 14:16:32 | /etc/multipath.conf does not exist, blacklisting all devices.\nJul 30 14:16:32 | A default multipath.conf file is located at\nJul 30 14:16:32 | /usr/share/doc/device-mapper-multipath-0.4.9/multipath.conf\nJul 30 14:16:32 | You can run /sbin/mpathconf to create or modify /etc/multipath.conf\nJul 30 14:16:32 | /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b: map in use\nJul 30 14:16:32 | failed to remove multipath map /dev/disk/by-id/dm-uuid-mpath-360002ac000000000000001ac0002107b\n'
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28] Stderr: u''
2019-07-30 14:17:12.834 6 ERROR nova.compute.manager [instance: 35940aef-cf19-465a-84e7-8aa14da7fe28]
2019-07-30 14:17:40.006 6 INFO nova.compute.resource_tracker [req-b6739a3b-c930-428c-8ba0-ea05e6cf7063 - - - - -] Instance 6996d49b-586a-4c14-9983-35062718d491 has allocations against this compute host but is not found in the database.
2019-07-30 14:17:40.046 6 INFO nova.compute.resource_tracker [req-b6739a3b-c930-428c-8ba0-ea05e6cf7063 - - - - -] Instance 7ad6610a-7652-4f5e-a868-9a27b0de105b has allocations against this compute host but is not found in the database.

[Matt Riedemann (mriedem)]

What version of os-brick are you using? There might be fixes in newer releases of os-brick but you'd have to check the change log probably. Lee Yarwood might be familiar with any related changes to os-brick as well.

[Ha Manh Dong (donghm)]

Hi Matt,

We're using os-brick version python2-os-brick-2.5.3-0.20180725153218.641337b.el7.noarch

I have checked the release notes of os-brick at [1] but it seems nothing related to my issue.

I also can not reproduce this issue, have no idea about this weird bug.

[1] https://docs.openstack.org/releasenotes/os-brick/

[Balazs Gibizer (balazs-gibizer)]

Based on that the reporter cannot reproduce the problem I'm closing the bug as Invalid. Please reset the bug state to New if you can reproduce it again.