On Thu, May 10, 2012 at 12:34:19PM -0400, Trent Piepho wrote:
On Thu, May 10, 2012 at 12:06 PM, Russell King - ARM Linux linux@arm.linux.org.uk wrote:
The question is - what would cause ALSA to hammer away at the buffer like that - checking it every 16 or 8 DMA bytes transferred? I'm also seeing around 75% system CPU time, which really isn't good.
The above was captured while aplay was running, with no apparant audio corruption.
I've had this happen, but not with aplay. I sent something to the list a few months ago about it.
The problem is triggered when writing to ALSA with writes that are unequal to the period size and using sampling rate conversion in an ALSA plugin.
I'm not using any plugins, and there's definitely no sample rate conversion going on. I'm basically piping a raw S16_LE stereo file into "aplay -c2 -r48000 -fS16_LE" and that's the only format the hardware supports:
Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo Plug PCM: Hardware PCM card 0 'Assabet' device 0 subdevice 0
Its setup is: stream : PLAYBACK access : RW_INTERLEAVED format : S16_LE subformat : STD channels : 2 rate : 48000 exact rate : 48000 (48000/1) msbits : 16 buffer_size : 16384 period_size : 4096 period_time : 85333 tick_time : 0 tstamp_mode : NONE period_step : 1 sleep_min : 0 avail_min : 4096 xfer_align : 4096 start_threshold : 16384 stop_threshold : 16384 silence_threshold: 0 silence_size : 0 boundary : 1073741824
Note that this is not using mmap, as ARM is not cache coherent.
Interestingly, if I use -M to aplay to force it to use mmap, things get a _lot_ better and I only get a lot fewer calls to the pcm_pointer() method per period. I've included in this log the DMA engine output (which shows the raw DMA address - the buffer is 64K aligned) and where the pcm_pointer() method was called from.
tx_status: addr:c0f14010 soc_dmaengine_pointer: index 1 stat 1 residue 3ff0 cookie 1792 pos 8000 bytes 4010 snd_pcm_update_hw_ptr0+0x30/0x24c soc_dmaengine_submit: submitting index 0 size 4000 cookie 1795 tx_status: addr:c0f14060 soc_dmaengine_pointer: index 1 stat 1 residue 3fa0 cookie 1792 pos 8000 bytes 4060 snd_pcm_update_hw_ptr0+0x30/0x24c tx_status: addr:c0f14130 soc_dmaengine_pointer: index 1 stat 1 residue 3ed0 cookie 1792 pos 8000 bytes 4130 snd_pcm_update_hw_ptr0+0x30/0x24c soc_dmaengine_callback: complete tx_status: addr:c0f18010 soc_dmaengine_pointer: index 2 stat 1 residue 3ff0 cookie 1793 pos c000 bytes 8010 snd_pcm_update_hw_ptr0+0x30/0x24c soc_dmaengine_submit: submitting index 1 size 4000 cookie 1796 tx_status: addr:c0f18060 soc_dmaengine_pointer: index 2 stat 1 residue 3fa0 cookie 1793 pos c000 bytes 8060 snd_pcm_update_hw_ptr0+0x30/0x24c tx_status: addr:c0f18150 soc_dmaengine_pointer: index 2 stat 1 residue 3eb0 cookie 1793 pos c000 bytes 8150 snd_pcm_update_hw_ptr0+0x30/0x24c soc_dmaengine_callback: complete tx_status: addr:c0f1c010 soc_dmaengine_pointer: index 3 stat 1 residue 3ff0 cookie 1794 pos 10000 bytes c010 snd_pcm_update_hw_ptr0+0x30/0x24c soc_dmaengine_submit: submitting index 2 size 4000 cookie 1797 tx_status: addr:c0f1c060 soc_dmaengine_pointer: index 3 stat 1 residue 3fa0 cookie 1794 pos 10000 bytes c060 snd_pcm_update_hw_ptr0+0x30/0x24c tx_status: addr:c0f1c130 soc_dmaengine_pointer: index 3 stat 1 residue 3ed0 cookie 1794 pos 10000 bytes c130 snd_pcm_update_hw_ptr0+0x30/0x24c soc_dmaengine_callback: complete tx_status: addr:c0f10068 soc_dmaengine_pointer: index 0 stat 1 residue 3f98 cookie 1795 pos 4000 bytes 0068 snd_pcm_update_hw_ptr0+0x30/0x24c soc_dmaengine_submit: submitting index 3 size 4000 cookie 1798 tx_status: addr:c0f100f0 soc_dmaengine_pointer: index 0 stat 1 residue 3f10 cookie 1795 pos 4000 bytes 00f0 snd_pcm_update_hw_ptr0+0x30/0x24c tx_status: addr:c0f101c8 soc_dmaengine_pointer: index 0 stat 1 residue 3e38 cookie 1795 pos 4000 bytes 01c8 snd_pcm_update_hw_ptr0+0x30/0x24c soc_dmaengine_callback: complete tx_status: addr:c0f14010 soc_dmaengine_pointer: index 1 stat 1 residue 3ff0 cookie 1796 pos 8000 bytes 4010 snd_pcm_update_hw_ptr0+0x30/0x24c soc_dmaengine_submit: submitting index 0 size 4000 cookie 1799 tx_status: addr:c0f14060 soc_dmaengine_pointer: index 1 stat 1 residue 3fa0 cookie 1796 pos 8000 bytes 4060 snd_pcm_update_hw_ptr0+0x30/0x24c tx_status: addr:c0f14130 soc_dmaengine_pointer: index 1 stat 1 residue 3ed0 cookie 1796 pos 8000 bytes 4130 snd_pcm_update_hw_ptr0+0x30/0x24c