Re: kern/51710: audio playback works only once

[Martin Husemann <martin%duskware.de@localhost>]

The following reply was made to PR kern/51710; it has been noted by GNATS.

From: Martin Husemann <martin%duskware.de@localhost>
To: gnats-bugs%NetBSD.org@localhost
Cc: 
Subject: Re: kern/51710: audio playback works only once
Date: Tue, 20 Dec 2016 15:00:33 +0100

 I added a bit more debug output and got a backtrace from the failing
 cv_wait_sig() call:
 
 AUDIO_DEBUG log from starting the second playback:
 
 audio_open: flags=0x2 sc=0x108f44000 hdl=0x107697b08
 audio_init_ringbuffer: MI blksize=8816
 audio_init_ringbuffer: final blksize=8816
 audio_init_ringbuffer: MI blksize=8816
 audio_init_ringbuffer: final blksize=8816
 audio_initbufs: mode=0x5
 audio_init_ringbuffer: MI blksize=8816
 audio_init_ringbuffer: final blksize=8816
 audio_init_ringbuffer: MI blksize=8816
 audio_init_ringbuffer: final blksize=8816
 audiosetinfo sc=0x108f44000 ai=0x2607f7460
 audiosetinfo() Setting record params: enc=1 1ch 8/8bit 8000Hz
 audiosetinfo() Setting play params: enc=1 1ch 8/8bit 8000Hz
 audio_setup_pfilters: HW-buffer=0x1093f92c8 pustream=0x1093f9048
 [0] enc=1 1ch 8/8bit 8000Hz
 [1] enc=7 1ch 16/16bit 8000Hz
 [HW] enc=7 2ch 16/16bit 44100Hz
 audio_setup_rfilters: HW-buffer=0x1093f9368 pustream=0x1093f9480
 [HW] enc=7 2ch 16/16bit 44100Hz
 [0] enc=7 1ch 16/16bit 8000Hz
 [1] enc=1 1ch 8/8bit 8000Hz
 audiosetinfo: filter setup is completed.
 audio_calc_blksize: record blksize=8820
 audio_calc_blksize: play blksize=8820
 audio_calc_blksize: record blksize=8820
 audio_calc_blksize: play blksize=8820
 audio_initbufs: mode=0x5
 audio_init_ringbuffer: MI blksize=8816
 audio_init_ringbuffer: final blksize=8816
 audio_calcwater: plow=49152 phigh=65536 rlow=0 rhigh=56716
 audiostartp: start=0x10a8a2000 used=0(hi=65536 blk=8816) mmapped=0
 audiostartp: wakeup and return
 audio_calcwater: plow=49152 phigh=65536 rlow=0 rhigh=56720
 audio_open: done sc_mode = 0x5
 audio_ioctl(136,'A',22)
 AUDIO_SETINFO mode=0x5
 audiosetinfo sc=0x108f44000 ai=0x10a7f9e28
 audiosetinfo() Setting play params: enc=3 1ch 16/16bit 8000Hz
 audio_setup_pfilters: HW-buffer=0x1093f92c8 pustream=0x1093f9048
 [0] enc=7 1ch 16/16bit 8000Hz
 [HW] enc=7 2ch 16/16bit 44100Hz
 audiosetinfo: filter setup is completed.
 audio_calc_blksize: record blksize=8820
 audio_calc_blksize: play blksize=8820
 audio_initbufs: mode=0x5
 audio_init_ringbuffer: MI blksize=8816
 audio_init_ringbuffer: final blksize=8816
 audio_calcwater: plow=49152 phigh=65536 rlow=0 rhigh=56716
 audio_ioctl(136,'A',22) result 0
 audio_ioctl(136,'A',22)
 AUDIO_SETINFO mode=0x5
 audiosetinfo sc=0x108f44000 ai=0x10a7f9e28
 audio_ioctl(136,'A',22) result 0
 audio_close: sc=0x108f44000
 audio_drain: enter busy=0
 audio_drain: n=0, used=0, drops=0
 audio_waitio: cv_wait_sig for condvar 0x108f5c0e0 with mutex 0x107697b10
 audio_waitio: cv_wait_sig for condvar 0x108f5c0e0 with mutex 0x107697b10 returned -3
 
 The call stack at this point is:
 
 audio_waitio+0xfc
 audio_drain+0x170
 audio_close+0x31c
 audioclose+0xec
 spec_close+0x1bc
 ufsspec_close+0x50
 VOP_CLOSE+0x30
 vn_close+0x84
 closef+0x5c
 sys_close+0x14
 syscall+0x4f4
 
 
 It seems that it is waiting for output to drain but that never happens.
 Maybe a driver specific bug? Any hints?
 
 Martin