Bug 1323714 - Glance image fails to delete
Summary: Glance image fails to delete
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-glance
Version: 6.0 (Juno)
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: ---
: 6.0 (Juno)
Assignee: Cyril Roelandt
QA Contact: nlevinki
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-04-04 13:35 UTC by Jeremy
Modified: 2020-03-11 15:05 UTC (History)
10 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-05-04 16:39:07 UTC
Target Upstream Version:


Attachments (Terms of Use)

Description Jeremy 2016-04-04 13:35:43 UTC
Description of problem: Customer hits the following traceback mentioned below when trying to delete an image


Version-Release number of selected component (if applicable):
python-glance-2014.2.3-4.el7ost.noarch 
ceph-0.80.8-17.el7cp.x86_64

How reproducible:
100%

Steps to Reproduce:
1.deploy osp7 with ceph backend for glance.
2.attempt to delete image 
3. note failure

Actual results:
image delete fails

Expected results:
image is deleted

Additional info:
Once of the images that fails to delete:
glance image-show 88e21cc9-e249-4b8e-97b6-b97e9bca0344
+--------------------------------+--------------------------------------+
| Property                       | Value                                |
+--------------------------------+--------------------------------------+
| Property 'architecture'        | x86_64                               |
| Property 'hw_qemu_guest_agent' | yes                                  |
| Property 'hw_scsi_model'       | virtio-scsi                          |
| Property 'os_require_quiesce'  | yes                                  |
| checksum                       | 0475216a7aa6a7fc58fbe64eb14dd170     |
| container_format               | bare                                 |
| created_at                     | 2016-03-24T15:36:06                  |
| deleted                        | False                                |
| disk_format                    | raw                                  |
| id                             | 88e21cc9-e249-4b8e-97b6-b97e9bca0344 |
| is_public                      | True                                 |
| min_disk                       | 32                                   |
| min_ram                        | 1024                                 |
| name                           | Win Std 2012R2 1.0                   |
| owner                          | e77ab73efbcc4a538b452476b5ed0e59     |
| protected                      | False                                |
| size                           | 34359738368                          |
| status                         | active                               |
| updated_at                     | 2016-03-28T13:27:11                  |
+--------------------------------+--------------------------------------+



Here is the trace from controller 003:L
2016-03-28 07:18:39.175 16884 DEBUG glance_store._drivers.rbd [-] snapshot 88e21cc9-e249-4b8e-97b6-b97e9bca0344@snap could not be unprotected because it is in use _cleanup_image /usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py:325
2016-03-28 07:18:39.186 16884 DEBUG glance_store._drivers.rbd [-] _cleanup_image() failed delete /usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py:448
2016-03-28 07:18:39.186 16884 TRACE glance_store._drivers.rbd Traceback (most recent call last):
2016-03-28 07:18:39.186 16884 TRACE glance_store._drivers.rbd   File "/usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py", line 446, in delete
2016-03-28 07:18:39.186 16884 TRACE glance_store._drivers.rbd     self._cleanup_image(target_pool, loc.image, loc.snapshot)
2016-03-28 07:18:39.186 16884 TRACE glance_store._drivers.rbd   File "/usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py", line 326, in _cleanup_image
2016-03-28 07:18:39.186 16884 TRACE glance_store._drivers.rbd     raise exceptions.InUseByStore()
2016-03-28 07:18:39.186 16884 TRACE glance_store._drivers.rbd InUseByStore: None
2016-03-28 07:18:39.186 16884 TRACE glance_store._drivers.rbd
2016-03-28 07:18:39.206 16884 DEBUG glance.registry.client.v1.api [-] Updating image metadata for image 88e21cc9-e249-4b8e-97b6-b97e9bca0344... update_image_metadata /usr/lib/python2.7/site-packages/glance/registry/client/v1/api.py:166
2016-03-28 07:18:39.207 16884 DEBUG glance.common.client [-] Constructed URL: http://10.100.91.22:9191/images/88e21cc9-e249-4b8e-97b6-b97e9bca0344 _construct_url /usr/lib/python2.7/site-packages/glance/common/client.py:398
2016-03-28 07:18:39.214 16885 DEBUG glance.registry.client.v1.client [-] Registry request GET /images/35dbddd8-0d68-4cf7-bc34-cda042eb0132 HTTP 200 request id req-e2e305ed-d260-460c-9af7-b769b3b3c6cf do_request /usr/lib/python2.7/site-packages/glance/registry/client/v1/client.py:122
2016-03-28 07:18:39.216 16885 INFO glance.wsgi.server [-] 10.100.91.23 - - [28/Mar/2016 07:18:39] "HEAD /v1/images/35dbddd8-0d68-4cf7-bc34-cda042eb0132 HTTP/1.1" 200 1032 0.313704
2016-03-28 07:18:39.312 16884 DEBUG glance.registry.client.v1.client [-] Registry request PUT /images/88e21cc9-e249-4b8e-97b6-b97e9bca0344 HTTP 200 request id req-9d02831b-599e-4afe-9764-5ba0068666e5 do_request /usr/lib/python2.7/site-packages/glance/registry/client/v1/client.py:122
2016-03-28 07:18:39.368 16884 INFO glance.wsgi.server [-] Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/eventlet/wsgi.py", line 454, in handle_one_response
  result = self.application(self.environ, start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
    resp = self.call_func(req, *args, **self.kwargs)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/glance/common/wsgi.py", line 394, in __call__
    response = req.get_response(self.application)
  File "/usr/lib/python2.7/site-packages/webob/request.py", line 1296, in send
    application, catch_exc_info=False)
  File "/usr/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application
    app_iter = application(self.environ, start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
    resp = self.call_func(req, *args, **self.kwargs)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/osprofiler/web.py", line 99, in __call__
    return request.get_response(self.application)
  File "/usr/lib/python2.7/site-packages/webob/request.py", line 1296, in send
    application, catch_exc_info=False)
  File "/usr/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application
    app_iter = application(self.environ, start_response)
  File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token.py", line 823, in __call__
    return self._call_app(env, start_response)
  File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token.py", line 758, in _call_app
    return self._app(env, _fake_start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
    resp = self.call_func(req, *args, **self.kwargs)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
    return self.func(req, *args, **kwargs)
  File "/usr/lib/python2.7/site-packages/glance/common/wsgi.py", line 394, in __call__
    response = req.get_response(self.application)
  File "/usr/lib/python2.7/site-packages/webob/request.py", line 1296, in send
    application, catch_exc_info=False)
  File "/usr/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application
    app_iter = application(self.environ, start_response)
  File "/usr/lib/python2.7/site-packages/paste/urlmap.py", line 203, in __call__
    return app(environ, start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
    return resp(environ, start_response)
  File "/usr/lib/python2.7/site-packages/routes/middleware.py", line 131, in __call__
    response = self.app(environ, start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
    return resp(environ, start_response)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
    resp = self.call_func(req, *args, **self.kwargs)
  File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
    return self.func(req, *args, **kwargs)
 File "/usr/lib/python2.7/site-packages/glance/api/v1/images.py", line 1082, in delete
    {'status': ori_status})
  File "/usr/lib/python2.7/site-packages/glance/openstack/common/excutils.py", line 82, in __exit__
    six.reraise(self.type_, self.value, self.tb)
  File "/usr/lib/python2.7/site-packages/glance/api/v1/images.py", line 1078, in delete
    upload_utils.initiate_deletion(req, loc_data, id)
  File "/usr/lib/python2.7/site-packages/glance/api/v1/upload_utils.py", line 46, in initiate_deletion
    id, location_data)
  File "/usr/lib/python2.7/site-packages/glance/common/store_utils.py", line 124, in delete_image_location_from_backend
    safe_delete_from_backend(context, image_id, location)
  File "/usr/lib/python2.7/site-packages/glance/common/store_utils.py", line 58, in safe_delete_from_backend
    ret = store_api.delete_from_backend(location['url'], context=context)
  File "/usr/lib/python2.7/site-packages/glance_store/backend.py", line 280, in delete_from_backend
    return store.delete(loc, context=context)
  File "/usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py", line 446, in delete
    self._cleanup_image(target_pool, loc.image, loc.snapshot)
  File "/usr/lib/python2.7/site-packages/glance_store/_drivers/rbd.py", line 326, in _cleanup_image
    raise exceptions.InUseByStore()
InUseByStore: None
2016-03-28 07:18:39.369 16884 INFO glance.wsgi.server [-] 10.100.91.23 - - [28/Mar/2016 07:18:39] "DELETE /v1/images/88e21cc9-e249-4b8e-97b6-b97e9bca0344 HTTP/1.1" 500 139 0.855919

Comment 2 Flavio Percoco 2016-04-04 14:16:00 UTC
Jeremy,

You mention that you can reproduce this deploying an OSP7 environment but the packages you referenced are for OSP6. Could you clarify this and update the version field accordingly?

Comment 3 Jeremy 2016-04-07 13:53:55 UTC
Flavio, 

In the case the customer listed the RHOSP version as 7.0;maybe they made a mistake. How can we confirm which version this actually?

Comment 4 Jeremy 2016-04-07 19:52:56 UTC
The customer says it is actually 6.0

Comment 5 Sergey Gotliv 2016-04-10 19:24:41 UTC
Jeremy,

Please, check with the customer whether they booted Nova instances from that image, if they did what is the current status of these instances. We have somehow confirmed that this image is not used.

Comment 6 Jeremy 2016-04-11 19:48:56 UTC
glance image-show  96fbfb00-913c-4dc4-bcb9-ffdd68597b8c
+--------------------------------+--------------------------------------+
| Property                       | Value                                |
+--------------------------------+--------------------------------------+
| Property 'architecture'        | x86_64                               |
| Property 'hw_qemu_guest_agent' | yes                                  |
| Property 'hw_scsi_model'       | virtio-scsi                          |
| Property 'os_require_quiesce'  | yes                                  |
| checksum                       | dcf5c0995870b8bdd55b40f2e1d46888     |
| container_format               | bare                                 |
| created_at                     | 2016-03-31T17:14:25                  |
| deleted                        | False                                |
| disk_format                    | raw                                  |
| id                             | 96fbfb00-913c-4dc4-bcb9-ffdd68597b8c |
| is_public                      | True                                 |
| min_disk                       | 32                                   |
| min_ram                        | 1024                                 |
| name                           | Win Std 2012R2 1.0                   |
| owner                          | e77ab73efbcc4a538b452476b5ed0e59     |
| protected                      | False                                |
| size                           | 34359738368                          |
| status                         | active                               |
| updated_at                     | 2016-04-11T19:35:44                  |
+--------------------------------+--------------------------------------+

glance image-delete  96fbfb00-913c-4dc4-bcb9-ffdd68597b8c
HTTPInternalServerError (HTTP 500): Unable to delete image 96fbfb00-913c-4dc4-bcb9-ffdd68597b8c



 nova show 741a6c1b-4035-4854-9b39-714962a7a7a2
+--------------------------------------+------------------------------------------------------------------+
| Property                             | Value                                                            |
+--------------------------------------+------------------------------------------------------------------+
| Internal network                     | 10.10.10.33                                 |
| OS-DCF:diskConfig                    | AUTO                                                             |
| OS-EXT-AZ:availability_zone          | nova                                                             |
| OS-EXT-SRV-ATTR:host                 | ocd1c007.osinst.net                                              |
| OS-EXT-SRV-ATTR:hypervisor_hostname  | ocd1c007.osinst.net                                              |
| OS-EXT-SRV-ATTR:instance_name        | instance-00000614                                                |
| OS-EXT-STS:power_state               | 1                                                                |
| OS-EXT-STS:task_state                | -                                                                |
| OS-EXT-STS:vm_state                  | active                                                           |
| OS-SRV-USG:launched_at               | 2016-03-31T17:47:10.000000                                       |
| OS-SRV-USG:terminated_at             | -                                                                |
| accessIPv4                           |                                                                  |
| accessIPv6                           |                                                                  |
| config_drive                         |                                                                  |
| created                              | 2016-03-31T17:46:55Z                                             |
| flavor                               | w1.small (7d2cba2d-4e1c-4713-b259-a1ccb0750ca5)                  |
| hostId                               | f780bac8450eb35da83730ac631bef9bf0de33d8897d7005fd55e340         |
| id                                   | 741a6c1b-4035-4854-9b39-714962a7a7a2                             |
| image                                | Win Std 2012R2 1.0 (96fbfb00-913c-4dc4-bcb9-ffdd68597b8c)        |
| key_name                             | cp-prodkey                                                       |
| metadata                             | {}                                                               |
| name                                 | cpwintest1                                                       |
| os-extended-volumes:volumes_attached | []                                                               |
| progress                             | 0                                                                |
| security_groups                      | default                                                          |
| status                               | ACTIVE                                                           |
| tenant_id                            | 5d2be791d77f4cd19b0666ad831d4377                                 |
| updated                              | 2016-03-31T17:47:10Z                                             |
| user_id                              | def8b1fba74af3b8edb20229430bf82d0f8ba1a7962f36a12fc9c8a15820c45a |
+--------------------------------------+------------------------------------------------------------------+

Comment 7 Jeremy 2016-05-04 21:16:42 UTC
any update on this?

Comment 8 Sergey Gotliv 2016-05-15 11:37:47 UTC
Jeremy,

IIUC, comment #6, Nova instance 741a6c1b-4035-4854-9b39-714962a7a7a2 is booted from image 96fbfb00-913c-4dc4-bcb9-ffdd68597b8c which you trying to delete. Can you, please terminate this nova instance and then try to delete image again. What happens?

Comment 9 Sergey Gotliv 2016-05-15 11:38:46 UTC
See comment #8.

Comment 10 Jeremy 2016-05-19 20:49:28 UTC
Sergey, 
If they delete the instance then they can delete the image.

Comment 13 Cyril Roelandt 2016-05-20 18:04:50 UTC
About comment #10, it is the expected behaviour. Now, we should probably log the error and print a nice message rather than leaving the user with a stacktrace. The way I see it, we would need to:

- patch glance_store so that the InUseByStore exception is propagated;
- patch glance so that safe_delete_from_backend catches the InUseByStore exception and logs it.

Would that be an acceptable solution? Also, the code has changed quite a bit since Juno, so I might try and fix this upstream, and then backport the patch all the way to Juno, but that might take some time (or even be impossible/unpratical). Any thought on that?

Comment 14 Sergey Gotliv 2016-05-22 19:05:26 UTC
(In reply to Cyril Roelandt from comment #13)
> About comment #10, it is the expected behaviour. Now, we should probably log
> the error and print a nice message rather than leaving the user with a
> stacktrace. The way I see it, we would need to:
> 
> - patch glance_store so that the InUseByStore exception is propagated;
> - patch glance so that safe_delete_from_backend catches the InUseByStore
> exception and logs it.
> 
> Would that be an acceptable solution? Also, the code has changed quite a bit
> since Juno, so I might try and fix this upstream, and then backport the
> patch all the way to Juno, but that might take some time (or even be
> impossible/unpratical). Any thought on that?

IIUC, this Juno patch https://review.openstack.org/108289 already addresses the api logging issue.

Comment 15 Cyril Roelandt 2016-05-23 10:04:51 UTC
This patch seems to exist in the Juno branch : https://github.com/openstack/glance/blob/juno-eol/glance/api/v1/images.py#L1101 .

OP's issue arise from somewhere else:

File "/usr/lib/python2.7/site-packages/glance/common/store_utils.py", line 58, in safe_delete_from_backend

I believe a second patch would be needed for this code path. Not sure of how well this would apply to master, though, I'll need to look at the code a bit more.

Comment 16 Jeremy 2016-05-23 14:33:29 UTC
Cyril, 
Ok that's fine, we just need a fix for the customer as soon as possible.

Comment 17 Cyril Roelandt 2016-05-24 15:46:14 UTC
So, I can reproduce this issue on master when using *raw* images. I can delete qcow2 images, though.

There is also a nice error message on master:

$ glance image-delete 2a0342c3-5f03-4c19-a960-cb9e229e266a
Unable to delete image '2a0342c3-5f03-4c19-a960-cb9e229e266a' because it is in use.

Comment 18 Jeremy 2016-05-24 21:37:56 UTC
cyril,
That seems to be correct. The customer is using ceph so the images are in raw format. Just to clarify, the customer wants to be able to delete the raw images without deleting the instance. The logging seems to be fine.

Comment 19 Cyril Roelandt 2016-05-25 15:56:11 UTC
Indeed. To be honest, I do not think this will be doable in Juno. This feature does not exist in the master branch, and will already be quite tricky to add, so there really is little hope for a backport.

Comment 20 Jeremy 2016-05-25 21:46:08 UTC
That's understandable, what RHOS version will this feature available?

Comment 21 Cyril Roelandt 2016-05-26 18:56:29 UTC
I can't say for sure. I brought up the subject at today's glance meeting:

http://eavesdrop.openstack.org/meetings/glance/2016/glance.2016-05-26-14.03.txt
http://eavesdrop.openstack.org/meetings/glance/2016/glance.2016-05-26-14.03.log.html

I'm not exactly sure of what we are going to be able to do about this, unfortunately.

Comment 22 Jeremy 2016-06-27 13:33:15 UTC
Cyril, 
Any update on this?

Comment 23 Cyril Roelandt 2016-06-27 16:04:24 UTC
I'm not sure exactly what should be done about the scrubber. adding Erno.

Erno, you said that the scrubber was a bit buggy at the moment, could you elaborate? How hard would it be to use it to delete images once they are no longer used by any VM?

Comment 24 Flavio Percoco 2016-07-21 07:12:33 UTC
@Cyril,

The scrubber has no knowledge of whether the image is being used or not. The scrubber is used to delete images asynchronously (known as "soft delete" in Glance). When soft delete is enabled, delete commands will only mark the image as pending_deletion and then the scrubber will do the actual deletion.

The InUser error seen in this report is an (unfortunate) side effect of how the interaction between Nova and Glance happens. If soft deletion is enabled, I'd assume the scrubber will try to delete this image on every run until it finally succeeds, but this should be tested

Comment 25 Elise Gafford 2016-08-02 15:23:59 UTC
Hi Jeremy,

Did Flavio's comments help the customer? It sounds to the Glance dev team as though the service is working as configured in this case (and that the image will eventually be scrubbed). Please update us with the case's status when you can.

Thanks,
Elise

Comment 26 Jeremy 2016-08-03 17:11:01 UTC
Elise, so you are saying the instance is immediately marked for soft delete but will eventually be really deleted? So the solution here is to just wait until it's really deleted ?

Comment 28 Jeremy 2016-09-29 13:57:08 UTC
Customer is still seeing this issue in OSP8.0

Comment 30 Jeremy 2017-02-06 16:27:29 UTC
Hello,
Any update on this BZ?

Comment 31 Cyril Roelandt 2017-02-08 21:25:52 UTC
Honestly, this seems like the expected behaviour to me. Being able to delete images that are "in use" might be a nice feature, but this would have to be taken upstream and then integrated into RHOS. This is not something that can be fixed downstream, I'm afraid.


Note You need to log in before you can comment on or make changes to this bug.