yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1241615] Re: rebuild with volume attached leaves instance without the volume and in an inconsistent state

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Thierry Carrez <thierry.carrez+lp@xxxxxxxxx>
Date: Wed, 05 Mar 2014 13:07:18 -0000
Reply-to: Bug 1241615 <1241615@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: nova
       Status: Fix Committed => Fix Released

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

Title:
  rebuild with volume attached leaves instance without the volume and in
  an inconsistent state

Status in OpenStack Compute (Nova):
  Fix Released
Status in OpenStack Compute (nova) havana series:
  In Progress

Bug description:
  I created a backup to an instance which had no volume attached.

  attached a volume -> rebuild the instance from the backup.

  It appears as though the volume is not attached anymore after the
  rebuild, but if we try to attach it to the same device we get an error
  that a device is already attached:

  2013-10-18 16:54:36.632 2478 DEBUG qpid.messaging [-] RETR[2fca830]: Message(properties={'x-amqp-0-10.routing-key': u'reply_70fb16e321724b38b3d3face4e83f363'}, content={u'oslo.message': u'{"_unique_id": "dd2a85b63c56498c8f2835f9b96e9bb9"
  , "failure": null, "_msg_id": "7ce524cebbb34aecab9d608a48103a1c", "result": null, "ending": true}', u'oslo.version': u'2.0'}) _get /usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py:654
  2013-10-18 16:54:36.633 2478 DEBUG qpid.messaging.io.ops [-] SENT[2fa6cb0]: MessageFlow(destination='0', unit=0, value=1L, id=serial(5206)) write_op /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:686
  2013-10-18 16:54:36.634 2478 DEBUG qpid.messaging.io.ops [-] SENT[2fa6cb0]: SessionCompleted(commands=[0-5199]) write_op /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:686
  2013-10-18 16:54:36.639 2478 ERROR nova.openstack.common.rpc.amqp [req-4a884bb4-5ba6-403d-8be7-df1eeebc1324 bbce236d5aac4d1dbc086a8835ed0ebc d09f3bf0f9224affa92ab97010b37270] Exception during message handling
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 461, in _process_data
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     **args)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/dispatcher.py", line 172, in dispatch
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     result = getattr(proxyobj, method)(ctxt, **kwargs)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 90, in wrapped
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     payload)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 73, in wrapped
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     return f(self, context, *args, **kw)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 243, in decorated_function
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     pass
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 229, in decorated_function
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 271, in decorated_function
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     e, sys.exc_info())
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 258, in decorated_function
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 3624, in reserve_block_device_name
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     return do_reserve()
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/openstack/common/lockutils.py", line 246, in inner
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     return f(*args, **kwargs)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 3613, in do_reserve
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     context, instance, bdms, device)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/utils.py", line 135, in get_device_name_for_instance
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     mappings['root'], device)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/utils.py", line 217, in get_next_device_name
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp     raise exception.DevicePathInUse(path=device)
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp DevicePathInUse: The supplied device path (/dev/vdc) is in use.
  2013-10-18 16:54:36.639 2478 TRACE nova.openstack.common.rpc.amqp 
  2013-10-18 16:54:36.641 2478 ERROR nova.openstack.common.rpc.common [req-4a884bb4-5ba6-403d-8be7-df1eeebc1324 bbce236d5aac4d1dbc086a8835ed0ebc d09f3bf0f9224affa92ab97010b37270] Returning exception The supplied device path (/dev/vdc) is i
  n use. to caller
  2013-10-18 16:54:36.642 2478 ERROR nova.openstack.common.rpc.common [req-4a884bb4-5ba6-403d-8be7-df1eeebc1324 bbce236d5aac4d1dbc086a8835ed0ebc d09f3bf0f9224affa92ab97010b37270] ['Traceback (most recent call last):\n', '  File "/usr/lib/p
  ython2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 461, in _process_data\n    **args)\n', '  File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/dispatcher.py", line 172, in dispatch\n    result = getattr(proxyo
  bj, method)(ctxt, **kwargs)\n', '  File "/usr/lib/python2.6/site-packages/nova/exception.py", line 90, in wrapped\n    payload)\n', '  File "/usr/lib/python2.6/site-packages/nova/exception.py", line 73, in wrapped\n    return f(self, con
  text, *args, **kw)\n', '  File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 243, in decorated_function\n    pass\n', '  File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 229, in decorated_function\
  n    return function(self, context, *args, **kwargs)\n', '  File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 271, in decorated_function\n    e, sys.exc_info())\n', '  File "/usr/lib/python2.6/site-packages/nova/compu
  te/manager.py", line 258, in decorated_function\n    return function(self, context, *args, **kwargs)\n', '  File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 3624, in reserve_block_device_name\n    return do_reserve()
  \n', '  File "/usr/lib/python2.6/site-packages/nova/openstack/common/lockutils.py", line 246, in inner\n    return f(*args, **kwargs)\n', '  File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 3613, in do_reserve\n    c
  ontext, instance, bdms, device)\n', '  File "/usr/lib/python2.6/site-packages/nova/compute/utils.py", line 135, in get_device_name_for_instance\n    mappings[\'root\'], device)\n', '  File "/usr/lib/python2.6/site-packages/nova/compute/u
  tils.py", line 217, in get_next_device_name\n    raise exception.DevicePathInUse(path=device)\n', 'DevicePathInUse: The supplied device path (/dev/vdc) is in use.\n']
  2013-10-18 16:54:36.642 2478 DEBUG nova.openstack.common.rpc.amqp [req-4a884bb4-5ba6-403d-8be7-df1eeebc1324 bbce236d5aac4d1dbc086a8835ed0ebc d09f3bf0f9224affa92ab97010b37270] UNIQUE_ID is 5d08dde3f40e4186b50e28a9dad5385b. _add_unique_id 
  /usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py:341

  
  If I try to attach the same volume to the same instance on a different device it seems to be working, however, when we try to detach it we get the following error: 

  2013-10-18 16:58:11.288 2478 DEBUG qpid.messaging [-] RCVD[2fca830]: Message(properties={'x-amqp-0-10.routing-key': u'reply_70fb16e321724b38b3d3face4e83f363'}, content={u'oslo.message': u'{"_unique_id": "20a035f66eac46f7b44e8420cd5a2d14"
  , "failure": null, "_msg_id": "27d7abfd907146c4a0e052cf067a4d69", "result": null, "ending": true}', u'oslo.version': u'2.0'}) do_message_transfer /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:1295
  2013-10-18 16:58:11.289 2478 DEBUG qpid.messaging [-] RETR[2fca830]: Message(properties={'x-amqp-0-10.routing-key': u'reply_70fb16e321724b38b3d3face4e83f363'}, content={u'oslo.message': u'{"_unique_id": "20a035f66eac46f7b44e8420cd5a2d14"
  , "failure": null, "_msg_id": "27d7abfd907146c4a0e052cf067a4d69", "result": null, "ending": true}', u'oslo.version': u'2.0'}) _get /usr/lib/python2.6/site-packages/qpid/messaging/endpoints.py:654
  2013-10-18 16:58:11.289 2478 DEBUG qpid.messaging.io.ops [-] SENT[2fa6cb0]: MessageFlow(destination='0', unit=0, value=1L, id=serial(5308)) write_op /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:686
  2013-10-18 16:58:11.290 2478 DEBUG qpid.messaging.io.ops [-] SENT[2fa6cb0]: SessionCompleted(commands=[0-5301]) write_op /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:686
  2013-10-18 16:58:11.296 2478 ERROR nova.openstack.common.rpc.amqp [req-62e56d8a-9dc1-447c-acef-2b2dafdd5079 bbce236d5aac4d1dbc086a8835ed0ebc d09f3bf0f9224affa92ab97010b37270] Exception during message handling
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 461, in _process_data
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     **args)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/dispatcher.py", line 172, in dispatch
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     result = getattr(proxyobj, method)(ctxt, **kwargs)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 90, in wrapped
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     payload)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 73, in wrapped
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     return f(self, context, *args, **kw)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 243, in decorated_function
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     pass
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 229, in decorated_function
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 271, in decorated_function
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     e, sys.exc_info())
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 258, in decorated_function
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 3760, in detach_volume
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     self._detach_volume(context, instance, bdm)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 3732, in _detach_volume
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     self.volume_api.roll_detaching(context, volume_id)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 3725, in _detach_volume
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     encryption=encryption)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 1205, in detach_volume
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp     raise exception.DiskNotFound(location=disk_dev)
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp DiskNotFound: No disk at vdc
  2013-10-18 16:58:11.296 2478 TRACE nova.openstack.common.rpc.amqp 
  2013-10-18 16:58:11.298 2478 DEBUG qpid.messaging.io.raw [-] SENT[2fa6cb0]: '\x0f\x01\x00\x19\x00\x01\x00\x00\x00\x00\x00\x00\x04\n\x01\x00\x07\x00\x010\x00\x00\x00\x00\x01\x0f\x00\x00\x1a\x00\x00\x00\x00\x00\x00\x00\x00\x02\n\x01\x00\x0
  0\x08\x00\x00\x00\x00\x00\x00\x14\xb5' writeable /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:480
  2013-10-18 16:58:14.265 2478 DEBUG qpid.messaging.io.raw [-] READ[2fa6cb0]: '\x0f\x00\x00\x10\x00\x00\x00\x00\x00\x00\x00\x00\x01\n\x00\x00' readable /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:416
  2013-10-18 16:58:14.266 2478 DEBUG qpid.messaging.io.ops [-] RCVD[2fa6cb0]: ConnectionHeartbeat() write /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:654
  2013-10-18 16:58:14.291 2478 DEBUG qpid.messaging.io.raw [-] READ[2fca998]: '\x0f\x00\x00\x10\x00\x00\x00\x00\x00\x00\x00\x00\x01\n\x00\x00' readable /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:416
  2013-10-18 16:58:14.291 2478 DEBUG qpid.messaging.io.ops [-] RCVD[2fca998]: ConnectionHeartbeat() write /usr/lib/python2.6/site-packages/qpid/messaging/driver.py:654
  2013-10-18 16:58:15.019 2478 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._poll_volume_usage run_periodic_tasks /usr/lib/python2.6/site-packages/nova/openstack/common/periodic_task.py:176
  2013-10-18 16:58:15.024 2478 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager._instance_usage_audit run_periodic_tasks /usr/lib/python2.6/site-packages/nova/openstack/common/periodic_task.py:176
  2013-10-18 16:58:15.024 2478 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks /usr/lib/python2.6/site-packages/nova/openstack/common/periodic_task.py:176
  2013-10-18 16:58:15.025 2478 DEBUG nova.openstack.common.lockutils [-] Got semaphore "compute_resources" lock /usr/lib/python2.6/site-packages/nova/openstack/common/lockutils.py:166
  2013-10-18 16:58:15.025 2478 DEBUG nova.openstack.common.lockutils [-] Got semaphore / lock "update_available_resource" inner /usr/lib/python2.6/site-packages/nova/openstack/common/lockutils.py:245
  2013-10-18 16:58:15.025 2478 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources

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