Bug 883578

Summary: remote-viewer gets frozen after migration of guest with video playback.
Product: Red Hat Enterprise Linux 6 Reporter: Marian Krcmarik <mkrcmari>
Component: xorg-x11-drv-qxlAssignee: Uri Lublin <uril>
Status: CLOSED ERRATA QA Contact: Desktop QE <desktop-qa-list>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.4CC: acathrow, cfergeau, cpelland, dblechte, ddumas, dyasny, marcandre.lureau, mkenneth, tlavigne, uril
Target Milestone: rcKeywords: Regression
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: xorg-x11-drv-qxl-0.1.0-4.el6 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-02-21 08:16:30 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: 902691    

Description Marian Krcmarik 2012-12-04 22:14:51 UTC
Description of problem:
remote-viewer gets frozen after migration of guest with video playback. See the log from remote-viewer during being frozen. Qemu ends up with:
"red_worker.c:9369:flush_display_commands: update timeout"
I am not sure but maybe related to bz #883564.

Video: MPEG-4 video 512x384, Frame rate 25 

Qemu CLI:
/usr/libexec/qemu-kvm -enable-kvm -m 1024 -smp 1 -spice port=5900,disable-ticketing,seamless-migration=on -vga qxl -global qxl-vga.vram_size=67108864 -device qxl -monitor stdio -device virtio-serial-pci,id=virtio_serial_pci0 -chardev spicevmc,id=devvdagent,name=vdagent -device virtserialport,chardev=devvdagent,name=com.redhat.spice.0,id=vdagent,bus=virtio_serial_pci0.0 /dev/mapper/rootvg-rhel6x64

Version-Release number of selected component (if applicable):
Client is RHEL6.4 Beta 32 bit with:
spice-gtk-0.14-4.el6.i686
virt-viewer-0.5.2-16.el6.i686

HOST RHEL6.4 beta:
spice-server-0.12.0-6.el6.x86_64
qemu-kvm-0.12.1.2-2.337.el6.x86_64

Guest is RHEL6.4 beta

How reproducible:
Always

Steps to Reproduce:
1. Connect to a RHEL guest with playing video in a video player (vlc in my case).
2. Migrate the guest

  
Actual results:
Frozen spice client

Expected results:
smooth migration

Additional info:
$ remote-viewer spice://10.34.131.204:5900

(remote-viewer:7630): GSpice-WARNING **: Warning no automount-inhibiting implementation available
(remote-viewer:7630): GSpice-DEBUG: #0 +0+0-1024x768

(remote-viewer:7630): GSpice-WARNING **: MonitorConfig max_allowed is not within permitted range, clamping

(remote-viewer:7630): GSpice-WARNING **: MonitorConfig count is not within permitted range, clamping

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -11584186

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -11584186

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10925232

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -11186859

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10988969

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10857383

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -11186348

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -11449518

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10660002

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10265498

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10397084

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10396314

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10461594

(remote-viewer:7630): GSpice-CRITICAL **: spice_main_set_display_enabled: assertion `id < G_N_ELEMENTS(c->display)' failed

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10265498

(remote-viewer:7630): GSpice-CRITICAL **: spice_main_set_display_enabled: assertion `id < G_N_ELEMENTS(c->display)' failed

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10331291

(remote-viewer:7630): GSpice-CRITICAL **: spice_main_set_display_enabled: assertion `id < G_N_ELEMENTS(c->display)' failed

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10462107

(remote-viewer:7630): GSpice-CRITICAL **: spice_main_set_display_enabled: assertion `id < G_N_ELEMENTS(c->display)' failed

(remote-viewer:7630): GSpice-WARNING **: FIXME: only support monitor config with primary surface 0, but given config surface -10132888
.......................

Comment 3 Marian Krcmarik 2012-12-11 16:28:18 UTC
My suspicious that the bug might be related to bz #883564 was not correct, the bug is still observed even though fixed spice-server was used.

Comment 4 Marc-Andre Lureau 2012-12-20 15:09:27 UTC
confirmed, looking at it

Comment 5 Marc-Andre Lureau 2012-12-20 15:13:39 UTC
since after reconnection the client keeps receiving garbage on display channel, it is most likely something wrong on server side, moving thre

Comment 6 Marc-Andre Lureau 2012-12-21 00:18:24 UTC
For some reason I can't explain yet, the dev_monitors_config is full of garbage after seamless migration, only *while playing a video*:

11340	    QXLMonitorsConfig *dev_monitors_config =
11341	        (QXLMonitorsConfig*)get_virt(&worker->mem_slots, msg->monitors_config,
11342	                                     min_size, msg->group_id, &error);

(The msg->monitors_config from QEMU PCIQXLDevice->guest_monitors_config copied during migration seems to be correct in all cases)..

Comment 7 Marc-Andre Lureau 2012-12-21 12:54:19 UTC
Apparently something got wrong in guest memory:

Old value = {count = 0, max_allowed = 0, heads = 0x7fff9b3e4004}
New value = {count = 1, max_allowed = 4, heads = 0x7fff9b3e4004}
__memcpy_ssse3_back () at ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S:1338
1338		add	$0x80, %rdx
(gdb) bt
#0  __memcpy_ssse3_back () at ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S:1338
#1  0x00000000004bc43a in qemu_peek_buffer (f=0x145c890, buf=0x7fff9b3e4000 "\001", 
    size=4096, offset=0) at savevm.c:568
#2  0x00000000004bc479 in qemu_get_buffer (f=0x145c890, buf=0x7fff9b3e4000 "\001", 
    size=4096) at savevm.c:580
#3  0x000000000040fb12 in ram_load (f=0x145c890, opaque=0x0, version_id=4)
    at /home/elmarco/320g/src/qemu/vl.c:3069
#4  0x00000000004bdf41 in vmstate_load (f=0x145c890, se=0xdf3e10, version_id=4)
    at savevm.c:1451
#5  0x00000000004becfd in qemu_loadvm_state (f=0x145c890) at savevm.c:1857
#6  0x00000000004b35a5 in process_incoming_migration (f=0x145c890) at migration.c:73
#7  0x00000000004b47a4 in tcp_accept_incoming_migration (opaque=0x1a)
    at migration-tcp.c:133
#8  0x00000000004109e3 in main_loop_wait (timeout=1000)
    at /home/elmarco/320g/src/qemu/vl.c:3975
#9  0x000000000043e8fa in kvm_main_loop ()
    at /home/elmarco/320g/src/qemu/qemu-kvm.c:2244
#10 0x000000000041111e in main_loop () at /home/elmarco/320g/src/qemu/vl.c:4187
#11 0x0000000000415850 in main (argc=20, argv=0x7fffffffda38, envp=0x7fffffffdae0)
    at /home/elmarco/320g/src/qemu/vl.c:6525


Old value = {count = 0, max_allowed = 0, heads = 0x7fff9b3e4004}
New value = {count = 64507, max_allowed = 65531, heads = 0x7fff9b3e4004}
__memcpy_ssse3_back () at ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S:189
189		add	$0x80, %rdx
(gdb) bt
#0  __memcpy_ssse3_back () at ../sysdeps/x86_64/multiarch/memcpy-ssse3-back.S:189
#1  0x00000000004bc43a in qemu_peek_buffer (f=0x145c890, 
    buf=0x7fff9b3e4000 "\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377"..., size=4096, offset=0) at savevm.c:568
#2  0x00000000004bc479 in qemu_get_buffer (f=0x145c890, 
    buf=0x7fff9b3e4000 "\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377\373\373\373\377"..., size=4096) at savevm.c:580
#3  0x000000000040fb12 in ram_load (f=0x145c890, opaque=0x0, version_id=4)
    at /home/elmarco/320g/src/qemu/vl.c:3069
#4  0x00000000004bdf41 in vmstate_load (f=0x145c890, se=0xdf3e10, version_id=4)
    at savevm.c:1451
#5  0x00000000004becfd in qemu_loadvm_state (f=0x145c890) at savevm.c:1857
#6  0x00000000004b35a5 in process_incoming_migration (f=0x145c890) at migration.c:73
#7  0x00000000004b47a4 in tcp_accept_incoming_migration (opaque=0x1a)
    at migration-tcp.c:133

Comment 8 Marc-Andre Lureau 2012-12-21 14:15:45 UTC
Corruption seems to happen on source side, while playing video in full screen:

Old value = {count = 1, max_allowed = 4, heads = 0x7fff9b3e4004}
New value = {count = 7955, max_allowed = 65309, heads = 0x7fff9b3e4004}
ring_next (ring=0x7fffe021d6b0, pos=0x7fffe029e1f0)
    at ../spice-common/common/ring.h:116
116	{
(gdb) bt
#0  ring_next (ring=0x7fffe021d6b0, pos=0x7fffe029e1f0)
    at ../spice-common/common/ring.h:116
#1  0x00007ffff77473b7 in red_channel_min_pipe_size (channel=0x7fffe021d680)
    at red_channel.c:1865
#2  0x00007ffff775d48a in red_process_cursor (worker=0x7fffe00008c0, max_pipe_size=50, 
    ring_is_empty=0x7fffedffbbc0) at red_worker.c:4858
#3  0x00007ffff77724b2 in red_worker_main (arg=0x7fffffffd090) at red_worker.c:11878
#4  0x00000036a0207d14 in start_thread (arg=0x7fffedffc700) at pthread_create.c:309
#5  0x000000369faf168d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

Comment 10 Uri Lublin 2013-01-15 13:57:20 UTC
Looking at the xorg-x11-drv-qxl code, I see in qxl_pre_init():
    pScrn->videoRam = (qxl->rom->num_pages * 4096) / 1024

I think that since monitors_config structure is allocated from "num_pages", the
size allocated to monitors_config should be subtracted.

Comment 11 Uri Lublin 2013-01-16 22:22:59 UTC
I think there is another problem with monitors_config in the Linux qxl driver:
Memory mapping may change (e.g. qxl_reset_and_create_mem_slots() and setup_slot()) but the monitors_config address does not change accordingly.

BTW, I think Hans' second patch for bug 868807 also helps this bug:
  "worker_update_monitors_config: Drop bogus real_count accounting"

Investigation is ongoing.

Comment 13 Uri Lublin 2013-01-17 00:09:42 UTC
(In reply to comment #11)
> Memory mapping may change ...
> ... but the monitors_config address does not change accordingly.

Also may be related to qxl_map_memory() followed by a qxl_resize_surface0()

Comment 14 Uri Lublin 2013-01-17 15:23:23 UTC
The problem is as follows:

1. monitors_config address is set once in the driver.
2. upon memory-remap, it may happen that monitors_config memory area overlaps with video-memory.
3. playing video writes into video-memory pages, that overwrites monitors_config values.
4. as part of migration (post load), the destination host reads bad values of monitors config.
5. both server and client get confused.

Fixed (in 012057) by adjusting monitors_config pointer when memory-remap occurs.

A patch-set was sent upstream starts with 012052 and ends with 012057:
  http://lists.freedesktop.org/archives/spice-devel/2013-January/012052.html

Comment 18 errata-xmlrpc 2013-02-21 08:16:30 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

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

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

http://rhn.redhat.com/errata/RHBA-2013-0308.html