OpenStack Compute (nova)

UnexpectedTaskStateError: Conflict updating instance xxxx Expected: {'task_state': [u'resize_prep']}. Actual: {'task_state': None}

Bug #1646841 reported by jichenjc
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
In Progress
Undecided
jichenjc

Bug Description

it's newton release version code, not 100% percent reproducable, but very likely

step1) boot instance
step2) restart compute service
step3) right after compute service start, resize the instance booted at step 1

2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/conductor/manager.py", line 87, in _object_dispatch
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server return getattr(target, method)(*args, **kwargs)
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 226, in wrapper
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server return fn(self, *args, **kwargs)
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 748, in save
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server columns_to_join=_expected_cols(expected_attrs))
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 838, in instance_update_and_get_original
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server expected=expected)
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 169, in wrapper
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 151, in wrapper
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server ectxt.value = e.inner_exc
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server self.force_reraise()
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 139, in wrapper
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 240, in wrapped
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server return f(context, *args, **kwargs)
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2635, in instance_update_and_get_original
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server context, instance_uuid, values, expected, original=instance_ref))
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2771, in _instance_update
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server raise exc(**exc_props)
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server
2016-12-02 13:41:22.265 36087 ERROR oslo_messaging.rpc.server UnexpectedTaskStateError: Conflict updating instance f8c68d7b-1234-4c99-a5c7-c5f18f203513. Expected: {'task_state': [u'resize_prep']}. Actual: {'task_state': None}

Revision history for this message
jichenjc (jichenjc) wrote :

no clue yet, maybe it's because compute node status might be changed between API layer set task state and init function of compute layer

Changed in nova:
assignee: nobody → jichenjc (jichenjc)
Revision history for this message
jichenjc (jichenjc) wrote :

2016-12-02 20:30:37.299 28333 DEBUG nova.compute.manager [req-35a8b9f0-f515-4c01-bd83-8cc0b3a59403 - - - - -] [instance: 7a31c72f-6f9a-4c94-9719-1c3ccb6ed117] Instance in transitional state resize_prep at start-up clearing task state _init_instance /usr/lib/python2.7/site-packages/nova/compute/manager.py:840

with debug on, I think I can confirm this is a race condition, the init process wrongly think the status is transitional , actually it's API layer just modified

Revision history for this message
jichenjc (jichenjc) wrote :

2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server self.force_reraise()
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 139, in wrapper
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 240, in wrapped
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server return f(context, *args, **kwargs)
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2635, in instance_update_and_get_original
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server context, instance_uuid, values, expected, original=instance_ref))
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2771, in _instance_update
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server raise exc(**exc_props)
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server
2016-12-02 21:08:50.605 24224 ERROR oslo_messaging.rpc.server UnexpectedTaskStateError: Conflict updating instance b8cb5d2e-2e61-45af-ab5a-bfe2d78b5ca0. Expected: {'task_state': [u'image_snapshot_pending']}. Actual: {'task_state': None}

2016-12-02 21:08:21.867 24224 DEBUG nova.compute.manager [req-4edf093f-c870-4933-bc8d-17f69149597d - - - - -] [instance: b8cb5d2e-2e61-45af-ab5a-bfe2d78b5ca0] Instance in transitional state image_snapshot_pending at start-up clearing task state _init_instance /usr/lib/python2.7/site-packages/nova/compute/manager.py:826

more than snapshoting....

seems

Matt Riedemann (mriedem)
tags: added: compute resize
Changed in nova:
status: New → Confirmed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Related fix proposed to nova (master)

Related fix proposed to branch: master
Review: https://review.openstack.org/406977

Maciej Szankin (mszankin)
Changed in nova:
status: Confirmed → In Progress
Revision history for this message
sajuptpm (sajuptpm) wrote :

I also got same error https://bugs.launchpad.net/nova/+bug/1669924

Revision history for this message
sajuptpm (sajuptpm) wrote :

not similar error, i am getting this error from nova.cells.messaging

Revision history for this message
Sean Dague (sdague) wrote :

Automatically discovered version newton in description. If this is incorrect, please update the description to include 'nova version: ...'

tags: added: openstack-version.newton
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on nova (master)

Change abandoned by Stephen Finucane (<email address hidden>) on branch: master
Review: https://review.openstack.org/406977
Reason: This has been around for a long time and is failing tests

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.