nova delete could not stop vm

Asked by willfu

when I try to stop vm instance by **nova delete xxxx(intance id)**, and list again, found instance is still active.
Then I read compute log accordingly as below errors.

2012-08-29 14:34:52 DEBUG nova.rpc.amqp [-] received {u'_context_roles': [u'admin'], u'_context_request_id': u'req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90', u'_context_read_deleted': u'no', u'args': {u'instance_uuid': u'58937fb2-695d-4db5-817f-66c2aae499fb'}, u'_context_auth_token': '<SANITIZED>', u'_context_is_admin': True, u'_context_project_id': u'5e962c586e9a4ccfa18ce572718ae1ce', u'_context_timestamp': u'2012-08-29T06:34:52.774025', u'_context_user_id': u'ecf118bde4cd484186f44757997da289', u'method': u'terminate_instance', u'_context_remote_address': u'192.168.11.100'} from (pid=18507) _safe_log /usr/lib/python2.6/site-packages/nova/rpc/common.py:160
2012-08-29 14:34:52 DEBUG nova.rpc.amqp [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] unpacked context: {'user_id': u'ecf118bde4cd484186f44757997da289', 'roles': [u'admin'], 'timestamp': '2012-08-29T06:34:52.774025', 'auth_token': '<SANITIZED>', 'remote_address': u'192.168.11.100', 'is_admin': True, 'request_id': u'req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90', 'project_id': u'5e962c586e9a4ccfa18ce572718ae1ce', 'read_deleted': u'no'} from (pid=18507) _safe_log /usr/lib/python2.6/site-packages/nova/rpc/common.py:160
2012-08-29 14:34:52 INFO nova.compute.manager [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] check_instance_lock: decorating: |<function terminate_instance at 0x1dd1668>|
2012-08-29 14:34:52 INFO nova.compute.manager [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] check_instance_lock: arguments: |<nova.compute.manager.ComputeManager object at 0x1c6aa90>| |<nova.rpc.amqp.RpcContext object at 0x4434d10>| |58937fb2-695d-4db5-817f-66c2aae499fb|
2012-08-29 14:34:52 DEBUG nova.compute.manager [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] instance 58937fb2-695d-4db5-817f-66c2aae499fb: getting locked state from (pid=18507) get_lock /usr/lib/python2.6/site-packages/nova/compute/manager.py:1621
2012-08-29 14:34:52 INFO nova.compute.manager [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] check_instance_lock: locked: |False|
2012-08-29 14:34:52 INFO nova.compute.manager [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] check_instance_lock: admin: |True|
2012-08-29 14:34:52 INFO nova.compute.manager [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] check_instance_lock: executing: |<function terminate_instance at 0x1dd1668>|
2012-08-29 14:34:52 DEBUG nova.utils [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] Attempting to grab semaphore "58937fb2-695d-4db5-817f-66c2aae499fb" for method "do_terminate_instance"... from (pid=18507) inner /usr/lib/python2.6/site-packages/nova/utils.py:928
2012-08-29 14:34:52 DEBUG nova.utils [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] Got semaphore "58937fb2-695d-4db5-817f-66c2aae499fb" for method "do_terminate_instance"... from (pid=18507) inner /usr/lib/python2.6/site-packages/nova/utils.py:932
2012-08-29 14:34:52 AUDIT nova.compute.manager [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] [instance: 58937fb2-695d-4db5-817f-66c2aae499fb] Terminating instance
2012-08-29 14:34:52 DEBUG nova.rpc.amqp [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] Making asynchronous call on network ... from (pid=18507) multicall /usr/lib/python2.6/site-packages/nova/rpc/amqp.py:326
2012-08-29 14:34:52 DEBUG nova.rpc.amqp [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] MSG_ID is aeeb7cf4f6f442a2810eb2419e3231e8 from (pid=18507) multicall /usr/lib/python2.6/site-packages/nova/rpc/amqp.py:329
2012-08-29 14:34:53 DEBUG nova.compute.manager [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] [instance: 58937fb2-695d-4db5-817f-66c2aae499fb] Deallocating network for instance from (pid=18507) _deallocate_network /usr/lib/python2.6/site-packages/nova/compute/manager.py:635
2012-08-29 14:34:53 DEBUG nova.rpc.amqp [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] Making asynchronous call on network ... from (pid=18507) multicall /usr/lib/python2.6/site-packages/nova/rpc/amqp.py:326
2012-08-29 14:34:53 DEBUG nova.rpc.amqp [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] MSG_ID is 057e830430984efaa0914738a7f0a0bb from (pid=18507) multicall /usr/lib/python2.6/site-packages/nova/rpc/amqp.py:329
2012-08-29 14:34:53 ERROR nova.rpc.amqp [req-233e791c-6a88-4a4d-85c7-3f8c81ee1c90 ecf118bde4cd484186f44757997da289 5e962c586e9a4ccfa18ce572718ae1ce] Exception during message handling
2012-08-29 14:34:53 TRACE nova.rpc.amqp Traceback (most recent call last):
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/rpc/amqp.py", line 253, in _process_data
2012-08-29 14:34:53 TRACE nova.rpc.amqp rval = node_func(context=ctxt, **node_args)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/exception.py", line 114, in wrapped
2012-08-29 14:34:53 TRACE nova.rpc.amqp return f(*args, **kw)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 159, in decorated_function
2012-08-29 14:34:53 TRACE nova.rpc.amqp function(self, context, instance_uuid, *args, **kwargs)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 183, in decorated_function
2012-08-29 14:34:53 TRACE nova.rpc.amqp sys.exc_info())
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2012-08-29 14:34:53 TRACE nova.rpc.amqp self.gen.next()
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 177, in decorated_function
2012-08-29 14:34:53 TRACE nova.rpc.amqp return function(self, context, instance_uuid, *args, **kwargs)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 771, in terminate_instance
2012-08-29 14:34:53 TRACE nova.rpc.amqp do_terminate_instance()
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/utils.py", line 946, in inner
2012-08-29 14:34:53 TRACE nova.rpc.amqp retval = f(*args, **kwargs)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 764, in do_terminate_instance
2012-08-29 14:34:53 TRACE nova.rpc.amqp self._delete_instance(context, instance)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 742, in _delete_instance
2012-08-29 14:34:53 TRACE nova.rpc.amqp self._shutdown_instance(context, instance, 'Terminating')
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 704, in _shutdown_instance
2012-08-29 14:34:53 TRACE nova.rpc.amqp self._deallocate_network(context, instance)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 636, in _deallocate_network
2012-08-29 14:34:53 TRACE nova.rpc.amqp self.network_api.deallocate_for_instance(context, instance)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/network/api.py", line 190, in deallocate_for_instance
2012-08-29 14:34:53 TRACE nova.rpc.amqp 'args': args})
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/rpc/__init__.py", line 68, in call
2012-08-29 14:34:53 TRACE nova.rpc.amqp return _get_impl().call(context, topic, msg, timeout)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/rpc/impl_qpid.py", line 526, in call
2012-08-29 14:34:53 TRACE nova.rpc.amqp return rpc_amqp.call(context, topic, msg, timeout, Connection.pool)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/rpc/amqp.py", line 343, in call
2012-08-29 14:34:53 TRACE nova.rpc.amqp rv = list(rv)
2012-08-29 14:34:53 TRACE nova.rpc.amqp File "/usr/lib/python2.6/site-packages/nova/rpc/amqp.py", line 311, in __iter__
2012-08-29 14:34:53 TRACE nova.rpc.amqp raise result
2012-08-29 14:34:53 TRACE nova.rpc.amqp RemoteError: Remote error: ProcessExecutionError Unexpected error while running command.
2012-08-29 14:34:53 TRACE nova.rpc.amqp Command: sudo nova-rootwrap dhcp_release br101 10.1.101.13 fa:16:3e:48:f8:ee
2012-08-29 14:34:53 TRACE nova.rpc.amqp Exit code: 1
2012-08-29 14:34:53 TRACE nova.rpc.amqp Stdout: ''
2012-08-29 14:34:53 TRACE nova.rpc.amqp Stderr: 'Traceback (most recent call last):\n File "/usr/bin/nova-rootwrap", line 69, in <module>\n env=filtermatch.get_environment(userargs))\n File "/usr/lib64/python2.6/subprocess.py", line 639, in __init__\n errread, errwrite)\n File "/usr/lib64/python2.6/subprocess.py", line 1228, in _execute_child\n raise child_exception\nOSError: [Errno 2] No such file or directory\n'
2012-08-29 14:34:53 TRACE nova.rpc.amqp [u'Traceback (most recent call last):\n', u' File "/usr/lib/python2.6/site-packages/nova/rpc/amqp.py", line 253, in _process_data\n rval = node_func(context=ctxt, **node_args)\n', u' File "/usr/lib/python2.6/site-packages/nova/network/manager.py", line 257, in wrapped\n return func(self, context, *args, **kwargs)\n', u' File "/usr/lib/python2.6/site-packages/nova/network/manager.py", line 379, in deallocate_for_instance\n super(FloatingIP, self).deallocate_for_instance(context, **kwargs)\n', u' File "/usr/lib/python2.6/site-packages/nova/network/manager.py", line 257, in wrapped\n return func(self, context, *args, **kwargs)\n', u' File "/usr/lib/python2.6/site-packages/nova/network/manager.py", line 934, in deallocate_for_instance\n **kwargs)\n', u' File "/usr/lib/python2.6/site-packages/nova/network/manager.py", line 247, in deallocate_fixed_ip\n address)\n', u' File "/usr/lib/python2.6/site-packages/nova/network/manager.py", line 1236, in deallocate_fixed_ip\n self.driver.release_dhcp(dev, address, vif[\'address\'])\n', u' File "/usr/lib/python2.6/site-packages/nova/network/linux_net.py", line 638, in release_dhcp\n utils.execute(\'dhcp_release\', dev, address, mac_address, run_as_root=True)\n', u' File "/usr/lib/python2.6/site-packages/nova/utils.py", line 243, in execute\n cmd=\' \'.join(cmd))\n', u'ProcessExecutionError: Unexpected error while running command.\nCommand: sudo nova-rootwrap dhcp_release br101 10.1.101.13 fa:16:3e:48:f8:ee\nExit code: 1\nStdout: \'\'\nStderr: \'Traceback (most recent call last):\\n File "/usr/bin/nova-rootwrap", line 69, in <module>\\n env=filtermatch.get_environment(userargs))\\n File "/usr/lib64/python2.6/subprocess.py", line 639, in __init__\\n errread, errwrite)\\n File "/usr/lib64/python2.6/subprocess.py", line 1228, in _execute_child\\n raise child_exception\\nOSError: [Errno 2] No such file or directory\\n\'\n'].

==========================================
Cloud somebody help?
Below is part of my nova.conf on compute node.
# COMPUTE
libvirt_type=kvm
connection_type=libvirt
instance_name_template=instance-%08x
api_paste_config=/etc/nova/api-paste.ini
allow_resize_to_same_host=True
instances_path=/home/instances

# NETWORK
network_manager=nova.network.manager.VlanManager
force_dhcp_release=True
dhcpbridge_flagfile=/etc/nova/nova.conf
dhcpbridge = /usr/bin/nova-dhcpbridge
firewall_driver=nova.virt.libvirt.firewall.IptablesFirewallDriver
public_interface=eth2
vlan_interface=eth4
fixed_range=10.1.101.0/24
network_size=256

Question information

Language:
English Edit question
Status:
Solved
For:
OpenStack Compute (nova) Edit question
Assignee:
No assignee Edit question
Solved by:
willfu
Solved:
Last query:
Last reply:
Revision history for this message
willfu (willfly0620) said :
#1

This is due to configuration in nova.conf on scheduler section.
Set force_dhcp_release=False