changed fields of versionedobjects not tracked properly when down-versioning object

[Chris Friesen]

Sorry for the complicated write-up below, but the issue is complicated.

I'm running into a problem between Mitaka and Kilo, but I *think* it'll also hit Mitaka/Liberty. The problem scenario is when we have older and newer services talking to each other. The problem occurs when nova-conductor writes to an object field that is removed in obj_make_compatible(). In particular, I'm hitting this with 'parent_addr' in the PciDevice class since it gets written in PciDevice._from_db_object().

In oslo_versionedobjects/base.py the remotable() function has the following line:
 self._changed_fields = set(updates.get('obj_what_changed', []))

This blindly sets the local self._changed_fields to be whatever the remote end sent as updates['obj_what_changed'].

This is a problem because the far end can include fields that don't actually exist in the older object version. On the far end (which may be newer) in nova.conductor.manager.ConductorManager.object_action(), we will call the following (where 'objinst' is the current version of the object):

 updates['obj_what_changed'] = objinst.obj_what_changed()

Since this is called against the newer object code, it can specify fields that do not exist in the older version of the object if nova-conductor has written those fields.

The only workaround I've been able to come up with for this is to modify oslo_versionedobjects.base.remotable() to only include a field in self._changed_fields if it's in self.fields. This requires updating the older code prior to an upgrade, however.

I think there's another related issue. In VersionedObject.obj_to_primitive() we set the changes in the primitive like this:

        if self.obj_what_changed():
            obj[self._obj_primitive_key('changes')] = list(
                self.obj_what_changed())

Since we call self.obj_what_changed() on the newer version of the object, I think we will include changes to fields that were removed by obj_make_compatible_from_manifest().

It seems to me that in obj_to_primitive() we should not allow fields to be included in obj[self._obj_primitive_key('changes')] unless they're also listed in obj[self._obj_primitive_key('data')].

[Chris Friesen (cbf123)]

Where this gets really problematic in the case of PciDevice is that the older compute node preserves 'parent_addr' as a changed field and includes it as such the next time it calls device.save(). On the nova-conductor side in PciDevice.save() we then call updates = self.obj_get_changes(), which does this:

        for key in self.obj_what_changed():
            changes[key] = getattr(self, key)

but in this code 'parent_addr' is listed in self.obj_what_changed(), but the attribute isn't actually set. This results in the following exception:

NotImplementedError: Cannot load 'parent_addr' in the base class

[Chris Friesen (cbf123)]

Is PciDevice misusing the API? or should VersionedObject be able to handle writes by nova-conductor to fields that don't exist in earlier class versions?

[Dan Smith (danms)]

Are you sure you're on the latest liberty before the upgrade? The parent_addr was backported to liberty to fix a problem, and done in a somewhat weird way, which requires that you're on the absolute latest liberty before you upgrade. This is in the release notes...

[Chris Friesen (cbf123)]

Hi Dan...this is actually Kilo (yeah, I know). The trace looks like this on the compute side, when running with a (modified for backwards compatibility) Mitaka nova-conductor.

2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task Traceback (most recent call last):
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "./usr/lib64/python2.7/site-packages/nova/openstack/common/periodic_task.py", line 224, in run_periodic_tasks
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/nova/compute/manager.py", line 4407, in update_available_resource
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task rt.update_available_resource(context)
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "./usr/lib64/python2.7/site-packages/nova/compute/resource_tracker.py", line 569, in update_available_resource
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/oslo_concurrency/lockutils.py", line 445, in inner
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task return f(*args, **kwargs)
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "./usr/lib64/python2.7/site-packages/nova/compute/resource_tracker.py", line 659, in _update_available_resource
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "./usr/lib64/python2.7/site-packages/nova/compute/resource_tracker.py", line 868, in _update
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/nova/pci/manager.py", line 71, in save
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task dev.save()
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/nova/objects/base.py", line 194, in wrapper
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task self._context, self, fn.__name__, args, kwargs)
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/nova/conductor/rpcapi.py", line 349, in object_action
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task objmethod=objmethod, args=args, kwargs=kwargs)
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/oslo_messaging/rpc/client.py", line 156, in call
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task retry=self.retry)
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/oslo_messaging/transport.py", line 90, in _send
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task timeout=timeout, retry=retry)
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task File "/usr/lib64/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 346, in send
2016-08-15 21:57:24.524 107915 TRACE nova.openstack.common.periodic_task ...

[Davanum Srinivas (DIMS) (dims-v)]

This issue was fixed in the openstack/oslo.versionedobjects 1.17.0 release.

[Chris Friesen (cbf123)]

The review for the oslo.versionedobjects change is here: https://review.openstack.org/#/c/355981/

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/oslo.versionedobjects 1.17.0 release.