"Could not find any paths for the volume." after instance restart

[Axel Sündermann]

Description
===========
In an environment using NVMeoF with SPDK, when an instance is shutoff or hard restarted, it is not able to find the volume again. The volume is visible on the node with "nvme list" but nova reports: "Could not find any paths for the volume."

Steps to reproduce
==================
- Create an instance using a volume provided via NVMeoF with SPDK
- Shutdown the instance
- Start the instance

Expected result
===============
Instance boots normally.

Actual result
=============
Instance fails to start, with "Could not find any paths for the volume."

Environment
===========
Openstack Xena

ii nova-common 3:24.0.0-0ubuntu1~cloud0 all OpenStack Compute - common files
ii nova-compute 3:24.0.0-0ubuntu1~cloud0 all OpenStack Compute - compute node base
ii nova-compute-kvm 3:24.0.0-0ubuntu1~cloud0 all OpenStack Compute - compute node (KVM)
ii nova-compute-libvirt 3:24.0.0-0ubuntu1~cloud0 all OpenStack Compute - compute node libvirt support
ii python3-nova 3:24.0.0-0ubuntu1~cloud0 all OpenStack Compute Python 3 libraries
ii python3-novaclient 2:17.6.0-0ubuntu1~cloud0 all client library for OpenStack Compute API - 3.x

 Libvirt + KVM

ii libvirt-clients 6.0.0-0ubuntu8.15 amd64 Programs for the libvirt library
ii libvirt-daemon 6.0.0-0ubuntu8.15 amd64 Virtualization daemon
ii libvirt-daemon-driver-qemu 6.0.0-0ubuntu8.15 amd64 Virtualization daemon QEMU connection driver
ii libvirt-daemon-driver-storage-rbd 6.0.0-0ubuntu8.15 amd64 Virtualization daemon RBD storage driver
ii libvirt-daemon-system 6.0.0-0ubuntu8.15 amd64 Libvirt daemon configuration files
ii libvirt-daemon-system-systemd 6.0.0-0ubuntu8.15 amd64 Libvirt daemon configuration files (systemd)
ii libvirt0:amd64 6.0.0-0ubuntu8.15 amd64 library for interfacing with different virtualization systems

ii qemu-kvm 1:4.2-3ubuntu6.19 amd64 QEMU Full virtualization on x86 hardware

2. Which storage type did you use?
NVMeoF with SPDK

3. Which networking type did you use?
Neutron with Linuxbridge for the instances
RDMA for NVMeoF

Logs & Configs
==============
2022-02-21 14:56:01.034 61392 INFO nova.compute.manager [req-7be86f95-5eda-4c35-a4a1-d966fde09128 65c5899d09e34b68b192f59ef4a04c10 6e6f0b00fdbb46e5bb15fad7f7450004 - default default] [instance: 26624f4c-98e9-4431-8226-43e015026d34] Successfully reverted task state from powering-on on failure for instance.
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server [req-7be86f95-5eda-4c35-a4a1-d966fde09128 65c5899d09e34b68b192f59ef4a04c10 6e6f0b00fdbb46e5bb15fad7f7450004 - default default] Exception during message handling: os_brick.exception.VolumePathsNotFound: Could not find any paths for the volume.
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_messaging/rpc/server.py", line 165, in _process_incoming
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_messaging/rpc/dispatcher.py", line 309, in dispatch
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_messaging/rpc/dispatcher.py", line 229, in _do_dispatch
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/exception_wrapper.py", line 71, in wrapped
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server _emit_versioned_exception_notification(
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server self.force_reraise()
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server raise self.value
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/exception_wrapper.py", line 63, in wrapped
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server return f(self, context, *args, **kw)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/compute/manager.py", line 183, in decorated_function
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server LOG.warning("Failed to revert task state for instance. "
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server self.force_reraise()
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server raise self.value
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/compute/manager.py", line 154, in decorated_function
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/compute/utils.py", line 1433, in decorated_function
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/compute/manager.py", line 211, in decorated_function
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server compute_utils.add_instance_fault_from_exc(context,
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 227, in __exit__
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server self.force_reraise()
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_utils/excutils.py", line 200, in force_reraise
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server raise self.value
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/compute/manager.py", line 200, in decorated_function
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/compute/manager.py", line 3192, in start_instance
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server self._power_on(context, instance)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/compute/manager.py", line 3160, in _power_on
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server self.driver.power_on(context, instance,
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/virt/libvirt/driver.py", line 3932, in power_on
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server self._hard_reboot(context, instance, network_info, block_device_info,
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/virt/libvirt/driver.py", line 3797, in _hard_reboot
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server xml = self._get_guest_xml(context, instance, network_info, disk_info,
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/virt/libvirt/driver.py", line 7038, in _get_guest_xml
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server conf = self._get_guest_config(instance, network_info, image_meta,
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/virt/libvirt/driver.py", line 6660, in _get_guest_config
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server storage_configs = self._get_guest_storage_config(context,
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/virt/libvirt/driver.py", line 5292, in _get_guest_storage_config
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server self._connect_volume(context, connection_info, instance)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/virt/libvirt/driver.py", line 1807, in _connect_volume
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server vol_driver.connect_volume(connection_info, instance)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/nova/virt/libvirt/volume/nvme.py", line 40, in connect_volume
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server device_info = self.connector.connect_volume(
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/os_brick/utils.py", line 154, in trace_logging_wrapper
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/oslo_concurrency/lockutils.py", line 360, in inner
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/os_brick/initiator/connectors/nvmeof.py", line 365, in connect_volume
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server path = self._get_device_path(current_nvme_devices)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/os_brick/utils.py", line 78, in _wrapper
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server return r(f, *args, **kwargs)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 423, in __call__
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server do = self.iter(retry_state=retry_state)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 372, in iter
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server raise retry_exc.reraise()
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 189, in reraise
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server raise self.last_attempt.result()
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.8/concurrent/futures/_base.py", line 437, in result
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server return self.__get_result()
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3.8/concurrent/futures/_base.py", line 389, in __get_result
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server raise self._exception
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/tenacity/__init__.py", line 426, in __call__
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server result = fn(*args, **kwargs)
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server File "/usr/lib/python3/dist-packages/os_brick/initiator/connectors/nvmeof.py", line 197, in _get_device_path
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server raise exception.VolumePathsNotFound()
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server os_brick.exception.VolumePathsNotFound: Could not find any paths for the volume.
2022-02-21 14:56:01.037 61392 ERROR oslo_messaging.rpc.server

[Sylvain Bauza (sylvain-bauza)]

This sounds an os-brick issue.

[Axel Sündermann (cubitusinthecloud)]

Ok thank you I will check there.

[melanie witt (melwitt)]

I've added the os-brick project to this bug so they can take a look.

For now I'm going to mark it as Incomplete for nova as this is showing a failure to find the device path in os-brick. The nova code doesn't do much ... it calls connect_volume in os-brick with connection_properties['data'] [1], same as connecting other types of volumes:

    def connect_volume(self, connection_info, instance):

        device_info = self.connector.connect_volume(
            connection_info['data'])

[1] https://github.com/openstack/nova/blob/stable/xena/nova/virt/libvirt/volume/nvme.py#L40