sle118 / squeezelite-esp32

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

LED Vu crashes GDS when no display present #414

Closed anabolyc closed 3 months ago

anabolyc commented 7 months ago

Describe the bug

Home Assistant / Music Assistant has a built-in LMS server that allows using slimproto clients to play the audio directly from HA. Seems that some communication that comes from the built-in server crashes squeezelite-esp32.

When enabled squeezelite-esp32 immediately goes into the bootloop. As soon as disabled, it acts normally.

Preliminary Information

  1. fw: I2S-4MFlash-1672, mode: Squeezelite-ESP32
  2. slimproto built-in into version 2024.3.6

Hardware Details

NVS Settings

nvs_config_loud-esparagus_1714076880283json.txt


{
  "a2dp_ctmt": "1000",
  "a2dp_ctrld": "500",
  "a2dp_dev_name": "loud-esparagus",
  "a2dp_sink_name": "SMSL BT4.2",
  "a2dp_spin": "0000",
  "actrls_config": "",
  "airplay_name": "loud-esparagus",
  "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": "loud-esparagus",
  "autoexec": "1",
  "autoexec1": "squeezelite -o I2S -b 500:2000 -d all=info -C 30 -W -n loud-esparagus",
  "bat_config": "",
  "bt_name": "loud-esparagus",
  "bt_sink_pin": "1234",
  "bt_sink_volume": "127",
  "bypass_wm": "0",
  "cspot_config": "{\"deviceName\":\"loud-esparagus\",\"bitrate\":160,\"zeroConf\":1}",
  "dac_config": "model=I2S,bck=26,ws=25,do=22",
  "dac_controlset": "",
  "dhcp_tmout": "8",
  "display_config": "",
  "enable_airplay": "Y",
  "enable_bt_sink": "Y",
  "enable_cspot": "Y",
  "equalizer": "",
  "eth_config": "",
  "ethtmout": "8",
  "gpio_exp_config": "",
  "host_name": "loud-esparagus",
  "i2c_config": "",
  "jack_mutes_amp": "n",
  "led_brightness": "",
  "led_vu_config": "type=[WS2812],length=1,gpio=33",
  "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": "CONFIG_SQUEEZELITE_ESP32_RELEASE_URL",
  "rotary_config": "",
  "set_GPIO": "39=ir",
  "sleep_config": "",
  "spdif_config": "",
  "spi_config": "",
  "stats": "Y",
  "target": "",
  "telnet_block": "500",
  "telnet_buffer": "40000",
  "telnet_enable": "D"
}

Logs



 rst:0xc (SW_CPU_RESET),boot:0x13 (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:1
load:0x3fff0030,len:6424
load:0x40078000,len:15632
load:0x40080400,len:4348
entry 0x40080688
I (27) boot: ESP-IDF v4.3.5-dirty 2nd stage bootloader
I (27) boot: compile time 03:05:16
I (27) boot: chip revision: v3.1
I (31) qio_mode: Enabling default flash chip QIO
I (36) boot.esp32: SPI Speed      : 80MHz
I (41) boot.esp32: SPI Mode       : QIO
I (45) boot.esp32: SPI Flash Size : 4MB
I (50) boot: Enabling RNG early entropy source...
I (55) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (74) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (81) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (88) boot:  3 recovery         factory app      00 00 00010000 00140000
I (96) boot:  4 ota_0            OTA app          00 10 00150000 002a0000
I (103) boot:  5 settings         WiFi data        01 02 003f0000 00010000
I (111) boot: End of partition table
I (115) esp_image: segment 0: paddr=00150020 vaddr=3f400020 size=aeaf0h (715504) map
I (321) esp_image: segment 1: paddr=001feb18 vaddr=3ffbdb60 size=01500h (  5376) load
I (323) esp_image: segment 2: paddr=00200020 vaddr=400d0020 size=1b2e5ch (1781340) map
I (817) esp_image: segment 3: paddr=003b2e84 vaddr=3ffbf060 size=0453ch ( 17724) load
I (823) esp_image: segment 4: paddr=003b73c8 vaddr=40080000 size=1e014h (122900) load
I (863) esp_image: segment 5: paddr=003d53e4 vaddr=400c0000 size=00068h (   104) load
I (878) boot: Loaded app from partition at offset 0x150000
I (878) boot: Disabling RNG early entropy source...
I (890) psram: This chip is ESP32-D0WD
I (890) spiram: Found 64MBit SPI RAM device
I (890) spiram: SPI RAM mode: flash 80m sram 80m
I (893) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (901) cpu_start: Pro cpu up.
I (904) cpu_start: Starting app cpu, entry point is 0x400813fc
I (897) cpu_start: App cpu up.
I (1410) spiram: SPI SRAM memory test OK
I (1422) cpu_start: Pro cpu start user code
I (1422) cpu_start: cpu freq: 240000000
I (1422) cpu_start: Application information:
I (1425) cpu_start: Project name:     Squeezelite-ESP32
I (1431) cpu_start: App version:      I2S-4MFlash-1672
I (1437) cpu_start: Compile time:     Mar 22 2024 03:06:48
I (1443) cpu_start: ELF file SHA256:  0000000000000000...
I (1449) cpu_start: ESP-IDF:          v4.3.5-dirty
I (1455) cpu_start: Min chip rev:     v1.0
I (1460) cpu_start: Max chip rev:     v3.99 
I (1465) cpu_start: Chip rev:         v3.1
I (1470) heap_init: Initializing. RAM available for dynamic allocation:
I (1477) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1483) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (1489) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (1495) heap_init: At 3FFC6EC8 len 00019138 (100 KiB): DRAM
I (1502) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1508) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1515) heap_init: At 4009E014 len 00001FEC (7 KiB): IRAM
I (1521) spiram: Adding pool of 4018K of external SPI memory to heap allocator
I (1529) spi_flash: detected chip: gd
I (1533) spi_flash: flash io: qio
W (1537) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (1553) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1561) spiram: Reserving pool of 64K of internal memory for DMA/internal allocations
I (1571) esp_app_main: Reset reason is: 3
I (1571) esp_app_main: Reboot counter=1

I (1581) esp_app_main: Starting app_main
I (1581) nvs_utilities: Initializing flash nvs 
I (1601) nvs_utilities: Initializing nvs partition settings
I (1631) esp_app_main: Setting up telnet.
I (1631) telnet: ***Redirecting log output to telnet
I (1631) esp_app_main: Setting up config subsystem.
W (1711) nvs_utilities: Configuration memory usage.  Heap internal:228835 (min:228695) (used:216) external:4054843 (min:4047271) (used:15512)
I (1711) esp_app_main: Registering default values
I (1721) system_api: Base MAC address is not set
I (1721) system_api: read default base MAC address from EFUSE
W (1731) config: Waiting for config commit ...
I (2711) config: configuration has some uncommitted entries
I (2711) config: Committing configuration to nvs. Locking config object.
I (2711) config: Done Committing configuration to nvs.
I (2711) config: Config committed!
I (2721) esp_app_main: Configuring services
I (2721) services: Configuring I2C sda:-1 scl:-1 port:1 speed:400000
W (2731) services: no I2C configured
I (2731) services: Configuring SPI mosi:-1 miso:-1 clk:-1 host:1 dc:-1
W (2741) services: no SPI configured
W (2751) led: LED GPIO -1 ignored
W (2751) led: LED GPIO -1 ignored
I (2751) led: Configuring LEDs green:-1 (on:0 rmt:-1 -1% ), red:-1 (on:0 rmt:-1 -1% )
I (2761) battery: No battery
I (2771) monitor: Initializing monitoring
I (2771) monitor: Heap internal:229511 (min:228507) external:4038259 (min:4038243) dma:221719 (min:220731)
I (2781) esp_app_main: Initializing display
I (2791) display: Trying to configure display with N/A
W (2791) display: No display driver
I (2801) esp_app_main: Initializing led_vu
I (2801) led_vu: vu meter using length:1 left:0 right:0 status:0 scale:100
I (2811) led_vu: led_vu using gpio:33 length:1 on channel:0
I (2811) esp_app_main: Checking for update url
W (2821) config: Value not found for key fwurl
I (2821) IR: Starting Infrared Receiver mode nec on gpio 39 and channel 7
I (2831) buttons: Created infrared receiver using GPIO 39
I (2831) buttons: starting button taW (2851) config: Value not found for key apdelay
I (2851) uart: queue free spaces: 3
I (2851) network_handlers: Network manager configuration: polling max 10176, polling min 15000, ap delay 20000, dhcp timeout 8000, eth timeout 8000
I (2881) http_server: Initializing HTTP Server
I (2881) network_ethernet: Attempting to initialize Ethernet
I (2891) network_ethernet: No Ethernet configuration, or configuration invalid
I (2911) wifi:wifi driver task: 3ffdfb20, prio:23, stack:6656, core=0
I (2911) wifi:wifi firmware version: 9ec65ef
I (2911) wifi:wifi certification version: v7.0
I (2911) wifi:config NVS flash: enabled
I (2921) wifi:config nano formating: disabled
I (2921) wifi:Init data frame dynamic rx buffer num: 40
I (2921) wifi:Init management frame dynamic rx buffer num: 40

I (2931) wifi:Init management short buffer num: 32
I (2941) wifi:Init static tx buffer num: 12
I (2941) wifi:Init tx cache buffer num: 32Type 'help' to get the list of commands.
Use UP/DOWN arrows to navigate through command history.
Press TAB when typing command name to auto-complete.

I (2961) wifi:Init static rx buffer size: 1600
I (2961) wifi:Init static rx buffer num: 12
I (2961) wifi:Init dynamic rx buffer num: 40To automatically execute lines at startup:
    Set NVS variable autoexec (U8) = 1 to enable, 0 to disable automatic execution.
    Set NVS variable autoexec[1~9] (string)to a command that should be executed automatically

I (2991) wifi_init: tcpip mbox: 32

I (3001) wifi_init: udp mbox: 32
I (3001) wifi_init: tcp mbox: 32
I (3001) wifi_init: tcp tx win: 8192

****************************
Your terminal application does not support escape sequences.
Line editing and history features are disabled.
On Windows, try using Putty instead.
****************************
I (3011) wifi_init: tcp rx win: 32768
W (3021) console: Processing autoexec commands while network manager active.  Wifi related commands will be ignored.
I (3031) wifi_init: tcp mss: 1440
I (3041) console: autoexec is set to perform auto-process
I (3041) wifi_init: WiFi/LWIP prefer SPIRAM
I (3041) console: Running command autoexec1 = squeezelite -o I2S -b 500:2000 -d all=info -C 30 -W -n loud-esparagus
I (3061) network_wifi: Starting wifi
W (3071) config: Value not found for key autoexec2
I (3071) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (3071) squeezelite_cmd: Calling squeezelite
squeezelite-esp32> [00:10:53.315] sb_controls_init:249 initializing audio (buttons/rotary/ir) controls (raw:0)
[00:10:53.329] sendSETD:440 sending dimension display:0x0 led_config:1
[00:10:53.331] stream_init:539 init stream
[00:10:53.332] output_init_embedded:78 init device: I2S
[00:10:53.344] output_init_common:433 supported rates: 192000 176400 96000 88200 48000 44100 32000 24000 22050 16000 12000 11025 8000 
[00:10:53.356] output_init_embedded:100 init I2S/SPDIF
W (3131) DAC core: DAC does not use i2c
I (3141) DAC external: DAC on I2C @0
W (3141) DAC external: no i2c controlset found
[00:10:53.369] output_init_i2s:347 configuring MCLK on GPIO -1
[00:10:53.380] output_init_i2s:359 invalid MCK gpio -1
I (3151) I2S: DMA Malloc info, datalen=blocksize=2048, dma_buf_count=12
I (3161) I2S: APLL: Req RATE: 44100, real rate: 44099.988, BITS: 16, CLKM: 1, BCK_M: 8, MCLK: 11289597.000, SCLK: 1411199I (3171) wifi:.625000, diva: 1, divb: 0
mode : sta (64:b7:08:d1:d8:10)
[00:10:53.406] output_init_i2s:376 I2S DAC using I2S bck:26, ws:25, do:22, mute:-1:0 (res:0)
I (3181) wifi:enable tsf[00:10:53.418] output_init_i2s:396 Initializing I2S mode normal with rate: 44100, bits per sample: 16, buffer frames: 512, number of buffers: 12 

[00:10:53.430] equalizer_set_samplerate:121 equalizer sample rate 44100
I (3201) network_handlers: Existing wifi config found. Attempting to connect.
[00:10:53. output_thread_i2s:518 Output state is -1
I (3211) network: Starting DHCP client
[00:10:53.443] output_visu_init:75 Initialize VISUEXPORT 512 16 bits samples
[00:10:53.455] output_thread_i2s:522 switching off amp GPIO -1
I (3231) network_wifi: Wifi Connecting to wifi-12-private...
[00:10:53.458] output_init_embedded:108 init completed.
[00:10:53.481] decode_init:153 init decode
[00:10:53.482] register_alac:547 using alac to decode alc
[00:10:53.483] register_helixaac:686 using helix-aac to decode aac
[00:10:53.494] register_vorbis:526 using vorbis to decode ogg
[00:10:53.494] register_opus:458 using opus to decode ops
[00:10:53.505] register_flac:338 using flac to decode ogf,flc
[00:10:53.506] register_pcm:468 using pcm to decode wav,aif,pcm
[00:10:53.517] register_mad:417 using mad to decode mp3
W (3291) BT_AV: BT Sink pin code is: [1234] 
I (3291) BTDM_INIT: BT controller compile version [2c56073]
[00:10:53.531] register_external:469 Initializing AirPlay sink
[00:10:53.533] register_external:480 Initializing CSpot sink
[00:10:53.547] discover_server:844 sending discovery 25
[00:10:53.548] discover_server:848 error sending discovery
I (3661) BT_AV: Bluetooth Init complete
I (5191) wifi:new:<13,2>, old:<1,0>, ap:<255,255>, sta:<13,2>, prof:1
I (5711) wifi:state: init -> auth (b0)
I (5711) wifi:state: auth -> assoc (0)
I (5721) wifi:state: assoc -> run (10)
I (5741) wifi:connected with wifi-12-private, aid = 11, channel 13, 40D, bssid = 34:5d:9e:5f:a5:c4
I (5741) wifi:security: WPA2-PSK, phy: bgn, rssi: -59
I (5751) wifi:pm start, type: 1

I (5771) network: Got an IP address from interface Wifi. IP=192.168.1.194, Gateway=192.168.1.1, NetMask=255.255.255.0, Address was changed
I (5771) esp_netif_handlers: sta ip: 192.168.1.194, mask: 255.255.255.0, gw: 192.168.1.1
I (5791) esp_app_main: Network connected and mDNS initialized with loud-esparagus
I (5791) wifi:AP's beacon interval = 102400 us, DTIM period = 1
[00:10:56.031] raop_sink_start:178 starting Airplay for ip 192.168.1.194 with servicename loud-esparagus
[00:10:56.044] raop_create:201 starting mDNS with 64B708D1D810@loud-esparagus
I (5831) cspot: starting Spotify on host loud-esparagus
[00:10:56.088] I Shim.cpp:344: CSpot instance service name loud-esparagus (id 142137fd329622137a1490160000001746976115)
[00:10:56.092] I Shim.cpp:331: ZeroConf mode (port 80)
I (7681) httpd_handlers: serving /status.json to peer 192.168.1.16 port 10894
I (7731) httpd_handlers: serving /config.json to peer 192.168.1.16 port 8334
[00:10:58.551] discover_server:844 sending discovery 24
I (11871) monitor: Heap internal:62323 (min:61839) external:1189983 (min:1179903) dma:54531 (min:54063)
[00:11:03.551] discover_server:844 sending discovery 23
[00:11:08.551] discover_server:844 sending discovery 22
I (21891) monitor: Heap internal:62103 (min:61839) external:1188939 (min:1179903) dma:54311 (min:54063)
I (21901) monitor:             IDLE (1) 96% s:  948     pseudo_idle (0)  0% s: 3312            IDLE (1) 99% s: 1052
I (21901) monitor:       output_i2s (2)  0% s: 2032          decode (2)  0% s:14020             tiT (2)  0% s: 1880
I (21921) monitor:          Tmr Svc (2)  0% s: 1192     squeezelite (2)  0% s: 3776          stream (2)  0% s: 3732
I (21941) monitor:           telnet (2)  0% s: 3200         console (2)  0% s:  868    sb_displayer (3)  0% s: 2560
I (21961) monitor:             ipc1 (2)  0% s:  416          BtAppT (2)  0% s: 1468        BTC_TASK (2)  0% s:  872
I (21971) monitor:             hciT (2)  0% s: 1572        BTU_TASK (2)  0% s: 3304            ipc0 (2)  0% s:  484
I (21971) monitor:          sys_evt (2)  0% s:  596            RTSP (2)  0% s: 7404  playerInstance (2)  0% s:29708
I (22001) monitor:             mdns (2)  0% s: 2344         network (2)  0% s:  812           httpd (2)  0% s: 1140
I (22001) monitor:     btController (2)  1% s: 2120            wifi (2)  1% s: 3188       esp_timer (3)  0% s: 3372
I (22021) monitor:          buttons (2)  0% s: 1544  led_strip_task (2)  0% s:  456
[00:11:13.551] discover_server:844 sending discovery 21
[00:11:18.551] discover_server:844 sending discovery 20
[00:11:18.561] discover_server:856 got response from: 192.168.1.224:3483
[00:11:18.562] slimproto:964 connecting to 192.168.1.224:3483
[00:11:18.572] slimproto:1011 connected
[00:11:18.574] sendHELO:153 mac: 64:b7:08:d1:d8:10
[00:11:18.574] sendHELO:155 cap: Model=squeezeesp32,AccuratePlayPoints=1,HasDigitalOut=1,HasPolarityInversion=1,Balance=1,Depth=16,Firmware=v1.0-1672-16,ModelName=SqueezeESP32,MaxSampleRate=192000,alc,aac,ogg,ops,ogf,flc,wav,aif,pcm,mp3
[00:11:18.599] sendSETD:440 sending dimension display:0x0 led_config:1
[00:11:18.608] notify:228 notified server 192.168.1.224 hport 9000 cport 9090
I (28381) network_status: LMS IP: 192.168.1.224, hport: 9000, cport: 9090
[00:11:18.613] process:578 unhandled vers
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.

Core  1 register dump:
PC      : 0x4026ec2f  PS      : 0x00060f30  A0      : 0x80102b8f  A1      : 0x3f801a20  
A2      : 0x00000000  A3      : 0x3ffbb1fc  A4      : 0x00000001  A5      : 0x00000000  
A6      : 0x00000000  A7      : 0x00000000  A8      : 0x80098de7  A9      : 0x3f8019e0  
A10     : 0x3ffc4388  A11     : 0x3ffbf5a8  A12     : 0x3ffc438c  A13     : 0x00060f20  
A14     : 0x000000fe  A15     : 0x00000001  SAR     : 0x0000001a  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000080  LBEG    : 0x40093da8  LEND    : 0x40093dc4  LCOUNT  : 0xffffffff  

Backtrace:0x4026ec2c:0x3f801a20 0x40102b8c:0x3f801a40 0x400fb3b9:0x3f801b20 0x400fbe1d:0x3f801b40 0x400ff57a:0x3f801b60 0x400fa0cb:0x3f801c40 0x400de558:0x3f801f70

ELF file SHA256: 0000000000000000

Rebooting...

Issue Description

  1. Observed Behavior: Presense of the HA slimproto server in the network cause device to bootloop
  2. Expected Behavior: Server should be discovered and paired normally
  3. Steps to Reproduce: 3.1. Make sure squeezelite-esp32 device boots and start LMS server discovery 3.2. Enable slimproto player provider in the HA / MA 3.3. Observe squeezelite-esp32 crash and bootloop within seconds.

If you guide me to investigate and possibly fix this issue, I would be happy to do it myself. From the looks of it, seems that message is malformed or at least does not look as expected. I tried to enable more logging via telnet, but this yield no more information that standard logs have

sle118 commented 7 months ago

for the record, the stack trace decodes as follow:

0x4026ec2c: GDS_DisplayOn at ../components/display/core/gds.c line 318
0x40102b8c: handler at ../components/squeezelite/displayer.c line 749
0x400fb3b9: handler at ../components/squeezelite/output_embedded.c line 70
0x400fbe1d: handler at ../components/squeezelite/output_i2s.c line 167
0x400ff57a: slimproto at ../components/squeezelite/slimproto.c line 809
0x400fa0cb: squeezelite_main at ../components/squeezelite/main.c line 820
0x400de558: squeezelite_thread at ../components/platform_console/app_squeezelite/cmd_squeezelite.c line 79

https://github.com/sle118/squeezelite-esp32/blob/12aa555ff30c7c632bd7bf906d632918b10f4e08/components/display/core/gds.c#L318

it seems like Music Assistant is sending some display commands even if there is no display.

Could you try to disable the led vu and see if the issue is still happening?

@philippe44 one way to prevend this would be to ensure that we have a valid display pointer in the GDS code. For example

void GDS_DisplayOn( struct GDS_Device* Device ) { if (Device && Device->DisplayOn) Device->DisplayOn( Device ); } instead of void GDS_DisplayOn( struct GDS_Device* Device ) { if (Device->DisplayOn) Device->DisplayOn( Device ); }

HA-TB303 commented 7 months ago

I have the same issue and I am not using Music Assistant.

sle118 commented 7 months ago

@HA-TB303 do you have the led_vu enabled?

anabolyc commented 7 months ago

Could you try to disable the led vu and see if the issue is still happening?

I can confirm that disabling led vu fix the issue.


rst:0x1 (POWERON_RESET),boot:0x13 (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:1
load:0x3fff0030,len:6424
load:0x40078000,len:15632
load:0x40080400,len:4348
entry 0x40080688
I (27) boot: ESP-IDF v4.3.5-dirty 2nd stage bootloader
I (27) boot: compile time 03:05:16
I (27) boot: chip revision: v3.1
I (31) qio_mode: Enabling default flash chip QIO
I (36) boot.esp32: SPI Speed      : 80MHz
I (41) boot.esp32: SPI Mode       : QIO
I (45) boot.esp32: SPI Flash Size : 4MB
I (50) boot: Enabling RNG early entropy source...
I (55) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (74) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (81) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (89) boot:  3 recovery         factory app      00 00 00010000 00140000
I (96) boot:  4 ota_0            OTA app          00 10 00150000 002a0000
I (104) boot:  5 settings         WiFi data        01 02 003f0000 00010000
I (111) boot: End of partition table
I (115) esp_image: segment 0: paddr=00150020 vaddr=3f400020 size=aeaf0h (715504) map
I (321) esp_image: segment 1: paddr=001feb18 vaddr=3ffbdb60 size=01500h (  5376) load
I (323) esp_image: segment 2: paddr=00200020 vaddr=400d0020 size=1b2e5ch (1781340) map
I (818) esp_image: segment 3: paddr=003b2e84 vaddr=3ffbf060 size=0453ch ( 17724) load
I (823) esp_image: segment 4: paddr=003b73c8 vaddr=40080000 size=1e014h (122900) load
I (863) esp_image: segment 5: paddr=003d53e4 vaddr=400c0000 size=00068h (   104) load
I (878) boot: Loaded app from partition at offset 0x150000
I (879) boot: Disabling RNG early entropy source...
I (890) psram: This chip is ESP32-D0WD
I (890) spiram: Found 64MBit SPI RAM device
I (890) spiram: SPI RAM mode: flash 80m sram 80m
I (893) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (901) cpu_start: Pro cpu up.
I (904) cpu_start: Starting app cpu, entry point is 0x400813fc
I (0) cpu_start: App cpu up.
I (1410) spiram: SPI SRAM memory test OK
I (1423) cpu_start: Pro cpu start user code
I (1423) cpu_start: cpu freq: 240000000
I (1423) cpu_start: Application information:
I (1426) cpu_start: Project name:     Squeezelite-ESP32
I (1432) cpu_start: App version:      I2S-4MFlash-1672
I (1437) cpu_start: Compile time:     Mar 22 2024 03:06:48
I (1444) cpu_start: ELF file SHA256:  0000000000000000...
I (1450) cpu_start: ESP-IDF:          v4.3.5-dirty
I (1455) cpu_start: Min chip rev:     v1.0
I (1460) cpu_start: Max chip rev:     v3.99 
I (1465) cpu_start: Chip rev:         v3.1
I (1470) heap_init: Initializing. RAM available for dynamic allocation:
I (1477) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1483) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (1489) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (1495) heap_init: At 3FFC6EC8 len 00019138 (100 KiB): DRAM
I (1502) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1508) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1515) heap_init: At 4009E014 len 00001FEC (7 KiB): IRAM
I (1521) spiram: Adding pool of 4018K of external SPI memory to heap allocator
I (1529) spi_flash: detected chip: gd
I (1533) spi_flash: flash io: qio
W (1537) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (1553) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1561) spiram: Reserving pool of 64K of internal memory for DMA/internal allocations
I (1571) esp_app_main: System is booting from power on.
I (1581) esp_app_main: Reset reason is: 1
I (1581) esp_app_main: Reboot counter=1

I (1581) esp_app_main: Starting app_main
I (1591) nvs_utilities: Initializing flash nvs 
I (1611) nvs_utilities: Initializing nvs partition settings
I (1641) esp_app_main: Setting up telnet.
I (1641) telnet: Telnet support disabled
I (1641) esp_app_main: Setting up config subsystem.
W (1711) nvs_utilities: Configuration memory usage.  Heap internal:228939 (min:228815) (used:216) external:4095127 (min:4087635) (used:15488)
I (1711) esp_app_main: Registering default values
I (1721) system_api: Base MAC address is not set
I (1721) system_api: read default base MAC address from EFUSE
W (1731) config: Waiting for config commit ...
I (2711) config: configuration has some uncommitted entries
I (2711) config: Committing configuration to nvs. Locking config object.
I (2711) config: Done Committing configuration to nvs.
I (2711) config: Config committed!
I (2721) esp_app_main: Configuring services
I (2721) services: Configuring I2C sda:-1 scl:-1 port:1 speed:400000
W (2731) services: no I2C configured
I (2731) services: Configuring SPI mosi:-1 miso:-1 clk:-1 host:1 dc:-1
W (2741) services: no SPI configured
W (2751) led: LED GPIO -1 ignored
W (2751) led: LED GPIO -1 ignored
I (2751) led: Configuring LEDs green:-1 (on:0 rmt:-1 -1% ), red:-1 (on:0 rmt:-1 -1% )
I (2761) battery: No battery
I (2771) monitor: Initializing monitoring
I (2771) monitor: Heap internal:229615 (min:228723) external:4078543 (min:4078527) dma:221823 (min:220947)
I (2781) esp_app_main: Initializing display
I (2791) display: Trying to configure display with N/A
W (2791) display: No display driver
I (2801) esp_app_main: Initializing led_vu
I (2801) led_vu: led_vu configuration invalid
I (2801) esp_app_main: Checking for update url
W (2811) config: Value not found for key fwurl
I (2821) IR: Starting Infrared Receiver mode nec on gpio 39 and channel 7
I (2821) buttons: Created infrared receiver using GPIO 39
I (2821) buttons: starting button tasks
W (2831) config: Value not found for key 
0;33mW (2851) config: Value not found for key apdelay
I (2851) uart: queue free spaces: 3
I (2851) network_handlers: Network manager configuration: polling max 10176, polling min 15000, ap delay 20000, dhcp timeout 8000, eth timeout 8000
I (2881) http_server: Initializing HTTP Server
I (2881) network_ethernet: Attempting to initialize Ethernet
I (2881) network_ethernet: No Ethernet configuration, or configuration invalid
I (2901) wifi:wifi driver task: 3ffdfdec, prio:23, stack:6656, core=0
I (2901) wifi:wifi firmware version: 9ec65ef
I (2901) wifi:wifi certification version: v7.0
I (2911) wifi:config NVS flash: enabled
I (2911) wifi:config nano formating: disabled
I (2911) wifi:Init data frame dynamic rx buffer num: 40
I (2921) wifi:Init management frame dynamic rx buffer num: 40
I (2921) wifi:Init management short buffer num: 32
I (2921) wifi:Init static tx buffer num: 12
I (2931) wifi:Init tx cache buffer num: 32
I (2941) wifi:Init static rx buffer size: 1600
I (2941) wifi:Init static rx buffer num: 12
I (2951) wifi:Init dynamic rx buffer num: 40
I (2951) wifi_init: tcpip mbox: 32
I (2951) wifi_init: udp mbox: 32
I (2961) wifi_init: tcp mbox: 32
I (2961) wifi_init: tcp tx win: 8192
I (2961) wifi_init: tcp rx win: 32768
I (2971) wifi_init: tcp mss: 1440
I (2971) wifi_init: WiFi/LWIP prefer SPIRAM
I (2971) network_wifi: Starting wifi
I (2981) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (3081) wifi:mode : sta (64:b7:08:d1:d8:10)
I (3081) wifi:enable tsf
I (3081) network_handlers: Existing wifi config found. Attempting to connect.
I (3081) network: Starting DHCP client
I (3101) network_wifi: Wifi Connecting to wifi-12-private...

Type 'help' to get the list of commands.
Use UP/DOWN arrows to navigate through command history.
Press TAB when typing command name to auto-complete.

To automatically execute lines at startup:
    Set NVS variable autoexec (U8) = 1 to enable, 0 to disable automatic execution.
    Set NVS variable autoexec[1~9] (string)to a command that should be executed automatically

****************************
Your terminal application does not support escape sequences.
Line editing and history features are disabled.
On Windows, try using Putty instead.
****************************
W (3161) console: Processing autoexec commands while network manager active.  Wifi related commands will be ignored.
I (3161) console: autoexec is set to perform auto-process
I (3171) console: Running command autoexec1 = squeezelite -o I2S -b 500:2000 -d all=info -C 30 -W -n loud-esparagus
W (3181) config: Value not found for key autoexec2
squeezelite-esp32> I (3181) squeezelite_cmd: Calling squeezelite
[00:00:01.770] sb_controls_init:249 initializing audio (buttons/rotary/ir) controls (raw:0)
[00:00:01.782] sb_displayer_init:327 no display or led visualizer for LMS
[00:00:01.783] stream_init:539 init stream
[00:00:01.783] output_init_embedded:78 init device: I2S
[00:00:01.795] output_init_common:433 supported rates: 192000 176400 96000 88200 48000 44100 32000 24000 22050 16000 12000 11025 8000 
[00:00:01.808] output_init_embedded:100 init I2S/SPDIF
W (3231) DAC core: DAC does not use i2c
I (3231) DAC external: DAC on I2C @0
W (3241) DAC external: no i2c controlset found
[00:00:01.821] output_init_i2s:347 configuring MCLK on GPIO -1
[00:00:01.832] output_init_i2s:359 invalid MCK gpio -1
I (3251) I2S: DMA Malloc info, datalen=blocksize=2048, dma_buf_count=12
I (3271) 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
[00:00:01.857] output_init_i2s:376 I2S DAC using I2S bck:26, ws:25, do:22, mute:-1:0 (res:0)
[00:00:01.858] output_init_i2s:396 Initializing I2S mode normal with rate: 44100, bits per sample: 16, buffer frames: 512, number of buffers: 12 
[00:00:01.880] equalizer_set_samplerate:121 equalizer sample rate 44100
[00:00:01. output_thread_i2s:518 Output state is -1
[00:00:01.881] output_visu_init:75 Initialize VISUEXPORT 512 16 bits samples
[00:00:01.882] output_thread_i2s:522 switching off amp GPIO -1
[00:00:01.893] output_init_embedded:108 init completed.
[00:00:01.905] decode_init:153 init decode
[00:00:01.905] register_alac:547 using alac to decode alc
[00:00:01.916] register_helixaac:686 using helix-aac to decode aac
[00:00:01.918] register_vorbis:526 using vorbis to decode ogg
[00:00:01.919] register_opus:458 using opus to decode ops
[00:00:01.930] register_flac:338 using flac to decode ogf,flc
[00:00:01.930] register_pcm:468 using pcm to decode wav,aif,pcm
[00:00:01.941] register_mad:417 using mad to decode mp3
W (3361) BT_AV: BT Sink pin code is: [1234] 
I (3361) BTDM_INIT: BT controller compile version [2c56073]
[00:00:01.955] register_external:469 Initializing AirPlay sink
[00:00:01.957] register_external:480 Initializing CSpot sink
[00:00:01.971] discover_server:844 sending discovery 25
[00:00:01.972] discover_server:848 error sending discovery
I (3741) BT_AV: Bluetooth Init complete
I (5021) wifi:new:<13,2>, old:<1,0>, ap:<255,255>, sta:<13,2>, prof:1
I (5541) wifi:state: init -> auth (b0)
I (5541) wifi:state: auth -> assoc (0)
I (5551) wifi:state: assoc -> run (10)
I (5581) wifi:connected with wifi-12-private, aid = 13, channel 13, 40D, bssid = 34:5d:9e:5f:a5:c4
I (5581) wifi:security: WPA2-PSK, phy: bgn, rssi: -66
I (5591) wifi:pm start, type: 1

I (5601) network: Got an IP address from interface Wifi. IP=192.168.1.154, Gateway=192.168.1.1, NetMask=255.255.255.0, Address was changed
I (5611) esp_netif_handlers: sta ip: 192.168.1.154, mask: 255.255.255.0, gw: 192.168.1.1
I (5621) esp_app_main: Network connected and mDNS initialized with loud-esparagus
[00:00:04.211] raop_sink_start:178 starting Airplay for ip 192.168.1.154 with servicename loud-esparagus
[00:00:04.214] raop_create:201 starting mDNS with 64B708D1D810@loud-esparagus
I (5661) cspot: starting Spotify on host loud-esparagus
I (5671) wifi:AP's beacon interval = 102400 us, DTIM period = 1
[00:00:04.269] I Shim.cpp:344: CSpot instance service name loud-esparagus (id 142137fd329622137a1490160000001746976115)
[00:00:04.282] I Shim.cpp:331: ZeroConf mode (port 80)
I (8111) httpd_handlers: serving /status.json to peer 192.168.1.16 port 13987
[00:00:06.969] discover_server:844 sending discovery 24
[00:00:06.975] discover_server:856 got response from: 192.168.1.48:3483
[00:00:06.977] slimproto:964 connecting to 192.168.1.48:3483
[00:00:06.982] slimproto:1011 connected
[00:00:06.984] sendHELO:153 mac: 64:b7:08:d1:d8:10
[00:00:06.984] sendHELO:155 cap: Model=squeezeesp32,AccuratePlayPoints=1,HasDigitalOut=1,HasPolarityInversion=1,Balance=1,Depth=16,Firmware=v1.0-1672-16,ModelName=SqueezeESP32,MaxSampleRate=192000,alc,aac,ogg,ops,ogf,flc,wav,aif,pcm,mp3
[00:00:07.026] notify:228 notified server 192.168.1.48 hport 9000 cport 9090
I (8451) network_status: LMS IP: 192.168.1.48, hport: 9000, cport: 9090
[00:00:07.040] process:578 unhandled vers
[00:00:07.043] process:578 unhandled grfb
[00:00:07.046] process:578 unhandled grfe
[00:00:07.048] process:578 unhandled grfe
[00:00:07.061] process:578 unhandled grfe
[00:00:12.138] process:578 unhandled grfe
[00:00:17.360] process:578 unhandled grfe
[00:00:22.275] process:578 unhandled grfe
I (25281) httpd_handlers: serving /status.json to peer 192.168.1.16 port 64703
[00:00:27.095] process:578 unhandled grfe
[00:00:32.108] process:578 unhandled grfe
[00:00:37.122] process:578 unhandled grfe
[00:00:42.139] process:578 unhandled grfe
[00:00:47.158] process:578 unhandled grfe
[00:00:52.177] process:578 unhandled grfe
[00:00:57.099] process:578 unhandled grfe
[00:01:02.219] process:578 unhandled grfe
[00:01:07.109] process:578 unhandled grfe
[00:01:12.245] process:578 unhandled grfe
[00:01:17.161] process:578 unhandled grfe
HA-TB303 commented 7 months ago

Yes indeed, disabling led vu fixed the issue for me as well.

wizmo2 commented 7 months ago

I'll have a look to see if I can see what's going on with led_vu

sle118 commented 7 months ago

Could be that led vu causes the system to report display support to the server. There may not be a choice other than adding some null checking in the GDS itself.

sle118 commented 6 months ago

I just pushed the following commit https://github.com/sle118/squeezelite-esp32/commit/21407e8c1c4decfc0da29812af590d98aa55d5be which I am hoping will resolve the issue. You can try installing the latest build when it will show up.

sle118 commented 6 months ago

Closing this now. Please reopen if needed

anabolyc commented 6 months ago

Hey @sle118

Sorry, just get to test the latest build. Unfortunately, it is still crashing with a different error.


rst:0xc (SW_CPU_RESET),boot:0x13 (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:1
load:0x3fff0030,len:6424
load:0x40078000,len:15632
load:0x40080400,len:4348
entry 0x40080688
I (27) boot: ESP-IDF v4.3.5-dirty 2nd stage bootloader
I (27) boot: compile time 21:43:45
I (27) boot: chip revision: v3.1
I (31) qio_mode: Enabling default flash chip QIO
I (36) boot.esp32: SPI Speed      : 80MHz
I (41) boot.esp32: SPI Mode       : QIO
I (45) boot.esp32: SPI Flash Size : 4MB
I (50) boot: Enabling RNG early entropy source...
I (55) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (74) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (81) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (88) boot:  3 recovery         factory app      00 00 00010000 00140000
I (96) boot:  4 ota_0            OTA app          00 10 00150000 002a0000
I (103) boot:  5 settings         WiFi data        01 02 003f0000 00010000
I (111) boot: End of partition table
I (115) esp_image: segment 0: paddr=00150020 vaddr=3f400020 size=aeaf0h (715504) map
I (321) esp_image: segment 1: paddr=001feb18 vaddr=3ffbdb60 size=01500h (  5376) load
I (323) esp_image: segment 2: paddr=00200020 vaddr=400d0020 size=1b2e84h (1781380) map
I (817) esp_image: segment 3: paddr=003b2eac vaddr=3ffbf060 size=0453ch ( 17724) load
I (823) esp_image: segment 4: paddr=003b73f0 vaddr=40080000 size=1e014h (122900) load
I (863) esp_image: segment 5: paddr=003d540c vaddr=400c0000 size=00068h (   104) load
I (878) boot: Loaded app from partition at offset 0x150000
I (878) boot: Disabling RNG early entropy source...
I (890) psram: This chip is ESP32-D0WD
I (890) spiram: Found 64MBit SPI RAM device
I (890) spiram: SPI RAM mode: flash 80m sram 80m
I (893) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (901) cpu_start: Pro cpu up.
I (904) cpu_start: Starting app cpu, entry point is 0x400813fc
I (897) cpu_start: App cpu up.
I (1410) spiram: SPI SRAM memory test OK
I (1422) cpu_start: Pro cpu start user code
I (1422) cpu_start: cpu freq: 240000000
I (1422) cpu_start: Application information:
I (1425) cpu_start: Project name:     Squeezelite-ESP32
I (1431) cpu_start: App version:      I2S-4MFlash-1673
I (1437) cpu_start: Compile time:     May  7 2024 21:45:16
I (1443) cpu_start: ELF file SHA256:  0000000000000000...
I (1449) cpu_start: ESP-IDF:          v4.3.5-dirty
I (1455) cpu_start: Min chip rev:     v1.0
I (1460) cpu_start: Max chip rev:     v3.99 
I (1465) cpu_start: Chip rev:         v3.1
I (1470) heap_init: Initializing. RAM available for dynamic allocation:
I (1477) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1483) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (1489) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (1495) heap_init: At 3FFC6EC8 len 00019138 (100 KiB): DRAM
I (1502) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1508) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1515) heap_init: At 4009E014 len 00001FEC (7 KiB): IRAM
I (1521) spiram: Adding pool of 4018K of external SPI memory to heap allocator
I (1529) spi_flash: detected chip: gd
I (1533) spi_flash: flash io: qio
W (1537) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (1553) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1561) spiram: Reserving pool of 64K of internal memory for DMA/internal allocations
I (1571) esp_app_main: Reset reason is: 3
I (1571) esp_app_main: Reboot counter=1

I (1581) esp_app_main: Starting app_main
I (1581) nvs_utilities: Initializing flash nvs 
I (1601) nvs_utilities: Initializing nvs partition settings
I (1631) esp_app_main: Setting up telnet.
I (1631) telnet: Telnet support disabled
I (1631) esp_app_main: Setting up config subsystem.
W (1691) nvs_utilities: Configuration memory usage.  Heap internal:228939 (min:228815) (used:216) external:4096391 (min:4089159) (used:14224)
I (1701) esp_app_main: Registering default values
I (1701) system_api: Base MAC address is not set
I (1711) system_api: read default base MAC address from EFUSE
W (1721) config: Waiting for config commit ...
I (2701) config: configuration has some uncommitted entries
I (2701) config: Committing configuration to nvs. Locking config object.
I (2701) config: Done Committing configuration to nvs.
I (2701) config: Config committed!
I (2711) esp_app_main: Configuring services
I (2711) services: Configuring I2C sda:-1 scl:-1 port:1 speed:400000
W (2721) services: no I2C configured
I (2721) services: Configuring SPI mosi:-1 miso:-1 clk:-1 host:1 dc:-1
W (2731) services: no SPI configured
W (2741) led: LED GPIO -1 ignored
W (2741) led: LED GPIO -1 ignored
I (2741) led: Configuring LEDs green:-1 (on:0 rmt:-1 -1% ), red:-1 (on:0 rmt:-1 -1% )
I (2751) battery: No battery
I (2761) monitor: Initializing monitoring
I (2761) monitor: Heap internal:229615 (min:228723) external:4079811 (min:4079795) dma:221823 (min:220947)
I (2771) esp_app_main: Initializing display
I (2781) display: Trying to configure display with N/A
W (2781) display: No display driver
I (2791) esp_app_main: Initializing led_vu
I (2791) led_vu: vu meter using length:1 left:0 right:0 status:0 scale:100
I (2801) led_vu: led_vu using gpio:33 length:1 on channel:0
I (2801) esp_app_main: Checking for update url
W (2811) config: Value not found for key fwurl
I (2811) IR: Starting Infrared Receiver mode nec on gpio 39 and channel 7
I (2821) buttons: Created infrared receiver using GPIO 39
I (2821) buttons: starting button taW (2841) config: Value not found for key apdelay
I (2841) uart: queue free spaces: 3
I (2841) network_handlers: Network manager configuration: polling max 10176, polling min 15000, ap delay 20000, dhcp timeout 8000, eth timeout 8000
I (2871) http_server: Initializing HTTP Server
I (2871) network_ethernet: Attempting to initialize Ethernet
I (2881) network_ethernet: No Ethernet configuration, or configuration invalid
I (2901) wifi:wifi driver task: 3ffdfa00, prio:23, stack:6656, core=0
I (2901) wifi:wifi firmware version: 9ec65ef
I (2901) wifi:wifi certification version: v7.0
I (2901) wifi:config NVS flash: enabled
I (2911) wifi:config nano formating: disabled
I (2911) wifi:Init data frame dynamic rx buffer num: 40
I (2911) wifi:Init management frame dynamic rx buffer num: 40
I (2921) wifi:Init management short buffer num: 32
I (2921) wifi:Init static tx buffer num: 12
I (2931) wifi:Init tx cache buffer num: 32
I (2941) wifi:Init static rx buffer size: 1600
I (2941) wifi:Init static rx buffer num: 12
I (2951) wifi:Init dynamic rx buffer num: 40
I (2951) wifi_init: tcpip mbox: 32
I (2951) wifi_init: udp mbox: 32
I (2951) wifi_init: tcp mbox: 32
I (2961) wifi_init: tcp tx win: 8192
I (2961) wifi_init: tcp rx win: 32768
I (2971) wifi_init: tcp mss: 1440
I (2971) wifi_init: WiFi/LWIP prefer SPIRAM
I (2971) network_wifi: Starting wifi
I (2981) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (3071) wifi:mode : sta (64:b7:08:d1:d8:10)
I (3071) wifi:enable tsf
I (3071) network_handlers: Existing wifi config found. Attempting to connect.
I (3081) network: Starting DHCP client
I (3081) network_wifi: Wifi Connecting to wifi-12-private...

Type 'help' to get the list of commands.
Use UP/DOWN arrows to navigate through command history.
Press TAB when typing command name to auto-complete.

To automatically execute lines at startup:
    Set NVS variable autoexec (U8) = 1 to enable, 0 to disable automatic execution.
    Set NVS variable autoexec[1~9] (string)to a command that should be executed automatically

****************************
Your terminal application does not support escape sequences.
Line editing and history features are disabled.
On Windows, try using Putty instead.
****************************
W (3141) console: Processing autoexec commands while network manager active.  Wifi related commands will be ignored.
I (3141) console: autoexec is set to perform auto-process
I (3151) console: Running command autoexec1 = squeezelite -o I2S -b 500:2000 -d all=info -C 30 -W -n loud-esparagus
W (3171) config: Value not found for key autoexec2
squeezelite-esp32> I (3171) squeezelite_cmd: Calling squeezelite
[00:02:43.304] sb_controls_init:249 initializing audio (buttons/rotary/ir) controls (raw:0)
[00:02:43.315] sendSETD:440 sending dimension display:0x0 led_config:1
[00:02:43.317] stream_init:539 init stream
[00:02:43.318] output_init_embedded:78 init device: I2S
[00:02:43.330] output_init_common:433 supported rates: 192000 176400 96000 88200 48000 44100 32000 24000 22050 16000 12000 11025 8000 
[00:02:43.332] output_init_embedded:100 init I2S/SPDIF
W (3221) DAC core: DAC does not use i2c
I (3221) DAC external: DAC on I2C @0
W (3231) DAC external: no i2c controlset found
[00:02:43.356] output_init_i2s:347 configuring MCLK on GPIO -1
[00:02:43.357] output_init_i2s:359 invalid MCK gpio -1
I (3241) I2S: DMA Malloc info, datalen=blocksize=2048, dma_buf_count=12
I (3241) 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
[00:02:43.392] output_init_i2s:376 I2S DAC using I2S bck:26, ws:25, do:22, mute:-1:0 (res:0)
[00:02:43.393] output_init_i2s:396 Initializing I2S mode normal with rate: 44100, bits per sample: 16, buffer frames: 512, number of buffers: 12 
[00:02:43.405] equalizer_set_samplerate:121 equalizer sample rate 44100
[00:02:43. output_thread_i2s:518 Output state is -1
[00:02:43.416] output_visu_init:75 Initialize VISUEXPORT 512 16 bits samples
[00:02:43.418] output_thread_i2s:522 switching off amp GPIO -1
[00:02:43.429] output_init_embedded:108 init completed.
[00:02:43.440] decode_init:153 init decode
[00:02:43.441] register_alac:547 using alac to decode alc
[00:02:43.441] register_helixaac:686 using helix-aac to decode aac
[00:02:43.452] register_vorbis:526 using vorbis to decode ogg
[00:02:43.453] register_opus:458 using opus to decode ops
[00:02:43.464] register_flac:338 using flac to decode ogf,flc
[00:02:43.465] register_pcm:468 using pcm to decode wav,aif,pcm
[00:02:43.476] register_mad:417 using mad to decode mp3
W (3351) BT_AV: BT Sink pin code is: [1234] 
I (3351) BTDM_INIT: BT controller compile version [2c56073]
[00:02:43.489] register_external:469 Initializing AirPlay sink
[00:02:43.491] register_external:480 Initializing CSpot sink
[00:02:43.506] discover_server:844 sending discovery 25
[00:02:43.507] discover_server:848 error sending discovery
I (3731) BT_AV: Bluetooth Init complete
I (5011) wifi:new:<13,2>, old:<1,0>, ap:<255,255>, sta:<13,2>, prof:1
I (5531) wifi:state: init -> auth (b0)
I (5541) wifi:state: auth -> assoc (0)
I (5541) wifi:state: assoc -> run (10)
I (5561) wifi:connected with wifi-12-private, aid = 10, channel 13, 40D, bssid = 34:5d:9e:5f:a5:c4
I (5561) wifi:security: WPA2-PSK, phy: bgn, rssi: -62
I (5571) wifi:pm start, type: 1

I (5581) network: Got an IP address from interface Wifi. IP=192.168.1.154, Gateway=192.168.1.1, NetMask=255.255.255.0, Address was changed
I (5591) esp_netif_handlers: sta ip: 192.168.1.154, mask: 255.255.255.0, gw: 192.168.1.1
I (5601) esp_app_main: Network connected and mDNS initialized with loud-esparagus
[00:02:45.735] raop_sink_start:178 starting Airplay for ip 192.168.1.154 with servicename loud-esparagus
[00:02:45.738] raop_create:201 starting mDNS with 64B708D1D810@loud-esparagus
I (5611) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (5641) cspot: starting Spotify on host loud-esparagus
[00:02:45.793] I Shim.cpp:344: CSpot instance service name loud-esparagus (id 142137fd329622137a1490160000001746976115)
[00:02:45.806] I Shim.cpp:331: ZeroConf mode (port 80)
I (6761) httpd_handlers: serving /config.json to peer 192.168.1.16 port 22186
[00:02:48.505] discover_server:844 sending discovery 24
[00:02:48.511] discover_server:856 got response from: 192.168.1.48:3483
[00:02:48.512] slimproto:964 connecting to 192.168.1.48:3483
[00:02:48.518] slimproto:1011 connected
[00:02:48.519] sendHELO:153 mac: 64:b7:08:d1:d8:10
[00:02:48.530] sendHELO:155 cap: Model=squeezeesp32,AccuratePlayPoints=1,HasDigitalOut=1,HasPolarityInversion=1,Balance=1,Depth=16,Firmware=v1.0-1673-16,ModelName=SqueezeESP32,MaxSampleRate=192000,alc,aac,ogg,ops,ogf,flc,wav,aif,pcm,mp3
[00:02:48.544] sendSETD:440 sending dimension display:0x0 led_config:1
[00:02:48.558] notify:228 notified server 192.168.1.48 hport 9000 cport 9090
I (8431) network_status: LMS IP: 192.168.1.48, hport: 9000, cport: 9090
[00:02:48.572] process:578 unhandled vers
[00:02:48.577] grfb_handler:755 brightness 1
Guru Meditation Error: Core  1 panic'ed (IntegerDivideByZero). Exception was unhandled.

Core  1 register dump:
PC      : 0x40102a62  PS      : 0x00060d30  A0      : 0x800fb3e4  A1      : 0x3f801a40  
A2      : 0x3f80a3fc  A3      : 0x00000208  A4      : 0x3f80e1a0  A5      : 0x00001000  
A6      : 0x3ffbfa88  A7      : 0x3ffc53f0  A8      : 0x80102a19  A9      : 0x00000000  
A10     : 0x00000001  A11     : 0x3ffbb034  A12     : 0x00000001  A13     : 0x00000000  
A14     : 0x00000000  A15     : 0x00000000  SAR     : 0x0000001a  EXCCAUSE: 0x00000006  
EXCVADDR: 0x00000000  LBEG    : 0x40093da8  LEND    : 0x40093dc4  LCOUNT  : 0xffffffff  

Backtrace:0x40102a5f:0x3f801a40 0x400fb3e1:0x3f801b20 0x400fbe45:0x3f801b40 0x400ff5a2:0x3f801b60 0x400fa0f3:0x3f801c40 0x400de55c:0x3f801f70
sle118 commented 6 months ago

I'm leaving this for the record:


Decoding stack results
0x40102a5f: handler at ../components/squeezelite/displayer.c line 709
0x400fb3e1: handler at ../components/squeezelite/output_embedded.c line 70
0x400fbe45: handler at ../components/squeezelite/output_i2s.c line 167
0x400ff5a2: slimproto at ../components/squeezelite/slimproto.c line 809
0x400fa0f3: squeezelite_main at ../components/squeezelite/main.c line 820
0x400de55c: squeezelite_thread at ../components/platform_console/app_squeezelite/cmd_squeezelite.c line 79

I'll try to have a look later tomorrow

wizmo2 commented 6 months ago

Apologies, been busy on other stuff. Just re-flashed one of my test systems with the latest version to test squeezelite-esp32 with HA Slimproto,

As I suspected, there is a divide-by-zero issue with Ledvu when setting string length of 1. I'll work on a PR to fix it.

Saying that, Ledvu is for visual effects on a string of multiple addressable leds. If you want to use a single WS2812 as a status light, use set-GPIO only.

wizmo2 commented 6 months ago

@sle118, the issue is with grfe_handler.

When I added LEDVU. I included an extra field to SETD. The display height reports 0 height, but currently aioslimproto sends a 'grfe' message regardless. I opened an issue (https://github.com/home-assistant-libs/aioslimproto/issues/331).

In the time-being, we can fix with some extra checks in displayer. Do you want me to create a PR?