Seen in the CI gate where ServerActionsV293TestJSON: test_rebuild_volume_backed_server rebuild fails due to "ValueError: Circular reference detected".
While rebuilding a volume-backed instance, if there is a timeout while waiting for the external event from Cinder [1], the exception handling eventually leads to a "ValueError: Circular reference detected". It appears to happen while in the @wrap_instance_event decorator when objects.InstanceActionEvent.event_finish_with_failure result is being serialized for RPC.
[1] https://github.com/openstack/nova/blob/55a27f0ac4badee439b03c8c52ae217767aa88fc/nova/compute/manager.py#L3633
Full traceback:
Dec 19 02:48:08.261374 np0036191650 nova-compute[85399]: INFO nova.compute.manager [None req-5ca3de1f-3ad5-4075-8cee-d060978d3797 tempest-ServerActionsV293TestJSON-1486319881 tempest-ServerActionsV293TestJSON-1486319881-project-member] [instance: f6a12b05-3e12-430e-b60a-eea2d8015815] Successfully reverted task state from rebuilding on failure for instance.
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server [None req-5ca3de1f-3ad5-4075-8cee-d060978d3797 tempest-ServerActionsV293TestJSON-1486319881 tempest-ServerActionsV293TestJSON-1486319881-project-member] Exception during message handling: ValueError: Circular reference detected
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server Traceback (most recent call last):
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/utils.py", line 1439, in decorated_function
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 203, in decorated_function
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 3858, in rebuild_instance
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server self._do_rebuild_instance_with_claim(
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 3944, in _do_rebuild_instance_with_claim
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server self._do_rebuild_instance(
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 4136, in _do_rebuild_instance
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server self._rebuild_default_impl(**kwargs)
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 3713, in _rebuild_default_impl
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server self._rebuild_volume_backed_instance(
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 3633, in _rebuild_volume_backed_instance
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server with self.virtapi.wait_for_instance_event(instance, events,
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/usr/lib/python3.10/contextlib.py", line 142, in __exit__
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server next(self.gen)
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 559, in wait_for_instance_event
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server self._wait_for_instance_events(
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 471, in _wait_for_instance_events
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server actual_event = event.wait()
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 436, in wait
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server instance_event = self.event.wait()
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/eventlet/event.py", line 125, in wait
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server result = hub.switch()
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/eventlet/hubs/hub.py", line 313, in switch
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return self.greenlet.switch()
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server eventlet.timeout.Timeout: 60 seconds
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server During handling of the above exception, another exception occurred:
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server Traceback (most recent call last):
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/server.py", line 165, in _process_incoming
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/dispatcher.py", line 309, in dispatch
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/dispatcher.py", line 229, in _do_dispatch
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/server.py", line 244, in inner
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return func(*args, **kwargs)
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/exception_wrapper.py", line 65, in wrapped
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server with excutils.save_and_reraise_exception():
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server self.force_reraise()
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server raise self.value
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/exception_wrapper.py", line 63, in wrapped
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return f(self, context, *args, **kw)
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 166, in decorated_function
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server with excutils.save_and_reraise_exception():
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 227, in __exit__
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server self.force_reraise()
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_utils/excutils.py", line 200, in force_reraise
Dec 19 02:48:08.335604 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server raise self.value
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/manager.py", line 157, in decorated_function
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/utils.py", line 1437, in decorated_function
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server with EventReporter(context, event_name, host, instance_uuid,
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/compute/utils.py", line 1400, in __exit__
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server objects.InstanceActionEvent.event_finish_with_failure(
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/objects/base.py", line 393, in wrapper
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return fn.__get__(None, obj)(*args, **kwargs)
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_versionedobjects/base.py", line 175, in wrapper
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server result = cls.indirection_api.object_class_action_versions(
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/nova/nova/conductor/rpcapi.py", line 240, in object_class_action_versions
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return cctxt.call(context, 'object_class_action_versions',
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/rpc/client.py", line 190, in call
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server result = self.transport._send(
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/transport.py", line 123, in _send
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return self._driver.send(target, ctxt, message,
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 689, in send
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return self._send(target, ctxt, message, wait_for_reply, timeout,
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 644, in _send
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server msg = rpc_common.serialize_msg(msg)
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/common.py", line 292, in serialize_msg
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server _MESSAGE_KEY: jsonutils.dumps(raw_msg)}
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/opt/stack/data/venv/lib/python3.10/site-packages/oslo_serialization/jsonutils.py", line 202, in dumps
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return json.dumps(obj, default=default, **kwargs)
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/usr/lib/python3.10/json/__init__.py", line 238, in dumps
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server **kw).encode(obj)
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/usr/lib/python3.10/json/encoder.py", line 199, in encode
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server chunks = self.iterencode(o, _one_shot=True)
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server File "/usr/lib/python3.10/json/encoder.py", line 257, in iterencode
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server return _iterencode(o, 0)
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server ValueError: Circular reference detected
Dec 19 02:48:08.344870 np0036191650 nova-compute[85399]: ERROR oslo_messaging.rpc.server
We are also hitting this bug presently