Instance Snapshot failure: "Unable to set 'kernel_id' to 'None'. Reason: None is not of type u'string'"

[Ben VanHavermaet]

Description
===========
Attempted to take a snapshot of a suspended server through the CLI, but the command failed. (Nova log stack trace appended below)

Steps to reproduce
==================
1. Created a server instance:
   $ nova boot --image <image> --flavor m1.tiny snapshotvm
2. Suspended the server:
   $ openstack server suspend <instance>
3. Attempt to create server snapshot:
   $ nova image-create snapshotvm snapshotimage --poll

Expected result
===============
Expected to have a snapshot of my instance created in the image list.

Actual result
=============
Received following error output from the image create command:

# nova image-create snapshotvm snapshotimage --poll

Server snapshotting... 25% complete
ERROR (NotFound): Image not found. (HTTP 404) (Request-ID: req-4670eba3-a0d5-4814-b0a8-4aba37a1dd3a)

Environment
===========
1. Running from master level of Openstack

2. Using KVM virtualization on Ubuntu 14.04:
# kvm --version
QEMU emulator version 2.0.0 (Debian 2.0.0+dfsg-2ubuntu1.24), Copyright (c) 2003-2008 Fabrice Bellard

2. Which storage type did you use?
   LVM

3. Which networking type did you use?
   Neutron

2016-06-27 15:04:21.361 10781 INFO nova.compute.manager [req-f393be05-96c2-4d52-bfc1-0c5b644c553e d672d690e856437196a748ebc85abb41 b9b13412e4fd4fd6a6016368b720309e - - -] [instance: ab71489a-0716-404b-808a-165f2a85af74] Successfully reverted task state from image_uploading on failure for instance.
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server [req-f393be05-96c2-4d52-bfc1-0c5b644c553e d672d690e856437196a748ebc85abb41 b9b13412e4fd4fd6a6016368b720309e - - -] Exception during message handling
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 133, in _process_incoming
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server res = self.dispatcher.dispatch(message)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 150, in dispatch
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server return self._do_dispatch(endpoint, method, ctxt, args)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 121, in _do_dispatch
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server result = func(ctxt, **new_args)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/exception.py", line 104, in wrapped
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server payload)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 221, in __exit__
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server self.force_reraise()
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 197, in force_reraise
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/exception.py", line 83, in wrapped
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server return f(self, context, *args, **kw)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/compute/manager.py", line 183, in decorated_function
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server LOG.warning(msg, e, instance=instance)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 221, in __exit__
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server self.force_reraise()
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 197, in force_reraise
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/compute/manager.py", line 152, in decorated_function
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/compute/manager.py", line 211, in decorated_function
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server kwargs['instance'], e, sys.exc_info())
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 221, in __exit__
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server self.force_reraise()
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 197, in force_reraise
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/compute/manager.py", line 199, in decorated_function
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server return function(self, context, *args, **kwargs)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/compute/manager.py", line 259, in decorated_function
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server instance=instance)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 221, in __exit__
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server self.force_reraise()
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/oslo_utils/excutils.py", line 197, in force_reraise
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server six.reraise(self.type_, self.value, self.tb)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/compute/manager.py", line 249, in decorated_function
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server *args, **kwargs)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/compute/manager.py", line 2983, in snapshot_instance
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server task_states.IMAGE_SNAPSHOT)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/compute/manager.py", line 3013, in _snapshot_instance
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server update_task_state)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 1549, in snapshot
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server image_file)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/image/api.py", line 130, in update
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server purge_props=purge_props)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/image/glance.py", line 694, in update
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server _reraise_translated_image_exception(image_id)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/image/glance.py", line 1019, in _reraise_translated_image_exception
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server six.reraise(new_exc, None, exc_trace)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/image/glance.py", line 692, in update
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server image = self._update_v2(context, sent_service_image_meta, data)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/image/glance.py", line 702, in _update_v2
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server context, 2, 'update', **sent_service_image_meta)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/nova/image/glance.py", line 174, in call
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server result = getattr(client.images, method)(*args, **kwargs)
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server File "/opt/bbc/openstack-11.0-master/nova/local/lib/python2.7/site-packages/glanceclient/v2/images.py", line 264, in update
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server raise TypeError(encodeutils.exception_to_unicode(e))
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server TypeError: Unable to set 'kernel_id' to 'None'. Reason: None is not of type u'string'
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server Failed validating u'type' in schema[u'additionalProperties']:
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server {u'type': u'string'}
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server On instance['kernel_id']:
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server None
2016-06-27 15:04:21.364 10781 ERROR oslo_messaging.rpc.server

[Matt Riedemann (mriedem)]

This is the failure:

Unable to set 'kernel_id' to 'None'. Reason: None is not of type u'string'

I think there is a duplicate bug for this, checking.

[Matt Riedemann (mriedem)]

Are you sure this is master of nova? Can you post the commit hash of the nova code you're running?

[Matt Riedemann (mriedem)]

Bug 1592808 is the duplicate I'm thinking of.

[Ben VanHavermaet (bvanhav)]

I checked my code base and https://review.openstack.org/#/c/329981 is included in my Openstack instance. So this is a separate problem from Bug 1592808.

[Matt Riedemann (mriedem)]

Talking with Mike Fedosin on IRC it sounds like this might be a known issue in python-glanceclient.

[Ben VanHavermaet (bvanhav)]

Rerouted to python-glanceclient at request of Mike Fedosin.

[Matt Riedemann (mriedem)]

OK so now I get this, the problem isn't in the image properties, the problem is in the metadata that nova tells glance to use to create the image, which is based in part on the instance's values, e.g.:

mysql> select kernel_id,ramdisk_id from nova.instances where uuid='e4bbbbd3-49be-4a44-9969-088c8f3b36ca';
+-----------+------------+
| kernel_id | ramdisk_id |
+-----------+------------+
| | |
+-----------+------------+
1 row in set (0.00 sec)

[Matt Riedemann (mriedem)]

https://github.com/openstack/nova/blob/47358449d359a287d21426b4e1f18479a4d1fd36/nova/compute/api.py#L867-L868

[Matt Riedemann (mriedem)]

We don't fail in the openstack CI system because for the libvirt driver, devstack uses a cirros image that has kernel_id and ramdisk_id properties set:

https://github.com/openstack-dev/devstack/blob/master/stackrc#L647

[Matt Riedemann (mriedem)]

http://lists.openstack.org/pipermail/openstack-dev/2016-July/099386.html

[Matt Riedemann (mriedem)]

This should be fixed by https://review.openstack.org/#/c/335152/.

[Matt Riedemann (mriedem)]

https://review.openstack.org/#/c/335152/ doesn't fix this.

[Matt Riedemann (mriedem)]

We also talked about this with mfedosin in Nova IRC here:

http://eavesdrop.openstack.org/irclogs/%23openstack-nova/%23openstack-nova.2016-06-28.log.html

[Matt Riedemann (mriedem)]

mfedosin pointed out this change which might be impacting this:

https://review.openstack.org/#/c/229560/

[Nikhil Komawar (nikhil-komawar)]

https://review.openstack.org/#/c/229560/ looks to only not validate schema for the GETs

I think the issue is that we are setting None for kernel and ramdisk prop values and the default schema (that you are using as per paste) expects a string. So, we should change https://review.openstack.org/#/c/329981/4/nova/image/glance.py@850 to '' (null string) rather than a python None.

Thoughts?

[Matt Riedemann (mriedem)]

I'm not able to reproduce this with devstack.

I booted an instance with a full disk image (no kernel_id or ramdisk_id properties set):

stack@list:~/devstack$ nova show e150bbb2-037a-4255-ba34-995aa2fb6709
+--------------------------------------+-----------------------------------------------------------------+
| Property | Value |
+--------------------------------------+-----------------------------------------------------------------+
| OS-DCF:diskConfig | MANUAL |
| OS-EXT-AZ:availability_zone | nova |
| OS-EXT-SRV-ATTR:host | list |
| OS-EXT-SRV-ATTR:hostname | full-disk-img |
| OS-EXT-SRV-ATTR:hypervisor_hostname | list |
| OS-EXT-SRV-ATTR:instance_name | instance-00000001 |
| OS-EXT-SRV-ATTR:kernel_id | |
| OS-EXT-SRV-ATTR:launch_index | 0 |
| OS-EXT-SRV-ATTR:ramdisk_id | |
| OS-EXT-SRV-ATTR:reservation_id | r-royqzdyj |
| OS-EXT-SRV-ATTR:root_device_name | /dev/vda |
| OS-EXT-SRV-ATTR:user_data | - |
| OS-EXT-STS:power_state | 1 |
| OS-EXT-STS:task_state | - |
| OS-EXT-STS:vm_state | active |
| OS-SRV-USG:launched_at | 2016-07-23T15:28:26.000000 |
| OS-SRV-USG:terminated_at | - |
| accessIPv4 | |
| accessIPv6 | |
| config_drive | True |
| created | 2016-07-23T15:28:17Z |
| description | - |
| flavor | m1.tiny (1) |
| hostId | efd1c8cdb0ef1070c1f74cff9704179f6211c7ab7f183b788b8a6a19 |
| host_status | UP ...

[Matt Riedemann (mriedem)]

I also have a devstack patch up to use a full disk image for our default config and see if I can reproduce it in the CI system:

https://review.openstack.org/#/c/346420/

[Matt Riedemann (mriedem)]

Hmm, when we update the snapshot image (and upload the snapshot), why do we specify version 1 when constructing the client?

https://github.com/openstack/nova/blob/3f8076acdc7756b8a5f0f16d4885a47cb001483e/nova/image/glance.py#L406

[Matt Riedemann (mriedem)]

Ignore comment 19, I was looking at the wrong GlanceImageService in nova.image.glance.

[Nikhil Komawar (nikhil-komawar)]

Related bug: https://bugs.launchpad.net/python-glanceclient/+bug/1447193

[Nikhil Komawar (nikhil-komawar)]

Another related bug: https://bugs.launchpad.net/glance/+bug/1447215

[Nikhil Komawar (nikhil-komawar)]

I missed the part where the schema allows type: ["null", "string"]

If that's set, I think it should work and also from the above two bug reports, it should be expected to work the way it is suggested in the latest schema.

[Nikhil Komawar (nikhil-komawar)]

Any updates here?

[Matt Riedemann (mriedem)]

So the problem it looks like is we don't deploy this file:

https://raw.githubusercontent.com/openstack/glance/master/etc/schema-image.json

To /etc/glance/ on our glance-api (controller) nodes. That defines the schema for kernel_id and ramdisk_id (among other things). It's deployed with devstack which is why we don't see issues in the upstream CI:

http://logs.openstack.org/77/335277/1/check/gate-tempest-dsvm-full/de259ec/logs/etc/glance/schema-image.json.txt.gz

The schema we have in our cloud is this:

http://paste.openstack.org/show/542625/

With:

   "additionalProperties":{
      "type":"string"
   },

So if you pass kernel_id and ramdisk_id, they must not be None, but that's what nova sends:

https://github.com/openstack/nova/blob/3f8076acdc7756b8a5f0f16d4885a47cb001483e/nova/image/glance.py#L844

Basically the glance API, or the image schema at least, is completely configurable and nova isn't using the schema from glance to tell what properties it can and can't set in the image body on the request to glance.

So this is a bug in nova now to use the schema from glance.

[Matt Riedemann (mriedem)]

For this specific bug with kernel_id and ramdisk_id, the easiest fix is to just not provide them if they are not set, so continue here:

https://github.com/openstack/nova/blob/master/nova/image/glance.py#L852

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/347971
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=2f2b0e954d7738c2bf49a48a708cc0ce2b19e726
Submitter: Jenkins
Branch: master

commit 2f2b0e954d7738c2bf49a48a708cc0ce2b19e726
Author: Mike Fedosin <email address hidden>
Date: Wed Jul 27 20:34:41 2016 +0300

    Don't set empty kernel_id and ramdisk_id to glance image

    In some cases, if 'allow_additional_properties' option is
    disabled in Glance, 'kernel_id' and 'ramdisk_id' are considered
    the usual properties and cannot have None values. So it's better
    always omit these props and never send them to Glance if they are
    empty.

    Change-Id: I3dd2a3f39d31a79c86bdbe7b656d42c20c560af3
    Closes-bug: #1596602

[OpenStack Infra (hudson-openstack)]

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