yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1615908] Re: dummy BDM record if reserve_block_device_name timeout

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Launchpad Bug Tracker <1615908@xxxxxxxxxxxxxxxxxx>
Date: Wed, 27 Sep 2017 04:18:13 -0000
Reply-to: Bug 1615908 <1615908@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
[Expired for OpenStack Compute (nova) because there has been no activity
for 60 days.]

** Changed in: nova
       Status: Incomplete => Expired

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

Title:
  dummy BDM record if reserve_block_device_name timeout

Status in OpenStack Compute (nova):
  Expired

Bug description:
  When attaching a volume, nova-api will initiate a rpc call to nova-
  compute to run reserve_block_device_name:

      def _attach_volume(self, context, instance, volume_id, device,
                         disk_bus, device_type):
          """Attach an existing volume to an existing instance.

          This method is separated to make it possible for cells version
          to override it.
          """
          # NOTE(vish): This is done on the compute host because we want
          #             to avoid a race where two devices are requested at
          #             the same time. When db access is removed from
          #             compute, the bdm will be created here and we will
          #             have to make sure that they are assigned atomically.
          volume_bdm = self.compute_rpcapi.reserve_block_device_name(
              context, instance, device, volume_id, disk_bus=disk_bus,
              device_type=device_type)
          try:
              volume = self.volume_api.get(context, volume_id)
              self.volume_api.check_attach(context, volume, instance=instance)
              self.volume_api.reserve_volume(context, volume_id)
              self.compute_rpcapi.attach_volume(context, instance=instance,
                      volume_id=volume_id, mountpoint=device, bdm=volume_bdm)
          except Exception:
              with excutils.save_and_reraise_exception():
                  volume_bdm.destroy()

          return volume_bdm.device_name

  
  If timeout occurs, a dummy BDM record is left in database. As a result, you will see an attached volume when run nova show, which is wrong.

  The trace:
  ---
  2016-08-03 10:29:29.929 4508 ERROR nova.api.openstack [req-9036ab02-c49e-408e-9914-1627175e9158 a3e789e51d6243e493483d12593757a6 597854e23bfe46abb6178f786af12391 - - -] Caught error: Timed out waiting for a reply to message ID ddf15f1d53764aa090920c64852e4fba
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack Traceback (most recent call last):
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/__init__.py", line 125, in __call__
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return req.get_response(self.application)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1296, in send
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     application, catch_exc_info=False)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/request.py", line 1260, in call_application
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     app_iter = application(self.environ, start_response)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return resp(environ, start_response)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 634, in __call__
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return self._call_app(env, start_response)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/keystonemiddleware/auth_token/__init__.py", line 554, in _call_app
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return self._app(env, _fake_start_response)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return resp(environ, start_response)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return resp(environ, start_response)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/routes/middleware.py", line 131, in __call__
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     response = self.app(environ, start_response)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 144, in __call__
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return resp(environ, start_response)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 130, in __call__
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     resp = self.call_func(req, *args, **self.kwargs)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/webob/dec.py", line 195, in call_func
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return self.func(req, *args, **kwargs)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 756, in __call__
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     content_type, body, accept)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 821, in _process_stack
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     action_result = self.dispatch(meth, request, action_args)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py", line 911, in dispatch
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return method(req=request, **action_args)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/api/openstack/compute/contrib/volumes.py", line 305, in create
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     volume_id, device)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 230, in wrapped
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return func(self, context, target, *args, **kwargs)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 219, in inner
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return function(self, context, instance, *args, **kwargs)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 200, in inner
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     return f(self, context, instance, *args, **kw)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 3147, in attach_volume
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     disk_bus, device_type)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/compute/api.py", line 3119, in _attach_volume
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     device_type=device_type)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/nova/compute/rpcapi.py", line 846, in reserve_block_device_name
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     volume_bdm = cctxt.call(ctxt, 'reserve_block_device_name', **kw)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 156, in call
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     retry=self.retry)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     timeout=timeout, retry=retry)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 350, in send
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     retry=retry)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 339, in _send
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     result = self._waiter.wait(msg_id, timeout)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 243, in wait
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     message = self.waiters.get(msg_id, timeout=timeout)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack   File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 149, in get
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack     'to message ID %s' % msg_id)
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack MessagingTimeout: Timed out waiting for a reply to message ID ddf15f1d53764aa090920c64852e4fba
  2016-08-03 10:29:29.929 4508 TRACE nova.api.openstack
  2016-08-03 10:29:29.932 4508 INFO nova.api.openstack [req-9036ab02-c49e-408e-9914-1627175e9158 a3e789e51d6243e493483d12593757a6 597854e23bfe46abb6178f786af12391 - - -] http://vip.haproxy.bcec.core:8774/v2/597854e23bfe46abb6178f786af12391/servers/34ed7a04-bd0a-4a65-b832-725319bf6847/os-volume_attachments returned with HTTP 500
  2016-08-03 10:29:29.933 4508 DEBUG nova.api.openstack.wsgi [req-9036ab02-c49e-408e-9914-1627175e9158 a3e789e51d6243e493483d12593757a6 597854e23bfe46abb6178f786af12391 - - -] Returning 500 to user: The server has either erred or is incapable of performing the requested operation. __call__ /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:1166
  2016-08-03 10:29:29.934 4508 INFO nova.osapi_compute.wsgi.server [req-9036ab02-c49e-408e-9914-1627175e9158 a3e789e51d6243e493483d12593757a6 597854e23bfe46abb6178f786af12391 - - -] Traceback (most recent call last):
    File "/usr/lib/python2.7/site-packages/eventlet/wsgi.py", line 483, in handle_one_response
      write(b''.join(towrite))
    File "/usr/lib/python2.7/site-packages/eventlet/wsgi.py", line 426, in write
      _writelines(towrite)
    File "/usr/lib64/python2.7/socket.py", line 334, in writelines
      self.flush()
    File "/usr/lib64/python2.7/socket.py", line 303, in flush
      self._sock.sendall(view[write_offset:write_offset+buffer_size])
    File "/usr/lib/python2.7/site-packages/eventlet/greenio/base.py", line 376, in sendall
      tail = self.send(data, flags)
    File "/usr/lib/python2.7/site-packages/eventlet/greenio/base.py", line 359, in send
      total_sent += fd.send(data[total_sent:], flags)
  error: [Errno 104] Connection reset by peer
  2016-08-03 10:29:29.934 4508 INFO nova.osapi_compute.wsgi.server [req-9036ab02-c49e-408e-9914-1627175e9158 a3e789e51d6243e493483d12593757a6 597854e23bfe46abb6178f786af12391 - - -] 172.16.187.56,172.16.216.1 "POST /v2/597854e23bfe46abb6178f786af12391/servers/34ed7a04-bd0a-4a65-b832-725319bf6847/os-volume_attachments HTTP/1.1" status: 500 len: 0 time: 300.0823390
  ---

  The master branch has the same issue.

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

[Bug 1615908] [NEW] dummy BDM record if reserve_block_device_name timeout
From: Felix Ma, 2016-08-23