3PAR: Not found (HTTP 404) 17 - host does not exist

[Gorka Eguileor]

When running tempest tests where we are simultaneously attaching and detaching volumes to the same host we may encounter the following error:

oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: 2020-10-05 17:03:45.867 159719 ERROR oslo_messaging.rpc.server [^[[01;36mNone req-c3fcfb86-d19c-497c-bacf-efe89d5b1dd9 ^[[00;36mtempest-VolumesSnapshotTestJSON-1799288435 None] ^[[01;35mException during message handling^[[00m: cinder.exception.ImageCopyFailure: Failed to copy image to volume: Bad or unexpected response from the storage volume backend API: Unable to fetch connection information from backend: Not found (HTTP 404) 17 - host does not exist
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00mTraceback (most recent call last):
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/driver.py", line 1045, in _attach_volume
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m conn = self.initialize_connection(volume, properties)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/utils.py", line 785, in trace_logging_wrapper
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m result = f(*args, **kwargs)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "<decorator-gen-763>", line 2, in initialize_connection
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/coordination.py", line 151, in _synchronized
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m return f(*a, **k)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/drivers/hpe/hpe_3par_fc.py", line 235, in initialize_connection
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m target_wwns, init_targ_map, numPaths)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/drivers/hpe/hpe_3par_fc.py", line 151, in _initialize_connection_common
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m remote_client)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/drivers/hpe/hpe_3par_common.py", line 1792, in create_vlun
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m remote_client=remote_client)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/drivers/hpe/hpe_3par_common.py", line 1473, in _create_3par_vlun
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m auto=auto, lun=lun_id)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/hpe3parclient/client.py", line 2257, in createVLUN
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m headers, body = self.http.post('/vluns', body=info)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/hpe3parclient/http.py", line 376, in post
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m return self._cs_request(url, 'POST', **kwargs)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/hpe3parclient/http.py", line 321, in _cs_request
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m **kwargs)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/hpe3parclient/http.py", line 297, in _time_request
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m resp, body = self.request(url, method, **kwargs)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/hpe3parclient/http.py", line 262, in request
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m raise exceptions.from_response(resp, body)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00mhpe3parclient.exceptions.HTTPNotFound: Not found (HTTP 404) 17 - host does not exist
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00mDuring handling of the above exception, another exception occurred:
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00mTraceback (most recent call last):
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/volume_utils.py", line 1144, in copy_image_to_volume
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m context, volume, image_service, image_id)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/driver.py", line 857, in copy_image_to_volume
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m context, volume, image_service, image_id, encrypted=False)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/driver.py", line 877, in _copy_image_data_to_volume
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m attach_info, volume = self._attach_volume(context, volume, properties)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/driver.py", line 1060, in _attach_volume
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m raise exception.VolumeBackendAPIException(data=err_msg)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00mcinder.exception.VolumeBackendAPIException: Bad or unexpected response from the storage volume backend API: Unable to fetch connection information from backend: Not found (HTTP 404) 17 - host does not exist
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00mDuring handling of the above exception, another exception occurred:
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00mTraceback (most recent call last):
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/oslo_messaging/rpc/server.py", line 165, in _process_incoming
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m res = self.dispatcher.dispatch(message)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 309, in dispatch
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m return self._do_dispatch(endpoint, method, ctxt, args)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 229, in _do_dispatch
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m result = func(ctxt, **new_args)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "<decorator-gen-751>", line 2, in create_volume
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/objects/cleanable.py", line 212, in wrapper
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m result = f(*args, **kwargs)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/manager.py", line 748, in create_volume
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m _run_flow()
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/manager.py", line 740, in _run_flow
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m flow_engine.run()
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/taskflow/engines/action_engine/engine.py", line 247, in run
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m for _state in self.run_iter(timeout=timeout):
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/taskflow/engines/action_engine/engine.py", line 340, in run_iter
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m failure.Failure.reraise_if_any(er_failures)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/taskflow/types/failure.py", line 339, in reraise_if_any
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m failures[0].reraise()
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/taskflow/types/failure.py", line 346, in reraise
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m six.reraise(*self._exc_info)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/six.py", line 703, in reraise
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m raise value
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/taskflow/engines/action_engine/executor.py", line 53, in _execute_task
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m result = task.execute(**arguments)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/flows/manager/create_volume.py", line 1134, in execute
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m **volume_spec)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/utils.py", line 683, in _wrapper
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m return r.call(f, *args, **kwargs)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/tenacity/__init__.py", line 409, in call
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m do = self.iter(retry_state=retry_state)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/tenacity/__init__.py", line 356, in iter
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m return fut.result()
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/lib64/python3.7/concurrent/futures/_base.py", line 428, in result
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m return self.__get_result()
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/lib64/python3.7/concurrent/futures/_base.py", line 384, in __get_result
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m raise self._exception
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/usr/local/lib/python3.7/site-packages/tenacity/__init__.py", line 412, in call
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m result = fn(*args, **kwargs)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/flows/manager/create_volume.py", line 1034, in _create_from_image
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m image_service)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/flows/manager/create_volume.py", line 925, in _create_from_image_cache_or_download
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m image_service
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/flows/manager/create_volume.py", line 738, in _create_from_image_download
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m image_service)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m File "/opt/remote_cinder/cinder/volume/volume_utils.py", line 1160, in copy_image_to_volume
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m raise exception.ImageCopyFailure(reason=ex)
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00mcinder.exception.ImageCopyFailure: Failed to copy image to volume: Bad or unexpected response from the storage volume backend API: Unable to fetch connection information from backend: Not found (HTTP 404) 17 - host does not exist
oct 05 17:03:45 fedora31.localdomain cinder-volume[159714]: ERROR oslo_messaging.rpc.server ^[[01;35m^[[00m

This is caused by a race condition between the host creation in initialize_connection and the deletion of the host in terminate_connection.

[Raghavendra Tilay (raghavendrat)]

Hi,
This bug is similar to existing bug:
https://bugs.launchpad.net/cinder/+bug/1658888

HPE had proposed locking mechanism; but there was no conclusion. It was later abandoned.
https://review.opendev.org/#/c/424454/

Regards,
Raghavendra Tilay.