Some additional details from Log investigation

The test that fails is expected to perform the following operations.
1-	Create a Volume 1.
2-	Create a Volume 2.
3-	Create and boot 2 instances Server 1 and Server 2.
4-	Attach Volume 1 to Server 1.
5-	Attach Volume 1 to Server 2.
6-	Swap Volume 1 with Volume 2 on Server 1.
7-	Check that Volume 1 is attached to Server 2.
8-	Check that Volume 1 is NOT attached to Server 1.
9-	Check that Volume 2 is attached to Server 1.
10-	Clean up and Exit

From the details below.  It is not clear what is causing the long detach as reported by tempest.


In the Tempest.log file you will find (See tempest.log clipping attached)

- Volume 1 is successfully created (ID: a54c67b7-786e-4ba7-94ea-d1e0a722424a)
                - However it take close to 5mins to create volume 1.
- Volume 2 is successfully created (ID: 9c237d89-284d-4608-8585-97f5be2fdb87)
                - Volume 2 is created in 15secs.
- Two instances (servers) 1 and 2 are successfully created (Server 1 ID: 43ba7e9c-8923-4587-bbd8-c91cf6ea6458 and Server 2 ID: 986b2dd5-542a-4344-a929-9ac7bbf35d7c)
- Volume 1 is successfully attached to Server 1 – Attachment ID: 02b20af4-af46-4f9e-840b-4664ebc093e0
- Volume 1 is successfully attached to Server 2 – Attachment ID: d5a7a2fa-7d22-4827-8c9b-e068727a927c
- Swap Volume 1 with Volume 2 on Server 2

2022-09-09 15:03:59.542 2703951 INFO tempest.lib.common.rest_client [req-75469d39-ab9e-48d6-b727-41448acc54d4 req-75469d39-ab9e-48d6-b727-41448acc54d4 ] Request (TestMultiAttachVolumeSwap:test_volume_swap_with_multiattach): 202 PUT http://15.113.218.46/compute/v2.1/servers/43ba7e9c-8923-4587-bbd8-c91cf6ea6458/os-volume_attachments/a54c67b7-786e-4ba7-94ea-d1e0a722424a 0.563s
2022-09-09 15:03:59.543 2703951 DEBUG tempest.lib.common.rest_client [req-75469d39-ab9e-48d6-b727-41448acc54d4 req-75469d39-ab9e-48d6-b727-41448acc54d4 ] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.60', 'X-Auth-Token': '<omitted>'}
        Body: {"volumeAttachment": {"volumeId": "9c237d89-284d-4608-8585-97f5be2fdb87"}}
    Response - Headers: {'date': 'Fri, 09 Sep 2022 22:03:58 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-length': '0', 'content-type': 'application/json', 'openstack-api-version': 'compute 2.60', 'x-openstack-nova-api-version': '2.60', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', 'x-openstack-request-id': 'req-75469d39-ab9e-48d6-b727-41448acc54d4', 'x-compute-request-id': 'req-75469d39-ab9e-48d6-b727-41448acc54d4', 'connection': 'close', 'status': '202', 'content-location': 'http://15.113.218.46/compute/v2.1/servers/43ba7e9c-8923-4587-bbd8-c91cf6ea6458/os-volume_attachments/a54c67b7-786e-4ba7-94ea-d1e0a722424a'}
        Body: b'' _log_request_full /opt/stack/tempest/tempest/lib/common/rest_client.py:455


- Check Volume 1 attachments:
                - Volume 1 is attached to Server 1 – Status: Detaching
                - Volume 1 is attached to Server 2

2022-09-09 15:03:59.614 2703951 INFO tempest.lib.common.rest_client [req-a6d4d438-52cc-4d7c-8a19-cd700b230357 req-a6d4d438-52cc-4d7c-8a19-cd700b230357 ] Request (TestMultiAttachVolumeSwap:test_volume_swap_with_multiattach): 200 GET http://15.113.218.46/volume/v3/70081f644bd940ad8c0fccdb60a7265d/volumes/a54c67b7-786e-4ba7-94ea-d1e0a722424a 0.070s
2022-09-09 15:03:59.615 2703951 DEBUG tempest.lib.common.rest_client [req-a6d4d438-52cc-4d7c-8a19-cd700b230357 req-a6d4d438-52cc-4d7c-8a19-cd700b230357 ] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Fri, 09 Sep 2022 22:03:59 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'x-compute-request-id': 'req-a6d4d438-52cc-4d7c-8a19-cd700b230357', 'content-length': '1525', 'openstack-api-version': 'volume 3.0', 'vary': 'OpenStack-API-Version', 'x-openstack-request-id': 'req-a6d4d438-52cc-4d7c-8a19-cd700b230357', 'connection': 'close', 'status': '200', 'content-location': 'http://15.113.218.46/volume/v3/70081f644bd940ad8c0fccdb60a7265d/volumes/a54c67b7-786e-4ba7-94ea-d1e0a722424a'}
        Body: b'{"volume": {"id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "status": "detaching", "size": 1, "availability_zone": "nova", "created_at": "2022-09-09T21:57:07.000000", "updated_at": "2022-09-09T22:03:59.000000", "name": "tempest-TestMultiAttachVolumeSwap-volume-2047598637", "description": null, "volume_type": "hpexp", "snapshot_id": null, "source_volid": null, "metadata": {"readonly": "True"}, "links": [{"rel": "self", "href": http://15.113.218.46/volume/v3/70081f644bd940ad8c0fccdb60a7265d/volumes/a54c67b7-786e-4ba7-94ea-d1e0a722424a}, {"rel": "bookmark", "href": http://15.113.218.46/volume/70081f644bd940ad8c0fccdb60a7265d/volumes/a54c67b7-786e-4ba7-94ea-d1e0a722424a}], "user_id": "556bc4c0a262402fbc17bbf775d94ad9", "bootable": "false", "encrypted": false, "replication_status": null, "consistencygroup_id": null, "multiattach": true, "attachments": [{"id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "attachment_id": "02b20af4-af46-4f9e-840b-4664ebc093e0", "volume_id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "server_id": "43ba7e9c-8923-4587-bbd8-c91cf6ea6458", "host_name": null, "device": "/dev/vdb", "attached_at": "2022-09-09T22:03:37.000000"}, {"id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "attachment_id": "d5a7a2fa-7d22-4827-8c9b-e068727a927c", "volume_id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "server_id": "986b2dd5-542a-4344-a929-9ac7bbf35d7c", "host_name": null, "device": "/dev/vdb", "attached_at": "2022-09-09T22:03:53.000000"}], "os-vol-tenant-attr:tenant_id": "70081f644bd940ad8c0fccdb60a7265d"}}' _log_request_full /opt/stack/tempest/tempest/lib/common/rest_client.py:455


- Repeat Check for Volume 1 attachments
                - Volume 1 is attached to Server 1 – Status: Detaching
- 13MINS LATER (Tempest reports, Volume 1 is not detaching from Instance 1 when the Swap is invoked).
                - Volume 1 is STILL attached to Server 1 (BAD) – Status: Detaching.
                - Volume 1 is attached to Server 2 (GOOD) – Expected.

2022-09-09 15:17:06.842 2703951 INFO tempest.lib.common.rest_client [req-5184bc29-1878-4cae-a598-460b86ef2675 req-5184bc29-1878-4cae-a598-460b86ef2675 ] Request (TestMultiAttachVolumeSwap:_run_cleanups): 200 GET http://15.113.218.46/volume/v3/70081f644bd940ad8c0fccdb60a7265d/volumes/a54c67b7-786e-4ba7-94ea-d1e0a722424a 0.073s
2022-09-09 15:17:06.843 2703951 DEBUG tempest.lib.common.rest_client [req-5184bc29-1878-4cae-a598-460b86ef2675 req-5184bc29-1878-4cae-a598-460b86ef2675 ] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Fri, 09 Sep 2022 22:17:06 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'content-type': 'application/json', 'x-compute-request-id': 'req-5184bc29-1878-4cae-a598-460b86ef2675', 'content-length': '1525', 'openstack-api-version': 'volume 3.0', 'vary': 'OpenStack-API-Version', 'x-openstack-request-id': 'req-5184bc29-1878-4cae-a598-460b86ef2675', 'connection': 'close', 'status': '200', 'content-location': 'http://15.113.218.46/volume/v3/70081f644bd940ad8c0fccdb60a7265d/volumes/a54c67b7-786e-4ba7-94ea-d1e0a722424a'}
        Body: b'{"volume": {"id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "status": "detaching", "size": 1, "availability_zone": "nova", "created_at": "2022-09-09T21:57:07.000000", "updated_at": "2022-09-09T22:03:59.000000", "name": "tempest-TestMultiAttachVolumeSwap-volume-2047598637", "description": null, "volume_type": "hpexp", "snapshot_id": null, "source_volid": null, "metadata": {"readonly": "True"}, "links": [{"rel": "self", "href": http://15.113.218.46/volume/v3/70081f644bd940ad8c0fccdb60a7265d/volumes/a54c67b7-786e-4ba7-94ea-d1e0a722424a}, {"rel": "bookmark", "href": http://15.113.218.46/volume/70081f644bd940ad8c0fccdb60a7265d/volumes/a54c67b7-786e-4ba7-94ea-d1e0a722424a}], "user_id": "556bc4c0a262402fbc17bbf775d94ad9", "bootable": "false", "encrypted": false, "replication_status": null, "consistencygroup_id": null, "multiattach": true, "attachments": [{"id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "attachment_id": "02b20af4-af46-4f9e-840b-4664ebc093e0", "volume_id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "server_id": "43ba7e9c-8923-4587-bbd8-c91cf6ea6458", "host_name": null, "device": "/dev/vdb", "attached_at": "2022-09-09T22:03:37.000000"}, {"id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "attachment_id": "d5a7a2fa-7d22-4827-8c9b-e068727a927c", "volume_id": "a54c67b7-786e-4ba7-94ea-d1e0a722424a", "server_id": "986b2dd5-542a-4344-a929-9ac7bbf35d7c", "host_name": null, "device": "/dev/vdb", "attached_at": "2022-09-09T22:03:53.000000"}], "os-vol-tenant-attr:tenant_id": "70081f644bd940ad8c0fccdb60a7265d"}}' _log_request_full /opt/stack/tempest/tempest/lib/common/rest_client.py:455


- Check Server 2 Volume attachments
                - Volume 1 is attached to Server 2 (GOOD) – Expected.
- Check Volume 1 Server Attachments (1HR LATER):
                - Volume 1 NOT attached to Server 1 (GOOD) – Expected but took a LONG TIME.
                - Volume 1 is attached to Server 2 (GOOD) – Expected.  Status: In Use.
- Delete Volume 1 attachment to Server 1
                - Fails.  Volume 1 is NOT attached to Server 1.

2022-09-09 16:17:19.927 2703951 INFO tempest.lib.common.rest_client [req-f3a2a077-81f7-4110-abb4-eaeb5f471d30 req-f3a2a077-81f7-4110-abb4-eaeb5f471d30 ] Request (TestMultiAttachVolumeSwap:_run_cleanups): 404 DELETE http://15.113.218.46/compute/v2.1/servers/43ba7e9c-8923-4587-bbd8-c91cf6ea6458/os-volume_attachments/a54c67b7-786e-4ba7-94ea-d1e0a722424a 0.565s
2022-09-09 16:17:19.927 2703951 DEBUG tempest.lib.common.rest_client [req-f3a2a077-81f7-4110-abb4-eaeb5f471d30 req-f3a2a077-81f7-4110-abb4-eaeb5f471d30 ] Request - Headers: {'Content-Type': 'application/json', 'Accept': 'application/json', 'X-OpenStack-Nova-API-Version': '2.60', 'X-Auth-Token': '<omitted>'}
        Body: None
    Response - Headers: {'date': 'Fri, 09 Sep 2022 23:17:19 GMT', 'server': 'Apache/2.4.41 (Ubuntu)', 'openstack-api-version': 'compute 2.60', 'x-openstack-nova-api-version': '2.60', 'vary': 'OpenStack-API-Version,X-OpenStack-Nova-API-Version', 'content-type': 'application/json; charset=UTF-8', 'content-length': '154', 'x-openstack-request-id': 'req-f3a2a077-81f7-4110-abb4-eaeb5f471d30', 'x-compute-request-id': 'req-f3a2a077-81f7-4110-abb4-eaeb5f471d30', 'connection': 'close', 'status': '404', 'content-location': 'http://15.113.218.46/compute/v2.1/servers/43ba7e9c-8923-4587-bbd8-c91cf6ea6458/os-volume_attachments/a54c67b7-786e-4ba7-94ea-d1e0a722424a'}
        Body: b'{"itemNotFound": {"code": 404, "message": "Instance 43ba7e9c-8923-4587-bbd8-c91cf6ea6458 is not attached to volume a54c67b7-786e-4ba7-94ea-d1e0a722424a"}}' _log_request_full /opt/stack/tempest/tempest/lib/common/rest_client.py:455
- Clean Up



In cinder-volume.log ( See clipping attached)

- cinder.volume.manager create successfully Volume 1 (ID: a54c67b7-786e-4ba7-94ea-d1e0a722424a)
- cinder.volume.manager create successfully Volume 2 (ID: 9c237d89-284d-4608-8585-97f5be2fdb87)

Then there are two successful attachments of volume 1 
- cinder.volume.drivers.hpe.xp.hpe_xp_iscsi Initialize Volume 1 attachment successfully to Server 1 (see attachment ID)

DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-5e29448c-8678-42ba-a5f3-a55eb515e04d req-dc4186ed-8317-47b1-b8aa-3fa4d4c46358 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35m==> initialize_connection: call "{'self': <cinder.volume.drivers.hpe.xp.hpe_xp_iscsi.HPEXPISCSIDriver object at 0x7f835e807dc0>, 'volume': Volume(_name_id=None,admin_metadata=<?>,attach_status='detached',availability_zone='nova',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2022-09-09T21:57:07Z,deleted=False,deleted_at=None,display_description=None,display_name='tempest-TestMultiAttachVolumeSwap-volume-2047598637',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='luminex2.ros.storage.hpecorp.net@hpexp#hpexp',id=a54c67b7-786e-4ba7-94ea-d1e0a722424a,launched_at=2022-09-09T22:01:57Z,metadata={},migration_status=None,multiattach=True,previous_status=None,project_id='70081f644bd940ad8c0fccdb60a7265d',provider_auth=None,provider_geometry=None,provider_id=None,provider_location='44686',replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2022-09-09T21:57:08Z,service_uuid='b3e99e9e-14b4-446f-a561-9a2f0219319e',shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='reserved',terminated_at=None,updated_at=2022-09-09T22:03:28Z,use_quota=True,user_id='556bc4c0a262402fbc17bbf775d94ad9',volume_attachment=VolumeAttachmentList,volume_type=VolumeType(4da632ef-3e6e-4716-bf4b-923f436c475e),volume_type_id=4da632ef-3e6e-4716-bf4b-923f436c475e), 'connector': {'platform': 'x86_64', 'os_type': 'linux', 'ip': '15.113.218.46', 'host': 'luminex2.ros.storage.hpecorp.net', 'multipath': False, 'initiator': 'iqn.2005-03.org.open-iscsi:6680bc34b699', 'do_local_attach': False, 'uuid': 'bb122d1c-28ef-4893-a142-cab155363baf', 'system uuid': 'ed832742-2186-e2d8-4d3d-590b0e3e804c', 'mountpoint': '/dev/vdb', 'mode': 'ro'}}"[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1485}}[00m
DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-5e29448c-8678-42ba-a5f3-a55eb515e04d req-dc4186ed-8317-47b1-b8aa-3fa4d4c46358 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35m<== initialize_connection: return (8343ms) {'driver_volume_type': 'iscsi', 'data': {'target_portal': '192.168.0.57:3260', 'target_iqn': 'iqn.2005-03.org.open-iscsi:fcdef5ffc8a8.hpexp-target', 'target_discovered': False, 'target_lun': 0}}[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1510}}[00m

DEBUG cinder.volume.manager [[01;36mreq-5e29448c-8678-42ba-a5f3-a55eb515e04d req-dc4186ed-8317-47b1-b8aa-3fa4d4c46358 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mConnection info returned from driver {'target_portal': '192.168.0.57:3260', 'target_iqn': 'iqn.2005-03.org.open-iscsi:fcdef5ffc8a8.hpexp-target', 'target_discovered': False, 'target_lun': 0, 'qos_specs': None, 'access_mode': 'rw', 'encrypted': False, 'cacheable': False, 'driver_volume_type': 'iscsi', 'attachment_id': '02b20af4-af46-4f9e-840b-4664ebc093e0'}[00m [00;33m{{(pid=2573474) _connection_create /opt/stack/cinder/cinder/volume/manager.py:4827}}[00m
INFO cinder.volume.manager [[01;36mreq-5e29448c-8678-42ba-a5f3-a55eb515e04d req-dc4186ed-8317-47b1-b8aa-3fa4d4c46358 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mattachment_update completed successfully.[00m


- cinder.volume.drivers.hpe.xp.hpe_xp_iscsi Initialize Volume 1 attachment successfully to Server 2 (see attachment ID)

DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-ca3aac1e-f37e-4ab5-b298-36cdc50a998e req-84f56686-f482-464e-a5e2-5d8078685711 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35m==> initialize_connection: call "{'self': <cinder.volume.drivers.hpe.xp.hpe_xp_iscsi.HPEXPISCSIDriver object at 0x7f835e807dc0>, 'volume': Volume(_name_id=None,admin_metadata=<?>,attach_status='attached',availability_zone='nova',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2022-09-09T21:57:07Z,deleted=False,deleted_at=None,display_description=None,display_name='tempest-TestMultiAttachVolumeSwap-volume-2047598637',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='luminex2.ros.storage.hpecorp.net@hpexp#hpexp',id=a54c67b7-786e-4ba7-94ea-d1e0a722424a,launched_at=2022-09-09T22:01:57Z,metadata={},migration_status=None,multiattach=True,previous_status=None,project_id='70081f644bd940ad8c0fccdb60a7265d',provider_auth=None,provider_geometry=None,provider_id=None,provider_location='44686',replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2022-09-09T21:57:08Z,service_uuid='b3e99e9e-14b4-446f-a561-9a2f0219319e',shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='reserved',terminated_at=None,updated_at=2022-09-09T22:03:44Z,use_quota=True,user_id='556bc4c0a262402fbc17bbf775d94ad9',volume_attachment=VolumeAttachmentList,volume_type=VolumeType(4da632ef-3e6e-4716-bf4b-923f436c475e),volume_type_id=4da632ef-3e6e-4716-bf4b-923f436c475e), 'connector': {'platform': 'x86_64', 'os_type': 'linux', 'ip': '15.113.218.46', 'host': 'luminex2.ros.storage.hpecorp.net', 'multipath': False, 'initiator': 'iqn.2005-03.org.open-iscsi:6680bc34b699', 'do_local_attach': False, 'uuid': 'bb122d1c-28ef-4893-a142-cab155363baf', 'system uuid': 'ed832742-2186-e2d8-4d3d-590b0e3e804c', 'mountpoint': '/dev/vdb', 'mode': 'ro'}}"[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1485}}[00m
DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-ca3aac1e-f37e-4ab5-b298-36cdc50a998e req-84f56686-f482-464e-a5e2-5d8078685711 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35m<== initialize_connection: return (8764ms) {'driver_volume_type': 'iscsi', 'data': {'target_portal': '192.168.0.57:3260', 'target_iqn': 'iqn.2005-03.org.open-iscsi:fcdef5ffc8a8.hpexp-target', 'target_discovered': False, 'target_lun': 0}}[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1510}}[00m

DEBUG cinder.volume.manager [[01;36mreq-ca3aac1e-f37e-4ab5-b298-36cdc50a998e req-84f56686-f482-464e-a5e2-5d8078685711 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mConnection info returned from driver {'target_portal': '192.168.0.57:3260', 'target_iqn': 'iqn.2005-03.org.open-iscsi:fcdef5ffc8a8.hpexp-target', 'target_discovered': False, 'target_lun': 0, 'qos_specs': None, 'access_mode': 'rw', 'encrypted': False, 'cacheable': False, 'driver_volume_type': 'iscsi', 'attachment_id': 'd5a7a2fa-7d22-4827-8c9b-e068727a927c'}[00m [00;33m{{(pid=2573474) _connection_create /opt/stack/cinder/cinder/volume/manager.py:4827}}[00m
INFO cinder.volume.manager [[01;36mreq-ca3aac1e-f37e-4ab5-b298-36cdc50a998e req-84f56686-f482-464e-a5e2-5d8078685711 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mattachment_update completed successfully.[00m


Then there is a successful attachment of Volume 2.  So I assume this is the volume swap because it is related to Volume 2 and has the expected attachment ID.

DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-75469d39-ab9e-48d6-b727-41448acc54d4 req-6c9c7d44-c663-460a-ad51-27f43d6a3fac [00;36mtempest-TestMultiAttachVolumeSwap-857785715 None] [01;35m==> initialize_connection: call "{'self': <cinder.volume.drivers.hpe.xp.hpe_xp_iscsi.HPEXPISCSIDriver object at 0x7f835e807dc0>, 'volume': Volume(_name_id=None,admin_metadata={},attach_status='detached',availability_zone='nova',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2022-09-09T22:02:10Z,deleted=False,deleted_at=None,display_description=None,display_name='tempest-TestMultiAttachVolumeSwap-volume-199234805',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='luminex2.ros.storage.hpecorp.net@hpexp#hpexp',id=9c237d89-284d-4608-8585-97f5be2fdb87,launched_at=2022-09-09T22:02:20Z,metadata={},migration_status=None,multiattach=True,previous_status=None,project_id='70081f644bd940ad8c0fccdb60a7265d',provider_auth=None,provider_geometry=None,provider_id=None,provider_location='44708',replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2022-09-09T22:02:10Z,service_uuid='b3e99e9e-14b4-446f-a561-9a2f0219319e',shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='reserved',terminated_at=None,updated_at=2022-09-09T22:03:59Z,use_quota=True,user_id='556bc4c0a262402fbc17bbf775d94ad9',volume_attachment=VolumeAttachmentList,volume_type=VolumeType(4da632ef-3e6e-4716-bf4b-923f436c475e),volume_type_id=4da632ef-3e6e-4716-bf4b-923f436c475e), 'connector': {'platform': 'x86_64', 'os_type': 'linux', 'ip': '15.113.218.46', 'host': 'luminex2.ros.storage.hpecorp.net', 'multipath': False, 'initiator': 'iqn.2005-03.org.open-iscsi:6680bc34b699', 'do_local_attach': False, 'uuid': 'bb122d1c-28ef-4893-a142-cab155363baf', 'system uuid': 'ed832742-2186-e2d8-4d3d-590b0e3e804c', 'mountpoint': '/dev/vdb'}}"[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1485}}[00m
DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-75469d39-ab9e-48d6-b727-41448acc54d4 req-6c9c7d44-c663-460a-ad51-27f43d6a3fac [00;36mtempest-TestMultiAttachVolumeSwap-857785715 None] [01;35m<== initialize_connection: return (14275ms) {'driver_volume_type': 'iscsi', 'data': {'target_portal': '192.168.0.57:3260', 'target_iqn': 'iqn.2005-03.org.open-iscsi:fcdef5ffc8a8.hpexp-target', 'target_discovered': False, 'target_lun': 1}}[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1510}}[00m
DEBUG cinder.volume.manager [[01;36mreq-75469d39-ab9e-48d6-b727-41448acc54d4 req-6c9c7d44-c663-460a-ad51-27f43d6a3fac [00;36mtempest-TestMultiAttachVolumeSwap-857785715 None] [01;35mConnection info returned from driver {'target_portal': '192.168.0.57:3260', 'target_iqn': 'iqn.2005-03.org.open-iscsi:fcdef5ffc8a8.hpexp-target', 'target_discovered': False, 'target_lun': 1, 'qos_specs': None, 'access_mode': 'rw', 'encrypted': False, 'cacheable': False, 'driver_volume_type': 'iscsi', 'attachment_id': 'ff67412a-b21e-4514-9bc7-bcac93fea294'}[00m [00;33m{{(pid=2573474) _connection_create /opt/stack/cinder/cinder/volume/manager.py:4827}}[00m
INFO cinder.volume.manager [[01;36mreq-75469d39-ab9e-48d6-b727-41448acc54d4 req-6c9c7d44-c663-460a-ad51-27f43d6a3fac [00;36mtempest-TestMultiAttachVolumeSwap-857785715 None] [01;35mattachment_update completed successfully.[00m

Within the same time frame, there appears to be a successful detach of Volume 1 from Instance 1 (See attachment ID)

- cinder.volume.drivers.hpe.xp.hpe_xp_iscsi detach Volume 1 attachment from Instance 1
DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-75469d39-ab9e-48d6-b727-41448acc54d4 req-849fe943-a39e-4dc7-9637-ce391d05b9c4 [00;36mtempest-TestMultiAttachVolumeSwap-857785715 None] [01;35m==> terminate_connection: call "{'self': <cinder.volume.drivers.hpe.xp.hpe_xp_iscsi.HPEXPISCSIDriver object at 0x7f835e807dc0>, 'volume': Volume(_name_id=None,admin_metadata=<?>,attach_status='attached',availability_zone='nova',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2022-09-09T21:57:07Z,deleted=False,deleted_at=None,display_description=None,display_name='tempest-TestMultiAttachVolumeSwap-volume-2047598637',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='luminex2.ros.storage.hpecorp.net@hpexp#hpexp',id=a54c67b7-786e-4ba7-94ea-d1e0a722424a,launched_at=2022-09-09T22:01:57Z,metadata=<?>,migration_status=None,multiattach=True,previous_status=None,project_id='70081f644bd940ad8c0fccdb60a7265d',provider_auth=None,provider_geometry=None,provider_id=None,provider_location='44686',replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2022-09-09T21:57:08Z,service_uuid='b3e99e9e-14b4-446f-a561-9a2f0219319e',shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='detaching',terminated_at=None,updated_at=2022-09-09T22:03:59Z,use_quota=True,user_id='556bc4c0a262402fbc17bbf775d94ad9',volume_attachment=<?>,volume_type=<?>,volume_type_id=4da632ef-3e6e-4716-bf4b-923f436c475e), 'connector': {'platform': 'x86_64', 'os_type': 'linux', 'ip': '15.113.218.46', 'host': 'luminex2.ros.storage.hpecorp.net', 'multipath': False, 'initiator': 'iqn.2005-03.org.open-iscsi:6680bc34b699', 'do_local_attach': False, 'uuid': 'bb122d1c-28ef-4893-a142-cab155363baf', 'system uuid': 'ed832742-2186-e2d8-4d3d-590b0e3e804c', 'mountpoint': '/dev/vdb', 'mode': 'ro'}, 'kwargs': {'force': False}}"[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1485}}[00m
DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-75469d39-ab9e-48d6-b727-41448acc54d4 req-849fe943-a39e-4dc7-9637-ce391d05b9c4 [00;36mtempest-TestMultiAttachVolumeSwap-857785715 None] [01;35m<== terminate_connection: return (23ms) None[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1510}}[00m
INFO cinder.volume.manager [[01;36mreq-75469d39-ab9e-48d6-b727-41448acc54d4 req-849fe943-a39e-4dc7-9637-ce391d05b9c4 [00;36mtempest-TestMultiAttachVolumeSwap-857785715 None] [01;35mTerminate volume connection completed successfully.[00m
DEBUG cinder.volume.manager [[01;36mreq-75469d39-ab9e-48d6-b727-41448acc54d4 req-849fe943-a39e-4dc7-9637-ce391d05b9c4 [00;36mtempest-TestMultiAttachVolumeSwap-857785715 None] [01;35mDeleting attachment 02b20af4-af46-4f9e-840b-4664ebc093e0.[00m [00;33m{{(pid=2573474) attachment_delete /opt/stack/cinder/cinder/volume/manager.py:4958}}[00m


Then about 15mins later:

- cinder.volume.drivers.hpe.xp.hpe_xp_iscsi detach Volume 1 attachment from Instance 2
DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-d4566b84-4f90-44c1-98f6-726a38d57534 req-99747ce0-cd41-4610-a411-1132ec508cb2 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35m==> terminate_connection: call "{'self': <cinder.volume.drivers.hpe.xp.hpe_xp_iscsi.HPEXPISCSIDriver object at 0x7f835e807dc0>, 'volume': Volume(_name_id=None,admin_metadata=<?>,attach_status='attached',availability_zone='nova',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2022-09-09T21:57:07Z,deleted=False,deleted_at=None,display_description=None,display_name='tempest-TestMultiAttachVolumeSwap-volume-2047598637',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='luminex2.ros.storage.hpecorp.net@hpexp#hpexp',id=a54c67b7-786e-4ba7-94ea-d1e0a722424a,launched_at=2022-09-09T22:01:57Z,metadata=<?>,migration_status=None,multiattach=True,previous_status=None,project_id='70081f644bd940ad8c0fccdb60a7265d',provider_auth=None,provider_geometry=None,provider_id=None,provider_location='44686',replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2022-09-09T21:57:08Z,service_uuid='b3e99e9e-14b4-446f-a561-9a2f0219319e',shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='in-use',terminated_at=None,updated_at=2022-09-09T22:18:27Z,use_quota=True,user_id='556bc4c0a262402fbc17bbf775d94ad9',volume_attachment=<?>,volume_type=<?>,volume_type_id=4da632ef-3e6e-4716-bf4b-923f436c475e), 'connector': {'platform': 'x86_64', 'os_type': 'linux', 'ip': '15.113.218.46', 'host': 'luminex2.ros.storage.hpecorp.net', 'multipath': False, 'initiator': 'iqn.2005-03.org.open-iscsi:6680bc34b699', 'do_local_attach': False, 'uuid': 'bb122d1c-28ef-4893-a142-cab155363baf', 'system uuid': 'ed832742-2186-e2d8-4d3d-590b0e3e804c', 'mountpoint': '/dev/vdb', 'mode': 'ro'}, 'kwargs': {'force': False}}"[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1485}}[00m
DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-d4566b84-4f90-44c1-98f6-726a38d57534 req-99747ce0-cd41-4610-a411-1132ec508cb2 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35m<== terminate_connection: return (8002ms) None[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1510}}[00m
INFO cinder.volume.manager [[01;36mreq-d4566b84-4f90-44c1-98f6-726a38d57534 req-99747ce0-cd41-4610-a411-1132ec508cb2 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mTerminate volume connection completed successfully.[00m
DEBUG cinder.volume.manager [[01;36mreq-d4566b84-4f90-44c1-98f6-726a38d57534 req-99747ce0-cd41-4610-a411-1132ec508cb2 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mDeleting attachment d5a7a2fa-7d22-4827-8c9b-e068727a927c.[00m [00;33m{{(pid=2573474) attachment_delete /opt/stack/cinder/cinder/volume/manager.py:4958}}[00m


- cinder.volume.drivers.hpe.xp.hpe_xp_iscsi detach Volume 2 attachment from Instance 1 (Note the new attachment ID similar to during the swap above).
DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-1ca9f1d2-2dce-45f1-9cb8-9a6525fdebe4 req-a57d1b3f-f60c-4194-8e8c-39e927f825c6 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35m==> terminate_connection: call "{'self': <cinder.volume.drivers.hpe.xp.hpe_xp_iscsi.HPEXPISCSIDriver object at 0x7f835e807dc0>, 'volume': Volume(_name_id=None,admin_metadata=<?>,attach_status='attached',availability_zone='nova',bootable=False,cluster=<?>,cluster_name=None,consistencygroup=<?>,consistencygroup_id=None,created_at=2022-09-09T22:02:10Z,deleted=False,deleted_at=None,display_description=None,display_name='tempest-TestMultiAttachVolumeSwap-volume-199234805',ec2_id=None,encryption_key_id=None,glance_metadata=<?>,group=<?>,group_id=None,host='luminex2.ros.storage.hpecorp.net@hpexp#hpexp',id=9c237d89-284d-4608-8585-97f5be2fdb87,launched_at=2022-09-09T22:02:20Z,metadata=<?>,migration_status=None,multiattach=True,previous_status=None,project_id='70081f644bd940ad8c0fccdb60a7265d',provider_auth=None,provider_geometry=None,provider_id=None,provider_location='44708',replication_driver_data=None,replication_extended_status=None,replication_status=None,scheduled_at=2022-09-09T22:02:10Z,service_uuid='b3e99e9e-14b4-446f-a561-9a2f0219319e',shared_targets=True,size=1,snapshot_id=None,snapshots=<?>,source_volid=None,status='in-use',terminated_at=None,updated_at=2022-09-09T22:18:27Z,use_quota=True,user_id='556bc4c0a262402fbc17bbf775d94ad9',volume_attachment=<?>,volume_type=<?>,volume_type_id=4da632ef-3e6e-4716-bf4b-923f436c475e), 'connector': {'platform': 'x86_64', 'os_type': 'linux', 'ip': '15.113.218.46', 'host': 'luminex2.ros.storage.hpecorp.net', 'multipath': False, 'initiator': 'iqn.2005-03.org.open-iscsi:6680bc34b699', 'do_local_attach': False, 'uuid': 'bb122d1c-28ef-4893-a142-cab155363baf', 'system uuid': 'ed832742-2186-e2d8-4d3d-590b0e3e804c', 'mountpoint': '/dev/vdb'}, 'kwargs': {'force': False}}"[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1485}}[00m
DEBUG cinder.volume.drivers.hpe.xp.hpe_xp_iscsi [[01;36mreq-1ca9f1d2-2dce-45f1-9cb8-9a6525fdebe4 req-a57d1b3f-f60c-4194-8e8c-39e927f825c6 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35m<== terminate_connection: return (16203ms) None[00m [00;33m{{(pid=2573474) trace_logging_wrapper /opt/stack/cinder/cinder/volume/volume_utils.py:1510}}[00m
INFO cinder.volume.manager [[01;36mreq-1ca9f1d2-2dce-45f1-9cb8-9a6525fdebe4 req-a57d1b3f-f60c-4194-8e8c-39e927f825c6 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mTerminate volume connection completed successfully.[00m
DEBUG cinder.volume.manager [[01;36mreq-1ca9f1d2-2dce-45f1-9cb8-9a6525fdebe4 req-a57d1b3f-f60c-4194-8e8c-39e927f825c6 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mDeleting attachment ff67412a-b21e-4514-9bc7-bcac93fea294.[00m [00;33m{{(pid=2573474) attachment_delete /opt/stack/cinder/cinder/volume/manager.py:4958}}[00m


No error/warning is reported on the delete attachment operations, according to manager.py this is expected:
   4957         try:
   4958             LOG.debug('Deleting attachment %(attachment_id)s.',
   4959                       {'attachment_id': attachment.id},
   4960                       resource=vref)
   4961             if has_shared_connection is not None and not has_shared_connection:
   4962                 self.driver.remove_export(context.elevated(), vref)
   4963         except Exception as exc:
   4964             # Failures on detach_volume and remove_export are not considered
   4965             # failures in terms of detaching the volume.
   4966             LOG.warning('Failed to detach volume on the backend, ignoring '
   4967                         'failure %s', exc)
   4968


Finally, both volumes are successfully deleted (Clean Up phase)
INFO cinder.volume.manager [[01;36mNone req-b3998e5c-6ba8-4b7f-b477-e1949dd30e6d [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mDeleted volume successfully.[00m
INFO cinder.volume.manager [[01;36mNone req-6244b31b-4795-4c67-b5fe-734ec9b403d6 [00;36mtempest-TestMultiAttachVolumeSwap-1341317054 None] [01;35mDeleted volume successfully.[00m