Drop outs in i2s data playing mp3 from sdcard
Posted: Mon Aug 24, 2020 5:03 am
I'm getting dropouts of about 20ms every 3 to 8 seconds (not regular) when playing an mp3 file read from the sdcard (spi mode). I'm not seeing any warnings or errors in the log while it is playing. I have wifi and networking turned off for now although when it was on requesting resources from the http server did not seem to induce the problem. The only other things going on are some interrupts for handling buttons, LED flashing and some longer period timers (about 10s or more). Does anyone have any clever ideas about how to diagnose this? I just updated from IDF 1.3 to the latest IDF and ADF and this is a regression I'm trying to fix.
Here is a sample of the log while playing (level Info):
W (2845487) I2S: I2S driver already installed
I (2845487) MP3_DECODER: MP3 init
I (2845487) AUDIO_PIPELINE: link el->rb, el:0x3ffca1b4, tag:mp3, rb:0x3ffca578
I (2845497) AUDIO_ELEMENT: [i2s-0x3ffc69f4] Element task created
I (2845497) AUDIO_ELEMENT: [mp3-0x3ffca1b4] Element task created
I (2845507) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:358, MEM Total:198548 Bytes
I (2845517) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:1
I (2845517) I2S_STREAM: AUDIO_STREAM_WRITER
I (2845527) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = IDLE
I (2845527) AUDIO_ELEMENT: [mp3] AEL_MSG_CMD_RESUME,state:1
I (2845537) MP3_DECODER: MP3 opened
I (2845537) AUDIO_PIPELINE: Pipeline started
W (2845547) MUSICLOG: Logged play 0,.,0
I (2845557) LED: Setting led to 0x402 with repeat:1
I (2845567) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = PLAYING
W (2845567) MUSIC_AEL: Other cmd received from mp3 decoder: 8
I (2845587) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = PLAYING
I (2845587) MUSIC: Got message: UNKNOWN!, In state: PLAYING
I (2845587) MUSIC: Got message: UNKNOWN!, In state: PLAYING
I (2845597) MUSIC: Received music info from mp3 decoder, sample_rate=44100, bits=16, ch=1
I (2845607) AMP: Set sample rate 7
I (2845677) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_PAUSE
I (2845677) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = PLAYING
I (2845727) I2S: APLL: Req RATE: 44100, real rate: 44099.988, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 11289597.000, SCLK: 1411199.625000, diva: 1, divb: 0
W (2845737) AUDIO_ELEMENT: [i2s] RESUME timeout
I (2845737) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:3
I (2845747) I2S_STREAM: AUDIO_STREAM_WRITER
I (2845747) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = PLAYING
I (2851647) BEAKBOX: The current date/time is: Wed Dec 31 12:47:37 1969
I (2851647) BEAKBOX: HEAP Available:163720, Largest:113792, Min:162288
I (2861647) BEAKBOX: The current date/time is: Wed Dec 31 12:47:47 1969
I (2861647) BEAKBOX: HEAP Available:163720, Largest:113792, Min:162288
Here is a sample of the log while playing (level Info):
W (2845487) I2S: I2S driver already installed
I (2845487) MP3_DECODER: MP3 init
I (2845487) AUDIO_PIPELINE: link el->rb, el:0x3ffca1b4, tag:mp3, rb:0x3ffca578
I (2845497) AUDIO_ELEMENT: [i2s-0x3ffc69f4] Element task created
I (2845497) AUDIO_ELEMENT: [mp3-0x3ffca1b4] Element task created
I (2845507) AUDIO_PIPELINE: Func:audio_pipeline_run, Line:358, MEM Total:198548 Bytes
I (2845517) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:1
I (2845517) I2S_STREAM: AUDIO_STREAM_WRITER
I (2845527) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = IDLE
I (2845527) AUDIO_ELEMENT: [mp3] AEL_MSG_CMD_RESUME,state:1
I (2845537) MP3_DECODER: MP3 opened
I (2845537) AUDIO_PIPELINE: Pipeline started
W (2845547) MUSICLOG: Logged play 0,.,0
I (2845557) LED: Setting led to 0x402 with repeat:1
I (2845567) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = PLAYING
W (2845567) MUSIC_AEL: Other cmd received from mp3 decoder: 8
I (2845587) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = PLAYING
I (2845587) MUSIC: Got message: UNKNOWN!, In state: PLAYING
I (2845587) MUSIC: Got message: UNKNOWN!, In state: PLAYING
I (2845597) MUSIC: Received music info from mp3 decoder, sample_rate=44100, bits=16, ch=1
I (2845607) AMP: Set sample rate 7
I (2845677) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_PAUSE
I (2845677) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = PLAYING
I (2845727) I2S: APLL: Req RATE: 44100, real rate: 44099.988, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 11289597.000, SCLK: 1411199.625000, diva: 1, divb: 0
W (2845737) AUDIO_ELEMENT: [i2s] RESUME timeout
I (2845737) AUDIO_ELEMENT: [i2s] AEL_MSG_CMD_RESUME,state:3
I (2845747) I2S_STREAM: AUDIO_STREAM_WRITER
I (2845747) MUSIC_AEL: Received audio event, sourcetype= 131072, music state = PLAYING
I (2851647) BEAKBOX: The current date/time is: Wed Dec 31 12:47:37 1969
I (2851647) BEAKBOX: HEAP Available:163720, Largest:113792, Min:162288
I (2861647) BEAKBOX: The current date/time is: Wed Dec 31 12:47:47 1969
I (2861647) BEAKBOX: HEAP Available:163720, Largest:113792, Min:162288