search

sle118 / squeezelite-esp32

ESP32 Music streaming based on Squeezelite, with support for multi-room sync, AirPlay, Bluetooth, Hardware buttons, display and more
1.07k stars 100 forks source link

Speaker makes loud static noise when it starts playing from LMS (Squeezebox). Serial logs show unhandled exception #403

Open digital-night opened 4 months ago

digital-night commented 4 months ago

Discussed in https://github.com/sle118/squeezelite-esp32/discussions/402

Originally posted by **digital-night** March 5, 2024 I have several ESP32 speakers that I mostly stream to using LMS (Squeezbox), content includes text to speech announcements, MP3, FLAC, and OGG audio. I haven't been able to identify all of the triggers, but fairly often my living room speaker will do this 3/4 of the time with the first sound of the morning. I setup a Pi to power / log the serial output and captured this info: ``` [2024-03-05 06:55:22.462] I (44132346) monitor: Heap internal:93755 (min:91187) external:830075 (min:607103) dma:85963 (min:83411) [2024-03-05 06:55:22.478] I (44132356) monitor: IDLE (1) 98% s: 948 pseudo_idle (0) 0% s: 2624 IDLE (1) 99% s: 956 [2024-03-05 06:55:22.484] I (44132356) monitor: tiT (2) 0% s: 1876 output_i2s (2) 0% s: 672 stream (2) 0% s: 2252 [2024-03-05 06:55:22.497] I (44132376) monitor: Tmr Svc (2) 0% s: 1016 squeezelite (2) 0% s: 3776 decode (2) 0% s: 8632 [2024-03-05 06:55:22.515] I (44132396) monitor: ipc1 (2) 0% s: 464 playerInstance (2) 0% s:29708 buttons (2) 0% s: 1544 [2024-03-05 06:55:22.535] I (44132416) monitor: console (2) 0% s: 692 telnet (2) 0% s: 3196 ipc0 (2) 0% s: 484 [2024-03-05 06:55:22.554] I (44132436) monitor: sys_evt (2) 0% s: 820 mdns (2) 0% s: 2032 wifi (2) 0% s: 3188 [2024-03-05 06:55:22.575] I (44132456) monitor: esp_timer (3) 0% s: 3260 httpd (2) 0% s: 1136 network (2) 0% s: 800 [2024-03-05 06:55:31.095] [16:58:31.287] decode_flush:251 decode flush [2024-03-05 06:55:31.096] [16:58:31.288] output_flush:446 flush output buffer (full) [2024-03-05 06:55:31.099] [16:58:31.290] codec_open:283 codec open: 'f' [2024-03-05 06:55:31.101] [16:58:31.292] stream_sock:660 connecting to 192.168.2.21:9000 [2024-03-05 06:55:31.105] [16:58:31.308] stream_sock:734 header: GET /stream.mp3?player=c8:c9:a3:d5:34:4c HTTP/1.0 [2024-03-05 06:55:31.108] [2024-03-05 06:55:31.108] [2024-03-05 06:55:31.205] [16:58:31.394] stream_thread:415 headers: len: 488 [2024-03-05 06:55:31.207] HTTP/1.1 200 OK [2024-03-05 06:55:31.208] Server: Logitech Media Server (8.3.1 - TRUNK) [2024-03-05 06:55:31.209] Connection: close [2024-03-05 06:55:31.211] Content-Type: audio/x-flac [2024-03-05 06:55:31.212] Set-Cookie: Squeezebox-albumView=; path=/ [2024-03-05 06:55:31.213] Set-Cookie: Squeezebox-expandPlayerControl=true; path=/ [2024-03-05 06:55:31.228] Set-Cookie: Squeezebox-expanded-MY_MUSIC=1; path=/ [2024-03-05 06:55:31.229] Set-Cookie: Squeezebox-expanded-FAVORITES=1; path=/ [2024-03-05 06:55:31.231] Set-Cookie: Squeezebox-expanded-PLUGINS=1; path=/ [2024-03-05 06:55:31.234] Set-Cookie: Squeezebox-expanded-PLUGIN_MY_APPS_MODULE_NAME=1; path=/ [2024-03-05 06:55:31.236] Set-Cookie: Squeezebox-expanded-RADIO=1; path=/ [2024-03-05 06:55:31.239] [2024-03-05 06:55:31.239] [2024-03-05 06:55:31.600] [16:58:31.811] output_thread_i2s:518 Output state is 5 [2024-03-05 06:55:31.612] [16:58:31.814] output_thread_i2s:585 Restarting I2S. [2024-03-05 06:55:31.644] [16:58:31.851] write_cb:145 setting track_start [2024-03-05 06:55:31.710] [16:58:31.907] _output_frames:150 track start sample rate: 44100 replay_gain: 0 [2024-03-05 06:55:31.735] [16:58:31.940] output_thread_i2s:518 Output state is 2 [2024-03-05 06:55:31.775] [16:58:31.963] i2s_stats:661 Output State: 2, current sample rate: 44100, bytes per frame: 4 [2024-03-05 06:55:31.779] [16:58:31.969] i2s_stats:662 +----------+----------+----------------+-----+----------------+ [2024-03-05 06:55:31.783] [16:58:31.975] i2s_stats:663 | max | min | average | | count | [2024-03-05 06:55:31.799] [16:58:31.986] i2s_stats:664 | (bytes) | (bytes) | (bytes) | | | [2024-03-05 06:55:31.804] [16:58:31.993] i2s_stats:665 +----------+----------+----------------+-----+----------------+ [2024-03-05 06:55:31.809] [16:58:31.999] i2s_stats:666 stream| 511999| 0| 255349| 49| 769| [2024-03-05 06:55:31.893] [16:58:32.083] i2s_stats:667 output| 209340| 0| 2168| 0| 1290| [2024-03-05 06:55:31.897] [16:58:32.090] i2s_stats:668 +----------+----------+----------------+-----+----------------+ [2024-03-05 06:55:31.915] [16:58:32.096] i2s_stats:669 received| 4096| 0| 2050| 0| 1446| [2024-03-05 06:55:31.918] [16:58:32.102] i2s_stats:670 +----------+----------+----------------+-----+----------------+ [2024-03-05 06:55:31.921] [16:58:32.119] i2s_stats:671 [2024-03-05 06:55:31.922] [16:58:32.121] i2s_stats:672 ----------+----------+-----------+-----------+ [2024-03-05 06:55:31.939] [16:58:32.126] i2s_stats:673 max (us) | min (us) | avg(us) | count | [2024-03-05 06:55:31.942] [16:58:32.131] i2s_stats:674 ----------+----------+-----------+-----------+ [2024-03-05 06:55:31.959] [16:58:32.147] i2s_stats:675 Buffering(us) 35453| 54| 144| 2140| [2024-03-05 06:55:31.961] [16:58:32.152] i2s_stats:676 i2s tfr(us) 90097| 66044| 88834| 387| [2024-03-05 06:55:31.964] [16:58:32.158] i2s_stats:677 ----------+----------+-----------+-----------+ [2024-03-05 06:55:32.894] [16:58:33.081] output_thread_i2s:518 Output state is 0 [2024-03-05 06:55:32.896] Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled. [2024-03-05 06:55:32.900] [2024-03-05 06:55:32.900] Core 0 register dump: [2024-03-05 06:55:32.901] PC : 0x401b00ac PS : 0x00060e30 A0 : 0x801b0e54 A1 : 0x3f809280 [2024-03-05 06:55:32.915] A2 : 0xffffffff A3 : 0x3f43ae0e A4 : 0x00000001 A5 : 0x00000001 [2024-03-05 06:55:32.919] A6 : 0x3f849478 A7 : 0xff000000 A8 : 0x00000000 A9 : 0x00000001 [2024-03-05 06:55:32.923] A10 : 0x3f809240 A11 : 0x00060023 A12 : 0x00060020 A13 : 0x3ff96355 [2024-03-05 06:55:32.939] A14 : 0x3f813ec8 A15 : 0x00000001 SAR : 0x00000007 EXCCAUSE: 0x0000001c [2024-03-05 06:55:32.942] EXCVADDR: 0x0000001f LBEG : 0x40095409 LEND : 0x40095419 LCOUNT : 0xfffffffc [2024-03-05 06:55:32.946] [2024-03-05 06:55:32.947] Backtrace:0x401b00a9:0x3f809280 0x401b0e51:0x3f8092a0 0x401011b1:0x3f8092c0 0x40101392:0x3f8092f0 0x400fb906:0x3f809310 [2024-03-05 06:55:32.952] [2024-03-05 06:55:32.952] [2024-03-05 06:55:32.952] ELF file SHA256: 0000000000000000 [2024-03-05 06:55:32.954] [2024-03-05 06:55:32.954] Rebooting... [2024-03-05 06:55:32.970] ets Jun 8 2016 00:22:57 [2024-03-05 06:55:32.971] ``` I haven't dug into what a Guru Meditation Error is. Is there any more information you'd like me to search for?
philippe44 commented 4 months ago

Which release is that so I can use the backtrace?

digital-night commented 4 months ago

Sorry, I should have listed that: Branch: master-v4.3 Build: 2.1670-16 Platform: Muse

digital-night commented 4 months ago

Let me also note, just for clarity: The LMS server version is: Logitech Media Server Version: 8.3.1 - TRUNK @ UNKNOWN

digital-night commented 3 months ago

Hi @philippe44 do you need any more information? Also, do you have a pointer to any articles on how to perform a back trace? I'd love to learn how to trace this back 😄 .

philippe44 commented 3 months ago

Just take the .map file and search for @ that matche what you have in the backtrace. Often, you need to remove the last digit of the address to find the closest match.

erwann2000 commented 3 months ago

I have the same issue with 2 muse luxe with synchronization. For example the morning, If I play on the first, the second reboot and make a big noise. If I play on the second, the first reboot and make a big noise. I tested many versions of squeezelite-esp32. And I have random reboot on play after long time without music.