Re: Trouble with Intenso FlashLine 32GB USB stick on Kernel 4.14

["gregkh@linuxfoundation.org" <gregkh@linuxfoundation.org>]

On Wed, Mar 16, 2022 at 01:39:57PM +0000, Schmid, Carsten wrote:
> Hi Greg, Mathias,
> 
> i have a USB stick that - when plugged in - forces a USB storage hang message.
> Prior to that message i can see USBDEVFS_CONTROL timeout messages.
> (BTW the stick works fine on a desktop system with a recent kernel)
> The stick is having  a USB-C connector, and is connected to a USB2 port through an adapter (that i also used on the Desktop system for a quick check, and it worked there on a USB2 port)
> 
> I built a reproducer and collected traces (see attachment).
> As there is no MAINTAINER given for drivers/usb/core, i send that to you and the USB mailing list to ask someone to look into that.
> 
> >From the kernel's dmesg, these are the entries when trace has been recorded.
> 
> [159909.172301] usb 1-1: new high-speed USB device number 13 using xhci_hcd
> [159909.314291] usb 1-1: New USB device found, idVendor=058f, idProduct=6387
> [159909.314299] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> [159909.314303] usb 1-1: Product: Intenso Flash Line
> [159909.314306] usb 1-1: Manufacturer: ALCOR
> [159909.314310] usb 1-1: SerialNumber: E13DF681
> [159909.317093] usb-storage 1-1:1.0: USB Mass Storage device detected
> [159909.319468] scsi host2: usb-storage 1-1:1.0
> [159909.614535] usb 1-1: usbfs: USBDEVFS_CONTROL failed cmd NmeDefaultPrio rqt 192 rq 51 len 2 ret -110
> [159909.665513] usb 1-1: usbfs: USBDEVFS_CONTROL failed cmd NmeDefaultPrio rqt 192 rq 51 len 2 ret -110
> [159909.729510] usb 1-1: usbfs: USBDEVFS_CONTROL failed cmd NmeDefaultPrio rqt 192 rq 51 len 2 ret -110
> [159909.780610] usb 1-1: usbfs: USBDEVFS_CONTROL failed cmd NmeDefaultPrio rqt 192 rq 51 len 2 ret -110

Why is usbfs being used for a storage device?  What userspace program do
you have that is poking at the device?

> [159928.908633] INFO: task usb-storage:31868 blocked for more than 10 seconds.
> [159928.908638]       Tainted: P     U     O    4.14.244-apl #1
> [159928.908638] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [159928.908640] usb-storage     D    0 31868      2 0x80000080
> [159928.908644] Call Trace:
> [159928.908657]  __schedule+0x1c2/0x7b0
> [159928.908659]  schedule+0x2e/0x90
> [159928.908661]  schedule_timeout+0x230/0x470
> [159928.908672]  ? usb_hcd_submit_urb+0x98/0xbc0 [usbcore]
> [159928.908674]  ? schedule_timeout+0x230/0x470
> [159928.908679]  ? usb_hcd_submit_urb+0x98/0xbc0 [usbcore]
> [159928.908681]  ? __switch_to_asm+0x35/0x70
> [159928.908683]  ? __switch_to_asm+0x41/0x70
> [159928.908684]  ? __switch_to_asm+0x35/0x70
> [159928.908685]  ? __switch_to_asm+0x41/0x70
> [159928.908687]  wait_for_common+0xb5/0x170
> [159928.908689]  ? wait_for_common+0xb5/0x170
> [159928.908692]  ? wake_up_q+0x80/0x80
> [159928.908694]  wait_for_completion+0x18/0x20
> [159928.908699]  usb_sg_wait+0x114/0x170 [usbcore]
> [159928.908706]  usb_stor_bulk_transfer_sglist.part.3+0x62/0xb0 [usb_storage]
> [159928.908708]  usb_stor_bulk_srb+0x46/0x80 [usb_storage]
> [159928.908711]  usb_stor_Bulk_transport+0x123/0x390 [usb_storage]
> [159928.908712]  ? __switch_to_asm+0x35/0x70
> [159928.908714]  ? __switch_to_asm+0x41/0x70
> [159928.908716]  usb_stor_invoke_transport+0x3c/0x530 [usb_storage]
> [159928.908718]  ? wait_for_common+0xb5/0x170
> [159928.908720]  ? wait_for_common+0x149/0x170
> [159928.908722]  ? wake_up_q+0x80/0x80
> [159928.908724]  usb_stor_transparent_scsi_command+0x9/0x10 [usb_storage]
> [159928.908726]  usb_stor_control_thread+0x1eb/0x2d0 [usb_storage]
> [159928.908729]  kthread+0x122/0x140
> [159928.908732]  ? fill_inquiry_response+0x20/0x20 [usb_storage]
> [159928.908733]  ? kthread_create_on_node+0x60/0x60
> [159928.908735]  ret_from_fork+0x35/0x40
> [159931.594483] usb 1-1: reset high-speed USB device number 13 using xhci_hcd
> 
> Anyone from USB who can help with that?

4.14 is really old.  Does 5.16 resolve this?

thanks,

greg k-h