On 13.01.2022 15:18, Takashi Iwai wrote:
> The recent change for DPCM locking caused spurious lockdep warnings.
> Actually the warnings are false-positive, as those are triggered due
> to the nested stream locks for FE and BE. Since both locks belong to
> the same lock class, lockdep sees it as if a deadlock.
>
> For fixing this, we need take PCM stream locks for BE with the nested
> lock primitives. Since currently snd_pcm_stream_lock*() helper
> assumes only the top-level single locking, a new helper function
> snd_pcm_stream_lock_irqsave_nested() is defined for a single-depth
> nested lock, which is now used in the BE DAI trigger that is always
> performed inside a FE stream lock.
>
> Fixes: b7898396f4bb ("ASoC: soc-pcm: Fix and cleanup DPCM locking")
> Reported-and-tested-by: Hans de Goede <hdegoede@xxxxxxxxxx>
> Reported-by: Marek Szyprowski <m.szyprowski@xxxxxxxxxxx>
> Link: https://lore.kernel.org/r/73018f3c-9769-72ea-0325-b3f8e2381e30@xxxxxxxxxx
> Link: https://lore.kernel.org/alsa-devel/9a0abddd-49e9-872d-2f00-a1697340f786@xxxxxxxxxxx
> Signed-off-by: Takashi Iwai <tiwai@xxxxxxx>
Thanks for the fix! It helps a bit, but I still get a warning (a
different one now):
root@target:~# speaker-test -l1
speaker-test 1.1.8
Playback device is default
Stream parameters are 48000Hz, S16_LE, 1 channels
Using 16 octaves of pink noise
Rate set to 48000Hz (requested 48000Hz)
Buffer size range from 128 to 131072
Period size range from 64 to 65536
Using max buffer size 131072
Periods = 4
was set period_size = 32768
was set buffer_size = 131072
0 - Front Left
Time per period = 0.022199
max98090 1-0010: PLL unlocked
=====================================================
WARNING: SOFTIRQ-safe -> SOFTIRQ-unsafe lock order detected
5.16.0-next-20220113-00001-g3967460dbcf4 #11212 Not tainted
-----------------------------------------------------
speaker-test/1319 [HC0[0]:SC0[0]:HE0:SE1] is trying to acquire:
c1296410 (pin_fs_lock){+.+.}-{2:2}, at: simple_pin_fs+0x1c/0xac
and this task is already holding:
c2fe6ea4 (&group->lock){..-.}-{2:2}, at: dpcm_be_disconnect+0x3c/0x348
which would create a new lock dependency:
(&group->lock){..-.}-{2:2} -> (pin_fs_lock){+.+.}-{2:2}
but this new dependency connects a SOFTIRQ-irq-safe lock:
(&group->lock){..-.}-{2:2}
... which became SOFTIRQ-irq-safe at:
_raw_spin_lock_irqsave+0x4c/0x60
snd_pcm_period_elapsed+0x10/0x2c
pl330_tasklet+0x9dc/0xaa4
tasklet_action_common.constprop.6+0x74/0xfc
__do_softirq+0x140/0x5ec
irq_exit+0x1cc/0x200
__irq_svc+0x54/0x88
arch_cpu_idle+0x40/0x44
arch_cpu_idle+0x40/0x44
default_idle_call+0x74/0x2c4
do_idle+0x1cc/0x284
cpu_startup_entry+0x18/0x1c
start_kernel+0x678/0x6bc
to a SOFTIRQ-irq-unsafe lock:
(pin_fs_lock){+.+.}-{2:2}
... which became SOFTIRQ-irq-unsafe at:
...
_raw_spin_lock+0x38/0x48
simple_pin_fs+0x1c/0xac
start_creating+0x6c/0x170
debugfs_create_dir+0x10/0x10c
pinctrl_init+0x2c/0xd4
do_one_initcall+0x6c/0x3a4
kernel_init_freeable+0x1c4/0x214
kernel_init+0x18/0x12c
ret_from_fork+0x14/0x2c
0x0
other info that might help us debug this:
Possible interrupt unsafe locking scenario:
CPU0 CPU1
---- ----
lock(pin_fs_lock);
local_irq_disable();
lock(&group->lock);
lock(pin_fs_lock);
<Interrupt>
lock(&group->lock);
*** DEADLOCK ***
3 locks held by speaker-test/1319:
#0: c2fcbef0 (&pcm->open_mutex){+.+.}-{3:3}, at: snd_pcm_release+0x38/0xa8
#1: c1fcb94c (&card->pcm_mutex){+.+.}-{3:3}, at:
dpcm_fe_dai_close+0x1c/0x120
#2: c2fe6ea4 (&group->lock){..-.}-{2:2}, at: dpcm_be_disconnect+0x3c/0x348
the dependencies between SOFTIRQ-irq-safe lock and the holding lock:
-> (&group->lock){..-.}-{2:2} {
IN-SOFTIRQ-W at:
_raw_spin_lock_irqsave+0x4c/0x60
snd_pcm_period_elapsed+0x10/0x2c
pl330_tasklet+0x9dc/0xaa4
tasklet_action_common.constprop.6+0x74/0xfc
__do_softirq+0x140/0x5ec
irq_exit+0x1cc/0x200
__irq_svc+0x54/0x88
arch_cpu_idle+0x40/0x44
arch_cpu_idle+0x40/0x44
default_idle_call+0x74/0x2c4
do_idle+0x1cc/0x284
cpu_startup_entry+0x18/0x1c
start_kernel+0x678/0x6bc
INITIAL USE at:
_raw_spin_lock_irq+0x4c/0x5c
dpcm_add_paths+0x260/0x4bc
dpcm_fe_dai_open+0x70/0x788
snd_pcm_open_substream+0x600/0x8f8
snd_pcm_open+0xa4/0x238
snd_pcm_playback_open+0x3c/0x60
chrdev_open+0xb0/0x1ac
do_dentry_open+0x244/0x3e4
path_openat+0x9f8/0xcbc
do_filp_open+0x78/0xe4
do_sys_openat2+0x28c/0x3d8
do_sys_open+0x8c/0xa8
ret_fast_syscall+0x0/0x1c
0xbefef3e0
}
... key at: [<c19c5f60>] __key.42687+0x0/0x8
the dependencies between the lock to be acquired
and SOFTIRQ-irq-unsafe lock:
-> (pin_fs_lock){+.+.}-{2:2} {
HARDIRQ-ON-W at:
_raw_spin_lock+0x38/0x48
simple_pin_fs+0x1c/0xac
start_creating+0x6c/0x170
debugfs_create_dir+0x10/0x10c
pinctrl_init+0x2c/0xd4
do_one_initcall+0x6c/0x3a4
kernel_init_freeable+0x1c4/0x214
kernel_init+0x18/0x12c
ret_from_fork+0x14/0x2c
0x0
SOFTIRQ-ON-W at:
_raw_spin_lock+0x38/0x48
simple_pin_fs+0x1c/0xac
start_creating+0x6c/0x170
debugfs_create_dir+0x10/0x10c
pinctrl_init+0x2c/0xd4
do_one_initcall+0x6c/0x3a4
kernel_init_freeable+0x1c4/0x214
kernel_init+0x18/0x12c
ret_from_fork+0x14/0x2c
0x0
INITIAL USE at:
_raw_spin_lock+0x38/0x48
simple_pin_fs+0x1c/0xac
start_creating+0x6c/0x170
debugfs_create_dir+0x10/0x10c
pinctrl_init+0x2c/0xd4
do_one_initcall+0x6c/0x3a4
kernel_init_freeable+0x1c4/0x214
kernel_init+0x18/0x12c
ret_from_fork+0x14/0x2c
0x0
}
... key at: [<c1296410>] pin_fs_lock+0x10/0x24
... acquired at:
simple_pin_fs+0x1c/0xac
debugfs_remove+0x28/0x4c
dpcm_be_disconnect+0x164/0x348
dpcm_fe_dai_cleanup+0x68/0xac
dpcm_fe_dai_close+0xbc/0x120
snd_pcm_release_substream.part.14+0x3c/0x9c
snd_pcm_release+0x9c/0xa8
__fput+0x88/0x258
task_work_run+0x8c/0xc8
do_work_pending+0x534/0x63c
slow_work_pending+0xc/0x20
0xb6d68ac0
stack backtrace:
CPU: 3 PID: 1319 Comm: speaker-test Not tainted
5.16.0-next-20220113-00001-g3967460dbcf4 #11212
Hardware name: Samsung Exynos (Flattened Device Tree)
unwind_backtrace from show_stack+0x10/0x14
show_stack from dump_stack_lvl+0x58/0x70
dump_stack_lvl from __lock_acquire+0x2fe4/0x3188
__lock_acquire from lock_acquire+0x2a0/0x42c
lock_acquire from _raw_spin_lock+0x38/0x48
_raw_spin_lock from simple_pin_fs+0x1c/0xac
simple_pin_fs from debugfs_remove+0x28/0x4c
debugfs_remove from dpcm_be_disconnect+0x164/0x348
dpcm_be_disconnect from dpcm_fe_dai_cleanup+0x68/0xac
dpcm_fe_dai_cleanup from dpcm_fe_dai_close+0xbc/0x120
dpcm_fe_dai_close from snd_pcm_release_substream.part.14+0x3c/0x9c
snd_pcm_release_substream.part.14 from snd_pcm_release+0x9c/0xa8
snd_pcm_release from __fput+0x88/0x258
__fput from task_work_run+0x8c/0xc8
task_work_run from do_work_pending+0x534/0x63c
do_work_pending from slow_work_pending+0xc/0x20
Exception stack(0xc2fe3fb0 to 0xc2fe3ff8)
3fa0: 00000000 00495260 0048aa9c
00000000
3fc0: 00495260 0049536c 00495210 00000006 0049b700 00486e8c 00476120
befefcc4
3fe0: b6e86e64 befef928 b6dedda4 b6d68ac0 60000050 00000004
BUG: sleeping function called from invalid context at
kernel/locking/rwsem.c:1513
in_atomic(): 1, irqs_disabled(): 128, non_block: 0, pid: 1319, name:
speaker-test
preempt_count: 1, expected: 0
RCU nest depth: 0, expected: 0
INFO: lockdep is turned off.
irq event stamp: 8596
hardirqs last enabled at (8595): [<c0b8b238>]
_raw_spin_unlock_irq+0x20/0x50
hardirqs last disabled at (8596): [<c0b8af94>] _raw_spin_lock_irq+0x24/0x5c
softirqs last enabled at (8392): [<c01016fc>] __do_softirq+0x4cc/0x5ec
softirqs last disabled at (8387): [<c012fe0c>] irq_exit+0x1cc/0x200
Preemption disabled at:
[<00000000>] 0x0
CPU: 3 PID: 1319 Comm: speaker-test Not tainted
5.16.0-next-20220113-00001-g3967460dbcf4 #11212
Hardware name: Samsung Exynos (Flattened Device Tree)
unwind_backtrace from show_stack+0x10/0x14
show_stack from dump_stack_lvl+0x58/0x70
dump_stack_lvl from __might_resched+0x248/0x298
__might_resched from down_write+0x24/0x90
down_write from simple_recursive_removal+0xb4/0x35c
simple_recursive_removal from debugfs_remove+0x38/0x4c
debugfs_remove from dpcm_be_disconnect+0x164/0x348
dpcm_be_disconnect from dpcm_fe_dai_cleanup+0x68/0xac
dpcm_fe_dai_cleanup from dpcm_fe_dai_close+0xbc/0x120
dpcm_fe_dai_close from snd_pcm_release_substream.part.14+0x3c/0x9c
snd_pcm_release_substream.part.14 from snd_pcm_release+0x9c/0xa8
snd_pcm_release from __fput+0x88/0x258
__fput from task_work_run+0x8c/0xc8
task_work_run from do_work_pending+0x534/0x63c
do_work_pending from slow_work_pending+0xc/0x20
Exception stack(0xc2fe3fb0 to 0xc2fe3ff8)
3fa0: 00000000 00495260 0048aa9c
00000000
3fc0: 00495260 0049536c 00495210 00000006 0049b700 00486e8c 00476120
befefcc4
3fe0: b6e86e64 befef928 b6dedda4 b6d68ac0 60000050 00000004
> ---
> include/sound/pcm.h | 15 +++++++++++++++
> sound/core/pcm_native.c | 13 +++++++++++++
> sound/soc/soc-pcm.c | 6 +++---
> 3 files changed, 31 insertions(+), 3 deletions(-)
>
> diff --git a/include/sound/pcm.h b/include/sound/pcm.h
> index 9b187d86e1bd..36da42cd0774 100644
> --- a/include/sound/pcm.h
> +++ b/include/sound/pcm.h
> @@ -617,6 +617,7 @@ void snd_pcm_stream_unlock(struct snd_pcm_substream *substream);
> void snd_pcm_stream_lock_irq(struct snd_pcm_substream *substream);
> void snd_pcm_stream_unlock_irq(struct snd_pcm_substream *substream);
> unsigned long _snd_pcm_stream_lock_irqsave(struct snd_pcm_substream *substream);
> +unsigned long _snd_pcm_stream_lock_irqsave_nested(struct snd_pcm_substream *substream);
>
> /**
> * snd_pcm_stream_lock_irqsave - Lock the PCM stream
> @@ -635,6 +636,20 @@ unsigned long _snd_pcm_stream_lock_irqsave(struct snd_pcm_substream *substream);
> void snd_pcm_stream_unlock_irqrestore(struct snd_pcm_substream *substream,
> unsigned long flags);
>
> +/**
> + * snd_pcm_stream_lock_irqsave_nested - Single-nested PCM stream locking
> + * @substream: PCM substream
> + * @flags: irq flags
> + *
> + * This locks the PCM stream like snd_pcm_stream_lock_irqsave() but with
> + * the single-depth lockdep subclass.
> + */
> +#define snd_pcm_stream_lock_irqsave_nested(substream, flags) \
> + do { \
> + typecheck(unsigned long, flags); \
> + flags = _snd_pcm_stream_lock_irqsave_nested(substream); \
> + } while (0)
> +
> /**
> * snd_pcm_group_for_each_entry - iterate over the linked substreams
> * @s: the iterator
> diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
> index 621883e71194..a056b3ef3c84 100644
> --- a/sound/core/pcm_native.c
> +++ b/sound/core/pcm_native.c
> @@ -172,6 +172,19 @@ unsigned long _snd_pcm_stream_lock_irqsave(struct snd_pcm_substream *substream)
> }
> EXPORT_SYMBOL_GPL(_snd_pcm_stream_lock_irqsave);
>
> +unsigned long _snd_pcm_stream_lock_irqsave_nested(struct snd_pcm_substream *substream)
> +{
> + unsigned long flags = 0;
> + if (substream->pcm->nonatomic)
> + mutex_lock_nested(&substream->self_group.mutex,
> + SINGLE_DEPTH_NESTING);
> + else
> + spin_lock_irqsave_nested(&substream->self_group.lock, flags,
> + SINGLE_DEPTH_NESTING);
> + return flags;
> +}
> +EXPORT_SYMBOL_GPL(_snd_pcm_stream_lock_irqsave_nested);
> +
> /**
> * snd_pcm_stream_unlock_irqrestore - Unlock the PCM stream
> * @substream: PCM substream
> diff --git a/sound/soc/soc-pcm.c b/sound/soc/soc-pcm.c
> index 7abfc48b26ca..e8876e65c649 100644
> --- a/sound/soc/soc-pcm.c
> +++ b/sound/soc/soc-pcm.c
> @@ -46,8 +46,8 @@ static inline void snd_soc_dpcm_stream_lock_irq(struct snd_soc_pcm_runtime *rtd,
> snd_pcm_stream_lock_irq(snd_soc_dpcm_get_substream(rtd, stream));
> }
>
> -#define snd_soc_dpcm_stream_lock_irqsave(rtd, stream, flags) \
> - snd_pcm_stream_lock_irqsave(snd_soc_dpcm_get_substream(rtd, stream), flags)
> +#define snd_soc_dpcm_stream_lock_irqsave_nested(rtd, stream, flags) \
> + snd_pcm_stream_lock_irqsave_nested(snd_soc_dpcm_get_substream(rtd, stream), flags)
>
> static inline void snd_soc_dpcm_stream_unlock_irq(struct snd_soc_pcm_runtime *rtd,
> int stream)
> @@ -2094,7 +2094,7 @@ int dpcm_be_dai_trigger(struct snd_soc_pcm_runtime *fe, int stream,
> be = dpcm->be;
> be_substream = snd_soc_dpcm_get_substream(be, stream);
>
> - snd_soc_dpcm_stream_lock_irqsave(be, stream, flags);
> + snd_soc_dpcm_stream_lock_irqsave_nested(be, stream, flags);
>
> /* is this op for this BE ? */
> if (!snd_soc_dpcm_be_can_update(fe, be, stream))
Best regards
--
Marek Szyprowski, PhD
Samsung R&D Institute Poland
