Re: xhci_hcd / ASMedia ASM4242: Bulk-OUT -EPROTO with Logitec 0789:0308 during DVD+RW recording

From: Michal Pecio

Date: Sun Sep 06 2026 - 06:21:33 EST


On Sun, 6 Sep 2026 11:13:45 +0900, wakasio wrote:
> Hi Michal,
>
> I applied the second patch on top of the first one and reproduced the
> failure again with the same three debug functions enabled.
>
> Cluster 1 (ep 2, start of write, unrelated): same as before, 4
> Stall/Hard-reset pairs within about 177 ms.
>
> Cluster 2 (ep 3, the real failure):
>
> 11:07:56.930732 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:56.931126 Soft-reset ep 3
> 11:07:56.939018 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:56.939183 Soft-reset ep 3
> 11:07:56.947399 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:56.947686 Soft-reset ep 3
> 11:07:56.955772 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:56.955939 Soft-reset ep 3
> 11:07:56.964233 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:56.964395 Soft-reset ep 3
> 11:07:56.972881 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:56.973060 Soft-reset ep 3
> 11:07:56.981806 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:56.981975 Soft-reset ep 3
> 11:07:56.991162 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:56.991324 Soft-reset ep 3
> 11:07:57.002050 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:57.002211 Soft-reset ep 3
> 11:07:57.015466 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:57.015576 Soft-reset ep 3
> 11:07:57.034026 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:57.034195 Soft-reset ep 3
> 11:07:57.041915 Transfer error, ep 3, at ffffccbbc21f1540, resid 23552
> 11:07:57.042019 Hard-reset ep 3
> 11:07:57.162742 usb 6-1: reset SuperSpeed USB device number 2
> 11:07:57.176799 Stopped on No-op or Link TRB, slot 1 ep 2
> 11:07:57.679888 clear err_count at ffffccbbc21e9000
>
> Same pattern as before. 11 soft-resets, all at the same TRB address
> and the same resid, then a hard-reset on the 12th. A different TRB
> address cleared err_count about 0.5 seconds after the port reset.
>
> The second patch did not change the pattern. This run failed at about
> 187 MB into the write, the furthest one so far, but I do not know if
> that means anything given how much the failure point already varies
> between runs (0.35 MB to 103 MB before this).

Seems quite random indeed, but apparently things consistently go wrong
after sending the 9th packet out of 32 (IIRC) in a random(?) URB.

I have no idea, let's try one more patch (applies on top of the prior
ones) to dump those transfer TRBs and see if they are correct.

--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c
@@ -2622,6 +2622,22 @@ static struct xhci_td *find_td_by_dma(struct xhci_ring *ep_ring, dma_addr_t dma)
return NULL;
}

+static void dump_ring(struct xhci_hcd *xhci, struct xhci_ring *ring)
+{
+ struct xhci_segment *seg;
+
+ xhci_for_each_ring_seg(ring->deq_seg->next, seg) {
+ union xhci_trb *trb;
+
+ for (trb = seg->trbs; trb < seg->trbs + TRBS_PER_SEGMENT; trb++) {
+ char msg[256];
+ xhci_decode_trb(msg, 256, trb->generic.field[0], trb->generic.field[1],
+ trb->generic.field[2], trb->generic.field[3]);
+ xhci_info(xhci, "%llx0: %s\n", (u64)seg->dma + (trb - seg->trbs), msg);
+ }
+ }
+}
+
/*
* If this function returns an error condition, it means it got a Transfer
* event with a corrupted Slot ID, Endpoint ID, or TRB DMA address.
@@ -2713,6 +2729,12 @@ static int handle_tx_event(struct xhci_hcd *xhci,
case COMP_USB_TRANSACTION_ERROR:
xhci_dbg(xhci, "Transfer error for slot %u ep %u on endpoint at %px resid %u\n",
slot_id, ep_index, ep_trb, EVENT_TRB_LEN(le32_to_cpu(event->transfer_len)));
+ if (ep->err_count > 10) {
+ xhci_info(xhci, "event ring:\n");
+ dump_ring(xhci, xhci->interrupters[0]->event_ring);
+ xhci_info(xhci, "endpoint ring:\n");
+ dump_ring(xhci, ep_ring);
+ }
status = -EPROTO;
break;
case COMP_BABBLE_DETECTED_ERROR: