[alsa-devel] Input/output error while playing a file using aplay
Hi
I am testing my audio driver using aplay. I trying to play an audio file using:
#aplay -Dplughw:0,0 --rate=44100 --format=S16 --channels=2 test.wav The log is as follows,
snd_card_omap_alsa_open start snd_card_omap_alsa_open end Playing WAVE 'test.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo snd_omap_alsa_hw_params start snd_omap_alsa_prepare start snd_omap_alsa_prepare end snd_omap_alsa_trigger start audio_start_dma_chain start audio_start_dma_chain end omap_start_alsa_sound_dma end snd_omap_alsa_trigger end snd_omap_alsa_pointer start audio_get_dma_pos start audio_get_dma_pos end
It waits here for sometime and then I get snd_omap_alsa_trigger starte error: Input/output error
Then the things are wound up as:
audio_stop_dma start omap_stop_alsa_sound_dma start omap_stop_alsa_sound_dma end omap_clear_alsa_sound_dma start omap_clear_alsa_sound_dma end snd_omap_alsa_trigger end
snd_omap_alsa_hw_free start snd_omap_alsa_hw_free end snd_card_omap_alsa_close start snd_card_omap_alsa_close end
So basically the problem is in trigger where it waits for something and then winds up things. Any idea, what could be the reason. I am thinking it has to do something with DMA interrupts etc.
So basically the problem is in trigger where it waits for something and then winds up things
It is not a problem with trigger, Strace revealed that this is an ioctl error and after that the aplay pcm write fails. I do not get the DMA interrupts which I should be getting.
Here is the entire log:
execve("/usr/local/bin/aplay", ["aplay", "-Dplughw:0,0", "--rate=44100", "--format=S16", "--channels=2", "startup.wav"], [/* 7 vars */]) = 0 uname({sys="Linux", node="192.168.200.214", ...}) = 0 brk(0) = 0x20000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=12436, ...}) = 0 mmap2(NULL, 12436, PROT_READ, MAP_PRIVATE, 3, 0) = 0x40015000 close(3) = 0 open("/usr/local/lib/libasound.so.2", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\314\353\1"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0775, st_size=2164893, ...}) = 0 mmap2(NULL, 777620, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x4001e000 mprotect(0x400d0000, 48532, PROT_NONE) = 0 mmap2(0x400d8000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xb2) = 0x400d8000 close(3) = 0 open("/lib/libm.so.6", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\00003\0\000"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0644, st_size=778699, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40019000 mmap2(NULL, 713068, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x400dc000 mprotect(0x40182000, 33132, PROT_NONE) = 0 mmap2(0x40189000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xa5) = 0x40189000 close(3) = 0 open("/lib/libdl.so.2", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\344\v\0\000"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0644, st_size=16868, ...}) = 0 mmap2(NULL, 41152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x4018b000 mprotect(0x4018d000, 32960, PROT_NONE) = 0 mmap2(0x40194000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1) = 0x40194000 close(3) = 0 open("/lib/libpthread.so.0", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0p?\0\0004"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0644, st_size=99172, ...}) = 0 mmap2(NULL, 367928, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x40196000 mprotect(0x401a5000, 306488, PROT_NONE) = 0 mmap2(0x401ac000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xe) = 0x401ac000 mmap2(0x401ae000, 269624, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x401ae000 close(3) = 0 open("/lib/libc.so.6", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0HM\1\0004"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0644, st_size=1424946, ...}) = 0 mmap2(NULL, 1132932, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x401f0000 mprotect(0x402f7000, 55684, PROT_NONE) = 0 mmap2(0x402ff000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x107) = 0x402ff000 mmap2(0x40303000, 6532, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40303000 close(3) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x4001a000 mprotect(0x402ff000, 8192, PROT_READ) = 0 mprotect(0x401ac000, 4096, PROT_READ) = 0 mprotect(0x40194000, 4096, PROT_READ) = 0 mprotect(0x40189000, 4096, PROT_READ) = 0 mprotect(0x4001c000, 4096, PROT_READ) = 0 munmap(0x40015000, 12436) = 0 getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0 setrlimit(RLIMIT_STACK, {rlim_cur=2044*1024, rlim_max=RLIM_INFINITY}) = 0 getpid() = 586 rt_sigaction(SIGRTMIN, {0x4019e980, [], 0x4000000 /* SA_??? */}, NULL, 8) = 0 rt_sigaction(SIGRT_1, {0x4019ea3c, [RTMIN], 0x4000000 /* SA_??? */}, NULL, 8) = 0 rt_sigaction(SIGRT_2, {0x4019eba8, [], 0x4000000 /* SA_??? */}, NULL, 8) = 0 rt_sigprocmask(SIG_BLOCK, [RTMIN], NULL, 8) = 0 rt_sigprocmask(SIG_UNBLOCK, [RT_1], NULL, 8) = 0 _sysctl({{CTL_KERN, KERN_VERSION}, 2, 0xbe863ad8, 40, (nil), 0}) = 0 brk(0) = 0x20000 brk(0x41000) = 0x41000 stat64("/usr/local/share/alsa/alsa.conf", {st_mode=S_IFREG|0664, st_size=7764, ...}) = 0 open("/usr/local/share/alsa/alsa.conf", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0664, st_size=7764, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40015000 read(3, "#\n# ALSA library configuration "..., 4096) = 4096 read(3, "cards.pcm.surround40\npcm.surroun"..., 4096) = 3668 read(3, "", 4096) = 0 read(3, "", 4096) = 0 close(3) = 0 munmap(0x40015000, 4096) = 0 access("/etc/asound.conf", R_OK) = 0 open("/etc/asound.conf", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0664, st_size=690, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40015000 read(3, "pcm.headset {\n\t@args [BDADDR TIM"..., 4096) = 690 read(3, "", 4096) = 0 read(3, "", 4096) = 0 close(3) = 0 munmap(0x40015000, 4096) = 0 access("//.asoundrc", R_OK) = -1 ENOENT (No such file or directory) open("/dev/snd/controlC0", O_RDONLY) = 3 close(3) = 0 open("/dev/snd/controlC0", O_RDWR) = 3 ioctl(3, USBDEVFS_CONTROL, 0xbe863874) = 0 ioctl(3, 0x4snd_card_omap_alsa_open start eac->base = c4954000 = 0
open("/dev/snd/pcmC0D0p", O_RDWBefore audio init R|O_NONBLOCKomap850_audio_init start eac->base = c4954000 CSMI: csmi_ctl_snd_res failed CSMI: csmi_ctl_snd failed eac_enable_clocks start Clocks are already enabled omap850_audio_init end omap850_audio_init failed after audio init snd_card_omap_alsa_open end ) = 4 close(3) = 0 ioctl(4, AGPIOC_ACQUIRE or APM_IOC_STANDBY, 0xbe863778) = 0 fcntl64(4, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) ioctl(4, AGPIOC_INFO, 0xbe8636f0) = 0 ioctl(4, AGPIOC_RELEASE or APM_IOC_SUSPEND, 0xbe8636ec) = 0 mmap2(NULL, 4096, PROT_READ, MAP_SHARED, 4, 0x80000) = -1 ENXIO (No such device or address) ioctl(4, 0xc0844123, 0xbe8636f4) = 0 fcntl64(4, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) fcntl64(4, F_SETFL, O_RDWR) = 0 ioctl(4, AGPIOC_ACQUIRE or APM_IOC_STANDBY, 0xbe863ccc) = 0 rt_sigaction(SIGINT, {0x401a28ac, [INT], SA_RESTART|0x4000000}, {SIG_DFL}, 8) = 0 rt_sigaction(SIGTERM, {0x401a28ac, [TERM], SA_RESTART|0x4000000}, {SIG_DFL}, 8) = 0 rt_sigaction(SIGABRT, {0x401a28ac, [ABRT], SA_RESTART|0x4000000}, {SIG_DFL}, 8) = 0 open("startup.wav", O_RDONLY|O_LARGEFILE) = 3 read(3, "RIFF(\310\24\0WAVEfmt \20\0\0\0\1\0\2\0", 24) = 24 read(3, "D\254\0\0", 4) = 4 read(3, "\20\261\2\0\4\0\20\0", 8) = 8 read(3, "data\4\310\24\0", 8) = 8 write(2, "Playing WAVE 'startup.wav' : ", 29Playing WAVE 'startup.wav' : ) = 29 write(2, "Signed 16 bit Little Endian, ", 29Signed 16 bit Little Endian, ) = 29 write(2, "Rate 44100 Hz, ", 15Rate 44100 Hz, ) = 15 write(2, "Stereo", 6Stereo) = 6 write(2, "\n", 1 ) = 1 ioctl(4, 0xc25c4110, 0xbe8635f4) = 0 ioctl(4, 0xc25c4110, 0xbe8632e8) = 0 ioctl(4, 0xc25c4110, 0xbe8632e8) = 0 ioctl(4, 0xc25c4110, 0xbe8635f4) = 0 ioctl(4, 0xc25c4110, 0xbe8632e8) = 0 ioctl(4, 0xc25c4110, 0xbe8632e8) = 0 ioctl(4, 0xc25c4110, 0xbe8635f4) = 0 ioctl(4, 0xc25c4110, 0xbe863368) = 0 ioctl(4, 0xc25c4110, 0xbe86305c) = 0 ioctl(4, 0xc25c4110, 0xbe86305c) = 0 ioctl(4, 0xc25c4110, 0xbe863368) = 0 ioctl(4, 0xc25c4110, 0xbe863368) = 0 ioctl(4, 0xc25c4110, 0xbe86305c) = 0 ioctl(4, 0xc25c4110, 0xbe86305c) = 0 ioctl(4, 0xc25c4110, 0xbe863368) = 0 ioctl(4, 0xc25c4110, 0xbe86305c) = 0 ioctl(snd_omap_alsa_hw_params start 4, 0xc25c4110, 0xbe86305c) = 0 ioctl(4, 0xc25c4110, 0xbe863368) = 0 ioctl(4, 0xcsnd_omap_alsa_prepare start snd_omap_alsa_prepare end = 0
ioctl(4, 0xc25c4110, 0xbe86305cSNDRV_PCM_IOCTL1_RESET ) = 0 ioctl(4, 0xc25c411Inside snd_pcm_lib_ioctl_reset 0, 0xbe86305c) = 0 ioctl(4, 0xc25c4110, 0xbe863368) = 0 ioctl(4, 0xc25c4110, 0xbe86305c) = 0 ioctl(4, 0xc25c4110, 0xbe86305c) = 0 ioctl(4, 0xc25c4110, 0xbe863368) = 0 ioctl(4, 0xc25c4110, 0xbe862e6c) = 0 ioctl(4, 0xc25c4110, 0xbe862b60) = 0 ioctl(4, 0xc25c4110, 0xbe862b60) = 0 ioctl(4, 0xc25c4110, 0xbe862e6c) = 0 ioctl(4, 0xc25c4110, 0xbe862b60) = 0 ioctl(4, 0xc25c4110, 0xbe862b60) = 0 ioctl(4, 0xc25c4110, 0xbe862e6c) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe8630d4) = 0 ioctl(4, 0xc25c4110, 0xbe863564) = 0 ioctl(4, 0xc25c4110, 0xbe863564) = 0 ioctl(4, 0xc25c4110, 0xbe863564) = 0 ioctl(4, 0xc25c4110, 0xbe863564) = 0 ioctl(4, 0xc25c4110, 0xbe863564) = 0 ioctl(4, 0xc25c4110, 0xbe863904) = 0 ioctl(4, 0xc25c4111, 0xbe863904) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 ioctl(4, 0xc0684113, 0xbe8634c4) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 ioctl(4, 0x4140, 0x400c3ed4) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 ioctl(4, 0xc0684113, 0xbe863898) = 0 read(3, "\377\377\0\0\0\0\0\0\1\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\1"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbe863bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\377\377\0\0\1\0\0\0\0\0\0\0\377\377\376\377\0\0\3\0\377"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbe863bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\374\377\7\0\0\0\0\0\372\377\0\0\376\377\3\0\3\0\373\377"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbe863bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\373\377\1\0\377\377\5\0\376\377\372\377\377\377\7\0\6"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbe863bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\212\377{\377\212\377\210\377\220\377\226\377\214\377\213"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbe863bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, ".\324\326\3438\323Q\343\375\322\34\343\254\323\223\343"..., 8192Inside snd_pcm_do_start snd_omap_alsa_trigger start audio_start_dma_chain start Inside omap_start_dma 1 Inside omap_start_dma 2 Inside omap_start_dma 3 audio_start_dma_chain end snd_omap_alsa_trigger end ) = 8192 ioctl(4, 0x400c4150, 0xbe863bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) =Inside snd_pcm_update_hw_ptr_pos snd_omap_alsa_pointer start Count is 34 Offset is 4294967288 and buffer size is 16384 Inside snd_pcm_update_hw_ptr_pos, pos is 0 0 read(3, "\2\fK\0x\v\220\375\361\n_\373\246\n\270\371\235\n;\371"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbe863bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\336\327R\357\277\330\361\357\256\331\211\360d\332(\361"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbe863bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "H\343#\355\233\342\317\355\377\341\312\356\216\341\250"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbe863bf0) = -1 EIO (Input/output error) write(2, "aplay: pcm_write:1268: ", 23aplay: pcm_write:1268: ) = 23 write(2Inside snd_pcm_do_stop snd_omap_alsa_trigger start audio_stop_dma start before writing to EAC_AGCTR = 60 aftere writing to EAC_AGCTR = 60 omap_stop_alsa_sound_dma end omap_clear_alsa_sound_dma start omap_clear_alsa_sound_dma end snd_omap_alsa_trigger end , "write error: Input/output errsnd_omap_alsa_hw_free start or", 31write error: Input/outputsnd_omap_alsa_hw_free end error) = 31 write(2, "\n", 1 snd_card_omap_alsa_close start ) = 1 io_omap850_audio_shutdown start submit(0x1, 0, 0x4eac_disable_clocks start eac_disable_clocks end CSMI: csmi_ctl_snd_res failed CSMI: csmi_ctl_snd failed omap850_audio_shutdown end snd_card_omap_alsa_close end <unfinished ... exit status 1> Process 586 detached
On 6/23/07, Pharaoh . pharaoh137@gmail.com wrote:
Hi
I am testing my audio driver using aplay. I trying to play an audio file using:
#aplay -Dplughw:0,0 --rate=44100 --format=S16 --channels=2 test.wav The log is as follows,
snd_card_omap_alsa_open start snd_card_omap_alsa_open end Playing WAVE 'test.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo snd_omap_alsa_hw_params start snd_omap_alsa_prepare start snd_omap_alsa_prepare end snd_omap_alsa_trigger start audio_start_dma_chain start audio_start_dma_chain end omap_start_alsa_sound_dma end snd_omap_alsa_trigger end snd_omap_alsa_pointer start audio_get_dma_pos start audio_get_dma_pos end
It waits here for sometime and then I get snd_omap_alsa_trigger starte error: Input/output error
Then the things are wound up as:
audio_stop_dma start omap_stop_alsa_sound_dma start omap_stop_alsa_sound_dma end omap_clear_alsa_sound_dma start omap_clear_alsa_sound_dma end snd_omap_alsa_trigger end
snd_omap_alsa_hw_free start snd_omap_alsa_hw_free end snd_card_omap_alsa_close start snd_card_omap_alsa_close end
So basically the problem is in trigger where it waits for something and then winds up things. Any idea, what could be the reason. I am thinking it has to do something with DMA interrupts etc.
Pharaoh . wrote:
... It waits here for sometime and then I get snd_omap_alsa_trigger starte error: Input/output error
The ALSA framework will stop the stream and return the error code EIO when there was no interrupt for ten seconds, i.e., when snd_pcm_period_elapsed() was not called.
Either s->active got corrupted, or your interrupt handler never got called.
BTW: snd_pcm_period_elapsed() can stop the stream in some situations, so you should move this call to the end of the interrupt handler, or check s->active again after calling it.
HTH Clemens
The ALSA framework will stop the stream and return the error code EIO when there was no interrupt for ten seconds, i.e., when snd_pcm_period_elapsed() was not called.
I am getting the interrupts, but why there wont be any interrupt for 10 seconds? I am setting the periods in prepare as periods = runtime->period, so interrupts should at period boundaries.
May be s->active got corrupted.
On 6/25/07, Clemens Ladisch cladisch@fastmail.net wrote:
Pharaoh . wrote:
... It waits here for sometime and then I get snd_omap_alsa_trigger starte error: Input/output error
The ALSA framework will stop the stream and return the error code EIO when there was no interrupt for ten seconds, i.e., when snd_pcm_period_elapsed() was not called.
Either s->active got corrupted, or your interrupt handler never got called.
BTW: snd_pcm_period_elapsed() can stop the stream in some situations, so you should move this call to the end of the interrupt handler, or check s->active again after calling it.
HTH Clemens
Pharaoh . wrote:
The ALSA framework will stop the stream and return the error code EIO when there was no interrupt for ten seconds, i.e., when snd_pcm_period_elapsed() was not called.
I am getting the interrupts, but why there wont be any interrupt for 10 seconds?
I don't quite understand this sentence. You do get interrupts? And snd_pcm_period_elapsed() is not called?
I am setting the periods in prepare as periods = runtime->period, so interrupts should at period boundaries.
runtime->periods is the number of periods. I don't know how your hardware works, but I guess it wants to know the period size, i.e., runtime->period_size converted to bytes.
Regards, Clemens
On 6/25/07, Clemens Ladisch cladisch@fastmail.net wrote:
Pharaoh . wrote:
The ALSA framework will stop the stream and return the error code EIO when there was no interrupt for ten seconds, i.e., when snd_pcm_period_elapsed() was not called.
I am getting the interrupts, but why there wont be any interrupt for 10 seconds?
I don't quite understand this sentence. You do get interrupts? And snd_pcm_period_elapsed() is not called?
I am setting the periods in prepare as periods = runtime->period, so interrupts should at period boundaries.
runtime->periods is the number of periods. I don't know how your hardware works, but I guess it wants to know the period size, i.e., runtime->period_size converted to bytes.
Regards, Clemens
Apologie for being ambiguous...
1. When I posted the question, I was not even getting the DMA interrupts. The input/output error was present.
2. After modifying the code a little I started getting the DMA interrupts, but the input/output error still persists. So I am doubting I might have messed up with the period size etc.
3. I am assigning s->periods = runtime->period i.e. without converting them in bytes, in prepare (I have seen some standard omap drivers doing the same, so I am not converting it to bytes, frames should be okay, but I will check this in h/w manual) and I take care in trigger too by updating the s->periods field.
4. Also, s->period is locked appropriately so dont think it is corrupted.
I am attaching the source file, I have attached only 1 file since I think it is relevant. Will send the log once I get chance to test it again.
Here is the log, it seems that the pointer function is not working. I am not supposed to use printks in many automic functions but I dont have any other debugging option.
snd_card_omap_alsa_open start
omap850_audio_init start
eac_enable_clocks start Clocks are already enabled eac_set_samplerate start
eac_set_samplerate end
audio_dma_request start omap_request_alsa_sound_dma start omap_request_alsa_sound_dma end snd_card_omap_alsa_open end Playing WAVE 'startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo snd_omap_alsa_hw_params start data format is 2 -- Channel 0 rate =2 and buffer size is ac44 snd_omap_alsa_hw_params end snd_omap_alsa_prepare start audio_configure_dma_channel start dma_size is 2000 dma_ptr is c3fa0000 snd_omap_alsa_prepare end SNDRV_PCM_IOCTL1_RESET Inside snd_pcm_lib_ioctl_reset Inside snd_pcm_do_start snd_omap_alsa_trigger start audio_set_dma_params_play start audio_set_dma_params_play end audio_start_dma_chain start Inside omap_start_dma 1 Inside omap_start_dma 2 Inside omap_start_dma 3 audio_start_dma_chain end Reading from c4954180 snd_omap_alsa_trigger end sound_dma_irq_handler start !!! In DMA IRQ handler lch=0,status=0x20, dma_status=32, data=c3cb5104 callback_omap_alsa_sound_dma start Inside /snd_pcm_period_elapsed Inside snd_pcm_update_hw_ptr_interrupt Inside snd_pcm_update_hw_ptr_pos snd_omap_alsa_pointer start audio stream->offset is 1000000 runtime->framebits is 20 Count is 8192 Offset is 4192256 and buffer size is 16384 Inside snd_pcm_update_hw_ptr_pos, pos is 0 audio_set_dma_params_play start audio_set_dma_params_play end audio_start_dma_chain start audio_start_dma_chain end Reading from c4954180 sound_dma_irq_handler end
Inside snd_pcm_update_hw_ptr_pos snd_omap_alsa_pointer start audio stream->offset is 2000 runtime->framebits is 20 Count is 8192 Offset is 0 and buffer size is 16384 Inside snd_pcm_update_hw_ptr_pos, pos is 0 /*Is waits here for sometime and then following error*/
Inside snd_pcm_do_stop write error: Input/output error
snd_omap_alsa_trigger start audio_stop_dma start omap_stop_alsa_sound_dma end omap_clear_alsa_sound_dma start omap_clear_alsa_sound_dma end snd_omap_alsa_trigger end
snd_omap_alsa_hw_free start snd_omap_alsa_hw_free end snd_card_omap_alsa_close start omap850_audio_shutdown start
eac_disable_clocks start eac_disable_clocks end omap850_audio_shutdown end audio_dma_free start omap_free_alsa_sound_dma start omap_sound_dma_unlink_lch start omap_sound_dma_unlink_lch end omap_free_alsa_sound_dma end snd_card_omap_alsa_close end
And detailed log using strace
# strace aplay -Dplughw:0,0 --rate=44100 --format=S16 --channels=2 startup.wav execve("/usr/local/bin/aplay", ["aplay", "-Dplughw:0,0", "--rate=44100", "--format=S16", "--channels=2", "startup.wav"], [/* 7 vars */]) = 0 uname({sys="Linux", node="192.168.200.217", ...}) = 0 brk(0) = 0x20000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0777, st_size=12436, ...}) = 0 mmap2(NULL, 12436, PROT_READ, MAP_PRIVATE, 3, 0) = 0x40015000 close(3) = 0 open("/usr/local/lib/libasound.so.2", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\314\353\1"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0777, st_size=2164893, ...}) = 0 mmap2(NULL, 777620, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x4001e000 mprotect(0x400d0000, 48532, PROT_NONE) = 0 mmap2(0x400d8000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xb2) = 0x400d8000 close(3) = 0 open("/lib/libm.so.6", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\00003\0\000"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0777, st_size=778699, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40019000 mmap2(NULL, 713068, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x400dc000 mprotect(0x40182000, 33132, PROT_NONE) = 0 mmap2(0x40189000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xa5) = 0x40189000 close(3) = 0 open("/lib/libdl.so.2", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\344\v\0\000"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0777, st_size=16868, ...}) = 0 mmap2(NULL, 41152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x4018b000 mprotect(0x4018d000, 32960, PROT_NONE) = 0 mmap2(0x40194000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1) = 0x40194000 close(3) = 0 open("/lib/libpthread.so.0", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0p?\0\0004"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0777, st_size=99172, ...}) = 0 mmap2(NULL, 367928, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x40196000 mprotect(0x401a5000, 306488, PROT_NONE) = 0 mmap2(0x401ac000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xe) = 0x401ac000 mmap2(0x401ae000, 269624, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x401ae000 close(3) = 0 open("/lib/libc.so.6", O_RDONLY) = 3 read(3, "\177ELF\1\1\1a\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0HM\1\0004"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0777, st_size=1424946, ...}) = 0 mmap2(NULL, 1132932, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x401f0000 mprotect(0x402f7000, 55684, PROT_NONE) = 0 mmap2(0x402ff000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x107) = 0x402ff000 mmap2(0x40303000, 6532, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40303000 close(3) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x4001a000 mprotect(0x402ff000, 8192, PROT_READ) = 0 mprotect(0x401ac000, 4096, PROT_READ) = 0 mprotect(0x40194000, 4096, PROT_READ) = 0 mprotect(0x40189000, 4096, PROT_READ) = 0 mprotect(0x4001c000, 4096, PROT_READ) = 0 munmap(0x40015000, 12436) = 0 getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM_INFINITY}) = 0 setrlimit(RLIMIT_STACK, {rlim_cur=2044*1024, rlim_max=RLIM_INFINITY}) = 0 getpid() = 613 rt_sigaction(SIGRTMIN, {0x4019e980, [], 0x4000000 /* SA_??? */}, NULL, 8) = 0 rt_sigaction(SIGRT_1, {0x4019ea3c, [RTMIN], 0x4000000 /* SA_??? */}, NULL, 8) = 0 rt_sigaction(SIGRT_2, {0x4019eba8, [], 0x4000000 /* SA_??? */}, NULL, 8) = 0 rt_sigprocmask(SIG_BLOCK, [RTMIN], NULL, 8) = 0 rt_sigprocmask(SIG_UNBLOCK, [RT_1], NULL, 8) = 0 _sysctl({{CTL_KERN, KERN_VERSION}, 2, 0xbed04ad8, 40, (nil), 0}) = 0 brk(0) = 0x20000 brk(0x41000) = 0x41000 stat64("/usr/local/share/alsa/alsa.conf", {st_mode=S_IFREG|0777, st_size=7764, ...}) = 0 open("/usr/local/share/alsa/alsa.conf", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0777, st_size=7764, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40015000 read(3, "#\n# ALSA library configuration "..., 4096) = 4096 read(3, "cards.pcm.surround40\npcm.surroun"..., 4096) = 3668 read(3, "", 4096) = 0 read(3, "", 4096) = 0 close(3) = 0 munmap(0x40015000, 4096) = 0 access("/etc/asound.conf", R_OK) = 0 open("/etc/asound.conf", O_RDONLY) = 3 fstat64(3, {st_mode=S_IFREG|0777, st_size=690, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40015000 read(3, "pcm.headset {\n\t@args [BDADDR TIM"..., 4096) = 690 read(3, "", 4096) = 0 read(3, "", 4096) = 0 close(3) = 0 munmap(0x40015000, 4096) = 0 access("//.asoundrc", R_OK) = -1 ENOENT (No such file or directory) open("/dev/snd/controlC0", O_RDONLY) = 3 close(3) = 0 open("/dev/snd/controlC0", O_RDWR) = 3 ioctl(3, USBDEVFS_CONTROL, 0xbed04874) = 0 ioctl(3, 0x4snd_card_omap_alsa_open start eac->base = c4954000 = 0
open("/dev/snd/pcmC0D0p", O_RDWBefore audio init R|O_NONBLOCKomap850_audio_init start eac_enable_clocks start Clocks are already enabled eac_set_samplerate start Reading from c4954178 eac_set_samplerate end after audio init audio_dma_request start omap_request_alsa_sound_dma start omap_request_alsa_sound_dma end snd_card_omap_alsa_open end ) = 4 close(3) = 0 ioctl(4, AGPIOC_ACQUIRE or APM_IOC_STANDBY, 0xbed04778) = 0 fcntl64(4, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) ioctl(4, AGPIOC_INFO, 0xbed046f0) = 0 ioctl(4, AGPIOC_RELEASE or APM_IOC_SUSPEND, 0xbed046ec) = 0 mmap2(NULL, 4096, PROT_READ, MAP_SHARED, 4, 0x80000) = -1 ENXIO (No such device or address) ioctl(4, 0xc0844123, 0xbed046f4) = 0 fcntl64(4, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK) fcntl64(4, F_SETFL, O_RDWR) = 0 ioctl(4, AGPIOC_ACQUIRE or APM_IOC_STANDBY, 0xbed04ccc) = 0 rt_sigaction(SIGINT, {0x401a28ac, [INT], SA_RESTART|0x4000000}, {SIG_DFL}, 8) = 0 rt_sigaction(SIGTERM, {0x401a28ac, [TERM], SA_RESTART|0x4000000}, {SIG_DFL}, 8) = 0 rt_sigaction(SIGABRT, {0x401a28ac, [ABRT], SA_RESTART|0x4000000}, {SIG_DFL}, 8) = 0 open("startup.wav", O_RDONLY|O_LARGEFILE) = 3 read(3, "RIFF(\310\24\0WAVEfmt \20\0\0\0\1\0\2\0", 24) = 24 read(3, "D\254\0\0", 4) = 4 read(3, "\20\261\2\0\4\0\20\0", 8) = 8 read(3, "data\4\310\24\0", 8) = 8 write(2, "Playing WAVE 'startup.wav' : ", 29Playing WAVE 'startup.wav' : ) = 29 write(2, "Signed 16 bit Little Endian, ", 29Signed 16 bit Little Endian, ) = 29 write(2, "Rate 44100 Hz, ", 15Rate 44100 Hz, ) = 15 write(2, "Stereo", 6Stereo) = 6 write(2, "\n", 1 ) = 1 ioctl(4, 0xc25c4110, 0xbed045f4) = 0 ioctl(4, 0xc25c4110, 0xbed042e8) = 0 ioctl(4, 0xc25c4110, 0xbed042e8) = 0 ioctl(4, 0xc25c4110, 0xbed045f4) = 0 ioctl(4, 0xc25c4110, 0xbed042e8) = 0 ioctl(4, 0xc25c4110, 0xbed042e8) = 0 ioctl(4, 0xc25c4110, 0xbed045f4) = 0 ioctl(4, 0xc25c4110, 0xbed04368) = 0 ioctl(4, 0xc25c4110, 0xbed0405c) = 0 ioctl(4, 0xc25c4110, 0xbed0405c) = 0 ioctl(4, 0xc25c4110, 0xbed04368) = 0 ioctl(4, 0xc25c4110, 0xbed04368) = 0 ioctl(4, 0xc25c4110, 0xbed0405c) = 0 ioctl(4, 0xc25c4110, 0xbed0405c) = 0 ioctl(4, 0xc25c4110, 0xbed04368) = 0 ioctl(4, 0xc25c4110snd_omap_alsa_hw_params start , 0xbed0405c) = 0 ioctl(data format is 2 -- Channel 0 rate =2 and buffer size is ac44 4, 0xc25c4110, 0xbed0405c) snd_omap_alsa_hw_params end = 0 ioctl(4, 0xc25c4110, 0xbed04368) = 0 snd_omap_alsa_prepare start4368) = 0
ioctl(4, 0xc25c4110, 0xbed0405caudio_configure_dma_channel start ) = 0 ioctl(4, 0xc25c411dma_size is 2000 0, 0xbed0405c) = 0 ioctldma_ptr is c3f20000 (4, 0xc25c4110, 0xbed04368) snd_omap_alsa_prepare end = 0 ioctl(4, 0xc25c4110, 0xbSNDRV_PCM_IOCTL1_RESET ed0405c) = 0 ioctl(4, 0xInside snd_pcm_lib_ioctl_reset c25c4110, 0xbed0405c) = 0 ioctl(4, 0xc25c4110, 0xbed04368) = 0 ioctl(4, 0xc25c4110, 0xbed03e6c) = 0 ioctl(4, 0xc25c4110, 0xbed03b60) = 0 ioctl(4, 0xc25c4110, 0xbed03b60) = 0 ioctl(4, 0xc25c4110, 0xbed03e6c) = 0 ioctl(4, 0xc25c4110, 0xbed03b60) = 0 ioctl(4, 0xc25c4110, 0xbed03b60) = 0 ioctl(4, 0xc25c4110, 0xbed03e6c) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed040d4) = 0 ioctl(4, 0xc25c4110, 0xbed04564) = 0 ioctl(4, 0xc25c4110, 0xbed04564) = 0 ioctl(4, 0xc25c4110, 0xbed04564) = 0 ioctl(4, 0xc25c4110, 0xbed04564) = 0 ioctl(4, 0xc25c4110, 0xbed04564) = 0 ioctl(4, 0xc25c4110, 0xbed04904) = 0 ioctl(4, 0xc25c4111, 0xbed04904) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 ioctl(4, 0xc0684113, 0xbed044c4) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 ioctl(4, 0x4140, 0x400c3ed4) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 ioctl(4, 0xc0684113, 0xbed04898) = 0 read(3, "\377\377\0\0\0\0\0\0\1\0\0\0\0\0\0\0\0\0\1\0\0\0\0\0\1"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbed04bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\377\377\0\0\1\0\0\0\0\0\0\0\377\377\376\377\0\0\3\0\377"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbed04bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\374\377\7\0\0\0\0\0\372\377\0\0\376\377\3\0\3\0\373\377"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbed04bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\373\377\1\0\377\377\5\0\376\377\372\377\377\377\7\0\6"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbed04bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\212\377{\377\212\377\210\377\220\377\226\377\214\377\213"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbed04bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, ".\324\326\3438\323Q\343\375\322\34\343\254\323\223\343"..., 8192) = 8192 ioctl(4, 0x400c4150, 0xbed04bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "\2\fK\0x\v\220\375\361\n_\373\246\n\270\371\235\n;\Inside snd_pcm_do_start snd_omap_alsa_trigger start audio_set_dma_params_play start audio_set_dma_params_play end audio_start_dma_chain start Inside omap_start_dma 1 Inside omap_start_dma 2 Inside omap_start_dma 3 audio_start_dma_chain end Reading from c4954180 snd_omap_alsa_trigger end 371"..., 8192) = 8192 ioctl(4, sound_dma_irq_handler start 0x400c4150, 0xbed04bf0) =!!! In DMA IRQ handler lch=0,status=0x20, dma_status=32, data=c3cb9884 0 ioctl(4, 0xc0844123, 0x27e10callback_omap_alsa_sound_dma start ) = 0 read(3, "\336\3Inside /snd_pcm_period_elapsed 27R\357\277\330\361\357\256\331\Inside snd_pcm_update_hw_ptr_interrupt Inside snd_pcm_update_hw_ptr_pos snd_omap_alsa_pointer start audio stream->offset is 1000000 runtime->framebits is 20 Count is 8192 Offset is 4192256 and buffer size is 16384 Inside snd_pcm_update_hw_ptr_pos, pos is 0 211\360d\332(\361"..., 8192) = 8audio_set_dma_params_play start 192 ioctl(4, 0x400c4150audio_set_dma_params_play end audio_start_dma_chain start audio_start_dma_chain end Reading from c4954180 sound_dma_irq_handler end , 0xbed04bf0) = 0 ioctl(4, 0xc0844123, 0x27e10) = 0 read(3, "H\343#\3Inside snd_pcm_update_hw_ptr_pos snd_omap_alsa_pointer start audio stream->offset is 2000 runtime->framebits is 20 Count is 8192 Offset is 0 and buffer size is 16384 Inside snd_pcm_update_hw_ptr_pos, pos is 0 55\233\342\317\355\377\341\312\356\216\341\250"..., 8192) = 8192 ioctl(4, 0x400c4150
/**********waits here **************/ 0xbed04bf0) = -1 EIO (Input/output error) write(2, "aplay: pcm_write:1268: ", 23aplay: pcm_write:1268: ) = 23 write(2Inside snd_pcm_do_stop snd_omap_alsa_trigger start audio_stop_dma start Reading from c4954180 before writing to EAC_AGCTR = 60 aftere writing to EAC_AGCTR = 60 omap_stop_alsa_sound_dma end omap_clear_alsa_sound_dma start omap_clear_alsa_sound_dma end snd_omap_alsa_trigger end , "write error: Input/output errsnd_omap_alsa_hw_free start or", 31write error: Input/outputsnd_omap_alsa_hw_free end error) = 31 write(2, "\n", 1 snd_card_omap_alsa_close start ) = 1 io_omap850_audio_shutdown start submit(0x1, 0, 0x4Reading from c4954180 eac_disable_clocks start eac_disable_clocks end
omap850_audio_shutdown end audio_dma_free start omap_free_alsa_sound_dma start omap_sound_dma_unlink_lch start omap_sound_dma_unlink_lch end omap_free_alsa_sound_dma end snd_card_omap_alsa_close end <unfinished ... exit status 1> Process 613 detached
On 6/25/07, Pharaoh . pharaoh137@gmail.com wrote:
On 6/25/07, Clemens Ladisch cladisch@fastmail.net wrote:
Pharaoh . wrote:
The ALSA framework will stop the stream and return the error code EIO when there was no interrupt for ten seconds, i.e., when snd_pcm_period_elapsed() was not called.
I am getting the interrupts, but why there wont be any interrupt for 10 seconds?
I don't quite understand this sentence. You do get interrupts? And snd_pcm_period_elapsed() is not called?
I am setting the periods in prepare as periods = runtime->period, so interrupts should at period boundaries.
runtime->periods is the number of periods. I don't know how your hardware works, but I guess it wants to know the period size, i.e., runtime->period_size converted to bytes.
Regards, Clemens
Apologie for being ambiguous...
- When I posted the question, I was not even getting the DMA
interrupts. The input/output error was present.
- After modifying the code a little I started getting the DMA
interrupts, but the input/output error still persists. So I am doubting I might have messed up with the period size etc.
- I am assigning s->periods = runtime->period i.e. without converting
them in bytes, in prepare (I have seen some standard omap drivers doing the same, so I am not converting it to bytes, frames should be okay, but I will check this in h/w manual) and I take care in trigger too by updating the s->periods field.
- Also, s->period is locked appropriately so dont think it is corrupted.
I am attaching the source file, I have attached only 1 file since I think it is relevant. Will send the log once I get chance to test it again.
I am pruning the logs in previous e-mails here since its becoming too lengthy to read. After rewriting the pointer function I am not getting the input/output error but I am getting underruns. I think I am little closer to the working driver now, am I?
here is the log, after getting couple of underrun error messages the dma just gets halted.
Log:
snd_card_omap_alsa_open start
eac_enable_clocks start Clocks are already enabled eac_set_samplerate start
eac_set_samplerate end after audio init audio_dma_request start omap_request_alsa_sound_dma start omap_request_alsa_sound_dma end snd_card_omap_alsa_open end Playing WAVE 'startup.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo snd_omap_alsa_hw_params start data format is 2 -- Channel 0 rate =2 and buffer size is ac44 snd_omap_alsa_hw_params end snd_omap_alsa_prepare start audio_configure_dma_channel start dma_size is 2000 dma_ptr is c3540000 snd_omap_alsa_prepare end SNDRV_PCM_IOCTL1_RESET Inside snd_pcm_lib_ioctl_reset Inside snd_pcm_do_start snd_omap_alsa_trigger start audio_set_dma_params_play start audio_set_dma_params_play end audio_start_dma_chain start /*These are the platform specific dma setup routines*/ Inside omap_start_dma 1 Inside omap_start_dma 2 Inside omap_start_dma 3 audio_start_dma_chain end snd_omap_alsa_trigger end sound_dma_irq_handler start !!! In DMA IRQ handler lch=0,status=0x20, dma_status=32, data=c3cb5704 callback_omap_alsa_sound_dma start Inside /snd_pcm_period_elapsed Inside snd_pcm_update_hw_ptr_interrupt Inside snd_pcm_update_hw_ptr_pos snd_omap_alsa_pointer start Inside snd_pcm_update_hw_ptr_pos, pos is 18153472 /**Here is a BUG**/ ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x1150000, buffer size = 0x4000, period size = 0x800 Inside snd_pcm_do_stop snd_omap_alsa_trigger start audio_stop_dma start omap_stop_alsa_sound_dma end omap_clear_alsa_sound_dma start omap_clear_alsa_sound_dma end snd_omap_alsa_trigger end Not active sound_dma_irq_handler end Inside snd_pcm_status /***Under run here ****/ underrun!!! (at least -33.431 mssnd_omap_alsa_prepare start long) audio_configure_dma_channel start dma_size is 2000 dma_ptr is c3540000 snd_omap_alsa_prepare end SNDRV_PCM_IOCTL1_RESET Inside snd_pcm_lib_ioctl_reset Inside snd_pcm_do_start snd_omap_alsa_trigger start audio_set_dma_params_play start audio_set_dma_params_play end audio_start_dma_chain start Inside omap_start_dma 1 Inside omap_start_dma 2 Inside omap_start_dma 3 audio_start_dma_chain end snd_omap_alsa_trigger end sound_dma_irq_handler start !!! In DMA IRQ handler lch=0,status=0x20, dma_status=32, data=c3cb5704 callback_omap_alsa_sound_dma start Inside /snd_pcm_period_elapsed Inside snd_pcm_update_hw_ptr_interrupt Inside snd_pcm_update_hw_ptr_pos snd_omap_alsa_pointer start Inside snd_pcm_update_hw_ptr_pos, pos is 18153472
/***Bug ***/ ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x1150000, buffer size = 0x4000, period size = 0x800 Inside snd_pcm_do_stop snd_omap_alsa_trigger start audio_stop_dma start omap_stop_alsa_sound_dma end omap_clear_alsa_sound_dma start omap_clear_alsa_sound_dma end snd_omap_alsa_trigger end Not active sound_dma_irq_handler end Inside snd_pcm_status /***underrun***/ underrun!!! (at least -33.633 mssnd_omap_alsa_prepare start long) audio_configure_dma_channel start dma_size is 2000 dma_ptr is c3540000 snd_omap_alsa_prepare end SNDRV_PCM_IOCTL1_RESET Inside snd_pcm_lib_ioctl_reset Inside snd_pcm_do_start snd_omap_alsa_trigger start audio_set_dma_params_play start audio_set_dma_params_play end audio_start_dma_chain start Inside omap_start_dma 1 Inside omap_start_dma 2 Inside omap_start_dma 3 audio_start_dma_chain end snd_omap_alsa_trigger end sound_dma_irq_handler start !!! In DMA IRQ handler lch=0,status=0x20, dma_status=32, data=c3cb5704 callback_omap_alsa_sound_dma start Inside /snd_pcm_period_elapsed Inside snd_pcm_update_hw_ptr_interrupt Inside snd_pcm_update_hw_ptr_pos snd_omap_alsa_pointer start Inside snd_pcm_update_hw_ptr_pos, pos is 18153472 /***BUG**/ ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x1150000, buffer size = 0x4000, period size = 0x800 Inside snd_pcm_do_stop snd_omap_alsa_trigger start audio_stop_dma start omap_stop_alsa_sound_dma end omap_clear_alsa_sound_dma start omap_clear_alsa_sound_dma end snd_omap_alsa_trigger end Not active sound_dma_irq_handler end Inside snd_pcm_status /***Underrun**/ underrun!!! (at least -33.759 mssnd_omap_alsa_prepare start long) audio_configure_dma_channel start dma_size is 2000 dma_ptr is c3540000 snd_omap_alsa_prepare end SNDRV_PCM_IOCTL1_RESET Inside snd_pcm_lib_ioctl_reset Inside snd_pcm_do_start snd_omap_alsa_trigger start audio_set_dma_params_play start audio_set_dma_params_play end audio_start_dma_chain start Inside omap_start_dma 1 Inside omap_start_dma 2
/******It hangs here, the dma halts here and no further messages are shown*******/
Pharaoh . wrote:
After rewriting the pointer function
It would really help if you'd show us the code of the version of the driver that you're currently talking about.
I am not getting the input/output error but I am getting underruns. ... ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x1150000, buffer size = 0x4000, period size = 0x800
Here, "pos" is the value returned by your pointer callback. This value should have been a frame number somewhere in the buffer, i.e., in the range 0..0x3fff. Apparently, the pointer callback doesn't correctly calculate this value.
Please remove most printk()s, and add some in the pointer callback to show both the value that you get from the DMA controller, and the value that this function returns.
Regards, Clemens
It would really help if you'd show us the code of the version of the driver that you're currently talking about.
Hi Clemens...
I had sent you the source file having pcm callbacks yesterday, now I have modified the pointer function as follows, I am just giving the pointer function here to avoid duplication, but please let me know in case you want to have look at the entire file.
static snd_pcm_uframes_t snd_omap_alsa_pointer(snd_pcm_substream_t *substream) {
struct omap_eac *chip = snd_pcm_substream_chip(substream); snd_pcm_uframes_t pos = 0;
FN_ENTER; pos = audio_get_dma_pos(&chip->s[substream->pstr->stream]); printk("Returning pos = %d\n", pos); return pos; FN_EXIT; }
static snd_pcm_uframes_t audio_get_dma_pos(struct audio_stream *s) { snd_pcm_substream_t *substream = s->stream; snd_pcm_runtime_t *runtime = substream->runtime; unsigned long flags; dma_addr_t count; unsigned long offset; dma_addr_t src,dest;
if (substream->stream == SNDRV_PCM_STREAM_CAPTURE) { dest = omap_get_dma_dst_pos(s->lch[s->dma_q_head]); offset = dest - runtime->dma_addr; printk("dest is %u and offset is %u\n",dest,offset); } else { src = omap_get_dma_src_pos(s->lch[s->dma_q_head]); offset = src - runtime->dma_addr; printk("src is %u and offset is %u\n",dest,offset); }
return bytes_to_frames(substream->runtime, offset); }
And the log is as follows.
For the first time.
snd_omap_alsa_pointer start src is 3246792928 and offset is 3304194048 Returning pos = 20742144 Inside snd_pcm_update_hw_ptr_pos, pos is 20742144 ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x13c8000, buffer size = 0x4000, period size = 0x800 returning pos 20742144
I can see things are horribaly wrong here....
On 6/26/07, Clemens Ladisch cladisch@fastmail.net wrote:
Pharaoh . wrote:
After rewriting the pointer function
It would really help if you'd show us the code of the version of the driver that you're currently talking about.
I am not getting the input/output error but I am getting underruns. ... ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x1150000, buffer
size = 0x4000, period size = 0x800
Here, "pos" is the value returned by your pointer callback. This value should have been a frame number somewhere in the buffer, i.e., in the range 0..0x3fff. Apparently, the pointer callback doesn't correctly calculate this value.
Please remove most printk()s, and add some in the pointer callback to show both the value that you get from the DMA controller, and the value that this function returns.
Regards, Clemens
wait..wait.....I need to use locking here...let me send you log after doing locking appropriately .....
On 6/26/07, Pharaoh . pharaoh137@gmail.com wrote:
It would really help if you'd show us the code of the version of the driver that you're currently talking about.
Hi Clemens...
I had sent you the source file having pcm callbacks yesterday, now I have modified the pointer function as follows, I am just giving the pointer function here to avoid duplication, but please let me know in case you want to have look at the entire file.
static snd_pcm_uframes_t snd_omap_alsa_pointer(snd_pcm_substream_t *substream) {
struct omap_eac *chip = snd_pcm_substream_chip(substream); snd_pcm_uframes_t pos = 0; FN_ENTER; pos = audio_get_dma_pos(&chip->s[substream->pstr->stream]); printk("Returning pos = %d\n", pos); return pos; FN_EXIT;}
static snd_pcm_uframes_t audio_get_dma_pos(struct audio_stream *s) { snd_pcm_substream_t *substream = s->stream; snd_pcm_runtime_t *runtime = substream->runtime; unsigned long flags; dma_addr_t count; unsigned long offset; dma_addr_t src,dest;
if (substream->stream == SNDRV_PCM_STREAM_CAPTURE) { dest = omap_get_dma_dst_pos(s->lch[s->dma_q_head]); offset = dest - runtime->dma_addr; printk("dest is %u and offset is %u\n",dest,offset); } else { src = omap_get_dma_src_pos(s->lch[s->dma_q_head]); offset = src - runtime->dma_addr; printk("src is %u and offset is %u\n",dest,offset); } return bytes_to_frames(substream->runtime, offset);}
And the log is as follows.
For the first time.
snd_omap_alsa_pointer start src is 3246792928 and offset is 3304194048 Returning pos = 20742144 Inside snd_pcm_update_hw_ptr_pos, pos is 20742144 ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x13c8000, buffer size = 0x4000, period size = 0x800 returning pos 20742144
I can see things are horribaly wrong here....
On 6/26/07, Clemens Ladisch cladisch@fastmail.net wrote:
Pharaoh . wrote:
After rewriting the pointer function
It would really help if you'd show us the code of the version of the driver that you're currently talking about.
I am not getting the input/output error but I am getting underruns. ... ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x1150000, buffer
size = 0x4000, period size = 0x800
Here, "pos" is the value returned by your pointer callback. This value should have been a frame number somewhere in the buffer, i.e., in the range 0..0x3fff. Apparently, the pointer callback doesn't correctly calculate this value.
Please remove most printk()s, and add some in the pointer callback to show both the value that you get from the DMA controller, and the value that this function returns.
Regards, Clemens
static snd_pcm_uframes_t audio_get_dma_pos(struct audio_stream *s) { snd_pcm_substream_t *substream = s->stream; snd_pcm_runtime_t *runtime = substream->runtime; unsigned long flags; dma_addr_t count; unsigned long offset; dma_addr_t src,dest;
if (substream->stream == SNDRV_PCM_STREAM_CAPTURE) { spin_lock_irqsave(&s->dma_lock, flags); dest = omap_get_dma_dst_pos(s->lch[s->dma_q_head]); offset = dest - runtime->dma_addr; spin_unlock_irqrestore(&s->dma_lock, flags); printk("dest is %u and offset is %u\n",dest,offset); } else { spin_lock_irqsave(&s->dma_lock, flags); src = omap_get_dma_src_pos(s->lch[s->dma_q_head]); offset = src - runtime->dma_addr; spin_unlock_irqrestore(&s->dma_lock, flags); printk("src is %u and offset is %u\n",dest,offset); }
return bytes_to_frames(substream->runtime, offset); }
and the log is as same....still no joy..
First time
snd_omap_alsa_pointer start src is 3246792928 and offset is 3296722944 Returning pos = 18874368 Inside snd_pcm_update_hw_ptr_pos, pos is 18874368 ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x1200000, buffer size = 0x4000, period size = 0x800 returning pos 18874368
....... ....... Second time
snd_omap_alsa_pointer start src is 3246792928 and offset is 3296722944 Returning pos = 18874368 Inside snd_pcm_update_hw_ptr_pos, pos is 18874368 ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x1200000, buffer size = 0x4000, period size = 0x800 returning pos 18874368
......
then it hangs in the omap_request_dma function.
On 6/26/07, Pharaoh . pharaoh137@gmail.com wrote:
wait..wait.....I need to use locking here...let me send you log after doing locking appropriately .....
On 6/26/07, Pharaoh . pharaoh137@gmail.com wrote:
It would really help if you'd show us the code of the version of the driver that you're currently talking about.
Hi Clemens...
I had sent you the source file having pcm callbacks yesterday, now I have modified the pointer function as follows, I am just giving the pointer function here to avoid duplication, but please let me know in case you want to have look at the entire file.
static snd_pcm_uframes_t snd_omap_alsa_pointer(snd_pcm_substream_t *substream) {
struct omap_eac *chip = snd_pcm_substream_chip(substream); snd_pcm_uframes_t pos = 0; FN_ENTER; pos = audio_get_dma_pos(&chip->s[substream->pstr->stream]); printk("Returning pos = %d\n", pos); return pos; FN_EXIT;}
static snd_pcm_uframes_t audio_get_dma_pos(struct audio_stream *s) { snd_pcm_substream_t *substream = s->stream; snd_pcm_runtime_t *runtime = substream->runtime; unsigned long flags; dma_addr_t count; unsigned long offset; dma_addr_t src,dest;
if (substream->stream == SNDRV_PCM_STREAM_CAPTURE) { dest = omap_get_dma_dst_pos(s->lch[s->dma_q_head]); offset = dest - runtime->dma_addr; printk("dest is %u and offset is %u\n",dest,offset); } else { src = omap_get_dma_src_pos(s->lch[s->dma_q_head]); offset = src - runtime->dma_addr; printk("src is %u and offset is %u\n",dest,offset); } return bytes_to_frames(substream->runtime, offset);}
And the log is as follows.
For the first time.
snd_omap_alsa_pointer start src is 3246792928 and offset is 3304194048 Returning pos = 20742144 Inside snd_pcm_update_hw_ptr_pos, pos is 20742144 ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x13c8000, buffer size = 0x4000, period size = 0x800 returning pos 20742144
I can see things are horribaly wrong here....
On 6/26/07, Clemens Ladisch cladisch@fastmail.net wrote:
Pharaoh . wrote:
After rewriting the pointer function
It would really help if you'd show us the code of the version of the driver that you're currently talking about.
I am not getting the input/output error but I am getting underruns. ... ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x1150000,
buffer
size = 0x4000, period size = 0x800
Here, "pos" is the value returned by your pointer callback. This value should have been a frame number somewhere in the buffer, i.e., in the range 0..0x3fff. Apparently, the pointer callback doesn't correctly calculate this value.
Please remove most printk()s, and add some in the pointer callback to show both the value that you get from the DMA controller, and the value that this function returns.
Regards, Clemens
Pharaoh . wrote:
src = omap_get_dma_src_pos(s->lch[s->dma_q_head]); offset = src - runtime->dma_addr; printk("src is %u and offset is %u\n",dest,offset);src is 3246792928 and offset is 3304194048 Returning pos = 20742144 ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x13c8000, buffer size = 0x4000, period size = 0x800
dma_addr = 0xFC9420E0 (is this correct?) src = 0xC18620E0 offset = 0xC4F20000
Apparently, the return value of omap_get_dma_src_pos() is wrong. Should this value be 16 bits?
Regards, Clemens
As per the plat-omap/dma.c the function is like this:
/* * Returns current physical source address for the given DMA channel. * If the channel is running the caller must disable interrupts prior calling * this function and process the returned value before re-enabling interrupt to * prevent races with the interrupt handler. Note that in continuous mode there * is a chance for CSSA_L register overflow inbetween the two reads resulting * in incorrect return value. */ dma_addr_t omap_get_dma_src_pos(int lch) { dma_addr_t offset;
if (cpu_class_is_omap1()) offset = (dma_addr_t) (OMAP1_DMA_CSSA_L_REG(lch) | (OMAP1_DMA_CSSA_U_REG(lch) << 16));
if (cpu_is_omap24xx()) offset = OMAP_DMA_CSAC_REG(lch);
return offset; }
I have one doubt here, I am referring Writing ALSA driver by Takashi it says following about the dma_addr_t.
If you use a standard ALSA function, snd_pcm_lib_malloc_pages(), for allocating the buffer, these fields are set by the ALSA middle layer, and you should not change them by yourself.
I am using the standard helper function to allocate the DMA buffer in my hw_params, so I am not setting the runtime->dma_addr field, pcm layer must be setting it, right?
But in my pointer function I am accessing runtime->dma_addr where as the guide says it is i.e the physical bus address is not accessible from the main CPU. I am doing wrong accessing it?
After allocating the buffer in hw_params i am trying to check the physical and virtual addr of the DMA buffer, I get
Physical DMA addr is 00000000 and virtual addr is c3540000
does it mean that dma_addr is really not accessible from main CPU?
In pointer when I check the dma addr I get
runtime->dma_addr is 00000000 !!
How come??
-pharaoh.
On 6/26/07, Clemens Ladisch cladisch@fastmail.net wrote:
Pharaoh . wrote:
src = omap_get_dma_src_pos(s->lch[s->dma_q_head]); offset = src - runtime->dma_addr; printk("src is %u and offset is %u\n",dest,offset);src is 3246792928 and offset is 3304194048 Returning pos = 20742144 ALSA sound/core/pcm_lib.c:167: BUG: stream = 0, pos = 0x13c8000, buffer
size = 0x4000, period size = 0x800
dma_addr = 0xFC9420E0 (is this correct?) src = 0xC18620E0 offset = 0xC4F20000
Apparently, the return value of omap_get_dma_src_pos() is wrong. Should this value be 16 bits?
Regards, Clemens
participants (2)
-
Clemens Ladisch -
Pharaoh .