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

On Sat,  5 Sep 2026 12:10:11 +0900, wakasio wrote:

Cluster 1, right at the very start of the cdrecord invocation
(before any error is visible to userspace), ~45 seconds before the
actual failure:

  Stalled endpoint for slot 1 ep 2
  Hard-reset ep 2, slot 1

Seems unrelated.

Cluster 2, at the exact moment cdrecord reported the write error
(matches the timestamp of "write track data: error after 103088128
bytes" in cdrecord's own log):

  Transfer error for slot 1 ep 3 on endpoint
  Soft-reset ep 3, slot 1
  Transfer error for slot 1 ep 3 on endpoint
  Soft-reset ep 3, slot 1
  Transfer error for slot 1 ep 3 on endpoint
  Soft-reset ep 3, slot 1
  Transfer error for slot 1 ep 3 on endpoint
  Soft-reset ep 3, slot 1
  Transfer error for slot 1 ep 3 on endpoint
  Hard-reset ep 3, slot 1
  usb 6-1: reset SuperSpeed USB device number 2 using xhci_hcd
  xhci_hcd 0000:77:00.0: Stopped on No-op or Link TRB for slot 1 ep 2

So to answer your question directly: it is not constant background
noise throughout the write. It's a single, tight burst of 5 "Transfer
error" events on the same endpoint within about one second.

Short fraction of a second, I suppose. Timestamps would help.

4 is the number of retries without ep->err_count reset, so it seems
they all happened in the same URB, possibly in the same place.

Let's add more debug logging and see if it's some transient stupid
problem that we can wait out or plow through with more retries.

One more dynamic debug will be needed with this patch:

  echo 'func handle_tx_event +p' >/proc/dynamic_debug/control
  echo 'func process_bulk_intr_td +p' >/proc/dynamic_debug/control
  echo 'func xhci_reset_halted_ep +p' >/proc/dynamic_debug/control

--- a/drivers/usb/host/xhci-ring.c
+++ b/drivers/usb/host/xhci-ring.c

@@ -2511,6 +2511,8 @@ static void process_bulk_intr_td(struct xhci_hcd *xhci, struct xhci_virt_ep *ep,
 
 	switch (trb_comp_code) {
 	case COMP_SUCCESS:
+		if (ep->err_count)
+			xhci_dbg(xhci, "clear err_count at %px\n", ep_trb);
 		ep->err_count = 0;
 		/* handle success with untransferred data as short packet */
 		if (ep_trb != td->end_trb || remaining) {

@@ -2522,6 +2524,8 @@ static void process_bulk_intr_td(struct xhci_hcd *xhci, struct xhci_virt_ep *ep,
 		td->status = 0;
 		break;
 	case COMP_SHORT_PACKET:
+		if (ep->err_count)
+			xhci_dbg(xhci, "clear err_count short at %px\n", ep_trb);
 		ep->err_count = 0;
 		td->status = 0;
 		break;

@@ -2534,9 +2538,10 @@ static void process_bulk_intr_td(struct xhci_hcd *xhci, struct xhci_virt_ep *ep,
 		goto finish_td;
 	case COMP_USB_TRANSACTION_ERROR:
 		if (xhci->quirks & XHCI_NO_SOFT_RETRY ||
-		    (ep->err_count++ > MAX_SOFT_RETRY) ||
+		    (ep->err_count++ > 10) ||
 		    le32_to_cpu(slot_ctx->tt_info) & TT_SLOT)
 			break;
+		udelay(5 << ep->err_count);
 
 		td->status = 0;
 

@@ -2706,8 +2711,8 @@ static int handle_tx_event(struct xhci_hcd *xhci,
 		status = -EPROTO;
 		break;
 	case COMP_USB_TRANSACTION_ERROR:
-		xhci_dbg(xhci, "Transfer error for slot %u ep %u on endpoint\n",
-			 slot_id, ep_index);
+		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)));
 		status = -EPROTO;
 		break;
 	case COMP_BABBLE_DETECTED_ERROR: