TypeError booting instance with libvirt+xen in _create_pty_device with libvirt>=1.3.3

[Matt Riedemann]

Someone reported this in the nova IRC channel today using ocata with libvirt+xen:

http://paste.openstack.org/raw/601670/

2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [req-937dedd1-35a1-46e4-8516-fc53c99a8f48 - - - - -] [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] Instance failed to spawn
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] Traceback (most recent call last):
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 2125, in _build_resources
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] yield resources
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1930, in _build_and_run_instance
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] block_device_info=block_device_info)
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 2683, in spawn
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] block_device_info=block_device_info)
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 4871, in _get_guest_xml
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] xml = conf.to_xml()
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/config.py", line 77, in to_xml
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] root = self.format_dom()
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/config.py", line 2161, in format_dom
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] self._format_devices(root)
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/config.py", line 2119, in _format_devices
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] devices.append(dev.format_dom())
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/config.py", line 1636, in format_dom
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] dev = super(LibvirtConfigGuestChar, self).format_dom()
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/config.py", line 1622, in format_dom
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] dev.append(self.log.format_dom())
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/config.py", line 1665, in format_dom
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] log.set("file", self.file)
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "src/lxml/lxml.etree.pyx", line 824, in lxml.etree._Element.set (src/lxml/lxml.etree.c:53073)
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "src/lxml/apihelpers.pxi", line 570, in lxml.etree._setAttributeValue (src/lxml/lxml.etree.c:23009)
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] File "src/lxml/apihelpers.pxi", line 1437, in lxml.etree._utf8 (src/lxml/lxml.etree.c:32414)
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c] TypeError: Argument must be bytes or unicode, got 'NoneType'
2017-03-06 17:09:47.609 8530 ERROR nova.compute.manager [instance: a2ac1972-54c4-4a7b-ab34-04cce319806c]

The problem is when adding guest consoles to the domain xml during spawn, for libvirt+xen we go here:

https://github.com/openstack/nova/blob/15.0.0/nova/virt/libvirt/driver.py#L4435

And log_path=None in _create_pty_device:

https://github.com/openstack/nova/blob/15.0.0/nova/virt/libvirt/driver.py#L4478

CONF.serial_console.enabled is False and they have new enough libvirt/qemu for virtlogd support so they get here:

https://github.com/openstack/nova/blob/15.0.0/nova/virt/libvirt/driver.py#L4510

So we set log.file to None here:

https://github.com/openstack/nova/blob/15.0.0/nova/virt/libvirt/driver.py#L4489

Which blows up eventually because it's None.

The workaround for now is to set [serial_console]enabled=True in nova.conf.

[Matt Riedemann (mriedem)]

By the way we didn't catch this in xenproject CI because it's running an older libvirt (1.3.1):

http://logs.openstack.xenproject.org/10/396210/5/check/dsvm-tempest-xen/d4ed0ef/logs/dpkg-l.txt.gz

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/ocata
Review: https://review.openstack.org/442550

[OpenStack Infra (hudson-openstack)]

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

commit ac61abb7c74f1a8e3e9134bc045455fd9fdac0fa
Author: Matt Riedemann <email address hidden>
Date: Mon Mar 6 19:00:31 2017 -0500

    libvirt: pass log_path to _create_pty_device for non-kvm/qemu

    log_path is required in _create_pty_device if:

    1. serial consoles are disabled
    2. libvirt/qemu are new enough that they support virtlogd

    This was working fine for kvm and qemu since _create_consoles_s390x
    and _create_consoles_qemu_kvm pass in the log_path, but for the
    non-kvm/qemu cases, like xen, the log_path wasn't provided.

    This wasn't caught by the XenProject CI since it's using libvirt
    1.3.1 which does not have virtlogd support so this path was
    not exercised and apparently not unit tested either.

    A release note is provided since this is a pretty severe bug if
    you're running new enough libvirt/qemu and not using kvm/qemu as
    the virt type because CONF.serial_console.enabled is False by
    default so you're going to have failed server creates immediately
    upon upgrading to Ocata.

    Change-Id: I7f60db1d243a75b90e3c0e53201cb6000ee95778
    Closes-Bug: #1670522

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/442550
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=30e604f57faa8321679881bdf6113f9389e80271
Submitter: Jenkins
Branch: stable/ocata

commit 30e604f57faa8321679881bdf6113f9389e80271
Author: Matt Riedemann <email address hidden>
Date: Mon Mar 6 19:00:31 2017 -0500

    libvirt: pass log_path to _create_pty_device for non-kvm/qemu

    log_path is required in _create_pty_device if:

    1. serial consoles are disabled
    2. libvirt/qemu are new enough that they support virtlogd

    This was working fine for kvm and qemu since _create_consoles_s390x
    and _create_consoles_qemu_kvm pass in the log_path, but for the
    non-kvm/qemu cases, like xen, the log_path wasn't provided.

    This wasn't caught by the XenProject CI since it's using libvirt
    1.3.1 which does not have virtlogd support so this path was
    not exercised and apparently not unit tested either.

    A release note is provided since this is a pretty severe bug if
    you're running new enough libvirt/qemu and not using kvm/qemu as
    the virt type because CONF.serial_console.enabled is False by
    default so you're going to have failed server creates immediately
    upon upgrading to Ocata.

    Change-Id: I7f60db1d243a75b90e3c0e53201cb6000ee95778
    Closes-Bug: #1670522
    (cherry picked from commit ac61abb7c74f1a8e3e9134bc045455fd9fdac0fa)

[OpenStack Infra (hudson-openstack)]

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

[OpenStack Infra (hudson-openstack)]

This issue was fixed in the openstack/nova 16.0.0.0b1 development milestone.