[Qemu-devel] usb_packet_complete: Assertion ... failed

[Qemu-devel] usb_packet_complete: Assertion ... failed

[Jan Kiszka]

Hi Gerd,

I'm getting

qemu/hw/usb/core.c:410: usb_packet_complete: Assertion `((&ep->queue)->tqh_first) == p' failed.

with a passed-through USB headset (UHCI controller). This was with
current QEMU git head. Known issues? Anything I can do to debug it?

Jan

-- 
Siemens AG, Corporate Technology, CT T DE IT 1
Corporate Competence Center Embedded Linux

Re: [Qemu-devel] usb_packet_complete: Assertion ... failed

[Erik Rull]

Jan Kiszka wrote:
> Hi Gerd,
>
> I'm getting
>
> qemu/hw/usb/core.c:410: usb_packet_complete: Assertion `((&ep->queue)->tqh_first) == p' failed.
>
> with a passed-through USB headset (UHCI controller). This was with
> current QEMU git head. Known issues? Anything I can do to debug it?
>
> Jan
>

Hi all,

I get this with another USB 1.1 hardware (running via UHCI) as well. Some 
weeks ago it was fine.
@Jan: If you go back some weeks, this should work (begin of April was 
definitvely ok). How long does it take to get the headset fully detected in 
your guest so that you can use the hardware? My USB 1.1 HW takes ~ 60 
seconds to work, after that everything is fine - during that I see several 
USB resets on the host (dmesg).

Best regards,

Erik

Re: [Qemu-devel] usb_packet_complete: Assertion ... failed

[Jan Kiszka]

[-- Attachment #1: Type: text/plain, Size: 1133 bytes --]

On 2012-06-23 11:29, Erik Rull wrote:
> Jan Kiszka wrote:
>> Hi Gerd,
>>
>> I'm getting
>>
>> qemu/hw/usb/core.c:410: usb_packet_complete: Assertion
>> `((&ep->queue)->tqh_first) == p' failed.
>>
>> with a passed-through USB headset (UHCI controller). This was with
>> current QEMU git head. Known issues? Anything I can do to debug it?
>>
>> Jan
>>
> 
> Hi all,
> 
> I get this with another USB 1.1 hardware (running via UHCI) as well.
> Some weeks ago it was fine.
> @Jan: If you go back some weeks, this should work (begin of April was
> definitvely ok).

Interesting, will try to bisect if it's a regression. Don't have the
hardware here, will try next week.

> How long does it take to get the headset fully detected
> in your guest so that you can use the hardware? My USB 1.1 HW takes ~ 60
> seconds to work, after that everything is fine - during that I see
> several USB resets on the host (dmesg).

I don't see other problems so far. The device is quickly recognized and
appears to work fine otherwise. But as the assert hit frequently, I was
not able to test in details.

Thanks,
Jan


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 262 bytes --]

Re: [Qemu-devel] usb_packet_complete: Assertion ... failed

[Gerd Hoffmann]

  Hi,

> What I also so in the trace is that the USB core apparently stumbled as
> a request that took very long too complete finally returned, and then
> the assertion triggered over this request.

Can I get such a trace please?  usb_host_req_* and usb_host_urb_*
enabled should show all interesting information.  Oh, and replacing the
assert which triggers with a tracepoint (or just a fprintf in case you
use the stderr tracer) would be nice, so I can see how qemu continues
after the assert().

A request taking a while shouldn't be a issue.  Requests for a specific
endpoint shouldn't be reordered though, and this seems to happen here.

thanks,
  Gerd

Re: [Qemu-devel] usb_packet_complete: Assertion ... failed

[Jan Kiszka]

On 2012-07-02 13:05, Gerd Hoffmann wrote:
>   Hi,
> 
>> What I also so in the trace is that the USB core apparently stumbled as
>> a request that took very long too complete finally returned, and then
>> the assertion triggered over this request.
> 
> Can I get such a trace please?  usb_host_req_* and usb_host_urb_*
> enabled should show all interesting information.  Oh, and replacing the
> assert which triggers with a tracepoint (or just a fprintf in case you
> use the stderr tracer) would be nice, so I can see how qemu continues
> after the assert().
> 
> A request taking a while shouldn't be a issue.  Requests for a specific
> endpoint shouldn't be reordered though, and this seems to happen here.

You can find a log at

http://www.kiszka.org/downloads/usb-log.xz

I instrumented the assert as follows:

diff --git a/hw/usb/core.c b/hw/usb/core.c
index 0e02da7..eacda74 100644
--- a/hw/usb/core.c
+++ b/hw/usb/core.c
@@ -407,7 +407,9 @@ void usb_packet_complete(USBDevice *dev, USBPacket *p)
     int ret;
 
     usb_packet_check_state(p, USB_PACKET_ASYNC);
-    assert(QTAILQ_FIRST(&ep->queue) == p);
+    if (QTAILQ_FIRST(&ep->queue) != p) {
+        trace_usb_assert(usb_bus_from_device(dev)->busnr, dev->port->path, p->ep->nr, p);
+    }
     usb_packet_set_state(p, USB_PACKET_COMPLETE);
     QTAILQ_REMOVE(&ep->queue, p, queue);
     dev->port->ops->complete(dev->port, p);
diff --git a/trace-events b/trace-events
index c935ba2..a953898 100644
--- a/trace-events
+++ b/trace-events
@@ -230,6 +230,7 @@ sun4m_iommu_bad_addr(uint64_t addr) "bad addr %"PRIx64
 # hw/usb/core.c
 usb_packet_state_change(int bus, const char *port, int ep, void *p, const char *o, const char *n) "bus %d, port %s, ep %d, packet %p, state %s -> %s"
 usb_packet_state_fault(int bus, const char *port, int ep, void *p, const char *o, const char *n) "bus %d, port %s, ep %d, packet %p, state %s, expected %s"
+usb_assert(int bus, const char *port, int ep, void *p) "bus %d, port %s, ep %d, packet %p"
 
 # hw/usb/bus.c
 usb_port_claim(int bus, const char *port) "bus %d, port %s"

There is a single occurrence of this event in the log.

Thanks,
Jan

-- 
Siemens AG, Corporate Technology, CT RTC ITP SDP-DE
Corporate Competence Center Embedded Linux

Re: [Qemu-devel] usb_packet_complete: Assertion ... failed

[Gerd Hoffmann]

> diff --git a/hw/usb/core.c b/hw/usb/core.c
> index 0e02da7..eacda74 100644
> --- a/hw/usb/core.c
> +++ b/hw/usb/core.c
> @@ -407,7 +407,9 @@ void usb_packet_complete(USBDevice *dev, USBPacket *p)
>      int ret;
>  
>      usb_packet_check_state(p, USB_PACKET_ASYNC);
> -    assert(QTAILQ_FIRST(&ep->queue) == p);
> +    if (QTAILQ_FIRST(&ep->queue) != p) {
> +        trace_usb_assert(usb_bus_from_device(dev)->busnr, dev->port->path, p->ep->nr, p);
> +    }

Can you also log QTAILQ_FIRST(&ep->queue) there?

usb_host_* & usb_packet_state_* tracepoints are good to have, usb_uhci_*
is not needed.

>From the trace it looks like the packets are completing in the same
order they have been submitted as they should, I'm puzzled why the
assert triggers ...

Can I also get a "lsusb -v" for the usb device in question?

cheers,
  Gerd

Re: [Qemu-devel] usb_packet_complete: Assertion ... failed

[Gerd Hoffmann]

On 07/02/12 17:47, Gerd Hoffmann wrote:
>> diff --git a/hw/usb/core.c b/hw/usb/core.c
>> index 0e02da7..eacda74 100644
>> --- a/hw/usb/core.c
>> +++ b/hw/usb/core.c
>> @@ -407,7 +407,9 @@ void usb_packet_complete(USBDevice *dev, USBPacket *p)
>>      int ret;
>>  
>>      usb_packet_check_state(p, USB_PACKET_ASYNC);
>> -    assert(QTAILQ_FIRST(&ep->queue) == p);
>> +    if (QTAILQ_FIRST(&ep->queue) != p) {
>> +        trace_usb_assert(usb_bus_from_device(dev)->busnr, dev->port->path, p->ep->nr, p);
>> +    }
> 
> Can you also log QTAILQ_FIRST(&ep->queue) there?

Oh, I think I've found it.  It's most likely NULL.

> Can I also get a "lsusb -v" for the usb device in question?

Would still be useful.

thanks,
  Gerd