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.
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-002507413 0 nova-compute[ 108182] : DEBUG oslo_concurrenc y.lockutils [None req-382bb669- 3d84-4d09- 9b01-870ab13264 2e tempest- AttachVolumeNeg ativeTest- 1273499975 tempest- AttachVolumeNeg ativeTest- 1273499975- project] Lock "e3d6fd2b- 7357-4d19- bcb4-482d97d332 e5" 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_concurrenc y/lockutils. py:367} } focal-inap- mtl01-002507413 0 nova-compute[ 108182] : DEBUG oslo_concurrenc y.lockutils [None req-aceedc3b- f03b-4bd5- 8e8e-cfe66170a2 e2 tempest- AttachVolumeNeg ativeTest- 1273499975 tempest- AttachVolumeNeg ativeTest- 1273499975- project] Lock "e3d6fd2b- 7357-4d19- bcb4-482d97d332 e5" 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_concurrenc y/lockutils. py:355} }
Jun 11 13:30:46.906588 ubuntu-
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-002507413 0 nova-compute[ 108182] : DEBUG nova.virt. libvirt. driver [None req-aceedc3b- f03b-4bd5- 8e8e-cfe66170a2 e2 tempest- AttachVolumeNeg ativeTest- 1273499975 tempest- AttachVolumeNeg ativeTest- 1273499975- project] Attempting to detach device vdb from instance e3d6fd2b- 7357-4d19- bcb4-482d97d332 e5 from the persistent domain config. {{(pid=108182) _detach_ from_persistent /opt/stack/ nova/nova/ virt/libvirt/ driver. py:2322} } focal-inap- mtl01-002507413 0 nova-compute[ 108182] : WARNING nova.virt. libvirt. driver [None req-171cb636- ab52-4632- a7b3-791246cae8 f4 None None] Received event <DeviceRemovedE vent: 1623418247.0404575, e3d6fd2b- 7357-4d19- bcb4-482d97d332 e5 => virtio-disk1> from libvirt but the driver is not waiting for it; ignored. focal-inap- mtl01-002507413 0 nova-compute[ 108182] : INFO nova.virt. libvirt. driver [None req-aceedc3b- f03b-4bd5- 8e8e-cfe66170a2 e2 tempest- AttachVolumeNeg ativeTest- 1273499975 tempest- AttachVolumeNeg ativeTest- 1273499975- project] Successfully detached device vdb from instance e3d6fd2b- 7357-4d19- bcb4-482d97d332 e5 from the persistent domain config. focal-inap- mtl01-002507413 0 nova-compute[ 108182] : DEBUG nova.virt. libvirt. driver [None req-aceedc3b- f03b-4bd5- 8e8e-cfe66170a2 e2 tempest- AttachVolumeNeg ativeTest- 1273499975 tempest- AttachVolumeNeg ativeTest- 1273499975- project] (1/8): Attempting to detach device vdb with device alias virtio-disk1 from instance e3d6fd2b- 7357-4d19- bcb4-482d97d332 e5 from the live domain config. {{(pid=108182) _detach_ from_live_ with_retry /opt/stack/ nova/nova/ virt/libvirt/ driver. py:2358} } focal-inap- mtl01-002507413 0 nova-compute[ 108182] : WARNING nova.virt. libvirt. driver [None req-aceedc3b- f03b-4bd5- 8e8e-cfe66170a2 e2 tempest- AttachVolumeNeg ativeTest- 1273499975 tempest- AttachVolumeNeg ativeTest- 1273499975- project] Unexpected libvirt error while detaching device vdb from instance e3d6fd2b- 7357-4d19- bcb4-482d97d332 e5: operation failed: disk vdb not found: libvirt. libvirtError: operation failed: disk vdb not found
Jun 11 13:30:47.045014 ubuntu-
Jun 11 13:30:47.049596 ubuntu-
Jun 11 13:30:47.050139 ubuntu-
Jun 11 13:30:47.054528 ubuntu-
There is a DeviceRemovedEvent from libvirt during the persistent detach phase that is ignored by the driver.