Issue with stream smoothjazz.com.pl

[dzikakuna]

Hello Wolle,

Could you check what is wrong during decoding below stream that mostly library can not play it correctly longer than few minutes and we get message about "slow stream, drops possible" and often (not always) wifi is crashing also.

Strange is that the all other FLAC stations are working correct even AIDA Radio with 24bits, 2000kpbs, 48kHz is playing smoothly long hours.
So there must be sth. specific/unique in this stream what crashes the audio task and wifi.

Smoothjazz.com.pl - http://bcast.vigormultimedia.com:8888/sjcomplflac

[dzikakuna]

Platform ESP32-S3, compiler Arduino or Platformio. I'm checking firmware on both. Tested on my Evo Web radio design (https://github.com/dzikakuna/ESP32_radio_evo3/tree/main).

[hevet]

Nothing like that happens to me, the radio has been on for several dozen minutes and there is no message about "slow stream, drops possible".

[dzikakuna]

You need to play little bit longer, I modified task priority in audio lib and now it takes 2-3h before it will stop and few minutes later you will have WiFi task destroyed. It still a problem with this particular stream. I leaving radio for night and any other FLAC stream will play whole night but not this one. I can understood some drops during network disconnection but it should not destroy WiFi task. Monitoring of RAM, PSRAM do not shows aby malfunction.

Still valid question - what is so "magic" in this stream that radio is stoping playing and destroying wifi task.

[schreibfaul1]

I don't yet know what the special magic is in this stream. I've had http://bcast.vigormultimedia.com:8888/sjcomplflac running for half an hour without any problems so far. The error is difficult to reproduce.
Can you please run this stream in this environment https://github.com/schreibfaul1/ESP32_Arduino_ESPIDF and with these menuconfig settings?
All you need is an ESP board from the box without any additional hardware.

[dzikakuna]

Maybe I do not state this info but I already using core 3.3.3 with modified libs (liblwip.a, libesp_netif.a) for better wifi throughput from yoRadio. Without that FLACs will not even play.

Monitoring of RAM and PSRAM also do not show any strange memory utilization:

Before drop:
18:39:28.477 -> debug-- Audio Bufor wolne: 0 / zajęte: 655350 Muzyka w buforze na: 5 sek. bitrate: 959671 [#####_____]
18:39:28.477 -> Free internal RAM: 161456
18:39:28.477 -> Free PSRAM: 7272556
18:39:28.477 -> Free heap: 161456
18:39:28.477 -> Total heap: 317324
18:39:28.518 -> Min free heap (od startu): 134612

After drop:
18:57:24.004 -> debug-- Audio Bufor wolne: 576062 / zajęte: 79288 Muzyka w buforze na: 0 sek. bitrate: 973735 [__________]
18:57:24.004 -> Free internal RAM: 161456
18:57:24.004 -> Free PSRAM: 7309304
18:57:24.004 -> Free heap: 161456
18:57:24.004 -> Total heap: 317324

[schreibfaul1]

Okay, so you're using the Arduino IDE, right?
VS Code with piaorduino as an extension would be much more convenient.
Free heap: 161456 looks very good.
I'll run SmoothJazz.com.pl tonight, maybe I'll know more tomorrow.

[dzikakuna]

Yes, mostly Arduino and before release to GitHub validating also on Platformio project replacing only libs to the same used in Arduino and main.cpp. OK Thanks, lets wait until tomorrow if you will also have some drops.

I will also run again for night, need only back to saved backup of your library. Otherwise this stream plays just 2-3 minutes and crash:

22:10:29.274 -> info: ....... SampleRate (Hz): 44100
22:10:29.274 -> info: ....... BitsPerSample: 16
22:10:31.875 -> info: ....... syncword found at pos 63966
22:10:31.875 -> info: ....... syncword found at pos 0
22:10:31.875 -> info: ....... syncword found at pos 491
22:10:31.875 -> info: ....... syncword found at pos 0
22:10:31.911 -> info: ....... Channels: 2
22:10:31.911 -> info: ....... SampleRate (Hz): 44100
22:10:31.911 -> info: ....... BitsPerSample: 16
22:10:55.112 -> info: ....... syncword found at pos 54157
22:10:55.112 -> info: ....... syncword found at pos 0
22:10:55.164 -> info: ....... syncword found at pos 808
22:10:55.164 -> info: ....... syncword found at pos 0
22:10:55.196 -> info: ....... Channels: 2
22:10:55.196 -> info: ....... SampleRate (Hz): 44100
22:10:55.196 -> info: ....... BitsPerSample: 16
22:11:05.532 -> info: ....... syncword found at pos 55137
22:11:05.532 -> info: ....... syncword found at pos 0
22:11:05.532 -> info: ....... syncword found at pos 11416
22:11:05.532 -> info: ....... syncword found at pos 0
22:11:05.603 -> info: ....... Channels: 2
22:11:05.603 -> info: ....... SampleRate (Hz): 44100
22:11:05.603 -> info: ....... BitsPerSample: 16
22:11:06.300 -> info: ....... syncword found at pos 52354
22:11:06.300 -> info: ....... syncword found at pos 0
22:11:06.342 -> info: ....... syncword found at pos 228
22:11:06.342 -> info: ....... syncword found at pos 0
22:11:06.387 -> info: ....... Channels: 2
22:11:06.387 -> info: ....... SampleRate (Hz): 44100
22:11:06.387 -> info: ....... BitsPerSample: 16
22:11:14.035 -> info: ....... syncword found at pos 55660
22:11:14.035 -> info: ....... syncword found at pos 0
22:11:14.035 -> info: ....... syncword found at pos 11864
22:11:14.035 -> info: ....... syncword found at pos 0
22:11:14.116 -> info: ....... Channels: 2
22:11:14.116 -> info: ....... SampleRate (Hz): 44100
22:11:14.116 -> info: ....... BitsPerSample: 16
22:11:25.702 -> info: ....... syncword found at pos 53646
22:11:25.702 -> info: ....... syncword found at pos 0
22:11:25.702 -> info: ....... syncword found at pos 10810
22:11:25.702 -> info: ....... syncword found at pos 0
22:11:25.770 -> info: ....... Channels: 2
22:11:25.770 -> info: ....... SampleRate (Hz): 44100
22:11:25.770 -> info: ....... BitsPerSample: 16
22:11:26.049 -> info: ....... syncword found at pos 304
22:11:26.049 -> info: ....... syncword found at pos 0
22:11:26.355 -> info: ....... Closing web file "http://bcast.vigormultimedia.com:8888/sjcomplflac"
22:11:26.401 -> info: ....... FLACDecoder has been destroyed

[schreibfaul1]

I let the stream run and couldn't detect any errors.

Jazz.com.pl.txt

According to your log, it looks as if entire Ogg blocks are being skipped. Try yesterday's latest version.

[dzikakuna]

I run last night on latest commit from yesterday night update and crash in same way. Its start to sending "slow stream, drops possible" later library is trying to reconnect to host but it stack and can not re-run connection.

If I will run manually (by remote controller in my radio or encoder) "changeStation()" what just calling "audio.connecttohost(stationUrl.c_str());" it will start to play. If I will leave it after some time WIFI onnection task will be killed and on uart there will info about that. No option for reconnect anymore only reset helps.

I do not know if this can have influence but all the time even in this crash I calling function in loop to read vuMeterValue - >

uint16_t raw = audio.getVUlevel();
vuMeterL = (raw >> 8) & 0xFF;
vuMeterR = raw & 0xFF;

Can this have any influence on that ?

I will try on today commit. On BDPST Rock Radio FLAC there is one info on start about sync position. On SmoothJazz there is many time re-sync and info about sync position ? Can this have any influence also ?

LOG:

PLAYING
22:31:51.254 -> ID3 data: ... Artist: Joe Mcbride
22:31:51.254 -> ID3 data: ... Title: Central Expressway
22:31:51.263 -> info: ....... stream title: Joe Mcbride - Central Expressway

STOPS PLAYING
22:33:13.453 -> info: ....... slow stream, dropouts are possible
22:33:14.453 -> info: ....... slow stream, dropouts are possible
22:33:20.487 -> info: ....... slow stream, dropouts are possible
22:33:23.474 -> info: ....... slow stream, dropouts are possible
22:33:29.523 -> info: ....... slow stream, dropouts are possible
22:33:35.549 -> info: ....... slow stream, dropouts are possible
22:33:41.546 -> info: ....... slow stream, dropouts are possible
22:33:44.574 -> info: ....... slow stream, dropouts are possible
22:33:46.568 -> info: ....... slow stream, dropouts are possible
22:33:47.534 -> info: ....... slow stream, dropouts are possible
22:33:48.563 -> info: ....... slow stream, dropouts are possible
22:33:49.534 -> info: ....... slow stream, dropouts are possible
22:33:50.550 -> info: ....... slow stream, dropouts are possible
22:33:50.850 -> info: ....... Stream lost -> try new connection

RECONNECT by LIB but it will never reconnect and will not play even you see here "slow stream, dropouts are possible"
22:33:50.850 -> info: ....... next URL: "http://bcast.vigormultimedia.com:8888/sjcomplflac"
22:33:50.894 -> info: ....... The host has disconnected, reconnecting
22:33:51.393 -> info: ....... icy-logo: http://bcast.vigormultimedia.com:7000/sj_logo.png
22:33:51.393 -> info: ....... stationLogoUrl: http://bcast.vigormultimedia.com:7000/sj_logo.png
22:33:51.439 -> icy logo: ... http://bcast.vigormultimedia.com:7000/sj_logo.png
22:33:51.439 -> info: ....... icy-genre: smooth jazz
22:33:51.439 -> info: ....... station name: SmoothJazz.com.pl
22:33:51.581 -> info: ....... slow stream, dropouts are possible
22:33:52.558 -> info: ....... slow stream, dropouts are possible

after 2-5 sometimes 10 minutes
WIFI Crash:
E (914534) wifi:Set status to INIT
E (914591) wifi:Set status to INIT
E (914673) wifi:Set status to INIT
E (914697) wifi:Set status to INIT
E (914738) wifi:Set status to INIT
E (914782) wifi:Set status to INIT
E (914843) wifi:Set status to INIT

Tested on 2 different routers, where one of them (Ubiquiti) was in special IoT mode with 2.4G separate network but this not help.

[dzikakuna]

Today I run this smoohtjazz.com.pl on your Platformio code from the link.
Just only remove config for ESP32, ESP32-P4 and just left ESP32-S3.

First time it runs around 5 minutes and get:
bitrate: 990802
info: estimated bitrate (b/s): 990802
id3data: Artist: Philippe Saisse
id3data: Title: Young Nation
streamtitle: Philippe Saisse - Young Nation
OOM: failed to allocate 62193264 bytes for unnamed
OOM: appendf() failed for 62193257 bytes

2nd try:
20:47:44.334 -> ----------------------------------
20:47:44.334 -> ESP32 Chip: ESP32-S3
20:47:44.334 -> Arduino Version: 3.3.6
20:47:44.334 -> ESP-IDF Version: 5.5.2
20:47:44.334 -> ARDUINO_LOOP_STACK_SIZE 8192 words (32 bit)
20:47:44.334 -> ----------------------------------
20:47:44.334 ->
20:47:44.334 ->
20:47:45.891 -> info: audioI2S Version 3.4.4j
20:47:45.891 -> info: inputBufferSize: 655349 bytes
20:47:45.891 -> info: connect to: "bcast.vigormultimedia.com" on port 8888 path "/sjcomplflac"
20:47:45.934 -> info: Connection has been established in 75 ms
20:47:45.934 -> lasthost: http://bcast.vigormultimedia.com:8888/sjcomplflac
20:47:46.330 -> info: icy-logo: http://bcast.vigormultimedia.com:7000/sj_logo.png
20:47:46.828 -> id3data: Title: Fantasy Love
20:47:46.861 -> streamtitle: Stanley Clarke - Fantasy Love
20:47:46.861 -> info: AudioDataStart: 436
20:47:46.861 -> info: Channels: 2
20:47:46.861 -> info: SampleRate (Hz): 44100
20:47:46.861 -> info: BitsPerSample: 16
20:47:53.479 -> Guru Meditation Error: Core 0 panic'ed (StoreProhibited). Exception was unhandled.
20:47:53.548 ->
20:47:53.548 -> Core 0 register dump:
20:47:53.548 -> PC : 0x4204dd81 PS : 0x00060330 A0 : 0x8204de68 A1 : 0x3fca3220
20:47:53.548 -> A2 : 0x00001200 A3 : 0x00000002 A4 : 0x3fcc2954 A5 : 0xffffe7ea
20:47:53.548 -> A6 : 0x3c1beff0 A7 : 0x3fcc2848 A8 : 0x00158880 A9 : 0x00000000
20:47:53.548 -> A10 : 0x3fcb00a9 A11 : 0x3fcb00a9 A12 : 0x3c1ba2b0 A13 : 0x00001200
20:47:53.579 -> A14 : 0x00001200 A15 : 0xfffff08b SAR : 0x0000000b EXCCAUSE: 0x0000001d
20:47:53.579 -> EXCVADDR: 0x00001200 LBEG : 0x4204dd00 LEND : 0x4204dd10 LCOUNT : 0x00000000
20:47:53.579 ->
20:47:53.579 ->
20:47:53.579 -> Backtrace: 0x4204dd7e:0x3fca3220 0x4204de65:0x3fca3250 0x4202952c:0x3fca3280 0x42029a10:0x3fca32d0 0x42029aad:0x3fca32f0
20:47:53.614 ->
20:47:53.614 ->
20:47:53.614 ->
20:47:53.614 ->
20:47:53.614 -> ELF file SHA256: b77ce6d43
20:47:53.614 ->
20:47:53.614 -> Rebooting...

3rd try:
20:49:11.378 -> ----------------------------------
20:49:11.378 -> ESP32 Chip: ESP32-S3
20:49:11.378 -> Arduino Version: 3.3.6
20:49:11.378 -> ESP-IDF Version: 5.5.2
20:49:11.378 -> ARDUINO_LOOP_STACK_SIZE 8192 words (32 bit)
20:49:11.378 -> ----------------------------------
20:49:11.378 ->
20:49:11.378 ->
20:49:12.937 -> info: audioI2S Version 3.4.4j
20:49:12.937 -> info: inputBufferSize: 655349 bytes
20:49:12.937 -> info: connect to: "bcast.vigormultimedia.com" on port 8888 path "/sjcomplflac"
20:49:12.983 -> info: Connection has been established in 74 ms
20:49:12.983 -> lasthost: http://bcast.vigormultimedia.com:8888/sjcomplflac
20:49:13.418 -> info: icy-logo: http://bcast.vigormultimedia.com:7000/sj_logo.png
20:49:13.418 -> icy_logo: http://bcast.vigormultimedia.com:7000/sj_logo.png
20:49:13.418 -> info: icy-genre: smooth jazz
20:49:13.418 -> station_name: SmoothJazz.com.pl
20:49:13.418 -> info: FLACDecoder has been initialized
20:49:13.465 -> info: stream ready
20:49:13.716 -> info: syncword found at pos 0
20:49:13.716 -> id3data: Artist: Alex Bugnon
20:49:13.716 -> id3data: Title: But Only For You
20:49:13.763 -> streamtitle: Alex Bugnon - But Only For You
20:49:13.763 -> info: AudioDataStart: 451
20:49:13.763 -> info: Channels: 2
20:49:13.763 -> info: SampleRate (Hz): 44100
20:49:13.763 -> info: BitsPerSample: 16
20:49:14.479 -> info: slow stream, dropouts are possible
20:49:29.189 -> LOGE: flac_decoder.cpp:762 �[31mSync 0xFFF8 not found�[0m
20:49:29.189 -> info: syncword found at pos 52190
20:49:29.222 -> info: syncword found at pos 0
20:49:29.222 -> LOGE: flac_decoder.cpp:762 �[31mSync 0xFFF8 not found�[0m
20:49:29.222 -> info: syncword found at pos 61362
20:49:29.222 -> info: syncword found at pos 0
20:49:29.222 -> LOGE: flac_decoder.cpp:762 �[31mSync 0xFFF8 not found�[0m
20:49:29.222 -> info: syncword found at pos 64630
20:49:29.222 -> info: syncword found at pos 0
20:49:29.222 -> LOGE: flac_decoder.cpp:762 �[31mSync 0xFFF8 not found�[0m
20:49:29.222 -> info: syncword found at pos 59750
20:49:29.259 -> info: syncword found at pos 0

last lines are repeating all the time about mSync... maybe this is a key to this story ?

[dzikakuna]

Wolle, why flac_decoder set Sync to 0xFFF8 ?

[schreibfaul1]

Hi @dzikakuna,
I tested the station today with the S3 (yesterday with the S4) and cannot reproduce the error.
But I noticed that the ESP32-S3 connects to the first available access point. I have two, one is in the immediate vicinity, the other is in the next room with a wall and two cupboards in between.
WiFiMulti solves the problem by searching for all networks and selecting the strongest one.

Why 0xFFF8? That's the beginning of every FLAC frame. 0xFFF8 can also be part of the audio block, but it's highly likely that it's the frame beginning.

[dzikakuna]

Hi @schreibfaul1
I connect today radio to shared router from mobile phone. There was few stops but after them radio play smoothly smoothjazz.com.pl without any issue 5h. Normally router (Mikrotik) is 1m away from radio, phone was just 5m away.
Unfortunately all the time I'm on mobile LTE/5G T-Mobile network.

I will replace lib with today commits, I see some changes related to FLAC and run test again.

[dzikakuna]

@schreibfaul1
After 48h of testing I probably found solution.
It looks like ESP32 has some problem to work with 20/40Mhz Ce settings. Switching booth my routers just to bandwidth 20MHz helps to avoid any issue with loosing stream or wifi connections. Lets verify that for a week if the stream will be stable I will close this topic.

[dzikakuna]

@schreibfaul1 It looks like issue can be related to the fact that Smoothjazz.com.pl is using old Icecast 2.4.4 with VBR codding. Icecast in this version was never officially released with FLAC streaming support - we get just pure stream send over ogg container.
There is no chunk transmission and from unknown reason server is responding always in http/1.0 header even if 2.4.4 should support http/1.1

In this case from time to time ESP was loosing stream buffer but there was no drop of m_client connection, after few seconds buffer was again filled properly but it looks like some "pages" from ogg are loosed and decoder stuck. lwIP (TCP) starts to collect some data, AsyncWebServers was blocked and due to shared resources with WiFi we have additionally crash of wifi task later.

Situation was like :
audio.isRunning() == true
client.available() and connected
but no data send over i2s

inside library I do not found any watchdog mechanism in function related to "Audio::connecttohost" checking that if m_client have connection, but no audio sent over i2s we do re-connect. Is there any ?

Right now I prepare own sdkconfig and recompile completely lwIP libs (liblwip.a and libesp_netif.a) with huge RX buffers and its solve the problem. Now streams play smoothly over more than 24h and no issues.