Playback not stable AAC / FLAC

DerPicknicker commented 11 months ago

Describe the bug

The Playback is really unstable. I want to use it not with LMS anymore. I am currently using the MusicAssistant. But the behaviour is nearly the same.:

The Playbacks suddenly stops (because the ESP32 is crashing).
I tested different Files, AAC, Lossless and MP3.
Inside MusicAssistant I tested also different output codecs:
The Most aweful is the FLAC-Codec. The esp32 is crashing almost instant. As you can see in the logs.
I tested also AAC which works better but still worse and not great for everyday use.
The Issue is reproducible For me its not useable at the moment.I can submit also log files for using with lms but I guess the issue is esp32 releated and not on a problem on the Server. The Files i wanted to play are ok. I tested them on different machines (mac and windows)

Preliminary Information

Firmware Version: I2S-4MFlash-1652, Wifi strenght: rssi: -59
Hardware Details

ESP Louder => https://github.com/sle118/squeezelite-esp32/discussions/357

NVS Settings

{
  "a2dp_ctmt": "1000",
  "a2dp_ctrld": "500",
  "a2dp_dev_name": "Player1",
  "a2dp_sink_name": "Player1",
  "a2dp_spin": "0000",
  "actrls_config": "",
  "airplay_name": "Player1",
  "airplay_port": "5000",
  "ap_channel": "1",
  "ap_ip_address": "192.168.4.1",
  "ap_ip_gateway": "192.168.4.1",
  "ap_ip_netmask": "255.255.255.0",
  "ap_pwd": "squeezelite",
  "ap_ssid": "Player1",
  "autoexec": "1",
  "autoexec1": "squeezelite  -o i2s  -s  192.168.178.122:3483 -b  500:2000 -C  30 -d  all=info ",
  "bat_config": "",
  "bt_name": "Player1",
  "bt_sink_pin": "1234",
  "bt_sink_volume": "127",
  "bypass_wm": "0",
  "cspot_config": "{\t\"deviceName\":\t\"Player1\",\t\"bitrate\":\t320,\t\"zeroConf\":\t0}",
  "dac_config": "model=I2S,bck=26,ws=25,do=22,sda=21,scl=27,i2c=45",
  "dac_controlset": "{\"init\":[{\"reg\":3,\"val\":2},{\"reg\":3,\"val\":3}],\"poweron\":[{\"reg\":3,\"val\":3}],\"poweroff\":[{\"reg\":3,\"val\":0}]}",
  "dhcp_tmout": "8",
  "display_config": "",
  "enable_airplay": "N",
  "enable_bt_sink": "N",
  "enable_cspot": "N",
  "equalizer": "-3,2,-4,0,5,4,4,3,5,6",
  "eth_config": "",
  "ethtmout": "8",
  "gpio_exp_config": "",
  "host_name": "Player1",
  "i2c_config": "scl=27,sda=21,speed=400000,port=1",
  "jack_mutes_amp": "n",
  "led_brightness": "",
  "led_vu_config": "",
  "lms_ctrls_raw": "n",
  "loudness": "0",
  "metadata_config": "",
  "model_config": "",
  "ota_erase_blk": "249856",
  "ota_prio": "6",
  "ota_stack": "10240",
  "pollmin": "15",
  "pollmx": "600",
  "rel_api": "https://api.github.com/repos/sle118/squeezelite-esp32/releases",
  "release_url": "https://github.com/sle118/squeezelite-esp32/releases",
  "rotary_config": "",
  "set_GPIO": "33=vcc",
  "sleep_config": "",
  "spdif_config": "",
  "spi_config": "",
  "stats": "N",
  "target": "",
  "telnet_block": "500",
  "telnet_buffer": "40000",
  "telnet_enable": "D"
}

Logs

AAC :

[00:01:36.635] stream_thread:264 headers: len: 337
[00:01:36.670] codec_open:283 codec open: 'a'
[00:01:36.671] helixaac_open:593 opening adts stream
[00:01:37.287] helixaac_decode:423 setting track start, samplerate: 44100 channels: 2
[00:01:37.289] output_thread_i2s:518 Output state is 1
[00:01:37.292] output_thread_i2s:585 Restarting I2S.
[00:01:37.307] equalizer_process:222 equalizer actived
[00:01:37.420] _output_frames:65 start buffer frames: 13312
[00:01:37.424] _output_frames:150 track start sample rate: 44100 replay_gain: 0
[00:01:37.429] output_thread_i2s:518 Output state is 2

Working fine suddenly playback stopps and chrashes same song, same source.

[00:00:20.919] helixaac_open:593 opening adts stream
[00:00:22.021] output_thread_i2s:518 Output state is 1
[00:00:22.023] output_thread_i2s:585 Restarting I2S.
[00:00:22.027] equalizer_process:222 equalizer actived
[00:00:22.055] helixaac_decode:423 setting track start, samplerate: 44100 channels: 2
[00:00:22.140] _output_frames:65 start buffer frames: 15360
[00:00:22.145] _output_frames:150 track start sample rate: 44100 replay_gain: 0
[00:00:22.147] output_thread_i2s:518 Output state is 2
W (26218) wifi:lmac if1 stop, discard packet
[00:00:26.011] helixaac_decode:465 AAC decode error -15
[00:00:26.012] helixaac_decode:503 unable to decode further
[00:00:26.013] decode_thread:100 decode error
[00:00:32.984] output_thread_i2s:518 Output state is 0
[00:00:56.440] decode_flush:251 decode flush
[00:00:56.441] output_flush:446 flush output buffer
[00:00:56.447] codec_open:283 codec open: 'a'
[00:00:56.448] helixaac_open:593 opening adts stream
[00:00:56.454] stream_sock:508 connecting to 192.168.178.XXX:8096
[00:00:56.675] stream_thread:264 headers: len: 337
[00:00:56.745] codec_open:283 codec open: 'a'
[00:00:56.746] helixaac_open:593 opening adts stream
[00:00:57.643] output_thread_i2s:518 Output state is 1
[00:00:57.734] helixaac_decode:423 setting track start, samplerate: 44100 channels: 2
[00:00:57.829] _output_frames:65 start buffer frames: 17408
[00:00:57.831] _output_frames:150 track start sample rate: 44100 replay_gain: 0
[00:00:57.833] output_thread_i2s:518 Output state is 2
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.
Core  0 register dump:
PC      : 0x40081317  PS      : 0x00060930  A0      : 0x80081392  A1      : 0x3f809220  
A2      : 0xf0d3ff28  A3      : 0x00000000  A4      : 0x80081dbe  A5      : 0x3ffbed00  
A6      : 0x3ffbe020  A7      : 0x3ffc422c  A8      : 0x00000016  A9      : 0x3ffca2d0  
A10     : 0x00000003  A11     : 0x00060523  A12     : 0x800823e2  A13     : 0x3ffbece0  
A14     : 0x3ffc4388  A15     : 0x3ffc4390  SAR     : 0x0000000a  EXCCAUSE: 0x0000001c  
EXCVADDR: 0xf0d3ff2c  LBEG    : 0x40094024  LEND    : 0x40094040  LCOUNT  : 0x00000000  
Backtrace:0x40081314:0x3f809220 0x4008138f:0x3f809240 0x400fcb72:0x3f809260 0x400fbd4d:0x3f809280 0x400faeef:0x3f8092b0 0x400fb942:0x3f809310
ELF file SHA256: 0000000000000000

Changing the output to FLAC. But not lossless files. Coming from the same source:

[00:08:57.407] codec_open:283 codec open: 'f'
[00:08:57.910] write_cb:141 setting track_start
[00:08:57.950] output_thread_i2s:518 Output state is 1
[00:08:57.953] output_thread_i2s:585 Restarting I2S.
[00:08:57.959] equalizer_process:222 equalizer actived
[00:08:57.977] _output_frames:65 start buffer frames: 11520
[00:08:57.981] _output_frames:150 track start sample rate: 44100 replay_gain: 0
[00:08:57.985] output_thread_i2s:518 Output state is 2
[00:09:03.052] error_cb:233 flac error: FLAC__STREAM_DECODER_ERROR_STATUS_FRAME_CRC_MISMATCH
Rewinding, seeking not necessary
[00:09:03.054] error_cb:233 flac error: FLAC__STREAM_DECODER_ERROR_STATUS_LOST_SYNC
Guru Meditation Error: Core  0 panic'ed (InstrFetchProhibited). Exception was unhandled.
Core  0 register dump:
PC      : 0xa36a8a2a  PS      : 0x00050033  A0      : 0xa36a8a2a  A1      : 0x3f809200  
A2      : 0x03900340  A3      : 0x03800340  A4      : 0x0f800330  A5      : 0x3ffd66f8  
A6      : 0x0034002b  A7      : 0x00370020  A8      : 0x00000000  A9      : 0x3f809270  
A10     : 0x3ffc4388  A11     : 0x3ffbc670  A12     : 0x3ffc4388  A13     : 0x00060520  
A14     : 0x000000fe  A15     : 0x00000001  SAR     : 0x0000000a  EXCCAUSE: 0x00000014  
EXCVADDR: 0xa36a8a28  LBEG    : 0x40094024  LEND    : 0x40094040  LCOUNT  : 0x0000002b  
Backtrace:0x636a8a27:0x3f809200 0x636a8a27:0x000000fe |<-CORRUPTED

DerPicknicker commented 11 months ago

Tested with latest Musicasisistant which should correct some SlimProto things and again the Board now crashes with FLAC ``` output Method and FLAC input file:

I (12158) httpd_handlers: serving /messages.json to peer 192.168.178.168 port 235
[00:01:14.031] codec_open:283 codec open: 'f'
I (12268) httpd_handlers: serving /messages.json to peer 192.168.178.66 port 33788
[00:01:14.438] write_cb:141 setting track_start
[00:01:14.448] output_thread_i2s:518 Output state is 1
[00:01:14.478] output_thread_i2s:585 Restarting I2S.
[00:01:14.502] equalizer_process:222 equalizer actived
W (12678) httpd_txrx: httpd_sock_err: error in recv : 104
[00:01:14.548] _output_frames:65 start buffer frames: 13824
[00:01:14.550] _output_frames:150 track start sample rate: 44100 replay_gain: 0
[00:01:14.553] output_thread_i2s:518 Output state is 2
I (17718) httpd_handlers: serving /messages.json to peer 192.168.178.168 port 26347
I (23578) httpd_handlers: serving /messages.json to peer 192.168.178.168 port 26603
I (26718) httpd_handlers: serving /messages.json to peer 192.168.178.66 port 39420
I (30048) httpd_handlers: serving /messages.json to peer 192.168.178.168 port 62444
I (33428) httpd_handlers: serving /messages.json to peer 192.168.178.66 port 39676
I (39728) httpd_handlers: serving /status.json to peer 192.168.178.168 port 4078
Guru Meditation Error: Core  0 panic'ed (StoreProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x4009bf2e  PS      : 0x00060d33  A0      : 0x8009c4ae  A1      : 0x3ffbab10  
A2      : 0x3f813444  A3      : 0x3facb574  A4      : 0xc30a0d0e  A5      : 0x3f813444  
A6      : 0x000000fe  A7      : 0x00000001  A8      : 0x00000003  A9      : 0x00000000  
A10     : 0x405816f0  A11     : 0x0000000c  A12     : 0x3f813468  A13     : 0x3f8134a8  
A14     : 0x000000fe  A15     : 0x00000001  SAR     : 0x0000001d  EXCCAUSE: 0x0000001d  
EXCVADDR: 0xc30a0d1a  LBEG    : 0x400843bd  LEND    : 0x400843c5  LCOUNT  : 0x00000027  

Backtrace:0x4009bf2b:0x3ffbab10 0x4009c4ab:0x3ffbab30 0x40081f07:0x3ffbab50 0x40081f19:0x3ffbab80 0x40081fc1:0x3ffbaba0 0x40081bd1:0x3ffbabf0 0x40214eeb:0x3ffbac10 0x4021da03:0x3ffbac30 0x4021b1fd:0x3ffbac50 0x400dd29f:0x3ffbac70

DerPicknicker commented 11 months ago

Any hints @philippe44 @sle118 ?

philippe44 commented 11 months ago

I don't have time to investigate for now. Try to get an older version and report when the issue occurred. Thanks

sle118 commented 11 months ago

Do you have the same problem with LMS? If so, did the problem also occur on previous versions?

DerPicknicker commented 11 months ago

I will try that and give here an update

DerPicknicker commented 11 months ago

I will some time for debugging it. Could it be also an issue that I am using an unstable power supply. Another guy has also some restarting issues with the same board. So if it there is a possibility that its caused due bad power supply. I would close this until I get the PowerSupply stable....

rjgrandy commented 11 months ago

I also have an issue with playback stopping when using Music Assistant. However LMS is pretty stable for me.

Also MP3 lasts longer than FLAC

And it seems like streaming TuneIn works longer than when I stream from YouTube Music

Below is the logs from my issue with MA

[05:30:47.514111] send_packet:115 failed writing to socket: Connection reset by peer
[05:30:47.516137] slimproto_run:609 error reading from socket: Connection reset by peer
[05:30:47.628581] slimproto:989 connected
[05:30:47.629631] sendHELO:153 mac: 8c:4b:14:14:75:08
[05:30:47.630467] sendHELO:155 cap: Model=squeezeesp32,AccuratePlayPoints=1,HasDigitalOut=1,HasPolarityInversion=1,Balance=1,Depth=16,Firmware=v1.0-1023-16,ModelName=SqueezeESP32,MaxSampleRate=192000,alc,aac,ogg,ops,ogf,flc,wav,aif,pcm,mp3
[05:30:47.659214] notify:223 notified server 192.168.1.199 hport 8096 cport 9091
I (968139) wifi_manager: LMS IP: 192.168.1.199, hport: 8096, cport: 9091
[05:30:47.675545] process:562 unhandled vers
[05:30:47.677632] decode_flush:251 decode flush
[05:30:47.678391] output_flush:446 flush output buffer
[05:30:47.683394] decode_flush:251 decode flush
[05:30:47.684229] output_flush:446 flush output buffer
[05:30:47.696417] decode_flush:251 decode flush
[05:30:47.697177] output_flush:446 flush output buffer
[05:30:47.703573] decode_flush:251 decode flush
[05:30:47.704409] output_flush:446 flush output buffer
I (1022979) httpd_handlers: serving /status.json to peer 192.168.1.144 port 22245
I (1025869) httpd_handlers: serving /status.json to peer 192.168.1.144 port 26085

sle118 commented 11 months ago

slimproto_run:609 error reading from socket: Connection reset by peer

This seems to indicate that the issue is on the server side, not the player.

sle118 commented 10 months ago

Going to close for now. Feel free to reopen if you think this is necessary

sle118 / squeezelite-esp32