nova/virt interactions could race leading to double-assigned instance

Bug #1404116 reported by Clint Byrum
16
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Ironic
Invalid
Medium
Unassigned

Bug Description

Here are the logs:

http://logs.openstack.org/19/142819/1/check-tripleo/check-tripleo-ironic-overcloud-f20-nonha/ad60fc3/

It looks like somehow nova tried to associate an instance with two different nodes.

Dec 18 17:21:40 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 ERROR oslo.messaging.rpc.dispatcher [-] Exception during message handling: Instance 00bf12bb-cf65-48e9-8fd3-9c3288d7faa3 is already associated with a node, it cannot be associated with this other node 3187ff3f-5f25-45f4-846c-079822854e41
Dec 18 17:21:40 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 137, in _dispatch_and_reply
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher incoming.message))
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 180, in _dispatch
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 126, in _do_dispatch
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args)
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/oslo/messaging/rpc/server.py", line 139, in inner
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher return func(*args, **kwargs)
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/ironic/conductor/manager.py", line 295, in update_node
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher node_obj.save()
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/ironic/objects/base.py", line 143, in wrapper
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher return fn(self, ctxt, *args, **kwargs)
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/ironic/objects/node.py", line 235, in save
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher self.dbapi.update_node(self.uuid, updates)
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/openstack/lib/python2.7/site-packages/ironic/db/sqlalchemy/api.py", line 335, in update_node
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher node=node_id)
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher InstanceAssociated: Instance 00bf12bb-cf65-48e9-8fd3-9c3288d7faa3 is already associated with a node, it cannot be associated with this other node 3187ff3f-5f25-45f4-846c-079822854e41
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:37.861 4026 TRACE oslo.messaging.rpc.dispatcher
Dec 18 17:21:41 host-192-168-1-240 ironic-conductor[4026]: 2014-12-18 17:21:38.020 4026 ERROR oslo.messaging._drivers.common [-] Returning exception Instance 00bf12bb-cf65-48e9-8fd3-9c3288d7faa3 is already associated with a node, it cannot be associated with this other node 3187ff3f-5f25-45f4-846c-079822854e41 to caller

Revision history for this message
John Stafford (john-stafford) wrote :

Is this still an active bug?

Revision history for this message
Dmitry Tantsur (divius) wrote :

Happened for us today, maybe a case of https://bugs.launchpad.net/ironic/+bug/1341420

Changed in ironic:
status: New → Confirmed
importance: Undecided → Medium
Dmitry Tantsur (divius)
summary: - noav/virt interactions could race leading to double-assigned instance
+ nova/virt interactions could race leading to double-assigned instance
Changed in ironic:
status: Confirmed → Triaged
Revision history for this message
Dmitry Tantsur (divius) wrote :

A lot has been changed in this area, I hope this issue has been fixed.

Changed in ironic:
status: Triaged → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.