It seems we have a race on rapidly open/closing usb devices (specifically a USB mouse). To reproduce this, I ran stress-ng on a 128 thread ppc64le Power8 box using the fstat stressor. This will open/fstat/close devices in /dev - it seems that when we have multiple processes closing the USB mouse we hit a deadlock. See kernel log below. Refs: [1] stress-ng: http://kernel.ubuntu.com/~cking/stress-ng/ [ 637.975607] usb 1-3.4: reset low-speed USB device number 4 using xhci_hcd [ 664.568574] usb 1-3.4: reset low-speed USB device number 4 using xhci_hcd [ 722.074678] usb 1-3.4: reset low-speed USB device number 4 using xhci_hcd [ 846.839077] INFO: task kworker/112:1:1148 blocked for more than 120 seconds. [ 846.839342] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 846.839405] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 846.839477] kworker/112:1 D 0 1148 2 0x00000800 [ 846.839486] Workqueue: events __usb_queue_reset_device [ 846.839488] Call Trace: [ 846.839491] [c0000007633f7610] [c0000007633f76d0] 0xc0000007633f76d0 (unreliable) [ 846.839497] [c0000007633f77e0] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 846.839501] [c0000007633f7840] [c000000000b86bb4] __schedule+0x334/0xac0 [ 846.839504] [c0000007633f7900] [c000000000b87388] schedule+0x48/0xc0 [ 846.839508] [c0000007633f7930] [c000000000896534] usb_kill_urb+0xf4/0x130 [ 846.839511] [c0000007633f79a0] [c0000000008944c0] usb_hcd_flush_endpoint+0x120/0x230 [ 846.839514] [c0000007633f7a50] [c000000000898e00] usb_disable_endpoint+0x80/0x110 [ 846.839518] [c0000007633f7a90] [c000000000898f00] usb_disable_interface+0x70/0xa0 [ 846.839521] [c0000007633f7ad0] [c000000000889840] usb_reset_and_verify_device+0x520/0x7a0 [ 846.839524] [c0000007633f7bb0] [c000000000889cb4] usb_reset_device+0x1f4/0x3d0 [ 846.839527] [c0000007633f7c50] [c000000000898a08] __usb_queue_reset_device+0x58/0x90 [ 846.839531] [c0000007633f7c90] [c0000000000f6368] process_one_work+0x1c8/0x570 [ 846.839534] [c0000007633f7d20] [c0000000000f67b8] worker_thread+0xa8/0x5d0 [ 846.839538] [c0000007633f7dc0] [c0000000000ff964] kthread+0x154/0x1a0 [ 846.839542] [c0000007633f7e30] [c00000000000b4e8] ret_from_kernel_thread+0x5c/0x74 [ 846.839583] INFO: task kworker/112:2:6031 blocked for more than 120 seconds. [ 846.839755] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 846.839813] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 846.839882] kworker/112:2 D 0 6031 2 0x00000800 [ 846.839887] Workqueue: usb_hub_wq hub_event [ 846.839889] Call Trace: [ 846.839891] [c00000076d71f6b0] [c00000076d71f770] 0xc00000076d71f770 (unreliable) [ 846.839895] [c00000076d71f880] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 846.839898] [c00000076d71f8e0] [c000000000b86bb4] __schedule+0x334/0xac0 [ 846.839901] [c00000076d71f9a0] [c000000000b87388] schedule+0x48/0xc0 [ 846.839904] [c00000076d71f9d0] [c000000000b878b0] schedule_preempt_disabled+0x20/0x30 [ 846.839907] [c00000076d71f9f0] [c000000000b88ec0] __mutex_lock.isra.0+0x2b0/0xd80 [ 846.839910] [c00000076d71fb20] [c00000000088d860] hub_event+0x4e0/0x1740 [ 846.839913] [c00000076d71fc90] [c0000000000f6368] process_one_work+0x1c8/0x570 [ 846.839916] [c00000076d71fd20] [c0000000000f67b8] worker_thread+0xa8/0x5d0 [ 846.839919] [c00000076d71fdc0] [c0000000000ff964] kthread+0x154/0x1a0 [ 846.839923] [c00000076d71fe30] [c00000000000b4e8] ret_from_kernel_thread+0x5c/0x74 [ 846.839926] INFO: task stress-ng-fstat:6286 blocked for more than 120 seconds. [ 846.839997] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 846.840055] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 846.840125] stress-ng-fstat D 0 6286 6174 0x00040002 [ 846.840128] Call Trace: [ 846.840130] [c0000006efcbf860] [c0000006efcbf920] 0xc0000006efcbf920 (unreliable) [ 846.840134] [c0000006efcbfa30] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 846.840137] [c0000006efcbfa90] [c000000000b86bb4] __schedule+0x334/0xac0 [ 846.840140] [c0000006efcbfb50] [c000000000b87388] schedule+0x48/0xc0 [ 846.840143] [c0000006efcbfb80] [c000000000896534] usb_kill_urb+0xf4/0x130 [ 846.840149] [c0000006efcbfbf0] [d00000000a0006f8] usbhid_close+0x108/0x150 [usbhid] [ 846.840156] [c0000006efcbfc30] [d000000009ee59fc] hidinput_close+0x3c/0x60 [hid] [ 846.840159] [c0000006efcbfc60] [c000000000917cbc] input_close_device+0x7c/0xd0 [ 846.840163] [c0000006efcbfca0] [c00000000091f178] mousedev_close_device+0x88/0xb0 [ 846.840166] [c0000006efcbfcd0] [c00000000091f248] mixdev_close_devices+0xa8/0xf0 [ 846.840170] [c0000006efcbfd10] [c0000000009206a0] mousedev_release+0xa0/0xd0 [ 846.840174] [c0000006efcbfd50] [c0000000003421a4] __fput+0xe4/0x310 [ 846.840177] [c0000006efcbfdb0] [c0000000000fc750] task_work_run+0x130/0x190 [ 846.840181] [c0000006efcbfe00] [c00000000001db64] do_notify_resume+0xe4/0xf0 [ 846.840184] [c0000006efcbfe30] [c00000000000b744] ret_from_except_lite+0x70/0x74 [ 967.671042] INFO: task kworker/112:1:1148 blocked for more than 120 seconds. [ 967.671283] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 967.671341] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 967.671412] kworker/112:1 D 0 1148 2 0x00000800 [ 967.671419] Workqueue: events __usb_queue_reset_device [ 967.671421] Call Trace: [ 967.671423] [c0000007633f7610] [c0000007633f76d0] 0xc0000007633f76d0 (unreliable) [ 967.671428] [c0000007633f77e0] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 967.671432] [c0000007633f7840] [c000000000b86bb4] __schedule+0x334/0xac0 [ 967.671435] [c0000007633f7900] [c000000000b87388] schedule+0x48/0xc0 [ 967.671439] [c0000007633f7930] [c000000000896534] usb_kill_urb+0xf4/0x130 [ 967.671442] [c0000007633f79a0] [c0000000008944c0] usb_hcd_flush_endpoint+0x120/0x230 [ 967.671446] [c0000007633f7a50] [c000000000898e00] usb_disable_endpoint+0x80/0x110 [ 967.671449] [c0000007633f7a90] [c000000000898f00] usb_disable_interface+0x70/0xa0 [ 967.671452] [c0000007633f7ad0] [c000000000889840] usb_reset_and_verify_device+0x520/0x7a0 [ 967.671455] [c0000007633f7bb0] [c000000000889cb4] usb_reset_device+0x1f4/0x3d0 [ 967.671458] [c0000007633f7c50] [c000000000898a08] __usb_queue_reset_device+0x58/0x90 [ 967.671462] [c0000007633f7c90] [c0000000000f6368] process_one_work+0x1c8/0x570 [ 967.671465] [c0000007633f7d20] [c0000000000f67b8] worker_thread+0xa8/0x5d0 [ 967.671468] [c0000007633f7dc0] [c0000000000ff964] kthread+0x154/0x1a0 [ 967.671472] [c0000007633f7e30] [c00000000000b4e8] ret_from_kernel_thread+0x5c/0x74 [ 967.671505] INFO: task kworker/112:2:6031 blocked for more than 120 seconds. [ 967.671673] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 967.671732] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 967.671803] kworker/112:2 D 0 6031 2 0x00000800 [ 967.671807] Workqueue: usb_hub_wq hub_event [ 967.671809] Call Trace: [ 967.671811] [c00000076d71f6b0] [c00000076d71f770] 0xc00000076d71f770 (unreliable) [ 967.671815] [c00000076d71f880] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 967.671818] [c00000076d71f8e0] [c000000000b86bb4] __schedule+0x334/0xac0 [ 967.671821] [c00000076d71f9a0] [c000000000b87388] schedule+0x48/0xc0 [ 967.671824] [c00000076d71f9d0] [c000000000b878b0] schedule_preempt_disabled+0x20/0x30 [ 967.671827] [c00000076d71f9f0] [c000000000b88ec0] __mutex_lock.isra.0+0x2b0/0xd80 [ 967.671830] [c00000076d71fb20] [c00000000088d860] hub_event+0x4e0/0x1740 [ 967.671833] [c00000076d71fc90] [c0000000000f6368] process_one_work+0x1c8/0x570 [ 967.671836] [c00000076d71fd20] [c0000000000f67b8] worker_thread+0xa8/0x5d0 [ 967.671839] [c00000076d71fdc0] [c0000000000ff964] kthread+0x154/0x1a0 [ 967.671843] [c00000076d71fe30] [c00000000000b4e8] ret_from_kernel_thread+0x5c/0x74 [ 967.671846] INFO: task stress-ng-fstat:6286 blocked for more than 120 seconds. [ 967.671915] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 967.671975] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 967.672046] stress-ng-fstat D 0 6286 6174 0x00040002 [ 967.672048] Call Trace: [ 967.672050] [c0000006efcbf860] [c0000006efcbf920] 0xc0000006efcbf920 (unreliable) [ 967.672054] [c0000006efcbfa30] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 967.672057] [c0000006efcbfa90] [c000000000b86bb4] __schedule+0x334/0xac0 [ 967.672060] [c0000006efcbfb50] [c000000000b87388] schedule+0x48/0xc0 [ 967.672063] [c0000006efcbfb80] [c000000000896534] usb_kill_urb+0xf4/0x130 [ 967.672068] [c0000006efcbfbf0] [d00000000a0006f8] usbhid_close+0x108/0x150 [usbhid] [ 967.672073] [c0000006efcbfc30] [d000000009ee59fc] hidinput_close+0x3c/0x60 [hid] [ 967.672077] [c0000006efcbfc60] [c000000000917cbc] input_close_device+0x7c/0xd0 [ 967.672080] [c0000006efcbfca0] [c00000000091f178] mousedev_close_device+0x88/0xb0 [ 967.672084] [c0000006efcbfcd0] [c00000000091f248] mixdev_close_devices+0xa8/0xf0 [ 967.672087] [c0000006efcbfd10] [c0000000009206a0] mousedev_release+0xa0/0xd0 [ 967.672091] [c0000006efcbfd50] [c0000000003421a4] __fput+0xe4/0x310 [ 967.672094] [c0000006efcbfdb0] [c0000000000fc750] task_work_run+0x130/0x190 [ 967.672098] [c0000006efcbfe00] [c00000000001db64] do_notify_resume+0xe4/0xf0 [ 967.672102] [c0000006efcbfe30] [c00000000000b744] ret_from_except_lite+0x70/0x74 [ 1088.503052] INFO: task kworker/112:1:1148 blocked for more than 120 seconds. [ 1088.503322] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 1088.503389] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1088.503599] kworker/112:1 D 0 1148 2 0x00000800 [ 1088.503606] Workqueue: events __usb_queue_reset_device [ 1088.503608] Call Trace: [ 1088.503611] [c0000007633f7610] [c0000007633f76d0] 0xc0000007633f76d0 (unreliable) [ 1088.503616] [c0000007633f77e0] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 1088.503619] [c0000007633f7840] [c000000000b86bb4] __schedule+0x334/0xac0 [ 1088.503622] [c0000007633f7900] [c000000000b87388] schedule+0x48/0xc0 [ 1088.503625] [c0000007633f7930] [c000000000896534] usb_kill_urb+0xf4/0x130 [ 1088.503629] [c0000007633f79a0] [c0000000008944c0] usb_hcd_flush_endpoint+0x120/0x230 [ 1088.503632] [c0000007633f7a50] [c000000000898e00] usb_disable_endpoint+0x80/0x110 [ 1088.503635] [c0000007633f7a90] [c000000000898f00] usb_disable_interface+0x70/0xa0 [ 1088.503638] [c0000007633f7ad0] [c000000000889840] usb_reset_and_verify_device+0x520/0x7a0 [ 1088.503641] [c0000007633f7bb0] [c000000000889cb4] usb_reset_device+0x1f4/0x3d0 [ 1088.503644] [c0000007633f7c50] [c000000000898a08] __usb_queue_reset_device+0x58/0x90 [ 1088.503648] [c0000007633f7c90] [c0000000000f6368] process_one_work+0x1c8/0x570 [ 1088.503651] [c0000007633f7d20] [c0000000000f67b8] worker_thread+0xa8/0x5d0 [ 1088.503654] [c0000007633f7dc0] [c0000000000ff964] kthread+0x154/0x1a0 [ 1088.503658] [c0000007633f7e30] [c00000000000b4e8] ret_from_kernel_thread+0x5c/0x74 [ 1088.503687] INFO: task kworker/112:2:6031 blocked for more than 120 seconds. [ 1088.503761] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 1088.503820] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1088.503890] kworker/112:2 D 0 6031 2 0x00000800 [ 1088.503894] Workqueue: usb_hub_wq hub_event [ 1088.503896] Call Trace: [ 1088.503898] [c00000076d71f6b0] [c00000076d71f770] 0xc00000076d71f770 (unreliable) [ 1088.503902] [c00000076d71f880] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 1088.503905] [c00000076d71f8e0] [c000000000b86bb4] __schedule+0x334/0xac0 [ 1088.503908] [c00000076d71f9a0] [c000000000b87388] schedule+0x48/0xc0 [ 1088.503911] [c00000076d71f9d0] [c000000000b878b0] schedule_preempt_disabled+0x20/0x30 [ 1088.503914] [c00000076d71f9f0] [c000000000b88ec0] __mutex_lock.isra.0+0x2b0/0xd80 [ 1088.503917] [c00000076d71fb20] [c00000000088d860] hub_event+0x4e0/0x1740 [ 1088.503920] [c00000076d71fc90] [c0000000000f6368] process_one_work+0x1c8/0x570 [ 1088.503923] [c00000076d71fd20] [c0000000000f67b8] worker_thread+0xa8/0x5d0 [ 1088.503926] [c00000076d71fdc0] [c0000000000ff964] kthread+0x154/0x1a0 [ 1088.503930] [c00000076d71fe30] [c00000000000b4e8] ret_from_kernel_thread+0x5c/0x74 [ 1088.503933] INFO: task stress-ng-fstat:6286 blocked for more than 120 seconds. [ 1088.504004] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 1088.504062] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1088.504132] stress-ng-fstat D 0 6286 6174 0x00040002 [ 1088.504134] Call Trace: [ 1088.504136] [c0000006efcbf860] [c0000006efcbf920] 0xc0000006efcbf920 (unreliable) [ 1088.504140] [c0000006efcbfa30] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 1088.504143] [c0000006efcbfa90] [c000000000b86bb4] __schedule+0x334/0xac0 [ 1088.504146] [c0000006efcbfb50] [c000000000b87388] schedule+0x48/0xc0 [ 1088.504149] [c0000006efcbfb80] [c000000000896534] usb_kill_urb+0xf4/0x130 [ 1088.504154] [c0000006efcbfbf0] [d00000000a0006f8] usbhid_close+0x108/0x150 [usbhid] [ 1088.504161] [c0000006efcbfc30] [d000000009ee59fc] hidinput_close+0x3c/0x60 [hid] [ 1088.504164] [c0000006efcbfc60] [c000000000917cbc] input_close_device+0x7c/0xd0 [ 1088.504168] [c0000006efcbfca0] [c00000000091f178] mousedev_close_device+0x88/0xb0 [ 1088.504171] [c0000006efcbfcd0] [c00000000091f248] mixdev_close_devices+0xa8/0xf0 [ 1088.504175] [c0000006efcbfd10] [c0000000009206a0] mousedev_release+0xa0/0xd0 [ 1088.504179] [c0000006efcbfd50] [c0000000003421a4] __fput+0xe4/0x310 [ 1088.504182] [c0000006efcbfdb0] [c0000000000fc750] task_work_run+0x130/0x190 [ 1088.504186] [c0000006efcbfe00] [c00000000001db64] do_notify_resume+0xe4/0xf0 [ 1088.504189] [c0000006efcbfe30] [c00000000000b744] ret_from_except_lite+0x70/0x74 [ 1209.335091] INFO: task kworker/112:1:1148 blocked for more than 120 seconds. [ 1209.335359] Tainted: G W 4.10.0-rc5-next-20170125+ #1 [ 1209.335427] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1209.335637] kworker/112:1 D 0 1148 2 0x00000800 [ 1209.335646] Workqueue: events __usb_queue_reset_device [ 1209.335649] Call Trace: [ 1209.335651] [c0000007633f7610] [c0000007633f76d0] 0xc0000007633f76d0 (unreliable) [ 1209.335658] [c0000007633f77e0] [c00000000001bf40] __switch_to+0x2c0/0x450 [ 1209.335662] [c0000007633f7840] [c000000000b86bb4] __schedule+0x334/0xac0 [ 1209.335665] [c0000007633f7900] [c000000000b87388] schedule+0x48/0xc0 [ 1209.335668] [c0000007633f7930] [c000000000896534] usb_kill_urb+0xf4/0x130 [ 1209.335671] [c0000007633f79a0] [c0000000008944c0] usb_hcd_flush_endpoint+0x120/0x230 [ 1209.335675] [c0000007633f7a50] [c000000000898e00] usb_disable_endpoint+0x80/0x110 [ 1209.335678] [c0000007633f7a90] [c000000000898f00] usb_disable_interface+0x70/0xa0 [ 1209.335682] [c0000007633f7ad0] [c000000000889840] usb_reset_and_verify_device+0x520/0x7a0 [ 1209.335684] [c0000007633f7bb0] [c000000000889cb4] usb_reset_device+0x1f4/0x3d0 [ 1209.335688] [c0000007633f7c50] [c000000000898a08] __usb_queue_reset_device+0x58/0x90 [ 1209.335692] [c0000007633f7c90] [c0000000000f6368] process_one_work+0x1c8/0x570 [ 1209.335695] [c0000007633f7d20] [c0000000000f67b8] worker_thread+0xa8/0x5d0 [ 1209.335698] [c0000007633f7dc0] [c0000000000ff964] kthread+0x154/0x1a0 [ 1209.335702] [c0000007633f7e30] [c00000000000b4e8] ret_from_kernel_thread+0x5c/0x74
Devices in question are: Bus 001 Device 004: ID 046b:ff10 American Megatrends, Inc. Virtual Keyboard and Mouse
I'm going to see if quirking this device helps
On Thu, Jan 26, 2017 at 02:37:15PM +0000, bugzilla-daemon@bugzilla.kernel.org wrote: > https://bugzilla.kernel.org/show_bug.cgi?id=193301 > > Bug ID: 193301 > Summary: deadlock on open/closing usb devices using stress-ng > Product: Drivers > Version: 2.5 > Kernel Version: all versions testing, 4.0 through to 4.10.0-rc5 All USB bugs should be sent to the linux-usb@vger.kernel.org mailing list, and not entered into bugzilla. Please bring this issue up there, if it is still a problem in the latest kernel release.