Bug 1625550 - virt-viewer can not establish tls connection for usbredir
Summary: virt-viewer can not establish tls connection for usbredir
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: spice-gtk
Version: 7.6
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: Victor Toso
QA Contact: SPICE QE bug list
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-09-05 08:06 UTC by yanqzhan@redhat.com
Modified: 2019-08-06 13:07 UTC (History)
11 users (show)

Fixed In Version: spice-gtk-0.35-4.el7
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-08-06 13:07:26 UTC
Target Upstream Version:


Attachments (Terms of Use)
spice_libvirtd_qemu_logs_guestxml (344.04 KB, application/x-gzip)
2018-09-05 08:13 UTC, yanqzhan@redhat.com
no flags Details


Links
System ID Priority Status Summary Last Updated
Red Hat Product Errata RHSA-2019:2229 None None None 2019-08-06 13:07:49 UTC

Description yanqzhan@redhat.com 2018-09-05 08:06:47 UTC
Description of problem:
virt-viewer can not establish tls connection for usbredir

Version-Release number of selected component (if applicable):
spice-gtk3-0.35-2.el7.x86_64
spice-server-0.14.0-6.el7.x86_64
spice-glib-0.35-2.el7.x86_64v
virt-viewer-5.0-11.el7.x86_64
libvirt-4.5.0-7.el7.x86_64
qemu-kvm-rhev-2.12.0-12.el7.x86_64

How reproducible:
100%

Steps to Reproduce:
1. Configure spice tls env and prepare a usb device on host.
#tail -3 /etc/libvirt/qemu.conf
spice_tls=1
spice_tls_x509_cert_dir="/etc/pki/libvirt-spice"

2.Install required packages for USB redirection:
usbredir usbredir-server

3.Configure 8 channels as 'secure' in guest graphics xml:
...
    <controller type='usb' index='0' model='ich9-ehci1'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x7'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci1'>
      <master startport='0'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0' multifunction='on'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci2'>
      <master startport='2'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x1'/>
    </controller>
    <controller type='usb' index='0' model='ich9-uhci3'>
      <master startport='4'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x2'/>
    </controller>
...
    <graphics type='spice' autoport='yes' listen='0.0.0.0'>
      <listen type='address' address='0.0.0.0'/>
      <channel name='main' mode='secure'/>
      <channel name='display' mode='secure'/>
      <channel name='inputs' mode='secure'/>
      <channel name='cursor' mode='secure'/>
      <channel name='playback' mode='secure'/>
      <channel name='record' mode='secure'/>
      <channel name='smartcard' mode='secure'/>
      <channel name='usbredir' mode='secure'/>
    </graphics>
...
    <video>
      <model type='qxl' ram='65536' vram='65536' vgamem='16384' heads='1' primary='yes'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <redirdev bus='usb' type='spicevmc'>
      <address type='usb' bus='0' port='2'/>
    </redirdev>
    <redirdev bus='usb' type='spicevmc'>
      <address type='usb' bus='0' port='3'/>
    </redirdev>
...
    <smartcard mode='passthrough' type='spicevmc'>
      <address type='ccid' controller='0' slot='0'/>
    </smartcard>
...
    <controller type='ccid' index='0'>
      <address type='usb' bus='0' port='4'/>
    </controller>
...

4.# virsh start V7.6-GUI
Domain V7.6-GUI started

5.Check qemu cmd line, can get "tls-channel" for all 8 devices:
#ps aux|grep qemu-kvm|grep tls-channel
... -spice port=5900,tls-port=5901,addr=0.0.0.0,disable-ticketing,x509-dir=/etc/pki/libvirt-spice,tls-channel=main,tls-channel=display,tls-channel=inputs,tls-channel=cursor,tls-channel=playback,tls-channel=record,tls-channel=smartcard,tls-channel=usbredir,seamless-migration=on ...

6. Connect guest by virt-viewer:
# virt-viewer V7.6-GUI --spice-smartcard  --spice-host-subject="C=IL,L=Raanana,O=Red Hat,CN=redhat" --spice-ca-file='/etc/pki/libvirt-spice/ca-cert.pem'  --debug --spice-debug  

7.Check connections of virt-viewer:
# netstat -tunap |grep virt-viewer
tcp        0      0 127.0.0.1:35216         127.0.0.1:5901          ESTABLISHED 12450/virt-viewer  
tcp        0      0 127.0.0.1:35192         127.0.0.1:5901          ESTABLISHED 12450/virt-viewer  
tcp        1      0 127.0.0.1:54832         127.0.0.1:5900          CLOSE_WAIT  12450/virt-viewer  
tcp        0      0 127.0.0.1:35218         127.0.0.1:5901          ESTABLISHED 12450/virt-viewer  
tcp        0      0 127.0.0.1:35214         127.0.0.1:5901          ESTABLISHED 12450/virt-viewer  
tcp        0      0 127.0.0.1:54830         127.0.0.1:5900          CLOSE_WAIT  12450/virt-viewer  
tcp        0      0 127.0.0.1:35194         127.0.0.1:5901          ESTABLISHED 12450/virt-viewer  
tcp        0      0 127.0.0.1:35188         127.0.0.1:5901          ESTABLISHED 12450/virt-viewer  
tcp        0      0 127.0.0.1:35152         127.0.0.1:5901          ESTABLISHED 12450/virt-viewer  
tcp6       0      0 ::1:46742               ::1:6010                ESTABLISHED 12450/virt-viewer   

8. In virt-viewer, try to redirect the usb device from host to guest by "FILE-> USB DEVICE SELECTION":
After select the usb device, the usb disappears on host "lsblk", but not appears in guest.


Actual results:
1. In step 7, can see only the two usb redirdev connections are not established: "CLOSE_WAIT", all other devices connected to tls channels successfully.
2. As in step 8, usb redirection can not succeed.
2. In step 6, can see usbredir connection log stopped after 'try switching to tls...reset' :
# cat spice-debug.log |grep usbredir -i
(virt-viewer:9392): GSpice-DEBUG: 17:04:21.918: spice-session.c:284 Supported channels: main, display, inputs, cursor, playback, record, smartcard, usbredir
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.032: spice-channel.c:141 usbredir-9:1: spice_channel_constructed
(virt-viewer:9392): virt-viewer-DEBUG: 17:04:22.032: New spice channel 0x55fba4283250 SpiceUsbredirChannel 1
(virt-viewer:9392): virt-viewer-DEBUG: 17:04:22.032: new usbredir channel
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.032: spice-channel.c:141 usbredir-9:0: spice_channel_constructed
(virt-viewer:9392): virt-viewer-DEBUG: 17:04:22.032: New spice channel 0x55fba4296a50 SpiceUsbredirChannel 0
(virt-viewer:9392): virt-viewer-DEBUG: 17:04:22.033: new usbredir channel
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.074: spice-channel.c:2693 usbredir-9:1: Open coroutine starting 0x55fba4283250
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.074: spice-channel.c:2534 usbredir-9:1: Started background coroutine 0x55fba42828d0
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.074: spice-session.c:2216 usbredir-9:1: Using plain text, port 5900
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.074: spice-channel.c:2693 usbredir-9:0: Open coroutine starting 0x55fba4296a50
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.074: spice-channel.c:2534 usbredir-9:0: Started background coroutine 0x55fba42960d0
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.074: spice-session.c:2216 usbredir-9:0: Using plain text, port 5900
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.075: spice-session.c:2069 usbredir-9:1: connecting 0x7f42517fca30...
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.075: spice-session.c:2069 usbredir-9:0: connecting 0x7f4247fffa30...
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-session.c:2053 usbredir-9:1: connect ready
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:1368 usbredir-9:1: channel type 9 id 1 num common caps 1 num caps 1
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-session.c:2053 usbredir-9:0: connect ready
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:1368 usbredir-9:0: channel type 9 id 0 num common caps 1 num caps 1
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:1392 usbredir-9:1: Peer version: 2:2
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:1935 usbredir-9:1: switching to tls
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:2670 usbredir-9:1: Coroutine exit usbredir-9:1
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:2863 usbredir-9:1: reset
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.077: spice-channel.c:1392 usbredir-9:0: Peer version: 2:2
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.077: spice-channel.c:1935 usbredir-9:0: switching to tls
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.077: spice-channel.c:2670 usbredir-9:0: Coroutine exit usbredir-9:0
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.077: spice-channel.c:2863 usbredir-9:0: reset


Expected results:
The connection should be established to tls port(5901) for usbredir with tls secure channel. Then usb redirection can be done successfully.


Additional info:
1.The usbredir connections can be established to port(5900) if set insecure channel. And then usb redirection can be done successfully.
2.The tls connection for other devices in spice log are like:
...
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.113: spice-channel.c:1935 smartcard-8:0: switching to tls
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.113: spice-channel.c:2670 smartcard-8:0: Coroutine exit smartcard-8:0
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.113: spice-channel.c:2863 smartcard-8:0: reset 
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.113: spice-channel.c:2805 smartcard-8:0: channel reset
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.113: spice-channel.c:2693 smartcard-8:0: Open coroutine starting 0x55fba43d7550
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.113: spice-channel.c:2534 smartcard-8:0: Started background coroutine 0x55fba43d6bd0
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.113: spice-session.c:2214 smartcard-8:0: Using TLS, port 5901
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.113: spice-session.c:2069 smartcard-8:0: connecting 0x7f4244fffa30...
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.114: spice-session.c:2053 smartcard-8:0: connect ready
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.114: spice-channel.c:2456 smartcard-8:0: Load CA, file: /etc/pki/libvirt-spice/ca-cert.pem, data: (nil)
...
3. Using "--spice-secure-channels=usbredir" in virt-viewer to force the usbredir channel to be secured works well, but usbredir should auto connect tls channel without this option just as other channels do.

Comment 2 yanqzhan@redhat.com 2018-09-05 08:13:33 UTC
Created attachment 1481007 [details]
spice_libvirtd_qemu_logs_guestxml

Comment 3 Victor Toso 2018-09-05 10:04:15 UTC
In comment #0 is missing but we can see on attached logs that client is at fault.

(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:1392 usbredir-9:1: Peer version: 2:2
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:1935 usbredir-9:1: switching to tls
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:2670 usbredir-9:1: Coroutine exit usbredir-9:1
(virt-viewer:9392): GSpice-DEBUG: 17:04:22.076: spice-channel.c:2863 usbredir-9:1: reset 

(virt-viewer:9392): GSpice-CRITICAL **: 17:04:22.077: channel_connect: assertion 'c->sock == NULL' failed

The channels connect once, server let the channel know that it should be secure, client must reconnect. Channel-usbredir fails to reconnect, likely due the fact that it does channel_reset() async (the only one doing that) .. channel_connect() in chained up after spice_channel_reset() and endup with the critical above and channel_connect() is not called again.

If I'm right about the issue, this is a regression since v0.32 ~ 9fbf6794

As the regression is quite old and there is workaround with --spice-secure-channels=usbredir, I would not consider it a blocker for 7.6.

Comment 5 Victor Toso 2018-09-06 14:15:16 UTC
Patch sent:
https://lists.freedesktop.org/archives/spice-devel/2018-September/045538.html

We probably should handle the UI as well (if usbredir is not connected, shouldn't be able to redirect, etc.)

Comment 6 Victor Toso 2018-09-26 15:34:54 UTC
Pushed upstream

commit 3afee7ae8db387e7f4339f2a4afaa63babf358b7
Author: Victor Toso <me@victortoso.com>
Date:   Wed Sep 5 15:43:28 2018 +0200

    channel-usbredir: Chain-up with parent's channel-reset
    
    Otherwise spice-channel is left with a broken state.
    
    This code moves parent's call to channel_reset() into
    _channel_reset_finish() - Note that spice-channel's channel_reset()
    can be called from GMainContext.
    
    Resolves: https://bugzilla.redhat.com/show_bug.cgi?id=1625550
    
    Signed-off-by: Victor Toso <victortoso@redhat.com>
    Acked-by: Frediano Ziglio <fziglio@redhat.com>

Comment 10 errata-xmlrpc 2019-08-06 13:07:26 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2019:2229


Note You need to log in before you can comment on or make changes to this bug.