yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #27879
[Bug 1418590] Re: No ERROR state if image deleted, _base is lost and instance is rescued
** Description changed:
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.
+ 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.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.
** Also affects: nova (Ubuntu)
Importance: Undecided
Status: New
** Description changed:
+ 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.
--
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1418590
Title:
No ERROR state if image deleted, _base is lost and instance is rescued
Status in OpenStack Compute (Nova):
New
Status in nova package in Ubuntu:
New
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
References