[PATCH] ASoC: soc-pcm: Fix DPCM lockdep warning due to nested stream locks

Marek Szyprowski m.szyprowski at samsung.com
Thu Jan 13 15:59:31 CET 2022


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 at redhat.com>
> Reported-by: Marek Szyprowski <m.szyprowski at samsung.com>
> Link: https://lore.kernel.org/r/73018f3c-9769-72ea-0325-b3f8e2381e30@redhat.com
> Link: https://lore.kernel.org/alsa-devel/9a0abddd-49e9-872d-2f00-a1697340f786@samsung.com
> Signed-off-by: Takashi Iwai <tiwai at suse.de>

Thanks for the fix! It helps a bit, but I still get a warning (a 
different one now):

root at 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



More information about the Alsa-devel mailing list