[alsa-devel] 3.18.0-rc1 pulseaudio possible recursive locking
Hi, I have been seeing this a few times lately, and noticed that it was still present
Is this the right place to report it or should I be reporting a bug against pulseaudio?
[ 182.273991] ============================================= [ 182.273996] [ INFO: possible recursive locking detected ] [ 182.274003] 3.18.0-rc1 #1297 Not tainted [ 182.274008] --------------------------------------------- [ 182.274013] pulseaudio/5183 is trying to acquire lock: [ 182.274018] (&(&substream->self_group.lock)->rlock/1){......}, at: [<f8432284>] snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274063] but task is already holding lock: [ 182.274069] (&(&substream->self_group.lock)->rlock/1){......}, at: [<f8432284>] snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274092] other info that might help us debug this: [ 182.274098] Possible unsafe locking scenario:
[ 182.274104] CPU0 [ 182.274108] ---- [ 182.274112] lock(&(&substream->self_group.lock)->rlock/1); [ 182.274122] lock(&(&substream->self_group.lock)->rlock/1); [ 182.274132] *** DEADLOCK ***
[ 182.274138] May be due to missing lock nesting notation
[ 182.274146] 4 locks held by pulseaudio/5183: [ 182.274151] #0: (snd_pcm_link_rwlock){......}, at: [<f8432fe3>] snd_pcm_stream_lock+0x1b/0x43 [snd_pcm] [ 182.274177] #1: (&(&substream->self_group.lock)->rlock){......}, at: [<f8432fee>] snd_pcm_stream_lock+0x26/0x43 [snd_pcm] [ 182.274202] #2: (&(&substream->group->lock)->rlock){......}, at: [<f8432cf4>] snd_pcm_action+0x34/0x10b [snd_pcm] [ 182.274227] #3: (&(&substream->self_group.lock)->rlock/1){......}, at: [<f8432284>] snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274254] stack backtrace: [ 182.274263] CPU: 1 PID: 5183 Comm: pulseaudio Not tainted 3.18.0-rc1 #1297 [ 182.274269] Hardware name: System Manufacturer System Name/P4S800, BIOS ASUS P4S800 ACPI BIOS Revision 1011 Beta 001 08/30/2005 [ 182.274275] c1bfc4e0 00000000 e55c9d50 c145d969 c1bfc4e0 e55c9dd4 c1082b7b c15b7f9a [ 182.274295] e55b630c 0000143f 00000000 e55b6010 e55b6070 00000000 5402a095 00000004 [ 182.274315] c17a4034 c1bfc4e0 e55b6508 e55b6520 00000000 00000008 00000000 e55b6508 [ 182.274335] Call Trace: [ 182.274353] [<c145d969>] dump_stack+0x4b/0x75 [ 182.274366] [<c1082b7b>] __lock_acquire+0x187c/0x19b3 [ 182.274378] [<c10834ad>] lock_acquire+0xa1/0x126 [ 182.274394] [<f8432284>] ? snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274404] [<c1463a9d>] _raw_spin_lock_nested+0x41/0x4e [ 182.274420] [<f8432284>] ? snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274436] [<f8432284>] snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274445] [<c146393b>] ? _raw_spin_trylock+0x6b/0x80 [ 182.274462] [<f8432d0f>] snd_pcm_action+0x4f/0x10b [snd_pcm] [ 182.274479] [<f843332a>] snd_pcm_drop+0x4a/0x7d [snd_pcm] [ 182.274496] [<f84351d9>] snd_pcm_common_ioctl1+0x7b0/0xcc4 [snd_pcm] [ 182.274514] [<f84357ce>] snd_pcm_playback_ioctl1+0xe1/0x3a8 [snd_pcm] [ 182.274532] [<f8435ab7>] snd_pcm_playback_ioctl+0x22/0x35 [snd_pcm] [ 182.274549] [<f8435a95>] ? snd_pcm_playback_ioctl1+0x3a8/0x3a8 [snd_pcm] [ 182.274561] [<c1171e82>] do_vfs_ioctl+0x306/0x576 [ 182.274573] [<c117d3ca>] ? mntput_no_expire+0x61/0x1e7 [ 182.274583] [<c117d377>] ? mntput_no_expire+0xe/0x1e7 [ 182.274594] [<c117d56b>] ? mntput+0x1b/0x29 [ 182.274603] [<c1161438>] ? __fput+0x144/0x1aa [ 182.274614] [<c1172147>] SyS_ioctl+0x55/0x75 [ 182.274624] [<c14646e0>] sysenter_do_call+0x12/0x12
Regards,
Arthur.
At Tue, 21 Oct 2014 00:30:59 +1030, Arthur Marsh wrote:
Hi, I have been seeing this a few times lately, and noticed that it was still present
Is this the right place to report it or should I be reporting a bug against pulseaudio?
This is likely a false-positive report, so ignore it unless you really encounter the deadlock by this.
Takashi
[ 182.273991] ============================================= [ 182.273996] [ INFO: possible recursive locking detected ] [ 182.274003] 3.18.0-rc1 #1297 Not tainted [ 182.274008] --------------------------------------------- [ 182.274013] pulseaudio/5183 is trying to acquire lock: [ 182.274018] (&(&substream->self_group.lock)->rlock/1){......}, at: [<f8432284>] snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274063] but task is already holding lock: [ 182.274069] (&(&substream->self_group.lock)->rlock/1){......}, at: [<f8432284>] snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274092] other info that might help us debug this: [ 182.274098] Possible unsafe locking scenario:
[ 182.274104] CPU0 [ 182.274108] ---- [ 182.274112] lock(&(&substream->self_group.lock)->rlock/1); [ 182.274122] lock(&(&substream->self_group.lock)->rlock/1); [ 182.274132] *** DEADLOCK ***
[ 182.274138] May be due to missing lock nesting notation
[ 182.274146] 4 locks held by pulseaudio/5183: [ 182.274151] #0: (snd_pcm_link_rwlock){......}, at: [<f8432fe3>] snd_pcm_stream_lock+0x1b/0x43 [snd_pcm] [ 182.274177] #1: (&(&substream->self_group.lock)->rlock){......}, at: [<f8432fee>] snd_pcm_stream_lock+0x26/0x43 [snd_pcm] [ 182.274202] #2: (&(&substream->group->lock)->rlock){......}, at: [<f8432cf4>] snd_pcm_action+0x34/0x10b [snd_pcm] [ 182.274227] #3: (&(&substream->self_group.lock)->rlock/1){......}, at: [<f8432284>] snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274254] stack backtrace: [ 182.274263] CPU: 1 PID: 5183 Comm: pulseaudio Not tainted 3.18.0-rc1 #1297 [ 182.274269] Hardware name: System Manufacturer System Name/P4S800, BIOS ASUS P4S800 ACPI BIOS Revision 1011 Beta 001 08/30/2005 [ 182.274275] c1bfc4e0 00000000 e55c9d50 c145d969 c1bfc4e0 e55c9dd4 c1082b7b c15b7f9a [ 182.274295] e55b630c 0000143f 00000000 e55b6010 e55b6070 00000000 5402a095 00000004 [ 182.274315] c17a4034 c1bfc4e0 e55b6508 e55b6520 00000000 00000008 00000000 e55b6508 [ 182.274335] Call Trace: [ 182.274353] [<c145d969>] dump_stack+0x4b/0x75 [ 182.274366] [<c1082b7b>] __lock_acquire+0x187c/0x19b3 [ 182.274378] [<c10834ad>] lock_acquire+0xa1/0x126 [ 182.274394] [<f8432284>] ? snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274404] [<c1463a9d>] _raw_spin_lock_nested+0x41/0x4e [ 182.274420] [<f8432284>] ? snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274436] [<f8432284>] snd_pcm_action_group+0x96/0x215 [snd_pcm] [ 182.274445] [<c146393b>] ? _raw_spin_trylock+0x6b/0x80 [ 182.274462] [<f8432d0f>] snd_pcm_action+0x4f/0x10b [snd_pcm] [ 182.274479] [<f843332a>] snd_pcm_drop+0x4a/0x7d [snd_pcm] [ 182.274496] [<f84351d9>] snd_pcm_common_ioctl1+0x7b0/0xcc4 [snd_pcm] [ 182.274514] [<f84357ce>] snd_pcm_playback_ioctl1+0xe1/0x3a8 [snd_pcm] [ 182.274532] [<f8435ab7>] snd_pcm_playback_ioctl+0x22/0x35 [snd_pcm] [ 182.274549] [<f8435a95>] ? snd_pcm_playback_ioctl1+0x3a8/0x3a8 [snd_pcm] [ 182.274561] [<c1171e82>] do_vfs_ioctl+0x306/0x576 [ 182.274573] [<c117d3ca>] ? mntput_no_expire+0x61/0x1e7 [ 182.274583] [<c117d377>] ? mntput_no_expire+0xe/0x1e7 [ 182.274594] [<c117d56b>] ? mntput+0x1b/0x29 [ 182.274603] [<c1161438>] ? __fput+0x144/0x1aa [ 182.274614] [<c1172147>] SyS_ioctl+0x55/0x75 [ 182.274624] [<c14646e0>] sysenter_do_call+0x12/0x12
Regards,
Arthur. _______________________________________________ Alsa-devel mailing list Alsa-devel@alsa-project.org http://mailman.alsa-project.org/mailman/listinfo/alsa-devel
At Tue, 21 Oct 2014 07:27:34 +0200, Takashi Iwai wrote:
At Tue, 21 Oct 2014 00:30:59 +1030, Arthur Marsh wrote:
Hi, I have been seeing this a few times lately, and noticed that it was still present
Is this the right place to report it or should I be reporting a bug against pulseaudio?
This is likely a false-positive report, so ignore it unless you really encounter the deadlock by this.
Or try the patch below. This seems hitting more often, so it's maybe worth to put into 3.18-rc2. Let me know if this solves the problem.
Takashi
-- 8< -- From: Takashi Iwai tiwai@suse.de Subject: [PATCH] ALSA: pcm: Fix false lockdep warnings
As PCM core handles the multiple linked streams in parallel, lockdep gets confused (partly because of weak annotations) and spews the false-positive warnings. This hasn't been a problem for long time but the latest PCM lock path update seems to have woken up a sleeping dog.
Here is an attempt to paper over this issue: pass the lock subclass just calculated from the depth in snd_pcm_action_group(). Also, a (possibly) wrong lock subclass set in snd_pcm_action_lock_mutex() is dropped, too.
Signed-off-by: Takashi Iwai tiwai@suse.de --- sound/core/pcm_native.c | 12 +++++------- 1 file changed, 5 insertions(+), 7 deletions(-)
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c index 815396d8427f..166d59cdc86b 100644 --- a/sound/core/pcm_native.c +++ b/sound/core/pcm_native.c @@ -781,16 +781,15 @@ static int snd_pcm_action_group(struct action_ops *ops, { struct snd_pcm_substream *s = NULL; struct snd_pcm_substream *s1; - int res = 0; + int res = 0, depth = 1;
snd_pcm_group_for_each_entry(s, substream) { if (do_lock && s != substream) { if (s->pcm->nonatomic) - mutex_lock_nested(&s->self_group.mutex, - SINGLE_DEPTH_NESTING); + mutex_lock_nested(&s->self_group.mutex, depth); else - spin_lock_nested(&s->self_group.lock, - SINGLE_DEPTH_NESTING); + spin_lock_nested(&s->self_group.lock, depth); + depth++; } res = ops->pre_action(s, state); if (res < 0) @@ -906,8 +905,7 @@ static int snd_pcm_action_lock_mutex(struct action_ops *ops, down_read(&snd_pcm_link_rwsem); if (snd_pcm_stream_linked(substream)) { mutex_lock(&substream->group->mutex); - mutex_lock_nested(&substream->self_group.mutex, - SINGLE_DEPTH_NESTING); + mutex_lock(&substream->self_group.mutex); res = snd_pcm_action_group(ops, substream, state, 1); mutex_unlock(&substream->self_group.mutex); mutex_unlock(&substream->group->mutex);
Takashi Iwai wrote, on 22/10/14 00:08:
At Tue, 21 Oct 2014 07:27:34 +0200, Takashi Iwai wrote:
At Tue, 21 Oct 2014 00:30:59 +1030, Arthur Marsh wrote:
Hi, I have been seeing this a few times lately, and noticed that it was still present
Is this the right place to report it or should I be reporting a bug against pulseaudio?
This is likely a false-positive report, so ignore it unless you really encounter the deadlock by this.
Or try the patch below. This seems hitting more often, so it's maybe worth to put into 3.18-rc2. Let me know if this solves the problem.
Takashi
-- 8< -- From: Takashi Iwai tiwai@suse.de Subject: [PATCH] ALSA: pcm: Fix false lockdep warnings
As PCM core handles the multiple linked streams in parallel, lockdep gets confused (partly because of weak annotations) and spews the false-positive warnings. This hasn't been a problem for long time but the latest PCM lock path update seems to have woken up a sleeping dog.
Here is an attempt to paper over this issue: pass the lock subclass just calculated from the depth in snd_pcm_action_group(). Also, a (possibly) wrong lock subclass set in snd_pcm_action_lock_mutex() is dropped, too.
Signed-off-by: Takashi Iwai tiwai@suse.de
sound/core/pcm_native.c | 12 +++++------- 1 file changed, 5 insertions(+), 7 deletions(-)
diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c index 815396d8427f..166d59cdc86b 100644 --- a/sound/core/pcm_native.c +++ b/sound/core/pcm_native.c @@ -781,16 +781,15 @@ static int snd_pcm_action_group(struct action_ops *ops, { struct snd_pcm_substream *s = NULL; struct snd_pcm_substream *s1;
- int res = 0;
int res = 0, depth = 1;
snd_pcm_group_for_each_entry(s, substream) { if (do_lock && s != substream) { if (s->pcm->nonatomic)
mutex_lock_nested(&s->self_group.mutex,
SINGLE_DEPTH_NESTING);
mutex_lock_nested(&s->self_group.mutex, depth); else
spin_lock_nested(&s->self_group.lock,
SINGLE_DEPTH_NESTING);
spin_lock_nested(&s->self_group.lock, depth);
} res = ops->pre_action(s, state); if (res < 0)depth++;
@@ -906,8 +905,7 @@ static int snd_pcm_action_lock_mutex(struct action_ops *ops, down_read(&snd_pcm_link_rwsem); if (snd_pcm_stream_linked(substream)) { mutex_lock(&substream->group->mutex);
mutex_lock_nested(&substream->self_group.mutex,
SINGLE_DEPTH_NESTING);
res = snd_pcm_action_group(ops, substream, state, 1); mutex_unlock(&substream->self_group.mutex); mutex_unlock(&substream->group->mutex);mutex_lock(&substream->self_group.mutex);
Hi, I applied this patch, rebuilt the kernel and am running it now and have not seen the "pulseaudio possible recursive locking" message yet.
For the previous 4 reboots with earlier kernels 3.17.0+ / 3.18.0-rc1 I saw the "pulseaudio possible recursive locking" message appear about 5 minutes after boot-up.
Thanks for your help!
Arthur.
participants (2)
-
Arthur Marsh
-
Takashi Iwai