yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1850694] Re: shelve doesn't handle UnexpectedTaskStateError

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: OpenStack Infra <1850694@xxxxxxxxxxxxxxxxxx>
Date: Fri, 01 Nov 2019 21:34:56 -0000
Reply-to: Bug 1850694 <1850694@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Reviewed:  https://review.opendev.org/692206
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=a423d8b27785623550f401a200b68ca926c0a119
Submitter: Zuul
Branch:    master

commit a423d8b27785623550f401a200b68ca926c0a119
Author: Artom Lifshitz <alifshit@xxxxxxxxxx>
Date:   Wed Oct 30 14:03:49 2019 -0400

    Avoid error 500 on shelve task_state race
    
    When shelving a server and saving its new SHELVING task state, we
    expect the current task state to be None and do not handle any
    UnexpectedTaskStateError exceptions that the database layer may throw
    at us. In those cases, we return an error 500 to the user, when in
    actuality an error 409 conflict would be more appropriate. This
    patch makes the API layer handle UnexpectedTaskStateError exceptions
    and return a 409 to the user.
    
    Closes-bug: 1850694
    Change-Id: Ie0b421cd5d3a5781c1dd09fab4ed013ece0f939d


** Changed in: nova
       Status: In Progress => Fix Released

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1850694

Title:
  shelve doesn't handle UnexpectedTaskStateError

Status in OpenStack Compute (nova):
  Fix Released

Bug description:
  Description
  ===========

  Shelving a server expects its task state to be None. If it's not None
  (for example, if attempting to shelve a server that's already being
  shelved), we get a UnexpectedTaskStateError from the database layer
  and return a 500 to the user. A 409 would be more appropriate.

  Steps to reproduce
  ==================

  1. Send multiple shelve requests in quick succession.

  Expected result
  ===============

  The initial request should be accepted, the rest should return 409.

  Actual result
  =============

  Error 500 for all requests except the first.

  Environment
  ===========

  This was reported on OSP13 (Queens) originally [1].

  Logs & Configs
  ==============

  2019-05-28 03:18:48.530 26 INFO nova.osapi_compute.wsgi.server [req-1437e513-3e32-4243-8f5d-1a7e17c111df 3ff59a48497842e7a716a03a17e5bf8b 493b17f3b02b4f9ea6e71b1ae4c5ac5d - e4c6faf4dfb04f2da40c0595f1a424c7 e4c6faf4dfb04f2da40c0595f1a424c7] 10.101.4.137,10.101.4.1 "POST /v2.1/493b17f3b02b4f9ea6e71b1ae4c5ac5d/servers/f905b880-9caa-465e-93c5-fffe9192c825/action HTTP/1.1" status: 500 len: 622 time: 0.1237578
  2019-05-28 03:18:48.529 26 INFO nova.api.openstack.wsgi [req-1437e513-3e32-4243-8f5d-1a7e17c111df 3ff59a48497842e7a716a03a17e5bf8b 493b17f3b02b4f9ea6e71b1ae4c5ac5d - e4c6faf4dfb04f2da40c0595f1a424c7 e4c6faf4dfb04f2da40c0595f1a424c7] HTTP 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.UnexpectedTaskStateError'>
  2019-05-28 03:18:48.529 26 DEBUG nova.api.openstack.wsgi [req-1437e513-3e32-4243-8f5d-1a7e17c111df 3ff59a48497842e7a716a03a17e5bf8b 493b17f3b02b4f9ea6e71b1ae4c5ac5d - e4c6faf4dfb04f2da40c0595f1a424c7 e4c6faf4dfb04f2da40c0595f1a424c7] Returning 500 to user: Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.
  <class 'nova.exception.UnexpectedTaskStateError'> __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:1064
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi [req-1437e513-3e32-4243-8f5d-1a7e17c111df 3ff59a48497842e7a716a03a17e5bf8b 493b17f3b02b4f9ea6e71b1ae4c5ac5d - e4c6faf4dfb04f2da40c0595f1a424c7 e4c6faf4dfb04f2da40c0595f1a424c7] Unexpected exception in API method: UnexpectedTaskStateError: Conflict updating instance f905b880-9caa-465e-93c5-fffe9192c825. Expected: {'task_state': [None]}. Actual: {'task_state': u'shelving'}
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi Traceback (most recent call last):
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 788, in wrapped
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     return f(*args, **kwargs)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/shelve.py", line 43, in _shelve
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     self.compute_api.shelve(context, instance)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 204, in inner
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     return function(self, context, instance, *args, **kwargs)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 152, in inner
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     return f(self, context, instance, *args, **kw)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 3518, in shelve
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     instance.save(expected_task_state=[None])
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 226, in wrapper
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     return fn(self, *args, **kwargs)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/objects/instance.py", line 826, in save
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     columns_to_join=_expected_cols(expected_attrs))
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 890, in instance_update_and_get_original
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     expected=expected)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 169, in wrapper
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     return f(*args, **kwargs)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 147, in wrapper
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     ectxt.value = e.inner_exc
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     self.force_reraise()
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     six.reraise(self.type_, self.value, self.tb)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 135, in wrapper
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     return f(*args, **kwargs)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 240, in wrapped
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     return f(context, *args, **kwargs)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2737, in instance_update_and_get_original
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     context, instance_uuid, values, expected, original=instance_ref))
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2878, in _instance_update
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi     raise exc(**exc_props)
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi UnexpectedTaskStateError: Conflict updating instance f905b880-9caa-465e-93c5-fffe9192c825. Expected: {'task_state': [None]}. Actual: {'task_state': u'shelving'}
  2019-05-28 03:18:48.523 26 ERROR nova.api.openstack.wsgi

  Additional Info
  ===============

  This is obviously minor, as the difference between a 500 and a 409 is
  purely semantic, but we're being told this is an SLA thing. An SLA
  defines 5xx as being "down", while 4xx is user error and therefore
  "up".

  [1] https://bugzilla.redhat.com/show_bug.cgi?id=1718171

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1850694/+subscriptions
References

[Bug 1850694] [NEW] shelve doesn't handle UnexpectedTaskStateError
From: Artom Lifshitz, 2019-10-30