On Tue, 30 Mar 2010, Nate Case wrote: > > These messages indicate that the controller failed, but they don't say > > what the reason for the failure was. > > True -- one other clue I just verified is that "lspci -vv" on the EHCI > controller *after* the HC dies reveals "<TAbort+". Bogus DMA address > perhaps? > > > Those events are merely cancellations of input URBs (although the > > start_frame and actual_length values don't make sense). According to > > the interval values, similar input URBs should show up in a full usbmon > > trace every 64 milliseconds. > > Thanks for the explanation. I do see these every ~64 milliseconds in my > trace. I think those bogus start_frame values are the key. They definitely indicate a bug in ehci-hcd, and that bug could cause the sort of problem you see. > > Use the most recent kernel version you can. Post the complete usbmon > > traces, not just the last few entries. To reduce the size of the > > output, you could play only 200 ms of silence instead of 2 seconds. > > OK, I did all of this today on the latest kernel and got similar > results. One difference I noticed is that the failure happens the first > time I play audio with 2.6.34-rc2, rather than failing the second time. > > Full usbmon trace here (for 250ms of silence): > http://xes-inc.com/sources/debug/usbmon-ehci-dies-2.6.34-rc2.txt The trace confirms this scheduling bug. > other debug output + usbmon output > http://pastebin.com/DwKWihUB Here's a patch which ought to fix that bug. However it may turn out that the end result is a little drastic: The aplay program might fail! The difficulty is that the audio driver schedules four Iso-IN URBs at 64-ms intervals, and the total scheduling window is only 236 ms long (actually 256 ms, but minus 20 for slop and overhead). The fourth URB should have been rejected with a -EFBIG error, and this patch will cause that to happen -- you can confirm with usbmon. How the driver and aplay will deal with the submission error, I don't know. Incidentally, do you know exactly which USB audio driver is being used? Alan Stern Index: usb-2.6/drivers/usb/host/ehci-sched.c =================================================================== --- usb-2.6.orig/drivers/usb/host/ehci-sched.c +++ usb-2.6/drivers/usb/host/ehci-sched.c @@ -1396,29 +1396,32 @@ iso_stream_schedule ( struct ehci_iso_stream *stream ) { - u32 now, next, start, period; + u32 now, next, start, period, span; int status; unsigned mod = ehci->periodic_size << 3; struct ehci_iso_sched *sched = urb->hcpriv; struct pci_dev *pdev; - if (sched->span > (mod - SCHEDULE_SLOP)) { + period = urb->interval; + span = sched->span; + if (!stream->highspeed) { + period <<= 3; + span <<= 3; + } + + if (span > mod - SCHEDULE_SLOP) { ehci_dbg (ehci, "iso request %p too long\n", urb); status = -EFBIG; goto fail; } - if ((stream->depth + sched->span) > mod) { + if (stream->depth + span > mod) { ehci_dbg (ehci, "request %p would overflow (%d+%d>%d)\n", - urb, stream->depth, sched->span, mod); + urb, stream->depth, span, mod); status = -EFBIG; goto fail; } - period = urb->interval; - if (!stream->highspeed) - period <<= 3; - now = ehci_readl(ehci, &ehci->regs->frame_index) % mod; /* Typical case: reuse current schedule, stream is still active. @@ -1448,7 +1451,7 @@ iso_stream_schedule ( period); /* Tried to schedule too far into the future? */ - if (unlikely(((start - now) & (mod - 1)) + sched->span + if (unlikely(((start - now) & (mod - 1)) + span >= mod - 2 * SCHEDULE_SLOP)) { status = -EFBIG; goto fail; -- 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
