yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1418590] Re: No ERROR state if image deleted, _base is lost and instance is rescued

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: AMRITANSHU <amritgeo@xxxxxxxxx>
Date: Mon, 24 Aug 2015 05:54:11 -0000
Reply-to: Bug 1418590 <1418590@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: nova (Ubuntu)
       Status: Incomplete => Invalid

-- 
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:
  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
References

[Bug 1418590] [NEW] No ERROR state if image deleted, _base is lost and instance is rescued
From: George Shuklin, 2015-02-05