Re: /dev/soiund/pcm/dsp.c: uma_zalloc with non-sleepable lock held

On Mon, May 26, 2008 at 03:55:14PM +0800, Ariff Abdullah wrote:
> On Sun, 25 May 2008 23:29:45 -0700
> Xin LI <delphij_at_delphij.net> wrote:
> > -----BEGIN PGP SIGNED MESSAGE-----
> > Hash: SHA1
> > 
> > Hi,
> > 
> > Hit this with WITNESS (today's -CURRENT).  It seems that if I play
> > music and have some other sound playing then the system would stop
> > to respond. ~ Is this an known issue?
> > 
> > May 25 23:26:50 charlie kernel: uma_zalloc_arg: zone "16" with the
> > following non-sleepable locks held:
> > May 25 23:26:50 charlie kernel: exclusive sleep mutex pcm0 (sound
> > cdev) r = 0 (0xffffff00019a9c20) locked _at_
> > /data/src/sys/modules/sound/sound/../../../dev/sound/pcm/dsp.c:650
> > May 25 23:26:50 charlie kernel: KDB: stack backtrace:
> > May 25 23:26:50 charlie kernel: db_trace_self_wrapper() at
> > db_trace_self_wrapper+0x2a
> > May 25 23:26:50 charlie kernel: witness_warn() at witness_warn+0x248
> > May 25 23:26:50 charlie kernel: uma_zalloc_arg() at
> > uma_zalloc_arg+0x334 May 25 23:26:50 charlie kernel: malloc() at
> > malloc+0x8a May 25 23:26:50 charlie kernel: notify() at notify+0x67
> > May 25 23:26:50 charlie kernel: destroy_devl() at destroy_devl+0x23b
> > May 25 23:26:50 charlie kernel: destroy_dev() at destroy_dev+0x19
> > May 25 23:26:50 charlie kernel: snd_clone_gc() at snd_clone_gc+0xc4
> > May 25 23:26:50 charlie kernel: snd_clone_unref() at
> > snd_clone_unref+0x58 May 25 23:26:50 charlie kernel: dsp_close() at
> > dsp_close+0x6d5 May 25 23:26:50 charlie kernel: devfs_close() at
> > devfs_close+0x15c May 25 23:26:50 charlie kernel: vn_close() at
> > vn_close+0xb6 May 25 23:26:50 charlie kernel: vn_closefile() at
> > vn_closefile+0x80 May 25 23:26:50 charlie kernel: devfs_close_f() at
> > devfs_close_f+0x1a May 25 23:26:50 charlie kernel: _fdrop() at
> > _fdrop+0x23 May 25 23:26:50 charlie kernel: closef() at closef+0x4c
> > May 25 23:26:50 charlie kernel: kern_close() at kern_close+0x10d
> > May 25 23:26:50 charlie kernel: syscall() at syscall+0x1bf
> > May 25 23:26:50 charlie kernel: Xfast_syscall() at
> > Xfast_syscall+0xab May 25 23:26:50 charlie kernel: --- syscall (6,
> > FreeBSD ELF64, close), rip = 0x804651f5c, rsp = 0x7fffffffd5e8, rbp
> > = 0x803aa53f0 ---
> > 
> 
> It is something new. Let me examine it first.

Not quite. You cannot hold a mutex over the destroy_dev(), because
the destroy_dev() may sleep. It was not very common situation, because
it requires another thread still in the driver methods to trigger the
problem. Now, because the malloc() is called unconditionally in the
destroy_dev() since rev. 1.212, the problem gets hit regularly.