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

[wakasio <scarabeeta@gmail.com>]

Hi Michal,

Thanks for the link. Bug 220936 looks like the same issue, same board
family (MSI X870E), same controller, same suspend timeout messages.

To answer your question: no device was connected to bus 5 or bus 6 at
any point before it happened. Full sequence from that boot:

  10:59:35.014709 xhci_hcd 0000:77:00.0: xHCI Host Controller
  10:59:35.014756 new USB bus registered, assigned bus number 5
  10:59:35.014848 xhci_hcd 0000:77:00.0: xHCI Host Controller
  10:59:35.014893 new USB bus registered, assigned bus number 6
  10:59:35.014938 Host supports USB 3.2 Enhanced SuperSpeed
  10:59:35.015160 usb usb5: SerialNumber: 0000:77:00.0
  10:59:35.015534 usb usb6: SerialNumber: 0000:77:00.0
  11:00:48.349628 Clearing Run/Stop bit failed -110
  11:00:48.349744 PM: suspend_common(): xhci_pci_suspend returns -110
  11:00:48.349812 can't suspend (hcd_pci_runtime_suspend returned -110)

Nothing else touches bus 5 or bus 6 in between. This was autosuspend
on an idle, empty controller, about 73 seconds after boot.

After that I tried unbind and bind on the PCI device by hand, that
did not recover it either:

  11:03:30.975422 xhci_hcd 0000:77:00.0: remove, state 4
  11:03:30.975812 USB bus 6 deregistered
  11:03:30.976136 Host halt failed, -110
  11:03:30.976262 Host controller not halted, aborting reset.
  11:03:30.976325 USB bus 5 deregistered
  11:03:33.058079 can't setup: -110
  11:03:33.058350 init 0000:77:00.0 fail, -110
  11:03:33.058416 probe with driver xhci_hcd failed with error -110

Only a full reboot brought it back. On the next boot I set
/sys/bus/pci/devices/0000:77:00.0/power/control to "on" before
plugging anything in, and did not see the problem again during that
session. I have not tried leaving it on "auto" again to see if it
happens on its own without that workaround.

Separately, I applied the TRB dump patch on top of the previous two
and reproduced the write failure again. Same pattern as the last two
times: 11 soft-resets then a hard-reset, all 12 Transfer error events
at the same TRB address (this run: ffffd140425178e0) with the same
resid (23552).

The dump itself printed fine, event ring and endpoint ring, about
1061 lines total. I could not tell which dumped entry corresponds to
the failing TRB though. The "Transfer error ... at %px" address is a
kernel virtual address, but dump_ring() prints each TRB using
(u64)seg->dma + offset, which is the DMA address. I do not have a way
to convert between the two from here, so I do not want to guess which
line in the dump is the one that failed.

I have the full dump saved. It is about 1061 lines, too long to paste
directly into this mail. Let me know if you want it pasted anyway, or
sent some other way, or if there is a specific part of it you want
first.

Thanks,
wakasio