sle118 / squeezelite-esp32

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

Squeezelite-ESP32 Installer: AP not available #406

Closed eric-joris closed 4 months ago

eric-joris commented 8 months ago

Describe the bug

I installed I2S-4MFlash-16 with the Squeezelite-ESP32 Installer on a Wrover device. The install apparently worked OK and the log (attached) showed AP SSID: squeezelite-4e91c8 and AP Password: squeezelite.

However there was no AP available. esp-web-tools-logs.txt

I tried this with 2 brand new Wrover devices, twice with the same result.

Preliminary Information

  1. Firmware Version: I2S-4MFlash-16
  2. Plugin Version: NA

Hardware Details

Please describe your hardware setup:

NVS Settings

Follow these steps to share your NVS settings: Not accessible

Logs

<[0;32mI (2341) config: configuration has some uncommitted entries I (2341) config: Committing configuration to nvs. Locking config object. I (2351) config: Done Committing configuration to nvs. I (2351) config: Config committed! I (2351) esp_app_main: Configuring services I (2351) services: Configuring I2C sda:-1 scl:-1 port:1 speed:400000 W (2361) services: no I2C configured I (2361) services: Configuring SPI mosi:-1 miso:-1 clk:-1 host:1 dc:-1 W (2371) services: no SPI configured W (2381) led: LED GPIO -1 ignored W (2381) led: LED GPIO -1 ignored I (2381) led: Configuring LEDs green:-1 (on:0 rmt:-1 -1% ), red:-1 (on:0 rmt:-1 -1% ) I (2391) battery: No battery I (2401) monitor: Initializing monitoring I (2401) monitor: Heap internal:263415 (min:262523) external:4135811 (min:4135795) dma:217067 (min:216191) I (2411) esp_app_main: Initializing display I (2421) display: Trying to configure display with N/A W (2421) display: No display driver I (2431) esp_app_main: Initializing led_vu I (2431) led_vu: led_vu configuration invalid I (2431) esp_app_main: Checking for update url W (2441) config: Value not found for key fwurl 0;33mW (2461) config: Value not found for key apdelay I (2461) uart: queue free spaces: 3 I (2461) network_handlers: Network manager configuration: polling max 10176, polling min 15000, ap delay 20000, dhcp timeout 8000, eth timeout 8000 W (2481) network_wifi: No known access point found E (2481) nvs_utilities: Could not open the nvs storage. W (2491) network_wifi: network manager has no previous configuration. ESP_FAIL I (2491) http_server: Initializing HTTP Server I (2511) network_handlers: Running recovery. Skipping ethernet, starting WiFi I (2521) wifi:wifi driver task: 3ffc952c, prio:23, stack:6656, core=0 I (2521) wifi:wifi firmware version: 9ec65ef I (2521) wifi:wifi certification version: v7.0 I (2521) wifi:config NVS flash: enabled I (2531) wifi:config nano formating: disabled I (2531) wifi:Init data frame dynamic rx buffer num: 40 I (2531) wifi:Init management frame dynamic rx buffer num: 40 I (2541) wifi:Init management short buffer num: 32 I (2541) wifi:Init static tx buffer num: 12 I (2551) wifi:Init tx cache buffer num: 32 I (2551) wifi:Init static rx buffer size: 1600 I (2561) wifi:Init static rx buffer num: 12 I (2571) wifi:Init dynamic rx buffer num: 40 I (2571) wifi_init: tcpip mbox: 32 I (2571) wifi_init: udp mbox: 32 I (2571) wifi_init: tcp mbox: 32 I (2581) wifi_init: tcp tx win: 8192 I (2581) wifi_init: tcp rx win: 32768 I (2591) wifi_init: tcp mss: 1440 I (2591) wifi_init: WiFi/LWIP prefer SPIRAM I (2591) network_wifi: Starting wifi I (2601) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07 I (2701) wifi:mode : sta (fc:b4:67:4e:91:c8) I (2701) wifi:enable tsf W (2701) network_handlers: No saved wifi. Starting AP configuration mode. I (2701) network_wifi: Configuring Access Point. I (2711) network: Stopping DHCP server I (2711) network: Starting DHCP server I (2731) network_wifi: AP SSID: squeezelite-4e91c8 I (2731) network_wifi: AP Password: squeezelite I (2741) wifi:mode : sta (fc:b4:67:4e:91:c8) + softAP (fc:b4:67:4e:91:c9) I (2741) wifi:Total power save buffer number: 6 I (2741) wifi:Init max length of beacon: 752/752 I (2751) wifi:Init max length of beacon: 752/752 **************************************************************** RECOVERY APPLICATION This mode is used to flash Squeezelite into the OTA partition **** I (3281) wifi:Total power save buffer number: 6 I (3301) wifi:Total power save buffer number: 6 I (3301) wifi:Set ps type: 1 I (3301) network_wifi: Initiating wifi network scan I (3301) dns_server: DNS Server listening on 53/udp 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. **************************** Your terminal application does not support escape sequences. Line editing and history features are disabled. On Windows, try using Putty instead. ****************************
sle118 commented 8 months ago

Not sure I understand your issue.

eric-joris commented 8 months ago

Thanks for your reply. Maybe I have it completely wrong but I expected that, after flashing the ESP32 Wrover with I2S-4MFlash-16, I would see an SSID that I could connect to. The problem is I don't see an SSID, not on my mobile and also not on my laptop. I did try 2 Wrovers. Are there more steps to do after flashing and rebooting the ESP32?

sle118 commented 8 months ago

Indeed this is the expected behaviour after flashing a new device. But this wouldn't happen after you have configured an acces point unless the device is away from the configured AP. What confuses me here is that the log file you uploaded shows the device connecting to your home network.

I (2678) network_handlers: Existing wifi config found. Attempting to connect.
I (2688) network: Starting DHCP client
I (2698) network_wifi: Wifi Connecting to Home...
****************************************************************
RECOVERY APPLICATION
This mode is used to flash Squeezelite into the OTA partition
****

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.

****************************
Your terminal application does not support escape sequences.
Line editing and history features are disabled.
On Windows, try using Putty instead.
****************************
recovery-squeezelite-esp32>I (5098) wifi:new:<5,0>, old:<1,0>, ap:<255,255>, sta:<5,0>, prof:1
I (5628) wifi:state: init -> auth (b0)
I (5638) wifi:state: auth -> assoc (0)
I (5638) wifi:state: assoc -> run (10)
I (5738) wifi:connected with Home, aid = 2, channel 5, BW20, bssid = 9c:a2:f4:c8:fe:dc
I (5748) wifi:security: WPA2-PSK, phy: bgn, rssi: -59
I (5748) wifi:pm start, type: 1

I (5768) network: Got an IP address from interface Wifi. IP=192.168.0.106, Gateway=192.168.0.1, NetMask=255.255.255.0, Address was changed
I (5778) esp_netif_handlers: sta ip: 192.168.0.106, mask: 255.255.255.0, gw: 192.168.0.1
I (5778) esp_app_main: Network connected and mDNS initialized with squeezelite-752520

I would try to erase the device fully and flash again if you think you have an issue. The storage of wifi credentials in this version was originally based on the WiFi manager project and as such config might be recognized if you flashed the device a project utilizing it on your device.

eric-joris commented 8 months ago

hi sle118, I'm a bit confused. In the first log I uploaded, I could not find that is was connected to Home neither the message "Existing wifi config found". Anyway, I did factory reset the Wrover modules (python -m esptool --chip esp32 erase_flash) and reinstalled the firmware on both Wrover devices. Despite the reset, I'm still unable to find the SSID. Attached the latest log file. Looks to me the same as the preveous one. Any thought on what is wrong here?

eric-joris commented 8 months ago

esp-web-tools-logs.txt

sle118 commented 8 months ago

It's my bad. I was looking at the log from a different issue. I am unable to download your latest log file, but as far as I can tell from the first log, the access point does start. But I am unable to see the rest of the logs. Did you truncate the file or did the logs stop there?

eric-joris commented 8 months ago

Here is the log from yesterday. I did not truncate the log. It stopped there.

Logs

[0;32mI (2341) config: configuration has some uncommitted entries
I (2341) config: Committing configuration to nvs. Locking config object.
I (2351) config: Done Committing configuration to nvs.
I (2351) config: Config committed!
I (2351) esp_app_main: Configuring services
I (2351) services: Configuring I2C sda:-1 scl:-1 port:1 speed:400000
W (2361) services: no I2C configured
I (2361) services: Configuring SPI mosi:-1 miso:-1 clk:-1 host:1 dc:-1
W (2371) services: no SPI configured
W (2381) led: LED GPIO -1 ignored
W (2381) led: LED GPIO -1 ignored
I (2381) led: Configuring LEDs green:-1 (on:0 rmt:-1 -1% ), red:-1 (on:0 rmt:-1 -1% )
I (2391) battery: No battery
I (2401) monitor: Initializing monitoring
I (2401) monitor: Heap internal:263415 (min:262523) external:4135811 (min:4135795) dma:217067 (min:216191)
I (2411) esp_app_main: Initializing display
I (2421) display: Trying to configure display with N/A
W (2421) display: No display driver
I (2431) esp_app_main: Initializing led_vu
I (2431) led_vu: led_vu configuration invalid
I (2431) esp_app_main: Checking for update url
W (2441) config: Value not found for key fwurl
0;33mW (2461) config: Value not found for key apdelay
I (2461) uart: queue free spaces: 3
I (2461) network_handlers: Network manager configuration: polling max 10176, polling min 15000, ap delay 20000, dhcp timeout 8000, eth timeout 8000
W (2481) network_wifi: No known access point found
E (2481) nvs_utilities: Could not open the nvs storage.
W (2491) network_wifi: network manager has no previous configuration. ESP_FAIL
I (2491) http_server: Initializing HTTP Server
I (2511) network_handlers: Running recovery. Skipping ethernet, starting WiFi
I (2521) wifi:wifi driver task: 3ffc952c, prio:23, stack:6656, core=0
I (2521) wifi:wifi firmware version: 9ec65ef
I (2521) wifi:wifi certification version: v7.0
I (2521) wifi:config NVS flash: enabled
I (2531) wifi:config nano formating: disabled
I (2531) wifi:Init data frame dynamic rx buffer num: 40
I (2531) wifi:Init management frame dynamic rx buffer num: 40
I (2541) wifi:Init management short buffer num: 32
I (2541) wifi:Init static tx buffer num: 12
I (2551) wifi:Init tx cache buffer num: 32
I (2551) wifi:Init static rx buffer size: 1600
I (2561) wifi:Init static rx buffer num: 12
I (2571) wifi:Init dynamic rx buffer num: 40
I (2571) wifi_init: tcpip mbox: 32
I (2571) wifi_init: udp mbox: 32
I (2571) wifi_init: tcp mbox: 32
I (2581) wifi_init: tcp tx win: 8192
I (2581) wifi_init: tcp rx win: 32768
I (2591) wifi_init: tcp mss: 1440
I (2591) wifi_init: WiFi/LWIP prefer SPIRAM
I (2591) network_wifi: Starting wifi
I (2601) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (2701) wifi:mode : sta (fc:b4:67:4e:91:c8)
I (2701) wifi:enable tsf

W (2701) network_handlers: No saved wifi. Starting AP configuration mode.
I (2701) network_wifi: Configuring Access Point.
I (2711) network: Stopping DHCP server
I (2711) network: Starting DHCP server
I (2721) network_wifi: AP SSID: squeezelite-4e91c8
I (2731) network_wifi: AP Password: squeezelite
I (2741) wifi:mode : sta (fc:b4:67:4e:91:c8) + softAP (fc:b4:67:4e:91:c9)
I (2741) wifi:Total power save buffer number: 6
I (2741) wifi:Init max length of beacon: 752/752
I (2751) wifi:Init max length of beacon: 752/752
****************************************************************
RECOVERY APPLICATION
This mode is used to flash Squeezelite into the OTA partition
****

I (3281) wifi:Total power save buffer number: 6
I (3291) wifi:Total power save buffer number: 6
I (3301) wifi:Set ps type: 1

I (3301) network_wifi: Initiating wifi network scan
I (3301) dns_server: DNS Server listening on 53/udp
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.

****************************
Your terminal application does not support escape sequences.
Line editing and history features are disabled.
On Windows, try using Putty instead.
****************************
>
sle118 commented 7 months ago

This is really strange. I did flash this release myself and had no issue. I'll have to try flashing after a complete erase just to see

VincentGijsen commented 6 months ago

hi, unfort. i can confirm same observation, with the forementioned release and using installer.

module esp32-wrover-e it boots up, but no AP, (also not as hidden SID).

tried switching between OTA and recovery, and tried, without joy :

wifi_erease_config -la
nvs_erase_configuration -la

log:

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) boot: Defaulting to factory image
I (120) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=53878h (342136) map
I (223) esp_image: segment 1: paddr=000638a0 vaddr=3ffbdb60 size=04858h ( 18520) load
I (229) esp_image: segment 2: paddr=00068100 vaddr=40080000 size=07f18h ( 32536) load
I (240) esp_image: segment 3: paddr=00070020 vaddr=400d0020 size=d1724h (857892) map
I (476) esp_image: segment 4: paddr=0014174c vaddr=40087f18 size=0c8b8h ( 51384) load
I (493) esp_image: segment 5: paddr=0014e00c vaddr=400c0000 size=00068h (   104) load
I (504) boot: Loaded app from partition at offset 0x10000
I (504) boot: Disabling RNG early entropy source...
I (515) psram: This chip is ESP32-D0WD
I (516) spiram: Found 64MBit SPI RAM device
I (516) spiram: SPI RAM mode: flash 80m sram 80m
I (519) spiram: PSRAM initialized, cache is in low/high (2-core) mode.
I (526) cpu_start: Pro cpu up.
I (530) cpu_start: Starting app cpu, entry point is 0x40081298
I (0) cpu_start: App cpu up.
I (1035) spiram: SPI SRAM memory test OK
I (1045) cpu_start: Pro cpu start user code
I (1045) cpu_start: cpu freq: 240000000
I (1045) cpu_start: Application information:
I (1048) cpu_start: Project name:     Squeezelite-ESP32
I (1054) cpu_start: App version:      I2S-4MFlash-1672
I (1060) cpu_start: Compile time:     Mar 22 2024 03:06:21
I (1066) cpu_start: ELF file SHA256:  035e94d04f4c2941...
I (1072) cpu_start: ESP-IDF:          v4.3.5-dirty
I (1077) cpu_start: Min chip rev:     v1.0
I (1082) cpu_start: Max chip rev:     v3.99 
I (1087) cpu_start: Chip rev:         v3.1
I (1092) heap_init: Initializing. RAM available for dynamic allocation:
I (1099) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (1105) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (1111) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (1118) heap_init: At 3FFC47F8 len 0001B808 (110 KiB): DRAM
I (1124) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1130) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1137) heap_init: At 400947D0 len 0000B830 (46 KiB): IRAM
I (1143) spiram: Adding pool of 4059K of external SPI memory to heap allocator
I (1152) spi_flash: detected chip: generic
I (1156) spi_flash: flash io: qio
I (1161) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (1171) spiram: Reserving pool of 64K of internal memory for DMA/internal allocations
I (1181) esp_app_main: System is booting from power on.
I (1191) esp_app_main: Reset reason is: 1
I (1191) esp_app_main: Recovery Reboot counter=1

I (1191) esp_app_main: Starting app_main
I (1201) nvs_utilities: Initializing flash nvs 
I (1211) nvs_utilities: Initializing nvs partition settings
I (1261) esp_app_main: Setting up telnet.
I (1261) telnet: Telnet support disabled
I (1261) esp_app_main: Setting up config subsystem.
W (1341) nvs_utilities: Configuration memory usage.  Heap internal:262927 (min:262551) (used:15144) external:4152147 (min:4144727) (used:0)
I (1341) esp_app_main: Registering default values
I (1341) system_api: Base MAC address is not set
I (1351) system_api: read default base MAC address from EFUSE
W (1361) config: Waiting for config commit ...
I (2341) config: configuration has some uncommitted entries
I (2341) config: Committing configuration to nvs. Locking config object.
I (2351) config: Done Committing configuration to nvs.
I (2351) config: Config committed!
I (2351) esp_app_main: Configuring services
I (2351) services: Configuring I2C sda:-1 scl:-1 port:1 speed:400000
W (2361) services: no I2C configured
I (2361) services: Configuring SPI mosi:-1 miso:-1 clk:-1 host:1 dc:-1
W (2371) services: no SPI configured
W (2381) led: LED GPIO -1 ignored
W (2381) led: LED GPIO -1 ignored
I (2381) led: Configuring LEDs green:-1 (on:0 rmt:-1 -1% ), red:-1 (on:0 rmt:-1 -1% )
I (2391) battery: No battery
I (2401) monitor: Initializing monitoring
I (2401) monitor: Heap internal:263415 (min:262523) external:4135811 (min:4135795) dma:217067 (min:216191)
I (2411) esp_app_main: Initializing display
I (2421) display: Trying to configure display with N/A
W (2421) display: No display driver
I (2431) esp_app_main: Initializing led_vu
I (2431) led_vu: led_vu configuration invalid
I (2431) esp_app_main: Checking for update url
W (2441) config: Value not found for key fwurl
0;33mW (2461) config: Value not found for key apdelay
I (2461) uart: queue free spaces: 3
I (2461) network_handlers: Network manager configuration: polling max 10176, polling min 15000, ap delay 20000, dhcp timeout 8000, eth timeout 8000
W (2481) network_wifi: No known access point found
E (2481) nvs_utilities: Could not open the nvs storage.
W (2491) network_wifi: network manager has no previous configuration. ESP_FAIL
I (2491) http_server: Initializing HTTP Server
I (2511) network_handlers: Running recovery. Skipping ethernet, starting WiFi
I (2521) wifi:wifi driver task: 3ffc952c, prio:23, stack:6656, core=0
I (2521) wifi:wifi firmware version: 9ec65ef
I (2521) wifi:wifi certification version: v7.0
I (2521) wifi:config NVS flash: enabled
I (2531) wifi:config nano formating: disabled
I (2531) wifi:Init data frame dynamic rx buffer num: 40
I (2531) wifi:Init management frame dynamic rx buffer num: 40
I (2541) wifi:Init management short buffer num: 32
I (2541) wifi:Init static tx buffer num: 12
I (2551) wifi:Init tx cache buffer num: 32
I (2551) wifi:Init static rx buffer size: 1600
I (2561) wifi:Init static rx buffer num: 12
I (2571) wifi:Init dynamic rx buffer num: 40
I (2571) wifi_init: tcpip mbox: 32
I (2571) wifi_init: udp mbox: 32
I (2571) wifi_init: tcp mbox: 32
I (2581) wifi_init: tcp tx win: 8192
I (2581) wifi_init: tcp rx win: 32768
I (2591) wifi_init: tcp mss: 1440
I (2591) wifi_init: WiFi/LWIP prefer SPIRAM
I (2591) network_wifi: Starting wifi
I (2601) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (2701) wifi:mode : sta (a0:a3:b3:2b:d2:3c)
I (2701) wifi:enable tsf

W (2701) network_handlers: No saved wifi. Starting AP configuration mode.
I (2701) network_wifi: Configuring Access Point.
I (2711) network: Stopping DHCP server
I (2711) network: Starting DHCP server
I (2721) network_wifi: AP SSID: squeezelite-2bd23c
I (2721) network_wifi: AP Password: squeezelite
I (2731) wifi:mode : sta (a0:a3:b3:2b:d2:3c) + softAP (a0:a3:b3:2b:d2:3d)
I (2741) wifi:Total power save buffer number: 6
I (2741) wifi:Init max length of beacon: 752/752
I (2751) wifi:Init max length of beacon: 752/752
****************************************************************
RECOVERY APPLICATION
This mode is used to flash Squeezelite into the OTA partition
****

I (3281) wifi:Total power save buffer number: 6
I (3291) wifi:Total power save buffer number: 6
I (3291) wifi:Set ps type: 1

I (3301) network_wifi: Initiating wifi network scan
I (3301) dns_server: DNS Server listening on 53/udp
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.

****************************
Your terminal application does not support escape sequences.
Line editing and history features are disabled.
On Windows, try using Putty instead.
****************************
>
sle118 commented 6 months ago

ok. tried one more time. Perform a fresh install using the online installer (with the "erase" option checked). Then from the web installer, clicked on the option to view the logs. I restarted the device to see logs populating there and got

I (2701) network_wifi: Configuring Access Point.
I (2711) network: Stopping DHCP server
I (2711) network: Starting DHCP server
I (2721) network_wifi: AP SSID: squeezelite-2bd23c
I (2721) network_wifi: AP Password: squeezelite
I (2731) wifi:mode : sta (a0:a3:b3:2b:d2:3c) + softAP (a0:a3:b3:2b:d2:3d)
I (2741) wifi:Total power save buffer number: 6
I (2741) wifi:Init max length of beacon: 752/752
I (2751) wifi:Init max length of beacon: 752/752
****************************************************************
RECOVERY APPLICATION
This mode is used to flash Squeezelite into the OTA partition
****

I (3281) wifi:Total power save buffer number: 6
I (3291) wifi:Total power save buffer number: 6

And the logs don't go further, so I can confirm your logs are looking ok. Now from your logs, the following: I (2731) wifi:mode : sta (a0:a3:b3:2b:d2:3c) + softAP (a0:a3:b3:2b:d2:3d) indicates that the ESP32 is correctly setting its radio as sta+softAP, so I am not sure I will be able to help you further. The code works as designed and I can't see anything wrong in the logs that would indicate otherwise.

Make sure you have a good adapter to power your esp32 and see if that helps.

tobox commented 4 months ago

I had exactly the same problem with a louder-esp bought from elecrow. Here are some of the things I tried:

sle118 commented 4 months ago

Given this is mostly hardware related, I'll go ahead and close the issue