espressif / esp-mesh-lite

A lite version Wi-Fi Mesh, each node can access the network over the IP layer.
126 stars 18 forks source link

Self-organising crashes. 2 Roots forces reset loop (AEGHB-605) #74

Open djswirl opened 6 months ago

djswirl commented 6 months ago

I have been struggling for a number of weeks to get mesh light to work. Due to the limited documentation error tracing is extremely difficult. Automatic root selection should happen if more than one node connects to the router.

The issue I am facing if I power my first node it will connect to the router without issue, however when I power the second node which also connects to the router something is Happening with the automatic selection which then causes both nodes getting stuck in a loop of stack canary watchpoint triggered (tmr svc), then resetting. I have increased the stack sizes across the board to try a trace this. I don't think it has something to do with the stack size but more to do with how it is handling messages.

Can somebody give me further information on what is happening in the background in order to determine the automatic root selection so that I can attempt to trace where this error is coming from.

Is there an uncompiled version of the libraries of available to enable us to debug code more easily?

Thanks

Brian

tswen commented 6 months ago

Hello, would it be possible to provide the complete device logs for further diagnosis?

djswirl commented 6 months ago

here are 2 logs. the first node seems to run with issus until i start the second node, then is crashes, witch makes the 2 node crash, and when it starts makes the 1st crash, and it just goes round in a loop

Node 1 `[ 13][D][esp32-hal-cpu.c:244] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz 5 4 3 2 1
[ 3288][I][main.cpp:175] setup(): [Mesh_Test] IDF Version : v4.4.6-dirty [ 3289][I][main.cpp:176] setup(): [Mesh_Test] Flash size : 4 MB (4194304)

I (3293) bridge_common: esp-iot-bridge version: 0.0.0 I (3381) bridge_common: IP Address:192.168.4.1 I (3382) bridge_common: GW Address:192.168.4.1 I (3382) bridge_common: NM Address:255.255.255.0 I (3386) bridge_wifi: IP Address:192.168.4.1 Add netif ap with MyMesh(commit id) I (3394) bridge_common: netif list add success Add netif sta with MyMesh(commit id) I (3403) bridge_common: netif list add success I (7135) bridge_common: [WIFI_AP_DEF ]Name Server1: 114.114.114.114 I (7147) bridge_wifi: [esp_bridge_wifi_set_config] sta ssid: xxxxxx password: xxxxxx [ 3435][I][main.cpp:96] wifi_init(): [Mesh_Test] esp_bridge_wifi_set_config(STA) : ESP_OK I (7162) bridge_wifi: [esp_bridge_wifi_set_config] softap ssid: xxxxx_035745 password: xxxxxx [ 4007][I][main.cpp:102] wifi_init(): [Mesh_Test] esp_bridge_wifi_set_config(AP) : ESP_OK I (7727) Mesh-Lite: esp-mesh-lite component version: 0.10.2 I (7732) bridge_common: [WIFI_AP_DEF ]Name Server1: 114.114.114.114 I (7738) ESPNOW: espnow [version: 1.0] init I (7741) [vendor_ie]: Mesh-Lite commit id: d919851

I (7747) [vendor_ie]: Mesh ID: 77 D (7752) [vendor_ie]: ota_data_len is 1388 ota_wnd 8328 I (7755) [ESP_Mesh_Lite_Comm]: msg action add success I (7760) [ESP_Mesh_Lite_Comm]: msg action add success I (7762) [ESP_Mesh_Lite_Comm]: Bind Socket 48, port 6364 I (7770) [ESP_Mesh_Lite_Comm]: Bind Socket 49, port 6363 I (7775) [ESP_Mesh_Lite_Comm]: Bind Socket 50, port 6366 I (7780) [ESP_Mesh_Lite_Comm]: Bind Socket 51, port 6365 D (7785) [ESP_Mesh_Lite_Comm]: free heap: 134056 I (7790) [mesh-lite-espnow]: Start espnow task I (7795) Mesh-Lite: Mesh-Lite connecting I (7800) [vendor_ie]: esp_mesh_lite_wifi_scan_start return ESP_OK [ 5076][I][main.cpp:50] printWifiMode(): [Mesh_Test] WiFi mode: Station + Access Point [ 5077][I][main.cpp:148] mesh_setup(): [Mesh_Test] Mesh Networking Mode : ROUTER [ 5082][I][main.cpp:150] mesh_setup(): [Mesh_Test] Node Level : 0 I (10644) [vendor_ie]: Mesh-Lite Scan done I (10645) [vendor_ie]: RTC store: ssid:xxxxx; bssid:00:00:00:00:00:00 crc:4109069645 I (10647) [vendor_ie]: wifi_cfg gatts router_config xxxxx I (10652) [vendor_ie]: esp_mesh_lite_wifi_connect return ESP_OK I (11621) bridge_wifi: Connected with IP Address:192.168.1.102 I (11622) bridge_common: [WIFI_AP_DEF ]Name Server1: 192.168.1.1 I (11624) [vendor_ie]: RTC store: ssid:xxxxx; bssid:00:00:00:00:00:00 crc:3408422391 [ 15089][I][esp_mesh_init.cpp:55] print_system_info_timercb(): [local_control] Sys info, channel: 2, layer: 1, self mac: 3c:71:bf:03:57:44, free heap: 128476 [ 15120][I][esp_mesh_init.cpp:65] print_system_info_timercb(): [local_control] Num of child nodes : 0 [ 25089][I][esp_mesh_init.cpp:55] print_system_info_timercb(): [local_control] Sys info, channel: 2, layer: 1, self mac: 3c:71:bf:03:57:44, free heap: 128476 [ 25093][I][esp_mesh_init.cpp:65] print_system_info_timercb(): [local_control] Num of child nodes : 0 [ 35089][I][esp_mesh_init.cpp:55] print_system_info_timercb(): [local_control] Sys info, channel: 2, layer: 1, self mac: 3c:71:bf:03:57:44, free heap: 128476 [ 35093][I][esp_mesh_init.cpp:65] print_system_info_timercb(): [local_control] Num of child nodes : 0 [ 45089][I][esp_mesh_init.cpp:55] print_system_info_timercb(): [local_control] Sys info, channel: 2, layer: 1, self mac: 3c:71:bf:03:57:44, free heap: 128476 [ 45093][I][esp_mesh_init.cpp:65] print_system_info_timercb(): [local_control] Num of child nodes : 0 [ 55089][I][esp_mesh_init.cpp:55] print_system_info_timercb(): [local_control] Sys info, channel: 2, layer: 1, self mac: 3c:71:bf:03:57:44, free heap: 128476 [ 55093][I][esp_mesh_init.cpp:65] print_system_info_timercb(): [local_control] Num of child nodes : 0 I (64776) bridge_wifi: STA Connecting to the AP again... <<<<<<<<<<<<<<<< start second node D (64878) [ESP_Mesh_Lite_Comm]: free heap: 125660 D (66088) [ESP_Mesh_Lite_Comm]: free heap: 125124 D (66091) [ESP_Mesh_Lite_Comm]: free heap: 125528 D (67082) [ESP_Mesh_Lite_Comm]: free heap: 125528 D (68080) [ESP_Mesh_Lite_Comm]: free heap: 125528 [ 65089][I][esp_mesh_init.cpp:55] print_system_info_timercb(): [local_control] Sys info, channel: 2, layer: 1, self mac: 3c:71:bf:03:57:44, free heap: 125400 [ 65093][I][esp_mesh_init.cpp:65] print_system_info_timercb(): [local_control] Num of child nodes : 1 [ 65102][I][esp_mesh_init.cpp:68] print_system_info_timercb(): [local_control] Child mac: 08:d1:f9:25:e8:ac Guru Meditation Error: Core 0 panic'ed (Double exception).

Core 0 register dump: PC : 0x4008c212 PS : 0x00040b36 A0 : 0x80083ba3 A1 : 0x3ffbcf50 A2 : 0x00060d30 A3 : 0x00040023 A4 : 0x00060d20 A5 : 0xffffffff A6 : 0x00060d23 A7 : 0x00000000 A8 : 0x00000001 A9 : 0x00000000 A10 : 0x00060d23 A11 : 0x00000000 A12 : 0x00000021 A13 : 0x00000084 A14 : 0x007b0300 A15 : 0x003fffff SAR : 0x0000001c EXCCAUSE: 0x00000002
EXCVADDR: 0x00000074 LBEG : 0x40089e95 LEND : 0x40089ea5 LCOUNT : 0xffffffff

Backtrace: 0x4008c20f:0x3ffbcf50 0x40083ba0:0x3ffbcf60 0x4008c20f:0x3ffbcf80 0x4008c20f:0x3ffbcfa0 0x4008007d:0x3ffbcfc0 0x40083bb5:0x3ffbcff0 0x40083bde:0x3ffbd010 0x400919d9:0x3ffbd030 0x4014d0b1:0x3ffbd050 0x4014d7bf:0x3ffbd070 0x4014bc4f:0x3ffbd0a0 0x4014395a:0x3ffbd140 0x40141519:0x3ffbd450 0x400fdec4:0x3ffbd510 0x400fe0f8:0x3ffbd570 0x400fe1c4:0x3ffbd5d0 0x400fe745:0x3ffbd620 0x400d96e2:0x3ffbd640 0x400d9e3a:0x3ffbd680 0x400d9e47:0x3ffbd6a0 0x4008f27b:0x3ffbd6c0

0 0x4008c20f:0x3ffbcf50 in _xt_context_save at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/port/xtensa/xtensa_context.S:194

1 0x40083ba0:0x3ffbcf60 in heap_caps_malloc_base at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/heap/heap_caps.c:175

  (inlined by) heap_caps_malloc_base at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/heap/heap_caps.c:120

2 0x4008c20f:0x3ffbcf80 in _xt_context_save at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/port/xtensa/xtensa_context.S:194

3 0x4008c20f:0x3ffbcfa0 in _xt_context_save at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/port/xtensa/xtensa_context.S:194

4 0x4008007d:0x3ffbcfc0 in _xt_alloca_exc at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/port/xtensa/xtensa_vectors.S:1802

5 0x40083bb5:0x3ffbcff0 in heap_caps_malloc at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/heap/heap_caps.c:195

6 0x40083bde:0x3ffbd010 in heap_caps_malloc_default at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/heap/heap_caps.c:220

7 0x400919d9:0x3ffbd030 in _calloc_r at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/newlib/heap.c:65

8 0x4014d0b1:0x3ffbd050 in _Balloc at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdlib/mprec.c:106

9 0x4014d7bf:0x3ffbd070 in __d2b at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdlib/mprec.c:778

10 0x4014bc4f:0x3ffbd0a0 in _dtoa_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdlib/dtoa.c:287

11 0x4014395a:0x3ffbd140 in cvt at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vfprintf.c:1877

  (inlined by) _svfprintf_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vfprintf.c:1314

12 0x40141519:0x3ffbd450 in sprintf at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/sprintf.c:618

13 0x400fdec4:0x3ffbd510 in print_number at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/json/cJSON/cJSON.c:568

  (inlined by) print_value at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/json/cJSON/cJSON.c:1402    
  (inlined by) print_value at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/json/cJSON/cJSON.c:1363    

14 0x400fe0f8:0x3ffbd570 in print_object at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/json/cJSON/cJSON.c:1775

  (inlined by) print_value at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/json/cJSON/cJSON.c:1429    
  (inlined by) print_value at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/json/cJSON/cJSON.c:1363    

15 0x400fe1c4:0x3ffbd5d0 in print at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/json/cJSON/cJSON.c:1202

16 0x400fe745:0x3ffbd620 in cJSON_PrintUnformatted at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/json/cJSON/cJSON.c:1255

17 0x400d96e2:0x3ffbd640 in esp_mesh_lite_try_sending_msg at /builds/ae_group/esp-mesh-lite-priv/esp-mesh-lite/components/mesh_lite_priv/priv_src/esp_mesh_lite_comm.c:651

18 0x400d9e3a:0x3ffbd680 in esp_mesh_lite_send_mesh_request at /builds/ae_group/esp-mesh-lite-priv/esp-mesh-lite/components/mesh_lite_priv/priv_src/esp_mesh_lite_comm.c:1933

19 0x400d9e47:0x3ffbd6a0 in mesh_req_timer_callback at /builds/ae_group/esp-mesh-lite-priv/esp-mesh-lite/components/mesh_lite_priv/priv_src/esp_mesh_lite_comm.c:414

20 0x4008f27b:0x3ffbd6c0 in prvProcessExpiredTimer at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/timers.c:565

  (inlined by) prvProcessTimerOrBlockTask at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/timers.c:634
  (inlined by) prvTimerTask at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/timers.c:597     

` Node 2

`5 4 3 2 1
[ 3281][I][main.cpp:175] setup(): [Mesh_Test] IDF Version : v4.4.6-dirty [ 3282][I][main.cpp:176] setup(): [Mesh_Test] Flash size : 4 MB (4194304)

I (3286) bridge_common: esp-iot-bridge version: 0.0.0 I (3374) bridge_common: IP Address:192.168.4.1 I (3375) bridge_common: GW Address:192.168.4.1 I (3375) bridge_common: NM Address:255.255.255.0 I (3379) bridge_wifi: IP Address:192.168.4.1 Add netif ap with MyMesh(commit id) I (3387) bridge_common: netif list add success Add netif sta with MyMesh(commit id) I (3396) bridge_common: netif list add success I (7033) bridge_common: [WIFI_AP_DEF ]Name Server1: 114.114.114.114 I (7044) bridge_wifi: [esp_bridge_wifi_set_config] sta ssid: xxxx password: xxxx [ 3428][I][main.cpp:96] wifi_init(): [Mesh_Test] esp_bridge_wifi_set_config(STA) : ESP_OK I (7059) bridge_wifi: [esp_bridge_wifi_set_config] softap ssid: PIXmesh_25e8ad password: xxxxx [ 4000][I][main.cpp:102] wifi_init(): [Mesh_Test] esp_bridge_wifi_set_config(AP) : ESP_OK I (7623) Mesh-Lite: esp-mesh-lite component version: 0.10.2 I (7627) bridge_common: [WIFI_AP_DEF ]Name Server1: 114.114.114.114 I (7635) ESPNOW: espnow [version: 1.0] init I (7638) [vendor_ie]: Mesh-Lite commit id: d919851

I (7644) [vendor_ie]: Mesh ID: 77 D (7649) [vendor_ie]: ota_data_len is 1388 ota_wnd 8328 I (7652) [ESP_Mesh_Lite_Comm]: msg action add success I (7658) [ESP_Mesh_Lite_Comm]: msg action add success I (7659) [ESP_Mesh_Lite_Comm]: Bind Socket 48, port 6364 I (7667) [ESP_Mesh_Lite_Comm]: Bind Socket 49, port 6363 I (7672) [ESP_Mesh_Lite_Comm]: Bind Socket 50, port 6366 I (7677) [ESP_Mesh_Lite_Comm]: Bind Socket 51, port 6365 D (7682) [ESP_Mesh_Lite_Comm]: free heap: 134344 I (7687) [mesh-lite-espnow]: Start espnow task I (7692) Mesh-Lite: Mesh-Lite connecting I (7697) [vendor_ie]: esp_mesh_lite_wifi_scan_start return ESP_OK [ 5069][I][main.cpp:50] printWifiMode(): [Mesh_Test] WiFi mode: Station + Access Point [ 5069][I][main.cpp:148] mesh_setup(): [Mesh_Test] Mesh Networking Mode : ROUTER [ 5075][I][main.cpp:150] mesh_setup(): [Mesh_Test] Node Level : 0 I (10541) [vendor_ie]: Mesh-Lite Scan done I (10543) [vendor_ie]: Find PIXmesh_035745 I (10543) [vendor_ie]: bssid 3c:71:bf:03:57:45 I (10543) [vendor_ie]: RTC store: ssid:PIXmesh_035745; bssid:3c:71:bf:03:57:45 crc:42116070 I (10552) [vendor_ie]: wifi_cfg PIXmesh_035745 router_config gatts I (10559) [vendor_ie]: esp_mesh_lite_wifi_connect return ESP_OK I (11371) bridge_wifi: Connected with IP Address:192.168.4.2 I (11373) bridge_common: [WIFI_AP_DEF ]Name Server1: 192.168.1.1 I (11374) bridge_common: [WIFI_AP_DEF ] I (11379) bridge_common: IP Address:192.168.5.1 I (11384) bridge_common: GW Address:192.168.5.1 I (11389) bridge_common: NM Address:255.255.255.0 I (11396) bridge_common: ip reallocate new:192.168.5.1 I (11400) bridge_wifi: SoftAP IP network segment has changed, deauth all station I (11409) [vendor_ie]: RTC store: ssid:PIXmesh_035745; bssid:3c:71:bf:03:57:45 crc:596469514 I (11417) Mesh-Lite: netif network segment conflict check D (12681) [ESP_Mesh_Lite_Comm]: free heap: 129036 [ 15082][I][esp_mesh_init.cpp:55] print_system_info_timercb(): [local_control] System information, channel: 2, layer: 2, self mac: 08:d1:f9:25:e8:ac, free heap: 128752 [ 15086][I][esp_mesh_init.cpp:60] print_system_info_timercb(): [local_control] parent bssid: 3c:71:bf:03:57:45, parent rssi: -23 [ 15098][I][esp_mesh_init.cpp:65] print_system_info_timercb(): [local_control] Num of child nodes : 0 I (24134) Mesh-Lite: netif network segment conflict check Guru Meditation Error: Core 0 panic'ed (Unhandled debug exception). Debug exception reason: Stack canary watchpoint triggered (Tmr Svc) Core 0 register dump: PC : 0x4008f6df PS : 0x00060536 A0 : 0x8008d0a5 A1 : 0x3ffbcf60 A2 : 0x3ffb944c A3 : 0xb33fffff A4 : 0x0000abab A5 : 0x00060523
A6 : 0x00060520 A7 : 0x0000cdcd A8 : 0xb33fffff A9 : 0xffffffff
A10 : 0x00000003 A11 : 0x00060523 A12 : 0x00060520 A13 : 0x00000044
A14 : 0x007b944c A15 : 0x003fffff SAR : 0x00000004 EXCCAUSE: 0x00000001 EXCVADDR: 0x00000000 LBEG : 0x40089e95 LEND : 0x40089ea5 LCOUNT : 0xffffffff

Backtrace: 0x4008f6dc:0x3ffbcf60 0x4008d0a2:0x3ffbcfa0 0x4008d164:0x3ffbcfe0 0x40084dd1:0x3ffbd000 0x40084edd:0x3ffbd030 0x400e5e1d:0x3ffbd050 0x400e5107:0x3ffbd070 0x400e498d:0x3ffbd090 0x40089b91:0x3ffbd0b0 0x40088f96:0x3ffbd0d0 0x40089020:0x3ffbd0f0 0x4008950d:0x3ffbd120 0x401528c7:0x3ffbd150 0x4014b81b:0x3ffbd170 0x4014b999:0x3ffbd480 0x4015d97d:0x3ffbd4b0 0x400ff26e:0x3ffbd4e0 0x400d3b05:0x3ffbd510 0x400d6499:0x3ffbd5f0 0x400d8850:0x3ffbd610 0x400d888b:0x3ffbd680 0x400d85f6:0x3ffbd6a0 0x4008f27b:0x3ffbd6c0

0 0x4008f6dc:0x3ffbcf60 in compare_and_set_native at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/esp_hw_support/include/soc/compare_set.h:25

  (inlined by) spinlock_acquire at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/esp_hw_support/include/soc/spinlock.h:103
  (inlined by) xPortEnterCriticalTimeout at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/port/xtensa/port.c:301

1 0x4008d0a2:0x3ffbcfa0 in vPortEnterCritical at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/port/xtensa/include/freertos/portmacro.h:578

  (inlined by) xQueueSemaphoreTake at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/queue.c:1563

2 0x4008d164:0x3ffbcfe0 in xQueueTakeMutexRecursive at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/queue.c:731

3 0x40084dd1:0x3ffbd000 in lock_acquire_generic at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/newlib/locks.c:153

4 0x40084edd:0x3ffbd030 in _lock_acquire_recursive at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/newlib/locks.c:167

5 0x400e5e1d:0x3ffbd050 in uart_write at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/vfs/vfs_uart.c:208

6 0x400e5107:0x3ffbd070 in console_write at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/vfs/vfs_console.c:73

7 0x400e498d:0x3ffbd090 in esp_vfs_write at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/vfs/vfs.c:431 (discriminator 4)

8 0x40089b91:0x3ffbd0b0 in __swrite at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/stdio.c:94

9 0x40088f96:0x3ffbd0d0 in __sflush_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fflush.c:224

10 0x40089020:0x3ffbd0f0 in _fflush_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fflush.c:278

11 0x4008950d:0x3ffbd120 in __sfvwrite_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fvwrite.c:251

12 0x401528c7:0x3ffbd150 in __sprint_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vfprintf.c:433

  (inlined by) __sprint_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vfprintf.c:403

13 0x4014b81b:0x3ffbd170 in _vfprintf_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vfprintf.c:1781 (discriminator 1)

14 0x4014b999:0x3ffbd480 in vprintf at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vprintf.c:34 (discriminator 5)

15 0x4015d97d:0x3ffbd4b0 in esp_log_writev at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/log/log.c:200

16 0x400ff26e:0x3ffbd4e0 in __wrap_esp_log_writev at /Users/ficeto/Desktop/ESP32/ESP32S2/esp32-arduino-lib-builder/components/esp-rainmaker/components/esp-insights/components/esp_diagnostics/src/esp_diagnostics_log_hook.c:452

17 0x400d3b05:0x3ffbd510 in esp_mesh_lite_log_write at src/esp_mesh_lite_log.c:56

18 0x400d6499:0x3ffbd5f0 in esp_mesh_lite_wifi_scan_start at /builds/ae_group/esp-mesh-lite-priv/esp-mesh-lite/components/mesh_lite_priv/priv_src/esp_mesh_lite.c:280 (discriminator 1)

19 0x400d8850:0x3ffbd610 in esp_mesh_lite_comm_scan at /builds/ae_group/esp-mesh-lite-priv/esp-mesh-lite/components/mesh_lite_priv/priv_src/esp_mesh_lite_comm.c:445

20 0x400d888b:0x3ffbd680 in volunteer_raise at /builds/ae_group/esp-mesh-lite-priv/esp-mesh-lite/components/mesh_lite_priv/priv_src/esp_mesh_lite_comm.c:1314

21 0x400d85f6:0x3ffbd6a0 in poll_timer_cb at /builds/ae_group/esp-mesh-lite-priv/esp-mesh-lite/components/mesh_lite_priv/priv_src/esp_mesh_lite_comm.c:2152

22 0x4008f27b:0x3ffbd6c0 in prvProcessExpiredTimer at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/timers.c:565

  (inlined by) prvProcessTimerOrBlockTask at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/timers.c:634
  (inlined by) prvTimerTask at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/timers.c:597

`

djswirl commented 5 months ago

Any news on this ?

xcguang commented 5 months ago

Sorry, the developer is on leave, we will debug it this week.

tswen commented 5 months ago

@djswirl What version of IDF are you using, down to which commit? Also, have there been updates to IDF's submodules? You can update them with git submodule update --init --recursive.

YannickIngecom commented 5 months ago

Hi, I get the same issue here except that only the root node crash with the following log. The leaf node is still up and running, restarting it's connection when the root is up again:

ESP-IDF v5.1.3-dirty Last version of submodules checkout today.

I (13) boot: ESP-IDF v5.1.3-dirty 2nd stage bootloader
I (13) boot: compile time Apr 29 2024 16:50:08
I (13) boot: Multicore bootloader
I (17) boot: chip revision: v3.0
I (21) boot.esp32: SPI Speed      : 40MHz
I (25) boot.esp32: SPI Mode       : DIO
I (30) boot.esp32: SPI Flash Size : 8MB
I (34) boot: Enabling RNG early entropy source...
I (40) boot: Partition Table:
I (43) boot: ## Label            Usage          Type ST Offset   Length
I (51) boot:  0 factory          factory app      00 00 00010000 00150000
I (58) boot:  1 ota_0            OTA app          00 10 00160000 00150000
I (66) boot:  2 ota_1            OTA app          00 11 002b0000 00150000
I (73) boot:  3 otadata          OTA data         01 00 00400000 00002000
I (81) boot:  4 phy_init         RF data          01 01 00402000 0000c000
I (88) boot:  5 storage          Unknown data     01 81 0040e000 00384000
I (96) boot:  6 nvs              WiFi data        01 02 00792000 0004b000
I (103) boot: End of partition table
I (107) boot: Defaulting to factory image
I (112) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=3c92ch (248108) map
I (210) esp_image: segment 1: paddr=0004c954 vaddr=3ffb0000 size=036c4h ( 14020) load
I (216) esp_image: segment 2: paddr=00050020 vaddr=400d0020 size=e1f70h (925552) map
I (550) esp_image: segment 3: paddr=00131f98 vaddr=3ffb36c4 size=00234h (   564) load
I (551) esp_image: segment 4: paddr=001321d4 vaddr=40080000 size=153bch ( 86972) load
I (603) boot: Loaded app from partition at offset 0x10000
I (603) boot: Disabling RNG early entropy source...
I (614) cpu_start: Multicore app
I (615) quad_psram: This chip is ESP32-D0WD
I (615) esp_psram: Found 8MB PSRAM device
I (617) esp_psram: Speed: 40MHz
I (621) esp_psram: PSRAM initialized, cache is in low/high (2-core) mode.
W (628) esp_psram: Virtual address not enough for PSRAM, map as much as we can. 4MB is mapped
I (637) cpu_start: Pro cpu up.
I (641) cpu_start: Starting app cpu, entry point is 0x40080f10
0x40080f10: call_start_cpu1 at /Users/yannick/Documents/Esp-Idf/esp-idf_5.1.3/components/esp_system/port/cpu_start.c:159

I (641) cpu_start: App cpu up.
I (1526) esp_psram: SPI SRAM memory test OK
I (1534) cpu_start: Pro cpu start user code
I (1534) cpu_start: cpu freq: 240000000 Hz
I (1534) cpu_start: Application information:
I (1538) cpu_start: Project name:     ap2201
I (1543) cpu_start: App version:      0.3.0
I (1547) cpu_start: Compile time:     Apr 29 2024 17:23:32
I (1554) cpu_start: ELF file SHA256:  ac6b182545cc2014...
I (1560) cpu_start: ESP-IDF:          v5.1.3-dirty
I (1565) cpu_start: Min chip rev:     v3.0
I (1570) cpu_start: Max chip rev:     v3.99 
I (1575) cpu_start: Chip rev:         v3.0
I (1580) heap_init: Initializing. RAM available for dynamic allocation:
I (1587) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1593) heap_init: At 3FFB9730 len 000268D0 (154 KiB): DRAM
I (1599) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1606) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1612) heap_init: At 400953BC len 0000AC44 (43 KiB): IRAM
I (1619) esp_psram: Adding pool of 4096K of PSRAM memory to heap allocator
I (1627) spi_flash: detected chip: generic
I (1631) spi_flash: flash io: dio
I (1636) app_start: Starting scheduler on CPU0
I (1640) app_start: Starting scheduler on CPU1
I (1640) main_task: Started on CPU0
I (1650) esp_psram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1655) main_task: Calling app_main()
I (1660) ap2201: INGECOM Access Point 2201
[ap2201] INGECOM Access Point 2201
[ap2201] ap2201_93FAB1F0
I (1670) ap2201: Mounting NVS storage filesystem
I (1875) ap2201: Mounting FAT storage filesystem
I (1930) config: Init
I (2005) ap2201: I2C Init
I (2005) ap2201: SPI Init
I (2005) ap2201: GPIO Init
I (2005) mqtt: Init
I (2005) ap2201: Ethernet Init
I (2020) esp_eth.netif.netif_glue: e8:31:cd:e5:e1:9b
I (2020) esp_eth.netif.netif_glue: ethernet attached to netif
I (2030) ap2201: ETH: Started
I (2140) ota: SHA-256 partition table:3a8d969b06603a286d500fab78ee4cba4de285c1540bf53a0e677dd8fcff73be
I (2160) ota: SHA-256 bootloader.....:7ddae99b670c6c3d8d2530f08b43cc9115ee195c564fc3527716d490264f0b47
I (2440) ota: SHA-256 current fw.....:28cbf3ed1a12f552f364a04d0c2a9e8ce9aacb579ec9dff1acd08092da8fa905
I (2445) ota: SHA-256 next firmware..:28cbf3ed1a12f552f364a04d0c2a9e8ce9aacb579ec9dff1acd08092da8fa905
I (2450) ota: Current partition.: factory
I (2455) ota: Next OTA partition: ota_0
I (2460) max4820: Init
I (2465) gpio: GPIO[14]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (2475) gpio: GPIO[15]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (2480) lora-e5: Init
I (2485) uart: queue free spaces: 20
I (4030) ap2201: ETH: Link Up
I (4030) ap2201: ETH: HW Addr = e8:31:cd:e5:e1:9b
I (4030) mqtt_client: Client force reconnect requested
I (4035) esp_netif_handlers: eth0 ip: 192.168.1.77, mask: 255.255.255.0, gw: 192.168.1.1
I (4045) ap2201: ETH: Got IP
I (4140) mqtt: Connected
I (5790) lora-e5: RF Config: RFCFG F:869525000, SF7, BW125K, TXPR:8, RXPR:10, POW:14dBm, CRC:ON, IQ:OFF, NET:OFF
I (5790) lora-e5: Config module success
I (5795) ap2201: Mesh Init
I (5795) bridge_common: esp-iot-bridge version: 0.11.3
I (5810) wifi:wifi driver task: 3ffd23c8, prio:23, stack:6656, core=0
I (5815) wifi:wifi firmware version: 0016c4d
I (5815) wifi:wifi certification version: v7.0
I (5815) wifi:config NVS flash: enabled
I (5820) wifi:config nano formating: disabled
I (5825) wifi:Init data frame dynamic rx buffer num: 32
I (5830) wifi:Init static rx mgmt buffer num: 5
I (5835) wifi:Init management short buffer num: 32
I (5840) wifi:Init static tx buffer num: 16
I (5845) wifi:Init tx cache buffer num: 32
I (5845) wifi:Init static rx buffer size: 1600
I (5850) wifi:Init static rx buffer num: 10
I (5855) wifi:Init dynamic rx buffer num: 32
I (5860) wifi_init: rx ba win: 6
I (5860) wifi_init: tcpip mbox: 32
I (5865) wifi_init: udp mbox: 6
I (5870) wifi_init: tcp mbox: 6
I (5875) wifi_init: tcp tx win: 5744
I (5880) wifi_init: tcp rx win: 5744
I (5880) wifi_init: tcp mss: 1440
I (5885) wifi_init: WiFi IRAM OP enabled
I (5890) wifi_init: WiFi RX IRAM OP enabled
I (5895) phy_init: phy_version 4791,2c4672b,Dec 20 2023,16:06:06
I (5970) wifi:mode : null
I (5975) wifi:mode : softAP (e8:31:cd:e5:e1:99)
I (5975) wifi:Total power save buffer number: 8
I (5975) wifi:Init max length of beacon: 752/752
I (5980) wifi:Init max length of beacon: 752/752
I (5985) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.4.1
I (5990) bridge_common: [WIFI_AP_DEF ]
I (5995) bridge_common: Set ip info:192.168.4.1
W (6000) bridge_common: SoftAP IP network segment has changed, deauth all station
Add netif ap with 38f0c1b(commit id)
I (6015) bridge_common: netif list add success
I (6020) wifi:Disabled PMF config for SoftAP
I (6025) wifi:Total power save buffer number: 8
I (6030) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.4.1
I (6035) bridge_common: [WIFI_AP_DEF ]Name Server1: 114.114.114.114
Add netif sta with 38f0c1b(commit id)
I (6045) bridge_common: netif list add success
I (6050) wifi:mode : sta (e8:31:cd:e5:e1:98) + softAP (e8:31:cd:e5:e1:99)
I (6055) wifi:enable tsf
E (6060) NVS: Failed to read IP info from NVS
I (6065) wifi:Disabled PMF config for STA
I (6070) bridge_wifi: [esp_bridge_wifi_set_config] sta ssid:  password: 
I (6075) bridge_wifi: [esp_bridge_wifi_set_config] softap ssid: ESP_Bridge password: 12345678
I (6230) wifi:Total power save buffer number: 8
I (6230) Mesh-Lite: esp-mesh-lite component version: 0.10.3
I (6230) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.4.1
I (6240) bridge_common: [WIFI_AP_DEF ]Name Server1: 192.168.1.1
I (6245) ESPNOW: espnow [version: 1.0] init
I (6250) [vendor_ie]: Mesh-Lite commit id: 67ed3d6

I (6255) [vendor_ie]: Mesh ID: 77 
I (6260) [ESP_Mesh_Lite_Comm]: msg action add success 
I (6265) [ESP_Mesh_Lite_Comm]: Bind Socket 49, port 6364 
I (6270) [ESP_Mesh_Lite_Comm]: Bind Socket 50, port 6363 
I (6275) [ESP_Mesh_Lite_Comm]: Bind Socket 51, port 6366 
I (6280) [ESP_Mesh_Lite_Comm]: Bind Socket 52, port 6365 
I (6290) [mesh-lite-espnow]: Start espnow task 
I (6295) ap2201: Root node
I (6295) Mesh-Lite: Mesh-Lite connecting
I (6300) ap2201: MeshLite init done
I (6405) msg_service: Init
I (6455) rf_tag_rx: Init
I (6455) rfmax: Init
I (6455) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (6455) gpio: GPIO[12]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:1 
I (6465) rfmax: Resetting...
I (7340) rfmax: Reset done
I (7440) rfmax: Set RF-Max config (1/50)...
I (7440) rfmax: Set RF-Max config success
I (7490) ds3231: Init
I (7490) ds3231: Init RTC OK
I (7490) ds3231: Date Time: [0x01, 0x15, 0x01, 0x01, 0x01, 0x01, 0x00]
I (7490) ds3231: Set time zone: CET-1CEST-2,M3.5.0/02:00:00,M10.5.0/03:00:00
I (7500) ds3231: Current date/time: Sat Jan  1 02:15:01 2000
I (7505) ds3231: Date Time: [0x01, 0x15, 0x01, 0x01, 0x01, 0x01, 0x00]
I (7505) ds3231: RTC timestamp: 946689301
I (7565) web_server: Init
I (7565) web_server: Starting HTTP Server
I (7620) ota: Init
I (7620) tftp: Init
I (12180) wifi:new:<11,2>, old:<11,2>, ap:<11,2>, sta:<0,0>, prof:11
I (12180) wifi:station: b0:b2:1c:b4:5c:08 join, AID=1, bgn, 40D
I (12200) bridge_wifi: STA Connecting to the AP again...
I (12230) esp_netif_lwip: DHCP server assigned IP to a client, IP is: 192.168.4.2
E (36260) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm 
E (41260) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm 
E (46260) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm 
E (51260) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm 
E (56260) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm 

***ERROR*** A stack overflow in task Tmr Svc has been detected.

Backtrace: 0x40081632:0x3ffbc5e0 0x4008ab39:0x3ffbc600 0x4008b1ea:0x3ffbc620 0x4008b8da:0x3ffbc6a0 0x4008ac70:0x3ffbc6d0 0x4008ac22:0xa5a5a5a5 |<-CORRUPTED
0x40081632: panic_abort at /Users/yannick/Documents/Esp-Idf/esp-idf_5.1.3/components/esp_system/panic.c:472
0x4008ab39: esp_system_abort at /Users/yannick/Documents/Esp-Idf/esp-idf_5.1.3/components/esp_system/port/esp_system_chip.c:84
0x4008b1ea: vApplicationStackOverflowHook at /Users/yannick/Documents/Esp-Idf/esp-idf_5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:581
0x4008b8da: vTaskSwitchContext at /Users/yannick/Documents/Esp-Idf/esp-idf_5.1.3/components/freertos/FreeRTOS-Kernel/tasks.c:3840
0x4008ac70: _frxt_dispatch at /Users/yannick/Documents/Esp-Idf/esp-idf_5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/portasm.S:450
0x4008ac22: _frxt_int_exit at /Users/yannick/Documents/Esp-Idf/esp-idf_5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/portasm.S:245

ELF file SHA256: ac6b182545cc2014
tswen commented 4 months ago

You can increase the ESP_TIMER_TASK_STACK_SIZE configuration in menuconfig.

djswirl commented 4 months ago

The stack is already set high. I've given up trying to get this to work. Maybe I'll re visit in the future when it's more stable. Do you have plans to make it Platformio compatible?

xcguang commented 4 months ago

The stack is already set high. I've given up trying to get this to work. Maybe I'll re visit in the future when it's more stable. Do you have plans to make it Platformio compatible?

  1. After failed to build, mv managed_components/espressif__iot_bridge to components/espressif__iot_bridge
  2. Modify components/espressif__iot_bridge/CMakeLists.txt as following
    set(FALLBACK_DNS_SERVER "8.8.8.8")
    target_compile_options(__idf_lwip PRIVATE
                       "-DIP_NAPT_PORTMAP=1"
                       "-DIP_PORTMAP_MAX=255"
                       "-DFALLBACK_DNS_SERVER_ADDRESS(p)=ipaddr_aton(\"${FALLBACK_DNS_SERVER}\",(p))")

to

target_compile_options(__idf_lwip PRIVATE
                       "-DIP_NAPT_PORTMAP=1"
                       "-DIP_PORTMAP_MAX=255")
  1. This is my sdkconfig, it can run

sdkconfig.esp32s3camlcd.zip

␛[0;31mE (86342) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm ␛[0m
␛[0;32mI (86342) [vendor_ie]: esp_mesh_lite_wifi_scan_start return ESP_OK ␛[0m
␛[0;32mI (89172) [vendor_ie]: Mesh-Lite Scan done ␛[0m
␛[0;32mI (89182) [vendor_ie]: RTC store: ssid:; bssid:00:00:00:00:00:00 crc:4043245259 ␛[0m
␛[0;31mE (91342) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm ␛[0m
␛[0;32mI (91392) no_router: System information, channel: 11, layer: 0, self mac: 34:85:18:90:e2:98, parent bssid: 00:00:00:00:00:00, parent rssi: -120, free heap: 249912␛[0m
␛[0;31mE (96342) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm ␛[0m
␛[0;32mI (96342) [vendor_ie]: esp_mesh_lite_wifi_scan_start return ESP_OK ␛[0m
␛[0;32mI (99172) [vendor_ie]: Mesh-Lite Scan done ␛[0m
␛[0;32mI (99172) [vendor_ie]: RTC store: ssid:; bssid:00:00:00:00:00:00 crc:4043245259 ␛[0m
␛[0;31mE (101342) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm ␛[0m
␛[0;32mI (101392) no_router: System information, channel: 11, layer: 0, self mac: 34:85:18:90:e2:98, parent bssid: 00:00:00:00:00:00, parent rssi: -120, free heap: 249900␛[0m
␛[0;31mE (106342) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm ␛[0m
␛[0;32mI (106342) [vendor_ie]: esp_mesh_lite_wifi_scan_start return ESP_OK ␛[0m
␛[0;32mI (109172) [vendor_ie]: Mesh-Lite Scan done ␛[0m
␛[0;32mI (109172) [vendor_ie]: RTC store: ssid:; bssid:00:00:00:00:00:00 crc:4043245259 ␛[0m
␛[0;31mE (111342) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm ␛[0m
␛[0;32mI (111392) no_router: System information, channel: 11, layer: 0, self mac: 34:85:18:90:e2:98, parent bssid: 00:00:00:00:00:00, parent rssi: -120, free heap: 249912␛[0m
␛[0;31mE (116342) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm ␛[0m
␛[0;32mI (116342) [vendor_ie]: esp_mesh_lite_wifi_scan_start return ESP_OK ␛[0m
␛[0;32mI (119172) [vendor_ie]: Mesh-Lite Scan done ␛[0m
␛[0;32mI (119182) [vendor_ie]: RTC store: ssid:; bssid:00:00:00:00:00:00 crc:4043245259 ␛[0m
␛[0;31mE (121342) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm ␛[0m
␛[0;32mI (121392) no_router: System information, channel: 11, layer: 0, self mac: 34:85:18:90:e2:98, parent bssid: 00:00:00:00:00:00, parent rssi: -120, free heap: 249900␛[0m
␛[0;31mE (126342) [ESP_Mesh_Lite_Comm]: ESP_Mesh_Lite_Comm ␛[0m