Run into 500 error during delete image

[Feilong Wang]

Recreate steps:
1. Enable delayed delete
    delayed_delete = True

2. Create a new image by:
    glance image-create --name flwang_1 --container-format bare --disk-format qcow2 --is-public yes --location https://launchpad.net/cirros/trunk/0.3.0/+download/cirros-0.3.0-x86_64-disk.img

3. Delete image by:
    glance image-delete flwang_1

You will see an error like below, but the image has been deleted, in 'pending-delete' state.
Request returned failure status.
HTTPInternalServerError (HTTP 500): Unable to delete image 86d0a3df-d140-4d41-aaae-f1c538591d3d

[Feilong Wang (flwang)]

After investigation, I think there are two places we should improve, though seems it's not a bug.

1. We are using /var/lib/glance as the default scrubber data dir. However, generally the /var/lib need root permission. So user will run into permission problem by default.

2. We're using lockutils in line https://github.com/openstack/glance/blob/master/glance/store/scrubber.py#L168 however, in glance-api.conf and glance-scrubber.conf, we didn't configure it by default. So this line will fail with error "value required for option: lock_path".

[Feilong Wang (flwang)]

It's most like a deployment issue. And given the lock_path will be set a default value in patch https://review.openstack.org/#/c/46479/, so i'm going to mark this bug as Invalid.

[Stuart McLaren (stuart-mclaren)]

If you enable delayed delete you get an E500 and the following stack trace:

Dec 2 11:29:17 gl-aw1rdc1-registry0000 4101 DEBUG eventlet.wsgi.server [f46a69d7-c49b-4e41-ad12-447bcd7d2c38 77049353665607 34096082065107] Traceback (most recent call last):
012 File "/usr/lib/python2.7/dist-packages/eventlet/wsgi.py", line 384, in handle_one_response
012 result = self.application(self.environ, start_response)
012 File "/usr/lib/python2.7/dist-packages/hp_glance_extras/middleware/healthcheck.py", line 38, in __call__
012 return self.app(env, start_response)
012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
012 resp = self.call_func(req, *args, **self.kwargs)
012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
012 return self.func(req, *args, **kwargs)
012 File "/usr/lib/python2.7/dist-packages/glance/common/wsgi.py", line 377, in __call__
012 response = req.get_response(self.application)
012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1296, in send
012 application, catch_exc_info=False)
012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1260, in call_application
012 app_iter = application(self.environ, start_response)
012 File "/usr/lib/python2.7/dist-packages/hp/middleware/cs_auth_token.py", line 160, in __call__
012 return super(CsAuthProtocol, self).__call__(env, start_response)
012 File "/usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py", line 539, in __call__
012 return self.app(env, start_response)
012 File "/usr/lib/python2.7/dist-packages/hp/middleware/cs_authz.py", line 30, in __call__
012 return self.app(env, start_response)
012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
012 resp = self.call_func(req, *args, **self.kwargs)
012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
012 return self.func(req, *args, **kwargs)
012 File "/usr/lib/python2.7/dist-packages/glance/common/wsgi.py", line 377, in __call__
012 response = req.get_response(self.application)
012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1296, in send
012 application, catch_exc_info=False)
012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1260, in call_application
012 app_iter = application(self.environ, start_response)
012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
012 resp = self.call_func(req, *args, **self.kwargs)
012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
012 return self.func(req, *args, **kwargs)
012 File "/usr/lib/python2.7/dist-packages/glance/common/wsgi.py", line 377, in __call__
012 response = req.get_response(self.application)
012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1296, in send
012 application, catch_exc_info=False)
012 File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1260, in call_application
012 app_iter = application(self.environ, start_response)
012 File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
012 resp = self.call_func(req, *...

[Stuart McLaren (stuart-mclaren)]

You can see the token gets dropped for the final call to the registry:

T 127.0.0.1:52222 -> 127.0.0.1:9191 [AP]
PUT /images/a6b28397-cc22-417b-b3bc-60954eb66e00 HTTP/1.1.
Host: localhost:9191.
Accept-Encoding: identity.
Content-Length: 39.
Content-Type: application/json.
x-auth-token: XXX.
.
{"image": {"status": "pending_delete"}}
##
T 127.0.0.1:9191 -> 127.0.0.1:52222 [AP]
HTTP/1.1 200 OK.
Content-Type: application/json; charset=UTF-8.
Content-Length: 1058.
X-Openstack-Request-Id: req-4f0b1b61-0921-4d74-bdba-85564defb16f.
Date: Mon, 02 Dec 2013 13:07:20 GMT.
.
{"image": {"status": "pending_delete", "created_at": "2013-12-02T13:07:20", "properties": {}, "name": null, "deleted": false, "container_format": "bare", "min_ram": 0, "disk_format": "raw", "location_data": [{"url": "oj1w9aZh6bRDhD0-212hwfrtpGFaca4BHbIgYDh9rk5klJnm5JD46_Vy36NEY_WhbLeK-k4aVR99JddzgiemE9srxDcdtrr579r_JcteC_hPTaZ0MAdSw9RCAWKN1YR6CQGbGD4Jg8Jm0zSQpn5X_SLiwuJI_hCMs60TsEe8GYbcFoEcmod0Jt-TgnWI-Ezb_D1YL9UHxVJfAkU_s_B-6t-IFF6KzoKpn30UoNhztvx9tGoz0g6bZSjhBsrsdyhuIH5UWUl53-eb_aUSl4--Lg==", "metadata": {}}], "updated_at": "2013-12-02T13:07:20", "owner": "34096082065107", "protected": false, "location": "oj1w9aZh6bRDhD0-212hwfrtpGFaca4BHbIgYDh9rk5klJnm5JD46_Vy36NEY_WhbLeK-k4aVR99JddzgiemE9srxDcdtrr579r_JcteC_hPTaZ0MAdSw9RCAWKN1YR6CQGbGD4Jg8Jm0zSQpn5X_SLiwuJI_hCMs60TsEe8GYbcFoEcmod0Jt-TgnWI-Ezb_D1YL9UHxVJfAkU_s_B-6t-IFF6KzoKpn30UoNhztvx9tGoz0g6bZSjhBsrsdyhuIH5UWUl53-eb_aUSl4--Lg==", "checksum": "d41d8cd98f00b204e9800998ecf8427e", "min_disk": 0, "is_public": false, "deleted_at": null, "id": "a6b28397-cc22-417b-b3bc-60954eb66e00", "size": 0}}
########
T 127.0.0.1:52224 -> 127.0.0.1:9191 [AP]
DELETE /images/a6b28397-cc22-417b-b3bc-60954eb66e00 HTTP/1.1.
Host: localhost:9191.
Accept-Encoding: identity.
x-auth-token: XXX.
.

##
T 127.0.0.1:9191 -> 127.0.0.1:52224 [AP]
HTTP/1.1 200 OK.
Content-Type: application/json; charset=UTF-8.
Content-Length: 503.
X-Openstack-Request-Id: req-c698a752-ae23-4641-a506-7d7b2e5d7a38.
Date: Mon, 02 Dec 2013 13:07:20 GMT.
.
{"image": {"status": "pending_delete", "created_at": "2013-12-02T13:07:20", "properties": {}, "name": null, "deleted": true, "container_format": "bare", "min_ram": 0, "disk_format": "raw", "location_data": [], "updated_at": "2013-12-02T13:07:20.760515", "owner": "34096082065107", "protected": false, "location": null, "checksum": "d41d8cd98f00b204e9800998ecf8427e", "min_disk": 0, "is_public": false, "deleted_at": "2013-12-02T13:07:20.759725", "id": "a6b28397-cc22-417b-b3bc-60954eb66e00", "size": 0}}
########
T 127.0.0.1:52225 -> 127.0.0.1:9191 [AP]
GET /images/a6b28397-cc22-417b-b3bc-60954eb66e00 HTTP/1.1.
Host: localhost:9191.
Accept-Encoding: identity.
. <<<< NO TOKEN!

##
T 127.0.0.1:9191 -> 127.0.0.1:52225 [AP]
HTTP/1.1 401 Unauthorized.
Www-Authenticate: Keystone uri='XXX'.
Content-Type: text/plain.
Content-Length: 23.
Date: Mon, 02 Dec 2013 13:07:20 GMT.
.
Authentication required

[Stuart McLaren (stuart-mclaren)]

Reproduced on devstack.

[Feilong Wang (flwang)]

https://review.openstack.org/#/c/59689/

[Feilong Wang (flwang)]

Stuart, route this bug to you since you're working on this. Thanks.

[Attila Fazekas (afazekas)]

Logstash:
message: "Object GET failed" AND filename:"logs/screen-g-api.txt" AND build_status:"FAILURE"
http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOiBcIk9iamVjdCBHRVQgZmFpbGVkXCIgQU5EIGZpbGVuYW1lOlwibG9ncy9zY3JlZW4tZy1hcGkudHh0XCIgQU5EIGJ1aWxkX3N0YXR1czpcIkZBSUxVUkVcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTM5NDE3OTU0NzQyNSwibW9kZSI6IiIsImFuYWx5emVfZmllbGQiOiIifQ==

Is it the same issue ?

[Alan Pevec (apevec)]

This was released in Icehouse-3
 https://github.com/openstack/glance/commit/f88ce19ed7be73b252c88257c9a37be0b1335e04

[Alan Pevec (apevec)]

stable/havana https://review.openstack.org/60224