Re: xhci regression for large transfers (commit e210c422b)
On Fri, Jan 08, 2016 at 02:52:28AM +1030, Ron wrote: > On Thu, Jan 07, 2016 at 05:38:09PM +0200, Mathias Nyman wrote: > > Hi > > > > On 02.01.2016 08:32, Ron wrote: > > > > > >Hi, > > > > > >It appears the commit e210c422b6fdd2dc123bedc588f399aefd8bf9de > > >"xhci: don't finish a TD if we get a short transfer event mid TD" > > >is causing transfers larger than 16kB to be unreliable. > > > > > >If I limit transfers to be no larger than 16kB, then it also works as > > >expected in an XHCI port with an unmodified build of Linus' current > > >head (v4.4-rc7-76-g9c982e8), but transfers larger than that do not. > > >I see an alternating cycle of a successful transfer, followed by two > > >that will time out waiting in libusb (with a 5 second timeout set), > > >before getting another successful transfer and the cycle repeating. > > > > > >I can run more tests and dig into this deeper if the reason for it > > >isn't immediately obvious in hindsight. > > > > > > > Thanks for the info, > > I can't spot anything obvious, but my brain might still be in vacation mode. > > > > Could you reproduce it with the attached patch, it only adds extra > > debugging? > > > > We should either see no output, or the following sequence: > > > > 1. "mid bulk/intr SP, wait for last TRB event" > > 2. "last trb has length set" > > 3. "and last trb is SHORT_TX, OK" > > > I guess one out of 3 ain't good ... all I see logged is: > > [ 60.015708] xhci_hcd :04:00.0: mid bulk/intr SP, wait for last TRB > event > [ 65.017374] xhci_hcd :04:00.0: mid bulk/intr SP, wait for last TRB > event > [ 70.455451] xhci_hcd :04:00.0: mid bulk/intr SP, wait for last TRB > event > [ 75.456248] xhci_hcd :04:00.0: mid bulk/intr SP, wait for last TRB > event > > I'm passing 5 seconds to libusb as the requested timeout. And if I limit the maximum transfer size to 16kB (the above was with 64kB transfers), then I see nothing logged at all. So if that code does indeed look sane, perhaps the issue is really in the code that's splitting large transfers doing something funny? Ron -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: xhci regression for large transfers (commit e210c422b)
On Thu, Jan 07, 2016 at 05:38:09PM +0200, Mathias Nyman wrote:
> Hi
>
> On 02.01.2016 08:32, Ron wrote:
> >
> >Hi,
> >
> >It appears the commit e210c422b6fdd2dc123bedc588f399aefd8bf9de
> >"xhci: don't finish a TD if we get a short transfer event mid TD"
> >is causing transfers larger than 16kB to be unreliable.
> >
> >If I limit transfers to be no larger than 16kB, then it also works as
> >expected in an XHCI port with an unmodified build of Linus' current
> >head (v4.4-rc7-76-g9c982e8), but transfers larger than that do not.
> >I see an alternating cycle of a successful transfer, followed by two
> >that will time out waiting in libusb (with a 5 second timeout set),
> >before getting another successful transfer and the cycle repeating.
> >
> >I can run more tests and dig into this deeper if the reason for it
> >isn't immediately obvious in hindsight.
> >
>
> Thanks for the info,
> I can't spot anything obvious, but my brain might still be in vacation mode.
>
> Could you reproduce it with the attached patch, it only adds extra debugging?
>
> We should either see no output, or the following sequence:
>
> 1. "mid bulk/intr SP, wait for last TRB event"
> 2. "last trb has length set"
> 3. "and last trb is SHORT_TX, OK"
I guess one out of 3 ain't good ... all I see logged is:
[ 60.015708] xhci_hcd :04:00.0: mid bulk/intr SP, wait for last TRB event
[ 65.017374] xhci_hcd :04:00.0: mid bulk/intr SP, wait for last TRB event
[ 70.455451] xhci_hcd :04:00.0: mid bulk/intr SP, wait for last TRB event
[ 75.456248] xhci_hcd :04:00.0: mid bulk/intr SP, wait for last TRB event
I'm passing 5 seconds to libusb as the requested timeout.
Ron
> From 1b9abc3d47f2c3fcb75209560b7226d99db7def9 Mon Sep 17 00:00:00 2001
> From: Mathias Nyman
> Date: Thu, 7 Jan 2016 17:22:09 +0200
> Subject: [PATCH] xhci: FOR TESTING ONLY add verbose debugging for short bulk
> transfers
>
> patch
> e210c422b6fdd2dc123bedc588f399aefd8bf9de
> "xhci: don't finish a TD if we get a short transfer event mid TD"
> caused regression for 64k bulk tranfers.
>
> Tt wont return the URB in case we get a short transfer trb mid TD.
> It waits for the last TRB which should be short as well.
>
> Add debugging for the short bulk tranfer case
>
> Signed-off-by: Mathias Nyman
> ---
> drivers/usb/host/xhci-ring.c | 16 +++-
> 1 file changed, 11 insertions(+), 5 deletions(-)
>
> diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
> index eeaa6c6..ed6ac7e 100644
> --- a/drivers/usb/host/xhci-ring.c
> +++ b/drivers/usb/host/xhci-ring.c
> @@ -2192,10 +2192,16 @@ static int process_bulk_intr_td(struct xhci_hcd
> *xhci, struct xhci_td *td,
> }
> /* Fast path - was this the last TRB in the TD for this URB? */
> } else if (event_trb == td->last_trb) {
> - if (td->urb_length_set && trb_comp_code == COMP_SHORT_TX)
> - return finish_td(xhci, td, event_trb, event, ep,
> - status, false);
> -
> + if (td->urb_length_set) {
> + xhci_warn(xhci, "last trb has length set\n");
> + if (trb_comp_code == COMP_SHORT_TX) {
> + xhci_warn(xhci, "and last trb is SHORT_TX,
> OK\n");
> + return finish_td(xhci, td, event_trb, event, ep,
> + status, false);
> + } else {
> + xhci_warn(xhci, "FAIL, expected SHORT_TX last
> trb\n");
> + }
> + }
> if (EVENT_TRB_LEN(le32_to_cpu(event->transfer_len)) != 0) {
> td->urb->actual_length =
> td->urb->transfer_buffer_length -
> @@ -2249,7 +2255,7 @@ static int process_bulk_intr_td(struct xhci_hcd *xhci,
> struct xhci_td *td,
> EVENT_TRB_LEN(le32_to_cpu(event->transfer_len));
>
> if (trb_comp_code == COMP_SHORT_TX) {
> - xhci_dbg(xhci, "mid bulk/intr SP, wait for last TRB
> event\n");
> + xhci_warn(xhci, "mid bulk/intr SP, wait for last TRB
> event\n");
> td->urb_length_set = true;
> return 0;
> }
> --
> 1.9.1
>
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
xhci regression for large transfers (commit e210c422b)
Hi, It appears the commit e210c422b6fdd2dc123bedc588f399aefd8bf9de "xhci: don't finish a TD if we get a short transfer event mid TD" is causing transfers larger than 16kB to be unreliable. I ran into this testing the code from here: http://www.bitbabbler.org which with a recent enough kernel and libusb, will try to transfer up to 64kB from the device to the host in a single request. The USB side of things on that device is relatively uncomplicated, it is using an FTDI FT232H, in MPSSE mode, providing USB 2.0, and it all works fine if plugged into an EHCI port, or if using a kernel without e210c422b applied. If I limit transfers to be no larger than 16kB, then it also works as expected in an XHCI port with an unmodified build of Linus' current head (v4.4-rc7-76-g9c982e8), but transfers larger than that do not. I see an alternating cycle of a successful transfer, followed by two that will time out waiting in libusb (with a 5 second timeout set), before getting another successful transfer and the cycle repeating. I'd originally thought this was an error in backporting that patch to the distro kernel (reported here: https://bugs.debian.org/808953) but after some more testing it appears any kernel including that patch has this problem, and reverting it reliably fixes it again. I'm using libusb 1.0.19 from Debian Jessie, and have reproduced this on two different machines. Currently I'd expect any device doing a transfer larger than 16kB should be able to reproduce it too. Ben has reverted this for the next uploads of the distro kernel now, until we figure out what is really wrong there and get a fix into the mainline. I can run more tests and dig into this deeper if the reason for it isn't immediately obvious in hindsight. Cheers, Ron -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
