Bug 868766

Summary: fail to do live migration with virt-viewer + usb redirection (seamless-migration=on)
Product: Red Hat Enterprise Linux 6 Reporter: Sibiao Luo <sluo>
Component: spice-serverAssignee: Hans de Goede <hdegoede>
Status: CLOSED NOTABUG QA Contact: Desktop QE <desktop-qa-list>
Severity: medium Docs Contact:
Priority: medium    
Version: 6.4CC: acathrow, cfergeau, chayang, dblechte, dyasny, flang, hdegoede, juzhang, marcandre.lureau, michen, mkenneth, qzhang, shuang, xfu
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2012-12-05 08:10:00 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
capture all usb-redir log of src qemu as your indication using debug=4
none
capture all usb-redir log of dest qemu as your indication using debug=4
none
source log
none
destination log.
none
src-qemu-log.
none
dest-qemu-log.
none
the dmest of guest.
none
the output logs of I/O action.
none
bug868766-src-qemu-logs.
none
bug868766-dest-qemu-logs.
none
guest-dmesg.
none
dd-logs. none

Description Sibiao Luo 2012-10-22 05:30:41 UTC
Description of problem:
install virt-viewer package in host, boot a guest with usb redirection (seamless-migration=on) and do dd to the usb disk in loop, then do live migration with 'remote-viewer spice://$host_ip:$port' to connect guest desktop, it fail to dd with 'Input/output error' in guest and 'sd 2:0:0:0: [sda] Unhandled error code' in guest kernel log.

Version-Release number of selected component (if applicable):
# uname -r && rpm -q qemu-kvm
2.6.32-331.el6.x86_64
qemu-kvm-0.12.1.2-2.327.el6.x86_64
virt-viewer-0.5.2-14.el6.x86_64
spice-gtk-0.14-4.el6.x86_64
guest info:
# uname -r
2.6.32-331.el6.x86_64

How reproducible:
100%

Steps to Reproduce:
1.boot guest with usb redirection and seamless-migration=on in src and '-incoming tcp:0:5888' in dst.
eg: # /usr/libexec/qemu-kvm -M rhel6.4.0 -cpu SandyBridge -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1,maxcpus=6 -usb -device usb-tablet,id=input0 -name sluo_migration -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x3 -drive file=/dev/vg-90.100-sluo/lv-90.100-migration-macvtap,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x4,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,id=hostnet0,vhost=on,fd=3 3<>/dev/tap3 -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x5 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -spice port=5931,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -device intel-hda,id=sound0,bus=pci.0,addr=0x6 -device hda-duplex -device usb-ehci,id=ehci,addr=0x7 -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=3 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x8 -drive file=/dev/vg-90.100-sluo/lv-90.100-data-disk,if=none,id=data-disk,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x9,drive=data-disk,id=sluo-disk -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0 -drive file=/mnt/RHEL6.3-20120613.2-Server-x86_64-DVD1.iso,if=none,media=cdrom,format=raw,id=drive-ide1-0-1 -device ide-drive,drive=drive-ide1-0-1,id=ide1-0-1,bus=ide.1,unit=1 -drive file=/mnt/floppy.vfd,if=none,id=drive-fdc0-0-0,format=raw -global isa-fdc.driveA=drive-fdc0-0-0 -nodefaults -serial unix:/tmp/ttyS0,server,nowait -qmp tcp:0:4444,server,nowait -boot menu=on -monitor stdio
2.Connect guest desktop with remote-viewer tools (provided by virt-viewer)
3.plug a USB disk to USB host, and click on menubar -> 'File' -> 'USB Device selection'.
# lsusb | grep Kingston
Bus 002 Device 007: ID 0951:1642 Kingston Technology DT101 G2
4.mkfs.ext4 the the usb-disk and mount it to /mnt.
5.do I/O to the mount target.
# cat script.sh 
while true
do
  dd if=/dev/zero of=/mnt/sluo bs=1M count=100
  rm -f /mnt/sluo
done
6.do live migrate
(qemu) __com.redhat_spice_migrate_info $dst_host_ip $dst_host_port
main_channel_client_handle_migrate_connected: client 0x7ffff99aef80 connected: 1 seamless 1
(qemu) migrate -d tcp:$dst_host_ip:$port

Actual results:
after step 6, 
the src migration completed and the dst in running status, but there are flooding with 'dd: opening `/mnt/sluo': Input/output error' in geust. 
# sh script.sh 
...
100+0 records in
100+0 records out
104857600 bytes (105 MB) copied, 0.0872394 s, 1.2 GB/s
100+0 records in
100+0 records out
104857600 bytes (105 MB) copied, 0.0864387 s, 1.2 GB/s
100+0 records in
100+0 records out
104857600 bytes (105 MB) copied, 0.0842231 s, 1.2 GB/s
100+0 records in
100+0 records out
104857600 bytes (105 MB) copied, 0.0865455 s, 1.2 GB/s
100+0 records in
100+0 records out
104857600 bytes (105 MB) copied, 0.086778 s, 1.2 GB/s
dd: opening `/mnt/sluo': Input/output error
dd: opening `/mnt/sluo': Input/output error
dd: opening `/mnt/sluo': Input/output error
dd: opening `/mnt/sluo': Input/output error
dd: opening `/mnt/sluo': Input/output error
dd: opening `/mnt/sluo': Input/output error
dd: opening `/mnt/sluo': Input/output error
dd: opening `/mnt/sluo': Input/output error
...

and the guest kernel log as following:
# nc -U /tmp/ttyS0 
usb 1-1: USB disconnect, device number 2
sd 2:0:0:0: [sda] Unhandled error code
sd 2:0:0:0: [sda] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
sd 2:0:0:0: [sda] CDB: Read(10): 28 00 00 00 29 98 00 00 01 00
FAT: FAT read failed (blocknr 10616)
FAT: FAT read failed (blocknr 10616)
FAT: unable to read inode block for updating (i_pos 473605)
FAT: Directory bread(block 29600) failed
FAT: bread failed in fat_clusters_flush
FAT: bread failed in fat_clusters_flush
FAT: unable to read inode block for updating (i_pos 473605)
FAT: FAT read failed (blocknr 10616)
FAT: Directory bread(block 29600) failed
FAT: Directory bread(block 29601) failed
FAT: Directory bread(block 29602) failed
FAT: Directory bread(block 29603) failed
FAT: Directory bread(block 29604) failed
FAT: Directory bread(block 29605) failed
...

Expected results:
It should complete migration successfully without any error, and the I/O is still continue without any error.

Additional info:

Comment 1 Sibiao Luo 2012-10-22 05:35:44 UTC
(In reply to comment #0)
> Description of problem:
> install virt-viewer package in host, boot a guest with usb redirection
> (seamless-migration=on) and do dd to the usb disk in loop, then do live
> migration with 'remote-viewer spice://$host_ip:$port' to connect guest
> desktop, it fail to dd with 'Input/output error' in guest and 'sd 2:0:0:0:
> [sda] Unhandled error code' in guest kernel log.
> 
> 5.do I/O to the mount target.
> # cat script.sh 
> while true
> do
>   dd if=/dev/zero of=/mnt/sluo bs=1M count=100
>   rm -f /mnt/sluo
> done
>
If do not do I/O in this steps and do migration, we can select it manually on menubar -> 'File' -> 'USB Device selection' after migration, but it cann't add it automatically, i donot think this is the meaning of migration.


Append my host cpu info:

processor	: 7
vendor_id	: GenuineIntel
cpu family	: 6
model		: 42
model name	: Intel(R) Core(TM) i7-2600 CPU @ 3.40GHz
stepping	: 7
cpu MHz		: 1600.000
cache size	: 8192 KB
physical id	: 0
siblings	: 8
core id		: 3
cpu cores	: 4
apicid		: 7
initial apicid	: 7
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx rdtscp lm constant_tsc arch_perfmon pebs bts rep_good xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm ida arat epb xsaveopt pln pts dts tpr_shadow vnmi flexpriority ept vpid
bogomips	: 6784.25
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual
power management:

Comment 3 Marc-Andre Lureau 2012-10-22 10:19:23 UTC
Hi, this is a known issue that is being resolved in qemu (& perhaps also spice server). I guess we already have a bug open for it.

Comment 4 Hans de Goede 2012-10-22 17:56:34 UTC
Hi,

(In reply to comment #3)
> Hi, this is a known issue that is being resolved in qemu (& perhaps also
> spice server). I guess we already have a bug open for it.

I disagree, I think you're confusing this issue with the "Don-t-make-migration-fail-in-none-seamless"
patches for qemu / spice-gtk, but these should not impact seamless migration, which is what is happening here.  Sibiao can you please provide the console output of both the src and dest qemu ? And also do info usb on the destination after the migration ?

Thanks & Regards,

Hans

Comment 5 Sibiao Luo 2012-10-23 04:48:28 UTC
(In reply to comment #4)
> Hi,
> 
> (In reply to comment #3)
> > Hi, this is a known issue that is being resolved in qemu (& perhaps also
> > spice server). I guess we already have a bug open for it.
> 
> I disagree, I think you're confusing this issue with the
> "Don-t-make-migration-fail-in-none-seamless"
> patches for qemu / spice-gtk, but these should not impact seamless
> migration, which is what is happening here.  Sibiao can you please provide
> the console output of both the src and dest qemu ? And also do info usb on
> the destination after the migration ?
> 
Hans, 

   Thanks for your kindly reminds, i will paste the info here.

- In usb host(spice client):
# lsusb | grep Kingston
Bus 001 Device 002: ID 0951:1642 Kingston Technology DT101 G2

- Before migraton:
1.the src of QEMU:
(qemu) info usb
  Device 0.2, Port 1, Speed 12 Mb/s, Product QEMU USB Tablet
  Device 1.0, Port 1, Speed 1.5 Mb/s, Product USB Redirection Device
(qemu) info usbhost 
husb: using sys file-system with /dev/bus/usb
  Bus 1, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 2, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 1, Addr 3, Port 1.3, Speed 12 Mb/s
    Hub: USB device 0557:7000
  Bus 1, Addr 4, Port 1.3.1, Speed 1.5 Mb/s
    Class 00: USB device 0557:2213, CS-1734A V4.2.414
  Bus 2, Addr 3, Port 1.7, Speed 480 Mb/s
    Class 00: USB device 0951:1642, DT 101 G2
(qemu) 
(qemu) qemu-kvm: usb-redir: attaching high speed device 0951:1642 version 1.0 class 00
(qemu) info usb
  Device 0.2, Port 1, Speed 12 Mb/s, Product QEMU USB Tablet
  Device 1.2, Port 1, Speed 480 Mb/s, Product USB Redirection Device
(qemu) info usbhost
  Bus 1, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 2, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 1, Addr 3, Port 1.3, Speed 12 Mb/s
    Hub: USB device 0557:7000
  Bus 1, Addr 4, Port 1.3.1, Speed 1.5 Mb/s
    Class 00: USB device 0557:2213, CS-1734A V4.2.414
  Bus 2, Addr 3, Port 1.7, Speed 480 Mb/s
    Class 00: USB device 0951:1642, DT 101 G2
2.the dest of QEMU:
(qemu) info usb
  Device 0.0, Port 1, Speed 12 Mb/s, Product QEMU USB Tablet
  Device 1.0, Port 1, Speed 1.5 Mb/s, Product USB Redirection Device
(qemu) info usbhost
husb: using sys file-system with /dev/bus/usb
  Bus 1, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 2, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 1, Addr 3, Port 1.3, Speed 12 Mb/s
    Hub: USB device 0557:7000
  Bus 1, Addr 4, Port 1.3.1, Speed 1.5 Mb/s
    Class 00: USB device 0557:2213, CS-1734A V4.2.414

- After migraton:
1.the src of QEMU:
(qemu) info migrate 
Migration status: completed
(qemu) info usb
  Device 0.2, Port 1, Speed 12 Mb/s, Product QEMU USB Tablet
  Device 1.0, Port 1, Speed 1.5 Mb/s, Product USB Redirection Device
(qemu) info usbhost 
  Bus 1, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 2, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 1, Addr 3, Port 1.3, Speed 12 Mb/s
    Hub: USB device 0557:7000
  Bus 1, Addr 4, Port 1.3.1, Speed 1.5 Mb/s
    Class 00: USB device 0557:2213, CS-1734A V4.2.414
  Bus 2, Addr 3, Port 1.7, Speed 480 Mb/s
    Class 00: USB device 0951:1642, DT 101 G2
2.the dest of QEMU:
(qemu) info status 
VM status: running
(qemu) info usb
  Device 0.2, Port 1, Speed 12 Mb/s, Product QEMU USB Tablet
  Device 1.0, Port 1, Speed 1.5 Mb/s, Product USB Redirection Device
(qemu) info usbhost 
  Bus 1, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 2, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 1, Addr 3, Port 1.3, Speed 12 Mb/s
    Hub: USB device 0557:7000
  Bus 1, Addr 4, Port 1.3.1, Speed 1.5 Mb/s
    Class 00: USB device 0557:2213, CS-1734A V4.2.414
(qemu)

--------------------------------------------------------------------------

BTW: If i cancel the I/O in dest guest after migration, and select the USB disk manually on menubar -> 'File' -> 'USB Device selection', the QEMU info as following:
(qemu) qemu-kvm: usb-redir: attaching high speed device 0951:1642 version 1.0 class 00
(qemu) info usb
  Device 0.2, Port 1, Speed 12 Mb/s, Product QEMU USB Tablet
  Device 1.3, Port 1, Speed 480 Mb/s, Product USB Redirection Device
(qemu) info usbhost
  Bus 1, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 2, Addr 2, Port 1, Speed 480 Mb/s
    Hub: USB device 8087:0024
  Bus 1, Addr 3, Port 1.3, Speed 12 Mb/s
    Hub: USB device 0557:7000
  Bus 1, Addr 4, Port 1.3.1, Speed 1.5 Mb/s
    Class 00: USB device 0557:2213, CS-1734A V4.2.414

Best Regards.
sluo

Comment 6 Hans de Goede 2012-10-29 13:59:47 UTC
I just tried to reproduce this with qemu-kvm-0.12.1.2-2.331.el6.x86_64 and the seamless migration while running dd to / from a USB-disk works fine for me.

Note that the destination qemu process must be *running* and *ready* when you do the __com.redhat_spice_migrate_info $dst_host_ip $dst_host_port command.

When I was asking for the qemu console output for the destination I was not talking about the info commands you listed in comment #5. But about the regular output. As soon as you give the _com.redhat_spice_migrate_info $dst_host_ip $dst_host_port command in the source qemu, you should see messages like this in the destination qemu, even *before* you give the actual migrate command:

QEMU 0.12.1 monitor - type 'help' for more information
(qemu)
main_channel_link: add main channel client
red_dispatcher_set_cursor_peer: 
inputs_connect: inputs channel client create

If you do not see these messages in the destination qemu *before* you give the actual migrate command, the migration is not seamless!

Also the USB command line options you are using are not correct, they should work, but they are not how the new USB is supposed to be used. The "-usb" on the cmdline creates a single uhci controller, only doing USB-1 and the "-device usb-ehci,id=ehci,addr=0x7" creates a *second* USB bus only doing USB-2, since you specify the ehci bus for the usb-redir device this works for the USB-disk you're testing with, but won't work if you try to use any USB-1 only devices.

The proper way to create a single USB-1 and USB-2 capable USB bus is to create an ehci controller with companion controllers for USB-1. This can be done easiest by downloading:
http://cgit.freedesktop.org/spice/qemu/plain/docs/ich9-ehci-uhci.cfg
Saving it as /etc/qemu/ich9-ehci-uhci.cfg and adding "-readconfig /etc/qemu/ich9-ehci-uhci.cfg" to the qemu cmdline before the first usb-device, so before the usbtablet. You then also need to remove the "-usb" and "-device usb-ehci,id=ehci,addr=0x7" cmdline options, as well as the bus option for the usb-redir device.

If you still have issues with seamless migration, please change the debug option to the usb-redir to debug=4 and post the console output from the destination qemu from before and immediately after the migration.

Comment 7 Sibiao Luo 2012-10-30 09:48:19 UTC
(In reply to comment #6)
> I just tried to reproduce this with qemu-kvm-0.12.1.2-2.331.el6.x86_64 and
> the seamless migration while running dd to / from a USB-disk works fine for
> me.
> 
> Note that the destination qemu process must be *running* and *ready* when
> you do the __com.redhat_spice_migrate_info $dst_host_ip $dst_host_port
> command.
> 
> When I was asking for the qemu console output for the destination I was not
> talking about the info commands you listed in comment #5. But about the
> regular output. As soon as you give the _com.redhat_spice_migrate_info
> $dst_host_ip $dst_host_port command in the source qemu, you should see
> messages like this in the destination qemu, even *before* you give the
> actual migrate command:
> 
> QEMU 0.12.1 monitor - type 'help' for more information
> (qemu)
> main_channel_link: add main channel client
> red_dispatcher_set_cursor_peer: 
> inputs_connect: inputs channel client create
> 
> If you do not see these messages in the destination qemu *before* you give
> the actual migrate command, the migration is not seamless!
yes, I see the message in dst qemu.
- src qemu:
(qemu) __com.redhat_spice_migrate_info 10.66.11.229 5931
main_channel_client_handle_migrate_connected: client 0x7ffff8b0ff80 connected: 1 seamless 
- dst qemu:
(qemu) 
main_channel_link: add main channel client
red_dispatcher_set_cursor_peer: 
inputs_connect: inputs channel client create

> Also the USB command line options you are using are not correct, they should
> work, but they are not how the new USB is supposed to be used. The "-usb" on
> the cmdline creates a single uhci controller, only doing USB-1 and the
> "-device usb-ehci,id=ehci,addr=0x7" creates a *second* USB bus only doing
> USB-2, since you specify the ehci bus for the usb-redir device this works
> for the USB-disk you're testing with, but won't work if you try to use any
> USB-1 only devices.
> 
> The proper way to create a single USB-1 and USB-2 capable USB bus is to
> create an ehci controller with companion controllers for USB-1. This can be
> done easiest by downloading:
> http://cgit.freedesktop.org/spice/qemu/plain/docs/ich9-ehci-uhci.cfg
> Saving it as /etc/qemu/ich9-ehci-uhci.cfg and adding "-readconfig
> /etc/qemu/ich9-ehci-uhci.cfg" to the qemu cmdline before the first
> usb-device, so before the usbtablet. You then also need to remove the "-usb"
> and "-device usb-ehci,id=ehci,addr=0x7" cmdline options, as well as the bus
> option for the usb-redir device.
>
> If you still have issues with seamless migration, please change the debug
> option to the usb-redir to debug=4 and post the console output from the
> destination qemu from before and immediately after the migration.
yes, i retest it as your instruction that use the ich9-ehci-uhci.cfg configure file, it can do migration successfully without any error and the I/O script is still continue without any error.

btw, if remove the '-usb -device usb-tablet,id=input0', just use the 'usb-ehci' for the usb-redir disk and specify the ehci bus for the usb-redir device, this issue also gone. this issue maybe is that the USB-disk confusion between '-usb' and 'usb-ehci' after migration. does we must use the ich9-ehci-uhci.cfg configure file when we add multi-usb? maybe can do good for it.

Best Regards.
sluo

Comment 8 Hans de Goede 2012-10-30 10:27:24 UTC
(In reply to comment #7)
> > If you still have issues with seamless migration, please change the debug
> > option to the usb-redir to debug=4 and post the console output from the
> > destination qemu from before and immediately after the migration.
> yes, i retest it as your instruction that use the ich9-ehci-uhci.cfg
> configure file, it can do migration successfully without any error and the
> I/O script is still continue without any error.
> 

Good!

> btw, if remove the '-usb -device usb-tablet,id=input0', just use the
> 'usb-ehci' for the usb-redir disk and specify the ehci bus for the usb-redir
> device, this issue also gone.

Also good :)

> this issue maybe is that the USB-disk
> confusion between '-usb' and 'usb-ehci' after migration. does we must use
> the ich9-ehci-uhci.cfg configure file when we add multi-usb? maybe can do
> good for it.

Hmm, live migration should work fine with multiple usb busses. I just tested
with the following cmdline:

exec sudo gdb -ex "handle SIGUSR2 nostop noprint" -ex run --args \
 /usr/libexec/qemu-kvm -enable-kvm \
 -m 1024 -name F14-x86_64 -boot menu=on \
 -usb -device usb-tablet,id=input0 \
 -drive file=/home/virt-images/f14-i386.qcow2.img,media=disk,index=0 \
 -net nic,macaddr=52:54:00:7a:b4:7e,vlan=0,model=virtio,name=virtio.0 -net user,vlan=0 \
 -vga qxl -spice port=$port,disable-ticketing,streaming-video=off,image-compression=off,seamless-migration=on \
 -device virtio-serial -chardev spicevmc,id=vdagent,debug=1,name=vdagent -device virtserialport,chardev=vdagent,name=com.redhat.spice.0 \
 -chardev spicevmc,name=usbredir,id=usbredirchardev1,debug=0 \
 -device usb-ehci,id=ehci,addr=0x7 \
 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,debug=4,filter='0x08:-1:-1:-1:1|-1:-1:-1:-1:1',bus=ehci.0 \
 -chardev spicevmc,name=usbredir,id=usbredirchardev2,debug=0 \
 -device usb-redir,chardev=usbredirchardev2,id=usbredirdev2,debug=4,filter='0x08:-1:-1:-1:1|-1:-1:-1:-1:1',bus=ehci.0 \
 -chardev spicevmc,name=usbredir,id=usbredirchardev3,debug=0 \
 -device usb-redir,chardev=usbredirchardev3,id=usbredirdev3,debug=4,filter='0x08:-1:-1:-1:1|-1:-1:-1:-1:1',bus=ehci.0 \
 -monitor stdio -soundhw ac97 $incoming "$@"

And it works fine. Are you sure you were using the exact same cmdline (other then the incoming argument) on both sides ?

Comment 9 Sibiao Luo 2012-11-05 07:10:15 UTC
(In reply to comment #7)
> (In reply to comment #6)
> yes, i retest it as your instruction that use the ich9-ehci-uhci.cfg
> configure file, it can do migration successfully without any error and the
> I/O script is still continue without any error.
> 
> btw, if remove the '-usb -device usb-tablet,id=input0', just use the
> 'usb-ehci' for the usb-redir disk and specify the ehci bus for the usb-redir
> device, this issue also gone. this issue maybe is that the USB-disk
> confusion between '-usb' and 'usb-ehci' after migration. does we must use
> the ich9-ehci-uhci.cfg configure file when we add multi-usb? maybe can do
> good for it.
> 

hi hans, 

   Maybe make mistake that i did not mount it successfully during my test, so i should correct my description. This issue is very simple reproduce, no matter use uhci & ehci controller or just only use ehci controller, or use the ich9-ehci-uhci.cfg configure file, the details as following:
+--------------------+-----------------+
| test type          |   test result   |
+--------------------+-----------------+
| 1 uhci + 1 ehci    |      fail       |
+--------------------+-----------------+
| only 1 ehci        |      fail       |
+--------------------+-----------------+
| just 2 ehci        |      fail       |
+--------------------+-----------------+
| ich9-ehci-uhci.cfg |      fail       |
+--------------------+-----------------+

I retest that use the uhci and ehci controller and enable multifunction with the  ich9-ehci-uhci.cfg configure file. it still hit this issue, i will list command-lines/results details when use ich9-ehci-uhci.cfg:
host info:
kernel-2.6.32-335.el6.x86_64
qemu-kvm-0.12.1.2-2.331.el6.x86_64
seabios-0.6.1.2-25.el6.x86_64
spice-server-0.12.0-1.el6.x86_64
spice-gtk-0.14-5.el6.x86_64
virt-viewer-0.5.2-14.el6.x86_64
guest info:
# uname -r
kernel-2.6.32-335.el6.x86_64

Steps:
same as comment #0

Actual results:
1.the console output of both the src and dest qemu.
- src:
(qemu) __com.redhat_spice_migrate_info 10.66.11.229 5931
main_channel_client_handle_migrate_connected: client 0x7ff3f45a67c0 connected: 1 seamless 1
- dest:
QEMU 0.12.1 monitor - type 'help' for more information
(qemu) main_channel_link: add main channel client
red_dispatcher_set_cursor_peer: 
inputs_connect: inputs channel client create

2.after step 6, 
the src migration completed and the dest in running status, but there are flooding with 'Input/output error' in geust, and there are many 'FAT: Directory bread(block 29600) failed' in guest kernel log. 
# sh script.sh
...
209715200 bytes (210 MB) copied, 2.00116 s, 105 MB/s
dd: writing `/mnt/sluo': Input/output error
139+0 records in
138+0 records out
145293312 bytes (145 MB) copied, 4.0682 s, 35.7 MB/s
dd: writing `/mnt/sluo': Input/output error
1+0 records in
0+0 records out
0 bytes (0 B) copied, 0.00117982 s, 0.0 kB/s
dd: writing `/mnt/sluo': Input/output error
1+0 records in
0+0 records out
0 bytes (0 B) copied, 0.000870856 s, 0.0 kB/s
dd: writing `/mnt/sluo': Input/output error
1+0 records in
0+0 records out
0 bytes (0 B) copied, 0.00214304 s, 0.0 kB/s
dd: writing `/mnt/sluo': Input/output error
1+0 records in
0+0 records out
0 bytes (0 B) copied, 0.000734393 s, 0.0 kB/s
dd: writing `/mnt/sluo': Input/output error
1+0 records in
0+0 records out
...
# dmesg 
usb 1-2: USB disconnect, device number 3
sd 2:0:0:0: [sda] Unhandled error code
sd 2:0:0:0: [sda] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
sd 2:0:0:0: [sda] CDB: Read(10): 28 00 00 00 31 e6 00 00 01 00
FAT: FAT read failed (blocknr 12742)
FAT: FAT read failed (blocknr 12742)
FAT: FAT read failed (blocknr 12742)
FAT: FAT read failed (blocknr 12742)
FAT: FAT read failed (blocknr 12742)
FAT: FAT read failed (blocknr 12742)
FAT: FAT read failed (blocknr 12742)
FAT: FAT read failed (blocknr 12742)
FAT: FAT read failed (blocknr 12742)
FAT: FAT read failed (blocknr 12742)
FAT: Directory bread(block 29600) failed
FAT: Directory bread(block 29600) failed
FAT: Directory bread(block 29600) failed
FAT: FAT read failed (blocknr 12742)
FAT: Directory bread(block 29600) failed
FAT: Directory bread(block 29600) failed
...

Qemu-kvm-command-lines:
- src: # /usr/libexec/qemu-kvm -M rhel6.4.0 -cpu SandyBridge -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1 -readconfig /mnt/ich9-ehci-uhci.cfg -device usb-tablet,id=input0 -name sluo_migration -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x3 -drive file=/dev/vg-90.100-sluo/lv-rhel6.4-guest,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x4,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x5 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -spice port=5931,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -device intel-hda,id=sound0,bus=pci.0,addr=0x6 -device hda-duplex -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=3 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x7 -drive file=/dev/vg-90.100-sluo/lv-90.100-data-disk,if=none,id=data-disk,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x8,drive=data-disk,id=sluo-disk -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0 -nodefaults -serial unix:/tmp/ttyS0,server,nowait -qmp tcp:0:4444,server,nowait -boot menu=on -monitor stdio

- dest: just append '-incoming tcp:0:5888,server,nowait', others are same to the src.

Best Regards.
sluo

Comment 10 Sibiao Luo 2012-11-05 07:16:31 UTC
(In reply to comment #9)
> 
> I retest that use the uhci and ehci controller and enable multifunction with
> the  ich9-ehci-uhci.cfg configure file. it still hit this issue, i will list
> command-lines/results details when use ich9-ehci-uhci.cfg:

I list the usb-redir info from dest qemu after migration, maybe the USB-stick fail to migrate, the speed is wrong, it should be 'addr 0.0, port 2, speed 480, name USB Redirection Device, attached'.
(qemu) info status 
VM status: running
(qemu) info qtree
...
      dev: ich9-usb-ehci1, id "ehci"
        dev-prop: freq = 1000
        dev-prop: maxframes = 128
        bus-prop: addr = 1d.7
        bus-prop: romfile = <null>
        bus-prop: rombar = 1
        bus-prop: multifunction = on
        class USB controller, addr 00:1d.7, pci id 8086:293a (sub 1af4:1100)
        bar 0: mem at 0xf4045000 [0xf4045fff]
        bus: ehci.0
          type USB
          dev: usb-redir, id "usbredirdev1"
            dev-prop: chardev = usbredirchardev1
            dev-prop: debug = 3
            dev-prop: filter = <null>
            bus-prop: port = <null>
            bus-prop: create_unique_serial = 1
            addr 0.0, port 2, speed 1.5, name USB Redirection Device <---wrong
          dev: usb-tablet, id "input0"
            dev-prop: migrate = 1
            bus-prop: port = <null>
            bus-prop: create_unique_serial = 1
            addr 0.2, port 1, speed 12, name QEMU USB Tablet, attached
...

Comment 11 Hans de Goede 2012-11-05 23:25:55 UTC
I notice in comment #9 that the "-device usb-tablet,id=input0" is back on the cmdline, can you please try without this on the cmdline?

Also can you change the debug=3 to debug=4 for the usb-redir device, and when you quote qemu console output, please include the full output and not only the last few lines.

Thanks,

Hans

Comment 12 Sibiao Luo 2012-11-06 03:22:54 UTC
(In reply to comment #11)
> I notice in comment #9 that the "-device usb-tablet,id=input0" is back on
> the cmdline, can you please try without this on the cmdline? 
> Also can you change the debug=3 to debug=4 for the usb-redir device, and
> when you quote qemu console output, please include the full output and not
> only the last few lines.
> 
I remove "-device usb-tablet,id=input0" from command line and with debug=3 for the usb-redir device, and still hit this issue with the same steps, there are flooding with 'Input/output error' in geust, and many 'FAT: Directory bread(block 29600) failed' in guest kernel log. 

# /usr/libexec/qemu-kvm -M rhel6.4.0 -cpu SandyBridge -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1 -name sluo_migration -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -drive file=/dev/vg-90.100-sluo/lv-rhel6.4-guest,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x3,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x4 -spice port=5931,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -readconfig /mnt/ich9-ehci-uhci.cfg -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=3 -boot menu=on -monitor stdio
QEMU 0.12.1 monitor - type 'help' for more information
(qemu) main_channel_link: add main channel client
main_channel_handle_parsed: net test: latency 0.265000 ms, bitrate 6168674698 bps (5882.906626 Mbps)
qemu-kvm: usbredirparser: Peer version: spice-gtk 0.14, using 64-bits ids

inputs_connect: inputs channel client create
red_dispatcher_set_cursor_peer: 
qemu-kvm: usb-redir: attaching high speed device 0951:1642 version 1.0 class 00

(qemu) info status 
VM status: running
(qemu) info usb
  Device 0.0, Port 1, Speed 480 Mb/s, Product USB Redirection Device      
(qemu) __com.redhat_spice_migrate_info 10.66.11.229 5931
main_channel_client_handle_migrate_connected: client 0x7fb0e5ab65d0 connected: 1 seamless 1
(qemu) mig
migrate               migrate_cancel        migrate_set_speed     
migrate_set_downtime  
(qemu) migrate -d tcp:10.66.11.229:5888
(qemu) info migrate 
Migration status: active
transferred ram: 67395 kbytes
remaining ram: 3644088 kbytes
total ram: 4325776 kbytes
(qemu) info migrate 
Migration status: active
transferred ram: 2263229 kbytes
remaining ram: 182880 kbytes
total ram: 4325776 kbytes
(qemu) 
(qemu) info migrate 
Migration status: active
transferred ram: 6319146 kbytes
remaining ram: 195032 kbytes
total ram: 4325776 kbytes
(qemu) red_client_migrate: migrate client with #channels 5
red_dispatcher_cursor_migrate: channel type 4 id 0
red_dispatcher_display_migrate: channel type 2 id 0
red_channel_client_disconnect: 0x7fb0c026ec20 (channel 0x7fb0c021d670 type 4 id 0)
red_channel_client_disconnect: 0x7fb0e6f0cb60 (channel 0x7fb0e5a096f0 type 3 id 0)
red_channel_client_disconnect: 0x7fb0d84e9010 (channel 0x7fb0c021d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7fb0e6ef6720 (channel 0x7fb0e6e9f140 type 9 id 0)
red_channel_client_disconnect: 0x7fb0e6ef6720 (channel 0x7fb0e6e9f140 type 9 id 0)
red_channel_client_disconnect: 0x7fb0e6ef02e0 (channel 0x7fb0e59ff5f0 type 1 id 0)
main_channel_client_on_disconnect: rcc=0x7fb0e6ef02e0
red_client_destroy: destroy client with #channels 4
red_dispatcher_disconnect_cursor_peer: 
red_channel_client_disconnect: 0x7fb0c026ec20 (channel 0x7fb0c021d670 type 4 id 0)
red_channel_client_disconnect: 0x7fb0c026ec20 (channel 0x7fb0c021d670 type 4 id 0)
red_channel_client_disconnect: 0x7fb0e6f0cb60 (channel 0x7fb0e5a096f0 type 3 id 0)
red_channel_client_disconnect: 0x7fb0e6f0cb60 (channel 0x7fb0e5a096f0 type 3 id 0)
red_dispatcher_disconnect_display_peer: 
red_channel_client_disconnect: 0x7fb0d84e9010 (channel 0x7fb0c021d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7fb0d84e9010 (channel 0x7fb0c021d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7fb0e6ef02e0 (channel 0x7fb0e59ff5f0 type 1 id 0)
red_channel_client_disconnect: 0x7fb0e6ef02e0 (channel 0x7fb0e59ff5f0 type 1 id 0)

(qemu) info migrate 
Migration status: completed
(qemu) info status 
VM status: paused (post-migrate)


The same command line appending with '-incoming tcp:0:5888,server,nowait' in dest.
(qemu) info status 
VM status: paused (incoming-migration)
(qemu) main_channel_link: add main channel client
red_dispatcher_set_cursor_peer: 
inputs_connect: inputs channel client create

(qemu) red_dispatcher_loadvm_commands: 

(qemu) info status 
VM status: running
(qemu) red_channel_client_disconnect: 0x7f7154c05010 (channel 0x7f703021d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7f71674cdb20 (channel 0x7f7167470140 type 9 id 0)
red_channel_client_disconnect: 0x7f71674cdb20 (channel 0x7f7167470140 type 9 id 0)
red_channel_client_disconnect: 0x7f71674c7720 (channel 0x7f7165fda730 type 3 id 0)
red_channel_client_disconnect: 0x7f71674c12e0 (channel 0x7f7165fd0610 type 1 id 0)
main_channel_client_on_disconnect: rcc=0x7f71674c12e0
red_client_destroy: destroy client with #channels 4
red_channel_client_disconnect: 0x7f71674c7720 (channel 0x7f7165fda730 type 3 id 0)
red_channel_client_disconnect: 0x7f71674c7720 (channel 0x7f7165fda730 type 3 id 0)
red_dispatcher_disconnect_display_peer: 
red_channel_client_disconnect: 0x7f7154c05010 (channel 0x7f703021d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7f7154c05010 (channel 0x7f703021d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7f7030221600 (channel 0x7f703021d670 type 4 id 0)
red_dispatcher_disconnect_cursor_peer: 
red_channel_client_disconnect: 0x7f7030221600 (channel 0x7f703021d670 type 4 id 0)
red_channel_client_disconnect: 0x7f7030221600 (channel 0x7f703021d670 type 4 id 0)
red_channel_client_disconnect: 0x7f71674c12e0 (channel 0x7f7165fd0610 type 1 id 0)
red_channel_client_disconnect: 0x7f71674c12e0 (channel 0x7f7165fd0610 type 1 id 0)
cpage out of range (5)
processing error - resetting ehci HC
main_channel_link: add main channel client
main_channel_handle_parsed: net test: latency 0.574000 ms, bitrate 621547799 bps (592.754172 Mbps)
qemu-kvm: usbredirparser: Peer version: spice-gtk 0.14, using 64-bits ids

red_dispatcher_set_cursor_peer: 
inputs_connect: inputs channel client create

(qemu) info status 
VM status: running

Comment 13 Sibiao Luo 2012-11-06 03:50:54 UTC
(In reply to comment #11)
> I notice in comment #9 that the "-device usb-tablet,id=input0" is back on
> the cmdline, can you please try without this on the cmdline?
> 
> Also can you change the debug=3 to debug=4 for the usb-redir device, and
> when you quote qemu console output, please include the full output and not
> only the last few lines.
> 
I remove "-device usb-tablet,id=input0" from command line and with debug=4 for the usb-redir device. but i cann't control the qemu monitor flooding with prompts on and on after i plug the USB stick, so i stop the src VM and then do migration, it still hit this issue.

# /usr/libexec/qemu-kvm -M rhel6.4.0 -cpu SandyBridge -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1 -name sluo_migration -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -drive file=/dev/vg-90.100-sluo/lv-rhel6.4-guest,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x3,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x4 -spice port=5931,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -readconfig /mnt/ich9-ehci-uhci.cfg -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=4 -boot menu=on -monitor stdio
QEMU 0.12.1 monitor - type 'help' for more information
(qemu) main_channel_link: add main channel client
main_channel_handle_parsed: net test: latency 0.068000 ms, bitrate 7757575757 bps (7398.200757 Mbps)
qemu-kvm: usb-redir: chardev open

qemu-kvm: usb-redir: removing 0 packet-ids from cancelled queue

qemu-kvm: usb-redir: removing 0 packet-ids from already-in-flight queue

qemu-kvm: usb-redir: creating usbredirparser

qemu-kvm: usbredirparser: Peer version: spice-gtk 0.14, using 64-bits ids

inputs_connect: inputs channel client create
red_dispatcher_set_cursor_peer: 

(qemu) info status 
VM status: running
(qemu) 
(qemu) 
(qemu) qemu-kvm: usb-redir: ep: 00 type: 0 interface: 0

qemu-kvm: usb-redir: ep: 02 type: 2 interface: 0

qemu-kvm: usb-redir: ep: 80 type: 0 interface: 0

qemu-kvm: usb-redir: ep: 81 type: 2 interface: 0

qemu-kvm: usb-redir: attaching high speed device 0951:1642 version 1.0 class 00

qemu-kvm: usb-redir: reset device

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x100 index 0 len 64 id 931139968

qemu-kvm: usb-redir: ctrl-in status 0 len 18 id 931139968

qemu-kvm: usb-redir: reset device

qemu-kvm: usb-redir: set address 2

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x100 index 0 len 18 id 931139968

qemu-kvm: usb-redir: ctrl-in status 0 len 18 id 931139968

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x200 index 0 len 9 id 931139872

qemu-kvm: usb-redir: ctrl-in status 0 len 9 id 931139872

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x200 index 0 len 32 id 931139680

qemu-kvm: usb-redir: ctrl-in status 0 len 32 id 931139680

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x300 index 0 len 255 id 931139968

qemu-kvm: usb-redir: ctrl-in status 0 len 4 id 931139968

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x302 index 1033 len 255 id 931139872

qemu-kvm: usb-redir: ctrl-in status 0 len 20 id 931139872

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x301 index 1033 len 255 id 931139680

qemu-kvm: usb-redir: ctrl-in status 0 len 18 id 931139680

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x303 index 1033 len 255 id 931139968

qemu-kvm: usb-redir: ctrl-in status 0 len 50 id 931139968

qemu-kvm: usb-redir: set config 1 id 931139776

qemu-kvm: usb-redir: set config status 0 config 1 id 931139776

qemu-kvm: usb-redir: ctrl-out type 0xa1 req 0xfe val 0x0 index 0 len 1 id 931139680

qemu-kvm: usb-redir: ctrl-in status 0 len 1 id 931139680

qemu-kvm: usb-redir: bulk-out ep 02 len 31 id 931139872

qemu-kvm: usb-redir: bulk-in status 0 ep 02 len 31 id 931139872
...

The same command line appending with '-incoming tcp:0:5888,server,nowait' in dest.
(qemu) info status 
VM status: paused (incoming-migration)
(qemu) main_channel_link: add main channel client
red_dispatcher_set_cursor_peer: 
inputs_connect: inputs channel client create
qemu-kvm: usb-redir: chardev open

qemu-kvm: usb-redir: removing 0 packet-ids from cancelled queue

qemu-kvm: usb-redir: removing 0 packet-ids from already-in-flight queue

qemu-kvm: usb-redir: creating usbredirparser

red_dispatcher_loadvm_commands: 
qemu-kvm: usbredirparser: unserialized int 55525031 : magic

qemu-kvm: usbredirparser: unserialized int 0000002c : length

qemu-kvm: usbredirparser: unserialized 4 bytes of our_caps data

qemu-kvm: usbredirparser: unserialized 4 bytes of peer_caps data

qemu-kvm: usbredirparser: unserialized int 00000000 : skip

qemu-kvm: usbredirparser: unserialized 0 bytes of header data

qemu-kvm: usbredirparser: unserialized 0 bytes of type_header data

qemu-kvm: usbredirparser: unserialized 0 bytes of data data

qemu-kvm: usbredirparser: unserialized int 00000000 : write_buf_count

qemu-kvm: usb-redir: get_packet_id_q cancelled size 0

qemu-kvm: usb-redir: get_packet_id_q already-in-flight size 0

qemu-kvm: usb-redir: bulk-out ep 81 len 13 id 931141120

qemu-kvm: usb-redir: bulk-in status 0 ep 81 len 13 id 931141120

qemu-kvm: usb-redir: reset device

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x100 index 0 len 64 id 931139968

qemu-kvm: usb-redir: ctrl-in status 0 len 18 id 931139968

qemu-kvm: usb-redir: reset device

qemu-kvm: usb-redir: set address 2

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x100 index 0 len 18 id 931139968

qemu-kvm: usb-redir: ctrl-in status 0 len 18 id 931139968

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x200 index 0 len 32 id 931139680

qemu-kvm: usb-redir: ctrl-in status 0 len 32 id 931139680

qemu-kvm: usb-redir: ctrl-out type 0x80 req 0x6 val 0x303 index 1033 len 255 id 931139776

qemu-kvm: usb-redir: ctrl-in status 0 len 50 id 931139776

qemu-kvm: usb-redir: set config 1 id 931141120

qemu-kvm: usb-redir: set config status 0 config 1 id 931141120

qemu-kvm: usb-redir: bulk-out ep 02 len 31 id 931140928

qemu-kvm: usb-redir: bulk-in status 0 ep 02 len 31 id 931140928

qemu-kvm: usb-redir: bulk-out ep 81 len 13 id 931141120

qemu-kvm: usb-redir: bulk-in status 0 ep 81 len 13 id 931141120

...

qemu-kvm: usb-redir: bulk-in status 0 ep 02 len 20480 id 931139872

qemu-kvm: usb-redir: bulk-out ep 02 len 20480 id 931140160

red_channel_client_disconnect: 0x7ff8f8221600 (channel 0x7ff8f821d670 type 4 id 0)
red_channel_client_disconnect: 0x7ffa24795010 (channel 0x7ff8f821d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7ffa30643b20 (channel 0x7ffa305e6140 type 9 id 0)
red_channel_client_disconnect: 0x7ffa30643b20 (channel 0x7ffa305e6140 type 9 id 0)
qemu-kvm: usb-redir: chardev close

red_channel_client_disconnect: 0x7ffa3063d720 (channel 0x7ffa2f150730 type 3 id 0)
red_channel_client_disconnect: 0x7ffa306372e0 (channel 0x7ffa2f146610 type 1 id 0)
main_channel_client_on_disconnect: rcc=0x7ffa306372e0
red_client_destroy: destroy client with #channels 4
red_channel_client_disconnect: 0x7ffa3063d720 (channel 0x7ffa2f150730 type 3 id 0)
red_channel_client_disconnect: 0x7ffa3063d720 (channel 0x7ffa2f150730 type 3 id 0)
red_dispatcher_disconnect_display_peer: 
red_channel_client_disconnect: 0x7ffa24795010 (channel 0x7ff8f821d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7ffa24795010 (channel 0x7ff8f821d0b0 type 2 id 0)
red_dispatcher_disconnect_cursor_peer: 
red_channel_client_disconnect: 0x7ff8f8221600 (channel 0x7ff8f821d670 type 4 id 0)
red_channel_client_disconnect: 0x7ff8f8221600 (channel 0x7ff8f821d670 type 4 id 0)
red_channel_client_disconnect: 0x7ffa306372e0 (channel 0x7ffa2f146610 type 1 id 0)
red_channel_client_disconnect: 0x7ffa306372e0 (channel 0x7ffa2f146610 type 1 id 0)
qemu-kvm: usb-redir: detaching device

qemu-kvm: usb-redir: adding packet id 931140160 to cancelled queue

qemu-kvm: usb-redir: removing 1 packet-ids from cancelled queue

qemu-kvm: usb-redir: removing 0 packet-ids from already-in-flight queue

qemu-kvm: usb-redir: destroying usbredirparser

cpage out of range (5)
processing error - resetting ehci HC
main_channel_link: add main channel client
main_channel_handle_parsed: net test: latency 0.333000 ms, bitrate 596041909 bps (568.429860 Mbps)
qemu-kvm: usb-redir: chardev open

qemu-kvm: usb-redir: removing 0 packet-ids from cancelled queue

qemu-kvm: usb-redir: removing 0 packet-ids from already-in-flight queue

qemu-kvm: usb-redir: creating usbredirparser

qemu-kvm: usbredirparser: Peer version: spice-gtk 0.14, using 64-bits ids

inputs_connect: inputs channel client create
red_dispatcher_set_cursor_peer: 

(qemu) info status 
VM status: running

Comment 14 Hans de Goede 2012-11-06 15:17:58 UTC
I *really* need the *full* qemu output to debug this, please *STOP* omitting parts of the qemu output!!!

To capture all usb-redir logging you can add 2> log to the end of the qemu cmdline, ie:

qemu ...   2> /tmp/src.log

and

qemu ... -incoming ... 2> /tmp/src.log

Please re-run the tests with debug=4 and capture *all* the output, and attach the log files here.

Also on the destination qemu the usb trafic does seem to continue for a while, and then it sees the client disconnect ?   Are you disconnecting the client after migration, and then re-connecting again, or is the client doing this automatically ?

Question: are you using the same machine as host for the source and destination of the migration, or are they both running on a different machine? And if they are on a different machine what sort of network connection is there between the 2 hosts machines ?

Comment 15 Sibiao Luo 2012-11-07 12:49:46 UTC
(In reply to comment #14)
> I *really* need the *full* qemu output to debug this, please *STOP* omitting
> parts of the qemu output!!!
> 
> To capture all usb-redir logging you can add 2> log to the end of the qemu
> cmdline, ie:
> 
> qemu ...   2> /tmp/src.log
> 
> and
> 
> qemu ... -incoming ... 2> /tmp/src.log
> 
> Please re-run the tests with debug=4 and capture *all* the output, and
> attach the log files here.
yes, thanks for your reminds, but i did not reproduce it because i my host re-install the new tree, this time it will segmentation fault in dest qemu. I will list it for detail later.

> Also on the destination qemu the usb trafic does seem to continue for a
> while, and then it sees the client disconnect ? 
no, i note that it fail to dd 'dd: writing `/mnt/sluo': Input/output error
' in dest after the src finish migrate.
> Are you disconnecting the client after migration, and then re-connecting 
> again, or is the client doing this automatically ?
I disconnect the client after migration and then re-connect again.
 
> Question: are you using the same machine as host for the source and
> destination of the migration, or are they both running on a different
> machine? And if they are on a different machine what sort of network
> connection is there between the 2 hosts machines ?
yes, my two host are the same type, and use wired network to connecte.

Comment 16 Sibiao Luo 2012-11-07 12:58:03 UTC
(In reply to comment #15)
> > Please re-run the tests with debug=4 and capture *all* the output, and
> > attach the log files here.
> yes, thanks for your reminds, but i did not reproduce it because i my host
> re-install the new tree, this time it will segmentation fault in dest qemu.
> I will list it for detail later.
i download all the kernel qemu spice-gtk spice-server to the version mentioned in comment #9, it will segmentation fault in dest qemu, so i list it detail here, the qemu log will attach.

host info:
kernel-2.6.32-339.el6.x86_64
qemu-kvm-0.12.1.2-2.334.el6.x86_64
spice-server-0.12.0-2.el6.x86_64
spice-gtk-0.14-5.el6.x86_64
virt-viewer-0.5.2-14.el6.x86_64
seabios-0.6.1.2-25.el6.x86_64
geust info:
kernel-2.6.32-339.el6.x86_64

Results:
after step 6, it will segmentation fault in dest qemu
(qemu) info status 
VM status: paused (incoming-migration)
(qemu) 
main_channel_link: add main channel client
red_dispatcher_set_cursor_peer: 
inputs_connect: inputs channel client create
qemu-kvm: usb-redir: chardev open

qemu-kvm: usb-redir: removing 0 packet-ids from cancelled queue

qemu-kvm: usb-redir: removing 0 packet-ids from already-in-flight queue

qemu-kvm: usb-redir: creating usbredirparser


Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffecb9fc700 (LWP 8487)]
0x00007ffff5f64b52 in display_channel_client_restore_surface (dcc=0x7fffec618010, surface_id=4158075104) at red_worker.c:9754
9754	        spice_assert(!dcc->surface_client_created[surface_id]);

(gdb) bt
#0  0x00007ffff5f64b52 in display_channel_client_restore_surface (dcc=0x7fffec618010, surface_id=4158075104) at red_worker.c:9754
#1  0x00007ffff5f672df in display_channel_client_restore_surfaces_lossy (rcc=0x7fffec618010, size=<value optimized out>, message=<value optimized out>) at red_worker.c:9782
#2  display_channel_handle_migrate_data (rcc=0x7fffec618010, size=<value optimized out>, message=<value optimized out>) at red_worker.c:9866
#3  0x00007ffff5f5a8df in red_channel_handle_migrate_data (rcc=0x7fffec618010, size=1040, type=<value optimized out>, message=0x7ffec421d208) at red_channel.c:1157
#4  red_channel_client_handle_message (rcc=0x7fffec618010, size=1040, type=<value optimized out>, message=0x7ffec421d208) at red_channel.c:1189
#5  0x00007ffff5f5a1eb in red_peer_handle_incoming (rcc=0x7fffec618010) at red_channel.c:272
#6  red_channel_client_receive (rcc=0x7fffec618010) at red_channel.c:294
#7  0x00007ffff5f5aa7c in red_channel_client_event (fd=<value optimized out>, event=<value optimized out>, data=0x7fffec618010) at red_channel.c:1204
#8  0x00007ffff5f7f86e in red_worker_main (arg=<value optimized out>) at red_worker.c:11782
#9  0x00007ffff773c851 in start_thread () from /lib64/libpthread.so.0
#10 0x00007ffff57fc90d in clone () from /lib64/libc.so.6
(gdb) q

# /usr/libexec/qemu-kvm -M rhel6.4.0 -cpu SandyBridge -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1 -name sluo_migration -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -drive file=/dev/vg-90.100-sluo/lv-90-100-RHEL6.4-20121019.0-Copy-x86_64,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x3,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x4 -spice port=5931,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -readconfig /mnt/ich9-ehci-uhci.cfg -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=4 -boot menu=on -monitor stdio

Comment 17 Sibiao Luo 2012-11-07 12:59:27 UTC
Created attachment 640051 [details]
capture all usb-redir log of src qemu as your indication using debug=4

Comment 18 Sibiao Luo 2012-11-07 13:00:26 UTC
Created attachment 640054 [details]
capture all usb-redir log of dest qemu as your indication using debug=4

Comment 19 Hans de Goede 2012-11-19 10:48:05 UTC
(In reply to comment #15)
> (In reply to comment #14)
> > Also on the destination qemu the usb trafic does seem to continue for a
> > while, and then it sees the client disconnect ? 
> no, i note that it fail to dd 'dd: writing `/mnt/sluo': Input/output error
> ' in dest after the src finish migrate.

Does this happen before or after you disconnect the client ?

> > Are you disconnecting the client after migration, and then re-connecting 
> > again, or is the client doing this automatically ?
> I disconnect the client after migration and then re-connect again.

Why? You should *not* do that, ofcourse redirection will break if you disconnect
the client, as the redirection runs through the client! Also if you take any additional
steps like disconnecting and reconnecting the client you *must*
include these steps in your problem description from now on please:

1) provide detailed step by step instructions on what exactly you are doing what
is leading to the problem you are seeing
2) provide full logs!

If you leave out important information like the fact that you're disconnecting
and re-connecting the client, and keep abbreviating the logs it is *impossible*
for me to debug this!

I really need you to provide better , and more complete information!!
(In reply to comment #18)

> Created attachment 640054 [details]
> capture all usb-redir log of dest qemu as your indication using debug=4

This log is incomplete (again !!!)

I need complete logs of both source and destination qemu, and the logs must
both be from one and the same migration attempt, if the logs don't match-up
they are useless!

Comment 20 Sibiao Luo 2012-11-19 12:41:12 UTC
(In reply to comment #19)
> (In reply to comment #15)
> > (In reply to comment #14)
> > > Also on the destination qemu the usb trafic does seem to continue for a
> > > while, and then it sees the client disconnect ? 
> > no, i note that it fail to dd 'dd: writing `/mnt/sluo': Input/output error
> > ' in dest after the src finish migrate.
> 
> Does this happen before or after you disconnect the client ?
this start happened before disconnect the source guest and continue flooding with 'dd: writing `/mnt/sluo': Input/output error' after i reconnect the on the destination guest.
> > > Are you disconnecting the client after migration, and then re-connecting 
> > > again, or is the client doing this automatically ?
> > I disconnect the client after migration and then re-connect again.
> 
> Why? You should *not* do that, ofcourse redirection will break if you
> disconnect
> the client, as the redirection runs through the client! 
Maybe you misunderstand, why cannot disconnect the source guest after it finish migration ? the source guest will stop after finish migration, i just quit source qmeu after migration finish successfully.
> Also if you take any additional steps like disconnecting and reconnecting the > client you *must* include these steps in your problem description from now on > please:
> 
> 1) provide detailed step by step instructions on what exactly you are doing
> what
> is leading to the problem you are seeing
> 2) provide full logs!
> 
> If you leave out important information like the fact that you're
> disconnecting
> and re-connecting the client, and keep abbreviating the logs it is
> *impossible*
> for me to debug this!
yes, I know, i will do my best to provide the detail information to you. 
> I really need you to provide better, and more complete information!!
> (In reply to comment #18)
> 
> > Created attachment 640054 [details]
> > capture all usb-redir log of dest qemu as your indication using debug=4
> 
> This log is incomplete (again !!!)
I retest it again, I capture the logs are just the same as comment #17 and comment #18, the destinatin qemu will occur segmentation fault after migration finish in source. I did not disconnect the source VM and not reconnect the destination VM, it will core dump just at finish migration, and the source qemu will be in pause status after migration. 
NOTE: the logs of comment #17 and comment #18 is for the test of comment #16.
> I need complete logs of both source and destination qemu, and the logs must
> both be from one and the same migration attempt, if the logs don't match-up
> they are useless!
I donot know why you said that the logs didn't match-up? I just use the method to capture the logs as your comment #14. if that, i will attach the log later that i test today.

Comment 21 Sibiao Luo 2012-11-19 12:45:13 UTC
Created attachment 647720 [details]
source log

Comment 22 Sibiao Luo 2012-11-19 12:45:52 UTC
Created attachment 647727 [details]
destination log.

Comment 23 Sibiao Luo 2012-11-19 12:52:05 UTC
Steps:
same as comment #0

- source qemu:
# /usr/libexec/qemu-kvm -M rhel6.4.0 -cpu SandyBridge -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1 -name sluo_migration -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -drive file=/dev/vg-90.100-sluo/lv-90-100-RHEL6.4-20121019.0-Copy-x86_64,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x3,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x4 -spice port=5931,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -readconfig /mnt/ich9-ehci-uhci.cfg -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=4 -boot menu=on -monitor stdio 2> /home/source.log
Detaching after fork from child process 17107.
QEMU 0.12.1 monitor - type 'help' for more information
(qemu) __com.redhat_spice_migrate_info 10.66.11.229 5931
(qemu) migrate -d tcp:10.66.11.229:5888
(qemu) info migrate 
Migration status: active
transferred ram: 1839403 kbytes
remaining ram: 116568 kbytes
total ram: 4325776 kbytes
(qemu) info migrate 
Migration status: active
transferred ram: 1855819 kbytes
remaining ram: 148640 kbytes
total ram: 4325776 kbytes
(qemu) info migrate 
Migration status: completed
(qemu)

- destination qemu:
# /usr/libexec/qemu-kvm -M rhel6.4.0 -cpu SandyBridge -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1 -name sluo_migration -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -drive file=/dev/vg-90.100-sluo/lv-90-100-RHEL6.4-20121019.0-Copy-x86_64,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x3,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x4 -spice port=5931,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -readconfig /mnt/ich9-ehci-uhci.cfg -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=4 -boot menu=on -monitor stdio -incoming tcp:0:5888,server,nowait 2> /home/destination.log
Detaching after fork from child process 14254.
QEMU 0.12.1 monitor - type 'help' for more information
(qemu) info status 
VM status: paused (incoming-migration)
(qemu) [Thread 0x7ffff005f700 (LWP 14260) exited]

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffecb9fc700 (LWP 14267)]
0x00007ffff5f64b52 in display_channel_client_restore_surface (dcc=0x7fffec410010, surface_id=4126520928) at red_worker.c:9754
9754	        spice_assert(!dcc->surface_client_created[surface_id]);

(gdb) bt
#0  0x00007ffff5f64b52 in display_channel_client_restore_surface (dcc=0x7fffec410010, surface_id=4126520928) at red_worker.c:9754
#1  0x00007ffff5f672df in display_channel_client_restore_surfaces_lossy (rcc=0x7fffec410010, size=<value optimized out>, message=<value optimized out>) at red_worker.c:9782
#2  display_channel_handle_migrate_data (rcc=0x7fffec410010, size=<value optimized out>, message=<value optimized out>) at red_worker.c:9866
#3  0x00007ffff5f5a8df in red_channel_handle_migrate_data (rcc=0x7fffec410010, size=1264, type=<value optimized out>, message=0x7ffec421d208) at red_channel.c:1157
#4  red_channel_client_handle_message (rcc=0x7fffec410010, size=1264, type=<value optimized out>, message=0x7ffec421d208) at red_channel.c:1189
#5  0x00007ffff5f5a1eb in red_peer_handle_incoming (rcc=0x7fffec410010) at red_channel.c:272
#6  red_channel_client_receive (rcc=0x7fffec410010) at red_channel.c:294
#7  0x00007ffff5f5aa7c in red_channel_client_event (fd=<value optimized out>, event=<value optimized out>, data=0x7fffec410010) at red_channel.c:1204
#8  0x00007ffff5f7f86e in red_worker_main (arg=<value optimized out>) at red_worker.c:11782
#9  0x00007ffff773c851 in start_thread () from /lib64/libpthread.so.0
#10 0x00007ffff57fc90d in clone () from /lib64/libc.so.6
(gdb) q

Comment 24 Hans de Goede 2012-11-19 14:16:00 UTC
(In reply to comment #20)
> (In reply to comment #19)
> > (In reply to comment #15)
> > > (In reply to comment #14)
> > > > Also on the destination qemu the usb trafic does seem to continue for a
> > > > while, and then it sees the client disconnect ? 
> > > no, i note that it fail to dd 'dd: writing `/mnt/sluo': Input/output error
> > > ' in dest after the src finish migrate.
> > 
> > Does this happen before or after you disconnect the client ?
> this start happened before disconnect the source guest and continue flooding
> with 'dd: writing `/mnt/sluo': Input/output error' after i reconnect the on
> the destination guest.

Please get your terminology straight, there is no source guest / destination guest, only
a source host (or qemu) and a destination host, both running the same guest. Also we
were not talking about the host at all, to quite my question:
"Does this happen before or after you disconnect the client"

So we're talking about the *client* iow spicy or remote-viewer. If you look at
the destination qemu logs in comment #13, the following is in there:

"
red_channel_client_disconnect: 0x7ff8f8221600 (channel 0x7ff8f821d670 type 4 id 0)
red_channel_client_disconnect: 0x7ffa24795010 (channel 0x7ff8f821d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7ffa30643b20 (channel 0x7ffa305e6140 type 9 id 0)
red_channel_client_disconnect: 0x7ffa30643b20 (channel 0x7ffa305e6140 type 9 id 0)
qemu-kvm: usb-redir: chardev close

red_channel_client_disconnect: 0x7ffa3063d720 (channel 0x7ffa2f150730 type 3 id 0)
red_channel_client_disconnect: 0x7ffa306372e0 (channel 0x7ffa2f146610 type 1 id 0)
main_channel_client_on_disconnect: rcc=0x7ffa306372e0
red_client_destroy: destroy client with #channels 4
red_channel_client_disconnect: 0x7ffa3063d720 (channel 0x7ffa2f150730 type 3 id 0)
red_channel_client_disconnect: 0x7ffa3063d720 (channel 0x7ffa2f150730 type 3 id 0)
red_dispatcher_disconnect_display_peer: 
red_channel_client_disconnect: 0x7ffa24795010 (channel 0x7ff8f821d0b0 type 2 id 0)
red_channel_client_disconnect: 0x7ffa24795010 (channel 0x7ff8f821d0b0 type 2 id 0)
red_dispatcher_disconnect_cursor_peer: 
red_channel_client_disconnect: 0x7ff8f8221600 (channel 0x7ff8f821d670 type 4 id 0)
red_channel_client_disconnect: 0x7ff8f8221600 (channel 0x7ff8f821d670 type 4 id 0)
red_channel_client_disconnect: 0x7ffa306372e0 (channel 0x7ffa2f146610 type 1 id 0)
red_channel_client_disconnect: 0x7ffa306372e0 (channel 0x7ffa2f146610 type 1 id 0)
qemu-kvm: usb-redir: detaching device
"

IOW the client is being disconnected from the destination qemu after migration!

Which led to me asking:

> > > > Are you disconnecting the client after migration, and then re-connecting 
> > > > again, or is the client doing this automatically ?
> > > I disconnect the client after migration and then re-connect again.
> > 
> > Why? You should *not* do that, ofcourse redirection will break if you
> > disconnect
> > the client, as the redirection runs through the client! 
> Maybe you misunderstand, why cannot disconnect the source guest after it
> finish migration ? the source guest will stop after finish migration, i just
> quit source qmeu after migration finish successfully.

We are not talking about qemu here at all, we are talking about disconnecting
the client (ie remote-viewer). Please use the correct terminology! Also you cannot
disconnect a guest, as you say later yourself you are quitting the source qemu,
again please use the correct terminology!

IMPORTANT: note that for seamless migration the source qemu needs to stay
around for a bit after the migration has finished, since for seamless some
final status is synced through the spice-client which is connected to both
source and destination qemu at the same time. If you're using a script to test
this, please stop using this and try testing this manually, as quitting the
source qemu too soon will break things!

> > (In reply to comment #18)
> > 
> > > Created attachment 640054 [details]
> > > capture all usb-redir log of dest qemu as your indication using debug=4
> > 
> > This log is incomplete (again !!!)
> I retest it again, I capture the logs are just the same as comment #17 and
> comment #18, the destinatin qemu will occur segmentation fault after
> migration finish in source. I did not disconnect the source VM and not
> reconnect the destination VM, it will core dump just at finish migration,
> and the source qemu will be in pause status after migration.

The segmentation fault is a *different* issue, I was expecting you to have fallen
back to the versions you were using in comment #13 and before, and to
provide actually usable logs!!

If the destination qemu crashes, of course usb-redirection will break too, and
the destination log will not contain any useful info!

So please provide full src and destination logs using the same setup / config
as you were using in comment #13.

IMPORTANT: and also open a NEW bug for the segfault you are seeing, using
spice-server as component.

Comment 25 Sibiao Luo 2012-11-21 07:24:16 UTC
(In reply to comment #24)
> (In reply to comment #20)
> > (In reply to comment #19)
> > > (In reply to comment #15)
> > > > (In reply to comment #14)
> > > > > Also on the destination qemu the usb trafic does seem to continue for a
> > > > > while, and then it sees the client disconnect ? 
> > > > no, i note that it fail to dd 'dd: writing `/mnt/sluo': Input/output error
> > > > ' in dest after the src finish migrate.
> > > 
> > > Does this happen before or after you disconnect the client ?
> > this start happened before disconnect the source guest and continue flooding
> > with 'dd: writing `/mnt/sluo': Input/output error' after i reconnect the on
> > the destination guest.
> 
> Please get your terminology straight, there is no source guest / destination
> guest, only
> a source host (or qemu) and a destination host, both running the same guest.
> Also we
> were not talking about the host at all, to quite my question:
> "Does this happen before or after you disconnect the client"
ok, thanks for your kindly guidance. I will talk the terminology correctly. 
> So we're talking about the *client* iow spicy or remote-viewer. 
> 
> Which led to me asking:
> 
> > > > > Are you disconnecting the client after migration, and then re-connecting 
> > > > > again, or is the client doing this automatically ?
> > > > I disconnect the client after migration and then re-connect again.
> > > 
> > > Why? You should *not* do that, ofcourse redirection will break if you
> > > disconnect
> > > the client, as the redirection runs through the client! 
> > Maybe you misunderstand, why cannot disconnect the source guest after it
> > finish migration ? the source guest will stop after finish migration, i just
> > quit source qmeu after migration finish successfully.
> 
> We are not talking about qemu here at all, we are talking about disconnecting
> the client (ie remote-viewer). Please use the correct terminology! Also you
> cannot
> disconnect a guest, as you say later yourself you are quitting the source
> qemu,
> again please use the correct terminology!
ok, thanks. 
> IMPORTANT: note that for seamless migration the source qemu needs to stay
> around for a bit after the migration has finished, since for seamless some
> final status is synced through the spice-client which is connected to both
> source and destination qemu at the same time. If you're using a script to
> test
> this, please stop using this and try testing this manually, as quitting the
> source qemu too soon will break things!
yes, maybe i need to wait a while before quit the source qemu.
> > > (In reply to comment #18)
> > > 
> > > > Created attachment 640054 [details]
> > > > capture all usb-redir log of dest qemu as your indication using debug=4
> > > 
> > > This log is incomplete (again !!!)
> > I retest it again, I capture the logs are just the same as comment #17 and
> > comment #18, the destinatin qemu will occur segmentation fault after
> > migration finish in source. I did not disconnect the source VM and not
> > reconnect the destination VM, it will core dump just at finish migration,
> > and the source qemu will be in pause status after migration.
> 
> The segmentation fault is a *different* issue, I was expecting you to have
> fallen
> back to the versions you were using in comment #13 and before, and to
> provide actually usable logs!!
Hans, i did not reproduce this issue any more after fall back to the version as comment #13 and comment #0, it just occur segmentation fault in destination qemu(bug 878700). it waste me the whole day to retest it, but have no any progress except core dump. Maybe this issue depend on the bug 878700. I will provide the detail logs if i meet this issue again. I think we could fix the bug 878700 firstly and we need to test this bug when verify the bug 878700. please correct me if any problem.

> If the destination qemu crashes, of course usb-redirection will break too,
> and
> the destination log will not contain any useful info!
> 
> So please provide full src and destination logs using the same setup / config
> as you were using in comment #13.
> 
> IMPORTANT: and also open a NEW bug for the segfault you are seeing, using
> spice-server as component.
yes, i open a new bug 878700 to trace this issue.

Comment 26 Sibiao Luo 2012-12-04 07:29:07 UTC
> Description of problem:
> install virt-viewer package in host, boot a guest with usb redirection
> (seamless-migration=on) and do dd to the usb disk in loop, then do live
> migration with 'remote-viewer spice://$host_ip:$port' to connect guest
> desktop, it fail to dd with 'Input/output error' in guest and 'sd 2:0:0:0:
> [sda] Unhandled error code' in guest kernel log.
> 
> Steps to Reproduce:
> 1.boot guest with usb redirection and seamless-migration=on in src and
> '-incoming tcp:0:5888' in dst.
> 2.Connect guest desktop with remote-viewer tools (provided by virt-viewer)
> 3.plug a USB disk to USB host, and click on menubar -> 'File' -> 'USB Device
> selection'.
> # lsusb | grep Kingston
> Bus 002 Device 007: ID 0951:1642 Kingston Technology DT101 G2
> 4.mkfs.ext4 the the usb-disk and mount it to /mnt.
> 5.do I/O to the mount target.
> # cat script.sh 
> while true
> do
>   dd if=/dev/zero of=/mnt/sluo bs=1M count=100
>   rm -f /mnt/sluo
> done
> 6.do live migrate
> (qemu) __com.redhat_spice_migrate_info $dst_host_ip $dst_host_port
> main_channel_client_handle_migrate_connected: client 0x7ffff99aef80
> connected: 1 seamless 1
> (qemu) migrate -d tcp:$dst_host_ip:$port
> 
> Actual results:
> after step 6, 
> the src migration completed and the dst in running status, but there are
> flooding with 'dd: opening `/mnt/sluo': Input/output error' in geust. 
> # sh script.sh 
> ...
> 100+0 records in
> 100+0 records out
> 104857600 bytes (105 MB) copied, 0.0872394 s, 1.2 GB/s
> 100+0 records in
> 100+0 records out
> 104857600 bytes (105 MB) copied, 0.0864387 s, 1.2 GB/s
> 100+0 records in
> 100+0 records out
> 104857600 bytes (105 MB) copied, 0.0842231 s, 1.2 GB/s
> 100+0 records in
> 100+0 records out
> 104857600 bytes (105 MB) copied, 0.0865455 s, 1.2 GB/s
> 100+0 records in
> 100+0 records out
> 104857600 bytes (105 MB) copied, 0.086778 s, 1.2 GB/s
> dd: opening `/mnt/sluo': Input/output error
> dd: opening `/mnt/sluo': Input/output error
> dd: opening `/mnt/sluo': Input/output error
> dd: opening `/mnt/sluo': Input/output error
> dd: opening `/mnt/sluo': Input/output error
> dd: opening `/mnt/sluo': Input/output error
> dd: opening `/mnt/sluo': Input/output error
> dd: opening `/mnt/sluo': Input/output error
> ...
> 
> and the guest kernel log as following:
> # nc -U /tmp/ttyS0 
> usb 1-1: USB disconnect, device number 2
> sd 2:0:0:0: [sda] Unhandled error code
> sd 2:0:0:0: [sda] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
> sd 2:0:0:0: [sda] CDB: Read(10): 28 00 00 00 29 98 00 00 01 00
> FAT: FAT read failed (blocknr 10616)
> FAT: FAT read failed (blocknr 10616)
> FAT: unable to read inode block for updating (i_pos 473605)
> FAT: Directory bread(block 29600) failed
> FAT: bread failed in fat_clusters_flush
> FAT: bread failed in fat_clusters_flush
> FAT: unable to read inode block for updating (i_pos 473605)
> FAT: FAT read failed (blocknr 10616)
> FAT: Directory bread(block 29600) failed
> FAT: Directory bread(block 29601) failed
> FAT: Directory bread(block 29602) failed
> FAT: Directory bread(block 29603) failed
> FAT: Directory bread(block 29604) failed
> FAT: Directory bread(block 29605) failed
> ...
> 
Hi Hans de Goede,

   I meet it again today, and i capture the full qemu logs of the src and dest qeme with a spice debug messages (export SPICE_DEBUG_LEVEL=5).

host info:
kernel-2.6.32-345.el6.x86_64
qemu-kvm-0.12.1.2-2.327.el6.x86_64
spice-server-0.12.0-2.el6.x86_64
spice-gtk-0.14-5.el6.x86_64
spice-gtk-tools-0.14-5.el6.x86_64
virt-viewer-0.5.2-16.el6.x86_64
guest info:
kernel-2.6.32-279.el6.x86_64

steps & results:
the same as comment #0

I will attach the log later.

Comment 27 Sibiao Luo 2012-12-04 07:30:41 UTC
Created attachment 657285 [details]
src-qemu-log.

Comment 28 Sibiao Luo 2012-12-04 07:32:18 UTC
Created attachment 657286 [details]
dest-qemu-log.

Comment 29 Sibiao Luo 2012-12-04 07:33:41 UTC
Created attachment 657287 [details]
the dmest of guest.

Comment 30 Sibiao Luo 2012-12-04 07:34:35 UTC
Created attachment 657288 [details]
the output logs of I/O action.

Comment 31 Sibiao Luo 2012-12-04 07:44:23 UTC
my qemu-kvm command line as following:
/usr/libexec/qemu-kvm -M rhel6.4.0 -cpu SandyBridge -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1,maxcpus=6 -usb -device usb-tablet,id=input0 -name sluo_migration -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x3 -drive file=/mnt/RHEL-Server-6.4-64-virtio.qcow2,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x4,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x5 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -spice port=5931,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -device intel-hda,id=sound0,bus=pci.0,addr=0x6 -device hda-duplex -device usb-ehci,id=ehci,addr=0x7 -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=3 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x8 -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0 -serial unix:/tmp/ttyS0,server,nowait -qmp tcp:0:4444,server,nowait -monitor stdio 2> /home/log.txt

Comment 32 Hans de Goede 2012-12-04 13:31:53 UTC
(In reply to comment #27)
> Created attachment 657285 [details]
> src-qemu-log.

This log is completely unusable due to the "export SPICE_DEBUG_LEVEL=5" No one asked you to set this
debugging variable for this bug.

I asked you to set the usb-redir device debug property on the qemu cmdline to 4, which is a different thing!

Also why are you still using spice-server 0.12.0-2?

We've a 0.12.0-7 build with many migration related bugs fixed, please use that version in all your testing!

Please re-do the tests without "export SPICE_DEBUG_LEVEL=5" and using spice-server 0.12.0-7

Comment 33 Sibiao Luo 2012-12-05 05:42:11 UTC
(In reply to comment #32)
> I asked you to set the usb-redir device debug property on the qemu cmdline
> to 4, which is a different thing!
>
> We've a 0.12.0-7 build with many migration related bugs fixed, please use
> that version in all your testing!
> 
> Please re-do the tests without "export SPICE_DEBUG_LEVEL=5" and using
> spice-server 0.12.0-7
yes, thanks for your reminds, i will retest it and provide it later.

host info:
kernel-2.6.32-345.el6.x86_64
qemu-kvm-0.12.1.2-2.327.el6.x86_64
spice-server-0.12.0-7.el6.x86_64
spice-gtk-0.14-5.el6.x86_64
spice-gtk-tools-0.14-5.el6.x86_64
virt-viewer-0.5.2-16.el6.x86_64
guest info:
kernel-2.6.32-279.el6.x86_64

the usb-redir device debug property is 4.
eg:...-device usb-ehci,id=ehci,addr=0x7 -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=4

steps & results:
the same as comment #0

qemu-kvm command line:
eg: # /usr/libexec/qemu-kvm -M rhel6.4.0 -cpu SandyBridge -enable-kvm -m 4096 -smp 4,sockets=2,cores=2,threads=1,maxcpus=6 -usb -device usb-tablet,id=input0 -name sluo_migration -uuid 990ea161-6b67-47b2-b803-19fb01d30d30 -rtc base=localtime,clock=host,driftfix=slew -device virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x3 -drive file=/mnt/RHEL-Server-6.4-64-virtio.qcow2,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop -device virtio-blk-pci,bus=pci.0,addr=0x4,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -netdev tap,id=hostnet0,vhost=on,script=/etc/qemu-ifup -device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=08:2E:5F:0A:0D:B1,bus=pci.0,addr=0x5 -chardev pty,id=charserial0 -device isa-serial,chardev=charserial0,id=serial0 -chardev spicevmc,id=charchannel0,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.spice.0 -spice port=5931,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -device intel-hda,id=sound0,bus=pci.0,addr=0x6 -device hda-duplex -device usb-ehci,id=ehci,addr=0x7 -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1,bus=ehci.0,debug=4 -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x8 -global PIIX4_PM.disable_s3=0 -global PIIX4_PM.disable_s4=0 -serial unix:/tmp/ttyS0,server,nowait -qmp tcp:0:4444,server,nowait -monitor stdio 2> /home/log.txt

Comment 34 Sibiao Luo 2012-12-05 06:19:49 UTC
Created attachment 657991 [details]
bug868766-src-qemu-logs.

Comment 35 Sibiao Luo 2012-12-05 06:20:23 UTC
Created attachment 657992 [details]
bug868766-dest-qemu-logs.

Comment 36 Sibiao Luo 2012-12-05 06:21:22 UTC
Created attachment 657993 [details]
guest-dmesg.

Comment 37 Sibiao Luo 2012-12-05 06:22:53 UTC
Created attachment 657994 [details]
dd-logs.

Comment 38 Hans de Goede 2012-12-05 08:10:00 UTC
(In reply to comment #35)
> Created attachment 657992 [details]
> bug868766-dest-qemu-logs.

Looking at this log I see everything working fine and usb traffic continues normally for a long time after migration, until the client disconnects.

Note that with spice usb-redirection the usb traffic goes over the spice-connection and thus through the client, so if you disconnect the client, you also disconnect / unplug the usb-device from the virtual machine, this is expected behavior !!!

(In reply to comment #36)
> Created attachment 657993 [details]
> guest-dmesg.

And in here I see the device disconnect, which happens when the client disconnects, which is expected behavior. With spice usb-redirection the virtual usb "wire" runs from the real device through the client, over the clients network connection to the vm.

So if you disconnect / quit the client then the network connection is broken and thus the virtual usb wire, and breaking the virtual usb connection has the same result as breaking a real physical usb connection, the device gets unplugged.

###

So everything is working as expected usb traffic continues normally until you quit / disconnect the client, at which point the device disconnect you are seeing is normal -> NOTABUG.