[Bug 1418590] Re: Instance is left in ACTIVE state even if rescue fails
OpenStack Infra
1418590 at bugs.launchpad.net
Tue Oct 6 14:49:49 UTC 2015
Reviewed: https://review.openstack.org/155120
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=a9e4e2c9a5aaa4d675057790816aa395bc27e9bc
Submitter: Jenkins
Branch: master
commit a9e4e2c9a5aaa4d675057790816aa395bc27e9bc
Author: George Shuklin <george.shuklin at gmail.com>
Date: Fri May 1 17:57:00 2015 +0300
If rescue failed set instance to ERROR
The compute API will allow attempting to rescue an instance that is in
active/stopped/error state. The compute manager will power off the instance
before calling driver.rescue.
If the rescue call fails in the virt driver, we should set the instance
to ERROR state since we (1) know the instance is definitely not active since
the compute manager powered it off and (2) we don't know what failed in the
virt driver, so punting and putting the instance into ERROR state is better
than leaving it broken and not signaling that with the vm_state.
Co-Authored-By: Matt Riedemann <mriedem at us.ibm.com>
Closes-Bug: 1418590
Change-Id: Ia1054d3f9193f876803f8b5a26d00bd9d5d66c12
** Changed in: nova
Status: In Progress => Fix Committed
--
You received this bug notification because you are a member of Ubuntu
OpenStack, which is subscribed to nova in Ubuntu.
https://bugs.launchpad.net/bugs/1418590
Title:
Instance is left in ACTIVE state even if rescue fails
Status in OpenStack Compute (nova):
Fix Committed
Status in nova package in Ubuntu:
Invalid
Bug description:
nova version: 1:2014.2.1-0ubuntu1~cloud0
State to reproduce:
1. Boot instance from image
2. Delete image
3. Stop nova-compute
4. Remove /var/lib/nova/instances/_base/*
5. start nova-compute
6. Try to rescue instance (nova rescue image)
Nova-compute will fail with few traces (see below) and instance get
strange state:
nova show 290ab4b7-7225-4b74-853a-d342974a2080
+--------------------------------------+----------------------------------------------------------+
| Property | Value |
+--------------------------------------+----------------------------------------------------------+
| OS-DCF:diskConfig | AUTO |
| OS-EXT-AZ:availability_zone | nova |
| OS-EXT-SRV-ATTR:host | pp3 |
| OS-EXT-SRV-ATTR:hypervisor_hostname | pp3 |
| OS-EXT-SRV-ATTR:instance_name | instance-000000f6 |
| OS-EXT-STS:power_state | 1 |
| OS-EXT-STS:task_state | - |
| OS-EXT-STS:vm_state | active |
| OS-SRV-USG:launched_at | 2015-02-05T14:15:30.000000 |
| OS-SRV-USG:terminated_at | - |
(skip)
After that it is impossible to unrescue instance (Cannot 'unrescue'
while instance is in vm_state active) or hard-reset (nothing happens).
Only nova reset-state helps.
Expected behavior: set it to ERROR state or, better, to reject rescue
if no image found.
Traces:
2015-02-05 15:59:41.973 7281 INFO nova.virt.libvirt.driver [req-af7026f3-4d85-4899-8452-2b69a3e66123 None] [instance: 290ab4b7-7225-4b74-853a-d342974a2080] Instance failed to shutdown in 60 seconds.
2015-02-05 15:59:42.363 7281 DEBUG nova.virt.driver [-] Emitting event <LifecycleEvent: 1423148382.36, 290ab4b7-7225-4b74-853a-d342974a2080 => Stopped> emit_event /usr/lib/python2.7/dist-packages/nova/virt/driver.py:1298
2015-02-05 15:59:42.364 7281 INFO nova.compute.manager [-] [instance: 290ab4b7-7225-4b74-853a-d342974a2080] VM Stopped (Lifecycle Event)
2015-02-05 15:59:42.366 7281 INFO nova.virt.libvirt.driver [-] [instance: 290ab4b7-7225-4b74-853a-d342974a2080] Instance destroyed successfully.
2015-02-05 15:59:42.368 7281 INFO nova.virt.libvirt.driver [req-af7026f3-4d85-4899-8452-2b69a3e66123 None] [instance: 290ab4b7-7225-4b74-853a-d342974a2080] Creating image
2015-02-05 15:59:42.369 7281 DEBUG nova.openstack.common.processutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 None] Running cmd (subprocess): sudo nova-rootwrap /etc/nova/rootwrap.conf chown 106 /var/lib/nova/instances/290ab4b7-7225-4b74-853a-d342974a2080/console.log execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:161
2015-02-05 15:59:42.389 7281 DEBUG nova.compute.manager [-] [instance: 290ab4b7-7225-4b74-853a-d342974a2080] Synchronizing instance power state after lifecycle event "Stopped"; current vm_state: active, current task_state: rescuing, current DB power_state: 1, VM power_state: 4 handle_lifecycle_event /usr/lib/python2.7/dist-packages/nova/compute/manager.py:1111
2015-02-05 15:59:42.405 7281 DEBUG nova.openstack.common.processutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 None] Result was 0 execute /usr/lib/python2.7/dist-packages/nova/openstack/common/processutils.py:195
2015-02-05 15:59:42.406 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Created new semaphore "70a880bdefde82d942a92de4c180c202e6090dd6" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-02-05 15:59:42.406 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Acquired semaphore "70a880bdefde82d942a92de4c180c202e6090dd6" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-02-05 15:59:42.406 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Attempting to grab external lock "70a880bdefde82d942a92de4c180c202e6090dd6" external_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:178
2015-02-05 15:59:42.406 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Got file lock "/var/lib/nova/instances/locks/nova-70a880bdefde82d942a92de4c180c202e6090dd6" acquire /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:93
2015-02-05 15:59:42.407 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Got semaphore / lock "fetch_func_sync" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-02-05 15:59:42.407 7281 DEBUG glanceclient.common.http [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] curl -i -X GET -H 'User-Agent: python-glanceclient' -H 'Content-Type: application/octet-stream' -H 'Accept-Encoding: gzip, deflate' -H 'Accept: */*' -H 'X-Auth-Token: ***' http://gi.controller:9292/v1/images/a58da6f6-cea3-4b3a-bdd0-30aefcdb37cf log_curl_request /usr/lib/python2.7/dist-packages/glanceclient/common/http.py:119
2015-02-05 15:59:42.417 7281 INFO nova.compute.manager [-] [instance: 290ab4b7-7225-4b74-853a-d342974a2080] During sync_power_state the instance has a pending task (rescuing). Skip.
2015-02-05 15:59:42.515 7281 ERROR glanceclient.common.http [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Request returned failure status 404.
2015-02-05 15:59:42.515 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Released file lock "/var/lib/nova/instances/locks/nova-70a880bdefde82d942a92de4c180c202e6090dd6" release /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:115
2015-02-05 15:59:42.515 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Releasing semaphore "70a880bdefde82d942a92de4c180c202e6090dd6" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-02-05 15:59:42.516 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Semaphore / lock released "fetch_func_sync" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-02-05 15:59:42.516 7281 ERROR nova.compute.manager [req-af7026f3-4d85-4899-8452-2b69a3e66123 None] [instance: 290ab4b7-7225-4b74-853a-d342974a2080] Error trying to Rescue Instance
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] Traceback (most recent call last):
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 3277, in rescue_instance
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] rescue_image_meta, admin_password)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 2569, in rescue
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] admin_pass=rescue_password)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 3005, in _create_image
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] project_id=instance['project_id'])
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/imagebackend.py", line 208, in cache
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] *args, **kwargs)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/imagebackend.py", line 410, in create_image
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] prepare_template(target=base, max_size=size, *args, **kwargs)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py", line 272, in inner
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] return f(*args, **kwargs)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/imagebackend.py", line 198, in fetch_func_sync
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] fetch_func(target=target, *args, **kwargs)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/utils.py", line 452, in fetch_image
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] max_size=max_size)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/virt/images.py", line 79, in fetch_to_raw
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] max_size=max_size)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/virt/images.py", line 73, in fetch
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] IMAGE_API.download(context, image_href, dest_path=path)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/image/api.py", line 178, in download
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] dst_path=dest_path)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 359, in download
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] _reraise_translated_image_exception(image_id)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 357, in download
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] image_chunks = self._client.call(context, 1, 'data', image_id)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/nova/image/glance.py", line 232, in call
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] return getattr(client.images, method)(*args, **kwargs)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/glanceclient/v1/images.py", line 142, in data
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] % urlparse.quote(str(image_id)))
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 253, in get
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] return self._request('GET', url, **kwargs)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] File "/usr/lib/python2.7/dist-packages/glanceclient/common/http.py", line 221, in _request
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] raise exc.from_response(resp, resp.content)
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080] ImageNotFound: Image a58da6f6-cea3-4b3a-bdd0-30aefcdb37cf could not be found.
2015-02-05 15:59:42.516 7281 TRACE nova.compute.manager [instance: 290ab4b7-7225-4b74-853a-d342974a2080]
2015-02-05 15:59:42.649 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Created new semaphore "compute_resources" internal_lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:206
2015-02-05 15:59:42.650 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Acquired semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:229
2015-02-05 15:59:42.650 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Got semaphore / lock "update_usage" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:271
2015-02-05 15:59:42.671 7281 INFO nova.scheduler.client.report [req-af7026f3-4d85-4899-8452-2b69a3e66123 None] Compute_service record updated for ('pp3', 'pp3')
2015-02-05 15:59:42.671 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Releasing semaphore "compute_resources" lock /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:238
2015-02-05 15:59:42.672 7281 DEBUG nova.openstack.common.lockutils [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Semaphore / lock released "update_usage" inner /usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py:275
2015-02-05 15:59:42.672 7281 ERROR oslo.messaging.rpc.dispatcher [req-af7026f3-4d85-4899-8452-2b69a3e66123 ] Exception during message handling: Instance 290ab4b7-7225-4b74-853a-d342974a2080 cannot be rescued: Driver Error: Image a58da6f6-cea3-4b3a-bdd0-30aefcdb37cf could not be found.
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher incoming.message))
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 419, in decorated_function
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher return function(self, context, *args, **kwargs)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 88, in wrapped
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher payload)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/openstack/common/excutils.py", line 82, in __exit__
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 71, in wrapped
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher return f(self, context, *args, **kw)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 303, in decorated_function
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher pass
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/openstack/common/excutils.py", line 82, in __exit__
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 289, in decorated_function
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher return function(self, context, *args, **kwargs)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 353, in decorated_function
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher return function(self, context, *args, **kwargs)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 331, in decorated_function
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher kwargs['instance'], e, sys.exc_info())
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/openstack/common/excutils.py", line 82, in __exit__
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 319, in decorated_function
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher return function(self, context, *args, **kwargs)
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 3283, in rescue_instance
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher reason=_("Driver Error: %s") % unicode(e))
2015-02-05 15:59:42.672 7281 TRACE oslo.messaging.rpc.dispatcher InstanceNotRescuable: Instance 290ab4b7-7225-4b74-853a-d342974a2080 cannot be rescued: Driver Error: Image a58da6f6-cea3-4b3a-bdd0-30aefcdb37cf could not be found.
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1418590/+subscriptions
More information about the Ubuntu-openstack-bugs
mailing list