Bug 208327

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

Created attachment 290293 [details]
dmesg_usb3.0

Created attachment 290295 [details]
trace_usb3.0.zip

I also notice this on: 5.7.8
5.7.8-vanilla #1 SMP PREEMPT Tue Jul 14 17:04:14 EEST 2020 x86_64 x86_64 x86_64 GNU/Linux

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.

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

To check if this is related to the soft retry of the transaction errors
we could prevent soft retry with the following change:

diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
index 2c255d0620b0..964cacc1092e 100644
--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c
@@ -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.

Created attachment 290449 [details]
usb-connect-trbs.txt

Created attachment 290451 [details]
usb-disconnect-trbs.txt

I tried with this change:

diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c
index 2c255d0620b0..964cacc1092e 100644
--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c
@@ -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