nova generate wrong spice channel type 'pty', which should be 'spicevmc'

Bug #1634495 reported by m4cr0v on 2016-10-18
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Medium
m4cr0v
Newton
Medium
Matt Riedemann
Ocata
Medium
Matt Riedemann

Bug Description

Description
===========
In openstack kilo release(I know it's somekind of out of date, howerver I noticed that the code cause this issue still exists in the latest nova.git repo), if you use spice as the default console, the type of a spice channel(used by apice agent) is 'pyt', which should be 'spicevmc'.

Steps to reproduce
==================
1. Modify the nova.conf to use spice as default console.
Edit /etc/nova/nova.conf, add the following lines:
[default]
vnc_enabled=false
[spice]
html5proxy_base_url=http://192.168.209.11:6082/spice_auto.html
server_listen=0.0.0.0
server_proxyclient_address=192.168.209.31
enabled=true
keymap=en-us

2. Modify the nova-compute log level to debug(For convenience, I just edit the log code from LOG.debug to LOG.error.)
The log code is in:
/usr/lib/python2.7/site-packages/nova/virt/libvirt/config.py
    def to_xml(self, pretty_print=True):
        root = self.format_dom()
        xml_str = etree.tostring(root, pretty_print=pretty_print)
        LOG.debug("Generated XML %s ", (xml_str,))
        return xml_str
Restart the openstack-nova-compute.service: systemctl restart openstack-nova-compute.service

3. Start an instance.

4. Check the printed xml in /var/log/nova/nova-compute.log, you will see the generated xml:
2016-10-18 16:54:36.848 7061 ERROR nova.virt.libvirt.config [req-76070e65-4c92-41eb-9ee6-a124fefae4d2 03a011159e8d464bafc89a88823a7403 92de23d236a6461f96c43e71ac7c60ae - - -] Generated XML ('<domain type="kvm">\n <uuid>38181e25-df56-4594-97e6-f1da2bfe1579</uuid>\n <name>instance-00000044</name>\n <memory>4194304</memory>\n <vcpu>2</vcpu>\n <metadata>\n <nova:instance xmlns:nova="http://openstack.org/xmlns/libvirt/nova/1.0">\n <nova:package version="2015.1.2-1.el7"/>\n <nova:name>test</nova:name>\n <nova:creationTime>2016-10-18 08:54:36</nova:creationTime>\n <nova:flavor name="win7">\n <nova:memory>4096</nova:memory>\n <nova:disk>40</nova:disk>\n <nova:swap>0</nova:swap>\n <nova:ephemeral>0</nova:ephemeral>\n <nova:vcpus>2</nova:vcpus>\n </nova:flavor>\n <nova:owner>\n <nova:user uuid="03a011159e8d464bafc89a88823a7403">admin</nova:user>\n <nova:project uuid="92de23d236a6461f96c43e71ac7c60ae">admin</nova:project>\n </nova:owner>\n <nova:root type="image" uuid="2d8a12f8-556a-4459-bb76-c10b398269a0"/>\n </nova:instance>\n </metadata>\n <sysinfo type="smbios">\n <system>\n <entry name="manufacturer">Fedora Project</entry>\n <entry name="product">OpenStack Nova</entry>\n <entry name="version">2015.1.2-1.el7</entry>\n <entry name="serial">4d6ca91a-f38e-4329-95cc-0ff79326bd37</entry>\n <entry name="uuid">38181e25-df56-4594-97e6-f1da2bfe1579</entry>\n </system>\n </sysinfo>\n <os>\n <type>hvm</type>\n <boot dev="hd"/>\n <smbios mode="sysinfo"/>\n </os>\n <features>\n <acpi/>\n <apic/>\n </features>\n <cputune>\n <shares>2048</shares>\n </cputune>\n <clock offset="utc">\n <timer name="pit" tickpolicy="delay"/>\n <timer name="rtc" tickpolicy="catchup"/>\n <timer name="hpet" present="no"/>\n </clock>\n <cpu mode="host-model" match="exact">\n <topology sockets="2" cores="1" threads="1"/>\n </cpu>\n <devices>\n <disk type="network" device="disk">\n <driver type="raw" cache="none"/>\n <source protocol="rbd" name="vms/38181e25-df56-4594-97e6-f1da2bfe1579_disk">\n <host name="192.168.30.208" port="6789"/>\n </source>\n <auth username="cinder">\n <secret type="ceph" uuid="812cdf8a-e932-4c03-84ed-d30ee2847fa2"/>\n </auth>\n <target bus="virtio" dev="vda"/>\n </disk>\n <interface type="bridge">\n <mac address="fa:16:3e:38:b4:6e"/>\n <model type="virtio"/>\n <source bridge="qbr313aad30-aa"/>\n <target dev="tap313aad30-aa"/>\n </interface>\n <serial type="file">\n <source path="/var/lib/nova/instances/38181e25-df56-4594-97e6-f1da2bfe1579/console.log"/>\n </serial>\n <serial type="pty"/>\n <channel type="pty">\n <target type="virtio" name="com.redhat.spice.0"/>\n </channel>\n <graphics type="spice" autoport="yes" keymap="en-us" listen="0.0.0.0"/>\n <video>\n <model type="qxl"/>\n </video>\n <memballoon model="virtio">\n <stats period="10"/>\n </memballoon>\n </devices>\n</domain>\n',)

Expected result
===============
The channel type should be 'spicevmc', like this:
    <channel type='spicevmc'>
        <target type='virtio' name='com.redhat.spice.0'/>
    </channel>

I confirmed the expect result from the following aspects:
1. Firstly, the test code in nova/tests/unit/virt/libvirt/test_config.py(latest nova.git repo)
1411 class LibvirtConfigGuestChannelTest(LibvirtConfigBaseTest):
1412 def test_config_spice_minimal(self):
1413 obj = config.LibvirtConfigGuestChannel()
1414 obj.type = "spicevmc"
1415
1416 xml = obj.to_xml()
1417 self.assertXmlEqual(xml, """
1418 <channel type="spicevmc">
1419 <target type='virtio'/>
1420 </channel>""")
1421
1422 def test_config_spice_full(self):
1423 obj = config.LibvirtConfigGuestChannel()
1424 obj.type = "spicevmc"
1425 obj.target_name = "com.redhat.spice.0"
1426
1427 xml = obj.to_xml()
1428 self.assertXmlEqual(xml, """
1429 <channel type="spicevmc">
1430 <target type='virtio' name='com.redhat.spice.0'/>
1431 </channel>""")

2. Secondly, if we use the channel whose type is 'pty', and install vdagent or spice-guest-tools-0.100.exe in windows 7 guest os, the CPU utilization of vdagent.exe is very high(I noticed both %50 and 99%, in two instances), and the error log is printed:
(C:\Windows\Temp\vdagent.log)
1724::INFO::2016-10-18 0613:21,821::VDAgent::run::***Agent started in session 1***
1724::INFO::2016-10-18 0613:21,821::log_version::0.5.1.0
1724::INFO::2016-10-18 0613:21,821::DesktopLayout::consistent_displays::#qxls 1 #others 0
1724::INFO::2016-10-18 0613:21,821::VDAgent::send_announce_capabilities::Sending capabilities:
1724::INFO::2016-10-18 0613:21,821::VDAgent::send_announce_capabilities::6B7
1724::INFO::2016-10-18 0613:21,821::VDAgent::run::Connected to server
1724::INFO::2016-10-18 0613:21,821::VDAgent::input_desktop_message_loop::Desktop: Winlogon
1724::INFO::2016-10-18 0613:21,821::VDAgent::write_completion:vio_serial write completion error 554

The mouse cursor moves slowly, you also cannot use clipboard between the guest os and the client.
If I modify the channel type to 'spicevmc', all the problems disappeared. And the mouse is released automatically if you move it out of the spice window, there is no need to press Ctrl+Alt.

Actual result
=============
The channel type for spice agent is 'pty':
    <channel type='pty'>
        <target type='virtio' name='com.redhat.spice.0'/>
    </channel>

Environment
===========
1. OS and openstack release
[root@node3 ~]# cat /etc/redhat-release
CentOS Linux release 7.2.1511 (Core)
[root@node3 ~]# uname -a
Linux node3 3.10.0-327.el7.x86_64 #1 SMP Thu Nov 19 22:10:57 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux
[root@node3 ~]# rpm -qa | grep nova
openstack-nova-common-2015.1.2-1.el7.noarch
openstack-nova-compute-2015.1.2-1.el7.noarch
python-nova-2015.1.2-1.el7.noarch
python-novaclient-2.23.0-1.el7.noarch

2. Hypervisor
Libvirt + QEMU + KVM
[root@node3 ~]# rpm -qa | grep libvirt
libvirt-client-1.2.17-13.el7_2.5.x86_64
libvirt-daemon-driver-nodedev-1.2.17-13.el7_2.5.x86_64
libvirt-daemon-driver-storage-1.2.17-13.el7_2.5.x86_64
libvirt-daemon-1.2.17-13.el7_2.5.x86_64
libvirt-daemon-driver-nwfilter-1.2.17-13.el7_2.5.x86_64
libvirt-daemon-driver-secret-1.2.17-13.el7_2.5.x86_64
libvirt-python-1.2.17-2.el7.x86_64
libvirt-daemon-driver-qemu-1.2.17-13.el7_2.5.x86_64
libvirt-daemon-kvm-1.2.17-13.el7_2.5.x86_64
libvirt-daemon-driver-network-1.2.17-13.el7_2.5.x86_64
libvirt-daemon-driver-interface-1.2.17-13.el7_2.5.x86_64
[root@node3 ~]# rpm -qa | grep qemu
libvirt-daemon-driver-qemu-1.2.17-13.el7_2.5.x86_64
qemu-kvm-common-1.5.3-105.el7_2.7.x86_64
ipxe-roms-qemu-20160127-1.git6366fa7a.el7.noarch
qemu-img-1.5.3-105.el7_2.7.x86_64
qemu-kvm-1.5.3-105.el7_2.7.x86_64

Logs & Configs
==============
Normal vdagent log if I use the 'spicevmc' channel type:
1284::INFO::2016-10-18 06:39:43,000::VDAgent::run::***Agent started in session 1***
1284::INFO::2016-10-18 06:39:43,000::log_version::0.5.1.0
1284::INFO::2016-10-18 06:39:43,000::DesktopLayout::consistent_displays::#qxls 1 #others 0
1284::INFO::2016-10-18 06:39:43,000::VDAgent::send_announce_capabilities::Sending capabilities:
1284::INFO::2016-10-18 06:39:43,000::VDAgent::send_announce_capabilities::6B7
1284::INFO::2016-10-18 06:39:43,000::VDAgent::run::Connected to server
1284::INFO::2016-10-18 06:39:43,000::VDAgent::input_desktop_message_loop::Desktop: Winlogon
1284::INFO::2016-10-18 06:39:43,031::VDAgent::handle_announce_capabilities::Got capabilities (1)
1284::INFO::2016-10-18 06:39:43,031::VDAgent::handle_announce_capabilities::1077
1284::INFO::2016-10-18 06:39:43,031::VDAgent::send_announce_capabilities::Sending capabilities:
1284::INFO::2016-10-18 06:39:43,031::VDAgent::send_announce_capabilities::6B7
1284::INFO::2016-10-18 06:39:43,046::DisplaySetting::set::setting display options
1284::INFO::2016-10-18 06:39:43,046::DisplaySetting::get_user_process_id::explorer.exe not found
1284::INFO::2016-10-18 06:39:43,046::DisplaySetting::reload_from_registry::get_user_process_id failed
1284::INFO::2016-10-18 06:39:43,046::VDAgent::handle_max_clipboard::Set max clipboard size: 104857600
1284::INFO::2016-10-18 06:39:43,046::VDAgent::handle_mon_config::0. 1024*768*32 (0,0) 1
1284::INFO::2016-10-18 06:39:43,046::DesktopLayout::consistent_displays::#qxls 1 #others 0
1284::INFO::2016-10-18 06:39:43,046::DesktopLayout::set_displays::Set display mode 1024x768
1284::INFO::2016-10-18 06:39:43,078::VDAgent::wnd_proc::Display change
1284::INFO::2016-10-18 06:39:43,078::DesktopLayout::consistent_displays::#qxls 1 #others 0
1284::INFO::2016-10-18 06:39:48,625::VDAgent::handle_control_event::Control command 2
1284::INFO::2016-10-18 06:39:48,625::VDAgent::handle_control_event::session logon
1284::INFO::2016-10-18 06:39:54,046::VDAgent::handle_control_event::Control command 1
1284::INFO::2016-10-18 06:39:54,062::VDAgent::input_desktop_message_loop::Desktop: Default
1284::INFO::2016-10-18 06:39:54,062::VDAgent::input_desktop_message_loop::First display setting
1284::INFO::2016-10-18 06:39:54,062::DisplaySetting::load::loading display setting
1284::INFO::2016-10-18 06:39:54,062::DisplaySetting::get_user_process_id::explorer.exe not found
1284::INFO::2016-10-18 06:39:54,062::DisplaySetting::reload_from_registry::get_user_process_id failed
1284::INFO::2016-10-18 06:40:25,187::VDAgent::handle_clipboard_grab::grab type 1
1284::INFO::2016-10-18 06:40:29,937::VDAgent::handle_control_event::Control command 3
1284::INFO::2016-10-18 06:40:29,937::VDAgent::handle_clipboard_grab::grab type 1
1284::INFO::2016-10-18 06:40:35,578::VDAgent::handle_control_event::Control command 3
1284::INFO::2016-10-18 06:40:35,578::VDAgent::handle_clipboard_grab::grab type 1

Patch
==============
From 2309f146f08c0d0c541ba3e8b392ee9ca072bd64 Mon Sep 17 00:00:00 2001
From: m4cr0v <email address hidden>
Date: Tue, 18 Oct 2016 20:55:22 +0800
Subject: [PATCH] Fix type of the channel for spice agent.

The type of the channel for spice agent should be 'spicevmc' instead of 'pty'.
---
 nova/virt/libvirt/driver.py | 1 +
 1 file changed, 1 insertion(+)

diff --git a/nova/virt/libvirt/driver.py b/nova/virt/libvirt/driver.py
index b0bba46..6ddf65e 100644
--- a/nova/virt/libvirt/driver.py
+++ b/nova/virt/libvirt/driver.py
@@ -4491,6 +4491,7 @@ class LibvirtDriver(driver.ComputeDriver):
         if (CONF.spice.enabled and CONF.spice.agent_enabled and
                 virt_type not in ('lxc', 'uml', 'xen')):
             channel = vconfig.LibvirtConfigGuestChannel()
+ channel.type = 'spicevmc'
             channel.target_name = "com.redhat.spice.0"
             guest.add_device(channel)

--
1.8.3.1

m4cr0v (m4cr0v) wrote :
m4cr0v (m4cr0v) on 2016-10-18
description: updated
description: updated
m4cr0v (m4cr0v) on 2016-10-19
description: updated
m4cr0v (m4cr0v) wrote :

Hi, I checked the link you posted, it seems not related to this bug.

sireeshak (sireeshak) on 2016-12-02
Changed in nova:
assignee: nobody → sireeshak (sireeshak)
m4cr0v (m4cr0v) on 2016-12-03
Changed in nova:
assignee: sireeshak (sireeshak) → m4cr0v (m4cr0v)
Sean Dague (sdague) wrote :

Please submit the patch to gerrit. We don't do patches out of launchpad.

Changed in nova:
status: New → Incomplete

Change abandoned by Sean Dague (<email address hidden>) on branch: master
Review: https://review.openstack.org/389262
Reason: This review is > 6 weeks without comment, and failed Jenkins the last time it was checked. We are abandoning this for now. Feel free to reactivate the review by pressing the restore button and leaving a 'recheck' comment to get fresh test results.

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

Changed in nova:
status: Incomplete → In Progress
Matt Riedemann (mriedem) on 2017-03-03
Changed in nova:
importance: Undecided → Medium
Matt Riedemann (mriedem) on 2017-03-03
tags: added: libvirt newton-backport-potential ocata-backport-potential spice

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

commit f4be97d8cf8811a64a2d9f7d990e79d45cdf0d62
Author: m4cr0v <email address hidden>
Date: Tue Dec 13 16:17:34 2016 +0800

    Fix spice channel type

    nova generate wrong spice channel type 'pty', which should be 'spicevmc'
    Closes-Bug: #1634495
    Change-Id: I58e9a8df9f40f900eeabd9d40429663cbbedb8d6

Changed in nova:
status: In Progress → Fix Released

Reviewed: https://review.openstack.org/441457
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=725f500d5e8e2058b8b2649b1908b13ab15a7a7b
Submitter: Jenkins
Branch: stable/newton

commit 725f500d5e8e2058b8b2649b1908b13ab15a7a7b
Author: m4cr0v <email address hidden>
Date: Tue Dec 13 16:17:34 2016 +0800

    Fix spice channel type

    nova generate wrong spice channel type 'pty', which should be 'spicevmc'
    Closes-Bug: #1634495
    Change-Id: I58e9a8df9f40f900eeabd9d40429663cbbedb8d6
    (cherry picked from commit f4be97d8cf8811a64a2d9f7d990e79d45cdf0d62)

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

commit c0fd42738819712e66336cf6f5f386f61cf26bda
Author: m4cr0v <email address hidden>
Date: Tue Dec 13 16:17:34 2016 +0800

    Fix spice channel type

    nova generate wrong spice channel type 'pty', which should be 'spicevmc'
    Closes-Bug: #1634495
    Change-Id: I58e9a8df9f40f900eeabd9d40429663cbbedb8d6
    (cherry picked from commit f4be97d8cf8811a64a2d9f7d990e79d45cdf0d62)

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

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

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

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

Other bug subscribers