lkml.org 
[lkml]   [2009]   [Dec]   [3]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: debugging oops after disconnecting Nexio USB touchscreen
On Thu, 3 Dec 2009, Ondrej Zary wrote:

> Luckily, it appeared with usbmon active, here's the output:

...

> > Also, try adding some more debugging output (and let's hope it doesn't
> > also make the problem disappear). In start_unlink_async(), just before
> > your "after:" label, add
> >
> > ehci_info(ehci, "unlink qh %p %p\n", qh, qh->qh_next);
> >
> > In qh_link_async(), just after the wmb(), add
> >
> > ehci_info(ehci, "link qh %p %p\n", qh, qh->qh_next);
> >
> > In end_unlink_async(), just after the iaa_watchdog_done(ehci), add
> >
> > ehci_info(ehci, "end unlink qh %p %p\n", qh, qh->next);
> >
> > And in qh_make(), just before the end, add
> >
> > ehci_info(ehci, "create qh %p, dev %s, ep %x\n",
> > qh, urb->dev->devpath, urb->ep->desc.bEndpointAddress);
>
> Thanks for suggestion, here's the output:

I wish you hadn't removed all the "create qh" log messages.

Anyway, it looks like the problem is caused by your driver overwriting
the data structure owned by ehci-hcd. Here's the important part of the
log:

> [ 151.688299] ehci_hcd 0000:00:1d.7: link qh f65cf700 (null)
> [ 151.688428] ehci_hcd 0000:00:1d.7: unlink qh f65cf700 (null)

Here f65cf700 is the only qh on the async list (it is linked in at the
head and its qh_next pointer is NULL).

> [ 151.688497] ehci_hcd 0000:00:1d.7: link qh f65cf080 (null)

Now f65cf080 is added to the start of the list.

> [ 151.688534] ehci_hcd 0000:00:1d.7: end unlink qh f65cf700 (null)
> [ 151.688546] ehci_hcd 0000:00:1d.7: link qh f65cf700 f65cf080

And f65cf700 is added to the start, preceding f65cf080.

> [ 151.688675] ehci_hcd 0000:00:1d.7: unlink qh f65cf700 f65cf080
> [ 151.688784] ehci_hcd 0000:00:1d.7: end unlink qh f65cf700 f65cf080

f65cf700 is removed from the start position, leaving f65cf080 at the
start.

> [ 151.688796] ehci_hcd 0000:00:1d.7: link qh f65cf700 f65cf080

It is added again at the start, preceding f65cf080.

> [ 151.688923] ehci_hcd 0000:00:1d.7: unlink qh f65cf700 f65cf080
> [ 151.689033] ehci_hcd 0000:00:1d.7: end unlink qh f65cf700 f65cf080

It is removed again from the start position.

> [ 151.689045] ehci_hcd 0000:00:1d.7: link qh f65cf700 f65cf080

It is added again at the start.

> [ 151.689106] usb 1-1.1: USB disconnect, address 9
> [ 152.712104] prev is NULL, qh=f65cf080, ehci->async=f65cf000

Evidently prev is f65cf700->qh_next. We know that the value was set to
f65cf080 just above, and you added log messages to every place where
ehci-hcd changes qh_next. Hence something your driver did must have
been responsible. Does it access urb->hcpriv anywhere?

Incidentally, look at the usbmon trace:

> f60eecc0 1501056647 S Bi:1:009:2 -115 128 <
> f60eecc0 1501056905 C Bi:1:009:2 -32 0
> f60eecc0 1501056916 S Bi:1:009:2 -115 128 <
> f60eecc0 1501057172 C Bi:1:009:2 -32 0
> f60eecc0 1501057183 S Bi:1:009:2 -115 128 <
> f60eecc0 1501057394 C Bi:1:009:2 -32 0

Why does your driver keep submitting the same request over and over
again when each time it fails?

Alan Stern



\
 
 \ /
  Last update: 2009-12-03 20:43    [W:0.072 / U:0.164 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site