Comment 1 for bug 1931716

Revision history for this message
Balazs Gibizer (balazs-gibizer) wrote :

The testcase:
1) attaches a volume
2) tries to attach the same volume again and expect it to fail
3) cleanup the resources used in the test, first it tries to detach the volume

From the log it is visible that the #1) attach and the #3) detach happens right after each other from the libvirt driver perspective

Jun 11 13:30:46.398669 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: DEBUG oslo_concurrency.lockutils [None req-382bb669-3d84-4d09-9b01-870ab132642e tempest-AttachVolumeNegativeTest-1273499975 tempest-AttachVolumeNegativeTest-1273499975-project] Lock "e3d6fd2b-7357-4d19-bcb4-482d97d332e5" released by "nova.compute.manager.ComputeManager.attach_volume.<locals>.do_attach_volume" :: held 6.947s {{(pid=108182) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Jun 11 13:30:46.906588 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: DEBUG oslo_concurrency.lockutils [None req-aceedc3b-f03b-4bd5-8e8e-cfe66170a2e2 tempest-AttachVolumeNegativeTest-1273499975 tempest-AttachVolumeNegativeTest-1273499975-project] Lock "e3d6fd2b-7357-4d19-bcb4-482d97d332e5" acquired by "nova.compute.manager.ComputeManager.detach_volume.<locals>.do_detach_volume" :: waited 0.000s {{(pid=108182) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:355}}

During detach:
1) the volume is found both in the persistent and in the live domain,
2) detached from the persistent domain successfully
3) failed to detach from the live domain as the device was not found.

So somehow the device disappeared from the live domain between 1) and 3)

Jun 11 13:30:47.028442 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: DEBUG nova.virt.libvirt.driver [None req-aceedc3b-f03b-4bd5-8e8e-cfe66170a2e2 tempest-AttachVolumeNegativeTest-1273499975 tempest-AttachVolumeNegativeTest-1273499975-project] Attempting to detach device vdb from instance e3d6fd2b-7357-4d19-bcb4-482d97d332e5 from the persistent domain config. {{(pid=108182) _detach_from_persistent /opt/stack/nova/nova/virt/libvirt/driver.py:2322}}
Jun 11 13:30:47.045014 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: WARNING nova.virt.libvirt.driver [None req-171cb636-ab52-4632-a7b3-791246cae8f4 None None] Received event <DeviceRemovedEvent: 1623418247.0404575, e3d6fd2b-7357-4d19-bcb4-482d97d332e5 => virtio-disk1> from libvirt but the driver is not waiting for it; ignored.
Jun 11 13:30:47.049596 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: INFO nova.virt.libvirt.driver [None req-aceedc3b-f03b-4bd5-8e8e-cfe66170a2e2 tempest-AttachVolumeNegativeTest-1273499975 tempest-AttachVolumeNegativeTest-1273499975-project] Successfully detached device vdb from instance e3d6fd2b-7357-4d19-bcb4-482d97d332e5 from the persistent domain config.
Jun 11 13:30:47.050139 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: DEBUG nova.virt.libvirt.driver [None req-aceedc3b-f03b-4bd5-8e8e-cfe66170a2e2 tempest-AttachVolumeNegativeTest-1273499975 tempest-AttachVolumeNegativeTest-1273499975-project] (1/8): Attempting to detach device vdb with device alias virtio-disk1 from instance e3d6fd2b-7357-4d19-bcb4-482d97d332e5 from the live domain config. {{(pid=108182) _detach_from_live_with_retry /opt/stack/nova/nova/virt/libvirt/driver.py:2358}}
Jun 11 13:30:47.054528 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: WARNING nova.virt.libvirt.driver [None req-aceedc3b-f03b-4bd5-8e8e-cfe66170a2e2 tempest-AttachVolumeNegativeTest-1273499975 tempest-AttachVolumeNegativeTest-1273499975-project] Unexpected libvirt error while detaching device vdb from instance e3d6fd2b-7357-4d19-bcb4-482d97d332e5: operation failed: disk vdb not found: libvirt.libvirtError: operation failed: disk vdb not found

There is a DeviceRemovedEvent from libvirt during the persistent detach phase that is ignored by the driver.