MrBuddyCasino / ESP32_MP3_Decoder

A internet radio and bluetooth speaker project for the Espressif ESP32
783 stars 183 forks source link

Buffer underflow and crash on bitrates lower than 256kbps #80

Open dmitrij9992905 opened 4 years ago

dmitrij9992905 commented 4 years ago

I have the same issue, but I use external DAC and good internet connection. I assembled my project on esp32-wroom.

here are logs:

The first time after booting player plays smoothly

ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6816
ho 0 tail 12 room 4
load:0x40078000,len:12072
ho 0 tail 12 room 4
load:0x40080400,len:6708
entry 0x40080778
I (74) boot: Chip Revision: 1
I (74) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (42) boot: ESP-IDF v3.3.2-107-g722043f73 2nd stage bootloader
I (42) boot: compile time 09:51:16
I (42) boot: Enabling RNG early entropy source...
I (48) boot: SPI Speed      : 40MHz
I (52) boot: SPI Mode       : DIO
I (56) boot: SPI Flash Size : 4MB
I (60) boot: Partition Table:
I (63) boot: ## Label            Usage          Type ST Offset   Length
I (71) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (78) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (86) boot:  2 factory          factory app      00 00 00010000 00200000
I (93) boot: End of partition table
I (97) boot_comm: chip revision: 1, min. application chip revision: 0
I (104) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x583a4 (361380) map
I (240) esp_image: segment 1: paddr=0x000683cc vaddr=0x3ffbdb60 size=0x05900 ( 22784) load
I (250) esp_image: segment 2: paddr=0x0006dcd4 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at /home/dmitrij999/esp/esp-adf/esp-idf/components/freertos/xtensa_vectors.S:1779

I (250) esp_image: segment 3: paddr=0x0006e0dc vaddr=0x40080400 size=0x01f34 (  7988) load
I (262) esp_image: segment 4: paddr=0x00070018 vaddr=0x400d0018 size=0xb2db0 (732592) map
0x400d0018: _stext at ??:?

I (524) esp_image: segment 5: paddr=0x00122dd0 vaddr=0x40082334 size=0x14a90 ( 84624) load
0x40082334: shared_intr_isr at /home/dmitrij999/esp/esp-adf/esp-idf/components/esp32/intr_alloc.c:784

I (574) boot: Loaded app from partition at offset 0x10000
I (574) boot: Disabling RNG early entropy source...
I (574) cpu_start: Pro cpu up.
I (578) cpu_start: Application information:
I (583) cpu_start: Project name:     mp3_decoder
I (588) cpu_start: App version:      fe57c88-dirty
I (593) cpu_start: Compile time:     Jun 19 2020 09:51:18
I (599) cpu_start: ELF file SHA256:  27d79fb5191c9f44...
I (605) cpu_start: ESP-IDF:          v3.3.2-107-g722043f73
I (612) cpu_start: Starting app cpu, entry point is 0x40081258
0x40081258: call_start_cpu1 at /home/dmitrij999/esp/esp-adf/esp-idf/components/esp32/cpu_start.c:268

I (0) cpu_start: App cpu up.
I (622) heap_init: Initializing. RAM available for dynamic allocation:
I (629) heap_init: At 3FFAE6E0 len 0000F480 (61 KiB): DRAM
I (635) heap_init: At 3FFD2FC0 len 0000D040 (52 KiB): DRAM
I (641) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (648) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (654) heap_init: At 40096DC4 len 0000923C (36 KiB): IRAM
I (660) cpu_start: Pro cpu start user code
I (8) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (9) main: starting app_main()
I (9) main: RAM left: 223172
I (39) main: hardware initialized
I (39) main: starting network
I (59) wifi:wifi driver task: 3ffb7ea0, prio:23, stack:3584, core=0
I (59) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (59) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (89) wifi:wifi firmware version: 5f8804c
I (89) wifi:config NVS flash: enabled
I (89) wifi:config nano formating: disabled
I (89) wifi:Init dynamic tx buffer num: 32
I (99) wifi:Init data frame dynamic rx buffer num: 32
I (99) wifi:Init management frame dynamic rx buffer num: 32
I (109) wifi:Init management short buffer num: 32
I (109) wifi:Init static rx buffer size: 1600
I (119) wifi:Init static rx buffer num: 10
I (119) wifi:Init dynamic rx buffer num: 32
I (219) phy: phy_version: 4180, cb3948e, Sep 12 2019, 16:39:13, 0, 0
I (229) wifi:mode : sta (24:0a:c4:af:f8:a4)
I (229) wifi: received wifi event 2
I (229) wifi: connected successfully
I (349) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
I (349) wifi:state: init -> auth (b0)
I (349) wifi:state: auth -> assoc (0)
I (359) wifi:state: assoc -> run (10)
I (369) wifi:connected with tp-link-cab, aid = 3, channel 1, BW20, bssid = 28:3b:82:47:95:da
I (369) wifi:security type: 3, phy: bgn, rssi: -35
I (379) wifi:pm start, type: 1

I (379) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (379) wifi: received wifi event 4
I (1039) event: sta ip: 192.168.0.101, mask: 255.255.255.0, gw: 192.168.0.1
I (1039) wifi: received wifi event 7
I (1039) playlist: Tracks:
SomaFM / Illinois Street Lounge - http://ice1.somafm.com/illstreet-128-mp3
SomaFM / Secret Agent - http://ice1.somafm.com/secretagent-128-mp3
SomaFM / Left Coast 70s - http://ice1.somafm.com/seventies-128-mp3
SomaFM / Boot Liquor - http://ice1.somafm.com/bootliquor-128-mp3
I (1069) renderer: init I2S mode 0, port 0, 16 bit, 44100 Hz
I (1069) renderer: chip revision 1, enabling APLL for I2S
I (1079) I2S: queue free spaces: 1
I (1079) I2S: DMA Malloc info, datalen=blocksize=256, dma_buf_count=32
I (1089) 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
I (1109) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:1 
I (1119) main: RAM left 169320
I (2229) http_client: DNS lookup succeeded. IP=173.239.76.148
I (2229) http_client: ... allocated socket
I (2529) http_client: ... connected
I (2539) http_client: requesting GET /illstreet-128-mp3 HTTP/1.0
Host:ice1.somafm.com
User-Agent: ESP32
Accept: */*
Icy-MetaData: 1

I (2539) http_client: ... socket send success
< content-type : audio/mpeg
< date : Fri, 19 Jun 2020 05:57:02 GMT
< icy-br : 128
< icy-genre : Exotica Lounge
< icy-name : Ill Street Lounge: Classic bachelor pad, playful exotica and vintage music of tomorrow. [SomaFM]
< icy-notice1 : <BR>This stream requires <a href="http://www.winamp.com/">Winamp</a><BR>
< icy-notice2 : SHOUTcast Distributed Network Audio Server/Linux v1.9.5<BR>
< icy-pub : 0
< icy-url : http://somafm.com
< server : Icecast 2.4.0-kh10
< cache-control : no-cache, no-store
< access-control-allow-origin : *
< access-control-allow-headers : Origin, Accept, X-Requested-With, Content-Type
< access-control-allow-methods : GET, OPTIONS, HEAD
< connection : Close
< expires : Mon, 26 Jul 1997 05:00:00 GMT
< icy-metaint : 16000
I (3769) audio_player: Buffer fill 49%, 15966 bytes
d/ decoded meta StreamTitle='Daniele Luppi - La Nudista';StreamUrl='http://somafm.com/logos/512/illstreet512.png';
I (4589) audio_player: RAM left 170036
I (4589) audio_player: created decoder task: mp3_decoder_task
I (4589) mad_decoder: decoder start
E (4599) mad_decoder: dec err 0x0235 (bad main_data_begin pointer)
E (4599) mad_decoder: dec err 0x0235 (bad main_data_begin pointer)
I (4899) audio_player: Buffer fill 74%, 23921 bytes
I (5829) audio_player: Buffer fill 77%, 24871 bytes
I (7059) audio_player: Buffer fill 64%, 20780 bytes
I (8279) audio_player: Buffer fill 52%, 16689 bytes
I (9519) audio_player: Buffer fill 47%, 15119 bytes
I (10559) audio_player: Buffer fill 42%, 13574 bytes
I (11769) audio_player: Buffer fill 29%, 9483 bytes
I (12989) audio_player: Buffer fill 16%, 5392 bytes
I (13959) audio_player: Buffer fill 19%, 6330 bytes
I (15219) audio_player: Buffer fill 8%, 2759 bytes

Then intermittent play begins:

E (15599) mad_decoder: Buffer underflow, need 2470 bytes.
E (15599) mad_decoder: Buffer underflow, need 2470 bytes.
E (15609) mad_decoder: Buffer underflow, need 2470 bytes.
E (15619) mad_decoder: Buffer underflow, need 2470 bytes.
E (15619) mad_decoder: Buffer underflow, need 2470 bytes.
...
E (15949) mad_decoder: Buffer underflow, need 2759 bytes.
E (15959) mad_decoder: Buffer underflow, need 2759 bytes.
E (16179) mad_decoder: Buffer underflow, need 2631 bytes.
E (16179) mad_decoder: Buffer underflow, need 2631 bytes.
E (16179) mad_decoder: Buffer underflow, need 2631 bytes.
E (16189) mad_decoder: Buffer underflow, need 2631 bytes.
E (16189) mad_decoder: Buffer underflow, need 2631 bytes.
E (16199) mad_decoder: Buffer underflow, need 2631 bytes.
E (16209) mad_decoder: Buffer underflow, need 2631 bytes.
E (16209) mad_decoder: Buffer underflow, need 2631 bytes.
E (16219) mad_decoder: Buffer underflow, need 2631 bytes.
E (16229) mad_decoder: Buffer underflow, need 2631 bytes.
E (16229) mad_decoder: Buffer underflow, need 2631 bytes.
E (16239) mad_decoder: Buffer underflow, need 2631 bytes.
...
E (16559) mad_decoder: Buffer underflow, need 2502 bytes.
E (16559) mad_decoder: Buffer underflow, need 2502 bytes.
E (16569) mad_decoder: Buffer underflow, need 2502 bytes.
E (16569) mad_decoder: Buffer underflow, need 2502 bytes.
I (16579) audio_player: Buffer fill 2%, 680 bytes
E (16829) mad_decoder: Buffer underflow, need 2793 bytes.
E (16829) mad_decoder: Buffer underflow, need 2793 bytes.
E (16829) mad_decoder: Buffer underflow, need 2793 bytes.
E (16829) mad_decoder: Buffer underflow, need 2793 bytes.
E (16839) mad_decoder: Buffer underflow, need 2793 bytes.
E (16849) mad_decoder: Buffer underflow, need 2793 bytes.
E (16849) mad_decoder: Buffer underflow, need 2793 bytes.
E (17159) mad_decoder: Buffer underflow, need 2665 bytes.
E (17169) mad_decoder: Buffer underflow, need 2665 bytes.
E (17169) mad_decoder: Buffer underflow, need 2665 bytes.
E (17179) mad_decoder: Buffer underflow, need 2665 bytes.
E (17179) mad_decoder: Buffer underflow, need 2665 bytes.
E (17189) mad_decoder: Buffer underflow, need 2476 bytes.
E (17419) mad_decoder: Buffer underflow, need 2536 bytes.
E (17419) mad_decoder: Buffer underflow, need 2536 bytes.
E (17419) mad_decoder: Buffer underflow, need 2536 bytes.
E (17419) mad_decoder: Buffer underflow, need 2536 bytes.
E (17429) mad_decoder: Buffer underflow, need 2536 bytes.
E (17439) mad_decoder: Buffer underflow, need 2536 bytes.
E (17439) mad_decoder: Buffer underflow, need 2536 bytes.
E (17449) mad_decoder: Buffer underflow, need 2536 bytes.
...
E (17769) mad_decoder: Buffer underflow, need 2826 bytes.
E (17769) mad_decoder: Buffer underflow, need 2826 bytes.
E (17779) mad_decoder: Buffer underflow, need 2826 bytes.
E (17789) mad_decoder: Buffer underflow, need 2826 bytes.
E (17789) mad_decoder: Buffer underflow, need 2826 bytes.
E (17799) mad_decoder: Buffer underflow, need 2826 bytes.
I (17799) audio_player: Buffer fill 0%, 252 bytes
E (17809) mad_decoder: Buffer underflow, need 2574 bytes.
E (18039) mad_decoder: Buffer underflow, need 2698 bytes.
E (18039) mad_decoder: Buffer underflow, need 2698 bytes.
E (18039) mad_decoder: Buffer underflow, need 2698 bytes.
E (18039) mad_decoder: Buffer underflow, need 2698 bytes.
E (18049) mad_decoder: Buffer underflow, need 2698 bytes.
E (18059) mad_decoder: Buffer underflow, need 2698 bytes.
E (18059) mad_decoder: Buffer underflow, need 2698 bytes.
E (18069) mad_decoder: Buffer underflow, need 2698 bytes.
...
E (18669) mad_decoder: Buffer underflow, need 2859 bytes.
E (18669) mad_decoder: Buffer underflow, need 2859 bytes.
E (18679) mad_decoder: Buffer underflow, need 2859 bytes.
E (18679) mad_decoder: Buffer underflow, need 2859 bytes.
E (18689) mad_decoder: Buffer underflow, need 2859 bytes.
E (18699) mad_decoder: Buffer underflow, need 2859 bytes.
E (18699) mad_decoder: Buffer underflow, need 2859 bytes.
E (18709) mad_decoder: Buffer underflow, need 2859 bytes.
E (18709) mad_decoder: Buffer underflow, need 2859 bytes.
E (18719) mad_decoder: Buffer underflow, need 2859 bytes.
I (18739) audio_player: Buffer fill 8%, 2683 bytes
E (18949) mad_decoder: Buffer underflow, need 2732 bytes.
E (18949) mad_decoder: Buffer underflow, need 2732 bytes.
E (18949) mad_decoder: Buffer underflow, need 2732 bytes.
E (18949) mad_decoder: Buffer underflow, need 2732 bytes.
E (18959) mad_decoder: Buffer underflow, need 2732 bytes.
E (18969) mad_decoder: Buffer underflow, need 2732 bytes.
E (18969) mad_decoder: Buffer underflow, need 2732 bytes.
E (18979) mad_decoder: Buffer underflow, need 2732 bytes.
E (18979) mad_decoder: Buffer underflow, need 2732 bytes.
E (18989) mad_decoder: Buffer underflow, need 2732 bytes.
E (18999) mad_decoder: Buffer underflow, need 2732 bytes.
E (18999) mad_decoder: Buffer underflow, need 2732 bytes.
E (19009) mad_decoder: Buffer underflow, need 2732 bytes.
E (19009) mad_decoder: Buffer underflow, need 2732 bytes.
E (19019) mad_decoder: Buffer underflow, need 2732 bytes.
E (19029) mad_decoder: Buffer underflow, need 2732 bytes.
E (19029) mad_decoder: Buffer underflow, need 2732 bytes.
E (19039) mad_decoder: Buffer underflow, need 2732 bytes.
...
E (19309) mad_decoder: Buffer underflow, need 2604 bytes.
E (19319) mad_decoder: Buffer underflow, need 2604 bytes.
E (19319) mad_decoder: Buffer underflow, need 2604 bytes.
E (19329) mad_decoder: Buffer underflow, need 2604 bytes.

Is it memory leak?

Also I added two stations from Zaycev.net and these stations plays smoothly. Maybe, standard station's server are too slow or it depends on the certain region? Or is it memory leak? Or buffer size is too small?

MrBuddyCasino commented 4 years ago

Maybe, standard station's server are too slow or it depends on the certain region?

I believe that is the case. Not sure why, maybe latency?

Or is it memory leak?

I don't think so.

Or buffer size is too small?

Probably, yes. If you don't use AAC you can increase it by quite a bit, don't remember by how much though, you'll have to check the free heap readings.