Public bug reported:

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

** Affects: nova
     Importance: Undecided
     Assignee: Artom Lifshitz (notartom)
         Status: In Progress

-- 
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):
  In Progress

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

-- 
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to     : yahoo-eng-team@lists.launchpad.net
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help   : https://help.launchpad.net/ListHelp

Reply via email to