nodemcu / nodemcu-firmware

Lua based interactive firmware for ESP8266, ESP8285 and ESP32
https://nodemcu.readthedocs.io
MIT License
7.64k stars 3.12k forks source link

wifi.connect() causes esp32c3 to reboot if log verbosity is set to "Info" #3660

Open serg3295 opened 1 month ago

serg3295 commented 1 month ago

Expected behavior

The ESP does not reboot after connecting to Wi-Fi if the "Log output" → "Default log detail" is set to "Info".

EDIT. Added Log for succsesful wifi connection. "Log output" → "Default log detail" -> "Warn" IDF v5.2.2, console JTAG

Log for succsesful wifi connection ``` NodeMCU ESP32 build 2024-08-09 14:58 powered by Lua 5.3.5 [5.3-int32-singlefp] on IDF v5.2.2 cannot open init.lua: No such file or directory > do wifi>> .mode(wifi.STATION) wifi.start() wifi.sta.settxpower>> (8) wifi.sta.config({ ssid = "Dacha", pwd = "**", auto = true }, true) wifi.sta.on("got_ip", function(ev, info) print("NodeMCU IP config:", info.ip) end) wifi.sta.connect>> () end>> >> >> >> > NodeMCU IP config: 192.168.1.74 ```

Actual behavior

If Component config → Log output → Default log verbosity -> "Info" is set, the ESP reboots immediately after connecting to WiFi.

Everything works until this command. errWifi

If the default log verbosity level is set to "Warning", the ESP connects to Wi-Fi and no reboot occurs. Because LOGI is not executed.

Сurrent settings are: (Top) → Component config → ESP System Settings → Channel for console output -> (X) Default: UART0 Channel for console secondary output (No secondary console)

The error occurs with both UART and JTAG console. Also it occurs on IDF 5.2.2

Crash log ``` I (415873) phy_init: phy_version 1150,7c3c08f,Jan 24 2024,17:32:21 I (415913) wifi:mode : sta (f0:f5:bd:fc:36:e8) I (415913) wifi:enable tsf > I (416023) wifi:new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1 I (416023) wifi:state: init -> auth (b0) I (416023) wifi:state: auth -> assoc (0) I (416033) wifi:state: assoc -> run (10) I (416043) wifi:connected with Dacha, aid = 12, channel 6, BW20, bssid = b0:4e:26:5c:eb:bd I (416043) wifi:security: WPA2-PSK, phy: bgn, rssi: -40 I (416043) wifi:pm start, type: 1 I (416053) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us I (416053) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 25000, mt_pti: 14, mt_time: 10000 I (416123) wifi:dp: 2, bi: 102400, li: 4, scale listen interval from 307200 us to 409600 us I (416123) wifi:AP's beacon interval = 102400 us, DTIM period = 2 I (417073) esp_netif_handlers: sta ip: 192.168.1.74, mask: 255.255.255.0, gw: 192.168.1.1 assert failed: xQueueGenericSend queue.c:873 (!( ( pvItemToQueue == ((void *)0) ) && ( pxQueue->uxItemSize != ( UBaseType_t ) 0U ) )) Core 0 register dump: MEPC : 0x40380706 RA : 0x40380706 SP : 0x3fcaad10 GP : 0x3fc94800 TP : 0x3fc828a4 T0 : 0x37363534 T1 : 0x7271706f T2 : 0x33323130 S0/FP : 0x00000042 S1 : 0x00000001 A0 : 0x00000000 A1 : 0x00000000 A2 : 0x3fcaace8 A3 : 0x00000001 A4 : 0x40385d3a A5 : 0x00000000 A6 : 0x00000000 A7 : 0x76757473 S2 : 0x00000009 S3 : 0x3fcaaeb5 S4 : 0x3fc967f8 S5 : 0x00000000 S6 : 0xffffffff S7 : 0x00000000 S8 : 0x00000000 S9 : 0x00000000 S10 : 0x00000000 S11 : 0x00000000 T3 : 0x6e6d6c6b T4 : 0x6a696867 T5 : 0x66656463 T6 : 0x62613938 MSTATUS : 0x00001881 MTVEC : 0x40380001 MCAUSE : 0x00000007 MTVAL : 0x00000000 MHARTID : 0x00000000 Stack memory: 3fcaad10: 0x3c0d2a52 0x3c0d2c6c 0x3fcaad54 0x403889b8 0x00000001 0x000000f0 0x3c0d3038 0x40390232 3fcaad30: 0x3fc96bd0 0x3c0d3038 0x3fc96fbc 0x3c0d2a52 0x3fc96be0 0x3fcaad54 0x3fc96be4 0x3c0d2c6c 3fcaad50: 0x3fc967f8 0x00333738 0x3fca4ae0 0x65737361 0x66207472 0x656c6961 0x78203a64 0x75657551 3fcaad70: 0x6e654765 0x63697265 0x646e6553 0x65757120 0x632e6575 0x3337383a 0x28212820 0x70202820 3fcaad90: 0x65744976 0x516f546d 0x65756575 0x203d3d20 0x6f762828 0x2a206469 0x20293029 0x26262029 3fcaadb0: 0x70202820 0x65755178 0x3e2d6575 0x74497875 0x69536d65 0x2120657a 0x2028203d 0x73614255 3fcaadd0: 0x70795465 0x20745f65 0x55302029 0x29202920 0x3fcb0029 0x00065d31 0x3fcb0004 0x4038f194 3fcaadf0: 0x420081e4 0x000000f0 0x00000000 0x3fcaae1c 0xffffffff 0x00000000 0xffffffff 0x42091a52 3fcaae10: 0x3fcb0004 0x3fcaaf44 0x3fcb0004 0x00065d31 0x3c0e94f4 0x00000000 0x00000000 0x00000000 3fcaae30: 0x000000b7 0x0000004a 0xffffffff 0x00000000 0x00000000 0x00000000 0x3fcaa3e8 0x40388fec 3fcaae50: 0x000000b7 0x00000000 0xffffffff 0x00000000 0x00000000 0x3fcb0004 0x3fca3fa0 0x4038ddc0 3fcaae70: 0x00000000 0x3fcaa174 0x3fcb0004 0x00000000 0x00000000 0x3fcaaf44 0x3fcaa3e8 0x40389238 3fcaae90: 0x00000000 0x3fcaa174 0x00000000 0x420cd1e2 0x00000101 0x3c0e40e4 0x00000000 0x3fcb0004 3fcaaeb0: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 3fcaaed0: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x3fcaa174 0x420cd24c 3fcaaef0: 0x00000000 0x00000000 0x00000000 0x40389a46 0x00000000 0x00000000 0x00000000 0x00000000 3fcaaf10: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 3fcaaf30: 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0xa5a5a5a5 0x00000154 0x3fcaadb0 0x3fca3fb4 0x3fc97a14 3fcaaf50: 0x3fc97a14 0x3fcaaf44 0x3fc97a0c 0x00000005 0x3fcaa148 0x3fcaa148 0x3fcaaf44 0x00000000 3fcaaf70: 0x00000014 0x3fcaa440 0x5f737973 0x00747665 0x3fcaafd4 0x00cab2c4 0x00000000 0x3fcaaf30 3fcaaf90: 0x00000014 0x00000001 0x3fcaeb34 0x42000262 0x00000000 0x3fca457c 0x3fca45e4 0x3fca464c 3fcaafb0: 0x00000000 0x00000000 0x00000001 0x00000000 0x00000000 0x00000000 0x420b6b6c 0x00000000 3fcaafd0: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 3fcaaff0: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 3fcab010: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 3fcab030: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 3fcab050: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 3fcab070: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 3fcab090: 0x00000000 0x3f000000 0x0000000c 0x3fcab0ac 0x3fcb1068 0x00000000 0x0000000c 0x3fcab0bc 3fcab0b0: 0x00000000 0x3fcab0a4 0x0000000c 0x420081e4 0x00000000 0x3fcab0b4 0x00000054 0x00000000 3fcab0d0: 0x3fcab0cc 0x00000000 0x00000000 0x00000000 0x3fcab0e4 0xffffffff 0x3fcab0e4 0x3fcab0e4 3fcab0f0: 0x00000000 0x3fcab0f8 0xffffffff 0x3fcab0f8 0x3fcab0f8 0x00000001 0x00000001 0x00000000 ```

Added crash log on IDF 5.2.2 and Channel for console output -> JTAG

Crash log on IDF 5.2.2 ``` wifi.sta.connect()> > > > I (37031) wifi:new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1 I (37031) wifi:state: init -> auth (b0) I (37031) wifi:state: auth -> assoc (0) I (37041) wifi:state: assoc -> run (10) I (37051) wifi:connected with Dacha, aid = 12, channel 6, BW20, bssid = b0:4e:26:5c:eb:bd I (37051) wifi:security: WPA2-PSK, phy: bgn, rssi: -43 I (37071) wifi:pm start, type: 1 I (37071) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us I (37071) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 25000, mt_pti: 14, mt_time: 10000 I (37101) wifi:dp: 2, bi: 102400, li: 4, scale listen interval from 307200 us to 409600 us I (37101) wifi:AP's beacon interval = 102400 us, DTIM period = 2 Guru Meditation Error: Core 0 panic'ed (Stack protection fault). Detected in task "sys_evt" at 0x40381588 0x40381588: lock_acquire_generic at /home/serg/Projects/lua/nodeMCU-firmware/sdk/esp32-esp-idf/components/newlib/locks.c:111 Stack pointer: 0x3fcab510 Stack bounds: 0x3fcab530 - 0x3fcac020 Setting breakpoint at 0x4038159a and returning... 0x4038159a: lock_acquire_generic at /home/serg/Projects/lua/nodeMCU-firmware/sdk/esp32-esp-idf/components/newlib/locks.c:113 ```

Test code

  wifi.mode(wifi.STATION)
  wifi.start()
  wifi.sta.settxpower(8)
  wifi.sta.config({ ssid = "Dacha", pwd = "**", auto = true }, true)
  -- wifi.sta.on("got_ip", function(ev, info) print("NodeMCU IP config:", info.ip) end)
  wifi.sta.connect()

NodeMCU startup banner

Startup banner ``` ESP-ROM:esp32c3-api1-20210207 Build:Feb 7 2021 rst:0x3 (RTC_SW_SYS_RST),boot:0xd (SPI_FAST_FLASH_BOOT) Saved PC:0x40048b82 SPIWP:0xee mode:DIO, clock div:1 load:0x3fcd5820,len:0x1704 load:0x403cc710,len:0x968 load:0x403ce710,len:0x2f9c entry 0x403cc710 I (35) boot: ESP-IDF v5.1.3 2nd stage bootloader I (35) boot: compile time Aug 9 2024 13:18:39 I (35) boot: chip revision: v0.4 I (38) boot.esp32c3: SPI Speed : 80MHz I (43) boot.esp32c3: SPI Mode : DIO I (48) boot.esp32c3: SPI Flash Size : 4MB I (52) boot: Enabling RNG early entropy source... I (58) boot: Partition Table: I (61) boot: ## Label Usage Type ST Offset Length I (69) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (76) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (83) boot: 2 factory factory app 00 00 00010000 00180000 I (91) boot: 3 lfs unknown c2 01 00190000 00010000 I (98) boot: 4 storage Unknown data 01 82 001a0000 00070000 I (106) boot: End of partition table I (110) esp_image: segment 0: paddr=00010020 vaddr=3c0d0020 size=28f70h (167792) map I (146) esp_image: segment 1: paddr=00038f98 vaddr=3fc94000 size=036e4h ( 14052) load I (149) esp_image: segment 2: paddr=0003c684 vaddr=40380000 size=03994h ( 14740) load I (155) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=cf25ch (848476) map I (298) esp_image: segment 4: paddr=0010f284 vaddr=40383994 size=1052ch ( 66860) load I (311) esp_image: segment 5: paddr=0011f7b8 vaddr=50000000 size=00020h ( 32) load I (318) boot: Loaded app from partition at offset 0x10000 I (318) boot: Disabling RNG early entropy source... I (331) cpu_start: Unicore app I (331) cpu_start: Pro cpu up. I (340) cpu_start: Pro cpu start user code I (340) cpu_start: cpu freq: 160000000 Hz I (340) cpu_start: Application information: I (343) cpu_start: Project name: nodemcu I (348) cpu_start: App version: tmr-libmain-binpatch150-887-g6b I (355) cpu_start: Compile time: Aug 9 2024 13:18:21 I (361) cpu_start: ELF file SHA256: 0d812e17b846dd88... I (367) cpu_start: ESP-IDF: v5.1.3 I (372) cpu_start: Min chip rev: v0.3 I (377) cpu_start: Max chip rev: v1.99 I (382) cpu_start: Chip rev: v0.4 I (386) heap_init: Initializing. RAM available for dynamic allocation: I (394) heap_init: At 3FCA3FA0 len 0001C060 (112 KiB): DRAM I (400) heap_init: At 3FCC0000 len 0001C710 (113 KiB): DRAM/RETENTION I (407) heap_init: At 3FCDC710 len 00002950 (10 KiB): DRAM/RETENTION/STACK I (414) heap_init: At 50000220 len 00001DC8 (7 KiB): RTCRAM I (421) spi_flash: detected chip: generic I (425) spi_flash: flash io: dio W (429) rmt(legacy): legacy driver is deprecated, please migrate to `driver/rmt_tx.h` and/or `driver/rmt_rx.h` W (440) ADC: legacy driver is deprecated, please migrate to `esp_adc/adc_oneshot.h` I (448) sleep: Configure to isolate all GPIO pins in sleep state I (455) sleep: Enable automatic switching of GPIO sleep configuration I (462) esp_apptrace: Apptrace initialized on CPU0. Tracing control block @ 0x3fca0238. I (471) coexist: coex firmware version: 77cd7f8 I (476) coexist: coexist rom version 9387209 I (481) app_start: Starting scheduler on CPU0 I (486) main_task: Started on CPU0 I (486) main_task: Calling app_main() E (506) mmap: esp_mmu_paddr_to_vaddr(752): paddr isn't mapped I (516) pp: pp rom version: 9387209 I (516) net80211: net80211 rom version: 9387209 I (526) wifi:wifi driver task: 3fcb3a28, prio:23, stack:6656, core=0 I (526) wifi:wifi firmware version: 0016c4d I (526) wifi:wifi certification version: v7.0 I (526) wifi:config NVS flash: enabled I (536) wifi:config nano formating: disabled I (536) wifi:Init data frame dynamic rx buffer num: 32 I (546) wifi:Init static rx mgmt buffer num: 5 I (546) wifi:Init management short buffer num: 32 I (556) wifi:Init dynamic tx buffer num: 32 I (566) wifi:Init static tx FG buffer num: 2 I (566) wifi:Init static rx buffer size: 1600 I (566) wifi:Init static rx buffer num: 10 I (576) wifi:Init dynamic rx buffer num: 32 I (576) wifi_init: rx ba win: 6 I (576) wifi_init: tcpip mbox: 32 I (576) wifi_init: udp mbox: 6 I (586) wifi_init: tcp mbox: 6 I (586) wifi_init: tcp tx win: 5760 I (586) wifi_init: tcp rx win: 5760 I (596) wifi_init: tcp mss: 1440 I (596) wifi_init: WiFi IRAM OP enabled I (596) wifi_init: WiFi RX IRAM OP enabled NodeMCU ESP32 build 2024-08-09 13:18 powered by Lua 5.3.5 [5.3-int32-singlefp] on IDF v5.1.3 cannot open init.lua: No such file or directory > ```

Hardware

esp32c3 supermini

serg3295 commented 1 month ago

I did some more research. This issue is common to all ESPs. ESP32 has the same error. I built the firmware for ESP32 on commit "Add support for using multiple memory slots in rmt setup" with IDF v5.0.2 and the error is gone.

Log for ESP32 on IDF 5.0.2 ``` LFS image loaded I (841) wifi:wifi driver task: 3ffc79dc, prio:23, stack:6656, core=0 I (841) system_api: Base MAC address is not set I (841) system_api: read default base MAC address from EFUSE I (861) wifi:wifi firmware version: 57982fe I (861) wifi:wifi certification version: v7.0 I (861) wifi:config NVS flash: enabled I (861) wifi:config nano formating: disabled I (861) wifi:Init data frame dynamic rx buffer num: 32 I (871) wifi:Init management frame dynamic rx buffer num: 32 I (871) wifi:Init management short buffer num: 32 I (881) wifi:Init dynamic tx buffer num: 32 I (881) wifi:Init static rx buffer size: 1600 I (891) wifi:Init static rx buffer num: 10 I (891) wifi:Init dynamic rx buffer num: 32 I (891) wifi_init: rx ba win: 6 I (901) wifi_init: tcpip mbox: 32 I (901) wifi_init: udp mbox: 6 I (901) wifi_init: tcp mbox: 6 I (911) wifi_init: tcp tx win: 5760 I (911) wifi_init: tcp rx win: 5760 I (921) wifi_init: tcp mss: 1440 I (921) wifi_init: WiFi IRAM OP enabled I (921) wifi_init: WiFi RX IRAM OP enabled NodeMCU ESP32 build unspecified powered by Lua 5.3.5 [5.3-int32-singlefp] on IDF v5.0.2 cannot open init.lua: No such file or directory > do wifi.mode(wifi.STATION) wifi.start() wifi.sta.settxpower(8) wifi.sta.config({ ssid = "Dacha", pwd = "**", auto = true }, true) wifi.sta.on("got_ip", function(ev, info) print("NodeMCU IP config:", info.ip) end) wifi.sta.connect() end>> >> >> >> >> I (8151) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07W (8151) phy_init: failed to load RF calibration data (0xffffffff), falling back to full calibration I (8321) wifi:mode : sta (7c:9e:bd:07:6b:bc) I (8321) wifi:enable tsf > I (8371) wifi:new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1 I (9061) wifi:state: init -> auth (b0) I (9071) wifi:state: auth -> assoc (0) I (9071) wifi:state: assoc -> run (10) I (9091) wifi:connected with Dacha, aid = 12, channel 6, BW20, bssid = b0:4e:26:5c:eb:bd I (9091) wifi:security: WPA2-PSK, phy: bgn, rssi: -40 I (9111) wifi:pm start, type: 1 I (9121) wifi:AP's beacon interval = 102400 us, DTIM period = 2 NodeMCU IP config: 192.168.1.35 I (10121) esp_netif_handlers: sta ip: 192.168.1.35, mask: 255.255.255.0, gw: 192.168.1.1 I (14341) wifi:idx:0 (ifx:0, b0:4e:26:5c:eb:bd), tid:0, ssn:1, winSize:64 ```

EDIT.

on IDF 5.1.2, 5.1.3, 5.2.2 we have the same bug Well. I changed the compiler flag from Debug (-Og) to Optimize for size (-Os), and esp32 works with v5.1.3 and v5.2.2 ¯\(ツ)

For esp32c3 this trick does not work.