OpenStack Compute (nova)

hyperv.vmutilsv2.destroy_vm fails with "HyperVException: Operation failed with return value: 32775" in hyper-v CI

Bug #1466515 reported by Matt Riedemann
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Invalid
Low
Unassigned

Bug Description

http://64.119.130.115/192406/2/Hyper-V_logs/hv-compute1/nova-compute.log.gz

2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 ERROR oslo_messaging.rpc.dispatcher [req-94c604a7-e023-4792-8f82-d4af076cda6e 2412437eb041483c8fde2d31507bb324 f088b7dc181a416a8edd2abc122c2c3d - - -] Exception during message handling: Operation failed with return value: 32775
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_messaging\rpc\dispatcher.py", line 142, in _dispatch_and_reply
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher executor_callback))
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_messaging\rpc\dispatcher.py", line 186, in _dispatch
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher executor_callback)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_messaging\rpc\dispatcher.py", line 130, in _do_dispatch
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\exception.py", line 90, in wrapped
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher payload)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_utils\excutils.py", line 119, in __exit__
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\exception.py", line 73, in wrapped
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher return f(self, context, *args, **kw)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 335, in decorated_function
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher LOG.warning(msg, e, instance_uuid=instance_uuid)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_utils\excutils.py", line 119, in __exit__
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 306, in decorated_function
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher return function(self, context, *args, **kwargs)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 385, in decorated_function
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher return function(self, context, *args, **kwargs)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 363, in decorated_function
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher kwargs['instance'], e, sys.exc_info())
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_utils\excutils.py", line 119, in __exit__
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 351, in decorated_function
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher return function(self, context, *args, **kwargs)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 2370, in terminate_instance
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher do_terminate_instance(instance, bdms)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_concurrency\lockutils.py", line 445, in inner
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher return f(*args, **kwargs)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 2368, in do_terminate_instance
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher self._set_instance_error_state(context, instance)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_utils\excutils.py", line 119, in __exit__
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 2358, in do_terminate_instance
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher self._delete_instance(context, instance, bdms, quotas)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\hooks.py", line 149, in inner
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher rv = f(*args, **kwargs)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 2337, in _delete_instance
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher quotas.rollback()
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_utils\excutils.py", line 119, in __exit__
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 2307, in _delete_instance
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher self._shutdown_instance(context, instance, bdms)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 2234, in _shutdown_instance
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher requested_networks)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_utils\excutils.py", line 119, in __exit__
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\compute\manager.py", line 2223, in _shutdown_instance
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher block_device_info)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\virt\hyperv\driver.py", line 76, in destroy
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher destroy_disks)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\virt\hyperv\vmops.py", line 461, in destroy
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher instance_name)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\oslo_utils\excutils.py", line 119, in __exit__
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\virt\hyperv\vmops.py", line 451, in destroy
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher self._vmutils.destroy_vm(instance_name)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\virt\hyperv\vmutilsv2.py", line 220, in destroy_vm
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher self.check_ret_val(ret_val, job_path)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher File "C:\Python27\lib\site-packages\nova\virt\hyperv\vmutils.py", line 580, in check_ret_val
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher % ret_val)
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher HyperVException: Operation failed with return value: 32775
2015-06-18 02:12:02.546 3276 86374000 GreenThread-11 TRACE oslo_messaging.rpc.dispatcher

This looks unrelated to the actual change being tested.

Tags: hyper-v
Revision history for this message
Alessandro Pilotti (alexpilotti) wrote :

This seems to be related to lack of locking during destroy.

32775 is just a code which means “Invalid state for this operation”, typically associated to the fact that another operation is in progress on the same instance, aka a race condition.

Changed in nova:
status: New → Confirmed
importance: Undecided → Low
Revision history for this message
Claudiu Belu (cbelu) wrote :

Hello Matt. Thanks for reporting this bug, but as it currently stands, this is a duplicate of bug: https://bugs.launchpad.net/nova/+bug/1461970

From what I can observe from the logs, failing to destroy in instance consistently appears after performing the snapshot operation. The reason why it fails to destroy the instance is because a request to destroy it has been received before the snapshoting completed and there is no locking mechanisms between operations (ideal for race conditions). This can be a problem with any long-lasting tasks such as this. I think this will have to be investigated further. Maybe other drivers are affected as well?

A fix is attempted for the mentioned bug.

Revision history for this message
Claudiu Belu (cbelu) wrote :

No longer a problem.

Changed in nova:
status: Confirmed → Invalid
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.