Bug 1036833 - client_migrate_info fails when r-v connects through vv file over SSL encryption
Summary: client_migrate_info fails when r-v connects through vv file over SSL encryption
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Virtualization Manager
Classification: Red Hat
Component: mingw-virt-viewer
Version: 3.3.0
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
: 3.3.0
Assignee: Default Assignee for SPICE Bugs
QA Contact: Desktop QE
URL:
Whiteboard:
Depends On: 1022565
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-12-02 17:24 UTC by Marian Krcmarik
Modified: 2018-12-09 17:20 UTC (History)
11 users (show)

Fixed In Version: mingw-virt-viewer-0.5.6-21.el6_5 mingw-spice-gtk-0.20-6.el6_5
Doc Type: Bug Fix
Doc Text:
Previously, migration of a virtual machine with a client connected using a mime connection file and SSL would fall back to non-seamless migration. This was caused by the CA not being correctly copied from memory. Now, the CA is copied to the destination session, making it possible to complete seamless migration successfully.
Clone Of: 1022565
Environment:
Last Closed: 2014-06-09 12:51:25 UTC
oVirt Team: ---
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Knowledge Base (Solution) 787503 0 None None None Never
Red Hat Product Errata RHBA-2014:0644 0 normal SHIPPED_LIVE rhevm-spice-client bug fix and enhancement update 2014-06-09 16:49:53 UTC

Comment 6 Tomas Jamrisko 2014-04-23 09:51:23 UTC
Migration sometimes falls back to switch host, but the client fails to connect and requires authentication.

I've noticed this only on RHEVM3.4, 3.3 works as expected.

Do you have any idea what might cause this?

Failure on the client seems to be:
(remote-viewer.exe:2604): GSpice-DEBUG: ../../gtk/spice-session.c:1709 connect ready
(remote-viewer.exe:2604): GSpice-DEBUG: ../../gtk/spice-channel.c:2162 main-1:0: Load CA, file: C:\Users\test/.spicec/sp
ice_truststore.pem, data: 024D7A90

(remote-viewer.exe:2604): GSpice-WARNING **: loading ca certs from C:\Users\test/.spicec/spice_truststore.pem failed

On the server: 
Spice-warning **: reds.c:1965:reds_handle_ticket: Ticketing is enabled, but no password is set. please set a ticket first

Yet libvirt seems to try to set password: 
2014-04-22 13:40:36.713+0000: 3785: debug : virDomainUpdateDeviceFlags:9914 : dom=0x7ffbb8176df0, (VM: name=rhel6-tj, uuid=ba0e212c-13a7-4c6a-a591-bc4181258ed9), xml=<graphics autoport="yes" connected="disconnect" keymap="en-us" passwd="L+6bKHIRpJQf" passwdValidTo="2014-04-22T13:42:36" port="5902" tlsPort="5903" type="spice">
      <listen address="10.34.73.135" network="vdsm-display" type="network"/>
      <channel mode="secure" name="main"/>
      <channel mode="secure" name="display"/>
      <channel mode="secure" name="inputs"/>
      <channel mode="secure" name="cursor"/>
      <channel mode="secure" name="playback"/>
      <channel mode="secure" name="record"/>
      <channel mode="secure" name="smartcard"/>
      <channel mode="secure" name="usbredir"/>
    </graphics>, flags=0
2014-04-22 13:40:36.713+0000: 3785: debug : qemuDomainObjBeginJobInternal:808 : Starting job: modify (async=none)
2014-04-22 13:40:36.713+0000: 3785: debug : qemuDomainChangeGraphics:1870 : Updating password on SPICE server 0x7ffbb80f21a0 (nil)
2014-04-22 13:40:36.713+0000: 3785: debug : qemuMonitorSetPasswordRH:1613 : mon=0x7ffbb40ec280, fd=35 type=4(spice), password=0x7ffbb80f21a0, action_if_connected=disconnect expiry=120
2014-04-22 13:40:36.713+0000: 3785: debug : qemuMonitorSend:904 : QEMU_MONITOR_SEND_MSG: mon=0x7ffbb40ec280 msg={"execute":"__com.redhat_set_password","arguments":{"protocol":"spice","password":"L+6bKHIRpJQf","connected":"disconnect","expiration":120},"id":"libvirt-256"}^M
 fd=-1
2014-04-22 13:40:36.713+0000: 3782: debug : qemuMonitorIOWrite:462 : QEMU_MONITOR_IO_WRITE: mon=0x7ffbb40ec280 buf={"execute":"__com.redhat_set_password","arguments":{"protocol":"spice","password":"L+6bKHIRpJQf","connected":"disconnect","expiration":120},"id":"libvirt-256"}^M
 len=161 ret=161 errno=11
2014-04-22 13:40:36.714+0000: 3782: debug : qemuMonitorIOProcess:354 : QEMU_MONITOR_IO_PROCESS: mon=0x7ffbb40ec280 buf={"return": {}, "id": "libvirt-256"}^M
 len=37
2014-04-22 13:40:36.748+0000: 3785: debug : qemuDomainObjEndJob:937 : Stopping job: modify (async=none)
2014-04-22 13:40:36.748+0000: 3785: debug : virDomainFree:2281 : dom=0x7ffbb8176df0, (VM: name=rhel6-tj, uuid=ba0e212c-13a7-4c6a-a591-bc4181258ed9)
2014-04-22 13:40:36.947+0000: 3789: debug : virDomainGetInfo:4208 : dom=0x7ffbac01b290, (VM: name=winXP-ve, uuid=88b0c998-42df-4be2-a739-26e28795ed05), info=0x7ffbc31a3ad0
2014-04-22 13:40:36.947+0000: 3789: debug : qemudGetProcessInfo:1335 : Got status for 7091/0 user=18343 sys=8183 cpu=0 rss=292707
2014-04-22 13:40:36.947+0000: 3789: debug : virDomainFree:2281 : dom=0x7ffbac01b290, (VM: name=winXP-ve, uuid=88b0c998-42df-4be2-a739-26e28795ed05)
2014-04-22 13:40:36.948+0000: 3787: debug : virDomainGetInfo:4208 : dom=0x7ffbb40c49e0, (VM: name=rhel6-tj, uuid=ba0e212c-13a7-4c6a-a591-bc4181258ed9), info=0x7ffbc45a5ad0
2014-04-22 13:40:36.948+0000: 3787: debug : qemudGetProcessInfo:1335 : Got status for 19018/0 user=643 sys=452 cpu=2 rss=294707
2014-04-22 13:40:36.948+0000: 3787: debug : virDomainFree:2281 : dom=0x7ffbb40c49e0, (VM: name=rhel6-tj, uuid=ba0e212c-13a7-4c6a-a591-bc4181258ed9)

Comment 7 Marc-Andre Lureau 2014-04-23 10:11:55 UTC
(In reply to Tomas Jamrisko from comment #6)
> Migration sometimes falls back to switch host, but the client fails to
> connect and requires authentication.
> 
> I've noticed this only on RHEVM3.4, 3.3 works as expected.

Did spice server changed in 3.4? If not, then libvirt?

> 
> Do you have any idea what might cause this?

It's hard to say, as I don't use rhevm regularly. Perhaps I can connect to a rhevm 3.4 instance to test this?

> 
> Failure on the client seems to be:
> (remote-viewer.exe:2604): GSpice-DEBUG: ../../gtk/spice-session.c:1709
> connect ready
> (remote-viewer.exe:2604): GSpice-DEBUG: ../../gtk/spice-channel.c:2162
> main-1:0: Load CA, file: C:\Users\test/.spicec/sp
> ice_truststore.pem, data: 024D7A90
> 
> (remote-viewer.exe:2604): GSpice-WARNING **: loading ca certs from
> C:\Users\test/.spicec/spice_truststore.pem failed
> 
> On the server: 
> Spice-warning **: reds.c:1965:reds_handle_ticket: Ticketing is enabled, but
> no password is set. please set a ticket first


Afaik, so far, the client doesn't need any password to connect to destination (the code seems to always use an empty password). But it seems now it would require it. Which one? Why such a change?

> 
> Yet libvirt seems to try to set password: 
> 2014-04-22 13:40:36.713+0000: 3785: debug : virDomainUpdateDeviceFlags:9914
> : dom=0x7ffbb8176df0, (VM: name=rhel6-tj,
> uuid=ba0e212c-13a7-4c6a-a591-bc4181258ed9), xml=<graphics autoport="yes"
> connected="disconnect" keymap="en-us" passwd="L+6bKHIRpJQf"
> passwdValidTo="2014-04-22T13:42:36" port="5902" tlsPort="5903" type="spice">
>       <listen address="10.34.73.135" network="vdsm-display" type="network"/>
>       <channel mode="secure" name="main"/>
>       <channel mode="secure" name="display"/>
>       <channel mode="secure" name="inputs"/>
>       <channel mode="secure" name="cursor"/>
>       <channel mode="secure" name="playback"/>
>       <channel mode="secure" name="record"/>
>       <channel mode="secure" name="smartcard"/>
>       <channel mode="secure" name="usbredir"/>
>     </graphics>, flags=0
> 2014-04-22 13:40:36.713+0000: 3785: debug :
> qemuDomainObjBeginJobInternal:808 : Starting job: modify (async=none)
> 2014-04-22 13:40:36.713+0000: 3785: debug : qemuDomainChangeGraphics:1870 :
> Updating password on SPICE server 0x7ffbb80f21a0 (nil)
> 2014-04-22 13:40:36.713+0000: 3785: debug : qemuMonitorSetPasswordRH:1613 :
> mon=0x7ffbb40ec280, fd=35 type=4(spice), password=0x7ffbb80f21a0,
> action_if_connected=disconnect expiry=120
> 2014-04-22 13:40:36.713+0000: 3785: debug : qemuMonitorSend:904 :
> QEMU_MONITOR_SEND_MSG: mon=0x7ffbb40ec280
> msg={"execute":"__com.redhat_set_password","arguments":{"protocol":"spice",
> "password":"L+6bKHIRpJQf","connected":"disconnect","expiration":120},"id":
> "libvirt-256"}^M
>  fd=-1
> 2014-04-22 13:40:36.713+0000: 3782: debug : qemuMonitorIOWrite:462 :
> QEMU_MONITOR_IO_WRITE: mon=0x7ffbb40ec280
> buf={"execute":"__com.redhat_set_password","arguments":{"protocol":"spice",
> "password":"L+6bKHIRpJQf","connected":"disconnect","expiration":120},"id":
> "libvirt-256"}^M
>  len=161 ret=161 errno=11
> 2014-04-22 13:40:36.714+0000: 3782: debug : qemuMonitorIOProcess:354 :
> QEMU_MONITOR_IO_PROCESS: mon=0x7ffbb40ec280 buf={"return": {}, "id":
> "libvirt-256"}^M
>  len=37
> 2014-04-22 13:40:36.748+0000: 3785: debug : qemuDomainObjEndJob:937 :
> Stopping job: modify (async=none)
> 2014-04-22 13:40:36.748+0000: 3785: debug : virDomainFree:2281 :
> dom=0x7ffbb8176df0, (VM: name=rhel6-tj,
> uuid=ba0e212c-13a7-4c6a-a591-bc4181258ed9)
> 2014-04-22 13:40:36.947+0000: 3789: debug : virDomainGetInfo:4208 :
> dom=0x7ffbac01b290, (VM: name=winXP-ve,
> uuid=88b0c998-42df-4be2-a739-26e28795ed05), info=0x7ffbc31a3ad0
> 2014-04-22 13:40:36.947+0000: 3789: debug : qemudGetProcessInfo:1335 : Got
> status for 7091/0 user=18343 sys=8183 cpu=0 rss=292707
> 2014-04-22 13:40:36.947+0000: 3789: debug : virDomainFree:2281 :
> dom=0x7ffbac01b290, (VM: name=winXP-ve,
> uuid=88b0c998-42df-4be2-a739-26e28795ed05)
> 2014-04-22 13:40:36.948+0000: 3787: debug : virDomainGetInfo:4208 :
> dom=0x7ffbb40c49e0, (VM: name=rhel6-tj,
> uuid=ba0e212c-13a7-4c6a-a591-bc4181258ed9), info=0x7ffbc45a5ad0
> 2014-04-22 13:40:36.948+0000: 3787: debug : qemudGetProcessInfo:1335 : Got
> status for 19018/0 user=643 sys=452 cpu=2 rss=294707
> 2014-04-22 13:40:36.948+0000: 3787: debug : virDomainFree:2281 :
> dom=0x7ffbb40c49e0, (VM: name=rhel6-tj,
> uuid=ba0e212c-13a7-4c6a-a591-bc4181258ed9)

Anyway, this bug was for 3.3 and if it works for 3.3, we should close now and open new bug for 3.4 for this password issue.

Comment 8 Tomas Jamrisko 2014-04-23 13:29:31 UTC
(In reply to Marc-Andre Lureau from comment #7)

> Did spice server changed in 3.4? If not, then libvirt?

No, spice-server and libvirt are the same, the only thing that's changed is vdsm and client.

 
> It's hard to say, as I don't use rhevm regularly. Perhaps I can connect to a
> rhevm 3.4 instance to test this?

Sure, ping me on irc. 

 
> Afaik, so far, the client doesn't need any password to connect to
> destination (the code seems to always use an empty password). But it seems
> now it would require it. Which one? Why such a change?

It requires password, but it's the same one as on first connection

> Anyway, this bug was for 3.3 and if it works for 3.3, we should close now
> and open new bug for 3.4 for this password issue.

This issue is on 3.4, which this advisory is for. So it should work there as expected.

Comment 9 Marc-Andre Lureau 2014-04-23 14:53:12 UTC
(In reply to Marc-Andre Lureau from comment #7)
> Afaik, so far, the client doesn't need any password to connect to
> destination (the code seems to always use an empty password). But it seems
> now it would require it. Which one? Why such a change?

correcting myself, the code does copy password from current session to migration session.

Comment 10 Tomas Jamrisko 2014-04-23 16:26:10 UTC
Tried this with VMs and migrations done manually (without libvirt/vsdm/rhevm) and the migration still failed with the
 
GSpice-WARMING **: no cert loaded
when loading from C:\Users\test/.spicec/spice_truststore.pem failed 

the dest VM:
(qemu) (/usr/libexec/qemu-kvm:2353): Spice-Warning **: reds.c:2718:reds_handle_read_link_done: spice channels 1 should be encrypted
(/usr/libexec/qemu-kvm:2353): Spice-Warning **: reds.c:2819:reds_handle_ssl_accept: SSL_accept failed, error=5
the source VM:
main_channel_client_handle_migrate_connected: client 0x7fcecdc28970 connected: 0 seamless 0
(qemu) red_channel_client_disconnect: rcc=0x7fcece146690 (channel=0x7fcecdb99c10 type=3 id=0)
red_channel_client_disconnect: rcc=0x7fceccf80010 (channel=0x7fce7421f350 type=2 id=0)
red_channel_client_disconnect: rcc=0x7fce7426c630 (channel=0x7fce7421f920 type=4 id=0)
red_channel_client_disconnect: rcc=0x7fcece137e20 (channel=0x7fcecdb8eb50 type=1 id=0)
main_channel_client_on_disconnect: rcc=0x7fcece137e20
red_client_destroy: destroy client 0x7fcecdc28970 with #channels=4
red_dispatcher_disconnect_cursor_peer: 
red_dispatcher_disconnect_display_peer:

Note that both VMs were on the same host.

Comment 11 Marc-Andre Lureau 2014-04-23 16:47:11 UTC
(In reply to Tomas Jamrisko from comment #10)
> Tried this with VMs and migrations done manually (without
> libvirt/vsdm/rhevm) and the migration still failed with the
>  
> GSpice-WARMING **: no cert loaded
> when loading from C:\Users\test/.spicec/spice_truststore.pem failed 

this is unrelated and harmless

Please provide fuller logs and instructions on what your test case

> 
> the dest VM:
> (qemu) (/usr/libexec/qemu-kvm:2353): Spice-Warning **:
> reds.c:2718:reds_handle_read_link_done: spice channels 1 should be encrypted
> (/usr/libexec/qemu-kvm:2353): Spice-Warning **:
> reds.c:2819:reds_handle_ssl_accept: SSL_accept failed, error=5

That shouldn't happen I guess.


> the source VM:
seems not much interesting there

> main_channel_client_handle_migrate_connected: client 0x7fcecdc28970
> connected: 0 seamless 0
> (qemu) red_channel_client_disconnect: rcc=0x7fcece146690
> (channel=0x7fcecdb99c10 type=3 id=0)
> red_channel_client_disconnect: rcc=0x7fceccf80010 (channel=0x7fce7421f350
> type=2 id=0)
> red_channel_client_disconnect: rcc=0x7fce7426c630 (channel=0x7fce7421f920
> type=4 id=0)
> red_channel_client_disconnect: rcc=0x7fcece137e20 (channel=0x7fcecdb8eb50
> type=1 id=0)
> main_channel_client_on_disconnect: rcc=0x7fcece137e20
> red_client_destroy: destroy client 0x7fcecdc28970 with #channels=4
> red_dispatcher_disconnect_cursor_peer: 
> red_dispatcher_disconnect_display_peer:
> 
> Note that both VMs were on the same host.

Comment 14 Tomas Jamrisko 2014-04-24 10:26:53 UTC
(In reply to Marc-Andre Lureau from comment #11)
> 
> Please provide fuller logs and instructions on what your test case

Attached some logs.

Instructions -- Run a VM: 
/usr/libexec/qemu-kvm -m 1024 -spice port=5967,tls-port=5968,addr=10.34.73.134,x509-dir=/etc/pki/vdsm/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 -monitor stdio

set a ticket using monitor, connect to it, run a second VM:

/usr/libexec/qemu-kvm -m 1024 -spice port=5967,tls-port=5968,addr=10.34.73.134,x509-dir=/etc/pki/vdsm/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 -monitor stdio -incoming tcp::4445

set the same ticket, send client_migrate_info from source (port, tls-port, host subject)

--this is where it falls back to switch-host

start migration. 

It migrates and swiches hosts without RHEVM. 
(going to check if libvirt actually sets the same password)

Comment 15 Marc-Andre Lureau 2014-04-24 12:24:32 UTC
hm, it seems to work fine with fedora.. here is what I do:

qemu-kvm -m 1024 -spice port=5967,tls-port=5968,x509-dir=/home/elmarco/tmp,tls-channel=main,tls-channel=display,tls-channel=inputs,tls-channel=cursor,tls-channel=playback,tls-channel=record,tls-channel=usbredir,seamless-migration=on -monitor stdio

qemu-kvm -m 1024 -spice port=5969,tls-port=5970,x509-dir=/home/elmarco/tmp,tls-channel=main,tls-channel=display,tls-channel=inputs,tls-channel=cursor,tls-channel=playback,tls-channel=record,tls-channel=usbredir,seamless-migration=on -monitor stdio -incoming tcp::4445

In both qemu:
(qemu) set_password spice pass


Connect with client:
SPICE_DEBUG=1 gtk/spicy -s 5968 --spice-ca-file=/home/elmarco/tmp/ca-cert.pem  --spice-host-subject="$SUBJECT"

and enter pass 

Then in source qemu:
(qemu) client_migrate_info spice localhost 5969 5970 "C=IL, L=Raanana, O=Red Hat, CN=192.168.1.42"
(qemu) migrate -d tcp:localhost:4445

all seems to work...

Can you try this on rhel6?

Comment 16 Marc-Andre Lureau 2014-04-24 12:26:47 UTC
in the meantime, I will be trying with the same windows client version.

Comment 17 Christophe Fergeau 2014-04-24 12:55:27 UTC
I've managed to reproduce it once with the 3.4 win client and migrations handled by rhevm 3.4

Comment 18 Marc-Andre Lureau 2014-04-24 13:07:42 UTC
(In reply to Marc-Andre Lureau from comment #16)
> in the meantime, I will be trying with the same windows client version.

same test as comment 15 worked with mingw-virt-viewer-0.5.6-21.el6_5 (with a critical that can be ignored for now)

Comment 29 errata-xmlrpc 2014-06-09 12:51:25 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.

http://rhn.redhat.com/errata/RHBA-2014-0644.html


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