2012-09-27 19:53:51 |
Vish Ishaya |
description |
If you detach a volume from an instance and then terminate the instance concurrently, the two execution paths can stomp on each other:
Traceback from terminate greenthread:
2012-09-27 18:32:40 ERROR nova.openstack.common.rpc.amqp [-] Exception during message handling
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.py", line 275, in _process_data
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp rval = self.proxy.dispatch(ctxt, version, method, **args)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/dispatcher.py", line 145, in dispatch
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 117, in wrapped
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp temp_level, payload)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 92, in wrapped
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return f(*args, **kw)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 181, in decorated_function
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp pass
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 167, in decorated_function
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 202, in decorated_function
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp kwargs['instance']['uuid'], e, sys.exc_info())
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 196, in decorated_function
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 917, in terminate_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp do_terminate_instance(instance)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 752, in inner
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp retval = f(*args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 909, in do_terminate_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self._delete_instance(context, instance)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 881, in _delete_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self._shutdown_instance(context, instance)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 845, in _shutdown_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp block_device_info)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 845, in _shutdown_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp block_device_info)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 492, in destroy
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self._cleanup(instance, network_info, block_device_info)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 535, in _cleanup
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp mount_device)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 610, in volume_driver_method
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return method(connection_info, *args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 752, in inner
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp retval = f(*args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume.py", line 202, in disconnect_volume
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp check_exit_code=[0, 255])
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume.py", line 115, in _iscsiadm_update
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return self._run_iscsiadm(iscsi_properties, iscsi_command, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume.py", line 106, in _run_iscsiadm
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp check_exit_code=check_exit_code)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 198, in execute
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp cmd=' '.join(cmd))
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp ProcessExecutionError: Unexpected error while running command.
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp Command: sudo nova-rootwrap /etc/nova/rootwrap.conf iscsiadm -m node -T iqn.2010-10.org.openstack:volume-f8731ea4-afb5-48f2-91b8-b64570f893e0 -p 10.129.28.4:3260 --op update -n node.startup -v manual
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp Exit code: 21
traceback from detach greenthread:
2012-09-27 18:32:39 ERROR nova.openstack.common.rpc.amqp [-] Exception during message handling
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.py", line 275, in _process_data
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp rval = self.proxy.dispatch(ctxt, version, method, **args)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/dispatcher.py", line 145, in dispatch
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 117, in wrapped
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp temp_level, payload)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 92, in wrapped
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp return f(*args, **kw)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 181, in decorated_function
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp pass
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 167, in decorated_function
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 202, in decorated_function
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp kwargs['instance']['uuid'], e, sys.exc_info())
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 196, in decorated_function
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1989, in detach_volume
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp self._detach_volume(context, instance, bdm)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1980, in _detach_volume
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp mp)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 117, in wrapped
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp temp_level, payload)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 92, in wrapped
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp return f(*args, **kw)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 685, in detach_volume
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp virt_dom.detachDevice(xml)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 187, in doit
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp result = proxy_call(self._autowrap, f, *args, **kwargs)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 147, in proxy_call
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp rv = execute(f,*args,**kwargs)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/eventlet/tpool.py", line 76, in tworker
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp rv = meth(*args,**kwargs)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/libvirt.py", line 615, in detachDevice
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp if ret == -1: raise libvirtError ('virDomainDetachDevice() failed', dom=self)
2012-09-27 18:32:39 TRACE nova.openstack.common.rpc.amqp libvirtError: Requested operation is not valid: cannot do live update a device on inactive domain
The error on the detach isn't particularly worrisome as the detach is actually failing because the volume is gone. Might be nice to catch the error and just log a warning instead of traceback. The other issue seems to be a lack of idempotency in the iscsi disconnect code. |
If you detach a volume from an instance and then terminate the instance concurrently, the two execution paths can stomp on each other:
Traceback from terminate greenthread:
2012-09-27 18:32:40 ERROR nova.openstack.common.rpc.amqp [-] Exception during message handling
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/amqp.py", line 275, in _process_data
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp rval = self.proxy.dispatch(ctxt, version, method, **args)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/openstack/common/rpc/dispatcher.py", line 145, in dispatch
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return getattr(proxyobj, method)(ctxt, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 117, in wrapped
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp temp_level, payload)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 92, in wrapped
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return f(*args, **kw)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 181, in decorated_function
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp pass
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 167, in decorated_function
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 202, in decorated_function
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp kwargs['instance']['uuid'], e, sys.exc_info())
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self.gen.next()
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 196, in decorated_function
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return function(self, context, *args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 917, in terminate_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp do_terminate_instance(instance)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 752, in inner
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp retval = f(*args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 909, in do_terminate_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self._delete_instance(context, instance)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 881, in _delete_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self._shutdown_instance(context, instance)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 845, in _shutdown_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp block_device_info)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 845, in _shutdown_instance
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp block_device_info)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 492, in destroy
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp self._cleanup(instance, network_info, block_device_info)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 535, in _cleanup
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp mount_device)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 610, in volume_driver_method
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return method(connection_info, *args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 752, in inner
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp retval = f(*args, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume.py", line 202, in disconnect_volume
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp check_exit_code=[0, 255])
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume.py", line 115, in _iscsiadm_update
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp return self._run_iscsiadm(iscsi_properties, iscsi_command, **kwargs)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/volume.py", line 106, in _run_iscsiadm
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp check_exit_code=check_exit_code)
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 198, in execute
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp cmd=' '.join(cmd))
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp ProcessExecutionError: Unexpected error while running command.
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp Command: sudo nova-rootwrap /etc/nova/rootwrap.conf iscsiadm -m node -T iqn.2010-10.org.openstack:volume-f8731ea4-afb5-48f2-91b8-b64570f893e0 -p 10.129.28.4:3260 --op update -n node.startup -v manual
2012-09-27 18:32:40 TRACE nova.openstack.common.rpc.amqp Exit code: 21
(other traceback reported as separate bug here: https://bugs.launchpad.net/nova/+bug/1057730
The error on the detach isn't particularly worrisome as the detach is actually failing because the volume is gone. Might be nice to catch the error and just log a warning instead of traceback. The other issue seems to be a lack of idempotency in the iscsi disconnect code. |
|