Bug 206779

Summary: usb subsystems hang
Product: Drivers Reporter: sander44 (ionut_n2001)
Component: USBAssignee: Default virtual assignee for Drivers/USB (drivers_usb)
Status: RESOLVED UNREPRODUCIBLE    
Severity: high    
Priority: P1    
Hardware: x86-64   
OS: Linux   
Kernel Version: 5.5.7 Subsystem:
Regression: No Bisected commit-id:

Description sander44 2020-03-07 16:18:36 UTC
Hi,

I observed issue with this version with one usb device.

My setup is:

Ubuntu 19.10 clean install
Kernel 5.5.7 vanilla, 5.5.7-vanilla

My issue is:
[  726.043665] INFO: task fastboot:1531 blocked for more than 120 seconds.
[  726.043716]       Not tainted 5.5.7-vanilla #1
[  726.043734] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  726.043753] fastboot        D    0  1531   1413 0x00000004
[  726.043755] Call Trace:
[  726.043778]  __schedule+0x28c/0x6e0
[  726.043779]  schedule+0x44/0xb0
[  726.043780]  schedule_timeout+0x1d3/0x2f0
[  726.043783]  ? ttwu_do_activate+0x5a/0x70
[  726.043784]  wait_for_completion_timeout+0xb3/0x140
[  726.043785]  ? wake_up_q+0xb0/0xb0
[  726.043787]  usb_start_wait_urb+0x8c/0x180
[  726.043788]  usb_bulk_msg+0xb8/0x160
[  726.043790]  proc_bulk+0x158/0x3a0
[  726.043791]  usbdev_ioctl+0xc08/0x1480
[  726.043794]  do_vfs_ioctl+0xa5/0x680
[  726.043796]  ? finish_task_switch+0x70/0x260
[  726.043798]  ? tomoyo_file_ioctl+0x19/0x20
[  726.043799]  ksys_ioctl+0x75/0x80
[  726.043801]  __x64_sys_ioctl+0x1a/0x20
[  726.043803]  do_syscall_64+0x57/0x1c0
[  726.043804]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[  726.043810] RIP: 0033:0x7f1da431867b
[  726.043815] Code: Bad RIP value.
[  726.043816] RSP: 002b:00007ffdb4c22af8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  726.043817] RAX: ffffffffffffffda RBX: 000055b82cb5c2a0 RCX: 00007f1da431867b
[  726.043818] RDX: 00007ffdb4c22b00 RSI: 00000000c0185502 RDI: 0000000000000004
[  726.043818] RBP: 0000000000000040 R08: 00000000000001ec R09: 00007ffdb4c22b40
[  726.043819] R10: 00007ffdb4c22b00 R11: 0000000000000246 R12: 0000000000000040
[  726.043819] R13: 00000006fc23abff R14: 0000000000000000 R15: 00007ffdb4c22c70
[  774.124057] usb 1-2: USB disconnect, device number 4

I had to restart the car so I could continue the process.
My task is: writing a phone with adb and fastboot.
Comment 1 sander44 2020-03-07 16:21:37 UTC
(In reply to sander44 from comment #0)
> Hi,
> 
> I observed issue with this version with one usb device.
> 
> My setup is:
> 
> Ubuntu 19.10 clean install
> Kernel 5.5.7 vanilla, 5.5.7-vanilla
> 
> My issue is:
> [  726.043665] INFO: task fastboot:1531 blocked for more than 120 seconds.
> [  726.043716]       Not tainted 5.5.7-vanilla #1
> [  726.043734] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
> this message.
> [  726.043753] fastboot        D    0  1531   1413 0x00000004
> [  726.043755] Call Trace:
> [  726.043778]  __schedule+0x28c/0x6e0
> [  726.043779]  schedule+0x44/0xb0
> [  726.043780]  schedule_timeout+0x1d3/0x2f0
> [  726.043783]  ? ttwu_do_activate+0x5a/0x70
> [  726.043784]  wait_for_completion_timeout+0xb3/0x140
> [  726.043785]  ? wake_up_q+0xb0/0xb0
> [  726.043787]  usb_start_wait_urb+0x8c/0x180
> [  726.043788]  usb_bulk_msg+0xb8/0x160
> [  726.043790]  proc_bulk+0x158/0x3a0
> [  726.043791]  usbdev_ioctl+0xc08/0x1480
> [  726.043794]  do_vfs_ioctl+0xa5/0x680
> [  726.043796]  ? finish_task_switch+0x70/0x260
> [  726.043798]  ? tomoyo_file_ioctl+0x19/0x20
> [  726.043799]  ksys_ioctl+0x75/0x80
> [  726.043801]  __x64_sys_ioctl+0x1a/0x20
> [  726.043803]  do_syscall_64+0x57/0x1c0
> [  726.043804]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
> [  726.043810] RIP: 0033:0x7f1da431867b
> [  726.043815] Code: Bad RIP value.
> [  726.043816] RSP: 002b:00007ffdb4c22af8 EFLAGS: 00000246 ORIG_RAX:
> 0000000000000010
> [  726.043817] RAX: ffffffffffffffda RBX: 000055b82cb5c2a0 RCX:
> 00007f1da431867b
> [  726.043818] RDX: 00007ffdb4c22b00 RSI: 00000000c0185502 RDI:
> 0000000000000004
> [  726.043818] RBP: 0000000000000040 R08: 00000000000001ec R09:
> 00007ffdb4c22b40
> [  726.043819] R10: 00007ffdb4c22b00 R11: 0000000000000246 R12:
> 0000000000000040
> [  726.043819] R13: 00000006fc23abff R14: 0000000000000000 R15:
> 00007ffdb4c22c70
> [  774.124057] usb 1-2: USB disconnect, device number 4
> 
> I had to restart the machine - vm so I could continue the process.
> My task is: writing a phone with adb and fastboot.
Comment 2 peter.chen 2020-03-12 10:13:41 UTC
On 20-03-07 16:21:37, bugzilla-daemon@bugzilla.kernel.org wrote:
>
> https://eur01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fbugzilla.kernel.org%2Fshow_bug.cgi%3Fid%3D206779&data=02%7C01%7Cpeter.chen%40nxp.com%7C6362fa93c31249cccc1408d7c2b39d9a%7C686ea1d3bc2b4c6fa92cd99c5c301635%7C0%7C0%7C637191949021070621&sdata=td13UwZNZb0wRL9WjLJXP%2FUHoxSxVut7Xq11JJ1iozM%3D&reserved=0
> 
> --- Comment #1 from sander44 (ionut_n2001@yahoo.com) ---
> (In reply to sander44 from comment #0)
> > Hi,
> > 
> > I observed issue with this version with one usb device.
> > 
> > My setup is:
> > 
> > Ubuntu 19.10 clean install
> > Kernel 5.5.7 vanilla, 5.5.7-vanilla
> > 
> > My issue is:
> > [  726.043665] INFO: task fastboot:1531 blocked for more than 120 seconds.
> > [  726.043716]       Not tainted 5.5.7-vanilla #1
> > [  726.043734] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
> > this message.
> > [  726.043753] fastboot        D    0  1531   1413 0x00000004
> > [  726.043755] Call Trace:
> > [  726.043778]  __schedule+0x28c/0x6e0
> > [  726.043779]  schedule+0x44/0xb0
> > [  726.043780]  schedule_timeout+0x1d3/0x2f0
> > [  726.043783]  ? ttwu_do_activate+0x5a/0x70
> > [  726.043784]  wait_for_completion_timeout+0xb3/0x140
> > [  726.043785]  ? wake_up_q+0xb0/0xb0
> > [  726.043787]  usb_start_wait_urb+0x8c/0x180
> > [  726.043788]  usb_bulk_msg+0xb8/0x160
> > [  726.043790]  proc_bulk+0x158/0x3a0
> > [  726.043791]  usbdev_ioctl+0xc08/0x1480
> > [  726.043794]  do_vfs_ioctl+0xa5/0x680
> > [  726.043796]  ? finish_task_switch+0x70/0x260
> > [  726.043798]  ? tomoyo_file_ioctl+0x19/0x20
> > [  726.043799]  ksys_ioctl+0x75/0x80
> > [  726.043801]  __x64_sys_ioctl+0x1a/0x20
> > [  726.043803]  do_syscall_64+0x57/0x1c0
> > [  726.043804]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
> > [  726.043810] RIP: 0033:0x7f1da431867b
> > [  726.043815] Code: Bad RIP value.
> > [  726.043816] RSP: 002b:00007ffdb4c22af8 EFLAGS: 00000246 ORIG_RAX:
> > 0000000000000010
> > [  726.043817] RAX: ffffffffffffffda RBX: 000055b82cb5c2a0 RCX:
> > 00007f1da431867b
> > [  726.043818] RDX: 00007ffdb4c22b00 RSI: 00000000c0185502 RDI:
> > 0000000000000004
> > [  726.043818] RBP: 0000000000000040 R08: 00000000000001ec R09:
> > 00007ffdb4c22b40
> > [  726.043819] R10: 00007ffdb4c22b00 R11: 0000000000000246 R12:
> > 0000000000000040
> > [  726.043819] R13: 00000006fc23abff R14: 0000000000000000 R15:
> > 00007ffdb4c22c70
> > [  774.124057] usb 1-2: USB disconnect, device number 4
> > 
> > I had to restart the machine - vm so I could continue the process.
> > My task is: writing a phone with adb and fastboot.
> 

The kernel is waiting the transfer has finished, but timeout value
from the user app is unlimited (maybe 0). Try to add timeout value
for this transfer to avoid process hang.
Comment 3 sander44 2020-03-12 20:53:32 UTC
Hello,
I understood, but how could I do it?
Can I do this from kernel variables? With /proc?
Or from the application I use? adb and fastboot.
Comment 4 sander44 2020-05-31 10:52:29 UTC
Hi peter.chen,

With a new kernel release, this issue has been resolved.
I tried 5.6.13 and 5.6.14 and it doesn't reproduce anymore.

Thank you very much.
The problem was somehow solved upstream.
It's ok to close this ticket.