1266718 – Invalid volume: being attached by another instance to caller

Bug 1266718 - Invalid volume: being attached by another instance to caller

Summary: Invalid volume: being attached by another instance to caller

Keywords:
Status:	CLOSED NOTABUG
Alias:	None
Product:	Red Hat OpenStack
Classification:	Red Hat
Component:	openstack-cinder
Sub Component:
Version:	5.0 (RHEL 7)
Hardware:	All
OS:	Linux
Priority:	unspecified
Severity:	high
Target Milestone:	---
Target Release:	5.0 (RHEL 7)
Assignee:	Eric Harney
QA Contact:	nlevinki
Docs Contact:
URL:
Whiteboard:
Depends On:
Blocks:	1317428
TreeView+	depends on / blocked

Reported:	2015-09-26 22:04 UTC by Jack Waterworth
Modified:	2019-10-10 10:15 UTC (History)
CC List:	5 users (show)
Fixed In Version:
Doc Type:	Bug Fix
Doc Text:
Clone Of:
Clones:	1317428 (view as bug list)
Environment:
Last Closed:	2016-03-13 07:06:09 UTC
Target Upstream Version:
Embargoed:

Attachments	(Terms of Use)

Description Jack Waterworth 2015-09-26 22:04:35 UTC

Description of problem:
Attempting to attach a volume to an instance returns the following exception in the logs:

--------------------
2015-09-25 14:05:24.773 29046 ERROR oslo.messaging._drivers.common [-] Returning exception Invalid input received: Invalid volume: being attached by another instance to caller
--------------------

Version-Release number of selected component (if applicable):

python-cinderclient-1.0.9-1.el7ost.noarch

How reproducible:

Every time

Steps to Reproduce:
1. Attempt to attach a volume to an instance
2. Verify the volume does NOT attach
3. Check logs

Actual results:
Invalid volume exception is thrown

Expected results:
No exception should occur.

Comment 2 Jack Waterworth 2015-09-26 22:09:23 UTC

Customer was attempting to detatch an volume from an instance (instance A), and attach it to another instance (instance B). They stated that they had a problem with a cinder device, and did some database level modification. I'm not certain exactly what.

They were able to attach the volume to instance B from a nova perspective, but the volume did not actually attach. a `dumpxml` against the virt shows that the device was not attached, and `cinder show` showed that the volume did not have any attachments.  A `nova show` showed the volume was attached to instance B.

I attempted to clear up this confusion by modifying the nova database:

mysql> UPDATE block_device_mapping SET 'deleted = 2' WHERE volume_id = 'your_volume_id';

This removed the attachment from a nova perspective.

The customer then attempted to attach the volume back to instance A, but it did not attach. There were no failures at the console, but the logs showed the following traceback:

2015-09-25 14:05:24.773 29046 ERROR oslo.messaging._drivers.common [-] Returning exception Invalid input received: Invalid volume: being attached by another instance to caller

Comment 3 Jack Waterworth 2015-09-26 22:09:35 UTC

----------------------------------------
2015-09-25 14:05:24.771 29046 ERROR oslo.messaging.rpc.dispatcher [-] Exception during message handling: Invalid input received: Invalid volume: being attached by another instance
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     incoming.message))
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 412, in decorated_function
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     payload)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     return f(self, context, *args, **kw)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 293, in decorated_function
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     LOG.warning(msg, e, instance_uuid=instance_uuid)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 270, in decorated_function
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 322, in decorated_function
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     e, sys.exc_info())
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 309, in decorated_function
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 4278, in attach_volume
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     bdm.destroy(context)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 4275, in attach_volume
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     return self._attach_volume(context, instance, driver_bdm)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 4296, in _attach_volume
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     self.volume_api.unreserve_volume(context, bdm.volume_id)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 68, in __exit__
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 4288, in _attach_volume
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     do_check_attach=False, do_driver_attach=True)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/block_device.py", line 45, in wrapped
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     ret_val = method(obj, context, *args, **kwargs)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/block_device.py", line 265, in attach
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     self['mount_device'], mode=mode)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/volume/cinder.py", line 174, in wrapper
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     res = method(self, ctx, volume_id, *args, **kwargs)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/volume/cinder.py", line 270, in attach
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     mountpoint, mode=mode)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinderclient/v1/volumes.py", line 266, in attach
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     'mode': mode})
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinderclient/v1/volumes.py", line 250, in _action
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     return self.api.client.post(url, body=body)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinderclient/client.py", line 223, in post
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     return self._cs_request(url, 'POST', **kwargs)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinderclient/client.py", line 187, in _cs_request
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     **kwargs)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/cinderclient/client.py", line 170, in request
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher     raise exceptions.from_response(resp, body)
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher InvalidInput: Invalid input received: Invalid volume: being attached by another instance
2015-09-25 14:05:24.771 29046 TRACE oslo.messaging.rpc.dispatcher 
2015-09-25 14:05:24.773 29046 ERROR oslo.messaging._drivers.common [-] Returning exception Invalid input received: Invalid volume: being attached by another instance to caller
----------------------------------------

Comment 6 Sergey Gotliv 2015-09-27 06:58:08 UTC

Steps introduced in comment #4 to workaround that issue look reasonable. Are you sure that they continue hitting exactly the same exception after setting instance uuid to NULL? What is the output of the "cinder show <volume_id>" command?

We have to understand why Cinder is still thinking that this volume is attached to another instance especially after you explicitly set an instance uuid to NULL.

Note You need to log in before you can comment on or make changes to this bug.