OpenStack Compute (nova)

nova-compute intermittently fail to detach vbd

Bug #999953 reported by Armando Migliaccio
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Invalid
Undecided
Armando Migliaccio
Essex
Fix Released
Undecided
Unassigned
OpenStack Compute (nova) 2012.1.1

Bug Description

Steps to reproduce:
Spawn multiple instances, using XenServer

What you see:
Some will boot, some don't. You'll find many ephemeral disks attached to the compute domU(s)

What you'd expect:
all of them will start.

Nova release: 2012.1-0ubuntu2.1

There is a retry logic to handle with this, but it wrongly expect a XenAPI.Failure exception whilst the unplug_vbd method raises a StorageError exception. The problem does not occur on Folsom trunk, and a fix would be needed to be ported to Essex/Stable

stack-trace from nova-compute:

2012-05-14 17:20:14 ERROR nova.virt.xenapi.vm_utils [req-ab3c1b32-8208-4ba6-9791-2040518e2a59 7cbacc62f59b41faacd3fc75ba5bbb70 5b8dacd7169e4273956d36b6d791c5c8] ['DEVICE_DETACH_REJECTED', 'VBD', 'OpaqueRef:cee99ae2-db47-d7a3-ba86-005ed98652c9', '16 Device in use; refusing to close']
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils Traceback (most recent call last):
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 251, in unplug_vbd
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils vbd_ref = session.call_xenapi('VBD.unplug', vbd_ref)
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi_conn.py", line 574, in call_xenapi
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils return tpool.execute(f, *args)
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 76, in tworker
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils rv = meth(*args,**kwargs)
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils File "/usr/local/lib/python2.7/dist-packages/XenAPI-1.2-py2.7.egg/XenAPI.py", line 229, in __call__
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils return self.__send(self.__name, args)
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils File "/usr/local/lib/python2.7/dist-packages/XenAPI-1.2-py2.7.egg/XenAPI.py", line 133, in xenapi_request
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils result = _parse_result(getattr(self, methodname)(*full_params))
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils File "/usr/local/lib/python2.7/dist-packages/XenAPI-1.2-py2.7.egg/XenAPI.py", line 203, in _parse_result
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils raise Failure(result['ErrorDescription'])
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils Failure: ['DEVICE_DETACH_REJECTED', 'VBD', 'OpaqueRef:cee99ae2-db47-d7a3-ba86-005ed98652c9', '16 Device in use; refusing to close']
2012-05-14 17:20:14 TRACE nova.virt.xenapi.vm_utils
2012-05-14 17:20:15 ERROR nova.virt.xenapi.vm_utils [req-ab3c1b32-8208-4ba6-9791-2040518e2a59 7cbacc62f59b41faacd3fc75ba5bbb70 5b8dacd7169e4273956d36b6d791c5c8] ['OPERATION_NOT_ALLOWED', "VBD '32654e4b-0128-109d-5fdb-1789acb3063c' still attached to '5961429b-a9d7-6334-eedc-daf612719438'"]
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils Traceback (most recent call last):
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 262, in destroy_vbd
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils session.call_xenapi('VBD.destroy', vbd_ref)
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi_conn.py", line 574, in call_xenapi
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils return tpool.execute(f, *args)
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 76, in tworker
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils rv = meth(*args,**kwargs)
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/local/lib/python2.7/dist-packages/XenAPI-1.2-py2.7.egg/XenAPI.py", line 229, in __call__
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils return self.__send(self.__name, args)
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/local/lib/python2.7/dist-packages/XenAPI-1.2-py2.7.egg/XenAPI.py", line 133, in xenapi_request
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils result = _parse_result(getattr(self, methodname)(*full_params))
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/local/lib/python2.7/dist-packages/XenAPI-1.2-py2.7.egg/XenAPI.py", line 203, in _parse_result
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils raise Failure(result['ErrorDescription'])
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils Failure: ['OPERATION_NOT_ALLOWED', "VBD '32654e4b-0128-109d-5fdb-1789acb3063c' still attached to '5961429b-a9d7-6334-eedc-daf612719438'"]
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils
2012-05-14 17:20:15 DEBUG nova.virt.xenapi.vm_utils [req-ab3c1b32-8208-4ba6-9791-2040518e2a59 7cbacc62f59b41faacd3fc75ba5bbb70 5b8dacd7169e4273956d36b6d791c5c8] Destroying VBD for VDI OpaqueRef:8c08b3bd-ff20-8975-d9e5-d94099341416 done. from (pid=2782) vdi_attached_here /usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py:1487
2012-05-14 17:20:15 ERROR nova.virt.xenapi.vm_utils [req-ab3c1b32-8208-4ba6-9791-2040518e2a59 7cbacc62f59b41faacd3fc75ba5bbb70 5b8dacd7169e4273956d36b6d791c5c8] ['VDI_IN_USE', 'OpaqueRef:8c08b3bd-ff20-8975-d9e5-d94099341416']
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils Traceback (most recent call last):
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 295, in destroy_vdi
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils session.call_xenapi('VDI.destroy', vdi_ref)
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi_conn.py", line 574, in call_xenapi
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils return tpool.execute(f, *args)
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 76, in tworker
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils rv = meth(*args,**kwargs)
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/local/lib/python2.7/dist-packages/XenAPI-1.2-py2.7.egg/XenAPI.py", line 229, in __call__
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils return self.__send(self.__name, args)
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/local/lib/python2.7/dist-packages/XenAPI-1.2-py2.7.egg/XenAPI.py", line 133, in xenapi_request
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils result = _parse_result(getattr(self, methodname)(*full_params))
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils File "/usr/local/lib/python2.7/dist-packages/XenAPI-1.2-py2.7.egg/XenAPI.py", line 203, in _parse_result
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils raise Failure(result['ErrorDescription'])
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils Failure: ['VDI_IN_USE', 'OpaqueRef:8c08b3bd-ff20-8975-d9e5-d94099341416']
2012-05-14 17:20:15 TRACE nova.virt.xenapi.vm_utils
2012-05-14 17:20:15 ERROR nova.utils [req-ab3c1b32-8208-4ba6-9791-2040518e2a59 7cbacc62f59b41faacd3fc75ba5bbb70 5b8dacd7169e4273956d36b6d791c5c8] Original exception being dropped
2012-05-14 17:20:15 TRACE nova.utils Traceback (most recent call last):
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 530, in _generate_disk
2012-05-14 17:20:15 TRACE nova.utils run_as_root=True)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-05-14 17:20:15 TRACE nova.utils self.gen.next()
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 1480, in vdi_attached_here
2012-05-14 17:20:15 TRACE nova.utils vbd_unplug_with_retry(session, vbd_ref)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 1497, in vbd_unplug_with_retry
2012-05-14 17:20:15 TRACE nova.utils VMHelper.unplug_vbd(session, vbd_ref)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 256, in unplug_vbd
2012-05-14 17:20:15 TRACE nova.utils _('Unable to unplug VBD %s') % vbd_ref)
2012-05-14 17:20:15 TRACE nova.utils StorageError: Unable to unplug VBD OpaqueRef:cee99ae2-db47-d7a3-ba86-005ed98652c9
2012-05-14 17:20:15 TRACE nova.utils
2012-05-14 17:20:15 ERROR nova.utils [req-ab3c1b32-8208-4ba6-9791-2040518e2a59 7cbacc62f59b41faacd3fc75ba5bbb70 5b8dacd7169e4273956d36b6d791c5c8] Instance aa386b2c-401a-4029-8a57-3d0eec11f7a5: Failed to spawn, rolling back.
2012-05-14 17:20:15 TRACE nova.utils Traceback (most recent call last):
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 349, in spawn
2012-05-14 17:20:15 TRACE nova.utils vm_ref = create_vm_step(undo_mgr, vdis, kernel_file, ramdisk_file)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 138, in inner
2012-05-14 17:20:15 TRACE nova.utils rv = f(*args, **kwargs)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 312, in create_vm_step
2012-05-14 17:20:15 TRACE nova.utils ramdisk_file=ramdisk_file)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 419, in _create_vm
2012-05-14 17:20:15 TRACE nova.utils vdis)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 491, in _attach_disks
2012-05-14 17:20:15 TRACE nova.utils vm_ref, userdevice, ephemeral_gb)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 554, in generate_ephemeral
2012-05-14 17:20:15 TRACE nova.utils FLAGS.default_ephemeral_format)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 537, in _generate_disk
2012-05-14 17:20:15 TRACE nova.utils cls.destroy_vdi(session, vdi_ref)
2012-05-14 17:20:15 TRACE nova.utils File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 299, in destroy_vdi
2012-05-14 17:20:15 TRACE nova.utils _('Unable to destroy VDI %s') % vdi_ref)
2012-05-14 17:20:15 TRACE nova.utils StorageError: Unable to destroy VDI OpaqueRef:8c08b3bd-ff20-8975-d9e5-d94099341416
2012-05-14 17:20:15 TRACE nova.utils
2012-05-14 17:20:15 DEBUG nova.virt.xenapi.vmops [req-ab3c1b32-8208-4ba6-9791-2040518e2a59 7cbacc62f59b41faacd3fc75ba5bbb70 5b8dacd7169e4273956d36b6d791c5c8] Removing VDI OpaqueRef:e1755a26-3f80-bf23-bf0d-85dfcb3b00e7(uuid:d642424e-523f-4e6a-9234-0b0e262c52f7) from (pid=2782) undo_create_disks /usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py:274
2012-05-14 17:20:15 ERROR nova.compute.manager [req-ab3c1b32-8208-4ba6-9791-2040518e2a59 7cbacc62f59b41faacd3fc75ba5bbb70 5b8dacd7169e4273956d36b6d791c5c8] [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] Instance failed to spawn
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] Traceback (most recent call last):
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 592, in _spawn
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] self._legacy_nw_info(network_info), block_device_info)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi_conn.py", line 184, in spawn
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] self._vmops.spawn(context, instance, image_meta, network_info)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 359, in spawn
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] undo_mgr.rollback_and_reraise(msg=msg)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 1714, in rollback_and_reraise
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] self._rollback()
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] self.gen.next()
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 349, in spawn
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] vm_ref = create_vm_step(undo_mgr, vdis, kernel_file, ramdisk_file)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 138, in inner
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] rv = f(*args, **kwargs)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 312, in create_vm_step
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] ramdisk_file=ramdisk_file)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 419, in _create_vm
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] vdis)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vmops.py", line 491, in _attach_disks
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] vm_ref, userdevice, ephemeral_gb)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 554, in generate_ephemeral
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] FLAGS.default_ephemeral_format)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 537, in _generate_disk
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] cls.destroy_vdi(session, vdi_ref)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] File "/usr/lib/python2.7/dist-packages/nova/virt/xenapi/vm_utils.py", line 299, in destroy_vdi
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] _('Unable to destroy VDI %s') % vdi_ref)
2012-05-14 17:20:15 TRACE nova.compute.manager [instance: aa386b2c-401a-4029-8a57-3d0eec11f7a5] StorageError: Unable to destroy VDI OpaqueRef:8c08b3bd-ff20-8975-d9e5-d94099341416

Related branches

lp://staging/~openstack-ubuntu-testing/nova/precise-essex-proposed
Chuck Short: Pending requested
Diff: 56 lines (+14/-4)
3 files modified
debian/changelog (+8/-0)
debian/control (+6/-3)
debian/nova-console.install (+0/-1)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nova (stable/essex)

Fix proposed to branch: stable/essex
Review: https://review.openstack.org/7551

Armando Migliaccio (armando-migliaccio)
Changed in nova:
assignee: nobody → Armando Migliaccio (armando-migliaccio)
Revision history for this message
Armando Migliaccio (armando-migliaccio) wrote :

this duplicates this bug: #960655

Changed in nova:
status: New → Invalid
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nova (stable/essex)

Reviewed: https://review.openstack.org/7551
Committed: http://github.com/openstack/nova/commit/1a838e2e99a75a7fb245ae9f46c57fc0fc507fd4
Submitter: Jenkins
Branch: stable/essex

commit 1a838e2e99a75a7fb245ae9f46c57fc0fc507fd4
Author: Armando Migliaccio <email address hidden>
Date: Thu May 17 18:34:58 2012 +0100

    bug #999953 xenapi driver intermittently fail to detach vbd

    ensure that unplug_vbd raises XenAPI.Failure as required by
    vbd_unplug_with_retry(session, vbd_ref).

    Change-Id: If689da4ebc5d9042f26c765afb02ae611967a66b

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.