yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1487025] [NEW] network-changed external_instance_event fails and traces hard if InstanceInfoCacheNotFound

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem@xxxxxxxxxx>
Date: Thu, 20 Aug 2015 13:09:19 -0000
Reply-to: Bug 1487025 <1487025@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

I saw this in a failed jenkins run with neutron:

http://logs.openstack.org/82/200382/6/check/gate-tempest-dsvm-neutron-
full/cd9bfaa/logs/screen-n-cpu.txt.gz?level=TRACE#_2015-08-20_12_36_06_873

2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     executor_callback))
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     executor_callback)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 129, in _do_dispatch
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     result = func(ctxt, **new_args)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/exception.py", line 89, in wrapped
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     payload)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 119, in __exit__
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/exception.py", line 72, in wrapped
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     return f(self, context, *args, **kw)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 6310, in external_instance_event
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     self.network_api.get_instance_nw_info(context, instance)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/network/base_api.py", line 244, in get_instance_nw_info
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     result = self._get_instance_nw_info(context, instance, **kwargs)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/network/neutronv2/api.py", line 873, in _get_instance_nw_info
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     compute_utils.refresh_info_cache_for_instance(context, instance)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/utils.py", line 356, in refresh_info_cache_for_instance
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     instance.info_cache.refresh()
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 195, in wrapper
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     ctxt, self, fn.__name__, args, kwargs)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/conductor/rpcapi.py", line 248, in object_action
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     objmethod=objmethod, args=args, kwargs=kwargs)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     retry=self.retry)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     timeout=timeout, retry=retry)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 431, in send
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     retry=retry)
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 422, in _send
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     raise result
2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher InstanceInfoCacheNotFound_Remote: Info cache for instance d9b950aa-be7c-40bd-93b4-d4d575ebdace could not be found.

Basically, the instance is deleted before the event is processed:

http://logs.openstack.org/82/200382/6/check/gate-tempest-dsvm-neutron-
full/cd9bfaa/logs/screen-n-cpu.txt.gz#_2015-08-20_12_36_06_097

http://logs.openstack.org/82/200382/6/check/gate-tempest-dsvm-neutron-
full/cd9bfaa/logs/screen-n-cpu.txt.gz#_2015-08-20_12_36_06_795

And things fail.

We should handle 404 type errors in the compute manager's
external_instance_event method so that we don't fail to process all
events when one fails in the loop.

** Affects: nova
     Importance: Medium
     Assignee: Matt Riedemann (mriedem)
         Status: Triaged


** Tags: compute network

** Changed in: nova
   Importance: Undecided => Medium

** Changed in: nova
       Status: New => Triaged

** Changed in: nova
     Assignee: (unassigned) => Matt Riedemann (mriedem)

-- 
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/1487025

Title:
  network-changed external_instance_event fails and traces hard if
  InstanceInfoCacheNotFound

Status in OpenStack Compute (nova):
  Triaged

Bug description:
  I saw this in a failed jenkins run with neutron:

  http://logs.openstack.org/82/200382/6/check/gate-tempest-dsvm-neutron-
  full/cd9bfaa/logs/screen-n-cpu.txt.gz?level=TRACE#_2015-08-20_12_36_06_873

  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher Traceback (most recent call last):
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     executor_callback))
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     executor_callback)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 129, in _do_dispatch
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     result = func(ctxt, **new_args)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/exception.py", line 89, in wrapped
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     payload)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 119, in __exit__
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/exception.py", line 72, in wrapped
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     return f(self, context, *args, **kw)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 6310, in external_instance_event
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     self.network_api.get_instance_nw_info(context, instance)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/network/base_api.py", line 244, in get_instance_nw_info
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     result = self._get_instance_nw_info(context, instance, **kwargs)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/network/neutronv2/api.py", line 873, in _get_instance_nw_info
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     compute_utils.refresh_info_cache_for_instance(context, instance)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/utils.py", line 356, in refresh_info_cache_for_instance
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     instance.info_cache.refresh()
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 195, in wrapper
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     ctxt, self, fn.__name__, args, kwargs)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/conductor/rpcapi.py", line 248, in object_action
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     objmethod=objmethod, args=args, kwargs=kwargs)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     retry=self.retry)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     timeout=timeout, retry=retry)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 431, in send
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     retry=retry)
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 422, in _send
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher     raise result
  2015-08-20 12:36:06.873 9235 ERROR oslo_messaging.rpc.dispatcher InstanceInfoCacheNotFound_Remote: Info cache for instance d9b950aa-be7c-40bd-93b4-d4d575ebdace could not be found.

  Basically, the instance is deleted before the event is processed:

  http://logs.openstack.org/82/200382/6/check/gate-tempest-dsvm-neutron-
  full/cd9bfaa/logs/screen-n-cpu.txt.gz#_2015-08-20_12_36_06_097

  http://logs.openstack.org/82/200382/6/check/gate-tempest-dsvm-neutron-
  full/cd9bfaa/logs/screen-n-cpu.txt.gz#_2015-08-20_12_36_06_795

  And things fail.

  We should handle 404 type errors in the compute manager's
  external_instance_event method so that we don't fail to process all
  events when one fails in the loop.

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1487025/+subscriptions
Follow ups

[Bug 1487025] Re: network-changed external_instance_event fails and traces hard if InstanceInfoCacheNotFound
From: Thierry Carrez, 2015-09-03