Description
===========
The test_attach_attached_volume_to_same_server tests within the nova-next job fail during detaching the volume:
File "/usr/local/lib/python3.8/dist-packages/libvirt.py", line 1515, in detachDeviceFlags
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] raise libvirtError('virDomainDetachDeviceFlags() failed')
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] libvirt.libvirtError: operation failed: disk vdb not found
Steps to reproduce
==================
Only seen as part of the nova-next job at present.
Expected result
===============
detach succeeds
Actual result
=============
test fails as the volume state
Environment
===========
1. Exact version of OpenStack you are running. See the following
list for all releases: http://docs.openstack.org/releases/
master
2. Which hypervisor did you use?
(For example: Libvirt + KVM, Libvirt + XEN, Hyper-V, PowerKVM, ...)
What's the version of that?
libvirt
2. Which storage type did you use?
(For example: Ceph, LVM, GPFS, ...)
What's the version of that?
cinder volume
3. Which networking type did you use?
(For example: nova-network, Neutron with OpenVSwitch, ...)
N/A
Logs & Configs
==============
https://zuul.opendev.org/t/openstack/build/02e6a99bf1574c978c663eb434705cbb/log/controller/logs/screen-n-cpu.txt?severity=0#34811
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [None req-aceedc3b-f03b-4bd5-8e8e-cfe66170a2e2 tempest-AttachVolumeNegativeTest-1273499975 tempest-AttachVolumeNegativeTest-1273499975-project] [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] Failed to detach volume 2939aa92-0156-45d6-9689-ed48dcc8fd8a from /dev/vdb: libvirt.libvirtError: operation failed: disk vdb not found
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] Traceback (most recent call last):
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/opt/stack/nova/nova/virt/block_device.py", line 328, in driver_detach
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] virt_driver.detach_volume(context, connection_info, instance, mp,
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2555, in detach_volume
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] self._detach_with_retry(
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2308, in _detach_with_retry
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] self._detach_from_live_with_retry(
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2364, in _detach_from_live_with_retry
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] self._detach_from_live_and_wait_for_event(
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2426, in _detach_from_live_and_wait_for_event
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] self._detach_sync(
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2498, in _detach_sync
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] guest.detach_device(dev, persistent=persistent, live=live)
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/opt/stack/nova/nova/virt/libvirt/guest.py", line 441, in detach_device
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] self._domain.detachDeviceFlags(device_xml, flags=flags)
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/usr/local/lib/python3.8/dist-packages/eventlet/tpool.py", line 190, in doit
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] result = proxy_call(self._autowrap, f, *args, **kwargs)
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/usr/local/lib/python3.8/dist-packages/eventlet/tpool.py", line 148, in proxy_call
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] rv = execute(f, *args, **kwargs)
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/usr/local/lib/python3.8/dist-packages/eventlet/tpool.py", line 129, in execute
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR
nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] six.reraise(c, e, tb)
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/usr/local/lib/python3.8/dist-packages/six.py", line 719, in reraise
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] raise value
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/usr/local/lib/python3.8/dist-packages/eventlet/tpool.py", line 83, in tworker
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] rv = meth(*args, **kwargs)
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] File "/usr/local/lib/python3.8/dist-packages/libvirt.py", line 1515, in detachDeviceFlags
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] raise libvirtError('virDomainDetachDeviceFlags() failed')
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5] libvirt.libvirtError: operation failed: disk vdb not found
Jun 11 13:30:47.071650 ubuntu-focal-inap-mtl01-0025074130 nova-compute[108182]: ERROR nova.virt.block_device [instance: e3d6fd2b-7357-4d19-bcb4-482d97d332e5]
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...
Jun 11 13:30:47.045014 ubuntu-
Jun 11 13:30:47.049596 ubuntu-
Jun 11 13:30:47.050139 ubuntu-