Bug 1613536

+++ This bug was initially created as a clone of Bug #1609959 +++

Description of problem:

A non-admin user creating a volume from image results in a blank volume but success reported. 

Version-Release number of selected component (if applicable): 9.1.4

How reproducible:

Every time in client environment.

Steps to Reproduce:
1. Create volume from image as non-admin user.
2. Verify on instance find blank.
3. Create volume from image as admin user.
4. Verify on instance find imaged successfully.


Actual results:

NON-ADMIN:
~~~
2018-07-30 15:45:02.910 146539 DEBUG glanceclient.common.http [req-050e8096-f8ad-4423-a60a-4ee51e7241c6 8302d373a4184d19a51ef7b3dc0e6eaa 85f64b8e939b4537abc0c6148b12e1f1 - default default] curl -g -i -X GET -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'User-Agent: python-glanceclient' -H 'Connection: keep-alive' -H 'X-Auth-Token: {SHA1}REMOVED' -H 'Content-Type: application/octet-stream' http://REMOVED:9292/v2/images/650b810a-fe91-4b7f-8447-17e95098a91c log_curl_request /usr/lib/python2.7/site-packages/glanceclient/common/http.py:205
2018-07-30 15:45:03.380 146539 DEBUG glanceclient.common.http [req-050e8096-f8ad-4423-a60a-4ee51e7241c6 8302d373a4184d19a51ef7b3dc0e6eaa 85f64b8e939b4537abc0c6148b12e1f1 - default default] GET call to glance-api for http://REMOVED:9292/v2/images/650b810a-fe91-4b7f-8447-17e95098a91c used request id req-cfe3ece4-d8e3-46bd-8d4b-e466df98acb0 _handle_response /usr/lib/python2.7/site-packages/glanceclient/common/http.py:103

Expected results:
ADMIN:
2018-07-30 15:44:46.330 156269 DEBUG glanceclient.common.http [req-6cf63747-f4a9-480e-81ea-11a3549a5187 472ae955ea0d4624a42f3e5594c1144e 6a3da4a835ec4557b5eb409efbdd5798 - default default] curl -g -i -X GET -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'User-Agent: python-glanceclient' -H 'Connection: keep-alive' -H 'X-Auth-Token: {SHA1}REMOVED' -H 'Content-Type: application/octet-stream' http://REMOVED:9292/v2/images/650b810a-fe91-4b7f-8447-17e95098a91c/file log_curl_request /usr/lib/python2.7/site-packages/glanceclient/common/http.py:205
2018-07-30 15:44:47.111 156269 DEBUG glanceclient.common.http [req-6cf63747-f4a9-480e-81ea-11a3549a5187 472ae955ea0d4624a42f3e5594c1144e 6a3da4a835ec4557b5eb409efbdd5798 - default default] GET call to glance-api for http://REMOVED:9292/v2/images/650b810a-fe91-4b7f-8447-17e95098a91c/file used request id req-03672352-96fd-4c99-bdb1-34c505006848 _handle_response /usr/lib/python2.7/site-packages/glanceclient/common/http.py:103


Additional info:

- I'll add in private notes.

--- Additional comment from Alan Bishop on 2018-08-07 12:41:13 EDT ---

I traced the problem to an issue with the Cinder SolidFire driver's "template
caching" feature. The non-admin user is the owner of the Glance image, and so
the driver attempts to create an internal cache of the image, which it then
clones to create the new volume requested by the user. But, when the cache
entry is created, two errors occur that result in cache entry consisting of a
blank volume. When the user makes a subsequent request for another volume from
that image, the blank cache entry is cloned, resulting in another blank
volume. Here is the overall sequence that results in a blank entry in the
template cache:

1. SolidFire driver determines the image has not been cached, so it downloads
   the image from Glance to a temporary location, creates a new (blank) volume
   on the SolidFire backend, and tries to copy the image data to the SolidFire
   volume. This volume represents the "template cache" entry.

2. The first error occurs when the driver attempts to create an iSCSI
   connection to the "template cache" volume that it just created. The error I
   see in the sosreports is:

iscsiadm: initiator reported error (24 - iSCSI login failed due to authorization failure)

3. The driver attempts to clean up by dropping any iSCSI connections to the
   "template cache" volume, deleting the volume, and purging the "template
   cache" entry.

4. The second error occurs when it tries to drop any iSCSI connections:

UnboundLocalError: local variable 'attach_info' referenced before assignment

5. The second error is not handled properly, and a side effect is the blank
   "template cache" volume is never deleted or purged from the cache.

All of this results in a blank "template cache" volume, so subsequent requests
to create more volumes from the same image result in more blank volumes.

When an admin attempts to create a volume from the same image, because the
image is not owned by the admin, the SolidFire driver does not attempt to use
the template caching feature. When this happens, Cinder downloads a fresh copy
of the Glance image, and does not rely on the SolidFire driver to do any
cloning. This explains why you can observe the new volume's status cycling
from 'creating' to 'downloading' to 'available'.

So, one suggestion is to troubleshoot the iSCSI login failure, which will
likely require examining logs on the SolidFire backend.

A better approach would be to disable the driver's template caching feature,
by setting 'sf_allow_template_caching = False' in the driver's section in
cinder.conf. The whole feature was deprecated by the vendor in Queens because
it essentially duplicates Cinder's own "image volume cache" feature. If image
caching is a performance requirement, then see [1] to enable the feature.

[1] https://access.redhat.com/documentation/en-us/red_hat_openstack_platform/10/html/storage_guide/ch-cinder#section-cinder-image-cache

--- Additional comment from Alan Bishop on 2018-08-07 14:47:19 EDT ---

In light of the fact that the vendor deprecated their own image caching feature in Queens [1] (and that change is already in OSP-13), then the cleanest way to resolve issues like this is to backport the vendor's patch to this OSP release.

[1] https://review.openstack.org/511623