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
