test_create_server_from_volume_snapshot (intermittently?) fails in devstack-plugin-ceph job - Delete snapshot failed, due to snapshot busy.: SnapshotIsBusy: deleting snapshot snapshot-cf654962-f53a-43e5-87eb-4c73bfd70804 that has dependent volumes

[Matt Riedemann]

Seen here:

http://logs.openstack.org/74/669474/1/check/devstack-plugin-ceph-tempest/adb055b/testr_results.html.gz

traceback-1: {{{
Traceback (most recent call last):
  File "tempest/lib/common/utils/test_utils.py", line 84, in call_and_ignore_notfound_exc
    return func(*args, **kwargs)
  File "tempest/lib/services/volume/v3/volumes_client.py", line 125, in delete_volume
    resp, body = self.delete(url)
  File "tempest/lib/common/rest_client.py", line 314, in delete
    return self.request('DELETE', url, extra_headers, headers, body)
  File "tempest/lib/services/volume/base_client.py", line 38, in request
    method, url, extra_headers, headers, body, chunked)
  File "tempest/lib/common/rest_client.py", line 679, in request
    self._error_checker(resp, resp_body)
  File "tempest/lib/common/rest_client.py", line 790, in _error_checker
    raise exceptions.BadRequest(resp_body, resp=resp)
tempest.lib.exceptions.BadRequest: Bad request
Details: {u'message': u'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 or be disassociated from snapshots after volume transfer.', u'code': 400}
}}}

traceback-2: {{{
Traceback (most recent call last):
  File "tempest/lib/common/rest_client.py", line 891, in wait_for_resource_deletion
    raise exceptions.TimeoutException(message)
tempest.lib.exceptions.TimeoutException: Request timed out
Details: (TestVolumeBootPattern:_run_cleanups) Failed to delete volume 435b6f02-532e-425d-bfee-88f220f0673c within the required time (196 s).
}}}

Traceback (most recent call last):
  File "tempest/lib/common/rest_client.py", line 891, in wait_for_resource_deletion
    raise exceptions.TimeoutException(message)
tempest.lib.exceptions.TimeoutException: Request timed out
Details: (TestVolumeBootPattern:_run_cleanups) Failed to delete volume-snapshot cf654962-f53a-43e5-87eb-4c73bfd70804 within the required time (196 s).

In the c-vol logs:

http://logs.openstack.org/74/669474/1/check/devstack-plugin-ceph-tempest/adb055b/controller/logs/screen-c-vol.txt.gz#_Jul_05_20_36_03_843973

Jul 05 20:36:03.843973 ubuntu-bionic-rax-ord-0008717840 cinder-volume[952]: ERROR cinder.volume.manager [None req-66637faa-12b1-4ef7-ab9b-55cf4b46d76d tempest-TestVolumeBootPattern-773280540 None] Delete snapshot failed, due to snapshot busy.: SnapshotIsBusy: deleting snapshot snapshot-cf654962-f53a-43e5-87eb-4c73bfd70804 that has dependent volumes

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22Delete%20snapshot%20failed%2C%20due%20to%20snapshot%20busy.%3A%20SnapshotIsBusy%3A%20deleting%20snapshot%5C%22%20AND%20message%3A%5C%22that%20has%20dependent%20volumes%5C%22%20AND%20tags%3A%5C%22screen-c-vol.txt%5C%22&from=7d

11 hits in 7 days, all failures. I'm not sure if this is a new regression on master or not, I don't see anything obvious related to rbd and snapshots in cinder/devstack/tempest repos since July 2.