← Back to team overview

yahoo-eng-team team mailing list archive

  1. yahoo-eng-team team
  2. Mailing list archive
  3. Message #45677

[Bug 1540682] [NEW] InstanceNotFound during instance usage audit

  Thread Previous • Date Previous • • Thread Next 
Public bug reported:

tl;dr set read_deleted to "yes" on the admin context used by the
periodic _instance_usage_audit() so info can be retrieved on deleted
instances.

Explanation:

nova.compute.manager.Manager._instance_usage_audit() has a bug where,
though get_active_by_window_joined() properly returned a list of
instances including deleted ones (because it's implicit that
read_deleted must be set to "yes" for that function to correctly
operate), notify_usage_exists() indirectly uses the more generic
get_flavor() (which cannot assume read_deleted should be "yes" to
properly operate and therefor defaults to "no") to report on each
instance without setting read_deleted to "yes".  this was masked until
commit 1337890a was merged which removed compatibility code that
retrieved the flavor if InstanceNotFound was encountered and the
instance was deleted.

Nova version: git HEAD since commit 1337890a

Log excerpt:

2016-01-14 00:01:51.112 18707 DEBUG nova.objects.instance [req-66e4a380-ed24-4ca1-a971-ee1d80878e2e - - - - -] Lazy-loading `flavor' on Instance uuid 85388355-6f83-4bca-9a11-a0914a2e3a3a obj_load_attr /opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py:843
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [req-66e4a380-ed24-4ca1-a971-ee1d80878e2e - - - - -] [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a] Failed to generate usage audit for instance on host c-10-13-135-245
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a] Traceback (most recent call last):
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 6036, in _instance_usage_audit
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     include_bandwidth=True)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/compute/utils.py", line 297, in notify_usage_exists
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     system_metadata=system_metadata, extra_usage_info=extra_info)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/compute/utils.py", line 317, in notify_about_instance_usage
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     network_info, system_metadata, **extra_usage_info)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/notifications.py", line 386, in info_from_instance
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     instance_type = instance.get_flavor()
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py", line 871, in get_flavor
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     return getattr(self, attr)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 67, in getter
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     self.obj_load_attr(name)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py", line 861, in obj_load_attr
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     self._load_flavor()
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py", line 754, in _load_flavor
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     expected_attrs=['flavor', 'system_metadata'])
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 179, in wrapper
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     result = fn(cls, context, *args, **kwargs)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py", line 373, in get_by_uuid
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     use_slave=use_slave)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/db/api.py", line 676, in instance_get_by_uuid
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     columns_to_join, use_slave=use_slave)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 219, in wrapper
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     return f(*args, **kwargs)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1815, in instance_get_by_uuid
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     columns_to_join=columns_to_join, use_slave=use_slave)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1827, in _instance_get_by_uuid
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     raise exception.InstanceNotFound(instance_id=uuid)
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a] InstanceNotFound: Instance 85388355-6f83-4bca-9a11-a0914a2e3a3a could not be found.
2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]

Reproduction steps:
1. enable instance usage audit
2. create instance
3. delete instance

Explanation:

** Affects: nova
     Importance: Undecided
         Status: New

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

Title:
  InstanceNotFound during instance usage audit

Status in OpenStack Compute (nova):
  New

Bug description:
  tl;dr set read_deleted to "yes" on the admin context used by the
  periodic _instance_usage_audit() so info can be retrieved on deleted
  instances.

  Explanation:

  nova.compute.manager.Manager._instance_usage_audit() has a bug where,
  though get_active_by_window_joined() properly returned a list of
  instances including deleted ones (because it's implicit that
  read_deleted must be set to "yes" for that function to correctly
  operate), notify_usage_exists() indirectly uses the more generic
  get_flavor() (which cannot assume read_deleted should be "yes" to
  properly operate and therefor defaults to "no") to report on each
  instance without setting read_deleted to "yes".  this was masked until
  commit 1337890a was merged which removed compatibility code that
  retrieved the flavor if InstanceNotFound was encountered and the
  instance was deleted.

  Nova version: git HEAD since commit 1337890a

  Log excerpt:

  2016-01-14 00:01:51.112 18707 DEBUG nova.objects.instance [req-66e4a380-ed24-4ca1-a971-ee1d80878e2e - - - - -] Lazy-loading `flavor' on Instance uuid 85388355-6f83-4bca-9a11-a0914a2e3a3a obj_load_attr /opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py:843
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [req-66e4a380-ed24-4ca1-a971-ee1d80878e2e - - - - -] [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a] Failed to generate usage audit for instance on host c-10-13-135-245
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a] Traceback (most recent call last):
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/compute/manager.py", line 6036, in _instance_usage_audit
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     include_bandwidth=True)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/compute/utils.py", line 297, in notify_usage_exists
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     system_metadata=system_metadata, extra_usage_info=extra_info)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/compute/utils.py", line 317, in notify_about_instance_usage
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     network_info, system_metadata, **extra_usage_info)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/notifications.py", line 386, in info_from_instance
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     instance_type = instance.get_flavor()
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py", line 871, in get_flavor
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     return getattr(self, attr)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 67, in getter
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     self.obj_load_attr(name)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py", line 861, in obj_load_attr
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     self._load_flavor()
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py", line 754, in _load_flavor
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     expected_attrs=['flavor', 'system_metadata'])
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 179, in wrapper
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     result = fn(cls, context, *args, **kwargs)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/objects/instance.py", line 373, in get_by_uuid
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     use_slave=use_slave)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/db/api.py", line 676, in instance_get_by_uuid
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     columns_to_join, use_slave=use_slave)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 219, in wrapper
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     return f(*args, **kwargs)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1815, in instance_get_by_uuid
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     columns_to_join=columns_to_join, use_slave=use_slave)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]   File "/opt/rackstack/rackstack.497.5/nova/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 1827, in _instance_get_by_uuid
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]     raise exception.InstanceNotFound(instance_id=uuid)
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a] InstanceNotFound: Instance 85388355-6f83-4bca-9a11-a0914a2e3a3a could not be found.
  2016-01-14 00:01:51.181 18707 ERROR nova.compute.manager [instance: 85388355-6f83-4bca-9a11-a0914a2e3a3a]

  Reproduction steps:
  1. enable instance usage audit
  2. create instance
  3. delete instance

  Explanation:

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

Follow ups

  Thread Previous • Date Previous • • Thread Next