object backport doesn't work

[Sam Morrison]

The code to backport an object doesn't work at all. This code is only called in one place.

In nova/objects/base.py in _process_object

If the version is incompatible it tries to backport it:

    def _process_object(self, context, objprim):
        try:
            objinst = NovaObject.obj_from_primitive(objprim, context=context)
        except exception.IncompatibleObjectVersion as e:
            objinst = self.conductor.object_backport(context, objprim,
                                                     e.kwargs['supported'])
        return objinst

You'll note here the object_backport is being passed in a primitive and a supported version and expecting back an object.

However the object_backport method does:

    def object_backport(self, context, objinst, target_version):
        return objinst.obj_to_primitive(target_version=target_version)

You'll see here it is expecting to be passed in an object and will return a primitive. Exactly the opposite of the only code in nova that calls this code.

This is meaning we can't have Icehouse and Havana working together when trying to upgrade.

Any ideas?

[Sam Morrison (sorrison)]

Here's a stacktrace

2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/openstack/common/rpc/amqp.py", line 461, in _process_data
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp **args)
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/openstack/common/rpc/dispatcher.py", line 172, in dispatch
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp result = getattr(proxyobj, method)(ctxt, **kwargs)
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/cells/rpc_driver.py", line 184, in process_message
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp message = self.msg_runner.message_from_json(message)
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/cells/messaging.py", line 1553, in message_from_json
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp message_dict['ctxt'], v)
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/objects/base.py", line 566, in deserialize_entity
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp entity = self._process_object(context, entity)
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/objects/base.py", line 536, in _process_object
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp e.kwargs['supported'])
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/conductor/api.py", line 331, in object_backport
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp return self._manager.object_backport(context, objinst, target_version)
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/utils.py", line 1108, in wrapper
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp return func(*args, **kwargs)
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp File "/opt/nova/nova/conductor/manager.py", line 604, in object_backport
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp return objinst.obj_to_primitive(target_version=target_version)
2014-04-17 11:17:22.932 4434 TRACE nova.openstack.common.rpc.amqp AttributeError: 'dict' object has no attribute 'obj_to_primitive'

[Dan Smith (danms)]

The act of passing the primitive to the conductor call will result in it being hydrated on the other end properly, which means it will be an object instance when that call is made. That is a function of using the NovaObjectSerializer as part of the RPC handler for a service. This is tested upstream on every commit as part of the partial-ncpu job, and I know this works for havana->icehouse live upgrades because I've done quite a bit of that already. However, that testing wasn't being done on cells, although I'm not sure why that would matter.

[Sam Morrison (sorrison)]

OK so does that mean you can't use the use_local flag for conductor in this case? I don't know this code too well so I assumed I was missing something.

I'm still a little confused how this can work in the stable/havana branch

The version of the object_bckport rpcapi call is 1.62
https://github.com/openstack/nova/blob/stable/havana/nova/conductor/rpcapi.py#L500

But the conductor manager only handles up to 1.58
https://github.com/openstack/nova/blob/stable/havana/nova/conductor/manager.py#L77

[Sam Morrison (sorrison)]

OK I have tried this with using the conductor service, I manually changed the rpcapi version of object_backport to 1.58 so it would pass version checking.

In the nova-conductor logs I see it receives about 100+ messages for object_backport then I get the following errors:

2014-04-24 11:22:00.337 5980 ERROR nova.openstack.common.rpc.common [req-d031a456-ed9d-4dfd-82d4-77c50972334a d1fa8867e42444cf8724e65fef1da549 094ae1e2c08f4eddb444a9d9db71ab40] ['Traceback (most recent call last):\n', ' File "/opt/nova/nova/openstack/common/rpc/amqp.py", line 461, in _process_data\n **args)\n', ' File "/opt/nova/nova/openstack/common/rpc/dispatcher.py", line 171, in dispatch\n kwargs = self._deserialize_args(ctxt, kwargs)\n', ' File "/opt/nova/nova/openstack/common/rpc/dispatcher.py", line 126, in _deserialize_args\n arg)\n', ' File "/opt/nova/nova/objects/base.py", line 566, in deserialize_entity\n entity = self._process_object(context, entity)\n', ' File "/opt/nova/nova/objects/base.py", line 536, in _process_object\n e.kwargs[\'supported\'])\n', ' File "/opt/nova/nova/conductor/api.py", line 331, in object_backport\n return self._manager.object_backport(context, objinst, target_version)\n', ' File "/opt/nova/nova/conductor/rpcapi.py", line 502, in object_backport\n target_version=target_version)\n', ' File "/opt/nova/nova/rpcclient.py", line 85, in call\n return self._invoke(self.proxy.call, ctxt, method, **kwargs)\n', ' File "/opt/nova/nova/rpcclient.py", line 63, in _invoke\n return cast_or_call(ctxt, msg, **self.kwargs)\n', ' File "/opt/nova/nova/openstack/common/rpc/proxy.py", line 130, in call\n exc.info, real_topic, msg.get(\'method\'))\n', 'Timeout: Timeout while waiting on RPC response - topic: "conductor", RPC method: "object_backport" info: "<unknown>"\n']
2014-04-24 11:22:00.339 5980 TRACE nova.openstack.common.rpc.amqp return self._invoke(self.proxy.call, ctxt, method, **kwargs)
2014-04-24 11:22:00.339 5980 TRACE nova.openstack.common.rpc.amqp exc.info, real_topic, msg.get('method'))
2014-04-24 11:22:00.339 5980 TRACE nova.openstack.common.rpc.amqp Timeout: Timeout while waiting on RPC response - topic: "conductor", RPC method: "object_backport" info: "<unknown>"
2014-04-24 11:22:00.367 5980 WARNING nova.openstack.common.rpc.amqp [-] No calling threads waiting for msg_id : 854a38503b0941a7822a621c2b7a26aa, message : {u'_unique_id': u'3056c57a64c64f5aa01b04ffbf525d62', u'failure': u'{"args": ["Timeout while waiting on RPC response - topic: \\"conductor\\", RPC method: \\"object_backport\\" info: \\"<unknown>\\""], "module": "nova.openstack.common.rpc.common", "kwargs": {"info": "<unknown>", "topic": "conductor", "method": "object_backport"}, "message": "Timeout while waiting on RPC response - topic: \\"conductor\\", RPC method: \\"object_backport\\" info: \\"<unknown>\\"", "tb": ["Traceback (most recent call last):\\n", " File \\"/opt/nova/nova/openstack/common/rpc/amqp.py\\", line 461, in _process_data\\n **args)\\n", " File \\"/opt/nova/nova/openstack/common/rpc/dispatcher.py\\", line 171, in dispatch\\n kwargs = self._deserialize_args(ctxt, kwargs)\\n", " File \\"/opt/nova/nova/opens...

[Dan Smith (danms)]

I think we determined this was related to a bad backport via mailing list convo. Re-open if not.