yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1580987] Re: "Cannot call obj_load_attr on orphaned Instance object" in baremetal_basic_ops

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: OpenStack Infra <1580987@xxxxxxxxxxxxxxxxxx>
Date: Thu, 12 May 2016 20:45:45 -0000
Reply-to: Bug 1580987 <1580987@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Reviewed:  https://review.openstack.org/315495
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=fa3453fcc1bc7061f9e39d872bdda6a6944ccaad
Submitter: Jenkins
Branch:    master

commit fa3453fcc1bc7061f9e39d872bdda6a6944ccaad
Author: Jim Rollenhagen <jim@xxxxxxxxxxxxxxxxxx>
Date:   Thu May 12 07:32:27 2016 -0400

    Eager load keypairs in instance metadata
    
    In the review for e83842b80b73c451f78a4bb9e7bd5dfcebdefcab it was
    pointed out that keypairs should be added to the eager load list for
    get_metadata_for_instance_id. Due to a lack of a proper context in a
    thread in the ironic driver, this actually totally broke ironic.
    The context problem is being fixed elsewhere, but this should be
    eager-loaded to minimize DB queries anyway.
    
    Change-Id: I67b4665bdebd45c66983c6a556d20f367fa7fbdf
    Closes-Bug: #1580987


** Changed in: nova
       Status: In Progress => Fix Released

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

Title:
  "Cannot call obj_load_attr on orphaned Instance object" in
  baremetal_basic_ops

Status in OpenStack Compute (nova):
  Fix Released

Bug description:
  Recent ironic job runs (like https://review.openstack.org/#/c/314917/)
  fail with the following traceback:

  2016-05-12 10:19:51.730 | ironic_tempest_plugin.tests.scenario.test_baremetal_basic_ops.BaremetalBasicOps.test_baremetal_server_ops[baremetal,compute,id-549173a5-38ec-42bb-b0e2-c8b9f4a08943,image,network]
  2016-05-12 10:19:51.731 | ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
  2016-05-12 10:19:51.731 | 
  2016-05-12 10:19:51.731 | Captured traceback:
  2016-05-12 10:19:51.731 | ~~~~~~~~~~~~~~~~~~~
  2016-05-12 10:19:51.731 |     Traceback (most recent call last):
  2016-05-12 10:19:51.731 |       File "tempest/test.py", line 113, in wrapper
  2016-05-12 10:19:51.731 |         return f(self, *func_args, **func_kwargs)
  2016-05-12 10:19:51.731 |       File "/opt/stack/new/ironic/ironic_tempest_plugin/tests/scenario/test_baremetal_basic_ops.py", line 113, in test_baremetal_server_ops
  2016-05-12 10:19:51.732 |         self.boot_instance()
  2016-05-12 10:19:51.732 |       File "/opt/stack/new/ironic/ironic_tempest_plugin/tests/scenario/baremetal_manager.py", line 164, in boot_instance
  2016-05-12 10:19:51.732 |         interval=30)
  2016-05-12 10:19:51.732 |       File "/opt/stack/new/ironic/ironic_tempest_plugin/tests/scenario/baremetal_manager.py", line 94, in wait_provisioning_state
  2016-05-12 10:19:51.732 |         target_states=state, timeout=timeout, interval=interval)
  2016-05-12 10:19:51.732 |       File "/opt/stack/new/ironic/ironic_tempest_plugin/tests/scenario/baremetal_manager.py", line 89, in _node_state_timeout
  2016-05-12 10:19:51.733 |         raise lib_exc.TimeoutException(msg)
  2016-05-12 10:19:51.733 |     tempest.lib.exceptions.TimeoutException: Request timed out
  2016-05-12 10:19:51.733 |     Details: Timed out waiting for node 92f193e8-9955-4335-b4cf-f24804bf5d07 to reach provision_state state(s) ['active']

  in n-cpu there is the following:

  2016-05-04 21:44:02.548 25779 ERROR nova.virt.ironic.driver [req-d8ace69f-f1f2-4901-bb4d-8975bc660cf2 tempest-BaremetalBasicOps-1503755723 tempest-BaremetalBasicOps-529747769] Error deploying instance 96a56107-9e09-42a2-a287-66e0305aeed4 on baremetal node 0c8fd6b5-0a02-44f3-a637-0b3e1e174732.
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [req-d8ace69f-f1f2-4901-bb4d-8975bc660cf2 tempest-BaremetalBasicOps-1503755723 tempest-BaremetalBasicOps-529747769] [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] Instance failed to spawn
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] Traceback (most recent call last):
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/opt/stack/new/nova/nova/compute/manager.py", line 2041, in _build_resources
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     yield resources
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/opt/stack/new/nova/nova/compute/manager.py", line 1887, in _build_and_run_instance
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     block_device_info=block_device_info)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/opt/stack/new/nova/nova/virt/ironic/driver.py", line 781, in spawn
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     'node': node_uuid})
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 220, in __exit__
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     self.force_reraise()
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 196, in force_reraise
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     six.reraise(self.type_, self.value, self.tb)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/opt/stack/new/nova/nova/virt/ironic/driver.py", line 773, in spawn
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     timer.start(interval=CONF.ironic.api_retry_interval).wait()
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/eventlet/event.py", line 121, in wait
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     return hubs.get_hub().switch()
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 294, in switch
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     return self.greenlet.switch()
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_service/loopingcall.py", line 136, in _run_loop
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     result = func(*self.args, **self.kw)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/opt/stack/new/nova/nova/virt/ironic/driver.py", line 382, in _wait_for_active
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     instance.refresh()
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 207, in wrapper
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     ctxt, self, fn.__name__, args, kwargs)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/opt/stack/new/nova/nova/conductor/rpcapi.py", line 241, in object_action
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     objmethod=objmethod, args=args, kwargs=kwargs)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     retry=self.retry)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     timeout=timeout, retry=retry)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 470, in send
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     retry=retry)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 461, in _send
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     raise result
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] OrphanedObjectError_Remote: Cannot call obj_load_attr on orphaned Instance object
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] Traceback (most recent call last):
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] 
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/opt/stack/new/nova/nova/conductor/manager.py", line 85, in _object_dispatch
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     return getattr(target, method)(*args, **kwargs)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] 
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 223, in wrapper
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     return fn(self, *args, **kwargs)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] 
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/opt/stack/new/nova/nova/objects/instance.py", line 760, in refresh
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     elif self[field] != current[field]:
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] 
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 724, in __getitem__
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     return getattr(self, name)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] 
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/usr/local/lib/python2.7/dist-packages/oslo_versionedobjects/base.py", line 67, in getter
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     self.obj_load_attr(name)
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] 
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]   File "/opt/stack/new/nova/nova/objects/instance.py", line 932, in obj_load_attr
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]     objtype=self.obj_name())
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] 
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] OrphanedObjectError: Cannot call obj_load_attr on orphaned Instance object
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4] 
  2016-05-04 21:44:02.549 25779 ERROR nova.compute.manager [instance: 96a56107-9e09-42a2-a287-66e0305aeed4]

  Seems to be happening after https://review.openstack.org/#/c/312750/
  was merged.

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

[Bug 1580987] [NEW] "Cannot call obj_load_attr on orphaned Instance object" in baremetal_basic_ops
From: Vladyslav Drok, 2016-05-12