OpenStack Compute (nova)

Deleting servers fails because of messaging timeouts

Bug #1372369 reported by Matthew Booth
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Confirmed
High
Unassigned

Bug Description

Tempest failure: http://logs.openstack.org/57/122757/1/check/check-tempest-dsvm-neutron-full/a08fb08/

2014-09-19 18:48:47.388 | 2014-09-19 18:15:35,926 6578 INFO [tempest.common.rest_client] Request (DeleteServersTestJSON:test_delete_server_while_in_verify_resize_state): 500 DELETE http://127.0.0.1:8774/v2/9959855b406d4563a6174eb27f11450e/servers/0a451fd1-72d8-4849-8b47-2095986f9cd4 60.155s
2014-09-19 18:48:47.389 | }}}

Due to:

2014-09-19 18:15:35.912 ERROR nova.api.openstack [req-c4a611b1-9d9b-407a-9f79-c83f19c4dd41 DeleteServersTestJSON-1044784101 DeleteServersTestJSON-1880429215] Caught error: Timed out waiting for a reply to message ID fcc1fca2d6a14e71b2222fc738224dec
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack Traceback (most recent call last):
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/__init__.py", line 124, in __call__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return req.get_response(self.application)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack application, catch_exc_info=False)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in call_application
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack app_iter = application(self.environ, start_response)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return resp(environ, start_response)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token.py", line 646, in __call__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return self._call_app(env, start_response)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token.py", line 624, in _call_app
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return self._app(env, _fake_start_response)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return resp(environ, start_response)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return resp(environ, start_response)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack response = self.app(environ, start_response)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return resp(environ, start_response)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack resp = self.call_func(req, *args, **self.kwargs)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return self.func(req, *args, **kwargs)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 908, in __call__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack content_type, body, accept)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 973, in _process_stack
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack action_result = self.dispatch(meth, request, action_args)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/wsgi.py", line 1057, in dispatch
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return method(req=request, **action_args)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 1210, in delete
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack self._delete(req.environ['nova.context'], req, id)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/api/openstack/compute/servers.py", line 1036, in _delete
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack self.compute_api.delete(context, instance)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 219, in wrapped
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return func(self, context, target, *args, **kwargs)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 209, in inner
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return function(self, context, instance, *args, **kwargs)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 236, in _wrapped
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return fn(self, context, instance, *args, **kwargs)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 190, in inner
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack return f(self, context, instance, *args, **kw)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 1792, in delete
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack self._delete_instance(context, instance)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 1782, in _delete_instance
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack task_state=task_states.DELETING)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 1614, in _delete
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack quotas.rollback()
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack six.reraise(self.type_, self.value, self.tb)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 1578, in _delete
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack self._confirm_resize_on_deleting(context, instance)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/api.py", line 1662, in _confirm_resize_on_deleting
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack cast=False)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/opt/stack/new/nova/nova/compute/rpcapi.py", line 384, in confirm_resize
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack reservations=reservations)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/client.py", line 152, in call
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack retry=self.retry)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/transport.py", line 90, in _send
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack timeout=timeout, retry=retry)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 408, in send
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack retry=retry)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 397, in _send
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack result = self._waiter.wait(msg_id, timeout)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 285, in wait
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack reply, ending = self._poll_connection(msg_id, timeout)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 235, in _poll_connection
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack % msg_id)
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack MessagingTimeout: Timed out waiting for a reply to message ID fcc1fca2d6a14e71b2222fc738224dec
2014-09-19 18:15:35.912 1508 TRACE nova.api.openstack

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

These 2 events are definitely not related. The periodic task having issues doesn't impact the API surface directly.

description: updated
summary: - Blockdev reports 'No such device or address'
+ Deleting servers fails because of messaging timeouts
Revision history for this message
Sean Dague (sdague) wrote :

It's worth noting that during this period of time we're under large scale IO Wait for over a minute - http://logs.openstack.org/57/122757/1/check/check-tempest-dsvm-neutron-full/a08fb08/logs/screen-dstat.txt.gz

Changed in nova:
status: New → Confirmed
importance: Undecided → Medium
importance: Medium → High
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.