circular reference detected with exception

[Robert Collins]

2014-07-07 02:10:08.727 10283 ERROR oslo.messaging.rpc.dispatcher [req-54c68afe-91a8-4a99-86e8-785c0abf7688 ] Exception during message handling: Circular reference detected
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher incoming.message))
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher payload)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 82, in __exit__
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher return f(self, context, *args, **kw)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/compute/manager.py", line 336, in decorated_function
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher function(self, context, *args, **kwargs)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/compute/utils.py", line 437, in __exit__
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher exc_tb=exc_tb)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/objects/base.py", line 142, in wrapper
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher args, kwargs)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/nova/conductor/rpcapi.py", line 355, in object_class_action
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher objver=objver, args=args, kwargs=kwargs)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/oslo/messaging/rpc/client.py", line 150, in call
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher wait_for_reply=True, timeout=timeout)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/oslo/messaging/transport.py", line 90, in _send
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher timeout=timeout)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 412, in send
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher return self._send(target, ctxt, message, wait_for_reply, timeout)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/oslo/messaging/_drivers/amqpdriver.py", line 385, in _send
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher msg = rpc_common.serialize_msg(msg)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/oslo/messaging/_drivers/common.py", line 462, in serialize_msg
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher _MESSAGE_KEY: jsonutils.dumps(raw_msg)}
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/venvs/nova/local/lib/python2.7/site-packages/oslo/messaging/openstack/common/jsonutils.py", line 164, in dumps
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher return json.dumps(value, default=default, **kwargs)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/json/__init__.py", line 250, in dumps
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher sort_keys=sort_keys, **kw).encode(obj)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/json/encoder.py", line 207, in encode
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher chunks = self.iterencode(o, _one_shot=True)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher File "/usr/lib/python2.7/json/encoder.py", line 270, in iterencode
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher return _iterencode(o, 0)
2014-07-07 02:10:08.727 10283 TRACE oslo.messaging.rpc.dispatcher ValueError: Circular reference detected

[Robert Collins (lifeless)]

I instrumented the error:
value is
'{\'_context_roles\': [u\'_member_\', u\'admin\'],
  \'_msg_id\': \'4dfe58bf8be54f9cb26e669bf626d20c\',
  \'_context_request_id\': u\'req-e559c418-f387-4b2e-b7e2-27d4809e7b4e\',
  \'_context_service_catalog\': [],
 \'args\': {\'objver\': \'1.0\',
                  \'objmethod\': \'event_finish_with_failure\',
                  \'args\': (\'e2019ea2-bd2c-479a-8908-75abbeb4833c\', \'compute_terminate_instance\'),
                 \'objname\': \'InstanceActionEvent\',
                \'kwargs\': {\'exc_val\': NovaException(u"Error destroying the instance on node 9e003bf8-9890-4566-8307-d4a250efd901. Provision state still \'deleting\'.",),
                                       \'exc_tb\': <traceback object at 0x7f24f3ce40e0>}},
   \'_unique_id\': \'91ad34be58b74b4cb161d5961a706163\',
   \'_context_user\': u\'d2caebd29b6f448e8fac0abd24b25810\',
   \'_context_user_id\': u\'d2caebd29b6f448e8fac0abd24b25810\',
  \'_context_project_name\': u\'admin\',
  \'_context_read_deleted\': u\'no\',
   \'_reply_q\': \'reply_d89d8e5285fc4d1f8d5ae5a5a7b5fe22\',
  \'_context_auth_token\': u\'MIIP........nrq\',
  \'_context_tenant\': u\'1767f7b0fe0d4ca39f4f9caaf884b630\',
  \'_context_instance_lock_checked\': False,
   \'_context_is_admin\': True,
  \'version\': \'2.0\',
   \'_context_project_id\': u\'1767f7b0fe0d4ca39f4f9caaf884b630\',
   \'_context_timestamp\': \'2014-07-07T05:41:50.904570\',
  \'_context_user_name\': u\'admin\',
  \'method\': \'object_class_action\',
   \'_context_remote_address\': u\'192.168.122.1\'}'

Its not obvious to me where the circular reference is - but I strongly suspect its in the exc_tb.

[Robert Collins (lifeless)]

Added Ironic as it may be an Ironic driver bug.

[Andrea Frittoli (andrea-frittoli)]

I'm got this once in devstack, using a version of nova from early June - it could be related as it failed to destroy an instance:

2014-07-08 23:03:09.743 16994 ERROR nova.virt.libvirt.driver [-] [instance: 556caeed-b676-440a-b56b-a16e51ad3768] During wait destroy, instance disappeared.
2014-07-08 23:03:10.133 ERROR oslo.messaging.rpc.dispatcher [req-469b8c35-3c3b-43e4-beac-aa51acff7598 None None] Exception during message handling: Circular reference detected
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 133, in _dispatch_and_reply
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher incoming.message))
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 176, in _dispatch
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher return self._do_dispatch(endpoint, method, ctxt, args)
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 122, in _do_dispatch
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher result = getattr(endpoint, method)(ctxt, **new_args)
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/exception.py", line 88, in wrapped
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher payload)
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/exception.py", line 71, in wrapped
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher return f(self, context, *args, **kw)
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/compute/manager.py", line 285, in decorated_function
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher pass
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher six.reraise(self.type_, self.value, self.tb)
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/compute/manager.py", line 271, in decorated_function
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher return function(self, context, *args, **kwargs)
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher File "/opt/stack/new/nova/nova/compute/manager.py", line 335, in decorated_function
2014-07-08 23:03:10.133 16994 TRACE oslo.messaging.rpc.dispatcher function(self, context, *args, **kwargs)
2014-07-08 23:03:10.133 16...

[Dmitry Tantsur (divius)]

Ironic driver now leaves in Nova tree, so we can't fix this bug on Ironic side.

[Grzegorz Grasza (xek)]

This is a duplicate of #1317804