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 -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
