Re: [Qemu-devel] [RFC] Break cross migration from qemu-1.5 to qemu-2.1. because of input/hid rewriting

[Gonglei <arei.gonglei@huawei.com>]

On 2014/11/21 23:16, Dr. David Alan Gilbert wrote:

> * Gonglei (arei.gonglei@huawei.com) wrote:
>> > Hi, Gerd
>> > 
>> > I encounter a problem that breaking  migration from qemu-1.5 to qemu-2.1.
>> > The error message as below:
>> >  qemu-system-x86_64: hw/input/hid.c:121: hid_pointer_event: Assertion `hs->n < 16' failed.
>> > Qemu assert in hid_pointer_event().
> What is your test to reproduce this?
> 
> Dave
> 

That's very easy.

a) Add some log in hid.c:

diff --git a/hw/input/hid.c b/hw/input/hid.c
index 148c003..6908680 100644
--- a/hw/input/hid.c
+++ b/hw/input/hid.c
@@ -161,12 +161,13 @@ static void hid_pointer_sync(DeviceState *dev)
     HIDState *hs = (HIDState *)dev;
     HIDPointerEvent *prev, *curr, *next;
     bool event_compression = false;
-
+    printf("hs->n = %d\n", hs->n);
     if (hs->n == QUEUE_LENGTH-1) {
         /*
          * Queue full.  We are losing information, but we at least
          * keep track of most recent button state.
          */
+        printf("Queue full....\n");
         return;
     }

b) Reproduce Steps:
1. An image without graphic mode. You can set "runlevel = 3"
2. Booting Guest with below Qemu cmdline:
 # ./qemu-system-x86_64 -enable-kvm -m 4096 -smp 4 -name redhat6.2 -drive file=/home/redhat_6.4_64 -device piix3-usb-uhci,id=uhci -device usb-tablet,bus=uhci.0,id=tablet.0 -vnc :10
3. Click, meanwhile move mouse ceaselessly.

c) Get result:
hs->n = 0
hs->n = 1
hs->n = 1
hs->n = 1
hs->n = 1
hs->n = 1
hs->n = 2
hs->n = 3
hs->n = 4
hs->n = 5
hs->n = 6
hs->n = 7
hs->n = 8
hs->n = 9
hs->n = 10
hs->n = 11
hs->n = 12
hs->n = 13
hs->n = 14
hs->n = 15
Queue full....
hs->n = 15
Queue full....
hs->n = 15
Queue full....
hs->n = 15
Queue full....
hs->n = 15
Queue full....

We can see the Queue is full and will decrease, that's say hid_pointer_poll() will not be called.
Normally, hid_pointer_poll() is called by below backstrace:

Breakpoint 1, hid_pointer_poll (hs=0x55555649d578, buf=0x55555649bf9c "\005\001\t\001\241\001\t\001\241", len=6)
    at hw/input/hid.c:322
322     {
(gdb) bt
#0  hid_pointer_poll (hs=0x55555649d578, buf=0x55555649bf9c "\005\001\t\001\241\001\t\001\241", len=6) at hw/input/hid.c:322
#1  0x00005555558c3b92 in usb_hid_handle_control (dev=0x55555649bec0, p=0x5555563f4410, request=41217, value=256, index=0, length=
    6, data=0x55555649bf9c "\005\001\t\001\241\001\t\001\241") at hw/usb/dev-hid.c:609
#2  0x00005555558a2999 in usb_device_handle_control (dev=0x55555649bec0, p=0x5555563f4410, request=41217, value=256, index=0,
    length=6, data=0x55555649bf9c "\005\001\t\001\241\001\t\001\241") at hw/usb/bus.c:171
#3  0x000055555589f42d in do_token_setup (s=0x55555649bec0, p=0x5555563f4410) at hw/usb/core.c:140
#4  0x000055555589fe8a in usb_process_one (p=0x5555563f4410) at hw/usb/core.c:383
#5  0x00005555558a00c7 in usb_handle_packet (dev=0x55555649bec0, p=0x5555563f4410) at hw/usb/core.c:428
#6  0x00005555558a9ac0 in uhci_handle_td (s=0x5555563fdf20, q=0x55555649f240, qh_addr=931145090, td=0x7fffffffd8a0, td_addr=
    931140928, int_mask=0x7fffffffd8cc) at hw/usb/hcd-uhci.c:867
#7  0x00005555558aa1e5 in uhci_process_frame (s=0x5555563fdf20) at hw/usb/hcd-uhci.c:1054
#8  0x00005555558aa826 in uhci_frame_timer (opaque=0x5555563fdf20) at hw/usb/hcd-uhci.c:1153
#9  0x000055555594ed57 in timerlist_run_timers (timer_list=0x555556346650) at qemu-timer.c:491
#10 0x000055555594edbf in qemu_clock_run_timers (type=QEMU_CLOCK_VIRTUAL) at qemu-timer.c:502
#11 0x000055555594f2b7 in qemu_clock_run_all_timers () at qemu-timer.c:608
#12 0x000055555594d604 in main_loop_wait (nonblocking=0) at main-loop.c:500
#13 0x0000555555756b67 in main_loop () at vl.c:1882
#14 0x000055555575e40e in main (argc=16, argv=0x7fffffffe0e8, envp=0x7fffffffe170) at vl.c:4400

But when Guest in non-graphic mode. the UHCI timer will be deleted because:
    if (!(s->cmd & UHCI_CMD_RS)) {
        /* Full stop */
        trace_usb_uhci_schedule_stop();
        timer_del(s->frame_timer);
        uhci_async_cancel_all(s);
        /* set hchalted bit in status - UHCI11D 2.1.2 */
        s->status |= UHCI_STS_HCHALTED;
        return;
    }

...and don't call  uhci_process_frame().

So, if somebody start VM with Qemu-1.5 and do above operations, then hs->n will arrive to 16 quickly,
migrate the VM to Qemu-2.1 or later version, The Qemu assert inevitably.
I think this problem is a big potential bug, caused by cross-version migration.

Gerd, what's your opinion? Thanks.

Best regards,
-Gonglei