[alsa-devel] my driver can't reproduce continuously
Hi
Now I'm creating sound driver. But can't reproduce continuously. So, I would like to ask.
I use module of SH to play sound. Player is aplay, sound data is wav file.
Q1) When I play sound, aplay said
underrun!!! (at least 0.000 ms long) underrun!!! (at least 0.000 ms long) underrun!!! (at least 0.000 ms long) underrun!!! (at least 0.000 ms long)
I checked source of aplay, but can not understand about snd_pcm_status_get_state. why snd_pcm_status_get_state return SND_PCM_STATE_XRUN ? What should my driver do (or where should I check) ?
Q2) The reason that it can not reproduce continuously seems soc-core.c :: soc_pcm_trigger timing. Call timing of soc_pcm_trigger is slow. What should my driver do to make call timing more fast ?
Best regards -- Kuninori Morimoto
Hi
Now I'm creating sound driver. But can't reproduce continuously.
(snip)
Q1) When I play sound, aplay said
underrun!!! (at least 0.000 ms long) underrun!!! (at least 0.000 ms long)
(snip)
Q2) The reason that it can not reproduce continuously seems soc-core.c :: soc_pcm_trigger timing. Call timing of soc_pcm_trigger is slow.
I attached my stupid driver. fsi.c, dma-sh7724.c, fsi.h This driver assume that input data is 16bit sound data.
The calculation of the transmission data size of FSI is confusing. But may be it is OK about this in my stupid driver.
I would like to ask following.
o Is there something wrong about call timing of snd_pcm_period_elapsed ? if period is 4, snd_pcm_period_elapsed is called 4 times. Is it correct ? If not what should I do ?
o Is there something wrong about return value of snd_pcm_ops :: pointer ?
o why aplay say underrun!!! ? where should I check ? - XXX size - XXX value - XXX call timing - XXX function return value - should have XXX function or do XXX operation... Does this have relationship to snd_pcm_period_elapsed ?
o soc-core.c :: soc_pcm_trigger timing seems slow. So, it can not reproduce continuously. but how to controll this ?
o sometimes BUG_ON is called when I use kmalloc on snd_soc_dai_ops :: trigger. This BUG_ON came frome cache_alloc_refill. Should I not use kmalloc on trigger function ?
On Thu, Jul 23, 2009 at 06:58:59PM +0900, Kuninori Morimoto wrote:
o why aplay say underrun!!! ? where should I check ?
Underrun means that the driver is consuming data more quickly than aplay is able to provide it. This may mean that there's some system performance problem or it may be due to your driver is consuming data more quickly than it should and causing problems further up the stack.
o sometimes BUG_ON is called when I use kmalloc on snd_soc_dai_ops :: trigger. This BUG_ON came frome cache_alloc_refill. Should I not use kmalloc on trigger function ?
You shouldn't be using kmalloc() there, no - the trigger function is called from an atomic context where only very limited memory allocation is possible.
I'll have a look at your code, but it's likely to be a few days before I have time to do so.
Dear Mark
Thank you for your advice.
Underrun means that the driver is consuming data more quickly than aplay is able to provide it. This may mean that there's some system performance problem or it may be due to your driver is consuming data more quickly than it should and causing problems further up the stack.
I could understand. I will re-check my code, system and more. Thank you
o sometimes BUG_ON is called when I use kmalloc on
(snip)
You shouldn't be using kmalloc() there, no - the trigger function is called from an atomic context where only very limited memory allocation is possible.
Hmm. OK. Thank you. The driver that I referred have used kmalloc on trigger funtion. Maybe it have same bug =).
I'll have a look at your code, but it's likely to be a few days before I have time to do so.
Thank you very much.
Best regards -- Kuninori Morimoto
Dear All
Underrun means that the driver is consuming data more quickly than aplay is able to provide it. This may mean that there's some system performance problem or it may be due to your driver is consuming data more quickly than it should and causing problems further up the stack.
I would like to ask about size of period, buffer.
In my environment, each data size are follows.
runtime->buffer_size = 8192 runtime->period_size = 2048 runtime->periods = 4 buffer_len = frames_to_bytes(runtime, runtime->buffer_size) = 32768 period_len = frames_to_bytes(runtime, runtime->period_size) = 8192
After sending period_len byte (=8192 byte = 2048 frame) I call snd_pcm_period_esapsed(). after that snd_pcm_update_hw_ptr_interrupt() is called. Is this correct ?
Then, runtime->hw_ptr_base will be updated In this function. How is this hw_ptr_base renewed ?
My stupid driver return -EPIPE on snd_pcm_update_hw_ptr_post So, I added following stupid debug printk
----------------------------------------------------- diff --git a/sound/core/pcm_lib.c b/sound/core/pcm_lib.c index 68d161a..01a41d3 100644 --- a/sound/core/pcm_lib.c +++ b/sound/core/pcm_lib.c @@ -199,6 +199,10 @@ static int snd_pcm_update_hw_ptr_post(struct snd_pcm_substr avail = snd_pcm_capture_avail(runtime); if (avail > runtime->avail_max) runtime->avail_max = avail; + printk("hw_prt_base = %d, hw_prt = %d, appl_prt = %d\n", + runtime->hw_ptr_base, + runtime->status->hw_ptr, + runtime->control->appl_ptr); if (avail >= runtime->stop_threshold) { if (substream->runtime->status->state == SNDRV_PCM_STATE_DRAININ snd_pcm_drain_done(substream); -----------------------------------------------------
The output is
----------------------------------------------------- hw_prt_base = 0, hw_prt = 127, appl_prt = 8192 hw_prt_base = 0, hw_prt = 255, appl_prt = 8319 hw_prt_base = 0, hw_prt = 383, appl_prt = 8447 hw_prt_base = 0, hw_prt = 533, appl_prt = 8575 hw_prt_base = 0, hw_prt = 661, appl_prt = 8725 hw_prt_base = 0, hw_prt = 789, appl_prt = 8853 hw_prt_base = 0, hw_prt = 938, appl_prt = 8981 hw_prt_base = 0, hw_prt = 1066, appl_prt = 9130 hw_prt_base = 0, hw_prt = 1194, appl_prt = 9258 hw_prt_base = 0, hw_prt = 1322, appl_prt = 9386 hw_prt_base = 0, hw_prt = 1472, appl_prt = 9514 hw_prt_base = 0, hw_prt = 1600, appl_prt = 9664 hw_prt_base = 0, hw_prt = 1728, appl_prt = 9792 hw_prt_base = 0, hw_prt = 1856, appl_prt = 9920 hw_prt_base = 0, hw_prt = 1984, appl_prt = 10048 hw_prt_base = 8192, hw_prt = 8256, appl_prt = 10176 <== ** hw_prt_base = 8192, hw_prt = 8192, appl_prt = 10176 hw_prt_base = 8192, hw_prt = 8384, appl_prt = 10240 hw_prt_base = 8192, hw_prt = 8512, appl_prt = 12288 hw_prt_base = 16384, hw_prt = 16384, appl_prt = 14336 <== hw_prt > appl_prt underrun!!! (at least 0.000 ms long) <== underrun -----------------------------------------------------
I think hw_prt_base mean "frame", not "byte". Because pointer function return value use bytes_to_frames(), and that value is used to new_hw_prt. Is it correct ?
why hw_prt_base update size is 8192 = buffer_size ?
please check hw_prt near <== **. ---------------------- hw_prt_base = 0, hw_prt = 1856 hw_prt_base = 0, hw_prt = 1984 hw_prt_base = 8192, hw_prt = 8256 <== ** hw_prt_base = 8192, hw_prt = 8192 ----------------------
I can uderstand if update size is 2048 = period_size.
Is my understanding wrong ?? my kernel is between 2.6.30 and 2.6.31-rc1
Best regards -- Kuninori Morimoto
At Fri, 24 Jul 2009 17:56:01 +0900, Kuninori Morimoto wrote:
Dear All
Underrun means that the driver is consuming data more quickly than aplay is able to provide it. This may mean that there's some system performance problem or it may be due to your driver is consuming data more quickly than it should and causing problems further up the stack.
I would like to ask about size of period, buffer.
In my environment, each data size are follows.
runtime->buffer_size = 8192 runtime->period_size = 2048 runtime->periods = 4 buffer_len = frames_to_bytes(runtime, runtime->buffer_size) = 32768 period_len = frames_to_bytes(runtime, runtime->period_size) = 8192
After sending period_len byte (=8192 byte = 2048 frame) I call snd_pcm_period_esapsed(). after that snd_pcm_update_hw_ptr_interrupt() is called. Is this correct ?
Correct.
Then, runtime->hw_ptr_base will be updated In this function. How is this hw_ptr_base renewed ?
At 4th snd_pcm_period_elapsed() call, buffer_size is added. Or, when the value returned from pointer callback is lapped to zero or such.
(snip)
why hw_prt_base update size is 8192 = buffer_size ?
please check hw_prt near <== **.
hw_prt_base = 0, hw_prt = 1856 hw_prt_base = 0, hw_prt = 1984 hw_prt_base = 8192, hw_prt = 8256 <== ** hw_prt_base = 8192, hw_prt = 8192
My rough guess is that your pointer callback returns a wrong value. The pointer callback is supposed to give the currently played position offset in a ring buffer, and ranged from 0 to buffer_size-1. When the first snd_pcm_period_elapsed() is called, it should be (ideally) pointing at period_size, at the succeeding calls, period_size*2, period_size*3, then 0 again.
Try to track the value returned from the pointer callback.
Takashi
Dear Takashi
Thank you for your comment
My rough guess is that your pointer callback returns a wrong value. The pointer callback is supposed to give the currently played position offset in a ring buffer, and ranged from 0 to buffer_size-1. When the first snd_pcm_period_elapsed() is called, it should be (ideally) pointing at period_size, at the succeeding calls, period_size*2, period_size*3, then 0 again.
The criminal is my wrong understanding... OK.
But I still have trouble now.
follows the log ------------ trigger called hw_prt_base = 0, hw_prt = 127, appl_prt = 8192 hw_prt_base = 0, hw_prt = 255, appl_prt = 8319 (snip) hw_prt_base = 0, hw_prt = 3845, appl_prt = 11888 hw_prt_base = 0, hw_prt = 3995, appl_prt = 12037 call elapsed // 2nd call hw_prt_base = 0, hw_prt = 4123, appl_prt = 12037 hw_prt_base = 0, hw_prt = 4272, appl_prt = 12187 call elapsed // 3rd call hw_prt_base = 0, hw_prt = 6202, appl_prt = 12288 call elapsed // 4th call hw_prt_base = 8192, hw_prt = 8192, appl_prt = 12288 <<< driver stopped here... >> ------------
when 1st buffer was send, driver stop. 2nd trigger function isn't called.
Best regards -- Kuninori Morimoto
Dear Takashi again
hw_prt_base = 0, hw_prt = 4272, appl_prt = 12187 call elapsed // 3rd call hw_prt_base = 0, hw_prt = 6202, appl_prt = 12288 call elapsed // 4th call hw_prt_base = 8192, hw_prt = 8192, appl_prt = 12288 <<< driver stopped here... >>
In above case, when 4th "elapse" is called, are appl_prt = 12288 too small ??
This time, appl_prt should be over 16384 (= 8192 * 2) ?
If so, is transmission speed of my driver too fast ?
Best regards -- Kuninori Morimoto
At Mon, 27 Jul 2009 09:58:19 +0900, Kuninori Morimoto wrote:
Dear Takashi
Thank you for your comment
My rough guess is that your pointer callback returns a wrong value. The pointer callback is supposed to give the currently played position offset in a ring buffer, and ranged from 0 to buffer_size-1. When the first snd_pcm_period_elapsed() is called, it should be (ideally) pointing at period_size, at the succeeding calls, period_size*2, period_size*3, then 0 again.
The criminal is my wrong understanding... OK.
But I still have trouble now.
follows the log
trigger called hw_prt_base = 0, hw_prt = 127, appl_prt = 8192 hw_prt_base = 0, hw_prt = 255, appl_prt = 8319 (snip) hw_prt_base = 0, hw_prt = 3845, appl_prt = 11888 hw_prt_base = 0, hw_prt = 3995, appl_prt = 12037 call elapsed // 2nd call hw_prt_base = 0, hw_prt = 4123, appl_prt = 12037 hw_prt_base = 0, hw_prt = 4272, appl_prt = 12187 call elapsed // 3rd call hw_prt_base = 0, hw_prt = 6202, appl_prt = 12288 call elapsed // 4th call hw_prt_base = 8192, hw_prt = 8192, appl_prt = 12288
<<< driver stopped here... >>
when 1st buffer was send, driver stop. 2nd trigger function isn't called.
Check the raw value returned from the pointer callback, too. This can be the real cause.
Takashi
Dear Takashi
Thank you for your comment
when 1st buffer was send, driver stop. 2nd trigger function isn't called.
Check the raw value returned from the pointer callback, too. This can be the real cause.
I might have been doing a very big misunderstanding.
The pointer callback is supposed to give the currently played position offset in a ring buffer, and ranged from 0 to buffer_size-1.
Does this "ring buffer" mean I should transmit runtime->dma_area many times from offset 0x0 ??
=> when I call 4th elapsed, should I send runtime->dma_area + 0x0 again ?
If so, my driver get STOP on trigger funtion many times even if I didn't stop it.
START STOP underrun!!! START STOP underrun!!! ...
Does this correct operation ?
Best regards -- Kuninori Morimoto
At Mon, 27 Jul 2009 16:43:05 +0900, Kuninori Morimoto wrote:
Dear Takashi
Thank you for your comment
when 1st buffer was send, driver stop. 2nd trigger function isn't called.
Check the raw value returned from the pointer callback, too. This can be the real cause.
I might have been doing a very big misunderstanding.
The pointer callback is supposed to give the currently played position offset in a ring buffer, and ranged from 0 to buffer_size-1.
Does this "ring buffer" mean I should transmit runtime->dma_area many times from offset 0x0 ??
Yes and no. A ring buffer may contain multiple "periods" (or "fragments") in it. In your case, a ring buffer has 4 periods. Until these 4 periods are sent out, the offset goes incrementally. Once it reaches to buffer_size, it returns to zero again.
=> when I call 4th elapsed, should I send runtime->dma_area + 0x0 again ?
Yes.
If so, my driver get STOP on trigger funtion many times even if I didn't stop it.
START STOP underrun!!! START STOP underrun!!! ...
Does this correct operation ?
Yes, because the PCM core thinks a buffer underrun happens, judging from the pointer callback value your driver returned. That's why I asked many times to check the values returned from the pointer callback. This value and the timing of snd_pcm_period_elapsed() is the only information the PCM core checks.
Takashi
Dear Takashi
Yes, because the PCM core thinks a buffer underrun happens, judging from the pointer callback value your driver returned. That's why I asked many times to check the values returned from the pointer callback. This value and the timing of snd_pcm_period_elapsed() is the only information the PCM core checks.
Thank you and sorry. I didn't know the "ring buffer".
The return value of pointer funtion seems OK. But I didn't use ring buffer. this is the reason driver will be stopped.
Best regards -- Kuninori Morimoto
participants (3)
-
Kuninori Morimoto -
Mark Brown -
Takashi Iwai