Server operations fail to complete with versioned notifications if payload contains unset non-nullable fields

Bug #1739325 reported by Mohammed Naser on 2017-12-20
28
This bug affects 6 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Medium
Matt Riedemann
Ocata
Medium
Matt Riedemann
Pike
Medium
Matt Riedemann
Queens
Medium
Matt Riedemann

Bug Description

With versioned notifications, the instance payload tries to attach a flavor payload which it looks up from the instance. It uses the one which is attached in instance_extras however there seems to be a scenario where the disabled field is missing in the database, causing all operations to fail in the notification stage.

The JSON string for the flavor in the database is attached below (note this is a cloud with a long lifetime so it might be some weird conversion at some point in the life time of the cloud).

The temporary workaround as suggested by Matt was to switch to unversioned notification which did the trick.

== flavor ==
{"new": null, "old": null, "cur": {"nova_object.version": "1.1", "nova_object.changes": ["root_gb", "name", "ephemeral_gb", "memory_mb", "vcpus", "extra_specs", "swap", "rxtx_factor", "flavorid", "vcpu_weight", "id"], "nova_object.name": "Flavor", "nova_object.data": {"root_gb": 80, "name": "nb.2G", "ephemeral_gb": 0, "memory_mb": 2048, "vcpus": 4, "extra_specs": {}, "swap": 0, "rxtx_factor": 1.0, "flavorid": "8c6a8477-20cb-4db9-ad1d-be3bc05cdae9", "vcpu_weight": null, "id": 8}, "nova_object.namespace": "nova"}}
== flavor ==

== stack ==
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server [req-edc9fb83-63ff-4c4b-b6c6-704d331905a8 604d5fd332904975a26b6e89c60a9d51 d6ebcbe536f848b3af4403f922377f80 - default default] Exception during message handling: ValueError: Field `disabled' cannot be None
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 160, in _process_incoming
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 213, in dispatch
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 183, in _do_dispatch
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 76, in wrapped
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server function_name, call_dict, binary)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server self.force_reraise()
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 67, in wrapped
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server return f(self, context, *args, **kw)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 189, in decorated_function
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server "Error: %s", e, instance=instance)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server self.force_reraise()
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 159, in decorated_function
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/compute/utils.py", line 874, in decorated_function
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 217, in decorated_function
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server kwargs['instance'], e, sys.exc_info())
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server self.force_reraise()
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 205, in decorated_function
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 4125, in pause_instance
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server phase=fields.NotificationPhase.START)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/rpc.py", line 225, in wrapped
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/compute/utils.py", line 365, in notify_about_instance_action
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server fault=fault)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/notifications/objects/instance.py", line 138, in __init__
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server super(InstanceActionPayload, self).__init__(instance=instance)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/notifications/objects/instance.py", line 115, in __init__
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server self.flavor = flavor_payload.FlavorPayload(flavor=instance.flavor)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/notifications/objects/flavor.py", line 85, in __init__
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server self.populate_schema(flavor=flavor)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/rpc.py", line 225, in wrapped
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/notifications/objects/base.py", line 130, in populate_schema
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server setattr(self, key, None)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 72, in setter
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server field_value = field.coerce(self, name, value)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/fields.py", line 193, in coerce
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server return self._null(obj, attr)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/fields.py", line 171, in _null
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server raise ValueError(_("Field `%s' cannot be None") % attr)
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server ValueError: Field `disabled' cannot be None
2017-10-23 14:49:21.117 40200 ERROR oslo_messaging.rpc.server
== stack ==

Fix proposed to branch: master
Review: https://review.openstack.org/529194

Changed in nova:
assignee: nobody → Matt Riedemann (mriedem)
status: New → In Progress
Matt Riedemann (mriedem) wrote :

Here is a prettier form of the json:

{
   "new":null,
   "old":null,
   "cur":{
      "nova_object.version":"1.1",
      "nova_object.changes":[
         "root_gb",
         "name",
         "ephemeral_gb",
         "memory_mb",
         "vcpus",
         "extra_specs",
         "swap",
         "rxtx_factor",
         "flavorid",
         "vcpu_weight",
         "id"
      ],
      "nova_object.name":"Flavor",
      "nova_object.data":{
         "root_gb":80,
         "name":"nb.2G",
         "ephemeral_gb":0,
         "memory_mb":2048,
         "vcpus":4,
         "extra_specs":{

         },
         "swap":0,
         "rxtx_factor":1.0,
         "flavorid":"8c6a8477-20cb-4db9-ad1d-be3bc05cdae9",
         "vcpu_weight":null,
         "id":8
      },
      "nova_object.namespace":"nova"
   }
}

tags: added: notifications
Changed in nova:
importance: Undecided → High
summary: - Server operations fail to complete with versioned notifications
+ Server operations fail to complete with versioned notifications if
+ payload contains unset non-nullable fields
Matt Riedemann (mriedem) wrote :

Yeah the workaround is to set this in nova.conf:

[notifications]
notification_format=unversioned

Changed in nova:
assignee: Matt Riedemann (mriedem) → Balazs Gibizer (balazs-gibizer)
Balazs Gibizer (balazs-gibizer) wrote :

@Mohammed Naser: Do you have any data about which OpenStack version was deployed when the Flavor in question was created? Also do you have any data about which OpenStack version was deployed when the Instance in question was created from this Flavor?

Matt Riedemann (mriedem) on 2018-01-23
Changed in nova:
importance: High → Medium
Daniel Speichert (dasp) wrote :

I had the same thing happen in my environment.
The environment was upgraded to Pike all they way back from Juno (one by one, over time).
The flavor was created ~2014 on whatever was stable then.

Balazs Gibizer (balazs-gibizer) wrote :

@Daniel: Thanks for the extra info. I will check the data migrations affecting the flavor data during upgrade.

Change abandoned by Matt Riedemann (<email address hidden>) on branch: master
Review: https://review.openstack.org/529194

Balazs Gibizer (balazs-gibizer) wrote :

This is also visible in tssurya's environment. I'm wondering if we can implement a nova-manage heal-instance-flavor command for these environment as I'm not sure I will be able to find the root cause why the disable field is missing from these flavors.

Changed in nova:
status: In Progress → Confirmed
Matt Riedemann (mriedem) wrote :

Looking at juno-eol code, I came across what I think might result in "ValueError: Field `disabled' cannot be None".

In the long long ago, we stored the flavor information in the instance.system_metadata field:

https://github.com/openstack/nova/blob/juno-eol/nova/compute/flavors.py#L327

Note that system_metadata_flavor_props does not include the "disabled" key, so we wouldn't have stored an instance_type_disabled key in the instance system_metadata.

Eventually we migrated how the embedded flavor in instance system_metadata was stored:

https://review.openstack.org/#/c/135700/56/nova/objects/instance.py@368

But we still pulled it out of the instance system_metadata to do that. Since that wouldn't have instance_type_disabled, we wouldn't store a serialized Flavor object with the disabled field set.

Then when we load up these old instance.flavor values from the serialized Flavor primitive in the instance_extra table, there is no 'disabled' key in the dict and we try to set Flavor.disabled=None which blows up since it's not a nullable field.

Matt Riedemann (mriedem) on 2018-07-03
Changed in nova:
assignee: Balazs Gibizer (balazs-gibizer) → Matt Riedemann (mriedem)
status: Confirmed → Triaged

Fix proposed to branch: master
Review: https://review.openstack.org/579925

Changed in nova:
status: Triaged → In Progress

Reviewed: https://review.openstack.org/579925
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=8df21c1e5fc46f2774a7653e1c9a4c2ac0b5dbfd
Submitter: Zuul
Branch: master

commit 8df21c1e5fc46f2774a7653e1c9a4c2ac0b5dbfd
Author: Matt Riedemann <email address hidden>
Date: Tue Jul 3 13:03:54 2018 -0400

    Default embedded instance.flavor.disabled attribute

    Before we stored flavors in instance_extra, certain fields, defined
    in nova.compute.flavors.system_metadata_flavor_props, were stored
    in the instance.system_metadata for the embedded instance.flavor.
    The "disabled" field wasn't one of those keys, however, so really
    old instances that had their embedded flavor converted to the
    serialized instance_extra form won't have the disabled attribute
    set and we need to default those here so callers, like the
    versioned notfication FlavorPayload, don't explode trying to load
    instance.flavor.disabled.

    Change-Id: I72f8c11b8b2df1416dec8e2d9250eac0693a30e9
    Closes-Bug: #1739325

Changed in nova:
status: In Progress → Fix Released

Reviewed: https://review.openstack.org/580522
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=b2146b02a943c784b6c6fe19ec9e5247bd8e503d
Submitter: Zuul
Branch: stable/queens

commit b2146b02a943c784b6c6fe19ec9e5247bd8e503d
Author: Matt Riedemann <email address hidden>
Date: Tue Jul 3 13:03:54 2018 -0400

    Default embedded instance.flavor.disabled attribute

    Before we stored flavors in instance_extra, certain fields, defined
    in nova.compute.flavors.system_metadata_flavor_props, were stored
    in the instance.system_metadata for the embedded instance.flavor.
    The "disabled" field wasn't one of those keys, however, so really
    old instances that had their embedded flavor converted to the
    serialized instance_extra form won't have the disabled attribute
    set and we need to default those here so callers, like the
    versioned notfication FlavorPayload, don't explode trying to load
    instance.flavor.disabled.

    Change-Id: I72f8c11b8b2df1416dec8e2d9250eac0693a30e9
    Closes-Bug: #1739325
    (cherry picked from commit 8df21c1e5fc46f2774a7653e1c9a4c2ac0b5dbfd)

Reviewed: https://review.openstack.org/580523
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=06387be5907f3b9f05bded85ff3d3bec132fb60b
Submitter: Zuul
Branch: stable/pike

commit 06387be5907f3b9f05bded85ff3d3bec132fb60b
Author: Matt Riedemann <email address hidden>
Date: Tue Jul 3 13:03:54 2018 -0400

    Default embedded instance.flavor.disabled attribute

    Before we stored flavors in instance_extra, certain fields, defined
    in nova.compute.flavors.system_metadata_flavor_props, were stored
    in the instance.system_metadata for the embedded instance.flavor.
    The "disabled" field wasn't one of those keys, however, so really
    old instances that had their embedded flavor converted to the
    serialized instance_extra form won't have the disabled attribute
    set and we need to default those here so callers, like the
    versioned notfication FlavorPayload, don't explode trying to load
    instance.flavor.disabled.

    Change-Id: I72f8c11b8b2df1416dec8e2d9250eac0693a30e9
    Closes-Bug: #1739325
    (cherry picked from commit 8df21c1e5fc46f2774a7653e1c9a4c2ac0b5dbfd)
    (cherry picked from commit b2146b02a943c784b6c6fe19ec9e5247bd8e503d)

This issue was fixed in the openstack/nova 18.0.0.0b3 development milestone.

Mario Sommer (mario-sommer) wrote :

Same for the "is_public" field. This is also missing.

2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server [req-4fc20a5a-56b2-4cd6-aae7-2e31bace60f2 15d72e13a10f46a5a65359f6c4e42b0f 512f554db789466f9a205e95edc24643 - default default] Exception during message handling: ValueError: Field `is_public' cannot be None
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 160, in _process_incoming
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 213, in dispatch
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 183, in _do_dispatch
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 76, in wrapped
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server function_name, call_dict, binary)
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
--
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/rpc.py", line 225, in wrapped
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server return f(*args, **kwargs)
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/nova/notifications/objects/base.py", line 130, in populate_schema
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server setattr(self, key, None)
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 72, in setter
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server field_value = field.coerce(self, name, value)
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/fields.py", line 193, in coerce
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server return self._null(obj, attr)
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/fields.py", line 171, in _null
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server raise ValueError(_("Field `%s' cannot be None") % attr)
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server ValueError: Field `is_public' cannot be None
2018-08-27 15:29:53.715 4725 ERROR oslo_messaging.rpc.server

Matt Riedemann (mriedem) wrote :

Same issue, very old instances wouldn't have the embedded flavor.is_public field stored because of this whitelist:

http://git.openstack.org/cgit/openstack/nova/tree/nova/compute/flavors.py#n52

So we'll need to default is_public=True when reading the embedded instance.flavor and is_public is not set.

Matt Riedemann (mriedem) wrote :

I've reported a new bug for the is_public issue:

https://bugs.launchpad.net/nova/+bug/1789423

Reviewed: https://review.openstack.org/580525
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=d2164c964ae009eb01b5271e41103cce9e92c1b6
Submitter: Zuul
Branch: stable/ocata

commit d2164c964ae009eb01b5271e41103cce9e92c1b6
Author: Matt Riedemann <email address hidden>
Date: Tue Jul 3 13:03:54 2018 -0400

    Default embedded instance.flavor.disabled attribute

    Before we stored flavors in instance_extra, certain fields, defined
    in nova.compute.flavors.system_metadata_flavor_props, were stored
    in the instance.system_metadata for the embedded instance.flavor.
    The "disabled" field wasn't one of those keys, however, so really
    old instances that had their embedded flavor converted to the
    serialized instance_extra form won't have the disabled attribute
    set and we need to default those here so callers, like the
    versioned notfication FlavorPayload, don't explode trying to load
    instance.flavor.disabled.

    Change-Id: I72f8c11b8b2df1416dec8e2d9250eac0693a30e9
    Closes-Bug: #1739325
    (cherry picked from commit 8df21c1e5fc46f2774a7653e1c9a4c2ac0b5dbfd)
    (cherry picked from commit b2146b02a943c784b6c6fe19ec9e5247bd8e503d)
    (cherry picked from commit 06387be5907f3b9f05bded85ff3d3bec132fb60b)

This issue was fixed in the openstack/nova 16.1.5 release.

This issue was fixed in the openstack/nova 17.0.6 release.

This issue was fixed in the openstack/nova 15.1.4 release.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers