Public bug reported:
http://logs.openstack.org/21/183321/1/gate/gate-tempest-dsvm-
full/a263953/logs/screen-n-cond.txt.gz?level=TRACE#_2015-05-15_15_06_44_176
2015-05-15 15:06:44.176 ERROR nova.notifications
[req-47aa9044-90c9-4bdd-b32c-b0b52f8c18eb ServersTestJSON-285875926
ServersTestJSON-1664086552] [instance: 1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad]
Failed to send state update notification
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] Traceback (most recent call last):
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/notifications.py", line 151, in send_update
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] old_display_name=old_display_name)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/notifications.py", line 231, in
_send_instance_update_notification
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] payload = info_from_instance(context,
instance, None, None)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/notifications.py", line 374, in info_from_instance
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] instance_type = instance.get_flavor()
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/instance.py", line 1025, in get_flavor
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] return getattr(self, attr)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/base.py", line 72, in getter
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] self.obj_load_attr(name)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/instance.py", line 1015, in obj_load_attr
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] self._load_flavor()
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/instance.py", line 941, in _load_flavor
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] expected_attrs=['flavor',
'system_metadata'])
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/base.py", line 163, in wrapper
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] result = fn(cls, context, *args,
**kwargs)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/instance.py", line 577, in get_by_uuid
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] use_slave=use_slave)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/db/api.py", line 651, in instance_get_by_uuid
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] columns_to_join, use_slave=use_slave)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 233, in wrapper
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] return f(*args, **kwargs)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1744, in
instance_get_by_uuid
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] columns_to_join=columns_to_join,
use_slave=use_slave)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1756, in
_instance_get_by_uuid
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] raise
exception.InstanceNotFound(instance_id=uuid)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] InstanceNotFound: Instance
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad could not be found.
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad]
This is a case where the instance goes to ERROR state because of a
NoValidHost and then tempest deletes the instance as soon as it hits
that state (it's polling every second).
We shouldn't trace in the conductor logs (those should be relatively
clean unless there are major issues) on expected exceptions, like
InstanceNotFound b/c some tooling deleted the instance once it failed.
** Affects: nova
Importance: Low
Assignee: Matt Riedemann (mriedem)
Status: Triaged
** Changed in: nova
Status: New => Triaged
** Changed in: nova
Importance: Undecided => Low
** 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/1455640
Title:
notifications._send_instance_update_notification should handle
InstanceNotFound
Status in OpenStack Compute (Nova):
Triaged
Bug description:
http://logs.openstack.org/21/183321/1/gate/gate-tempest-dsvm-
full/a263953/logs/screen-n-cond.txt.gz?level=TRACE#_2015-05-15_15_06_44_176
2015-05-15 15:06:44.176 ERROR nova.notifications
[req-47aa9044-90c9-4bdd-b32c-b0b52f8c18eb ServersTestJSON-285875926
ServersTestJSON-1664086552] [instance: 1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad]
Failed to send state update notification
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] Traceback (most recent call last):
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/notifications.py", line 151, in send_update
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] old_display_name=old_display_name)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/notifications.py", line 231, in
_send_instance_update_notification
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] payload = info_from_instance(context,
instance, None, None)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/notifications.py", line 374, in info_from_instance
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] instance_type = instance.get_flavor()
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/instance.py", line 1025, in get_flavor
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] return getattr(self, attr)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/base.py", line 72, in getter
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] self.obj_load_attr(name)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/instance.py", line 1015, in obj_load_attr
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] self._load_flavor()
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/instance.py", line 941, in _load_flavor
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] expected_attrs=['flavor',
'system_metadata'])
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/base.py", line 163, in wrapper
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] result = fn(cls, context, *args,
**kwargs)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/objects/instance.py", line 577, in get_by_uuid
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] use_slave=use_slave)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/db/api.py", line 651, in instance_get_by_uuid
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] columns_to_join, use_slave=use_slave)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 233, in wrapper
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] return f(*args, **kwargs)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1744, in
instance_get_by_uuid
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] columns_to_join=columns_to_join,
use_slave=use_slave)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] File
"/opt/stack/new/nova/nova/db/sqlalchemy/api.py", line 1756, in
_instance_get_by_uuid
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] raise
exception.InstanceNotFound(instance_id=uuid)
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad] InstanceNotFound: Instance
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad could not be found.
2015-05-15 15:06:44.176 899 TRACE nova.notifications [instance:
1ea21d0c-5b5a-4417-bca0-4aaeabfb19ad]
This is a case where the instance goes to ERROR state because of a
NoValidHost and then tempest deletes the instance as soon as it hits
that state (it's polling every second).
We shouldn't trace in the conductor logs (those should be relatively
clean unless there are major issues) on expected exceptions, like
InstanceNotFound b/c some tooling deleted the instance once it failed.
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1455640/+subscriptions
--
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to : yahoo-eng-team@lists.launchpad.net
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help : https://help.launchpad.net/ListHelp
