Re: LOR with sound

On 16 Feb, Munehiro Matsuda wrote:
> Hi all,
> 
> I've gotten following LoR with sounde code, using kernel from Feb 15th
> with patch from Mathew Kanner:
>      http://docs.freebsd.org/cgi/mid.cgi?20031215185606.GA63202
> 
>> lock order reversal
>>  1st 0xc31ca140 pcm0:play:0 (pcm play channel) _at_ dev/sound/pcm/channel.c:1069
>>  2nd 0xc31b6ec0 pcm0:record:0 (pcm record channel) _at_ dev/sound/pcm/channel.c:1350
>> Stack backtrace:
>> backtrace(0,ffffffff,c0761120,c0761148,c07303fc) at backtrace+0x12
>> witness_checkorder(c31b6ec0,9,c06cfeaf,546) at witness_checkorder+0x593
>> _mtx_lock_flags(c31b6ec0,0,c06cfea6,546,d29f2a70) at _mtx_lock_flags+0x67
>> chn_lock(c32add80,c,c407b000,c405b000,102) at chn_lock+0x1a
>> sndbuf_remalloc(c31bab00,200,100,c32add80,100) at sndbuf_remalloc+0x8c
>> chn_setblocksize(c32add80,200,0,20000,c31cf718) at chn_setblocksize+0x306
>> chn_tryspeed(c32add80,1f40) at chn_tryspeed+0x149
>> chn_tryformat(c32add80,10,10,d29f2c60,d29f2c60) at chn_tryformat+0xaf
>> chn_setformat(c32add80,10,0,c1616a00,c32add80) at chn_setformat+0x15
>> dsp_ioctl(c075a6a0,c0045005,d29f2c60,3,c3733540) at dsp_ioctl+0x9f2
>> spec_ioctl(d29f2b88,d29f2c34,c0583df7,d29f2b88,c074fc40) at spec_ioctl+0x12d
>> spec_vnoperate(d29f2b88) at spec_vnoperate+0x13
>> vn_ioctl(c3778f24,c0045005,d29f2c60,c371f180,c3733540) at vn_ioctl+0x17f
>> ioctl(c3733540,d29f2d14,3,5,296) at ioctl+0x37c
>> syscall(c068002f,2f,2f,0,0) at syscall+0x217
>> Xint0x80_syscall() at Xint0x80_syscall+0x1d
>> --- syscall (54), eip = 0x284e7b1b, esp = 0xbfbf5dfc, ebp = 0xbfbf5e18 ---

This is seriously wierd.  channel.c:1069 is in chn_setblocksize(), and
it is locking the play channel lock, as one would expect.  The
sndbuf_remalloc() call should be calling chn_unlock() and chn_lock() on
the same play channel lock, but it sure looks like it is trying to lock
the record channel lock.

> Also, I'm getting following warning with sound related code path.
> 
>> malloc() of "4096" with the following non-sleepable locks held:
>> exclusive sleep mutex pcm0:play:0 (pcm play channel) r = 0 (0xc31ca140) locked _at_ dev/sound/pcm/channel.c:1069
>> malloc() of "4096" with the following non-sleepable locks held:
>> exclusive sleep mutex pcm0 (sound cdev) r = 0 (0xc31ca2c0) locked _at_ dev/sound/pcm/dsp.c:213
>> malloc() of "4096" with the following non-sleepable locks held:
>> exclusive sleep mutex pcm0:record:0 (pcm record channel) r = 0 (0xc31b6ec0) locked _at_ dev/sound/pcm/dsp.c:479
>
> FYI, I use following sound card build into my note book.
> 
> pcm0: <Yamaha DS-1E (YMF744)> port 0xfcac-0xfcaf,0xfc00-0xfc3f mem 0xfecf0000-0xfecf7fff irq 9 at device 9.0 on pci0
> pcm0: <Asahi Kasei AK4543 AC97 Codec>

My suspicion is that there are problems with locking of the record
channel, though I can't explain why the locking problems are reported
like they are above instead of problems pointing directly to
dsp_ioctl().

Because the defined lock order is record channel and then play channel,
dsp_ioctl() should unlock the play channel any time it calls a function
on the record channel that could potentially unlock the record channel,
and then relock the play channel afterwards.  The it looks like the
affected ioctl() commands are:
	AIOSSIZE
	AIOSFMT
	SNDCTL_DSP_SETBLKSIZE
	SNDCTL_DSP_SPEED
	SNDCTL_DSP_STEREO
	SOUND_PCM_WRITE_CHANNELS
	SNDCTL_DSP_SETFMT
	SNDCTL_DSP_SETFRAGMENT