* 3.0-rc6: USB khubd deadlock when hub is powered down @ 2011-07-07 8:05 Stefan Richter 2011-07-07 13:29 ` Stefan Richter 0 siblings, 1 reply; 9+ messages in thread From: Stefan Richter @ 2011-07-07 8:05 UTC (permalink / raw) To: linux-usb; +Cc: linux-kernel Yesterday I updated from 3.0-rc4 to 3.0-rc6. I have got an LCD monitor with integrated USB hub and card reader. Besides the card reader, I had a keyboard and two mice attached to that integrated hub. When I switched off the monitor yesterday, I go the following deadlock. I noticed it today when I switched the monitor back on and the USB subsystem was dead. Note, this is not necessarily a 3.0-rc4...3.0-rc6 regression. USB device unplugging has been unstable for me for several kernel releases. (Although the major culprit hasn't been the USB subsystem but the SCSI and maybe block subsystems which nowadays handle storage device removal in Windows 95 fashion.) So, here is last night's deadlock: Jul 7 00:48:44 stein kernel: usb 1-3: USB disconnect, device number 2 Jul 7 00:48:44 stein kernel: usb 1-3.1: USB disconnect, device number 3 Jul 7 00:48:44 stein kernel: usb 1-3.1.1: USB disconnect, device number 6 Jul 7 00:48:44 stein kernel: generic-usb 0003:046D:C518.0005: can't reset device, 0000:00:12.2-3.1.3/input0, status -71 Jul 7 00:48:44 stein kernel: generic-usb 0003:046D:C042.0001: can't reset device, 0000:00:12.2-3.2/input0, status -71 Jul 7 00:48:44 stein kernel: generic-usb 0003:1267:0103.0003: can't reset device, 0000:00:12.2-3.3/input0, status -71 Jul 7 00:48:44 stein kernel: usb 1-3: clear tt 2 (0040) error -19 Jul 7 00:48:44 stein kernel: usb 1-3: clear tt 3 (0050) error -19 Jul 7 00:48:44 stein kernel: usb 1-3.1: clear tt 1 (0070) error -19 Jul 7 00:48:44 stein kernel: usb 1-3.1.3: USB disconnect, device number 7 Jul 7 00:48:44 stein kernel: usb 1-3.2: USB disconnect, device number 4 Jul 7 00:48:44 stein kernel: usb 1-3.3: USB disconnect, device number 5 Jul 7 00:48:44 stein kernel: Jul 7 00:48:44 stein kernel: ============================================= Jul 7 00:48:44 stein kernel: [ INFO: possible recursive locking detected ] Jul 7 00:48:44 stein kernel: 3.0.0-rc6 #9 Jul 7 00:48:44 stein kernel: --------------------------------------------- Jul 7 00:48:44 stein kernel: khubd/303 is trying to acquire lock: Jul 7 00:48:44 stein kernel: (hcd->bandwidth_mutex){+.+.+.}, at: [<ffffffff8129f588>] usb_set_interface+0x84/0x210 Jul 7 00:48:44 stein kernel: Jul 7 00:48:44 stein kernel: but task is already holding lock: Jul 7 00:48:44 stein kernel: (hcd->bandwidth_mutex){+.+.+.}, at: [<ffffffff81299d7d>] usb_disconnect+0x9a/0x140 Jul 7 00:48:44 stein kernel: Jul 7 00:48:44 stein kernel: other info that might help us debug this: Jul 7 00:48:44 stein kernel: Possible unsafe locking scenario: Jul 7 00:48:44 stein kernel: Jul 7 00:48:44 stein kernel: CPU0 Jul 7 00:48:44 stein kernel: ---- Jul 7 00:48:44 stein kernel: lock(hcd->bandwidth_mutex); Jul 7 00:48:44 stein kernel: lock(hcd->bandwidth_mutex); Jul 7 00:48:44 stein kernel: Jul 7 00:48:44 stein kernel: *** DEADLOCK *** Jul 7 00:48:44 stein kernel: Jul 7 00:48:44 stein kernel: May be due to missing lock nesting notation Jul 7 00:48:44 stein kernel: Jul 7 00:48:44 stein kernel: 4 locks held by khubd/303: Jul 7 00:48:44 stein kernel: #0: (&__lockdep_no_validate__){+.+.+.}, at: [<ffffffff8129a891>] hub_thread+0xdf/0xe5a Jul 7 00:48:44 stein kernel: #1: (&__lockdep_no_validate__){+.+.+.}, at: [<ffffffff81299d3c>] usb_disconnect+0x59/0x140 Jul 7 00:48:44 stein kernel: #2: (hcd->bandwidth_mutex){+.+.+.}, at: [<ffffffff81299d7d>] usb_disconnect+0x9a/0x140 Jul 7 00:48:44 stein kernel: #3: (&__lockdep_no_validate__){+.+.+.}, at: [<ffffffff812674fe>] device_release_driver+0x18/0x2d Jul 7 00:48:44 stein kernel: Jul 7 00:48:44 stein kernel: stack backtrace: Jul 7 00:48:44 stein kernel: Pid: 303, comm: khubd Not tainted 3.0.0-rc6 #9 Jul 7 00:48:44 stein kernel: Call Trace: Jul 7 00:48:44 stein kernel: [<ffffffff8105cfaf>] __lock_acquire+0x169b/0x1734 Jul 7 00:48:44 stein kernel: [<ffffffff8105a1ff>] ? mark_held_locks+0x52/0x70 Jul 7 00:48:44 stein kernel: [<ffffffff8102e603>] ? sub_preempt_count+0x92/0xa6 Jul 7 00:48:44 stein kernel: [<ffffffff8134fcc1>] ? _raw_spin_unlock_irq+0x36/0x53 Jul 7 00:48:44 stein kernel: [<ffffffff810465eb>] ? wait_on_cpu_work+0x6a/0x99 Jul 7 00:48:44 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 Jul 7 00:48:44 stein kernel: [<ffffffff8105d471>] lock_acquire+0x57/0x6d Jul 7 00:48:44 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 Jul 7 00:48:44 stein kernel: [<ffffffff8102e6c4>] ? add_preempt_count+0xad/0xb2 Jul 7 00:48:44 stein kernel: [<ffffffff8134e711>] mutex_lock_nested+0x5e/0x2f9 Jul 7 00:48:44 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 Jul 7 00:48:44 stein kernel: [<ffffffff810466e1>] ? wait_on_work+0xc7/0x115 Jul 7 00:48:44 stein kernel: [<ffffffff8104661a>] ? wait_on_cpu_work+0x99/0x99 Jul 7 00:48:44 stein kernel: [<ffffffff8129f588>] usb_set_interface+0x84/0x210 Jul 7 00:48:44 stein kernel: [<ffffffff81046803>] ? __cancel_work_timer+0xd4/0x11d Jul 7 00:48:44 stein kernel: [<ffffffff812a099b>] usb_unbind_interface+0x93/0xd1 Jul 7 00:48:44 stein kernel: [<ffffffff812673e6>] __device_release_driver+0x67/0xb0 Jul 7 00:48:44 stein kernel: [<ffffffff81267506>] device_release_driver+0x20/0x2d Jul 7 00:48:44 stein kernel: [<ffffffff81266a24>] bus_remove_device+0xb1/0xc6 Jul 7 00:48:44 stein kernel: [<ffffffff812654fa>] device_del+0x11b/0x187 Jul 7 00:48:44 stein kernel: [<ffffffff8129e81b>] usb_disable_device+0x55/0x14b Jul 7 00:48:44 stein kernel: [<ffffffff81299d87>] usb_disconnect+0xa4/0x140 Jul 7 00:48:44 stein kernel: [<ffffffff8129acef>] hub_thread+0x53d/0xe5a Jul 7 00:48:44 stein kernel: [<ffffffff8134d259>] ? schedule+0x878/0x8b0 Jul 7 00:48:44 stein kernel: [<ffffffff8104b06d>] ? wake_up_bit+0x25/0x25 Jul 7 00:48:44 stein kernel: [<ffffffff8134fd24>] ? _raw_spin_unlock_irqrestore+0x46/0x64 Jul 7 00:48:44 stein kernel: [<ffffffff8129a7b2>] ? hub_probe+0x7f3/0x7f3 Jul 7 00:48:44 stein kernel: [<ffffffff8104acca>] kthread+0x7d/0x85 Jul 7 00:48:44 stein kernel: [<ffffffff81351594>] kernel_thread_helper+0x4/0x10 Jul 7 00:48:44 stein kernel: [<ffffffff8102e4f5>] ? finish_task_switch+0x42/0xbe Jul 7 00:48:44 stein kernel: [<ffffffff813500c4>] ? retint_restore_args+0xe/0xe Jul 7 00:48:44 stein kernel: [<ffffffff8104ac4d>] ? __init_kthread_worker+0x56/0x56 Jul 7 00:48:44 stein kernel: [<ffffffff81351590>] ? gs_change+0xb/0xb Jul 7 00:51:26 stein kernel: INFO: task khubd:303 blocked for more than 120 seconds. Jul 7 00:51:26 stein kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Jul 7 00:51:26 stein kernel: khubd D 0000000000000000 0 303 2 0x00000000 Jul 7 00:51:26 stein kernel: ffff88021e3c3af0 0000000000000046 ffffffff8134ccf0 ffffffff8194c2d0 Jul 7 00:51:26 stein kernel: ffff88021e1e6900 ffff88021e3c2010 ffff88021e1e6900 ffff88021e3c3fd8 Jul 7 00:51:26 stein kernel: 00000000000102c0 0000000000004000 ffff88021e3c3fd8 00000000000102c0 Jul 7 00:51:26 stein kernel: Call Trace: Jul 7 00:51:26 stein kernel: [<ffffffff8134ccf0>] ? schedule+0x30f/0x8b0 Jul 7 00:51:26 stein kernel: [<ffffffff8102e603>] ? sub_preempt_count+0x92/0xa6 Jul 7 00:51:26 stein kernel: [<ffffffff8134fcc1>] ? _raw_spin_unlock_irq+0x36/0x53 Jul 7 00:51:26 stein kernel: [<ffffffff810465eb>] ? wait_on_cpu_work+0x6a/0x99 Jul 7 00:51:26 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 Jul 7 00:51:26 stein kernel: [<ffffffff8134e857>] mutex_lock_nested+0x1a4/0x2f9 Jul 7 00:51:26 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 Jul 7 00:51:26 stein kernel: [<ffffffff8104661a>] ? wait_on_cpu_work+0x99/0x99 Jul 7 00:51:26 stein kernel: [<ffffffff8129f588>] usb_set_interface+0x84/0x210 Jul 7 00:51:26 stein kernel: [<ffffffff81046803>] ? __cancel_work_timer+0xd4/0x11d Jul 7 00:51:26 stein kernel: [<ffffffff812a099b>] usb_unbind_interface+0x93/0xd1 Jul 7 00:51:26 stein kernel: [<ffffffff812673e6>] __device_release_driver+0x67/0xb0 Jul 7 00:51:26 stein kernel: [<ffffffff81267506>] device_release_driver+0x20/0x2d Jul 7 00:51:26 stein kernel: [<ffffffff81266a24>] bus_remove_device+0xb1/0xc6 Jul 7 00:51:26 stein kernel: [<ffffffff812654fa>] device_del+0x11b/0x187 Jul 7 00:51:26 stein kernel: [<ffffffff8129e81b>] usb_disable_device+0x55/0x14b Jul 7 00:51:26 stein kernel: [<ffffffff81299d87>] usb_disconnect+0xa4/0x140 Jul 7 00:51:26 stein kernel: [<ffffffff8129acef>] hub_thread+0x53d/0xe5a Jul 7 00:51:26 stein kernel: [<ffffffff8134d259>] ? schedule+0x878/0x8b0 Jul 7 00:51:26 stein kernel: [<ffffffff8104b06d>] ? wake_up_bit+0x25/0x25 Jul 7 00:51:26 stein kernel: [<ffffffff8134fd24>] ? _raw_spin_unlock_irqrestore+0x46/0x64 Jul 7 00:51:26 stein kernel: [<ffffffff8129a7b2>] ? hub_probe+0x7f3/0x7f3 Jul 7 00:51:26 stein kernel: [<ffffffff8104acca>] kthread+0x7d/0x85 Jul 7 00:51:26 stein kernel: [<ffffffff81351594>] kernel_thread_helper+0x4/0x10 Jul 7 00:51:26 stein kernel: [<ffffffff8102e4f5>] ? finish_task_switch+0x42/0xbe Jul 7 00:51:26 stein kernel: [<ffffffff813500c4>] ? retint_restore_args+0xe/0xe Jul 7 00:51:26 stein kernel: [<ffffffff8104ac4d>] ? __init_kthread_worker+0x56/0x56 Jul 7 00:51:26 stein kernel: [<ffffffff81351590>] ? gs_change+0xb/0xb Jul 7 00:51:26 stein kernel: INFO: lockdep is turned off. -- Stefan Richter -=====-==-== -=== --=== http://arcgraph.de/sr/ ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: 3.0-rc6: USB khubd deadlock when hub is powered down 2011-07-07 8:05 3.0-rc6: USB khubd deadlock when hub is powered down Stefan Richter @ 2011-07-07 13:29 ` Stefan Richter 2011-07-07 13:38 ` Stefan Richter 0 siblings, 1 reply; 9+ messages in thread From: Stefan Richter @ 2011-07-07 13:29 UTC (permalink / raw) To: linux-usb; +Cc: linux-kernel On Jul 07 Stefan Richter wrote: > Yesterday I updated from 3.0-rc4 to 3.0-rc6. I have got an LCD monitor > with integrated USB hub and card reader. Besides the card reader, I had a > keyboard and two mice attached to that integrated hub. > > When I switched off the monitor yesterday, I go the following deadlock. I > noticed it today when I switched the monitor back on and the USB subsystem > was dead. > > Note, this is not necessarily a 3.0-rc4...3.0-rc6 regression. It appears to be a regression from -rc4 to -rc6. At the second occasion that I switched the monitor off while running 3.0-rc6, the same happened again. (IOW judging from the mere two tries I did so far, this issue is 100% reproducible.) khubd locked up; no subsequent device re-attachments were recognized; only an USB mouse that was attached to a motherboard USB port already before the deadlock continued to let me move the pointer. Jul 7 15:08:41 stein kernel: usb 1-3.2: USB disconnect, device number 4 Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0006: can't reset device, 0000:00:12.2-3.3/input1, status -71 Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -71 Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0005: can't reset device, 0000:00:12.2-3.3/input0, status -71 Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -71 Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0006: can't reset device, 0000:00:12.2-3.3/input1, status -71 Jul 7 15:08:41 stein kernel: hub 1-3:1.0: hub_port_status failed (err = -71) Jul 7 15:08:41 stein kernel: hub 1-3:1.0: connect-debounce failed, port 2 disabled Jul 7 15:08:41 stein kernel: usb 1-3: USB disconnect, device number 2 Jul 7 15:08:41 stein kernel: usb 1-3.1: USB disconnect, device number 3 Jul 7 15:08:41 stein kernel: usb 1-3.1.1: USB disconnect, device number 6 Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -71 Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0005: can't reset device, 0000:00:12.2-3.3/input0, status -71 Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -19 Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0006: can't reset device, 0000:00:12.2-3.3/input1, status -71 Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -19 Jul 7 15:08:41 stein kernel: usb 1-3.3: USB disconnect, device number 5 Jul 7 15:08:42 stein kernel: Jul 7 15:08:42 stein kernel: ============================================= Jul 7 15:08:42 stein kernel: [ INFO: possible recursive locking detected ] Jul 7 15:08:42 stein kernel: 3.0.0-rc6 #9 Jul 7 15:08:42 stein kernel: --------------------------------------------- Jul 7 15:08:42 stein kernel: khubd/303 is trying to acquire lock: Jul 7 15:08:42 stein kernel: (hcd->bandwidth_mutex){+.+.+.}, at: [<ffffffff8129f588>] usb_set_interface+0x84/0x210 Jul 7 15:08:42 stein kernel: Jul 7 15:08:42 stein kernel: but task is already holding lock: Jul 7 15:08:42 stein kernel: (hcd->bandwidth_mutex){+.+.+.}, at: [<ffffffff81299d7d>] usb_disconnect+0x9a/0x140 Jul 7 15:08:42 stein kernel: Jul 7 15:08:42 stein kernel: other info that might help us debug this: Jul 7 15:08:42 stein kernel: Possible unsafe locking scenario: Jul 7 15:08:42 stein kernel: Jul 7 15:08:42 stein kernel: CPU0 Jul 7 15:08:42 stein kernel: ---- Jul 7 15:08:42 stein kernel: lock(hcd->bandwidth_mutex); Jul 7 15:08:42 stein kernel: lock(hcd->bandwidth_mutex); Jul 7 15:08:42 stein kernel: Jul 7 15:08:42 stein kernel: *** DEADLOCK *** Jul 7 15:08:42 stein kernel: Jul 7 15:08:42 stein kernel: May be due to missing lock nesting notation Jul 7 15:08:42 stein kernel: Jul 7 15:08:42 stein kernel: 4 locks held by khubd/303: Jul 7 15:08:42 stein kernel: #0: (&__lockdep_no_validate__){+.+.+.}, at: [<ffffffff8129a891>] hub_thread+0xdf/0xe5a Jul 7 15:08:42 stein kernel: #1: (&__lockdep_no_validate__){+.+.+.}, at: [<ffffffff81299d3c>] usb_disconnect+0x59/0x140 Jul 7 15:08:42 stein kernel: #2: (hcd->bandwidth_mutex){+.+.+.}, at: [<ffffffff81299d7d>] usb_disconnect+0x9a/0x140 Jul 7 15:08:42 stein kernel: #3: (&__lockdep_no_validate__){+.+.+.}, at: [<ffffffff812674fe>] device_release_driver+0x18/0x2d Jul 7 15:08:42 stein kernel: Jul 7 15:08:42 stein kernel: stack backtrace: Jul 7 15:08:42 stein kernel: Pid: 303, comm: khubd Not tainted 3.0.0-rc6 #9 Jul 7 15:08:42 stein kernel: Call Trace: Jul 7 15:08:42 stein kernel: [<ffffffff8105cfaf>] __lock_acquire+0x169b/0x1734 Jul 7 15:08:42 stein kernel: [<ffffffff8105a1ff>] ? mark_held_locks+0x52/0x70 Jul 7 15:08:42 stein kernel: [<ffffffff8102e603>] ? sub_preempt_count+0x92/0xa6 Jul 7 15:08:42 stein kernel: [<ffffffff8134fcc1>] ? _raw_spin_unlock_irq+0x36/0x53 Jul 7 15:08:42 stein kernel: [<ffffffff810465eb>] ? wait_on_cpu_work+0x6a/0x99 Jul 7 15:08:42 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 Jul 7 15:08:42 stein kernel: [<ffffffff8105d471>] lock_acquire+0x57/0x6d Jul 7 15:08:42 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 Jul 7 15:08:42 stein kernel: [<ffffffff8102e6c4>] ? add_preempt_count+0xad/0xb2 Jul 7 15:08:42 stein kernel: [<ffffffff8134e711>] mutex_lock_nested+0x5e/0x2f9 Jul 7 15:08:42 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 Jul 7 15:08:42 stein kernel: [<ffffffff810466e1>] ? wait_on_work+0xc7/0x115 Jul 7 15:08:42 stein kernel: [<ffffffff8104661a>] ? wait_on_cpu_work+0x99/0x99 Jul 7 15:08:42 stein kernel: [<ffffffff8129f588>] usb_set_interface+0x84/0x210 Jul 7 15:08:42 stein kernel: [<ffffffff81046803>] ? __cancel_work_timer+0xd4/0x11d Jul 7 15:08:42 stein kernel: [<ffffffff812a099b>] usb_unbind_interface+0x93/0xd1 Jul 7 15:08:42 stein kernel: [<ffffffff812673e6>] __device_release_driver+0x67/0xb0 Jul 7 15:08:42 stein kernel: [<ffffffff81267506>] device_release_driver+0x20/0x2d Jul 7 15:08:42 stein kernel: [<ffffffff81266a24>] bus_remove_device+0xb1/0xc6 Jul 7 15:08:42 stein kernel: [<ffffffff812654fa>] device_del+0x11b/0x187 Jul 7 15:08:42 stein kernel: [<ffffffff8129e81b>] usb_disable_device+0x55/0x14b Jul 7 15:08:42 stein kernel: [<ffffffff81299d87>] usb_disconnect+0xa4/0x140 Jul 7 15:08:42 stein kernel: [<ffffffff8129acef>] hub_thread+0x53d/0xe5a Jul 7 15:08:42 stein kernel: [<ffffffff8134d259>] ? schedule+0x878/0x8b0 Jul 7 15:08:42 stein kernel: [<ffffffff8134ccf0>] ? schedule+0x30f/0x8b0 Jul 7 15:08:42 stein kernel: [<ffffffff8104b06d>] ? wake_up_bit+0x25/0x25 Jul 7 15:08:42 stein kernel: [<ffffffff8134fd24>] ? _raw_spin_unlock_irqrestore+0x46/0x64 Jul 7 15:08:42 stein kernel: [<ffffffff8129a7b2>] ? hub_probe+0x7f3/0x7f3 Jul 7 15:08:42 stein kernel: [<ffffffff8104acca>] kthread+0x7d/0x85 Jul 7 15:08:42 stein kernel: [<ffffffff81351594>] kernel_thread_helper+0x4/0x10 Jul 7 15:08:42 stein kernel: [<ffffffff8102e4f5>] ? finish_task_switch+0x42/0xbe Jul 7 15:08:42 stein kernel: [<ffffffff813500c4>] ? retint_restore_args+0xe/0xe Jul 7 15:08:42 stein kernel: [<ffffffff8104ac4d>] ? __init_kthread_worker+0x56/0x56 Jul 7 15:08:42 stein kernel: [<ffffffff81351590>] ? gs_change+0xb/0xb -- Stefan Richter -=====-==-== -=== --=== http://arcgraph.de/sr/ ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: 3.0-rc6: USB khubd deadlock when hub is powered down 2011-07-07 13:29 ` Stefan Richter @ 2011-07-07 13:38 ` Stefan Richter 2011-07-07 14:10 ` Greg KH 0 siblings, 1 reply; 9+ messages in thread From: Stefan Richter @ 2011-07-07 13:38 UTC (permalink / raw) To: Sarah Sharp; +Cc: linux-usb, linux-kernel On Jul 07 Stefan Richter wrote: > It appears to be a regression from -rc4 to -rc6. At the second occasion > that I switched the monitor off while running 3.0-rc6, the same happened > again. (IOW judging from the mere two tries I did so far, this issue is > 100% reproducible.) > > khubd locked up; no subsequent device re-attachments were recognized; > only an USB mouse that was attached to a motherboard USB port already > before the deadlock continued to let me move the pointer. Sarah, "gitk v3.0-rc4.. drivers/usb/core/" makes it look like this is from commit fccf4e86200b8f5edd9a65da26f150e32ba79808. When I find spare time I will test 3.0-rc6 with that one reverted. > Jul 7 15:08:41 stein kernel: usb 1-3.2: USB disconnect, device number 4 > Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0006: can't reset device, 0000:00:12.2-3.3/input1, status -71 > Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -71 > Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0005: can't reset device, 0000:00:12.2-3.3/input0, status -71 > Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -71 > Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0006: can't reset device, 0000:00:12.2-3.3/input1, status -71 > Jul 7 15:08:41 stein kernel: hub 1-3:1.0: hub_port_status failed (err = -71) > Jul 7 15:08:41 stein kernel: hub 1-3:1.0: connect-debounce failed, port 2 disabled > Jul 7 15:08:41 stein kernel: usb 1-3: USB disconnect, device number 2 > Jul 7 15:08:41 stein kernel: usb 1-3.1: USB disconnect, device number 3 > Jul 7 15:08:41 stein kernel: usb 1-3.1.1: USB disconnect, device number 6 > Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -71 > Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0005: can't reset device, 0000:00:12.2-3.3/input0, status -71 > Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -19 > Jul 7 15:08:41 stein kernel: generic-usb 0003:1267:0103.0006: can't reset device, 0000:00:12.2-3.3/input1, status -71 > Jul 7 15:08:41 stein kernel: usb 1-3: clear tt 3 (0050) error -19 > Jul 7 15:08:41 stein kernel: usb 1-3.3: USB disconnect, device number 5 > Jul 7 15:08:42 stein kernel: > Jul 7 15:08:42 stein kernel: ============================================= > Jul 7 15:08:42 stein kernel: [ INFO: possible recursive locking detected ] > Jul 7 15:08:42 stein kernel: 3.0.0-rc6 #9 > Jul 7 15:08:42 stein kernel: --------------------------------------------- > Jul 7 15:08:42 stein kernel: khubd/303 is trying to acquire lock: > Jul 7 15:08:42 stein kernel: (hcd->bandwidth_mutex){+.+.+.}, at: [<ffffffff8129f588>] usb_set_interface+0x84/0x210 > Jul 7 15:08:42 stein kernel: > Jul 7 15:08:42 stein kernel: but task is already holding lock: > Jul 7 15:08:42 stein kernel: (hcd->bandwidth_mutex){+.+.+.}, at: [<ffffffff81299d7d>] usb_disconnect+0x9a/0x140 > Jul 7 15:08:42 stein kernel: > Jul 7 15:08:42 stein kernel: other info that might help us debug this: > Jul 7 15:08:42 stein kernel: Possible unsafe locking scenario: > Jul 7 15:08:42 stein kernel: > Jul 7 15:08:42 stein kernel: CPU0 > Jul 7 15:08:42 stein kernel: ---- > Jul 7 15:08:42 stein kernel: lock(hcd->bandwidth_mutex); > Jul 7 15:08:42 stein kernel: lock(hcd->bandwidth_mutex); > Jul 7 15:08:42 stein kernel: > Jul 7 15:08:42 stein kernel: *** DEADLOCK *** > Jul 7 15:08:42 stein kernel: > Jul 7 15:08:42 stein kernel: May be due to missing lock nesting notation > Jul 7 15:08:42 stein kernel: > Jul 7 15:08:42 stein kernel: 4 locks held by khubd/303: > Jul 7 15:08:42 stein kernel: #0: (&__lockdep_no_validate__){+.+.+.}, at: [<ffffffff8129a891>] hub_thread+0xdf/0xe5a > Jul 7 15:08:42 stein kernel: #1: (&__lockdep_no_validate__){+.+.+.}, at: [<ffffffff81299d3c>] usb_disconnect+0x59/0x140 > Jul 7 15:08:42 stein kernel: #2: (hcd->bandwidth_mutex){+.+.+.}, at: [<ffffffff81299d7d>] usb_disconnect+0x9a/0x140 > Jul 7 15:08:42 stein kernel: #3: (&__lockdep_no_validate__){+.+.+.}, at: [<ffffffff812674fe>] device_release_driver+0x18/0x2d > Jul 7 15:08:42 stein kernel: > Jul 7 15:08:42 stein kernel: stack backtrace: > Jul 7 15:08:42 stein kernel: Pid: 303, comm: khubd Not tainted 3.0.0-rc6 #9 > Jul 7 15:08:42 stein kernel: Call Trace: > Jul 7 15:08:42 stein kernel: [<ffffffff8105cfaf>] __lock_acquire+0x169b/0x1734 > Jul 7 15:08:42 stein kernel: [<ffffffff8105a1ff>] ? mark_held_locks+0x52/0x70 > Jul 7 15:08:42 stein kernel: [<ffffffff8102e603>] ? sub_preempt_count+0x92/0xa6 > Jul 7 15:08:42 stein kernel: [<ffffffff8134fcc1>] ? _raw_spin_unlock_irq+0x36/0x53 > Jul 7 15:08:42 stein kernel: [<ffffffff810465eb>] ? wait_on_cpu_work+0x6a/0x99 > Jul 7 15:08:42 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 > Jul 7 15:08:42 stein kernel: [<ffffffff8105d471>] lock_acquire+0x57/0x6d > Jul 7 15:08:42 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 > Jul 7 15:08:42 stein kernel: [<ffffffff8102e6c4>] ? add_preempt_count+0xad/0xb2 > Jul 7 15:08:42 stein kernel: [<ffffffff8134e711>] mutex_lock_nested+0x5e/0x2f9 > Jul 7 15:08:42 stein kernel: [<ffffffff8129f588>] ? usb_set_interface+0x84/0x210 > Jul 7 15:08:42 stein kernel: [<ffffffff810466e1>] ? wait_on_work+0xc7/0x115 > Jul 7 15:08:42 stein kernel: [<ffffffff8104661a>] ? wait_on_cpu_work+0x99/0x99 > Jul 7 15:08:42 stein kernel: [<ffffffff8129f588>] usb_set_interface+0x84/0x210 > Jul 7 15:08:42 stein kernel: [<ffffffff81046803>] ? __cancel_work_timer+0xd4/0x11d > Jul 7 15:08:42 stein kernel: [<ffffffff812a099b>] usb_unbind_interface+0x93/0xd1 > Jul 7 15:08:42 stein kernel: [<ffffffff812673e6>] __device_release_driver+0x67/0xb0 > Jul 7 15:08:42 stein kernel: [<ffffffff81267506>] device_release_driver+0x20/0x2d > Jul 7 15:08:42 stein kernel: [<ffffffff81266a24>] bus_remove_device+0xb1/0xc6 > Jul 7 15:08:42 stein kernel: [<ffffffff812654fa>] device_del+0x11b/0x187 > Jul 7 15:08:42 stein kernel: [<ffffffff8129e81b>] usb_disable_device+0x55/0x14b > Jul 7 15:08:42 stein kernel: [<ffffffff81299d87>] usb_disconnect+0xa4/0x140 > Jul 7 15:08:42 stein kernel: [<ffffffff8129acef>] hub_thread+0x53d/0xe5a > Jul 7 15:08:42 stein kernel: [<ffffffff8134d259>] ? schedule+0x878/0x8b0 > Jul 7 15:08:42 stein kernel: [<ffffffff8134ccf0>] ? schedule+0x30f/0x8b0 > Jul 7 15:08:42 stein kernel: [<ffffffff8104b06d>] ? wake_up_bit+0x25/0x25 > Jul 7 15:08:42 stein kernel: [<ffffffff8134fd24>] ? _raw_spin_unlock_irqrestore+0x46/0x64 > Jul 7 15:08:42 stein kernel: [<ffffffff8129a7b2>] ? hub_probe+0x7f3/0x7f3 > Jul 7 15:08:42 stein kernel: [<ffffffff8104acca>] kthread+0x7d/0x85 > Jul 7 15:08:42 stein kernel: [<ffffffff81351594>] kernel_thread_helper+0x4/0x10 > Jul 7 15:08:42 stein kernel: [<ffffffff8102e4f5>] ? finish_task_switch+0x42/0xbe > Jul 7 15:08:42 stein kernel: [<ffffffff813500c4>] ? retint_restore_args+0xe/0xe > Jul 7 15:08:42 stein kernel: [<ffffffff8104ac4d>] ? __init_kthread_worker+0x56/0x56 > Jul 7 15:08:42 stein kernel: [<ffffffff81351590>] ? gs_change+0xb/0xb > -- Stefan Richter -=====-==-== -=== --=== http://arcgraph.de/sr/ ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: 3.0-rc6: USB khubd deadlock when hub is powered down 2011-07-07 13:38 ` Stefan Richter @ 2011-07-07 14:10 ` Greg KH 2011-07-07 19:24 ` Stefan Richter 0 siblings, 1 reply; 9+ messages in thread From: Greg KH @ 2011-07-07 14:10 UTC (permalink / raw) To: Stefan Richter; +Cc: Sarah Sharp, linux-usb, linux-kernel [-- Attachment #1: Type: text/plain, Size: 975 bytes --] On Thu, Jul 07, 2011 at 03:38:49PM +0200, Stefan Richter wrote: > On Jul 07 Stefan Richter wrote: > > It appears to be a regression from -rc4 to -rc6. At the second occasion > > that I switched the monitor off while running 3.0-rc6, the same happened > > again. (IOW judging from the mere two tries I did so far, this issue is > > 100% reproducible.) > > > > khubd locked up; no subsequent device re-attachments were recognized; > > only an USB mouse that was attached to a motherboard USB port already > > before the deadlock continued to let me move the pointer. > > Sarah, "gitk v3.0-rc4.. drivers/usb/core/" makes it look like this is from > commit fccf4e86200b8f5edd9a65da26f150e32ba79808. When I find spare time I > will test 3.0-rc6 with that one reverted. Can you test Linus's tree, along with a patch sent yesterday from Alan Stern to the linux-usb mailing list (attached below)? That should resolve this issue, if not, please let us know. thanks, greg k-h [-- Attachment #2: s --] [-- Type: text/plain, Size: 4919 bytes --] >From stern+4e0774f0@rowland.harvard.edu Wed Jul 6 14:03:47 2011 Return-Path: <stern+4e0774f0@rowland.harvard.edu> X-OfflineIMAP: 2303515278-5823848424 Delivered-To: unknown Received: from imap.suse.de ([unix socket]) by imap-int (Cyrus v2.2.12) with LMTPA; Wed, 06 Jul 2011 23:03:47 +0200 X-Sieve: CMU Sieve 2.2 Received: from relay2.suse.de (relay2.suse.de [149.44.160.134]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (Client CN "relay.suse.de", Issuer "CAcert Class 3 Root" (verified OK)) by imap.suse.de (Postfix) with ESMTPS id 685C43C539A9 for <gregkh@imap.suse.de>; Wed, 6 Jul 2011 23:03:47 +0200 (CEST) Received: by relay2.suse.de (Postfix) id 5F09B1855766; Wed, 6 Jul 2011 23:03:47 +0200 (CEST) Received: from localhost (localhost [127.0.0.1]) by relay2.suse.de (Postfix) with ESMTP id 53D4018552DE for <gregkh@suse.de>; Wed, 6 Jul 2011 23:03:47 +0200 (CEST) Received: from relay2.suse.de ([127.0.0.1]) by localhost (localhost [127.0.0.1]) (amavisd-new, port 10026) with ESMTP id 07676-11 for <gregkh@suse.de>; Wed, 6 Jul 2011 23:03:47 +0200 (CEST) Received: from mx2.suse.de (cantor2.suse.de [195.135.220.15]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) by relay2.suse.de (Postfix) with ESMTPS id 0B33018552CC for <gregkh@suse.de>; Wed, 6 Jul 2011 23:03:47 +0200 (CEST) Received: from iolanthe.rowland.org (iolanthe.rowland.org [192.131.102.54]) by mx2.suse.de (Postfix) with SMTP id A86F58B2F9 for <gregkh@suse.de>; Wed, 6 Jul 2011 23:03:46 +0200 (CEST) Received: (qmail 6472 invoked by uid 2102); 6 Jul 2011 17:03:45 -0400 Received: from localhost (sendmail-bs@127.0.0.1) by localhost with SMTP; 6 Jul 2011 17:03:45 -0400 Date: Wed, 6 Jul 2011 17:03:45 -0400 (EDT) From: Alan Stern <stern@rowland.harvard.edu> X-X-Sender: stern@iolanthe.rowland.org To: Greg KH <gregkh@suse.de> Cc: Arkadiusz Miskiewicz <a.miskiewicz@gmail.com>, =?iso-8859-1?Q?=C9ric?= Piel <E.A.B.Piel@tudelft.nl>, Sarah Sharp <sarah.a.sharp@linux.intel.com>, LKML <linux-kernel@vger.kernel.org>, USB list <linux-usb@vger.kernel.org>, "Rafael J. Wysocki" <rjw@sisk.pl> Subject: [PATCH] USB: additional regression fix for device removal In-Reply-To: <20110706204647.GC1460@suse.de> Message-ID: <Pine.LNX.4.44L0.1107061658180.1995-100000@iolanthe.rowland.org> MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII X-Virus-Scanned: by amavisd-new at localhost X-Spam-Status: No, score=0.001 tagged_above=-20 required=5 tests=[BAYES_50=0.001] X-Spam-Score: 0.001 X-Spam-Level: Status: RO Content-Length: 2323 Commit e534c5b831c8b8e9f5edee5c8a37753c808b80dc (USB: fix regression occurring during device removal) didn't go far enough. It failed to take into account that when a driver claims multiple interfaces, it may release them all at the same time. As a result, some interfaces can get released before they are unregistered, and we deadlock trying to acquire the bandwidth_mutex that we already own. This patch (asl478) handles this case by setting the "unregistering" flag on all the interfaces before removing any of them. Signed-off-by: Alan Stern <stern@rowland.harvard.edu> CC: <stable@kernel.org> --- This should take care of Eric's problem as well as Arkadiusz, since they seemed to be hitting the same thing (cdc_ether claiming multiple interfaces and hanging while releasing them). Still, we need to rewrite this stuff. A possible race remains, because a driver may try to change an altsetting at the same time as the device is removed. Either the driver's disconnect routine would hang waiting for the altsetting change (which is waiting to acquire the bandwidth_mutex) or else the altsetting change would go through after the driver was unbound from the device. Neither alternative is good. Alan Stern drivers/usb/core/message.c | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) Index: usb-3.0/drivers/usb/core/message.c =================================================================== --- usb-3.0.orig/drivers/usb/core/message.c +++ usb-3.0/drivers/usb/core/message.c @@ -1147,6 +1147,14 @@ void usb_disable_device(struct usb_devic * any drivers bound to them (a key side effect) */ if (dev->actconfig) { + /* + * FIXME: In order to avoid self-deadlock involving the + * bandwidth_mutex, we have to mark all the interfaces + * before unregistering any of them. + */ + for (i = 0; i < dev->actconfig->desc.bNumInterfaces; i++) + dev->actconfig->interface[i]->unregistering = 1; + for (i = 0; i < dev->actconfig->desc.bNumInterfaces; i++) { struct usb_interface *interface; @@ -1156,7 +1164,6 @@ void usb_disable_device(struct usb_devic continue; dev_dbg(&dev->dev, "unregistering interface %s\n", dev_name(&interface->dev)); - interface->unregistering = 1; remove_intf_ep_devs(interface); device_del(&interface->dev); } ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: 3.0-rc6: USB khubd deadlock when hub is powered down 2011-07-07 14:10 ` Greg KH @ 2011-07-07 19:24 ` Stefan Richter 2011-07-07 20:42 ` Sarah Sharp 0 siblings, 1 reply; 9+ messages in thread From: Stefan Richter @ 2011-07-07 19:24 UTC (permalink / raw) To: Greg KH; +Cc: Sarah Sharp, linux-usb, linux-kernel, Alan Stern On Jul 07 Greg KH wrote: > Can you test Linus's tree, along with a patch sent yesterday from Alan > Stern to the linux-usb mailing list (attached below)? That should > resolve this issue, if not, please let us know. OK. I am using 3.0-rc6-71-g4dd1b49 plus Alan's "USB: additional regression fix for device removal" now. So far it survived a dozen of power toggles of the hub and the attached devices. Thanks. Alan Stern wrote: > Still, we need to rewrite this stuff. A possible race remains, On a general level, the last few kernel.org releases have all been rather weak. Dissatisfied, -- Stefan Richter -=====-==-== -=== --=== http://arcgraph.de/sr/ ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: 3.0-rc6: USB khubd deadlock when hub is powered down 2011-07-07 19:24 ` Stefan Richter @ 2011-07-07 20:42 ` Sarah Sharp 2011-07-07 21:56 ` Stefan Richter 0 siblings, 1 reply; 9+ messages in thread From: Sarah Sharp @ 2011-07-07 20:42 UTC (permalink / raw) To: Stefan Richter; +Cc: Greg KH, linux-usb, linux-kernel, Alan Stern On Thu, Jul 07, 2011 at 09:24:49PM +0200, Stefan Richter wrote: > On Jul 07 Greg KH wrote: > > Can you test Linus's tree, along with a patch sent yesterday from Alan > > Stern to the linux-usb mailing list (attached below)? That should > > resolve this issue, if not, please let us know. > > OK. I am using 3.0-rc6-71-g4dd1b49 plus Alan's "USB: additional > regression fix for device removal" now. So far it survived a dozen of > power toggles of the hub and the attached devices. Thanks. > > Alan Stern wrote: > > Still, we need to rewrite this stuff. A possible race remains, > > On a general level, the last few kernel.org releases have all been rather > weak. Dissatisfied, For USB regressions or the kernel overall? Yes, last kernel release had some nasty regressions-disguised-as-bug-fixes in the USB tree as well. My fault there, not sure how to improve other than coming up with a list of every possible plug-unplug/reset/configure/alt setting change combination possible and testing before sending any thing at all. Suggestions welcome, testing appreciated. Sarah Sharp ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: 3.0-rc6: USB khubd deadlock when hub is powered down 2011-07-07 20:42 ` Sarah Sharp @ 2011-07-07 21:56 ` Stefan Richter 2011-07-08 14:12 ` Alan Stern 0 siblings, 1 reply; 9+ messages in thread From: Stefan Richter @ 2011-07-07 21:56 UTC (permalink / raw) To: Sarah Sharp; +Cc: Greg KH, linux-usb, linux-kernel, Alan Stern On Jul 07 Sarah Sharp wrote: > On Thu, Jul 07, 2011 at 09:24:49PM +0200, Stefan Richter wrote: > > On Jul 07 Greg KH wrote: > > > Can you test Linus's tree, along with a patch sent yesterday from Alan > > > Stern to the linux-usb mailing list (attached below)? That should > > > resolve this issue, if not, please let us know. > > > > OK. I am using 3.0-rc6-71-g4dd1b49 plus Alan's "USB: additional > > regression fix for device removal" now. So far it survived a dozen of > > power toggles of the hub and the attached devices. Thanks. > > > > Alan Stern wrote: > > > Still, we need to rewrite this stuff. A possible race remains, > > > > On a general level, the last few kernel.org releases have all been rather > > weak. Dissatisfied, > > For USB regressions or the kernel overall? Kernel overall. USB unplug issues have been there before, but not as reproducible as this one now. (Which is apparently fixed for me now.) I felt compelled to comment on Alan's sentence though because this does not sound like the 2.6 development approach at all. (Some other subsystem projects, outside USB, ignore that approach anyway and work 2.5 style.) -- Stefan Richter -=====-==-== -=== --=== http://arcgraph.de/sr/ ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: 3.0-rc6: USB khubd deadlock when hub is powered down 2011-07-07 21:56 ` Stefan Richter @ 2011-07-08 14:12 ` Alan Stern 2011-07-08 17:43 ` Stefan Richter 0 siblings, 1 reply; 9+ messages in thread From: Alan Stern @ 2011-07-08 14:12 UTC (permalink / raw) To: Stefan Richter; +Cc: Sarah Sharp, Greg KH, linux-usb, linux-kernel On Thu, 7 Jul 2011, Stefan Richter wrote: > > > On a general level, the last few kernel.org releases have all been rather > > > weak. Dissatisfied, > > > > For USB regressions or the kernel overall? > > Kernel overall. USB unplug issues have been there before, but not as > reproducible as this one now. (Which is apparently fixed for me now.) > > I felt compelled to comment on Alan's sentence though because this does > not sound like the 2.6 development approach at all. (Some other > subsystem projects, outside USB, ignore that approach anyway and work 2.5 > style.) In general, adding support for USB-3.0 has been a tremendous job (of which Sarah has done the lion's share of the work), involving not just adding a new driver but also making significant changes to the subsystem core. Those changes have been sufficiently complicated that things haven't settled down yet. Particularly since it has now become clear that a key implementation decision (to allocate periodic bandwidth dynamically, as it is used, rather than statically) needs to be reversed. The fan-out effects from this will require changes to several other drivers as well, and this is all still in the design stage. Thus, we are forced to limp along with a hacky, not-entirely-correct implementation until everything can be put right. I don't expect this to happen quickly. Alan Stern ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: 3.0-rc6: USB khubd deadlock when hub is powered down 2011-07-08 14:12 ` Alan Stern @ 2011-07-08 17:43 ` Stefan Richter 0 siblings, 0 replies; 9+ messages in thread From: Stefan Richter @ 2011-07-08 17:43 UTC (permalink / raw) To: Alan Stern; +Cc: Sarah Sharp, Greg KH, linux-usb, linux-kernel On Jul 08 Alan Stern wrote: > In general, adding support for USB-3.0 has been a tremendous job (of > which Sarah has done the lion's share of the work), involving not just > adding a new driver but also making significant changes to the > subsystem core. Those changes have been sufficiently complicated that > things haven't settled down yet. > > Particularly since it has now become clear that a key implementation > decision (to allocate periodic bandwidth dynamically, as it is used, > rather than statically) needs to be reversed. The fan-out effects from > this will require changes to several other drivers as well, and this is > all still in the design stage. Thus, we are forced to limp along with > a hacky, not-entirely-correct implementation until everything can be > put right. I don't expect this to happen quickly. OK, fair enough. I acknowledge that such a scope expansion at all layers of the subsystem is a difficult undertaking. Plus, you had working patches that addressed my issue, even before I got around to report it. -- Stefan Richter -=====-==-== -=== -=--- http://arcgraph.de/sr/ ^ permalink raw reply [flat|nested] 9+ messages in thread
end of thread, other threads:[~2011-07-08 17:43 UTC | newest] Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2011-07-07 8:05 3.0-rc6: USB khubd deadlock when hub is powered down Stefan Richter 2011-07-07 13:29 ` Stefan Richter 2011-07-07 13:38 ` Stefan Richter 2011-07-07 14:10 ` Greg KH 2011-07-07 19:24 ` Stefan Richter 2011-07-07 20:42 ` Sarah Sharp 2011-07-07 21:56 ` Stefan Richter 2011-07-08 14:12 ` Alan Stern 2011-07-08 17:43 ` Stefan Richter
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).