Re: [xhci] usb 4-1: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd

[Sedat Dilek]

On Fri, Mar 5, 2021 at 8:05 PM Sedat Dilek <sedat.dilek@xxxxxxxxx> wrote:
>
> On Fri, Mar 5, 2021 at 5:07 PM Alan Stern <stern@xxxxxxxxxxxxxxxxxxx> wrote:
> >
> > On Fri, Mar 05, 2021 at 01:09:16PM +0100, Sedat Dilek wrote:
> > > On Mon, Mar 1, 2021 at 4:53 PM Alan Stern <stern@xxxxxxxxxxxxxxxxxxx> wrote:
> > > [ ... ]
> > > > You can use usbmon on bus 4 to record the USB traffic.  It may indicate
> > > > why the resets occur.
> > > >
> > >
> > > Hi Alan,
> > >
> > > I followed the instructions in [1].
> > >
> > > root# modprobe -v usbmon
> > >
> > > root# ls /sys/kernel/debug/usb/usbmon
> > > 0s  0u  1s  1t  1u  2s  2t  2u  3s  3t  3u  4s  4t  4u
> > >
> > > root# cat /sys/kernel/debug/usb/usbmon/4u > /tmp/usbmon-log_4u.txt
> > > [ Ctrl+C ]
> > >
> > > I recorded 13:03 - 13:04 (one minute).
> > >
> > > So these xhci-resets should be included:
> > >
> > > [Fri Mar  5 13:03:07 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
> > > number 2 using xhci_hcd
> > > [Fri Mar  5 13:03:07 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
> > > number 2 using xhci_hcd
> > > [Fri Mar  5 13:03:27 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
> > > number 2 using xhci_hcd
> > > [Fri Mar  5 13:03:27 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
> > > number 2 using xhci_hcd
> > > [Fri Mar  5 13:03:27 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
> > > number 2 using xhci_hcd
> > > [Fri Mar  5 13:03:28 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
> > > number 2 using xhci_hcd
> > > [Fri Mar  5 13:03:28 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
> > > number 2 using xhci_hcd
> > >
> > > The usbmon-log is attached.
> > >
> > > Unsure how to interpret the log - the kernel-doc says `raw data`.
> > > How can I bring this into a human-readable format?
> > > Can you give me a hand?
> >
> > Don't worry about trying to decode the output.  To me it looks like the
> > drive crashes and needs to be reset at times when the computer sends it
> > an ATA command.  (Not all ATA commands, but some.)  You can prevent this
> > by setting the following module parameter for the usb-storage driver:
> >
> >         quirks=174c:55aa:t
> >
> > where the two numbers are the Vendor and Product IDs for the external
> > drive, and the 't' is a quirks flag saying not to use any ATA commands.
> > If this module parameter fixes the problem, we can add a permanent quirk
> > setting to the kernel.
> >
>
> Thanks Alan.
>
> I did:
>
> [ /etc/modules-load.d/usb-storage.conf ]
>
> # Add quirks for ATA commands for usb-storage devices connected to
> ASMedia M1042 USB-3.0 controller
> options usb-storage quirks=174c:55aa:t
> - EOF -
>
> It is:
>
> /lib/modules/5.12.0-rc1-11-amd64-clang13-cfi/kernel/drivers/usb/storage/usb-storage.ko
>
> But:
>
> root# lsmod | grep usb | grep storage
> usb_storage            90112  2 uas
> scsi_mod              307200  6 sd_mod,usb_storage,uas,libata,sg,sr_mod
> usbcore               385024  14
> usbserial,xhci_hcd,ehci_pci,usbnet,usbhid,usb_storage,usb_wwan,uvcvideo,ehci_hcd,btusb,xhci_pci,cdc_ether,uas,option
>
> I have not rebooted yet.
>
> Interferences with PowerTop?
>
> These xhci-resets happen every 10mins in a sequence of 4.
>
> I have here a powertop.service (systemd) with passing --auto-tune option.
> That was not a problem with previous Linux-kernels >= v5.12-rc1, so.
>
> Alan, what do you think?
>

The quirks match:

[Fri Mar  5 20:06:56 2021] usb-storage 4-1:1.0: USB Mass Storage device detected
[Fri Mar  5 20:06:56 2021] usb-storage 4-1:1.0: Quirks match for vid
174c pid 55aa: 400000

That seems not to be the trick:

root# LC_ALL=C dmesg -T | grep 'usb 4-1:'
[Fri Mar  5 20:06:55 2021] usb 4-1: new SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:55 2021] usb 4-1: New USB device found,
idVendor=174c, idProduct=55aa, bcdDevice= 1.00
[Fri Mar  5 20:06:55 2021] usb 4-1: New USB device strings: Mfr=2,
Product=3, SerialNumber=1
[Fri Mar  5 20:06:55 2021] usb 4-1: Product: MEDION HDDrive-n-GO
[Fri Mar  5 20:06:55 2021] usb 4-1: Manufacturer: MEDION
[Fri Mar  5 20:06:55 2021] usb 4-1: SerialNumber: 3180000000000000092C
[Fri Mar  5 20:06:57 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:57 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:57 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:58 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:58 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:58 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:58 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:58 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:59 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:59 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:59 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:06:59 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:00 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:00 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:00 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:00 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:00 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:01 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:01 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:01 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:01 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:02 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:02 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:02 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:02 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:28 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:30 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:37 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:37 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:38 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:39 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:39 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:39 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:46 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:47 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:48 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:49 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:52 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:52 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:52 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:52 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:53 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:53 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:54 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:54 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:55 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:55 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:55 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:55 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:56 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:56 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:07:56 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:09:09 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:17:56 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:17:56 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:17:56 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:17:57 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd
[Fri Mar  5 20:17:57 2021] usb 4-1: reset SuperSpeed Gen 1 USB device
number 2 using xhci_hcd

- Sedat -