diff mbox

usb_packet_complete: Assertion ... failed

Message ID 4FF1AF8C.5030400@siemens.com
State New
Headers show

Commit Message

Jan Kiszka July 2, 2012, 2:26 p.m. UTC 
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:


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

Thanks,
Jan

Comments

Gerd Hoffmann July 2, 2012, 3:47 p.m. UTC | #1 
> 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
Gerd Hoffmann July 2, 2012, 3:59 p.m. UTC | #2 
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
diff mbox

Patch

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"