Our environment has two ceph clusters (az1 and az2) with a separate ceph-rbd-mirror charm deployed to each. The ceph-rbd-mirror charm enables pool mirroring on all rbd pools.

Glance is backed by only one of the ceph clusters, az1. 

We have volume types named after the ceph cluster, arbor-az1 and arbor-az2.

When we copy an image to cinder using the following openstack cli, it's fast and reliable when copying from az1 to az1, but we have greater than 50% failure when copying from az1 to az2.

  openstack volume create --image bionic --size 3 --type arbor-az1 volume-az1 # works
  openstack volume create --image bionic --size 3 --type arbor-az2 volume-az2 # fails >50%

When the az2 image upload fails, it's always with "cinder.exception.VolumeIsBusy: deleting volume volume-<id> that has snapshot"

The full log from the cinder-volume log follows.

2020-10-19 10:15:35.871 45458 INFO cinder.volume.flows.manager.create_volume [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Volume 63e4d69c-0722-40fc-b44f-cb59fca0d435: being created as image with specification: {'status': 'creating', 'volume_name': 'volume-63e4d69c-0722-40fc-b44f-cb59fca0d435', 'volume_size': 20, 'image_id': 'e93f97e0-f514-435d-a277-0ac288ed0c6c', 'image_location': ('rbd://36bd979e-0511-11eb-bced-ecebb88db476/glance/e93f97e0-f514-435d-a277-0ac288ed0c6c/snap', [{'url': 'rbd://36bd979e-0511-11eb-bced-ecebb88db476/glance/e93f97e0-f514-435d-a277-0ac288ed0c6c/snap', 'metadata': {}}]), 'image_meta': {'name': 'UBUNTU-18.04', 'disk_format': 'qcow2', 'container_format': 'bare', 'visibility': 'public', 'size': 359923712, 'virtual_size': None, 'status': 'active', 'checksum': '9aa011b2b79b1fe42a7c306555923b1b', 'protected': False, 'min_ram': 0, 'min_disk': 0, 'owner': '86fcc0b3839b45029dd325641ddc2a09', 'os_hidden': False, 'os_hash_algo': 'sha512', 'os_hash_value': '03786c51866c1c6c50ef671502b265afb71084e0d018748ca9b29f871ca5445c9eefffffdf927d540bddaf0e8597adc673e218e785fcf16013fba7e7d9898e6e', 'id': 'e93f97e0-f514-435d-a277-0ac288ed0c6c', 'created_at': datetime.datetime(2020, 10, 15, 16, 49, tzinfo=<iso8601.Utc>), 'updated_at': datetime.datetime(2020, 10, 15, 16, 49, 18, tzinfo=<iso8601.Utc>), 'locations': [{'url': 'rbd://36bd979e-0511-11eb-bced-ecebb88db476/glance/e93f97e0-f514-435d-a277-0ac288ed0c6c/snap', 'metadata': {}}], 'direct_url': 'rbd://36bd979e-0511-11eb-bced-ecebb88db476/glance/e93f97e0-f514-435d-a277-0ac288ed0c6c/snap', 'tags': [], 'file': '/v2/images/e93f97e0-f514-435d-a277-0ac288ed0c6c/file', 'properties': {}}, 'image_service': <cinder.image.glance.GlanceImageService object at 0x7fb92712cda0>}
2020-10-19 10:15:40.810 45458 INFO cinder.image.image_utils [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Image download 343.25 MB at 70.20 MB/s
2020-10-19 10:15:44.685 45458 INFO cinder.image.image_utils [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Converted 2252.00 MB image at 1170.20 MB/s
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Failed to copy image e93f97e0-f514-435d-a277-0ac288ed0c6c to volume: 63e4d69c-0722-40fc-b44f-cb59fca0d435: cinder.exception.VolumeIsBusy: deleting volume volume-63e4d69c-0722-40fc-b44f-cb59fca0d435 that has snapshot
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils Traceback (most recent call last):
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils   File "/usr/lib/python3/dist-packages/cinder/volume/volume_utils.py", line 1153, in copy_image_to_volume
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils     context, volume, image_service, image_id)
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils   File "/usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py", line 1527, in copy_image_to_volume
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils     self._copy_image_to_volume(context, volume, image_service, image_id)
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils   File "/usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py", line 1575, in _copy_image_to_volume
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils     self.delete_volume(volume)
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils   File "/usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py", line 1135, in delete_volume
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils     raise exception.VolumeIsBusy(volume_name=volume_name)
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils cinder.exception.VolumeIsBusy: deleting volume volume-63e4d69c-0722-40fc-b44f-cb59fca0d435 that has snapshot
2020-10-19 10:15:44.973 45458 ERROR cinder.volume.volume_utils
2020-10-19 10:15:45.125 45458 WARNING cinder.volume.manager [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (99bc2fa2-1ae2-4d84-80be-07324276e5d3) transitioned into state 'FAILURE' from state 'RUNNING'
5 predecessors (most recent first):
  Atom 'cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start' {'intention': 'EXECUTE', 'state': 'SUCCESS', 'requires': {'context': <cinder.context.RequestContext object at 0x7fb927296f28>, 'volume': Volume(_name_id=None,admin_metadata={},attach_status='detached',availability_zone='zone2',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2020-10-19T10:15:35Z,deleted=False,deleted_at=None,display_description='',display_name='demo_pravin16',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='cinder@cinder-ceph-az2-arbor#cinder-ceph-az2-arbor',id=63e4d69c-0722-40fc-b44f-cb59fca0d435,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='0c0bb65d03f446ca8a845d1ae9229790',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2020-10-19T10:15:36Z,service_uuid=None,shared_targets=True,size=20,snapshot_id=None,snapshots=<?>,source_volid=None,status='downloading',terminated_at=None,updated_at=2020-10-19T10:15:36Z,user_id='f2ee9e8060e54d058060d220fab84088',volume_attachment=<?>,volume_type=VolumeType(f3fec838-26e1-4fd5-a315-6985f9b3cd5c),volume_type_id=f3fec838-26e1-4fd5-a315-6985f9b3cd5c)}, 'provides': None}
  |__Atom 'cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create' {'intention': 'EXECUTE', 'state': 'SUCCESS', 'requires': {'context': <cinder.context.RequestContext object at 0x7fb927296f28>, 'volume': Volume(_name_id=None,admin_metadata={},attach_status='detached',availability_zone='zone2',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2020-10-19T10:15:35Z,deleted=False,deleted_at=None,display_description='',display_name='demo_pravin16',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='cinder@cinder-ceph-az2-arbor#cinder-ceph-az2-arbor',id=63e4d69c-0722-40fc-b44f-cb59fca0d435,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='0c0bb65d03f446ca8a845d1ae9229790',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2020-10-19T10:15:36Z,service_uuid=None,shared_targets=True,size=20,snapshot_id=None,snapshots=<?>,source_volid=None,status='downloading',terminated_at=None,updated_at=2020-10-19T10:15:36Z,user_id='f2ee9e8060e54d058060d220fab84088',volume_attachment=<?>,volume_type=VolumeType(f3fec838-26e1-4fd5-a315-6985f9b3cd5c),volume_type_id=f3fec838-26e1-4fd5-a315-6985f9b3cd5c), 'request_spec': RequestSpec(CG_backend=<?>,availability_zones=['zone2'],backup_id=None,cgsnapshot_id=None,consistencygroup_id=None,group_backend=<?>,group_id=None,image_id=e93f97e0-f514-435d-a277-0ac288ed0c6c,operation='create_volume',resource_backend=<?>,snapshot_id=None,source_replicaid=<?>,source_volid=None,volume=Volume(63e4d69c-0722-40fc-b44f-cb59fca0d435),volume_id=63e4d69c-0722-40fc-b44f-cb59fca0d435,volume_properties=VolumeProperties,volume_type=VolumeType(f3fec838-26e1-4fd5-a315-6985f9b3cd5c))}, 'provides': {'status': 'creating', 'type': 'image', 'volume_id': '63e4d69c-0722-40fc-b44f-cb59fca0d435', 'volume_name': 'volume-63e4d69c-0722-40fc-b44f-cb59fca0d435', 'volume_size': 20, 'image_id': 'e93f97e0-f514-435d-a277-0ac288ed0c6c', 'image_location': ('rbd://36bd979e-0511-11eb-bced-ecebb88db476/glance/e93f97e0-f514-435d-a277-0ac288ed0c6c/snap', [{'url': 'rbd://36bd979e-0511-11eb-bced-ecebb88db476/glance/e93f97e0-f514-435d-a277-0ac288ed0c6c/snap', 'metadata': {}}]), 'image_meta': {'name': 'UBUNTU-18.04', 'disk_format': 'qcow2', 'container_format': 'bare', 'visibility': 'public', 'size': 359923712, 'virtual_size': None, 'status': 'active', 'checksum': '9aa011b2b79b1fe42a7c306555923b1b', 'protected': False, 'min_ram': 0, 'min_disk': 0, 'owner': '86fcc0b3839b45029dd325641ddc2a09', 'os_hidden': False, 'os_hash_algo': 'sha512', 'os_hash_value': '03786c51866c1c6c50ef671502b265afb71084e0d018748ca9b29f871ca5445c9eefffffdf927d540bddaf0e8597adc673e218e785fcf16013fba7e7d9898e6e', 'id': 'e93f97e0-f514-435d-a277-0ac288ed0c6c', 'created_at': datetime.datetime(2020, 10, 15, 16, 49, tzinfo=<iso8601.Utc>), 'updated_at': datetime.datetime(2020, 10, 15, 16, 49, 18, tzinfo=<iso8601.Utc>), 'locations': [{'url': 'rbd://36bd979e-0511-11eb-bced-ecebb88db476/glance/e93f97e0-f514-435d-a277-0ac288ed0c6c/snap', 'metadata': {}}], 'direct_url': 'rbd://36bd979e-0511-11eb-bced-ecebb88db476/glance/e93f97e0-f514-435d-a277-0ac288ed0c6c/snap', 'tags': [], 'file': '/v2/images/e93f97e0-f514-435d-a277-0ac288ed0c6c/file', 'properties': {}}, 'image_service': <cinder.image.glance.GlanceImageService object at 0x7fb92712cda0>}}
     |__Atom 'cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create' {'intention': 'EXECUTE', 'state': 'SUCCESS', 'requires': {'filter_properties': {'retry': {'num_attempts': 1, 'backends': ['cinder@cinder-ceph-az2-arbor#cinder-ceph-az2-arbor'], 'hosts': ['cinder@cinder-ceph-az2-arbor#cinder-ceph-az2-arbor']}, 'request_spec': {'consistencygroup_id': None, 'group_id': None, 'cgsnapshot_id': None, 'image_id': 'e93f97e0-f514-435d-a277-0ac288ed0c6c', 'snapshot_id': None, 'source_volid': None, 'volume_id': '63e4d69c-0722-40fc-b44f-cb59fca0d435', 'volume': {'id': '63e4d69c-0722-40fc-b44f-cb59fca0d435', '_name_id': None, 'ec2_id': None, 'user_id': 'f2ee9e8060e54d058060d220fab84088', 'project_id': '0c0bb65d03f446ca8a845d1ae9229790', 'snapshot_id': None, 'cluster_name': None, 'host': None, 'size': 20, 'availability_zone': 'zone2', 'status': 'creating', 'attach_status': 'detached', 'migration_status': None, 'scheduled_at': None, 'launched_at': None, 'terminated_at': None, 'display_name': 'demo_pravin16', 'display_description': '', 'provider_id': None, 'provider_location': None, 'provider_auth': None, 'provider_geometry': None, 'volume_type_id': 'f3fec838-26e1-4fd5-a315-6985f9b3cd5c', 'source_volid': None, 'encryption_key_id': None, 'consistencygroup_id': None, 'group_id': None, 'deleted': False, 'bootable': False, 'multiattach': False, 'replication_status': None, 'replication_extended_status': None, 'replication_driver_data': None, 'previous_status': None, 'metadata': {}, 'service_uuid': None, 'shared_targets': True, 'created_at': '2020-10-19T10:15:35.000000', 'updated_at': None, 'deleted_at': None, 'name': 'volume-63e4d69c-0722-40fc-b44f-cb59fca0d435', 'name_id': '63e4d69c-0722-40fc-b44f-cb59fca0d435', 'volume_metadata': [], 'volume_admin_metadata': [], 'volume_glance_metadata': []}, 'volume_type': {'id': 'f3fec838-26e1-4fd5-a315-6985f9b3cd5c', 'name': 'arbor-az2', 'description': None, 'is_public': True, 'projects': [], 'extra_specs': {'volume_backend_name': 'cinder-ceph-az2-arbor', 'RESKEY:availability_zones': 'zone2'}, 'qos_specs_id': '2d5ee9fe-e8f4-4d0a-9095-863dd7896891', 'created_at': '2020-10-03T05:29:17.000000', 'updated_at': '2020-10-14T19:56:11.000000', 'deleted_at': None, 'deleted': False}, 'volume_properties': {'attach_status': 'detached', 'availability_zone': 'zone2', 'cgsnapshot_id': None, 'consistencygroup_id': None, 'group_id': None, 'display_description': '', 'display_name': 'demo_pravin16', 'encryption_key_id': None, 'metadata': {}, 'multiattach': False, 'project_id': '0c0bb65d03f446ca8a845d1ae9229790', 'qos_specs': {'total_bytes_sec_per_gb_min': '.25', 'total_iops_sec_per_gb': '5', 'total_iops_sec_per_gb_min': '20'}, 'reservations': ['14a503b6-25a1-4216-b9c6-7975b31904e9', '880d345a-962c-4f59-a74d-d4ba94157684', '72f3690e-ce4a-431a-a776-6b8e5717e295', '3ea62e14-0e83-4fc2-9ced-839d184c4f46'], 'size': 20, 'snapshot_id': None, 'source_volid': None, 'status': 'creating', 'user_id': 'f2ee9e8060e54d058060d220fab84088', 'volume_type_id': 'f3fec838-26e1-4fd5-a315-6985f9b3cd5c'}, 'backup_id': None, 'operation': 'create_volume', 'availability_zones': ['zone2'], 'resource_properties': {'attach_status': 'detached', 'availability_zone': 'zone2', 'cgsnapshot_id': None, 'consistencygroup_id': None, 'group_id': None, 'display_description': '', 'display_name': 'demo_pravin16', 'encryption_key_id': None, 'metadata': {}, 'multiattach': False, 'project_id': '0c0bb65d03f446ca8a845d1ae9229790', 'qos_specs': {'total_bytes_sec_per_gb_min': '.25', 'total_iops_sec_per_gb': '5', 'total_iops_sec_per_gb_min': '20'}, 'reservations': ['14a503b6-25a1-4216-b9c6-7975b31904e9', '880d345a-962c-4f59-a74d-d4ba94157684', '72f3690e-ce4a-431a-a776-6b8e5717e295', '3ea62e14-0e83-4fc2-9ced-839d184c4f46'], 'size': 20, 'snapshot_id': None, 'source_volid': None, 'status': 'creating', 'user_id': 'f2ee9e8060e54d058060d220fab84088', 'volume_type_id': 'f3fec838-26e1-4fd5-a315-6985f9b3cd5c'}}, 'config_options': {}, 'volume_type': VolumeType(created_at=2020-10-03T05:29:17Z,deleted=False,deleted_at=None,description=None,extra_specs={RESKEY:availability_zones='zone2',volume_backend_name='cinder-ceph-az2-arbor'},id=f3fec838-26e1-4fd5-a315-6985f9b3cd5c,is_public=True,name='arbor-az2',projects=[],qos_specs=<?>,qos_specs_id=2d5ee9fe-e8f4-4d0a-9095-863dd7896891,updated_at=2020-10-14T19:56:11Z), 'resource_type': VolumeType(created_at=2020-10-03T05:29:17Z,deleted=False,deleted_at=None,description=None,extra_specs={RESKEY:availability_zones='zone2',volume_backend_name='cinder-ceph-az2-arbor'},id=f3fec838-26e1-4fd5-a315-6985f9b3cd5c,is_public=True,name='arbor-az2',projects=[],qos_specs=<?>,qos_specs_id=2d5ee9fe-e8f4-4d0a-9095-863dd7896891,updated_at=2020-10-14T19:56:11Z), 'size': 20, 'availability_zone': 'zone2', 'user_id': 'f2ee9e8060e54d058060d220fab84088', 'metadata': {}, 'qos_specs': {'total_bytes_sec_per_gb_min': '.25', 'total_iops_sec_per_gb': '5', 'total_iops_sec_per_gb_min': '20'}}, 'request_spec': RequestSpec(CG_backend=<?>,availability_zones=['zone2'],backup_id=None,cgsnapshot_id=None,consistencygroup_id=None,group_backend=<?>,group_id=None,image_id=e93f97e0-f514-435d-a277-0ac288ed0c6c,operation='create_volume',resource_backend=<?>,snapshot_id=None,source_replicaid=<?>,source_volid=None,volume=Volume(63e4d69c-0722-40fc-b44f-cb59fca0d435),volume_id=63e4d69c-0722-40fc-b44f-cb59fca0d435,volume_properties=VolumeProperties,volume_type=VolumeType(f3fec838-26e1-4fd5-a315-6985f9b3cd5c)), 'volume': Volume(_name_id=None,admin_metadata={},attach_status='detached',availability_zone='zone2',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2020-10-19T10:15:35Z,deleted=False,deleted_at=None,display_description='',display_name='demo_pravin16',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='cinder@cinder-ceph-az2-arbor#cinder-ceph-az2-arbor',id=63e4d69c-0722-40fc-b44f-cb59fca0d435,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='0c0bb65d03f446ca8a845d1ae9229790',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2020-10-19T10:15:36Z,service_uuid=None,shared_targets=True,size=20,snapshot_id=None,snapshots=<?>,source_volid=None,status='downloading',terminated_at=None,updated_at=2020-10-19T10:15:36Z,user_id='f2ee9e8060e54d058060d220fab84088',volume_attachment=<?>,volume_type=VolumeType(f3fec838-26e1-4fd5-a315-6985f9b3cd5c),volume_type_id=f3fec838-26e1-4fd5-a315-6985f9b3cd5c), 'context': <cinder.context.RequestContext object at 0x7fb927296f28>}, 'provides': None}
        |__Atom 'cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create' {'intention': 'EXECUTE', 'state': 'SUCCESS', 'requires': {'context': <cinder.context.RequestContext object at 0x7fb927296f28>, 'volume': Volume(_name_id=None,admin_metadata={},attach_status='detached',availability_zone='zone2',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2020-10-19T10:15:35Z,deleted=False,deleted_at=None,display_description='',display_name='demo_pravin16',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='cinder@cinder-ceph-az2-arbor#cinder-ceph-az2-arbor',id=63e4d69c-0722-40fc-b44f-cb59fca0d435,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='0c0bb65d03f446ca8a845d1ae9229790',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2020-10-19T10:15:36Z,service_uuid=None,shared_targets=True,size=20,snapshot_id=None,snapshots=<?>,source_volid=None,status='downloading',terminated_at=None,updated_at=2020-10-19T10:15:36Z,user_id='f2ee9e8060e54d058060d220fab84088',volume_attachment=<?>,volume_type=VolumeType(f3fec838-26e1-4fd5-a315-6985f9b3cd5c),volume_type_id=f3fec838-26e1-4fd5-a315-6985f9b3cd5c)}, 'provides': Volume(_name_id=None,admin_metadata={},attach_status='detached',availability_zone='zone2',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2020-10-19T10:15:35Z,deleted=False,deleted_at=None,display_description='',display_name='demo_pravin16',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='cinder@cinder-ceph-az2-arbor#cinder-ceph-az2-arbor',id=63e4d69c-0722-40fc-b44f-cb59fca0d435,launched_at=None,metadata={},migration_status=None,multiattach=False,previous_status=None,project_id='0c0bb65d03f446ca8a845d1ae9229790',provider_auth=None,provider_geometry=None,provider_id=None,provider_location=None,replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2020-10-19T10:15:36Z,service_uuid=None,shared_targets=True,size=20,snapshot_id=None,snapshots=<?>,source_volid=None,status='downloading',terminated_at=None,updated_at=2020-10-19T10:15:36Z,user_id='f2ee9e8060e54d058060d220fab84088',volume_attachment=<?>,volume_type=VolumeType(f3fec838-26e1-4fd5-a315-6985f9b3cd5c),volume_type_id=f3fec838-26e1-4fd5-a315-6985f9b3cd5c)}
           |__Flow 'volume_create_manager': cinder.exception.ImageCopyFailure: Failed to copy image to volume: deleting volume volume-63e4d69c-0722-40fc-b44f-cb59fca0d435 that has snapshot
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager Traceback (most recent call last):
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/volume_utils.py", line 1153, in copy_image_to_volume
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     context, volume, image_service, image_id)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py", line 1527, in copy_image_to_volume
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     self._copy_image_to_volume(context, volume, image_service, image_id)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py", line 1575, in _copy_image_to_volume
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     self.delete_volume(volume)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py", line 1135, in delete_volume
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     raise exception.VolumeIsBusy(volume_name=volume_name)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager cinder.exception.VolumeIsBusy: deleting volume volume-63e4d69c-0722-40fc-b44f-cb59fca0d435 that has snapshot
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager During handling of the above exception, another exception occurred:
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager Traceback (most recent call last):
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     result = task.execute(**arguments)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 1135, in execute
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     **volume_spec)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/utils.py", line 696, in _wrapper
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     return r.call(f, *args, **kwargs)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/retrying.py", line 206, in call
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     return attempt.get(self._wrap_exception)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/retrying.py", line 247, in get
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     six.reraise(self.value[0], self.value[1], self.value[2])
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     raise value
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/retrying.py", line 200, in call
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 1025, in _create_from_image
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     image_service)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "<decorator-gen-238>", line 2, in _prepare_image_cache_entry
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/coordination.py", line 151, in _synchronized
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     return f(*a, **k)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 823, in _prepare_image_cache_entry
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     update_cache=True)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 926, in _create_from_image_cache_or_download
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     image_service
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 739, in _create_from_image_download
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     image_service)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager   File "/usr/lib/python3/dist-packages/cinder/volume/volume_utils.py", line 1169, in copy_image_to_volume
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager     raise exception.ImageCopyFailure(reason=ex)
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager cinder.exception.ImageCopyFailure: Failed to copy image to volume: deleting volume volume-63e4d69c-0722-40fc-b44f-cb59fca0d435 that has snapshot
2020-10-19 10:15:45.125 45458 ERROR cinder.volume.manager
2020-10-19 10:15:45.130 45458 WARNING cinder.volume.manager [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Task 'cinder.volume.flows.manager.create_volume.CreateVolumeFromSpecTask;volume:create' (99bc2fa2-1ae2-4d84-80be-07324276e5d3) transitioned into state 'REVERTED' from state 'REVERTING'
2020-10-19 10:15:45.132 45458 WARNING cinder.volume.manager [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Task 'cinder.volume.flows.manager.create_volume.NotifyVolumeActionTask;volume:create, create.start' (8d1d4f29-610d-4e6e-8067-d1ed34343659) transitioned into state 'REVERTED' from state 'REVERTING'
2020-10-19 10:15:45.134 45458 WARNING cinder.volume.manager [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeSpecTask;volume:create' (43f38186-ce05-4fa6-b891-e0e04130d36d) transitioned into state 'REVERTED' from state 'REVERTING'
2020-10-19 10:15:45.139 45458 ERROR cinder.volume.flows.manager.create_volume [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Volume 63e4d69c-0722-40fc-b44f-cb59fca0d435: create failed
2020-10-19 10:15:45.140 45458 WARNING cinder.volume.manager [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Task 'cinder.volume.flows.manager.create_volume.OnFailureRescheduleTask;volume:create' (ae33bb7b-1806-4945-8a91-e192013f466d) transitioned into state 'REVERTED' from state 'REVERTING'
2020-10-19 10:15:45.142 45458 WARNING cinder.volume.manager [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Task 'cinder.volume.flows.manager.create_volume.ExtractVolumeRefTask;volume:create' (43f4d9db-0709-43eb-880d-46c40f0a507f) transitioned into state 'REVERTED' from state 'REVERTING'
2020-10-19 10:15:45.144 45458 WARNING cinder.volume.manager [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Flow 'volume_create_manager' (efe3fac0-00e0-4f43-951c-0438b15ef447) transitioned into state 'REVERTED' from state 'RUNNING'
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server [req-a4905f43-c6f8-42e4-a602-a00238068492 f2ee9e8060e54d058060d220fab84088 0c0bb65d03f446ca8a845d1ae9229790 - 1e59a4057fb24003a902bc4df6247d3c 1e59a4057fb24003a902bc4df6247d3c] Exception during message handling: cinder.exception.ImageCopyFailure: Failed to copy image to volume: deleting volume volume-63e4d69c-0722-40fc-b44f-cb59fca0d435 that has snapshot
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/volume_utils.py", line 1153, in copy_image_to_volume
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     context, volume, image_service, image_id)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py", line 1527, in copy_image_to_volume
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     self._copy_image_to_volume(context, volume, image_service, image_id)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py", line 1575, in _copy_image_to_volume
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     self.delete_volume(volume)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/drivers/rbd.py", line 1135, in delete_volume
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     raise exception.VolumeIsBusy(volume_name=volume_name)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server cinder.exception.VolumeIsBusy: deleting volume volume-63e4d69c-0722-40fc-b44f-cb59fca0d435 that has snapshot
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server During handling of the above exception, another exception occurred:
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/oslo_messaging/rpc/server.py", line 165, in _process_incoming
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/oslo_messaging/rpc/dispatcher.py", line 274, in dispatch
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/oslo_messaging/rpc/dispatcher.py", line 194, in _do_dispatch
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "<decorator-gen-239>", line 2, in create_volume
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/objects/cleanable.py", line 212, in wrapper
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     result = f(*args, **kwargs)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 749, in create_volume
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     _run_flow()
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/manager.py", line 741, in _run_flow
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     flow_engine.run()
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/taskflow/engines/action_engine/engine.py", line 247, in run
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     for _state in self.run_iter(timeout=timeout):
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/taskflow/engines/action_engine/engine.py", line 340, in run_iter
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     failure.Failure.reraise_if_any(er_failures)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/taskflow/types/failure.py", line 339, in reraise_if_any
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     failures[0].reraise()
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/taskflow/types/failure.py", line 346, in reraise
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     six.reraise(*self._exc_info)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     raise value
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     result = task.execute(**arguments)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 1135, in execute
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     **volume_spec)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/utils.py", line 696, in _wrapper
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     return r.call(f, *args, **kwargs)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/retrying.py", line 206, in call
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     return attempt.get(self._wrap_exception)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/retrying.py", line 247, in get
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     six.reraise(self.value[0], self.value[1], self.value[2])
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/six.py", line 693, in reraise
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     raise value
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/retrying.py", line 200, in call
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     attempt = Attempt(fn(*args, **kwargs), attempt_number, False)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 1025, in _create_from_image
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     image_service)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "<decorator-gen-238>", line 2, in _prepare_image_cache_entry
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/coordination.py", line 151, in _synchronized
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     return f(*a, **k)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 823, in _prepare_image_cache_entry
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     update_cache=True)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 926, in _create_from_image_cache_or_download
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     image_service
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/flows/manager/create_volume.py", line 739, in _create_from_image_download
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     image_service)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server   File "/usr/lib/python3/dist-packages/cinder/volume/volume_utils.py", line 1169, in copy_image_to_volume
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server     raise exception.ImageCopyFailure(reason=ex)
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server cinder.exception.ImageCopyFailure: Failed to copy image to volume: deleting volume volume-63e4d69c-0722-40fc-b44f-cb59fca0d435 that has snapshot
2020-10-19 10:15:45.156 45458 ERROR oslo_messaging.rpc.server