Bug 868747
| Summary: | core dump when do live migration with spicy + usb redirection (seamless-migration=on) | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 6 | Reporter: | Sibiao Luo <sluo> | ||||||
| Component: | spice-server | Assignee: | Uri Lublin <uril> | ||||||
| Status: | CLOSED NOTABUG | QA Contact: | Desktop QE <desktop-qa-list> | ||||||
| Severity: | high | Docs Contact: | |||||||
| Priority: | medium | ||||||||
| Version: | 6.4 | CC: | acathrow, areis, bsarathy, cfergeau, chayang, dblechte, dyasny, flang, hdegoede, juzhang, michen, mkenneth, owasserm, quintela, qzhang, shuang, virt-maint, xfu, yhalperi | ||||||
| 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-11-27 16:51:01 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: | |||||||||
| Bug Depends On: | |||||||||
| Bug Blocks: | 808057 | ||||||||
| Attachments: |
|
||||||||
My two 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 : 6782.75 clflush size : 64 cache_alignment : 64 address sizes : 36 bits physical, 48 bits virtual power management: Can you reproduce this? Does it happen every time you try this, or does it only happen every now and then ? (In reply to comment #2) > Can you reproduce this? Does it happen every time you try this, or does it > only happen every now and then ? yes, i tried many times, all of them can hit this issue. btw, spice-gtk-0.14-5.el6.x86_64 and spice-gtk-tools-0.14-5.el6.x86_64 also can hit this issue. host info: # uname -r && rpm -q qemu-kvm 2.6.32-335.el6.x86_64 qemu-kvm-0.12.1.2-2.331.el6.x86_64 (/usr/bin/gdb:2605): Spice-ERROR **: char_device.c:898:spice_char_device_state_restore: assertion `!dev->cur_write_buf && ring_is_empty(&dev->write_queue)' failed Detaching after fork from child process 2712. Program received signal SIGABRT, Aborted. 0x00007ffff57468a5 in raise () from /lib64/libc.so.6 (gdb) bt #0 0x00007ffff57468a5 in raise () from /lib64/libc.so.6 #1 0x00007ffff5748085 in abort () from /lib64/libc.so.6 #2 0x00007ffff5fa0c35 in spice_logv (log_domain=0x7ffff6017c4e "Spice", log_level=SPICE_LOG_LEVEL_ERROR, strloc=0x7ffff6017fbb "char_device.c:898", function= 0x7ffff6018020 "spice_char_device_state_restore", format=0x7ffff6017c38 "assertion `%s' failed", args=0x7fffffffc620) at log.c:109 #3 0x00007ffff5fa0d6a in spice_log (log_domain=<value optimized out>, log_level=<value optimized out>, strloc=<value optimized out>, function=<value optimized out>, format=<value optimized out>) at log.c:123 #4 0x00007ffff5f4c76e in spice_char_device_state_restore (dev=0x7ffff8904ae0, mig_data=0x7ffff8918228) at char_device.c:898 #5 0x00007ffff5f5a8ff in red_channel_handle_migrate_data (rcc=0x7ffff9d882a0, size=33, type=<value optimized out>, message=0x7ffff8918220) at red_channel.c:1157 #6 red_channel_client_handle_message (rcc=0x7ffff9d882a0, size=33, type=<value optimized out>, message=0x7ffff8918220) at red_channel.c:1189 #7 0x00007ffff5f5a2f4 in red_peer_handle_incoming (rcc=0x7ffff9d882a0) at red_channel.c:276 #8 red_channel_client_receive (rcc=0x7ffff9d882a0) at red_channel.c:294 #9 0x00007ffff5f5aa9c in red_channel_client_event (fd=<value optimized out>, event=<value optimized out>, data=0x7ffff9d882a0) at red_channel.c:1204 #10 0x00007ffff7de279f in main_loop_wait (timeout=1000) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:3980 #11 0x00007ffff7e0475a in kvm_main_loop () at /usr/src/debug/qemu-kvm-0.12.1.2/qemu-kvm.c:2244 #12 0x00007ffff7de542a in main_loop (argc=74, argv=<value optimized out>, envp=<value optimized out>) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:4192 #13 main (argc=74, argv=<value optimized out>, envp=<value optimized out>) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:6528 (gdb) Hi, (In reply to comment #3) > (In reply to comment #2) > > Can you reproduce this? Does it happen every time you try this, or does it > > only happen every now and then ? > > yes, i tried many times, all of them can hit this issue. Ok, good to know. And you're only seeing this when using spicy, not when using remote-viewer, right ? Regards, Hans (In reply to comment #4) > Hi, > > (In reply to comment #3) > > (In reply to comment #2) > > > Can you reproduce this? Does it happen every time you try this, or does it > > > only happen every now and then ? > > > > yes, i tried many times, all of them can hit this issue. > > Ok, good to know. And you're only seeing this when using spicy, not when > using remote-viewer, right ? > yes, i just use the spicy to connect spice client with spicy tools (provided by spice-gtk-tools) for this bug. # spicy -h $ip_addr -p $port Best Regards. sluo I'm afraid I cannot reproduce this issue... Are you sure your testing exactly the same way as when using remote-viewer ? Perhaps you're doing something else different which is causing this ? (In reply to comment #6) > I'm afraid I cannot reproduce this issue... Are you sure your testing > exactly the same way as when using remote-viewer ? Perhaps you're doing > something else different which is causing this ? No, just the steps exactly as the comment #0, both the spice-gtk-0.14-5.el6.x86_64 and spice-gtk-tools-0.14-5.el6.x86_64 can hit this issue. (In reply to comment #7) > (In reply to comment #6) > > I'm afraid I cannot reproduce this issue... Are you sure your testing > > exactly the same way as when using remote-viewer ? Perhaps you're doing > > something else different which is causing this ? > > No, just the steps exactly as the comment #0, both the > spice-gtk-0.14-5.el6.x86_64 and spice-gtk-tools-0.14-5.el6.x86_64 can hit > this issue. both spice-gtk-tools-0.14-4.el6.x86_64 and spice-gtk-tools-0.14-5.el6.x86_64 In rhel only remote-viewer client is supported (not spicec! and not spicy!), and reporter confirmed in comment 5 that the bug is reproducible only with spicy. Hi Yonit, I capture the full qemu logs of the src and dest qeme with a spice debug messages (export SPICE_DEBUG_LEVEL=5) as your instruction. btw, this issue not 100% reproduce but always occur. 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-4.el6.x86_64 spice-gtk-tools-0.14-4.el6.x86_64 guest info: kernel-2.6.32-279.el6.x86_64 steps& results: the same as comment #0. I will attach the qemu logs later. Created attachment 657298 [details]
src-qemu-logs.
Created attachment 657299 [details]
dest-qemu-logs.
Hi Yonit,
My qemu-kvm commands and core dump logs.
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=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 -incoming tcp:0:5888,server,nowait 2> /home/log.txt
(qemu) info status
VM status: paused (incoming-migration)
(qemu)
Detaching after fork from child process 19626.
Program received signal SIGABRT, Aborted.
0x00007ffff574a8a5 in raise () from /lib64/libc.so.6
(gdb)
(gdb) bt
#0 0x00007ffff574a8a5 in raise () from /lib64/libc.so.6
#1 0x00007ffff574c085 in abort () from /lib64/libc.so.6
#2 0x00007ffff5fa4c15 in spice_logv (log_domain=0x7ffff601bc2e "Spice", log_level=SPICE_LOG_LEVEL_ERROR, strloc=0x7ffff601bf9b "char_device.c:898",
function=0x7ffff601c000 "spice_char_device_state_restore", format=0x7ffff601bc18 "assertion `%s' failed", args=0x7fffffffc610) at log.c:109
#3 0x00007ffff5fa4d4a in spice_log (log_domain=<value optimized out>, log_level=<value optimized out>, strloc=<value optimized out>, function=<value optimized out>,
format=<value optimized out>) at log.c:123
#4 0x00007ffff5f5078e in spice_char_device_state_restore (dev=0x7ffff890a190, mig_data=0x7ffff89f5ef8) at char_device.c:898
#5 0x00007ffff5f5e8df in red_channel_handle_migrate_data (rcc=0x7ffff9da72b0, size=33, type=<value optimized out>, message=0x7ffff89f5ef0) at red_channel.c:1157
#6 red_channel_client_handle_message (rcc=0x7ffff9da72b0, size=33, type=<value optimized out>, message=0x7ffff89f5ef0) at red_channel.c:1189
#7 0x00007ffff5f5e2d4 in red_peer_handle_incoming (rcc=0x7ffff9da72b0) at red_channel.c:276
#8 red_channel_client_receive (rcc=0x7ffff9da72b0) at red_channel.c:294
#9 0x00007ffff5f5ea7c in red_channel_client_event (fd=<value optimized out>, event=<value optimized out>, data=0x7ffff9da72b0) at red_channel.c:1204
#10 0x00007ffff7de540f in main_loop_wait (timeout=1000) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:3994
#11 0x00007ffff7e071ba in kvm_main_loop () at /usr/src/debug/qemu-kvm-0.12.1.2/qemu-kvm.c:2244
#12 0x00007ffff7de7f65 in main_loop (argc=20, argv=<value optimized out>, envp=<value optimized out>) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:4206
#13 main (argc=20, argv=<value optimized out>, envp=<value optimized out>) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:6443
(gdb) q
|
Description of problem: There is I/O to the USB-disk, and then do live migration with usb redirection (seamless-migration=on), the dst will core dump after src migration completed. Version-Release number of selected component (if applicable): host info: # uname -r && rpm -q qemu-kvm 2.6.32-331.el6.x86_64 qemu-kvm-0.12.1.2-2.327.el6.x86_64 # rpm -qa | grep spice-gtk spice-gtk-python-0.14-4.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 spice client with spicy tools (provided by spice-gtk-tools) 3.Select "Auto redirect newly plugged in USB devices" in "Option" menu, and then plug a USB disk to spice client host. 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 dst will core dump after src migration completed. in src: (qemu) info migrate Migration status: completed in dst: (qemu) info status VM status: paused (incoming-migration) (qemu) red_dispatcher_loadvm_commands: (/usr/bin/gdb:18107): Spice-ERROR **: char_device.c:898:spice_char_device_state_restore: assertion `!dev->cur_write_buf && ring_is_empty(&dev->write_queue)' failed Detaching after fork from child process 18122. Program received signal SIGABRT, Aborted. 0x00007ffff574a8a5 in raise () from /lib64/libc.so.6 (gdb) bt #0 0x00007ffff574a8a5 in raise () from /lib64/libc.so.6 #1 0x00007ffff574c085 in abort () from /lib64/libc.so.6 #2 0x00007ffff5fa3c35 in spice_logv (log_domain=0x7ffff601ac4e "Spice", log_level=SPICE_LOG_LEVEL_ERROR, strloc=0x7ffff601afbb "char_device.c:898", function=0x7ffff601b020 "spice_char_device_state_restore", format=0x7ffff601ac38 "assertion `%s' failed", args=0x7fffffffc3d0) at log.c:109 #3 0x00007ffff5fa3d6a in spice_log (log_domain=<value optimized out>, log_level=<value optimized out>, strloc=<value optimized out>, function=<value optimized out>, format=<value optimized out>) at log.c:123 #4 0x00007ffff5f4f76e in spice_char_device_state_restore (dev=0x7ffff8a634f0, mig_data=0x7ffff8a9fc78) at char_device.c:898 #5 0x00007ffff5f5d8ff in red_channel_handle_migrate_data (rcc=0x7ffff9eed6c0, size=33, type=<value optimized out>, message=0x7ffff8a9fc70) at red_channel.c:1157 #6 red_channel_client_handle_message (rcc=0x7ffff9eed6c0, size=33, type=<value optimized out>, message=0x7ffff8a9fc70) at red_channel.c:1189 #7 0x00007ffff5f5d2f4 in red_peer_handle_incoming (rcc=0x7ffff9eed6c0) at red_channel.c:276 #8 red_channel_client_receive (rcc=0x7ffff9eed6c0) at red_channel.c:294 #9 0x00007ffff5f5da9c in red_channel_client_event (fd=<value optimized out>, event=<value optimized out>, data=0x7ffff9eed6c0) at red_channel.c:1204 #10 0x00007ffff7de540f in main_loop_wait (timeout=1000) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:3994 #11 0x00007ffff7e071ba in kvm_main_loop () at /usr/src/debug/qemu-kvm-0.12.1.2/qemu-kvm.c:2244 #12 0x00007ffff7de7f65 in main_loop (argc=20, argv=<value optimized out>, envp=<value optimized out>) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:4206 #13 main (argc=20, argv=<value optimized out>, envp=<value optimized out>) at /usr/src/debug/qemu-kvm-0.12.1.2/vl.c:6443 (gdb) q Expected results: migration finished successfully with usb redirection (seamless-migration=on), the usb disk is still over there and guest work well, and can still read/write to the USB disk successfully. Additional info: