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 0000:04:00.0: mid bulk/intr SP, wait for last TRB event
[ 65.017374] xhci_hcd 0000:04:00.0: mid bulk/intr SP, wait for last TRB event
[ 70.455451] xhci_hcd 0000:04:00.0: mid bulk/intr SP, wait for last TRB event
[ 75.456248] xhci_hcd 0000: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 <mathias.ny...@linux.intel.com>
> 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 <mathias.ny...@linux.intel.com>
> ---
> 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
>
