Public bug reported: Description ===========
We reproduce this bug in https://review.openstack.org/#/c/530429 In test_resize_server_negative_invalid_state 1. first, the confirm resize action are recorded: https://github.com/openstack/nova/blob/2fc5d27332023a68e0a3977305a594f061f99cc8/nova/compute/api.py#L1950 2. and then a delete action are recorded. the import thing is: the delete action and the resize action have SAME instance uuid and same requst id. But when we get the action in here: https://github.com/openstack/nova/blob/2fc5d27332023a68e0a3977305a594f061f99cc8/nova/db/sqlalchemy/api.py#L5755-L5756 it assume that we can get the only one action by different instance uuid and request_id. We want to record the terminate_event on delete action, unfortunately, we get the wrong confirm-resize action first. I think this problem has always existed, but after we add the index, the order of we get action is changed. so, this bug are exposed. Steps to reproduce ================== 1. add index: https://review.openstack.org/#/c/530429/ 2. run test nosetests -svx nova.tests.functional.test_servers:ServersTest.test_resize_server_negative_invalid_state Logs & Configs ============== Traceback (most recent call last): File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming res = self.dispatcher.dispatch(message) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch return self._do_dispatch(endpoint, method, ctxt, args) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch result = func(ctxt, **new_args) File "nova/exception_wrapper.py", line 76, in wrapped function_name, call_dict, binary) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ self.force_reraise() File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise six.reraise(self.type_, self.value, self.tb) File "nova/exception_wrapper.py", line 67, in wrapped return f(self, context, *args, **kw) File "nova/compute/manager.py", line 186, in decorated_function "Error: %s", e, instance=instance) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ self.force_reraise() File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise six.reraise(self.type_, self.value, self.tb) File "nova/compute/manager.py", line 156, in decorated_function return function(self, context, *args, **kwargs) File "nova/compute/utils.py", line 911, in decorated_function return function(self, context, *args, **kwargs) File "nova/compute/utils.py", line 889, in __exit__ exc_tb=exc_tb, want_result=False) File "nova/objects/base.py", line 308, in wrapper return fn.__get__(None, obj)(*args, **kwargs) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 184, in wrapper result = fn(cls, context, *args, **kwargs) File "nova/objects/instance_action.py", line 185, in event_finish_with_failure db_event = db.action_event_finish(context, values) File "nova/db/api.py", line 1906, in action_event_finish return IMPL.action_event_finish(context, values) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_db/api.py", line 147, in wrapper ectxt.value = e.inner_exc File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ self.force_reraise() File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise six.reraise(self.type_, self.value, self.tb) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_db/api.py", line 135, in wrapper return f(*args, **kwargs) File "nova/db/sqlalchemy/api.py", line 253, in wrapped return f(context, *args, **kwargs) File "nova/db/sqlalchemy/api.py", line 5845, in action_event_finish event=values['event']) InstanceActionEventNotFound: Event compute_terminate_instance not found for action id 3 2017-12-29 06:45:21,779 ERROR [nova.api.openstack.wsgi] Unexpected exception in API method Traceback (most recent call last): File "nova/api/openstack/wsgi.py", line 803, in wrapped return f(*args, **kwargs) File "nova/api/openstack/compute/servers.py", line 831, in delete self._delete(req.environ['nova.context'], req, id) File "nova/api/openstack/compute/servers.py", line 685, in _delete self.compute_api.delete(context, instance) File "nova/compute/api.py", line 201, in inner return function(self, context, instance, *args, **kwargs) File "nova/compute/api.py", line 209, in _wrapped return fn(self, context, instance, *args, **kwargs) File "nova/compute/api.py", line 149, in inner return f(self, context, instance, *args, **kw) File "nova/compute/api.py", line 2111, in delete self._delete_instance(context, instance) File "nova/compute/api.py", line 2102, in _delete_instance task_state=task_states.DELETING) File "nova/compute/api.py", line 1897, in _delete cb(context, instance, bdms) File "nova/compute/api.py", line 2065, in _do_delete delete_type='delete') File "nova/compute/rpcapi.py", line 1041, in terminate_instance reservations=reservations) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 174, in call retry=self.retry) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/transport.py", line 131, in _send timeout=timeout, retry=retry) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_fake.py", line 219, in send return self._send(target, ctxt, message, wait_for_reply, timeout) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_fake.py", line 206, in _send raise failure InstanceActionEventNotFound: Event compute_terminate_instance not found for action id 3 2017-12-29 06:45:21,780 INFO [nova.api.openstack.wsgi] 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.InstanceActionEventNotFound'> 2017-12-29 06:45:21,782 INFO [nova.api.openstack.requestlog] 127.0.0.1 "DELETE /v2.1/6f70656e737461636b20342065766572/servers/f39a6060-4612-4855-8de1-8b9aa9d12df3" status: 500 len: 216 microversion: 2.1 time: 0.607800 2017-12-29 06:45:22,001 WARNING [nova.service] Service killed that has no database entry }}} Traceback (most recent call last): File "nova/tests/functional/test_servers.py", line 702, in test_resize_server_negative_invalid_state self._delete_server(created_server_id) File "nova/tests/functional/test_servers.py", line 102, in _delete_server self.api.delete_server(server_id) File "nova/tests/functional/api/client.py", line 286, in delete_server return self.api_delete('/servers/%s' % server_id) File "nova/tests/functional/api/client.py", line 239, in api_delete return APIResponse(self.api_request(relative_uri, **kwargs)) File "nova/tests/functional/api/client.py", line 202, in api_request response=response) nova.tests.functional.api.client.OpenStackApiException: Unexpected status code: {"computeFault": {"code": 500, "message": "Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.\n<class 'nova.exception.InstanceActionEventNotFound'>"}} ** Affects: nova Importance: Undecided Assignee: Yikun Jiang (yikunkero) 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/1741220 Title: raise 500 in test_resize_server_negative_invalid_state Status in OpenStack Compute (nova): In Progress Bug description: Description =========== We reproduce this bug in https://review.openstack.org/#/c/530429 In test_resize_server_negative_invalid_state 1. first, the confirm resize action are recorded: https://github.com/openstack/nova/blob/2fc5d27332023a68e0a3977305a594f061f99cc8/nova/compute/api.py#L1950 2. and then a delete action are recorded. the import thing is: the delete action and the resize action have SAME instance uuid and same requst id. But when we get the action in here: https://github.com/openstack/nova/blob/2fc5d27332023a68e0a3977305a594f061f99cc8/nova/db/sqlalchemy/api.py#L5755-L5756 it assume that we can get the only one action by different instance uuid and request_id. We want to record the terminate_event on delete action, unfortunately, we get the wrong confirm-resize action first. I think this problem has always existed, but after we add the index, the order of we get action is changed. so, this bug are exposed. Steps to reproduce ================== 1. add index: https://review.openstack.org/#/c/530429/ 2. run test nosetests -svx nova.tests.functional.test_servers:ServersTest.test_resize_server_negative_invalid_state Logs & Configs ============== Traceback (most recent call last): File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming res = self.dispatcher.dispatch(message) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch return self._do_dispatch(endpoint, method, ctxt, args) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch result = func(ctxt, **new_args) File "nova/exception_wrapper.py", line 76, in wrapped function_name, call_dict, binary) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ self.force_reraise() File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise six.reraise(self.type_, self.value, self.tb) File "nova/exception_wrapper.py", line 67, in wrapped return f(self, context, *args, **kw) File "nova/compute/manager.py", line 186, in decorated_function "Error: %s", e, instance=instance) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ self.force_reraise() File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise six.reraise(self.type_, self.value, self.tb) File "nova/compute/manager.py", line 156, in decorated_function return function(self, context, *args, **kwargs) File "nova/compute/utils.py", line 911, in decorated_function return function(self, context, *args, **kwargs) File "nova/compute/utils.py", line 889, in __exit__ exc_tb=exc_tb, want_result=False) File "nova/objects/base.py", line 308, in wrapper return fn.__get__(None, obj)(*args, **kwargs) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 184, in wrapper result = fn(cls, context, *args, **kwargs) File "nova/objects/instance_action.py", line 185, in event_finish_with_failure db_event = db.action_event_finish(context, values) File "nova/db/api.py", line 1906, in action_event_finish return IMPL.action_event_finish(context, values) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_db/api.py", line 147, in wrapper ectxt.value = e.inner_exc File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ self.force_reraise() File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise six.reraise(self.type_, self.value, self.tb) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_db/api.py", line 135, in wrapper return f(*args, **kwargs) File "nova/db/sqlalchemy/api.py", line 253, in wrapped return f(context, *args, **kwargs) File "nova/db/sqlalchemy/api.py", line 5845, in action_event_finish event=values['event']) InstanceActionEventNotFound: Event compute_terminate_instance not found for action id 3 2017-12-29 06:45:21,779 ERROR [nova.api.openstack.wsgi] Unexpected exception in API method Traceback (most recent call last): File "nova/api/openstack/wsgi.py", line 803, in wrapped return f(*args, **kwargs) File "nova/api/openstack/compute/servers.py", line 831, in delete self._delete(req.environ['nova.context'], req, id) File "nova/api/openstack/compute/servers.py", line 685, in _delete self.compute_api.delete(context, instance) File "nova/compute/api.py", line 201, in inner return function(self, context, instance, *args, **kwargs) File "nova/compute/api.py", line 209, in _wrapped return fn(self, context, instance, *args, **kwargs) File "nova/compute/api.py", line 149, in inner return f(self, context, instance, *args, **kw) File "nova/compute/api.py", line 2111, in delete self._delete_instance(context, instance) File "nova/compute/api.py", line 2102, in _delete_instance task_state=task_states.DELETING) File "nova/compute/api.py", line 1897, in _delete cb(context, instance, bdms) File "nova/compute/api.py", line 2065, in _do_delete delete_type='delete') File "nova/compute/rpcapi.py", line 1041, in terminate_instance reservations=reservations) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 174, in call retry=self.retry) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/transport.py", line 131, in _send timeout=timeout, retry=retry) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_fake.py", line 219, in send return self._send(target, ctxt, message, wait_for_reply, timeout) File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/functional/local/lib/python2.7/site-packages/oslo_messaging/_drivers/impl_fake.py", line 206, in _send raise failure InstanceActionEventNotFound: Event compute_terminate_instance not found for action id 3 2017-12-29 06:45:21,780 INFO [nova.api.openstack.wsgi] 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.InstanceActionEventNotFound'> 2017-12-29 06:45:21,782 INFO [nova.api.openstack.requestlog] 127.0.0.1 "DELETE /v2.1/6f70656e737461636b20342065766572/servers/f39a6060-4612-4855-8de1-8b9aa9d12df3" status: 500 len: 216 microversion: 2.1 time: 0.607800 2017-12-29 06:45:22,001 WARNING [nova.service] Service killed that has no database entry }}} Traceback (most recent call last): File "nova/tests/functional/test_servers.py", line 702, in test_resize_server_negative_invalid_state self._delete_server(created_server_id) File "nova/tests/functional/test_servers.py", line 102, in _delete_server self.api.delete_server(server_id) File "nova/tests/functional/api/client.py", line 286, in delete_server return self.api_delete('/servers/%s' % server_id) File "nova/tests/functional/api/client.py", line 239, in api_delete return APIResponse(self.api_request(relative_uri, **kwargs)) File "nova/tests/functional/api/client.py", line 202, in api_request response=response) nova.tests.functional.api.client.OpenStackApiException: Unexpected status code: {"computeFault": {"code": 500, "message": "Unexpected API Error. Please report this at http://bugs.launchpad.net/nova/ and attach the Nova API log if possible.\n<class 'nova.exception.InstanceActionEventNotFound'>"}} To manage notifications about this bug go to: https://bugs.launchpad.net/nova/+bug/1741220/+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
