novaclient.exceptions.BadRequest: Invalid volume: Invalid input received: Invalid volume: Unable to detach volume. Volume status must be 'in-use' and attach_status must be 'attached' to detach.

[freyes]

When the test is tearing down the resources, it's assuming that the dettach operation is fast, it's not blocking until that state reaches available, so the next call to delete the volume fails

The function detach_volume() should block after calling nova.volumes.delete_server_volume() until the volume gets to available state - https://github.com/openstack-charmers/zaza-openstack-tests/blob/master/zaza/openstack/utilities/openstack.py#L2753

2023-05-15 00:28:42.658609 | focal-medium | 2023-05-15 00:28:42 [INFO] Running teardown
2023-05-15 00:28:42.769368 | focal-medium | 2023-05-15 00:28:42 [INFO] tearDown - volumes: zaza-cindertests-200-vol
2023-05-15 00:28:42.770197 | focal-medium | 2023-05-15 00:28:42 [INFO] detaching volume: zaza-cindertests-200-vol
2023-05-15 00:28:42.770244 | focal-medium | 2023-05-15 00:28:42 [INFO] Detaching volume f9bb847b-3983-494d-a566-793aea156dc4 from instance 278e8b72-2ecc-4847-8d16-91ee791ec7ae
2023-05-15 00:28:43.751365 | focal-medium | 2023-05-15 00:28:43 [INFO] removing volume: zaza-cindertests-200-vol
2023-05-15 00:28:43.823101 | focal-medium | 2023-05-15 00:28:43 [ERROR] error removing volume: Invalid volume: Volume status must be available or error or error_restoring or error_extending or error_managing and must not be migrating, attached, belong to a group, have snapshots, awaiting a transfer, or be disassociated from snapshots after volume transfer. (HTTP 400) (Request-ID: req-48d8f3be-862f-4677-90c5-085a21ca0a06)

2023-05-15 00:36:59.903372 | focal-medium | 2023-05-15 00:36:59 [INFO] ======================================================================
2023-05-15 00:36:59.903453 | focal-medium | 2023-05-15 00:36:59 [INFO] ERROR: test_200_online_extend_volume (zaza.openstack.charm_tests.cinder.tests.CinderTests)
2023-05-15 00:36:59.903483 | focal-medium | 2023-05-15 00:36:59 [INFO] Test extending a volume while attached to an instance.
2023-05-15 00:36:59.903507 | focal-medium | 2023-05-15 00:36:59 [INFO] ----------------------------------------------------------------------
2023-05-15 00:36:59.903529 | focal-medium | 2023-05-15 00:36:59 [INFO] Traceback (most recent call last):
2023-05-15 00:36:59.903574 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/zaza/openstack/charm_tests/cinder/tests.py", line 81, in tearDown
2023-05-15 00:36:59.903644 | focal-medium | 2023-05-15 00:36:59 [INFO]     cls._remove_volumes(volumes)
2023-05-15 00:36:59.903676 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/zaza/openstack/charm_tests/cinder/tests.py", line 138, in _remove_volumes
2023-05-15 00:36:59.903755 | focal-medium | 2023-05-15 00:36:59 [INFO]     openstack_utils.detach_volume(cls.nova_client,
2023-05-15 00:36:59.904353 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/zaza/openstack/utilities/openstack.py", line 2766, in detach_volume
2023-05-15 00:36:59.904395 | focal-medium | 2023-05-15 00:36:59 [INFO]     return nova.volumes.delete_server_volume(server_id=instance_id,
2023-05-15 00:36:59.904427 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/novaclient/v2/volumes.py", line 187, in delete_server_volume
2023-05-15 00:36:59.904441 | focal-medium | 2023-05-15 00:36:59 [INFO]     return self._delete("/servers/%s/os-volume_attachments/%s" %
2023-05-15 00:36:59.904461 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/novaclient/base.py", line 376, in _delete
2023-05-15 00:36:59.904474 | focal-medium | 2023-05-15 00:36:59 [INFO]     resp, body = self.api.client.delete(url)
2023-05-15 00:36:59.905096 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/keystoneauth1/adapter.py", line 410, in delete
2023-05-15 00:36:59.905135 | focal-medium | 2023-05-15 00:36:59 [INFO]     return self.request(url, 'DELETE', **kwargs)
2023-05-15 00:36:59.905148 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/novaclient/client.py", line 78, in request
2023-05-15 00:36:59.905160 | focal-medium | 2023-05-15 00:36:59 [INFO]     raise exceptions.from_response(resp, body, url, method)
2023-05-15 00:36:59.905190 | focal-medium | 2023-05-15 00:36:59 [INFO] novaclient.exceptions.BadRequest: Invalid volume: Invalid input received: Invalid volume: Unable to detach volume. Volume status must be 'in-use' and attach_status must be 'attached' to detach. (HTTP 400) (Request-ID: req-c1576efa-8df9-43ca-a84e-efca9bd531ab) (HTTP 400) (Request-ID: req-dde2db74-10aa-4a3c-bd17-069b799703c5)
2023-05-15 00:36:59.905225 | focal-medium | 2023-05-15 00:36:59 [INFO] The above exception was the direct cause of the following exception:
2023-05-15 00:36:59.905237 | focal-medium | 2023-05-15 00:36:59 [INFO] Traceback (most recent call last):
2023-05-15 00:36:59.905793 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/zaza/openstack/charm_tests/cinder/tests.py", line 60, in tearDown
2023-05-15 00:36:59.905828 | focal-medium | 2023-05-15 00:36:59 [INFO]     for attempt in Retrying(
2023-05-15 00:36:59.905841 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/tenacity/__init__.py", line 347, in __iter__
2023-05-15 00:36:59.905852 | focal-medium | 2023-05-15 00:36:59 [INFO]     do = self.iter(retry_state=retry_state)
2023-05-15 00:36:59.905864 | focal-medium | 2023-05-15 00:36:59 [INFO]   File "/home/ubuntu/src/review.opendev.org/openstack/charm-cinder-ceph/.tox/func-target/lib/python3.8/site-packages/tenacity/__init__.py", line 326, in iter
2023-05-15 00:36:59.905875 | focal-medium | 2023-05-15 00:36:59 [INFO]     raise retry_exc from fut.exception()
2023-05-15 00:36:59.905885 | focal-medium | 2023-05-15 00:36:59 [INFO] tenacity.RetryError: RetryError[<Future at 0x7f44917244f0 state=finished raised BadRequest>]