[Bug 1864020] Re: libvirt.libvirtError: Requested operation is not valid: format of backing image %s of image %s was not specified in the image metadata (See https://libvirt.org/kbase/backing_chains.html for troubleshooting)

OpenStack Infra 1864020 at bugs.launchpad.net
Fri Mar 27 23:16:54 UTC 2020 

Reviewed:  https://review.opendev.org/710790
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=f5bc2c7ae45d83d90770a3e55bac0ae2465a8775
Submitter: Zuul
Branch:    stable/stein

commit f5bc2c7ae45d83d90770a3e55bac0ae2465a8775
Author: Lee Yarwood <lyarwood at redhat.com>
Date:   Wed Feb 19 20:39:54 2020 +0000

    libvirt: Provide the backing file format when creating qcow2 disks
    
    Libvirt v6.0.0 [1] will now fail to launch a domain when using qcow2
    disks where the backing file format is not recorded in the qcow2
    metadata.
    
    There are some discussions upstream around relaxing this slightly [2]
    but for now any attempt to launch an instance using qcow2 disks will
    fail as Nova does not populate this value when creating the disk.
    
    Nova needs to at a minimum start populating this field and depending on
    the outcome of the thread upstream in Libvirt also potentially handle
    the upgrade case where we may need to rebase existing disks in order to
    update the metadata.
    
    For now this change simply adds the backing_fmt option to the qemu-img
    command line used to create these disks.
    
    [1] https://github.com/libvirt/libvirt/commit/3615e8b39badf2a526996a69dc91a92b04cf262e
    [2] https://www.redhat.com/archives/libvir-list/2020-February/msg00616.html
    
    Partial-Bug: #1864020
    Change-Id: I77ebada015f6522a300be4fa043fb8676458402b
    (cherry picked from commit 0cfe9c81e3fe4d268c9949c6b8e873abab94a407)
    (cherry picked from commit 7fd41e9b8c0f0f9cbccd63fbdbcc863de7db50f5)


** Tags added: in-stable-stein

-- 
You received this bug notification because you are a member of Ubuntu
OpenStack, which is subscribed to nova in Ubuntu.
https://bugs.launchpad.net/bugs/1864020

Title:
  libvirt.libvirtError: Requested operation is not valid: format of
  backing image %s of image %s was not specified in the image metadata
  (See https://libvirt.org/kbase/backing_chains.html for
  troubleshooting)

Status in OpenStack Compute (nova):
  Fix Committed
Status in nova package in Ubuntu:
  Fix Released

Bug description:
  The following was discovered using Fedora 30 and a virt-preview job in
  the below change:

  zuul: Add the fedora-latest-virt-preview job to the experimental queue
  https://review.opendev.org/#/c/704573/

  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [None req-7efa9e8b-3c21-4787-8b47-54cab5fe3756 tempest-AggregatesAdminTestJSON-76056319 tempest-AggregatesAdminTestJSON-76056319] [instance: 543723fb-3afc-460c-9139-809bcacd1840] Instance failed to spawn: libvirt.libvirtError: Requested operation is not valid: format of backing image '/opt/stack/data/nova/instances/_base/8e0569aaf1cbdb522514c3dc9d0fa8fad6f78c50' of image '/opt/stack/data/nova/instances/543723fb-3afc-460c-9139-809bcacd1840/disk' was not specified in the image metadata (See https://libvirt.org/kbase/backing_chains.html for troubleshooting)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840] Traceback (most recent call last):
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/opt/stack/nova/nova/compute/manager.py", line 2604, in _build_resources
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     yield resources
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/opt/stack/nova/nova/compute/manager.py", line 2377, in _build_and_run_instance
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     block_device_info=block_device_info)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 3399, in spawn
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     power_on=power_on)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 6193, in _create_domain_and_network
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     destroy_disks_on_failure)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     self.force_reraise()
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     six.reraise(self.type_, self.value, self.tb)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/six.py", line 703, in reraise
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     raise value
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 6165, in _create_domain_and_network
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     post_xml_callback=post_xml_callback)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 6106, in _create_domain
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     guest.launch(pause=pause)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/opt/stack/nova/nova/virt/libvirt/guest.py", line 142, in launch
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     self._encoded_xml, errors='ignore')
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     self.force_reraise()
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     six.reraise(self.type_, self.value, self.tb)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/six.py", line 703, in reraise
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     raise value
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/opt/stack/nova/nova/virt/libvirt/guest.py", line 137, in launch
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     return self._domain.createWithFlags(flags)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/eventlet/tpool.py", line 190, in doit
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     result = proxy_call(self._autowrap, f, *args, **kwargs)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/eventlet/tpool.py", line 148, in proxy_call
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     rv = execute(f, *args, **kwargs)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/eventlet/tpool.py", line 129, in execute
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     six.reraise(c, e, tb)
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/six.py", line 703, in reraise
  Feb 19 16:45:21.405351 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     raise value
  Feb 19 16:45:21.407911 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib/python3.7/site-packages/eventlet/tpool.py", line 83, in tworker
  Feb 19 16:45:21.407911 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     rv = meth(*args, **kwargs)
  Feb 19 16:45:21.407911 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]   File "/usr/local/lib64/python3.7/site-packages/libvirt.py", line 1265, in createWithFlags
  Feb 19 16:45:21.407911 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
  Feb 19 16:45:21.407911 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840] libvirt.libvirtError: Requested operation is not valid: format of backing image '/opt/stack/data/nova/instances/_base/8e0569aaf1cbdb522514c3dc9d0fa8fad6f78c50' of image '/opt/stack/data/nova/instances/543723fb-3afc-460c-9139-809bcacd1840/disk' was not specified in the image metadata (See https://libvirt.org/kbase/backing_chains.html for troubleshooting)
  Feb 19 16:45:21.407911 fedora-30-rax-ord-0014691277 nova-compute[2019]: ERROR nova.compute.manager [instance: 543723fb-3afc-460c-9139-809bcacd1840] 

  As shown above Libvirt v6.0.0 [1] will now fail to launch a domain
  when using -blockdev if a given qcow2 disk does not have a `backing
  file format` defined in its metadata.

  There are some discussions upstream around relaxing this slightly [2]
  but for now any attempt to launch an instance using qcow2 disks will
  fail as Nova does not populate this value when creating the disk.

  Nova needs to at a minimum start populating this field and depending
  on the outcome of the thread upstream in Libvirt also potentially
  handle the upgrade case where we may need to rebase existing disks in
  order to update the metadata.

  [1] https://github.com/libvirt/libvirt/commit/3615e8b39badf2a526996a69dc91a92b04cf262e
  [2] https://www.redhat.com/archives/libvir-list/2020-February/msg00616.html

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1864020/+subscriptions

More information about the Ubuntu-openstack-bugs mailing list