OpenStack Compute (nova)

Image goes to saving state when we delete instance just after taking snapshot and remain the state forever

Bug #1555065 reported by Prateek Arora
40
This bug affects 13 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
Low
Prateek Arora
Newton
In Progress
Low
Chuck Short

Bug Description

Steps to reproduce

1) nova image-create test test-img & nova delete test

where test is the name of the instance

I get the following message

[stack@localhost compute]$ nova image-create test test-img & nova delete test
[1] 2506
ERROR (ClientException): Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'nova.exception.UnexpectedDeletingTaskStateError'> (HTTP 500) (Request-ID: req-f699c746-0b29-4d84-b258-c8233d5b7a42)
Request to delete server test has been accepted.
[1]+ Exit 1 nova image-create test test-img

In the nova api logs i can see the following stacktrace

'c59f52ce-b51f-433e-81b0-099e3b65b0a3', '89ba4861-99e2-4376-8015-3f5ac02538d0']^[[00m ^[[00;33mfrom (pid=12399) reserve /opt/stack/nova/nova/quota.py:1345^[[00m
2016-03-09 02:04:25.304 ^[[01;31mERROR nova.api.openstack.extensions [^[[01;36mreq-f699c746-0b29-4d84-b258-c8233d5b7a42 ^[[00;36madmin admin^[[01;31m] ^[[01;35m^[[01;31mUnexpected exception in API method^[[00m
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00mTraceback (most recent call last):
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/api/openstack/extensions.py", line 478, in wrapped
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return f(*args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/api/openstack/common.py", line 391, in inner
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return f(*args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return func(*args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/api/validation/__init__.py", line 73, in wrapper
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return func(*args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/api/openstack/compute/servers.py", line 1113, in _action_create_image
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m extra_properties=metadata)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/compute/api.py", line 169, in wrapped
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return func(self, context, target, *args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/compute/api.py", line 186, in _wrapped
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return fn(self, context, instance, *args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/compute/api.py", line 139, in inner
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return f(self, context, instance, *args, **kw)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/compute/api.py", line 2238, in snapshot
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m instance.save(expected_task_state=[None])
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 223, in wrapper
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return fn(self, *args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/objects/instance.py", line 694, in save
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m columns_to_join=_expected_cols(expected_attrs))
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/db/api.py", line 805, in instance_update_and_get_original
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m expected=expected)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 229, in wrapper
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return f(*args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 148, in wrapper
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m ectxt.value = e.inner_exc
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m self.force_reraise()
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m six.reraise(self.type_, self.value, self.tb)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 138, in wrapper
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return f(*args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 300, in wrapped
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m return f(context, *args, **kwargs)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 2707, in instance_update_and_get_original
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m context, instance_uuid, values, expected, original=instance_ref))
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 2843, in _instance_update
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m raise exc(**exc_props)
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00mUnexpectedDeletingTaskStateError: Conflict updating instance 74940cbc-3947-434c-93ce-9489faa78073. Expected: {'task_state': [None]}. Actual: {'task_state': u'deleting'}
^[[01;31m2016-03-09 02:04:25.304 TRACE nova.api.openstack.extensions ^[[01;35m^[[00m
2016-03-09 02:04:25.311 ^[[00;36mINFO nova.api.openstack.wsgi [^[[01;36mreq-f699c746-0b29-4d84-b258-c8233d5b7a42 ^[[00;36madmin admin^[[00;36m] ^[[01;35m^[[00;36mHTTP exception thrown: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
<class 'nova.exception.UnexpectedDeletingTaskStateError'>^[[00m

Tags: api compute
Prateek Arora (parora)
Changed in nova:
assignee: nobody → Prateek Arora (parora)
Prateek Arora (parora)
Changed in nova:
assignee: Prateek Arora (parora) → nobody
assignee: nobody → Prateek Arora (parora)
Revision history for this message
Markus Zoeller (markus_z) (mzoeller) wrote :

Adding "api" tag because of HTTP status code 500.
Adding "compute" as I think this is the layer which should handle
the "UnexpectedDeletingTaskStateError" raised from the db layer.

tags: added: api compute
Changed in nova:
status: New → Confirmed
Prateek Arora (parora)
Changed in nova:
status: Confirmed → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (master)

Fix proposed to branch: master
Review: https://review.openstack.org/294513

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on nova (master)

Change abandoned by Matt Riedemann (<email address hidden>) on branch: master
Review: https://review.openstack.org/294513

OpenStack Infra (hudson-openstack)
Changed in nova:
assignee: Prateek Arora (parora) → Matt Riedemann (mriedem)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (master)

Reviewed: https://review.openstack.org/294513
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=d8e695cb900ad71996e6cf970894bc2e3f2df8b4
Submitter: Jenkins
Branch: master

commit d8e695cb900ad71996e6cf970894bc2e3f2df8b4
Author: Prateek Arora <email address hidden>
Date: Fri Mar 18 06:46:43 2016 -0400

    Delete traces of in-progress snapshot on VM being deleted

    When user tries to create snapshot of instance and at the same time
    if another request tries to delete the instance, at that time image
    goes in saving status for forever because of race between instance
    delete and snapshot requests.

    Caught exceptions(InstanceNotFound and UnexpectedDeletingTaskStateError)
    in except block and deleting the image which got stuck in saving state.

    Closes-Bug: #1555065
    Change-Id: If0b918dc951030e6b6ffba147443225e0e4a370a

Changed in nova:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (stable/newton)

Fix proposed to branch: stable/newton
Review: https://review.openstack.org/384353

Matt Riedemann (mriedem)
Changed in nova:
assignee: Matt Riedemann (mriedem) → Prateek Arora (parora)
importance: Undecided → Medium
importance: Medium → Low
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on nova (stable/newton)

Change abandoned by Chuck Short (<email address hidden>) on branch: stable/newton
Review: https://review.openstack.org/384353

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/nova 15.0.0.0b1

This issue was fixed in the openstack/nova 15.0.0.0b1 development milestone.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.