yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1491276] Re: During evacuate cinder-api tries to call cinder-volume of halted node

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Eduard Biceri-Matei <cubusbacau@xxxxxxxxx>
Date: Thu, 10 Sep 2015 11:07:53 -0000
Reply-to: Bug 1491276 <1491276@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
(bump)

** Also affects: nova
   Importance: Undecided
       Status: New

-- 
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/1491276

Title:
  During evacuate cinder-api tries to call cinder-volume of halted node

Status in Cinder:
  New
Status in OpenStack Compute (nova):
  New

Bug description:
  Three nodes devstack Juno (2012.2.4) with shared storage.

  One instance running on second node of the cluster.
  Halted the host, instance still shows status "Running".
  Tried to evacuate the host but got following errors:

  (n-cpu log)

  2015-09-01 19:19:50.291 DEBUG nova.openstack.common.lockutils [req-56b30762-dad3-410d-a50d-a74318c43198 admin admin] Semaphore / lock released "update_usage" from (pid=16720) inner /opt/stack/nova/nova/openstack/common/lockutils.py:275
  2015-09-01 19:19:50.296 ERROR oslo.messaging.rpc.dispatcher [req-56b30762-dad3-410d-a50d-a74318c43198 admin admin] Exception during message handling: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-dcf02ffd-0916-45b1-b2a3-4623e71d340c)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     incoming.message))
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 430, in decorated_function
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/server.py", line 139, in inner
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     return func(*args, **kwargs)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/exception.py", line 88, in wrapped
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     payload)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/exception.py", line 71, in wrapped
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     return f(self, context, *args, **kw)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 314, in decorated_function
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     LOG.warning(msg, e, instance_uuid=instance_uuid)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 286, in decorated_function
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 364, in decorated_function
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 342, in decorated_function
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     kwargs['instance'], e, sys.exc_info())
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 330, in decorated_function
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 2889, in rebuild_instance
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     self._rebuild_default_impl(**kwargs)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 2725, in _rebuild_default_impl
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     detach_block_devices(context, bdms)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 2867, in detach_block_devices
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     destroy_bdm=False)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/compute/manager.py", line 4710, in _detach_volume
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     self.volume_api.terminate_connection(context, volume_id, connector)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/volume/cinder.py", line 185, in wrapper
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     res = method(self, ctx, volume_id, *args, **kwargs)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/nova/nova/volume/cinder.py", line 360, in terminate_connection
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     connector)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/cinderclient/v1/volumes.py", line 331, in terminate_connection
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     {'connector': connector})
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/cinderclient/v1/volumes.py", line 250, in _action
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     return self.api.client.post(url, body=body)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/cinderclient/client.py", line 305, in post
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     return self._cs_request(url, 'POST', **kwargs)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/cinderclient/client.py", line 269, in _cs_request
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     **kwargs)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/cinderclient/client.py", line 252, in request
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher     raise exceptions.from_response(resp, body)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher ClientException: The server has either erred or is incapable of performing the requested operation. (HTTP 500) (Request-ID: req-dcf02ffd-0916-45b1-b2a3-4623e71d340c)
  2015-09-01 19:19:50.296 TRACE oslo.messaging.rpc.dispatcher

  (c-api log)

  2015-09-01 19:19:49.696 ERROR cinder.api.middleware.fault [req-dcf02ffd-0916-45b1-b2a3-4623e71d340c 13e9d15ce670486a852427a9f94a19d2 ac5dec9bc10b4ac8b7b3ee79e3a06f0e] Caught error: Timed out waiting for a reply to message ID e83aa194d740457494288b61a1251caa
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault Traceback (most recent call last):
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/opt/stack/cinder/cinder/api/middleware/fault.py", line 76, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return req.get_response(self.application)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     application, catch_exc_info=False)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in call_application
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     app_iter = application(self.environ, start_response)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return resp(environ, start_response)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     resp = self.call_func(req, *args, **self.kwargs)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return self.func(req, *args, **kwargs)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/osprofiler/web.py", line 99, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return request.get_response(self.application)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     application, catch_exc_info=False)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in call_application
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     app_iter = application(self.environ, start_response)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token.py", line 823, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return self._call_app(env, start_response)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/keystonemiddleware/auth_token.py", line 758, in _call_app
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return self._app(env, _fake_start_response)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return resp(environ, start_response)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return resp(environ, start_response)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/routes/middleware.py", line 136, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     response = self.app(environ, start_response)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return resp(environ, start_response)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     resp = self.call_func(req, *args, **self.kwargs)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return self.func(req, *args, **kwargs)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/opt/stack/cinder/cinder/api/openstack/wsgi.py", line 897, in __call__
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     content_type, body, accept)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/opt/stack/cinder/cinder/api/openstack/wsgi.py", line 945, in _process_stack
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     action_result = self.dispatch(meth, request, action_args)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/opt/stack/cinder/cinder/api/openstack/wsgi.py", line 1021, in dispatch
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return method(req=request, **action_args)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/opt/stack/cinder/cinder/api/contrib/volume_actions.py", line 218, in _terminate_connection
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     self.volume_api.terminate_connection(context, volume, connector)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/opt/stack/cinder/cinder/volume/api.py", line 87, in wrapped
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     return func(self, context, target_obj, *args, **kwargs)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/opt/stack/cinder/cinder/volume/api.py", line 519, in terminate_connection
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     force)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/opt/stack/cinder/cinder/volume/rpcapi.py", line 170, in terminate_connection
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     connector=connector, force=force)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/client.py", line 152, in call
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     retry=self.retry)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/transport.py", line 90, in _send
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     timeout=timeout, retry=retry)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 408, in send
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     retry=retry)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 397, in _send
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     result = self._waiter.wait(msg_id, timeout)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 285, in wait
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     reply, ending = self._poll_connection(msg_id, timeout)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 235, in _poll_connection
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault     % msg_id)
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault MessagingTimeout: Timed out waiting for a reply to message ID e83aa194d740457494288b61a1251caa
  2015-09-01 19:19:49.696 TRACE cinder.api.middleware.fault 

  
  So it looks like the c-api of first node is trying to call c-vol of halted node to terminate_connection although the node is halted (and the message times out).

  Instead it should simply "rebuild" the instance on another available
  node.

To manage notifications about this bug go to:
https://bugs.launchpad.net/cinder/+bug/1491276/+subscriptions