Skip to contentSkip to conversation

New: xhci_hcd issue transfer event - usb3.0

Bug 208327 [email protected] 1 participant 6 messages Jun 26, 2020 – Jul 22, 2020

Subsystems (2)
USB USB xHCI driver
lore
Share & tools
lore

[email protected]

author
#0 lore raw

https://bugzilla.kernel.org/show_bug.cgi?id=208327

            Bug ID: 208327
           Summary: xhci_hcd issue transfer event - usb3.0
           Product: Drivers
           Version: 2.5
    Kernel Version: 4.14.170
          Hardware: x86-64
                OS: Linux
              Tree: Mainline
            Status: NEW
          Severity: high
          Priority: P1
         Component: USB
          Assignee: [email protected]
          Reporter: [email protected]
        Regression: No

Hi Kernel Team,

With compile vanilla kernel 4.14.170, observe this issue with connect/disconnect usb device (mouse and keyboard).

usb xhci_hcd issue, USB3.0

[  146.924776] usb 1-2: USB disconnect, device number 2
[  146.926153] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 1 comp_code 1
[  146.926163] xhci_hcd 0000:00:14.0: Looking for event-dma 00000000ffee2350
trb-start 00000000ffee2360 trb-end 00000000ffee2360 seg-start 00000000ffee2000
seg-end 00000000ffee2ff0
[  146.927151] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 1 comp_code 1
[  146.927160] xhci_hcd 0000:00:14.0: Looking for event-dma 00000000ffee2360
trb-start 00000000ffee2370 trb-end 00000000ffee2370 seg-start 00000000ffee2000
seg-end 00000000ffee2ff0
[  146.928153] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 1 comp_code 1
[  146.928163] xhci_hcd 0000:00:14.0: Looking for event-dma 00000000ffee2370
trb-start 00000000ffee2380 trb-end 00000000ffee2380 seg-start 00000000ffee2000
seg-end 00000000ffee2ff0
[  146.929150] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 1 comp_code 1
[  146.929159] xhci_hcd 0000:00:14.0: Looking for event-dma 00000000ffee2380
trb-start 00000000ffee2390 trb-end 00000000ffee2390 seg-start 00000000ffee2000
seg-end 00000000ffee2ff0
[  146.930150] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 1 comp_code 1
[  146.930158] xhci_hcd 0000:00:14.0: Looking for event-dma 00000000ffee2390

trb-start 00000000ffee23a0 trb-end 00000000ffee23a0 seg-start 00000000ffee2000 seg-end 00000000ffee2ff0

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
author
#1 lore raw

[Bug 208327] xhci_hcd issue transfer event - usb3.0

https://bugzilla.kernel.org/show_bug.cgi?id=208327

Mathias Nyman ([email protected]) changed:

What |Removed |Added
----------------------------------------------------------------------------

                 CC|                            |[email protected]
                   |                            |om

--- Comment #1 from Mathias Nyman ([email protected]) --- Can this issue be reproduced with 5.7 kernel or later?

If yes, then logs and traces with a more recent kernel would help:

mount -t debugfs none /sys/kernel/debug
echo 'module xhci_hcd =p' >/sys/kernel/debug/dynamic_debug/control echo 'module usbcore =p' >/sys/kernel/debug/dynamic_debug/control echo 81920 > /sys/kernel/debug/tracing/buffer_size_kb echo 1 > /sys/kernel/debug/tracing/events/xhci-hcd/enable < trigger the issue >
Send output of dmesg
Send content of /sys/kernel/debug/tracing/trace

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
author
#2 lore raw

[Bug 208327] xhci_hcd issue transfer event - usb3.0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=208327

--- Comment #5 from Mathias Nyman ([email protected]) --- Thanks

Logs show we get double (duplicate) events for some ISOC transfers. Driver expects only one event per TRB and warns when we get a second event for the same TRB

A wild guess is that this is somehow related to the soft retry of transaction errors seen on another endpoint on the same device.
Driver tries to recover from the transaction error with a soft retry three times. the duplicate events seen on the other endpoint occur close to the soft retries, almost like this ISOC enpoint is being retried as well.

driver will ignore the duplicate events after warning about it, so there shouldn't be any functional impact, but this isn't how it's supposed to behave.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
author
#3 lore raw

[Bug 208327] xhci_hcd issue transfer event - usb3.0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=208327

--- Comment #6 from Mathias Nyman ([email protected]) --- Could you please dump the event ring ringht after seeing the "Transfer event TRB DMA ptr not part of current TD.." message. Just to verify hardware actually writes duplicate events on the ring buffer.

This can be done by:
mount -t debugfs none /sys/kernel/debug
cat /sys/kernel/debug/usb/xhci/0000:00:14.0/event-ring/trbs

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
author
#4 lore raw

[Bug 208327] xhci_hcd issue transfer event - usb3.0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=208327

--- Comment #7 from Mathias Nyman ([email protected]) --- To check if this is related to the soft retry of the transaction errors we could prevent soft retry with the following change:

drivers/usb/host/xhci-ring.c +0 -0
index 2c255d0620b0..964cacc1092e 100644
@@ -2302,6 +2302,7 @@ static int process_bulk_intr_td(struct xhci_hcd *xhci,

struct xhci_td *td,

                remaining       = 0;
                break;
        case COMP_USB_TRANSACTION_ERROR:
+               break;
                if ((ep_ring->err_count++ > MAX_SOFT_RETRY) ||
                    le32_to_cpu(slot_ctx->tt_info) & TT_SLOT)
                        break;

Does that help?
After this chagen you should still see the Transactio errors, but not the "Transfer event TRB DMA ptr not part of current TD.." message.

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.
author
#5 lore raw

[Bug 208327] xhci_hcd issue transfer event - usb3.0

In reply to [email protected]

https://bugzilla.kernel.org/show_bug.cgi?id=208327

--- Comment #10 from sander44 ([email protected]) --- I tried with this change:

drivers/usb/host/xhci-ring.c +0 -0
index 2c255d0620b0..964cacc1092e 100644
@@ -2302,6 +2302,7 @@ static int process_bulk_intr_td(struct xhci_hcd *xhci,

struct xhci_td *td,

                remaining       = 0;
                break;
        case COMP_USB_TRANSACTION_ERROR:
+               break;
                if ((ep_ring->err_count++ > MAX_SOFT_RETRY) ||
                    le32_to_cpu(slot_ctx->tt_info) & TT_SLOT)
                        break;

And it doesn't help.
Error messages still appear.

[  245.472838] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 1 comp_code 1
[  245.473676] xhci_hcd 0000:00:14.0: Looking for event-dma 000000035ae0cea0
trb-start 000000035ae0ceb0 trb-end 000000035ae0ceb0 seg-start 000000035ae0c000
seg-end 000000035ae0cff0
[  245.473828] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 1 comp_code 1
[  245.474575] xhci_hcd 0000:00:14.0: Looking for event-dma 000000035ae0ceb0
trb-start 000000035ae0cec0 trb-end 000000035ae0cec0 seg-start 000000035ae0c000
seg-end 000000035ae0cff0
[  245.474829] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 1 comp_code 1
[  245.475710] xhci_hcd 0000:00:14.0: Looking for event-dma 000000035ae0cec0
trb-start 000000035ae0ced0 trb-end 000000035ae0ced0 seg-start 000000035ae0c000
seg-end 000000035ae0cff0
[  245.475828] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part
of current TD ep_index 1 comp_code 1
[  245.476706] xhci_hcd 0000:00:14.0: Looking for event-dma 000000035ae0ced0

trb-start 000000035ae0cee0 trb-end 000000035ae0cee0 seg-start 000000035ae0c000 seg-end 000000035ae0cff0

Signature · 2 lines
You are receiving this mail because:
You are watching the assignee of the bug.