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

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

[Gonglei]

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().

I get the value of hs->n which is 16 by  reproduction. And the code of qemu-1.5 :

static void hid_pointer_event(void *opaque,
                              int x1, int y1, int z1, int buttons_state)
{
    HIDState *hs = opaque;
    unsigned use_slot = (hs->head + hs->n - 1) & QUEUE_MASK;
    unsigned previous_slot = (use_slot - 1) & QUEUE_MASK;

    if (hs->n == QUEUE_LENGTH) {
        /* Queue full.  Discard old button state, combine motion normally.  */
        hs->ptr.queue[use_slot].buttons_state = buttons_state;
    }

Which indicate it is legal when hs->n == QUEUE_LENGTH.

But now:
static void hid_pointer_event(DeviceState *dev, QemuConsole *src,
                              InputEvent *evt)
{
    static const int bmap[INPUT_BUTTON_MAX] = {
        [INPUT_BUTTON_LEFT]   = 0x01,
        [INPUT_BUTTON_RIGHT]  = 0x02,
        [INPUT_BUTTON_MIDDLE] = 0x04,
    };
    HIDState *hs = (HIDState *)dev;
    HIDPointerEvent *e;

    assert(hs->n < QUEUE_LENGTH);
    e = &hs->ptr.queue[(hs->head + hs->n) & QUEUE_MASK];
...

static void hid_pointer_sync(DeviceState *dev)
{
    HIDState *hs = (HIDState *)dev;
    HIDPointerEvent *prev, *curr, *next;
    bool event_compression = false;

    if (hs->n == QUEUE_LENGTH-1) {
        /*
         * Queue full.  We are losing information, but we at least
         * keep track of most recent button state.
         */
        return;
    }

What about this patch:

diff --git a/hw/input/hid.c b/hw/input/hid.c
index 148c003..56e0637 100644
--- a/hw/input/hid.c
+++ b/hw/input/hid.c
@@ -116,7 +116,7 @@ static void hid_pointer_event(DeviceState *dev, QemuConsole *src,
     HIDState *hs = (HIDState *)dev;
     HIDPointerEvent *e;

-    assert(hs->n < QUEUE_LENGTH);
+    assert(hs->n <= QUEUE_LENGTH);
     e = &hs->ptr.queue[(hs->head + hs->n) & QUEUE_MASK];

     switch (evt->kind) {

Best regards,
-Gonglei

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

[Gerd Hoffmann]

> What about this patch:
> 
> diff --git a/hw/input/hid.c b/hw/input/hid.c
> index 148c003..56e0637 100644
> --- a/hw/input/hid.c
> +++ b/hw/input/hid.c
> @@ -116,7 +116,7 @@ static void hid_pointer_event(DeviceState *dev, QemuConsole *src,
>      HIDState *hs = (HIDState *)dev;
>      HIDPointerEvent *e;
> 
> -    assert(hs->n < QUEUE_LENGTH);
> +    assert(hs->n <= QUEUE_LENGTH);
>      e = &hs->ptr.queue[(hs->head + hs->n) & QUEUE_MASK];
> 
>      switch (evt->kind) {

No.  There is a reason this assert is in there.  This needs to be
handled in a post_load function, to bring the queue into a state 2.1 can
deal with.

Easiest would be to just flush the queue in case n == 16, or leave in
there a single event with final pointer location and button state.

I think you can also try to combine events (like it is done for
event_compression = true).  qemu 1.5 was less aggressive in doing that
(only did it when the queue was full), so chances are high that you'll
find events in the queue with identical button state where you can
either just drop all but the last first (tablet mode) or add up the
motions (mouse mode).  Not sure it is worth the trouble though.

cheers,
  Gerd

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

[Gonglei]

On 2014/11/21 16:06, Gerd Hoffmann wrote:

>> What about this patch:
>>
>> diff --git a/hw/input/hid.c b/hw/input/hid.c
>> index 148c003..56e0637 100644
>> --- a/hw/input/hid.c
>> +++ b/hw/input/hid.c
>> @@ -116,7 +116,7 @@ static void hid_pointer_event(DeviceState *dev, QemuConsole *src,
>>      HIDState *hs = (HIDState *)dev;
>>      HIDPointerEvent *e;
>>
>> -    assert(hs->n < QUEUE_LENGTH);
>> +    assert(hs->n <= QUEUE_LENGTH);
>>      e = &hs->ptr.queue[(hs->head + hs->n) & QUEUE_MASK];
>>
>>      switch (evt->kind) {
> 
> No.  There is a reason this assert is in there.  This needs to be
> handled in a post_load function, to bring the queue into a state 2.1 can
> deal with.
> 

OK.

> Easiest would be to just flush the queue in case n == 16, or leave in
> there a single event with final pointer location and button state.
> 
> I think you can also try to combine events (like it is done for
> event_compression = true).  qemu 1.5 was less aggressive in doing that
> (only did it when the queue was full), so chances are high that you'll
> find events in the queue with identical button state where you can
> either just drop all but the last first (tablet mode) or add up the
> motions (mouse mode).  Not sure it is worth the trouble though.
> 

Sorry, I'm not familiar with the realization of input/hid module. Could you
please post a patch for this issue? Thanks a lot!

Best regards,
-Gonglei

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

[Dr. David Alan Gilbert]

* 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

> I get the value of hs->n which is 16 by  reproduction. And the code of qemu-1.5 :
> 
> static void hid_pointer_event(void *opaque,
>                               int x1, int y1, int z1, int buttons_state)
> {
>     HIDState *hs = opaque;
>     unsigned use_slot = (hs->head + hs->n - 1) & QUEUE_MASK;
>     unsigned previous_slot = (use_slot - 1) & QUEUE_MASK;
> 
>     if (hs->n == QUEUE_LENGTH) {
>         /* Queue full.  Discard old button state, combine motion normally.  */
>         hs->ptr.queue[use_slot].buttons_state = buttons_state;
>     }
> 
> Which indicate it is legal when hs->n == QUEUE_LENGTH.
> 
> But now:
> static void hid_pointer_event(DeviceState *dev, QemuConsole *src,
>                               InputEvent *evt)
> {
>     static const int bmap[INPUT_BUTTON_MAX] = {
>         [INPUT_BUTTON_LEFT]   = 0x01,
>         [INPUT_BUTTON_RIGHT]  = 0x02,
>         [INPUT_BUTTON_MIDDLE] = 0x04,
>     };
>     HIDState *hs = (HIDState *)dev;
>     HIDPointerEvent *e;
> 
>     assert(hs->n < QUEUE_LENGTH);
>     e = &hs->ptr.queue[(hs->head + hs->n) & QUEUE_MASK];
> ...
> 
> static void hid_pointer_sync(DeviceState *dev)
> {
>     HIDState *hs = (HIDState *)dev;
>     HIDPointerEvent *prev, *curr, *next;
>     bool event_compression = false;
> 
>     if (hs->n == QUEUE_LENGTH-1) {
>         /*
>          * Queue full.  We are losing information, but we at least
>          * keep track of most recent button state.
>          */
>         return;
>     }
> 
> What about this patch:
> 
> diff --git a/hw/input/hid.c b/hw/input/hid.c
> index 148c003..56e0637 100644
> --- a/hw/input/hid.c
> +++ b/hw/input/hid.c
> @@ -116,7 +116,7 @@ static void hid_pointer_event(DeviceState *dev, QemuConsole *src,
>      HIDState *hs = (HIDState *)dev;
>      HIDPointerEvent *e;
> 
> -    assert(hs->n < QUEUE_LENGTH);
> +    assert(hs->n <= QUEUE_LENGTH);
>      e = &hs->ptr.queue[(hs->head + hs->n) & QUEUE_MASK];
> 
>      switch (evt->kind) {
> 
> Best regards,
> -Gonglei
> 
--
Dr. David Alan Gilbert / dgilbert@redhat.com / Manchester, UK

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

[Gonglei]

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

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

[Gonglei]

On 2014/11/24 17:08, Gonglei wrote:

> 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.

Sorry, a typo. :(    s/will decrease/will not decrease/

> 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