ServerShowV254Test.test_rebuild_server fails with OrphanedObjectError in cells v1

[Matt Riedemann]

Seen here:

http://logs.openstack.org/00/549300/33/check/nova-cells-v1/fa9aa6c/logs/screen-n-cell-child.txt.gz?level=TRACE#_May_18_17_09_57_950092

May 18 17:09:57.950092 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging [None req-613da9d7-ea06-4bc6-b709-a70c1f2cc534 tempest-ServerShowV254Test-1265048581 tempest-ServerShowV254Test-1265048581] Error processing message locally: OrphanedObjectError: Cannot call obj_load_attr on orphaned Instance object
May 18 17:09:57.950290 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging Traceback (most recent call last):
May 18 17:09:57.950453 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/cells/messaging.py", line 189, in _process_locally
May 18 17:09:57.950606 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging resp_value = self.msg_runner._process_message_locally(self)
May 18 17:09:57.950759 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/cells/messaging.py", line 1289, in _process_message_locally
May 18 17:09:57.950917 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging return fn(message, **message.method_kwargs)
May 18 17:09:57.951089 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/cells/messaging.py", line 943, in rebuild_instance
May 18 17:09:57.951240 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging files_to_inject, **kwargs)
May 18 17:09:57.951397 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/cells/messaging.py", line 814, in _call_compute_api_with_obj
May 18 17:09:57.951556 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging instance.refresh()
May 18 17:09:57.951713 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 226, in wrapper
May 18 17:09:57.951891 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging return fn(self, *args, **kwargs)
May 18 17:09:57.952050 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/objects/instance.py", line 868, in refresh
May 18 17:09:57.952214 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging elif self[field] != current[field]:
May 18 17:09:57.952371 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 774, in __getitem__
May 18 17:09:57.952527 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging return getattr(self, name)
May 18 17:09:57.952684 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 67, in getter
May 18 17:09:57.952853 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging self.obj_load_attr(name)
May 18 17:09:57.953011 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging File "/opt/stack/new/nova/nova/objects/instance.py", line 1072, in obj_load_attr
May 18 17:09:57.953169 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging objtype=self.obj_name())
May 18 17:09:57.953327 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging OrphanedObjectError: Cannot call obj_load_attr on orphaned Instance object
May 18 17:09:57.953493 ubuntu-xenial-inap-mtl01-0004089915 nova-cells[28513]: ERROR nova.cells.messaging

The test merged in tempest on May 17:

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

There is a patch to fix it here:

https://review.openstack.org/569461

[Matt Riedemann (mriedem)]

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22ServerShowV254Test%5C%22%20AND%20message%3A%5C%22Error%20processing%20message%20locally%3A%20OrphanedObjectError%3A%20Cannot%20call%20obj_load_attr%20on%20orphaned%20Instance%20object%5C%22%20AND%20tags%3A%5C%22screen-n-cell-child.txt%5C%22&from=7d

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/queens
Review: https://review.openstack.org/569576

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/569576
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=419e6198fadf4e91855109b76374d5205164b467
Submitter: Zuul
Branch: stable/queens

commit 419e6198fadf4e91855109b76374d5205164b467
Author: Dan Smith <email address hidden>
Date: Fri May 18 09:28:18 2018 -0700

    Make instance.refresh() avoid recursion better

    The instance.refresh() method is careful to prevent recursion, to avoid
    lazy-loads on the object we just pulled from the database. However, it
    was allowing those to raise OrphanedObjectError to the caller to make
    them visible. The caller is not really at fault in that case, and can not
    avoid it.

    The only time this has ever come up is in the context of cellsv1 and the
    keypairs field that it doesn't have set on instances in the child cells.
    Thus, this changes refresh() to just skip fields that are set on the
    current object and unset on the one we pull from the database, as we
    would not be able to refresh those anyway. This logs the situation so that
    it is visible (at DEBUG) if it becomes relevant.

    Closes-Bug: #1772088

    Change-Id: Ibfca4ae922766b5b977e217594d12e1169ddeee8
    (cherry picked from commit 549e5a2226ccf3920fd49e6726d5cea7fabf2914)

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 17.0.5 release.