InstanceNotFound traceback errors in n-api logs while polling for server delete

[Matt Riedemann]

As a result of this change:

https://review.openstack.org/#/c/591658/

The nova-api logs now traceback InstanceNotFound errors when polling a server to be deleted, which is an expected situation and we shouldn't be logging errors in the API logs for that:

http://logs.openstack.org/58/591658/22/check/tempest-full/04cf08b/controller/logs/screen-n-api.txt.gz?level=ERROR

Nov 05 11:46:49.066760 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context [None req-8b6e5657-8ac9-4c33-9337-87c58b32fc7a tempest-DeleteServersAdminTestJSON-984972888 tempest-DeleteServersAdminTestJSON-984972888] Error gathering result from cell f40f1143-3d61-4e69-8377-a35e2fd47356: InstanceNotFound: Instance 45cbaca4-7e53-45df-99da-13674d0a241f could not be found.
Nov 05 11:46:49.067002 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context Traceback (most recent call last):
Nov 05 11:46:49.067223 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/opt/stack/nova/nova/context.py", line 441, in gather_result
Nov 05 11:46:49.067463 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context result = fn(cctxt, *args, **kwargs)
Nov 05 11:46:49.067708 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 184, in wrapper
Nov 05 11:46:49.067932 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context result = fn(cls, context, *args, **kwargs)
Nov 05 11:46:49.068173 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/opt/stack/nova/nova/objects/instance.py", line 503, in get_by_uuid
Nov 05 11:46:49.068408 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context use_slave=use_slave)
Nov 05 11:46:49.068639 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 212, in wrapper
Nov 05 11:46:49.068954 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context return f(*args, **kwargs)
Nov 05 11:46:49.069175 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/opt/stack/nova/nova/objects/instance.py", line 495, in _db_instance_get_by_uuid
Nov 05 11:46:49.069399 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context columns_to_join=columns_to_join)
Nov 05 11:46:49.069814 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/opt/stack/nova/nova/db/api.py", line 758, in instance_get_by_uuid
Nov 05 11:46:49.070036 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context return IMPL.instance_get_by_uuid(context, uuid, columns_to_join)
Nov 05 11:46:49.070262 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 170, in wrapper
Nov 05 11:46:49.070523 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context return f(*args, **kwargs)
Nov 05 11:46:49.070766 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 257, in wrapped
Nov 05 11:46:49.071002 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context return f(context, *args, **kwargs)
Nov 05 11:46:49.071221 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 1845, in instance_get_by_uuid
Nov 05 11:46:49.071517 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context columns_to_join=columns_to_join)
Nov 05 11:46:49.071756 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context File "/opt/stack/nova/nova/db/sqlalchemy/api.py", line 1854, in _instance_get_by_uuid
Nov 05 11:46:49.071990 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context raise exception.InstanceNotFound(instance_id=uuid)
Nov 05 11:46:49.072222 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context InstanceNotFound: Instance 45cbaca4-7e53-45df-99da-13674d0a241f could not be found.
Nov 05 11:46:49.072481 ubuntu-xenial-rax-dfw-0000329307 <email address hidden>[5952]: ERROR nova.context

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/619110

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/619110
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=939a61d1c6054f24b6d47b5a6f1fa90fadc0c690
Submitter: Zuul
Branch: master

commit 939a61d1c6054f24b6d47b5a6f1fa90fadc0c690
Author: Matt Riedemann <email address hidden>
Date: Tue Nov 20 17:30:36 2018 -0500

    Remove NovaException logging from scatter_gather_cells

    With change I861b223ee46b0f0a31f646a4b45f8a02410253cf
    the caller of the various scatter_gatter functions can
    get any exception result and decide what kind of logging
    is necessary, so this change removes the logging from
    the scatter_gather_cells method **for NovaExceptions**.
    This is needed because of change
    Iaea1cb4ed93bb98f451de4f993106d7891ca3682 where
    showing a server which is deleted, which results in an
    InstanceNotFound exception, gets logged as an exception
    in the nova-api logs and shouldn't be.

    Non-NovaExceptions will still get logged as before since
    those are likely due to unexpected errors, like DBErrors.

    Change-Id: I930ee897c46385c3c9719b393753c4484caf909f
    Closes-Bug: #1804325

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 19.0.0.0rc1 release candidate.