Sound+USB: deadlock problem

Sound+USB: deadlock problem

[Jiri Slaby]

Hello,

I've just plugged+unplugged+plugged my USB audio card and the audio
subsystem got stuck:

INFO: task khubd:440 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
khubd           D ffff8801cbc92400     0   440      2 0x00000000
 ffff8801c4ae3a38 0000000000000046 ffff8801c49be270 ffff8801c4ae3fd8
 ffff8801c4ae3fd8 ffff8801c4ae3fd8 ffff8801c4284830 ffff8801c49be270
 ffff8801c4ae3a28 ffff8801a7198758 ffff8801a719875c ffff8801c49be270
Call Trace:
 [<ffffffff816ae109>] schedule+0x29/0x70
 [<ffffffff816ae38e>] schedule_preempt_disabled+0xe/0x10
 [<ffffffff816ad02a>] __mutex_lock_slowpath+0xca/0x140
 [<ffffffff816acb5a>] mutex_lock+0x2a/0x50
 [<ffffffff8157c8e6>] snd_pcm_dev_disconnect+0x46/0x1f0
 [<ffffffff81576512>] snd_device_disconnect+0x62/0xa0
 [<ffffffff815765f4>] snd_device_disconnect_all+0x44/0x70
 [<ffffffff81570d83>] snd_card_disconnect+0x153/0x1d0
 [<ffffffff816ad3a8>] ? down_write+0x38/0x40
 [<ffffffff815bf038>] usb_audio_disconnect+0x88/0x1c0
 [<ffffffff814df460>] usb_unbind_interface+0x60/0x1a0
 [<ffffffff81436e4c>] __device_release_driver+0x7c/0xe0
 [<ffffffff814370bc>] device_release_driver+0x2c/0x40
 [<ffffffff8143681e>] bus_remove_device+0xee/0x160
 [<ffffffff81433c2a>] device_del+0x11a/0x1b0
 [<ffffffff814dce40>] usb_disable_device+0xb0/0x270
 [<ffffffff814d38ed>] usb_disconnect+0xad/0x160
 [<ffffffff814d613e>] hub_thread+0x6fe/0x1700
 [<ffffffff810b643e>] ? dequeue_task_fair+0xee/0x100
 [<ffffffff810a2c70>] ? finish_wait+0x80/0x80
 [<ffffffff814d5a40>] ? usb_remote_wakeup+0x70/0x70
 [<ffffffff810a2620>] kthread+0xc0/0xd0
 [<ffffffff810a2560>] ? kthread_create_on_node+0x130/0x130
 [<ffffffff816afb5c>] ret_from_fork+0x7c/0xb0
 [<ffffffff810a2560>] ? kthread_create_on_node+0x130/0x130
INFO: task pulseaudio:4642 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
pulseaudio      D ffff8801cbc12400     0  4642      1 0x00000000
 ffff8801c1c39cf0 0000000000000082 ffff8801c0d7d550 ffff8801c1c39fd8
 ffff8801c1c39fd8 ffff8801c1c39fd8 ffff8801a7203480 ffff8801c0d7d550
 ffff8801aa37b530 ffff8801c0d7d550 ffff8800ab118a48 fffffffeffffffff
Call Trace:
 [<ffffffff816ae109>] schedule+0x29/0x70
 [<ffffffff816aeafd>] rwsem_down_failed_common+0xbd/0x150
 [<ffffffff816aebc5>] rwsem_down_read_failed+0x15/0x17
 [<ffffffff81302c04>] call_rwsem_down_read_failed+0x14/0x30
 [<ffffffff816ad3d4>] ? down_read+0x24/0x2b
 [<ffffffff815c84b2>] snd_usb_hw_free+0x42/0x90
 [<ffffffff815809ab>] snd_pcm_release_substream+0x5b/0xc0
 [<ffffffff81580a58>] snd_pcm_release+0x48/0xb0
 [<ffffffff815707d7>] snd_disconnect_release+0x97/0xe0
 [<ffffffff8116ed8c>] __fput+0xec/0x230
 [<ffffffff8116eede>] ____fput+0xe/0x10
 [<ffffffff8109ef37>] task_work_run+0xa7/0xe0
 [<ffffffff81045959>] do_notify_resume+0x59/0x80
 [<ffffffff816afe08>] int_signal+0x12/0x17
INFO: task khubd:440 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
khubd           D ffff8801cbc92400     0   440      2 0x00000000
 ffff8801c4ae3a38 0000000000000046 ffff8801c49be270 ffff8801c4ae3fd8
 ffff8801c4ae3fd8 ffff8801c4ae3fd8 ffff8801c4284830 ffff8801c49be270
 ffff8801c4ae3a28 ffff8801a7198758 ffff8801a719875c ffff8801c49be270
Call Trace:
 [<ffffffff816ae109>] schedule+0x29/0x70
 [<ffffffff816ae38e>] schedule_preempt_disabled+0xe/0x10
 [<ffffffff816ad02a>] __mutex_lock_slowpath+0xca/0x140
 [<ffffffff816acb5a>] mutex_lock+0x2a/0x50
 [<ffffffff8157c8e6>] snd_pcm_dev_disconnect+0x46/0x1f0
 [<ffffffff81576512>] snd_device_disconnect+0x62/0xa0
 [<ffffffff815765f4>] snd_device_disconnect_all+0x44/0x70
 [<ffffffff81570d83>] snd_card_disconnect+0x153/0x1d0
 [<ffffffff816ad3a8>] ? down_write+0x38/0x40
 [<ffffffff815bf038>] usb_audio_disconnect+0x88/0x1c0
 [<ffffffff814df460>] usb_unbind_interface+0x60/0x1a0
 [<ffffffff81436e4c>] __device_release_driver+0x7c/0xe0
 [<ffffffff814370bc>] device_release_driver+0x2c/0x40
 [<ffffffff8143681e>] bus_remove_device+0xee/0x160
 [<ffffffff81433c2a>] device_del+0x11a/0x1b0
 [<ffffffff814dce40>] usb_disable_device+0xb0/0x270
 [<ffffffff814d38ed>] usb_disconnect+0xad/0x160
 [<ffffffff814d613e>] hub_thread+0x6fe/0x1700
 [<ffffffff810b643e>] ? dequeue_task_fair+0xee/0x100
 [<ffffffff810a2c70>] ? finish_wait+0x80/0x80
 [<ffffffff814d5a40>] ? usb_remote_wakeup+0x70/0x70
 [<ffffffff810a2620>] kthread+0xc0/0xd0
 [<ffffffff810a2560>] ? kthread_create_on_node+0x130/0x130
 [<ffffffff816afb5c>] ret_from_fork+0x7c/0xb0
 [<ffffffff810a2560>] ? kthread_create_on_node+0x130/0x130
sadc            D ffff8801cbc92400     0  7883   7870 0x00000004
 ffff8801b9ab5d98 0000000000000082 ffff8801087b0d20 ffff8801b9ab5fd8
 ffff8801b9ab5fd8 ffff8801b9ab5fd8 ffff8801c487c830 ffff8801087b0d20
 ffff8801c0ca5380 ffff8801b99b08e8 ffff8801b99b08ec ffff8801087b0d20
Call Trace:
 [<ffffffff816ae109>] schedule+0x29/0x70
 [<ffffffff816ae38e>] schedule_preempt_disabled+0xe/0x10
 [<ffffffff816ad02a>] __mutex_lock_slowpath+0xca/0x140
 [<ffffffff816acb5a>] mutex_lock+0x2a/0x50
 [<ffffffff814e312b>] show_manufacturer+0x2b/0x60
 [<ffffffff81433910>] dev_attr_show+0x20/0x60
 [<ffffffff81129707>] ? __get_free_pages+0x17/0x50
 [<ffffffff811d6fc5>] sysfs_read_file+0xa5/0x1c0
 [<ffffffff8116dcb9>] vfs_read+0xa9/0x180
 [<ffffffff8116dde2>] sys_read+0x52/0xa0
 [<ffffffff816afc02>] system_call_fastpath+0x16/0x1b


thanks,
-- 
js
suse labs

Re: Sound+USB: deadlock problem

[Takashi Iwai]

At Tue, 13 Nov 2012 09:26:17 +0100,
Jiri Slaby wrote:
> 
> Hello,
> 
> I've just plugged+unplugged+plugged my USB audio card and the audio
> subsystem got stuck:

Which kernel?  If it's older than 3.7-rc5, could you try 3.7-rc5?


Takashi

> 
> INFO: task khubd:440 blocked for more than 120 seconds.
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> khubd           D ffff8801cbc92400     0   440      2 0x00000000
>  ffff8801c4ae3a38 0000000000000046 ffff8801c49be270 ffff8801c4ae3fd8
>  ffff8801c4ae3fd8 ffff8801c4ae3fd8 ffff8801c4284830 ffff8801c49be270
>  ffff8801c4ae3a28 ffff8801a7198758 ffff8801a719875c ffff8801c49be270
> Call Trace:
>  [<ffffffff816ae109>] schedule+0x29/0x70
>  [<ffffffff816ae38e>] schedule_preempt_disabled+0xe/0x10
>  [<ffffffff816ad02a>] __mutex_lock_slowpath+0xca/0x140
>  [<ffffffff816acb5a>] mutex_lock+0x2a/0x50
>  [<ffffffff8157c8e6>] snd_pcm_dev_disconnect+0x46/0x1f0
>  [<ffffffff81576512>] snd_device_disconnect+0x62/0xa0
>  [<ffffffff815765f4>] snd_device_disconnect_all+0x44/0x70
>  [<ffffffff81570d83>] snd_card_disconnect+0x153/0x1d0
>  [<ffffffff816ad3a8>] ? down_write+0x38/0x40
>  [<ffffffff815bf038>] usb_audio_disconnect+0x88/0x1c0
>  [<ffffffff814df460>] usb_unbind_interface+0x60/0x1a0
>  [<ffffffff81436e4c>] __device_release_driver+0x7c/0xe0
>  [<ffffffff814370bc>] device_release_driver+0x2c/0x40
>  [<ffffffff8143681e>] bus_remove_device+0xee/0x160
>  [<ffffffff81433c2a>] device_del+0x11a/0x1b0
>  [<ffffffff814dce40>] usb_disable_device+0xb0/0x270
>  [<ffffffff814d38ed>] usb_disconnect+0xad/0x160
>  [<ffffffff814d613e>] hub_thread+0x6fe/0x1700
>  [<ffffffff810b643e>] ? dequeue_task_fair+0xee/0x100
>  [<ffffffff810a2c70>] ? finish_wait+0x80/0x80
>  [<ffffffff814d5a40>] ? usb_remote_wakeup+0x70/0x70
>  [<ffffffff810a2620>] kthread+0xc0/0xd0
>  [<ffffffff810a2560>] ? kthread_create_on_node+0x130/0x130
>  [<ffffffff816afb5c>] ret_from_fork+0x7c/0xb0
>  [<ffffffff810a2560>] ? kthread_create_on_node+0x130/0x130
> INFO: task pulseaudio:4642 blocked for more than 120 seconds.
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> pulseaudio      D ffff8801cbc12400     0  4642      1 0x00000000
>  ffff8801c1c39cf0 0000000000000082 ffff8801c0d7d550 ffff8801c1c39fd8
>  ffff8801c1c39fd8 ffff8801c1c39fd8 ffff8801a7203480 ffff8801c0d7d550
>  ffff8801aa37b530 ffff8801c0d7d550 ffff8800ab118a48 fffffffeffffffff
> Call Trace:
>  [<ffffffff816ae109>] schedule+0x29/0x70
>  [<ffffffff816aeafd>] rwsem_down_failed_common+0xbd/0x150
>  [<ffffffff816aebc5>] rwsem_down_read_failed+0x15/0x17
>  [<ffffffff81302c04>] call_rwsem_down_read_failed+0x14/0x30
>  [<ffffffff816ad3d4>] ? down_read+0x24/0x2b
>  [<ffffffff815c84b2>] snd_usb_hw_free+0x42/0x90
>  [<ffffffff815809ab>] snd_pcm_release_substream+0x5b/0xc0
>  [<ffffffff81580a58>] snd_pcm_release+0x48/0xb0
>  [<ffffffff815707d7>] snd_disconnect_release+0x97/0xe0
>  [<ffffffff8116ed8c>] __fput+0xec/0x230
>  [<ffffffff8116eede>] ____fput+0xe/0x10
>  [<ffffffff8109ef37>] task_work_run+0xa7/0xe0
>  [<ffffffff81045959>] do_notify_resume+0x59/0x80
>  [<ffffffff816afe08>] int_signal+0x12/0x17
> INFO: task khubd:440 blocked for more than 120 seconds.
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> khubd           D ffff8801cbc92400     0   440      2 0x00000000
>  ffff8801c4ae3a38 0000000000000046 ffff8801c49be270 ffff8801c4ae3fd8
>  ffff8801c4ae3fd8 ffff8801c4ae3fd8 ffff8801c4284830 ffff8801c49be270
>  ffff8801c4ae3a28 ffff8801a7198758 ffff8801a719875c ffff8801c49be270
> Call Trace:
>  [<ffffffff816ae109>] schedule+0x29/0x70
>  [<ffffffff816ae38e>] schedule_preempt_disabled+0xe/0x10
>  [<ffffffff816ad02a>] __mutex_lock_slowpath+0xca/0x140
>  [<ffffffff816acb5a>] mutex_lock+0x2a/0x50
>  [<ffffffff8157c8e6>] snd_pcm_dev_disconnect+0x46/0x1f0
>  [<ffffffff81576512>] snd_device_disconnect+0x62/0xa0
>  [<ffffffff815765f4>] snd_device_disconnect_all+0x44/0x70
>  [<ffffffff81570d83>] snd_card_disconnect+0x153/0x1d0
>  [<ffffffff816ad3a8>] ? down_write+0x38/0x40
>  [<ffffffff815bf038>] usb_audio_disconnect+0x88/0x1c0
>  [<ffffffff814df460>] usb_unbind_interface+0x60/0x1a0
>  [<ffffffff81436e4c>] __device_release_driver+0x7c/0xe0
>  [<ffffffff814370bc>] device_release_driver+0x2c/0x40
>  [<ffffffff8143681e>] bus_remove_device+0xee/0x160
>  [<ffffffff81433c2a>] device_del+0x11a/0x1b0
>  [<ffffffff814dce40>] usb_disable_device+0xb0/0x270
>  [<ffffffff814d38ed>] usb_disconnect+0xad/0x160
>  [<ffffffff814d613e>] hub_thread+0x6fe/0x1700
>  [<ffffffff810b643e>] ? dequeue_task_fair+0xee/0x100
>  [<ffffffff810a2c70>] ? finish_wait+0x80/0x80
>  [<ffffffff814d5a40>] ? usb_remote_wakeup+0x70/0x70
>  [<ffffffff810a2620>] kthread+0xc0/0xd0
>  [<ffffffff810a2560>] ? kthread_create_on_node+0x130/0x130
>  [<ffffffff816afb5c>] ret_from_fork+0x7c/0xb0
>  [<ffffffff810a2560>] ? kthread_create_on_node+0x130/0x130
> sadc            D ffff8801cbc92400     0  7883   7870 0x00000004
>  ffff8801b9ab5d98 0000000000000082 ffff8801087b0d20 ffff8801b9ab5fd8
>  ffff8801b9ab5fd8 ffff8801b9ab5fd8 ffff8801c487c830 ffff8801087b0d20
>  ffff8801c0ca5380 ffff8801b99b08e8 ffff8801b99b08ec ffff8801087b0d20
> Call Trace:
>  [<ffffffff816ae109>] schedule+0x29/0x70
>  [<ffffffff816ae38e>] schedule_preempt_disabled+0xe/0x10
>  [<ffffffff816ad02a>] __mutex_lock_slowpath+0xca/0x140
>  [<ffffffff816acb5a>] mutex_lock+0x2a/0x50
>  [<ffffffff814e312b>] show_manufacturer+0x2b/0x60
>  [<ffffffff81433910>] dev_attr_show+0x20/0x60
>  [<ffffffff81129707>] ? __get_free_pages+0x17/0x50
>  [<ffffffff811d6fc5>] sysfs_read_file+0xa5/0x1c0
>  [<ffffffff8116dcb9>] vfs_read+0xa9/0x180
>  [<ffffffff8116dde2>] sys_read+0x52/0xa0
>  [<ffffffff816afc02>] system_call_fastpath+0x16/0x1b
> 
> 
> thanks,
> -- 
> js
> suse labs
> 

Re: Sound+USB: deadlock problem

[Jiri Slaby]

On 11/13/2012 09:28 AM, Takashi Iwai wrote:
> At Tue, 13 Nov 2012 09:26:17 +0100,
> Jiri Slaby wrote:
>>
>> Hello,
>>
>> I've just plugged+unplugged+plugged my USB audio card and the audio
>> subsystem got stuck:
> 
> Which kernel?  If it's older than 3.7-rc5, could you try 3.7-rc5?

Oh, forgot to mention:
3.7.0-rc5-next-20121112_64+

thanks,
-- 
js
suse labs

Re: Sound+USB: deadlock problem

[Takashi Iwai]

At Tue, 13 Nov 2012 09:30:10 +0100,
Jiri Slaby wrote:
> 
> On 11/13/2012 09:28 AM, Takashi Iwai wrote:
> > At Tue, 13 Nov 2012 09:26:17 +0100,
> > Jiri Slaby wrote:
> >>
> >> Hello,
> >>
> >> I've just plugged+unplugged+plugged my USB audio card and the audio
> >> subsystem got stuck:
> > 
> > Which kernel?  If it's older than 3.7-rc5, could you try 3.7-rc5?
> 
> Oh, forgot to mention:
> 3.7.0-rc5-next-20121112_64+

Through a quick glance, one of mutex locks seems stuck.
Just a blind short -- does the patch below cure the problem?


thanks,

Takashi

---
diff --git a/sound/core/pcm.c b/sound/core/pcm.c
index 030102c..a66a7ca 100644
--- a/sound/core/pcm.c
+++ b/sound/core/pcm.c
@@ -1086,7 +1086,7 @@ static int snd_pcm_dev_disconnect(struct snd_device *device)
 	if (list_empty(&pcm->list))
 		goto unlock;
 
-	mutex_lock(&pcm->open_mutex);
+	/* mutex_lock(&pcm->open_mutex); */
 	wake_up(&pcm->open_wait);
 	list_del_init(&pcm->list);
 	for (cidx = 0; cidx < 2; cidx++)
@@ -1118,7 +1118,7 @@ static int snd_pcm_dev_disconnect(struct snd_device *device)
 			pcm->streams[cidx].chmap_kctl = NULL;
 		}
 	}
-	mutex_unlock(&pcm->open_mutex);
+	/* mutex_unlock(&pcm->open_mutex); */
  unlock:
 	mutex_unlock(&register_mutex);
 	return 0;

Re: Sound+USB: deadlock problem

[Jiri Slaby]

On 11/13/2012 09:45 AM, Takashi Iwai wrote:
> At Tue, 13 Nov 2012 09:30:10 +0100,
> Jiri Slaby wrote:
>>
>> On 11/13/2012 09:28 AM, Takashi Iwai wrote:
>>> At Tue, 13 Nov 2012 09:26:17 +0100,
>>> Jiri Slaby wrote:
>>>>
>>>> Hello,
>>>>
>>>> I've just plugged+unplugged+plugged my USB audio card and the audio
>>>> subsystem got stuck:
>>>
>>> Which kernel?  If it's older than 3.7-rc5, could you try 3.7-rc5?
>>
>> Oh, forgot to mention:
>> 3.7.0-rc5-next-20121112_64+
> 
> Through a quick glance, one of mutex locks seems stuck.
> Just a blind short -- does the patch below cure the problem?

Yes, this helps.

Adding a LOCKDEP splash _before_ applying the patch:
======================================================
[ INFO: possible circular locking dependency detected ]
3.7.0-rc5-next-20121112_64-ldep+ #15 Not tainted
-------------------------------------------------------
khubd/446 is trying to acquire lock:
 (&pcm->open_mutex){+.+.+.}, at: [<ffffffff8154c555>]
snd_pcm_dev_disconnect+0x45/0x1f0

but task is already holding lock:
 (register_mutex#2){+.+.+.}, at: [<ffffffff8154c533>]
snd_pcm_dev_disconnect+0x23/0x1f0

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (register_mutex#2){+.+.+.}:
       [<ffffffff810c5e8a>] lock_acquire+0x5a/0x70
       [<ffffffff81697fa9>] mutex_lock_nested+0x69/0x3a0
       [<ffffffff8154c533>] snd_pcm_dev_disconnect+0x23/0x1f0
       [<ffffffff815462e2>] snd_device_disconnect+0x62/0xa0
       [<ffffffff815463bc>] snd_device_disconnect_all+0x3c/0x60
       [<ffffffff81540ec7>] snd_card_disconnect+0x147/0x1d0
       [<ffffffff8158c328>] usb_audio_disconnect+0x98/0x1d0
       [<ffffffff814aa4fe>] usb_unbind_interface+0x5e/0x1a0
       [<ffffffff81404ad7>] __device_release_driver+0x77/0xe0
       [<ffffffff81404d49>] device_release_driver+0x29/0x40
       [<ffffffff814044aa>] bus_remove_device+0xfa/0x170
       [<ffffffff81401917>] device_del+0x127/0x1c0
       [<ffffffff814a7f20>] usb_disable_device+0xb0/0x270
       [<ffffffff8149ea0d>] usb_disconnect+0xad/0x160
       [<ffffffff814a12bc>] hub_thread+0x71c/0x1730
       [<ffffffff810967e6>] kthread+0xd6/0xe0
       [<ffffffff8169c2ec>] ret_from_fork+0x7c/0xb0

-> #1 (&chip->shutdown_rwsem){++++++}:
       [<ffffffff810c5e8a>] lock_acquire+0x5a/0x70
       [<ffffffff816993b7>] down_read+0x47/0x5c
       [<ffffffff8158cf9c>] snd_usb_autoresume+0x2c/0x60
       [<ffffffff81594e2f>] snd_usb_pcm_open+0x20f/0x4a0
       [<ffffffff815950db>] snd_usb_playback_open+0xb/0x10
       [<ffffffff81553c0e>] snd_pcm_open_substream+0x4e/0x90
       [<ffffffff81553d02>] snd_pcm_open+0xb2/0x250
       [<ffffffff81553f53>] snd_pcm_playback_open+0x43/0x70
       [<ffffffff8153fb9a>] snd_open+0xba/0x200
       [<ffffffff81152766>] chrdev_open+0x96/0x1c0
       [<ffffffff8114c766>] do_dentry_open.isra.16+0x1e6/0x280
       [<ffffffff8114c836>] finish_open+0x36/0x70
       [<ffffffff8115c53e>] do_last.isra.64+0x2ce/0xcc0
       [<ffffffff8115cfe3>] path_openat.isra.65+0xb3/0x4d0
       [<ffffffff8115d66c>] do_filp_open+0x3c/0x90
       [<ffffffff8114d8af>] do_sys_open+0xef/0x1d0
       [<ffffffff8114d9ac>] sys_open+0x1c/0x20
       [<ffffffff8169c392>] system_call_fastpath+0x16/0x1b

-> #0 (&pcm->open_mutex){+.+.+.}:
       [<ffffffff810c5968>] __lock_acquire+0x1c38/0x1c40
       [<ffffffff810c5e8a>] lock_acquire+0x5a/0x70
       [<ffffffff81697fa9>] mutex_lock_nested+0x69/0x3a0
       [<ffffffff8154c555>] snd_pcm_dev_disconnect+0x45/0x1f0
       [<ffffffff815462e2>] snd_device_disconnect+0x62/0xa0
       [<ffffffff815463bc>] snd_device_disconnect_all+0x3c/0x60
       [<ffffffff81540ec7>] snd_card_disconnect+0x147/0x1d0
       [<ffffffff8158c328>] usb_audio_disconnect+0x98/0x1d0
       [<ffffffff814aa4fe>] usb_unbind_interface+0x5e/0x1a0
       [<ffffffff81404ad7>] __device_release_driver+0x77/0xe0
       [<ffffffff81404d49>] device_release_driver+0x29/0x40
       [<ffffffff814044aa>] bus_remove_device+0xfa/0x170
       [<ffffffff81401917>] device_del+0x127/0x1c0
       [<ffffffff814a7f20>] usb_disable_device+0xb0/0x270
       [<ffffffff8149ea0d>] usb_disconnect+0xad/0x160
       [<ffffffff814a12bc>] hub_thread+0x71c/0x1730
       [<ffffffff810967e6>] kthread+0xd6/0xe0
       [<ffffffff8169c2ec>] ret_from_fork+0x7c/0xb0

other info that might help us debug this:

Chain exists of:
  &pcm->open_mutex --> &chip->shutdown_rwsem --> register_mutex#2

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(register_mutex#2);
                               lock(&chip->shutdown_rwsem);
                               lock(register_mutex#2);
  lock(&pcm->open_mutex);

 *** DEADLOCK ***

6 locks held by khubd/446:
 #0:  (&__lockdep_no_validate__){......}, at: [<ffffffff814a0c7e>]
hub_thread+0xde/0x1730
 #1:  (&__lockdep_no_validate__){......}, at: [<ffffffff8149e9c1>]
usb_disconnect+0x61/0x160
 #2:  (&__lockdep_no_validate__){......}, at: [<ffffffff81404d41>]
device_release_driver+0x21/0x40
 #3:  (register_mutex#5){+.+.+.}, at: [<ffffffff8158c2c5>]
usb_audio_disconnect+0x35/0x1d0
 #4:  (&chip->shutdown_rwsem){++++++}, at: [<ffffffff8158c2d5>]
usb_audio_disconnect+0x45/0x1d0
 #5:  (register_mutex#2){+.+.+.}, at: [<ffffffff8154c533>]
snd_pcm_dev_disconnect+0x23/0x1f0

stack backtrace:
Pid: 446, comm: khubd Not tainted 3.7.0-rc5-next-20121112_64-ldep+ #15
Call Trace:
 [<ffffffff81691220>] print_circular_bug+0x1fb/0x20c
 [<ffffffff810c5968>] __lock_acquire+0x1c38/0x1c40
 [<ffffffff81546a6e>] ? snd_unregister_oss_device+0x9e/0x120
 [<ffffffff810c5e8a>] lock_acquire+0x5a/0x70
 [<ffffffff8154c555>] ? snd_pcm_dev_disconnect+0x45/0x1f0
 [<ffffffff81697fa9>] mutex_lock_nested+0x69/0x3a0
 [<ffffffff8154c555>] ? snd_pcm_dev_disconnect+0x45/0x1f0
 [<ffffffff8154c555>] snd_pcm_dev_disconnect+0x45/0x1f0
 [<ffffffff815462e2>] snd_device_disconnect+0x62/0xa0
 [<ffffffff815463bc>] snd_device_disconnect_all+0x3c/0x60
 [<ffffffff81540ec7>] snd_card_disconnect+0x147/0x1d0
 [<ffffffff8158c328>] usb_audio_disconnect+0x98/0x1d0
 [<ffffffff814aa4fe>] usb_unbind_interface+0x5e/0x1a0
 [<ffffffff81404ad7>] __device_release_driver+0x77/0xe0
 [<ffffffff81404d49>] device_release_driver+0x29/0x40
 [<ffffffff814044aa>] bus_remove_device+0xfa/0x170
 [<ffffffff81401917>] device_del+0x127/0x1c0
 [<ffffffff8149e9c1>] ? usb_disconnect+0x61/0x160
 [<ffffffff814a7f20>] usb_disable_device+0xb0/0x270
 [<ffffffff8149ea0d>] usb_disconnect+0xad/0x160
 [<ffffffff814a12bc>] hub_thread+0x71c/0x1730
 [<ffffffff810c689d>] ? trace_hardirqs_on_caller+0x10d/0x1e0
 [<ffffffff81096d70>] ? __init_waitqueue_head+0x60/0x60
 [<ffffffff814a0ba0>] ? usb_remote_wakeup+0x70/0x70
 [<ffffffff810967e6>] kthread+0xd6/0xe0
 [<ffffffff8169b65b>] ? _raw_spin_unlock_irq+0x2b/0x50
 [<ffffffff81096710>] ? kthread_create_on_node+0x140/0x140
 [<ffffffff8169c2ec>] ret_from_fork+0x7c/0xb0
 [<ffffffff81096710>] ? kthread_create_on_node+0x140/0x140



-- 
js
suse labs

Re: Sound+USB: deadlock problem

[Takashi Iwai]

At Tue, 13 Nov 2012 10:39:14 +0100,
Jiri Slaby wrote:
> 
> On 11/13/2012 09:45 AM, Takashi Iwai wrote:
> > At Tue, 13 Nov 2012 09:30:10 +0100,
> > Jiri Slaby wrote:
> >>
> >> On 11/13/2012 09:28 AM, Takashi Iwai wrote:
> >>> At Tue, 13 Nov 2012 09:26:17 +0100,
> >>> Jiri Slaby wrote:
> >>>>
> >>>> Hello,
> >>>>
> >>>> I've just plugged+unplugged+plugged my USB audio card and the audio
> >>>> subsystem got stuck:
> >>>
> >>> Which kernel?  If it's older than 3.7-rc5, could you try 3.7-rc5?
> >>
> >> Oh, forgot to mention:
> >> 3.7.0-rc5-next-20121112_64+
> > 
> > Through a quick glance, one of mutex locks seems stuck.
> > Just a blind short -- does the patch below cure the problem?
> 
> Yes, this helps.
> 
> Adding a LOCKDEP splash _before_ applying the patch:

Thanks, this helps much for understanding the cause.
It's a new rwsem in the usb-audio driver that deadlocks.

Although the previous patch fixes the deadlock it opens the race
again. 

Could you try the patch below instead?  The rwsem above doesn't have
to be taken for the whole operation, but just needs to protect for
turning on the flag.  The patch below should suffice for protecting
races but avoids the deadlock.


Takashi

---
diff --git a/sound/usb/card.c b/sound/usb/card.c
index 282f0fc..dbf7999 100644
--- a/sound/usb/card.c
+++ b/sound/usb/card.c
@@ -559,9 +559,11 @@ static void snd_usb_audio_disconnect(struct usb_device *dev,
 		return;
 
 	card = chip->card;
-	mutex_lock(&register_mutex);
 	down_write(&chip->shutdown_rwsem);
 	chip->shutdown = 1;
+	up_write(&chip->shutdown_rwsem);
+
+	mutex_lock(&register_mutex);
 	chip->num_interfaces--;
 	if (chip->num_interfaces <= 0) {
 		snd_card_disconnect(card);
@@ -582,11 +584,9 @@ static void snd_usb_audio_disconnect(struct usb_device *dev,
 			snd_usb_mixer_disconnect(p);
 		}
 		usb_chip[chip->index] = NULL;
-		up_write(&chip->shutdown_rwsem);
 		mutex_unlock(&register_mutex);
 		snd_card_free_when_closed(card);
 	} else {
-		up_write(&chip->shutdown_rwsem);
 		mutex_unlock(&register_mutex);
 	}
 }

Re : Re: Sound+USB: deadlock problem

[Matthieu CASTET]

A deadlock was detected with this patch. You need the following patch [1]


Matthieu


> 3.2-stable review patch.  If anyone has any objections, please let me know.
> 
> ------------------
> 
> From: Takashi Iwai <tiwai@suse.de>
> 
> commit 34f3c89fda4fba9fe689db22253ca8db2f5e6386 upstream.
> 
> Replace mutex with rwsem for codec->shutdown protection so that
> concurrent accesses are allowed.
> 
> Also add the protection to snd_usb_autosuspend() and
> snd_usb_autoresume(), too.
> 
> Reported-by: Matthieu CASTET <matthieu.castet@parrot.com>
> Signed-off-by: Takashi Iwai <tiwai@suse.de>
> Signed-off-by: Ben Hutchings <ben@decadent.org.uk>
> ---
>  sound/usb/card.c     | 12 ++++++++----
>  sound/usb/mixer.c    | 12 ++++++------
>  sound/usb/pcm.c      | 12 ++++++------
>  sound/usb/usbaudio.h |  2 +-
>  4 files changed, 21 insertions(+), 17 deletions(-)



[1]

Takashi Iwai a écrit :
> At Tue, 13 Nov 2012 10:39:14 +0100,
> Jiri Slaby wrote:
>> On 11/13/2012 09:45 AM, Takashi Iwai wrote:
>>> At Tue, 13 Nov 2012 09:30:10 +0100,
>>> Jiri Slaby wrote:
>>>> On 11/13/2012 09:28 AM, Takashi Iwai wrote:
>>>>> At Tue, 13 Nov 2012 09:26:17 +0100,
>>>>> Jiri Slaby wrote:
>>>>>> Hello,
>>>>>>
>>>>>> I've just plugged+unplugged+plugged my USB audio card and the audio
>>>>>> subsystem got stuck:
>>>>> Which kernel?  If it's older than 3.7-rc5, could you try 3.7-rc5?
>>>> Oh, forgot to mention:
>>>> 3.7.0-rc5-next-20121112_64+
>>> Through a quick glance, one of mutex locks seems stuck.
>>> Just a blind short -- does the patch below cure the problem?
>> Yes, this helps.
>>
>> Adding a LOCKDEP splash _before_ applying the patch:
> 
> Thanks, this helps much for understanding the cause.
> It's a new rwsem in the usb-audio driver that deadlocks.
> 
> Although the previous patch fixes the deadlock it opens the race
> again. 
> 
> Could you try the patch below instead?  The rwsem above doesn't have
> to be taken for the whole operation, but just needs to protect for
> turning on the flag.  The patch below should suffice for protecting
> races but avoids the deadlock.
> 
> 
> Takashi
> 
> ---
> diff --git a/sound/usb/card.c b/sound/usb/card.c
> index 282f0fc..dbf7999 100644
> --- a/sound/usb/card.c
> +++ b/sound/usb/card.c
> @@ -559,9 +559,11 @@ static void snd_usb_audio_disconnect(struct usb_device *dev,
>  		return;
>  
>  	card = chip->card;
> -	mutex_lock(&register_mutex);
>  	down_write(&chip->shutdown_rwsem);
>  	chip->shutdown = 1;
> +	up_write(&chip->shutdown_rwsem);
> +
> +	mutex_lock(&register_mutex);
>  	chip->num_interfaces--;
>  	if (chip->num_interfaces <= 0) {
>  		snd_card_disconnect(card);
> @@ -582,11 +584,9 @@ static void snd_usb_audio_disconnect(struct usb_device *dev,
>  			snd_usb_mixer_disconnect(p);
>  		}
>  		usb_chip[chip->index] = NULL;
> -		up_write(&chip->shutdown_rwsem);
>  		mutex_unlock(&register_mutex);
>  		snd_card_free_when_closed(card);
>  	} else {
> -		up_write(&chip->shutdown_rwsem);
>  		mutex_unlock(&register_mutex);
>  	}
>  }
> --
> To unsubscribe from this list: send the line "unsubscribe linux-usb" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 

Re: Re : Re: Sound+USB: deadlock problem

[Takashi Iwai]

At Wed, 14 Nov 2012 11:44:44 +0100,
Matthieu CASTET wrote:
> 
> A deadlock was detected with this patch. You need the following patch [1]

I'm going to send a pull request including this fix commit to Linus
tomorrow.


Takashi

> 
> 
> Matthieu
> 
> 
> > 3.2-stable review patch.  If anyone has any objections, please let me know.
> > 
> > ------------------
> > 
> > From: Takashi Iwai <tiwai@suse.de>
> > 
> > commit 34f3c89fda4fba9fe689db22253ca8db2f5e6386 upstream.
> > 
> > Replace mutex with rwsem for codec->shutdown protection so that
> > concurrent accesses are allowed.
> > 
> > Also add the protection to snd_usb_autosuspend() and
> > snd_usb_autoresume(), too.
> > 
> > Reported-by: Matthieu CASTET <matthieu.castet@parrot.com>
> > Signed-off-by: Takashi Iwai <tiwai@suse.de>
> > Signed-off-by: Ben Hutchings <ben@decadent.org.uk>
> > ---
> >  sound/usb/card.c     | 12 ++++++++----
> >  sound/usb/mixer.c    | 12 ++++++------
> >  sound/usb/pcm.c      | 12 ++++++------
> >  sound/usb/usbaudio.h |  2 +-
> >  4 files changed, 21 insertions(+), 17 deletions(-)
> 
> 
> 
> [1]
> 
> Takashi Iwai a écrit :
> > At Tue, 13 Nov 2012 10:39:14 +0100,
> > Jiri Slaby wrote:
> >> On 11/13/2012 09:45 AM, Takashi Iwai wrote:
> >>> At Tue, 13 Nov 2012 09:30:10 +0100,
> >>> Jiri Slaby wrote:
> >>>> On 11/13/2012 09:28 AM, Takashi Iwai wrote:
> >>>>> At Tue, 13 Nov 2012 09:26:17 +0100,
> >>>>> Jiri Slaby wrote:
> >>>>>> Hello,
> >>>>>>
> >>>>>> I've just plugged+unplugged+plugged my USB audio card and the audio
> >>>>>> subsystem got stuck:
> >>>>> Which kernel?  If it's older than 3.7-rc5, could you try 3.7-rc5?
> >>>> Oh, forgot to mention:
> >>>> 3.7.0-rc5-next-20121112_64+
> >>> Through a quick glance, one of mutex locks seems stuck.
> >>> Just a blind short -- does the patch below cure the problem?
> >> Yes, this helps.
> >>
> >> Adding a LOCKDEP splash _before_ applying the patch:
> > 
> > Thanks, this helps much for understanding the cause.
> > It's a new rwsem in the usb-audio driver that deadlocks.
> > 
> > Although the previous patch fixes the deadlock it opens the race
> > again. 
> > 
> > Could you try the patch below instead?  The rwsem above doesn't have
> > to be taken for the whole operation, but just needs to protect for
> > turning on the flag.  The patch below should suffice for protecting
> > races but avoids the deadlock.
> > 
> > 
> > Takashi
> > 
> > ---
> > diff --git a/sound/usb/card.c b/sound/usb/card.c
> > index 282f0fc..dbf7999 100644
> > --- a/sound/usb/card.c
> > +++ b/sound/usb/card.c
> > @@ -559,9 +559,11 @@ static void snd_usb_audio_disconnect(struct usb_device *dev,
> >  		return;
> >  
> >  	card = chip->card;
> > -	mutex_lock(&register_mutex);
> >  	down_write(&chip->shutdown_rwsem);
> >  	chip->shutdown = 1;
> > +	up_write(&chip->shutdown_rwsem);
> > +
> > +	mutex_lock(&register_mutex);
> >  	chip->num_interfaces--;
> >  	if (chip->num_interfaces <= 0) {
> >  		snd_card_disconnect(card);
> > @@ -582,11 +584,9 @@ static void snd_usb_audio_disconnect(struct usb_device *dev,
> >  			snd_usb_mixer_disconnect(p);
> >  		}
> >  		usb_chip[chip->index] = NULL;
> > -		up_write(&chip->shutdown_rwsem);
> >  		mutex_unlock(&register_mutex);
> >  		snd_card_free_when_closed(card);
> >  	} else {
> > -		up_write(&chip->shutdown_rwsem);
> >  		mutex_unlock(&register_mutex);
> >  	}
> >  }
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-usb" in
> > the body of a message to majordomo@vger.kernel.org
> > More majordomo info at  http://vger.kernel.org/majordomo-info.html
> > 
> 

Re: Re : Re: Sound+USB: deadlock problem

[Ben Hutchings]

[-- Attachment #1: Type: text/plain, Size: 453 bytes --]

On Wed, 2012-11-14 at 15:59 +0100, Takashi Iwai wrote:
> At Wed, 14 Nov 2012 11:44:44 +0100,
> Matthieu CASTET wrote:
> > 
> > A deadlock was detected with this patch. You need the following patch [1]
> 
> I'm going to send a pull request including this fix commit to Linus
> tomorrow.

Since this is now upstream, I've added it to the queue.  Thanks all.

Ben.

-- 
Ben Hutchings
friends: People who know you well, but like you anyway.

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 828 bytes --]