espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.7k stars 7.3k forks source link

'wifi' task crashes issue (IDFGH-12738) #13721

Open InterfacerCompany opened 6 months ago

InterfacerCompany commented 6 months ago

Answers checklist.

IDF version.

v5.1.3

Espressif SoC revision.

ESP32-D0WD-V3

Operating System used.

Windows

How did you build your project?

Command line with idf.py

If you are using Windows, please specify command line type.

CMD

Development Kit.

custom PCB

Power Supply used.

External 5V

What is the expected behavior?

I expected that my device would work continuously for a long period of time without crashes and reboots.

What is the actual behavior?

After working for a while, my device crashes and reboots.

Steps to reproduce.

Unfortunately, I don't have the steps to reproduce. It just happens with some period. It can crash a few times during the day. Or even it can be working 24 hours and then crash.

Debug Logs.

Here is the decoded core dump. 

Setting PYTHONNOUSERSITE, was not set
Using Python in D:\esp32\Espressif\python_env\idf5.1_py3.11_env\Scripts\
Python 3.11.2
Using Git in D:\esp32\Espressif\tools\idf-git\2.43.0\cmd\
git version 2.43.0.windows.1
Checking Python compatibility
Setting IDF_PATH: D:\esp32\Espressif\frameworks\esp-idf-v5.1.3

Adding ESP-IDF tools to PATH...
    D:\esp32\Espressif\tools\xtensa-esp-elf-gdb\12.1_20231023\xtensa-esp-elf-gdb\bin
    D:\esp32\Espressif\tools\riscv32-esp-elf-gdb\12.1_20231023\riscv32-esp-elf-gdb\bin
    D:\esp32\Espressif\tools\xtensa-esp32-elf\esp-12.2.0_20230208\xtensa-esp32-elf\bin
    D:\esp32\Espressif\tools\xtensa-esp32s2-elf\esp-12.2.0_20230208\xtensa-esp32s2-elf\bin
    D:\esp32\Espressif\tools\xtensa-esp32s3-elf\esp-12.2.0_20230208\xtensa-esp32s3-elf\bin
    D:\esp32\Espressif\tools\riscv32-esp-elf\esp-12.2.0_20230208\riscv32-esp-elf\bin
    D:\esp32\Espressif\tools\esp32ulp-elf\2.35_20220830\esp32ulp-elf\bin
    D:\esp32\Espressif\tools\cmake\3.24.0\bin
    D:\esp32\Espressif\tools\openocd-esp32\v0.12.0-esp32-20230921\openocd-esp32\bin
    D:\esp32\Espressif\tools\ninja\1.10.2\
    D:\esp32\Espressif\tools\idf-exe\1.0.3\
    D:\esp32\Espressif\tools\ccache\4.8\ccache-4.8-windows-x86_64
    D:\esp32\Espressif\tools\dfu-util\0.11\dfu-util-0.11-win64
    D:\esp32\Espressif\frameworks\esp-idf-v5.1.3\tools

Checking if Python packages are up to date...
Constraint file: D:\esp32\Espressif\espidf.constraints.v5.1.txt
Requirement files:
 - D:\esp32\Espressif\frameworks\esp-idf-v5.1.3\tools\requirements\requirements.core.txt
Python being checked: D:\esp32\Espressif\python_env\idf5.1_py3.11_env\Scripts\python.exe
Python requirements are satisfied.

Detected installed tools that are not currently used by active ESP-IDF version.
For removing old versions of ccache, cmake, dfu-util, esp-rom-elfs, idf-driver, idf-python-wheels, openocd-esp32, riscv32-esp-elf, riscv32-esp-elf-gdb, xtensa-esp-elf-gdb, xtensa-esp32-elf, xtensa-esp32s2-elf, xtensa-esp32s3-elf use command 'python.exe D:\esp32\Espressif\frameworks\esp-idf-v5.1.3\tools\idf_tools.py uninstall'
For free up even more space, remove installation packages of those tools. Use option 'python.exe D:\esp32\Espressif\frameworks\esp-idf-v5.1.3\tools\idf_tools.py uninstall --remove-archives'.

Done! You can now compile ESP-IDF projects.
Go to the project directory and run:

  idf.py build

D:\esp32\Espressif\frameworks\esp-idf-v5.1.3>cd d:\my_projects\ESP32\tmp\exeption-dec\1.29.33\82\

d:\my_projects\ESP32\tmp\exeption-dec\1.29.33\82>
d:\my_projects\ESP32\tmp\exeption-dec\1.29.33\82>
d:\my_projects\ESP32\tmp\exeption-dec\1.29.33\82>
d:\my_projects\ESP32\tmp\exeption-dec\1.29.33\82>
d:\my_projects\ESP32\tmp\exeption-dec\1.29.33\82>python coredump-decoder.py

===============================================================
==================== ESP32 CORE DUMP START ====================

Crashed task handle: 0x3ffd9c08, name: 'wifi', GDB name: 'process 1073585160'
Crashed task is not in the interrupt context

================== CURRENT THREAD REGISTERS ===================
exccause       0x1c (LoadProhibitedCause)
excvaddr       0xf3a15a34
epc1           0x40094778
epc2           0x0
epc3           0x402009e2
epc4           0x402009e2
epc5           0x0
epc6           0x0
eps2           0x0
eps3           0x60620
eps4           0x60620
eps5           0x0
eps6           0x0
pc             0x4009876f          0x4009876f <tlsf_malloc+543>
lbeg           0x401f4834          1075791924
lend           0x401f483b          1075791931
lcount         0x0                 0
sar            0x1b                27
ps             0x60c23             396323
threadptr      <unavailable>
br             <unavailable>
scompare1      <unavailable>
acclo          <unavailable>
acchi          <unavailable>
m0             <unavailable>
m1             <unavailable>
m2             <unavailable>
m3             <unavailable>
expstate       <unavailable>
f64r_lo        <unavailable>
f64r_hi        <unavailable>
f64s           <unavailable>
fcr            <unavailable>
fsr            <unavailable>
a0             0x800980ff          -2146860801
a1             0x3ffd9870          1073584240
a2             0x3ffcee7c          1073540732
a3             0x3ffcee84          1073540740
a4             0x3ffceea0          1073540768
a5             0xf3a15a30          -207529424
a6             0x4814a8c0          1209313472
a7             0x3ffb5fa0          1073438624
a8             0xb3a46b04          -1281070332
a9             0x3ffcee7c          1073540732
a10            0xa8                168
a11            0x3ffcef28          1073540904
a12            0xfffffffc          -4
a13            0x3ffcef30          1073540912
a14            0xb                 11
a15            0x3ffceed0          1073540816

==================== CURRENT THREAD STACK =====================
#0  block_set_prev_free (block=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf_block_functions.h:102
#1  block_mark_as_free (block=0x3ffcef28) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf_block_functions.h:110
#2  block_split (size=168, block=0x3ffcee7c) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf.c:418
#3  block_trim_free (size=168, block=0x3ffcee7c, control=0x3ffcee7c) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf.c:499
#4  block_prepare_used (size=168, block=0x3ffcee7c, control=0x3ffcee7c) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf.c:579
#5  tlsf_malloc (tlsf=0x3ffcee7c, size=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf.c:1006
#6  0x400980ff in multi_heap_malloc_impl (heap=0x3ffcee68, size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/multi_heap.c:207
#7  0x40081d7a in heap_caps_malloc_base (size=168, caps=6144) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/heap_caps.c:176
#8  0x40081dc3 in heap_caps_malloc (caps=6144, size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/heap_caps.c:197
#9  heap_caps_malloc_default (size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/heap_caps.c:223
#10 0x40098f80 in malloc (size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/newlib/heap.c:24
#11 0x40185a87 in mem_malloc (size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/mem.c:209
#12 0x40185b2e in do_memp_malloc_pool (desc=0x3f45bd7c) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/memp.c:254
#13 0x40185b6e in memp_malloc (type=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/memp.c:350
#14 0x40187da8 in tcp_alloc (prio=64 '@') at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/tcp.c:1851
#15 0x401897e1 in tcp_listen_input (pcb=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/tcp_in.c:672
#16 tcp_input (p=0x3ffb3fb0, inp=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/tcp_in.c:391
#17 0x4018f861 in ip4_input (p=0x3ffb3fb0, inp=0x3ffdd6a0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/ipv4/ip4.c:752
#18 0x4018ff6d in ethernet_input (p=0x3ffb3fb0, netif=0x3ffdd6a0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/netif/ethernet.c:186
#19 0x40184a14 in tcpip_inpkt (input_fn=<optimized out>, inp=0x3ffdd6a0, p=0x3ffb3fb0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/api/tcpip.c:246
#20 tcpip_input (p=0x3ffb3fb0, inp=0x3ffdd6a0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/api/tcpip.c:287
#21 0x401945e6 in wlanif_input (h=0x3ffdd6a0, buffer=<optimized out>, len=<optimized out>, l2_buff=0x3ffd0cbc) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_netif/lwip/netif/wlanif.c:160
#22 0x401f48e8 in esp_netif_receive (esp_netif=0x3ffdd61c, buffer=0x3ffd0d4e, len=66, eb=0x3ffd0cbc) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_netif/lwip/esp_netif_lwip.c:1258
#23 0x4019614c in wifi_sta_receive (buffer=0x3ffd0d4e, len=66, eb=0x3ffd0cbc) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_wifi/src/wifi_netif.c:39
#24 0x401faf70 in sta_input ()
#25 0x401fb028 in sta_rx_cb ()
#26 0x401fcfe0 in ppRxPkt ()
#27 0x401f865b in ppTask ()
#28 0x40095391 in vPortTaskWrapper (pxCode=0x401f856c <ppTask>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

======================== THREADS INFO =========================
  Id   Target Id          Frame
* 1    process 1073585160 block_set_prev_free (block=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf_block_functions.h:102
  2    process 1073446084 esp_vApplicationIdleHook () at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/freertos_hooks.c:47
  3    process 1073644856 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  4    process 1073468364 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  5    process 1073561052 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  6    process 1073565108 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  7    process 1073609108 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  8    process 1073438664 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  9    process 1073569296 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  10   process 1073608748 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  11   process 1073574700 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  12   process 1073613332 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  13   process 1073672636 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  14   process 1073429828 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  15   process 1073438092 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  16   process 1073669064 0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
  17   process 1073444608 0x4000bff0 in ?? ()

       TCB             NAME PRIO C/B  STACK USED/FREE
---------- ---------------- -------- ----------------
0x3ffd9c08             wifi    23/23         800/5340
0x3ffb7cc4             IDLE      0/0         400/1124
0x3ffe8538common_blocking_thread      1/1         480/3612
0x3ffbd3cc       log_thread      1/1         512/1528
0x3ffd3ddccommon_no_blocking_thread      1/1         464/2600
0x3ffd4db4   charger_thread      1/1         704/2864
0x3ffdf994mb_tcp_serv_thread      1/1         592/3496
0x3ffb5fc8    mb_cli_thread      1/1         528/2540
0x3ffd5e10              tiT    18/18         528/2532
0x3ffdf82c  wifi_app_thread      1/1         656/2404
0x3ffd732c          sys_evt    20/20         560/3784
0x3ffe0a14  ssh_serv_thread      1/1        1776/3332
0x3ffef1bc      nimble_host    21/21         560/3520
0x3ffb3d44             mdns      1/1         528/3552
0x3ffb5d8c        async_tcp      1/1         480/7696
0x3ffee3c8     btController    23/23         512/3068
0x3ffb7700        esp_timer    22/22         464/3116

==================== THREAD 1 (TCB: 0x3ffd9c08, name: 'wifi') =====================
#0  block_set_prev_free (block=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf_block_functions.h:102
#1  block_mark_as_free (block=0x3ffcef28) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf_block_functions.h:110
#2  block_split (size=168, block=0x3ffcee7c) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf.c:418
#3  block_trim_free (size=168, block=0x3ffcee7c, control=0x3ffcee7c) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf.c:499
#4  block_prepare_used (size=168, block=0x3ffcee7c, control=0x3ffcee7c) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf.c:579
#5  tlsf_malloc (tlsf=0x3ffcee7c, size=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/tlsf/tlsf.c:1006
#6  0x400980ff in multi_heap_malloc_impl (heap=0x3ffcee68, size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/multi_heap.c:207
#7  0x40081d7a in heap_caps_malloc_base (size=168, caps=6144) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/heap_caps.c:176
#8  0x40081dc3 in heap_caps_malloc (caps=6144, size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/heap_caps.c:197
#9  heap_caps_malloc_default (size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/heap/heap_caps.c:223
#10 0x40098f80 in malloc (size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/newlib/heap.c:24
#11 0x40185a87 in mem_malloc (size=168) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/mem.c:209
#12 0x40185b2e in do_memp_malloc_pool (desc=0x3f45bd7c) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/memp.c:254
#13 0x40185b6e in memp_malloc (type=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/memp.c:350
#14 0x40187da8 in tcp_alloc (prio=64 '@') at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/tcp.c:1851
#15 0x401897e1 in tcp_listen_input (pcb=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/tcp_in.c:672
#16 tcp_input (p=0x3ffb3fb0, inp=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/tcp_in.c:391
#17 0x4018f861 in ip4_input (p=0x3ffb3fb0, inp=0x3ffdd6a0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/core/ipv4/ip4.c:752
#18 0x4018ff6d in ethernet_input (p=0x3ffb3fb0, netif=0x3ffdd6a0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/netif/ethernet.c:186
#19 0x40184a14 in tcpip_inpkt (input_fn=<optimized out>, inp=0x3ffdd6a0, p=0x3ffb3fb0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/api/tcpip.c:246
#20 tcpip_input (p=0x3ffb3fb0, inp=0x3ffdd6a0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/api/tcpip.c:287
#21 0x401945e6 in wlanif_input (h=0x3ffdd6a0, buffer=<optimized out>, len=<optimized out>, l2_buff=0x3ffd0cbc) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_netif/lwip/netif/wlanif.c:160
#22 0x401f48e8 in esp_netif_receive (esp_netif=0x3ffdd61c, buffer=0x3ffd0d4e, len=66, eb=0x3ffd0cbc) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_netif/lwip/esp_netif_lwip.c:1258
#23 0x4019614c in wifi_sta_receive (buffer=0x3ffd0d4e, len=66, eb=0x3ffd0cbc) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_wifi/src/wifi_netif.c:39
#24 0x401faf70 in sta_input ()
#25 0x401fb028 in sta_rx_cb ()
#26 0x401fcfe0 in ppRxPkt ()
#27 0x401f865b in ppTask ()
#28 0x40095391 in vPortTaskWrapper (pxCode=0x401f856c <ppTask>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 2 (TCB: 0x3ffb7cc4, name: 'IDLE') =====================
#0  esp_vApplicationIdleHook () at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/freertos_hooks.c:47
#1  0x40200c56 in prvIdleTask (pvParameters=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/tasks.c:4439
#2  0x40095391 in vPortTaskWrapper (pxCode=0x40200bd8 <prvIdleTask>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 3 (TCB: 0x3ffe8538, name: 'common_blocking_thread') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200ddd in vTaskDelay (xTicksToDelay=5) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x400e11f6 in utils_delay (ms=<optimized out>) at D:/my_projects/ESP32/test/main/common/utils.cpp:247
#3  0x400df0a6 in common_blocking_thread (parameter=<optimized out>) at D:/my_projects/ESP32/test/main/common/common.cpp:478
#4  0x40095391 in vPortTaskWrapper (pxCode=0x400dee10 <common_blocking_thread(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 4 (TCB: 0x3ffbd3cc, name: 'log_thread') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200ddd in vTaskDelay (xTicksToDelay=5) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x400e11f6 in utils_delay (ms=<optimized out>) at D:/my_projects/ESP32/test/main/common/utils.cpp:247
#3  0x400f22fc in log_thread (pvParameters=<optimized out>) at D:/my_projects/ESP32/test/main/log/log_app.cpp:551
#4  0x40095391 in vPortTaskWrapper (pxCode=0x400f1ea4 <log_thread(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 5 (TCB: 0x3ffd3ddc, name: 'common_no_blocking_thread') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200ddd in vTaskDelay (xTicksToDelay=5) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x400e11f6 in utils_delay (ms=<optimized out>) at D:/my_projects/ESP32/test/main/common/utils.cpp:247
#3  0x400df9da in common_no_blocking_thread (parameter=<optimized out>) at D:/my_projects/ESP32/test/main/common/common.cpp:447
#4  0x40095391 in vPortTaskWrapper (pxCode=0x400df8b8 <common_no_blocking_thread(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 6 (TCB: 0x3ffd4db4, name: 'charger_thread') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200ddd in vTaskDelay (xTicksToDelay=10) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x400e11f6 in utils_delay (ms=<optimized out>) at D:/my_projects/ESP32/test/main/common/utils.cpp:247
#3  0x400dd97e in charger_thread (parameter=<optimized out>) at D:/my_projects/ESP32/test/main/charger/charger.cpp:4336
#4  0x40095391 in vPortTaskWrapper (pxCode=0x400dc684 <charger_thread(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 7 (TCB: 0x3ffdf994, name: 'mb_tcp_serv_thread') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200ddd in vTaskDelay (xTicksToDelay=10) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x400e11f6 in utils_delay (ms=<optimized out>) at D:/my_projects/ESP32/test/main/common/utils.cpp:247
#3  0x400f56e4 in mb_tcp_serv_thread (parameter=<optimized out>) at D:/my_projects/ESP32/test/main/modbus/mb_tcp_server.cpp:2006
#4  0x40095391 in vPortTaskWrapper (pxCode=0x400f55cc <mb_tcp_serv_thread(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 8 (TCB: 0x3ffb5fc8, name: 'mb_cli_thread') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200ddd in vTaskDelay (xTicksToDelay=50) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x400e11f6 in utils_delay (ms=<optimized out>) at D:/my_projects/ESP32/test/main/common/utils.cpp:247
#3  0x400f3964 in mb_cli_proc () at D:/my_projects/ESP32/test/main/modbus/mb_tcp_client.cpp:967
#4  mb_cli_thread (parameter=<optimized out>) at D:/my_projects/ESP32/test/main/modbus/mb_tcp_client.cpp:1039
#5  0x40095391 in vPortTaskWrapper (pxCode=0x400f3674 <mb_cli_thread(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 9 (TCB: 0x3ffd5e10, name: 'tiT') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200750 in xQueueReceive (xQueue=0x3ffd50dc, pvBuffer=0x3ffd5d40, xTicksToWait=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x40190400 in sys_arch_mbox_fetch (mbox=0x3ffc92e4 <tcpip_mbox>, msg=0x3ffd5d40, timeout=206) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/port/freertos/sys_arch.c:317
#3  0x40184990 in tcpip_timeouts_mbox_fetch (mbox=<optimized out>, msg=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/api/tcpip.c:104
#4  tcpip_thread (arg=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/api/tcpip.c:142
#5  0x40095391 in vPortTaskWrapper (pxCode=0x4018491c <tcpip_thread>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 10 (TCB: 0x3ffdf82c, name: 'wifi_app_thread') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200ddd in vTaskDelay (xTicksToDelay=100) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x400e11f6 in utils_delay (ms=<optimized out>) at D:/my_projects/ESP32/test/main/common/utils.cpp:247
#3  0x40101a9c in wifi_app_thread (parameter=<optimized out>) at D:/my_projects/ESP32/test/main/net/wifi/wifi_app.cpp:1188
#4  0x40095391 in vPortTaskWrapper (pxCode=0x40101454 <wifi_app_thread(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 11 (TCB: 0x3ffd732c, name: 'sys_evt') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200750 in xQueueReceive (xQueue=0x3ffd5f78, pvBuffer=0x3ffd7220, xTicksToWait=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x401fdf80 in esp_event_loop_run (event_loop=0x3ffd4f30, ticks_to_run=4294967295) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_event/esp_event.c:569
#3  0x401fdf9b in esp_event_loop_run_task (args=0x3ffd4f30) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_event/esp_event.c:107
#4  0x40095391 in vPortTaskWrapper (pxCode=0x401fdf8c <esp_event_loop_run_task>, pvParameters=0x3ffd4f30) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 12 (TCB: 0x3ffe0a14, name: 'ssh_serv_thread') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200750 in xQueueReceive (xQueue=0x3ffe8c28, pvBuffer=0x3ffe6538, xTicksToWait=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x401903e4 in sys_arch_mbox_fetch (mbox=0x3ffe89bc, msg=0x3ffe6538, timeout=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/port/freertos/sys_arch.c:313
#3  0x401912ae in netconn_accept (conn=0x3ffe89a8, new_conn=0x3ffe6574) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/api/api_lib.c:510
#4  0x40183191 in lwip_accept (s=<optimized out>, addr=0x0, addrlen=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/lwip/src/api/sockets.c:645
#5  0x40117ea3 in accept (addrlen=0x0, addr=0x0, s=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/lwip/include/lwip/sockets.h:16
#6  ssh_bind_accept (sshbind=0x3ffe6ac0, session=0x3ffe6f50) at D:/my_projects/ESP32/test/libraries/LibSSH-ESP32/src/bind.c:597
#7  0x4010cd98 in ssh_serv_proc () at D:/my_projects/ESP32/test/main/shell/ssh_server.cpp:472
#8  ssh_serv_thread (parameter=<optimized out>) at D:/my_projects/ESP32/test/main/shell/ssh_server.cpp:639
#9  0x40095391 in vPortTaskWrapper (pxCode=0x4010cc9c <ssh_serv_thread(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 13 (TCB: 0x3ffef1bc, name: 'nimble_host') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200750 in xQueueReceive (xQueue=0x3fff00f4, pvBuffer=0x3fff12c4, xTicksToWait=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x4015ad71 in npl_freertos_eventq_get (evq=<optimized out>, tmo=4294967295) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/bt/host/nimble/nimble/porting/npl/freertos/src/npl_os_freertos.c:282
#3  0x40083cac in ble_npl_eventq_get (tmo=<optimized out>, evq=0x3ffcd758 <g_eventq_dflt>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/bt/host/nimble/nimble/porting/npl/freertos/include/nimble/nimble_npl_os.h:167
#4  nimble_port_run () at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/bt/host/nimble/nimble/porting/nimble/src/nimble_port.c:246
#5  0x4012ff69 in NimBLEDevice::host_task (param=0x0) at D:/my_projects/ESP32/test/components/esp-nimble-cpp/src/NimBLEDevice.cpp:865
#6  0x40095391 in vPortTaskWrapper (pxCode=0x4012ff60 <NimBLEDevice::host_task(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 14 (TCB: 0x3ffb3d44, name: 'mdns') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200750 in xQueueReceive (xQueue=0x3ffb2a28, pvBuffer=0x3ffb3c58, xTicksToWait=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x40144730 in _mdns_service_task (pvParameters=<optimized out>) at D:/my_projects/ESP32/test/components/mdns/mdns.c:5210
#3  0x40095391 in vPortTaskWrapper (pxCode=0x40144708 <_mdns_service_task>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 15 (TCB: 0x3ffb5d8c, name: 'async_tcp') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200750 in xQueueReceive (xQueue=0x3ffb5c34, pvBuffer=0x3ffe39ec, xTicksToWait=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x401172e6 in _get_async_event (e=0x3ffe39ec) at D:/my_projects/ESP32/test/libraries/AsyncTCP/src/AsyncTCP.cpp:127
#3  _async_service_task (pvParameters=<optimized out>) at D:/my_projects/ESP32/test/libraries/AsyncTCP/src/AsyncTCP.cpp:203
#4  0x40095391 in vPortTaskWrapper (pxCode=0x401172c8 <_async_service_task(void*)>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 16 (TCB: 0x3ffee3c8, name: 'btController') =====================
#0  0x4008d8d0 in esp_crosscore_int_send_yield (core_id=0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_system/crosscore_int.c:158
#1  0x40200750 in xQueueReceive (xQueue=0x3ffed410, pvBuffer=0x3ffee300, xTicksToWait=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/xtensa/include/xt_utils.h:40
#2  0x4014d075 in queue_recv_hlevel_wrapper (queue=<optimized out>, item=0x3ffee300, block_time_ms=4294967295) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/bt/controller/esp32/bt.c:776
#3  0x4015e5e5 in btdm_controller_task ()
#4  0x40095391 in vPortTaskWrapper (pxCode=0x4015e5cc <btdm_controller_task>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

==================== THREAD 17 (TCB: 0x3ffb7700, name: 'esp_timer') =====================
#0  0x4000bff0 in ?? ()
#1  0x4009542e in vPortClearInterruptMaskFromISR (prev_level=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:568
#2  vPortExitCritical (mux=0x3ffbdbc8 <xKernelLock>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:532
#3  0x40200d28 in ulTaskGenericNotifyTake (uxIndexToWait=<optimized out>, xClearCountOnExit=1, xTicksToWait=4294967295) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/tasks.c:5932
#4  0x400d5b96 in timer_task (arg=<optimized out>) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/esp_timer/src/esp_timer.c:475
#5  0x40095391 in vPortTaskWrapper (pxCode=0x400d5b84 <timer_task>, pvParameters=0x0) at D:/esp32/Espressif/frameworks/esp-idf-v5.1.3/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

======================= ALL MEMORY REGIONS ========================
Name   Address   Size   Attrs
.rtc.text 0x400c0000 0x0 RW
.rtc.dummy 0x3ff80000 0x0 RW
.rtc.force_fast 0x3ff80000 0x0 RW
.rtc_noinit 0x50000000 0x0 RW
.rtc.force_slow 0x50000000 0x0 RW
.rtc_fast_reserved 0x3ff82000 0x0 RW
.iram0.vectors 0x40080000 0x403 R XA
.iram0.text 0x40080404 0x1a87f R XA
.dram0.data 0x3ffbdb60 0x8174 RW A
.ext_ram_noinit 0x3f800000 0x0 RW
.ext_ram.bss 0x3f800000 0x0 RW
.flash.appdesc 0x3f400020 0x100 R  A
.flash.rodata 0x3f400120 0x74624 RW A
.flash.text 0x400d0020 0x1321e3 R XA
.phyiram.0 0x40202204 0x2b R XA
.phyiram.1 0x40202230 0x7d R XA
.phyiram.2 0x402022b0 0x21e R XA
.phyiram.3 0x402024d0 0xb2 R XA
.phyiram.6 0x40202584 0xde R XA
.phyiram.4 0x40202664 0xea R XA
.phyiram.7 0x40202750 0xe4 R XA
.phyiram.8 0x40202834 0x223 R XA
.phyiram.9 0x40202a58 0x183 R XA
.phyiram.10 0x40202bdc 0x8e R XA
.phyiram.13 0x40202c6c 0x188 R XA
.phyiram.15 0x40202df4 0xba R XA
.phyiram.14 0x40202eb0 0xef R XA
.phyiram.16 0x40202fa0 0x1cb R XA
.phyiram.18 0x4020316c 0x72 R XA
.phyiram.12 0x402031e0 0x78 R XA
.phyiram.17 0x40203258 0xee R XA
.phyiram.24 0x40203348 0x4a R XA
.phyiram.25 0x40203394 0x31 R XA
.phyiram.26 0x402033c8 0x103 R XA
.phyiram.27 0x402034cc 0x87 R XA
.phyiram.22 0x40203554 0x61 R XA
.phyiram.20 0x402035b8 0x10e R XA
.phyiram.21 0x402036c8 0x9e R XA
.phyiram.19 0x40203768 0x2df R XA
.iram0.data 0x4009ac84 0x0 RW
.iram0.bss 0x4009ac84 0x0 RW
.dram0.heap_start 0x3ffcee68 0x0 RW
.coredump.tasks.data 0x3ffd9c08 0x164 RW
.coredump.tasks.data 0x3ffd97b0 0x450 RW
.coredump.tasks.data 0x3ffb7cc4 0x164 RW
.coredump.tasks.data 0x3ffbbf70 0x190 RW
.coredump.tasks.data 0x3ffe8538 0x164 RW
.coredump.tasks.data 0x3ffe8350 0x1e0 RW
.coredump.tasks.data 0x3ffbd3cc 0x164 RW
.coredump.tasks.data 0x3ffbd1c0 0x200 RW
.coredump.tasks.data 0x3ffd3ddc 0x164 RW
.coredump.tasks.data 0x3ffd3c00 0x1d0 RW
.coredump.tasks.data 0x3ffd4db4 0x164 RW
.coredump.tasks.data 0x3ffd4ae0 0x2c0 RW
.coredump.tasks.data 0x3ffdf994 0x164 RW
.coredump.tasks.data 0x3ffe5460 0x250 RW
.coredump.tasks.data 0x3ffb5fc8 0x164 RW
.coredump.tasks.data 0x3ffe44a0 0x210 RW
.coredump.tasks.data 0x3ffd5e10 0x164 RW
.coredump.tasks.data 0x3ffd5bf0 0x210 RW
.coredump.tasks.data 0x3ffdf82c 0x164 RW
.coredump.tasks.data 0x3ffe1810 0x290 RW
.coredump.tasks.data 0x3ffd732c 0x164 RW
.coredump.tasks.data 0x3ffd70f0 0x230 RW
.coredump.tasks.data 0x3ffe0a14 0x164 RW
.coredump.tasks.data 0x3ffe63c0 0x6f0 RW
.coredump.tasks.data 0x3ffef1bc 0x164 RW
.coredump.tasks.data 0x3fff11a0 0x230 RW
.coredump.tasks.data 0x3ffb3d44 0x164 RW
.coredump.tasks.data 0x3ffb3b20 0x210 RW
.coredump.tasks.data 0x3ffb5d8c 0x164 RW
.coredump.tasks.data 0x3ffe38c0 0x1e0 RW
.coredump.tasks.data 0x3ffee3c8 0x164 RW
.coredump.tasks.data 0x3ffee1c0 0x200 RW
.coredump.tasks.data 0x3ffb7700 0x164 RW
.coredump.tasks.data 0x3ffba930 0x1d0 RW

===================== ESP32 CORE DUMP END =====================
===============================================================
Exception in thread Thread-1 (_readerthread):
Traceback (most recent call last):
  File "threading.py", line 1038, in _bootstrap_inner
Exception in thread Thread-2 (_readerthread):
Traceback (most recent call last):
  File "threading.py", line 1038, in _bootstrap_inner
  File "threading.py", line 975, in run
  File "threading.py", line 975, in run
  File "subprocess.py", line 1552, in _readerthread
  File "subprocess.py", line 1552, in _readerthread
OSError: [Errno 22] Invalid argument
OSError: [Errno 22] Invalid argument
Done!

More Information.

I have several devices in the fields and they crashed at different times. Most of them in 'wifi' thread, sometimes in 'tiT' thread. I used WI-FI and BLE(Host is NimBLE - BLE only ) communication at the same time. WI-FI power save mode is WIFI_PS_MIN_MODEM. I have also enabled LWIP_TCPIP_CORE_LOCKING and LWIP_TCPIP_CORE_LOCKING_INPUT . In my opinion, after enabling it my device starts working more stable(increases time before crash).

InterfacerCompany commented 6 months ago

Here is my SDK config file:

sdkconfig.txt

filzek commented 6 months ago

We have found that if we do have more than 12 devices in the same network it seens that the wifi crash issue happen more frenquently, with 25 devices it crashes 2 out 25 daily in random hours, sometimes takes 4 hours to come back, sometimes 3 minutes, even without reboot and without any explanation.

Some crashes doesnt recover and it shows the wifi interface connected but there is no tcp/ip or udp reply.

BLE still working perfect in this case but it NIMBLE.

We are using 5.2.1 and could not found what is the root cause of it yet.

Xiehanxin commented 6 months ago

hi @filzek @InterfacerCompany ,so your crash issue will happen both on v5.1.3 and v5.2.1

Xiehanxin commented 6 months ago

and could you describe your application scenario? I think you use the nimble and wifi coexist, and connecting to a TCP server, uploading data at regular intervals?

filzek commented 6 months ago

Hi @Xiehanxin,

We've been working hard to ensure the WiFi driver and the lwIP stack don't cause any issues. We've made some intriguing discoveries, but we're not ready to share details just yet. Tomorrow, we'll conduct an extensive debugging session across 57 devices that have been specially configured via the sdkconfig. This setup aims to stabilize the system and prevent crashes, and we're hopeful it will resolve the issues.

As of now, the latest firmware build, which only includes changes to the SDKCONFIG, has been running smoothly without any problems for the past 48 hours. Although these adjustments might seem a bit unusual or counterintuitive, they appear to be effective. We'll provide a more detailed update once we verify the fixes in tomorrow's session.

Also we have add this boards to the esp-insights, we can share the results if you want to be part of the dashboard, or if you have access it is dashboard-id=18558382-e648-46c0-9a8e-f9243b2f0dd0

We still have problem with the POWER on Nimble, sometimes the power get very very low, like -50 to -80 dBm.

InterfacerCompany commented 6 months ago

Hi @Xiehanxin. I'm not tested on v5.2.1 yet. But previously my project used v5.0.6 - similar situation, it crashed randomly. I'm updated it to v5.1.3 hoping that it will be stable. The logic of my application is next:

  1. MB tcp client. Keep one connection all the time and read some holding registers every second.
  2. MB tcp server. Handle up to 7 connections. But usual it is about 2-3 connections, and 2-3 requests per second.
  3. SSH server that can handle one connection. But it is in listen state. Nobody connect there when system crashes.
  4. Http server. Based on asyncWebServer library and asyncTcp library(used latest from espHome repo). Used for internal web interface. But also nobody open that interface when system is crashed.
  5. mDNS is also activated and advertise one service with 2 records.
  6. BLE activated. Can handle one connection. But most of the time there is no connection and BLE just advertising public data. When system is crashed nobody connected to BLE.

You can see decoded core dump after the system is crashed. I will provide more from different devices.

All the time my devices in WiFi STA mode and connected to router.

Xiehanxin commented 6 months ago

hi @InterfacerCompany @filzek it seems that it run out of the memory, Could you add a task to periodically use _esp_get_minimum_free_heapsize to print the remaining memory

InterfacerCompany commented 6 months ago

Hi @Xiehanxin. I don't think so. My app all the time monitoring the free heap size, and fragmentation. I also have a special logic that will reboot esp32 if the memory becomes too low or fragmentation too big. But I don't see that logic become active and reboot the board. But it is only for critical cases, normally my app is not going out of memory. Here is the memory status during system runtime:

[FREE-HEAP ]-0000076003-C0-I- U8: 82.47 KBytes(min: 77.07 KBytes, max: 104.76 KBytes), U32: 6.30 KBytes, Max block: 62.00 KBytes, Frag: 25%

[FREE-HEAP ]-0000086005-C0-I- U8: 82.45 KBytes(min: 77.07 KBytes, max: 104.76 KBytes), U32: 6.30 KBytes, Max block: 62.00 KBytes, Frag: 25%

[FREE-HEAP ]-0000096008-C0-I- U8: 82.47 KBytes(min: 77.07 KBytes, max: 104.76 KBytes), U32: 6.30 KBytes, Max block: 62.00 KBytes, Frag: 25%

btsimonh commented 5 months ago

I have a similar thing on ESP32 (ESP32-D0WDQ6 v1.0) and esp32s3. The straight esp32cam ('aithinker' style) board is much worse than the s3 board. In my case, it's hosting a webserver, reading video and streaming mjpg to the browser, whilst listening for BLE adverts, and occasionally connecting to one BLE device at a time to gather data). However, the failure can happen randomly at any time. e.g. it just crashed immediately after boot and nimble startup with me accessing a plain text webpage with no video flowing, and probably no adverts received, and no BLE connections in progress.

The symptom is that from the serial all seems normal, but the device can no longer deliver data, and is no longer available to ping on the wifi. Unfortunately, I can't supply detailed debug logs, as I'm not competent at modifying aspects of the compilation. The firmware in use is Tasmota (latest dev uses IDF 5.2.1). I understand that I am pushing it really hard; but I would hope that this would just degrade performance, not result in complete network loss.

If I don't enable Nimble at startup, then the issue does not occur, so it feels like a coexistence issue.

InterfacerCompany commented 5 months ago

Continuing this topic. I've switched to v5.1.4 - the issue is NOT resolved. I've collected more core-dump data from different devices. Interesting that 5 devices connected to the same network were crashed(assert failed) at the same time in the same function 'block_trim_free'.
So, devices 86, 87, 89 -> 'assert failed' in the 'wifi' thread in the 'block_trim_free' function. Device 90 -> 'assert failed' in the 'mdns' thread in the 'block_trim_free' function. Device 91 -> strange core dump file, it does not provide all information. Just this "Panic reason: assert failed: block_trim_free tlsf". So, same function 'block_trim_free'. In the attachment, you can find decoded core dump files for each device. Also here are some statistics data for all devices. There you can see up-time, reboot reason, memory usage, rps for servers. `// 86 --------------------------------- {"ts":87162508,"upTime":"1day,00:09:21","locTime":"2024.06.02 13:38:43","rst":{"cntr":1,"code":4,"descr":"Software reset due to exception/panic","cdf":true,"cpu0":{"code":12, "descr":"Software reset CPU"},"cpu1":{"code":14, "descr":"for APP CPU, reseted by PRO CPU"}},"fs":{"total":"11.81 MBytes", "used":"1.13 MBytes", "free":"10.68 MBytes", "recCntr":0},"perfomance": {"cpu0Load":83, "cpu1Load":0},"mem":{"u8": {"cur": "86.11 KBytes", "min": "79.58 KBytes", "max": "110.72 KBytes", "maxBlock": "72.00 KBytes", "frag":"17%"},"u32": {"cur":"16.04 KBytes"}},"httpServ":{"rps":0,"rpsLatest":1,"rpsMax":3},"mbTcpServ":{"rps":18,"rpsLatest":18,"rpsMax":43},"sysWdtRst": {"cntr":0, "code":0, "descr":"RESET_REASON_NOT_PERF", "date":"2024-05-31", "time":"14:00:34"}}

// 87 --------------------------------- {"ts":87202247,"upTime":"1day,00:09:52","locTime":"2024.06.02 13:39:30","rst":{"cntr":1,"code":4,"descr":"Software reset due to exception/panic","cdf":true,"cpu0":{"code":12, "descr":"Software reset CPU"},"cpu1":{"code":14, "descr":"for APP CPU, reseted by PRO CPU"}},"fs":{"total":"11.80 MBytes", "used":"1.13 MBytes", "free":"10.67 MBytes", "recCntr":0},"perfomance": {"cpu0Load":82, "cpu1Load":0},"mem":{"u8": {"cur": "87.96 KBytes", "min": "76.25 KBytes", "max": "110.98 KBytes", "maxBlock": "76.00 KBytes", "frag":"14%"},"u32": {"cur":"16.04 KBytes"}},"httpServ":{"rps":0,"rpsLatest":1,"rpsMax":9},"mbTcpServ":{"rps":0,"rpsLatest":1,"rpsMax":42},"sysWdtRst": {"cntr":0, "code":0, "descr":"RESET_REASON_NOT_PERF", "date":"2024-05-31", "time":"14:01:39"}}

// 89 --------------------------------- {"ts":87235205,"upTime":"1day,00:10:27","locTime":"2024.06.02 13:39:55","rst":{"cntr":1,"code":4,"descr":"Software reset due to exception/panic","cdf":true,"cpu0":{"code":12, "descr":"Software reset CPU"},"cpu1":{"code":14, "descr":"for APP CPU, reseted by PRO CPU"}},"fs":{"total":"11.81 MBytes", "used":"1.13 MBytes", "free":"10.68 MBytes", "recCntr":0},"perfomance": {"cpu0Load":81, "cpu1Load":0},"mem":{"u8": {"cur": "87.91 KBytes", "min": "80.85 KBytes", "max": "110.33 KBytes", "maxBlock": "76.00 KBytes", "frag":"14%"},"u32": {"cur":"16.04 KBytes"}},"httpServ":{"rps":0,"rpsLatest":1,"rpsMax":3},"mbTcpServ":{"rps":1,"rpsLatest":1,"rpsMax":43},"sysWdtRst": {"cntr":0, "code":0, "descr":"RESET_REASON_NOT_PERF", "date":"2024-05-31", "time":"14:03:56"}}

// 90 --------------------------------- {"ts":87304159,"upTime":"1day,00:11:36","locTime":"2024.06.02 13:41:05","rst":{"cntr":1,"code":4,"descr":"Software reset due to exception/panic","cdf":true,"cpu0":{"code":12, "descr":"Software reset CPU"},"cpu1":{"code":14, "descr":"for APP CPU, reseted by PRO CPU"}},"fs":{"total":"11.81 MBytes", "used":"1.13 MBytes", "free":"10.68 MBytes", "recCntr":0},"perfomance": {"cpu0Load":82, "cpu1Load":0},"mem":{"u8": {"cur": "88.94 KBytes", "min": "74.91 KBytes", "max": "110.54 KBytes", "maxBlock": "76.00 KBytes", "frag":"15%"},"u32": {"cur":"16.04 KBytes"}},"httpServ":{"rps":0,"rpsLatest":1,"rpsMax":3},"mbTcpServ":{"rps":1,"rpsLatest":1,"rpsMax":50},"sysWdtRst": {"cntr":0, "code":0, "descr":"RESET_REASON_NOT_PERF", "date":"2024-05-31", "time":"14:04:34"}}

// 91 --------------------------------- {"ts":87277908,"upTime":"1day,00:11:12","locTime":"2024.06.02 13:40:44","rst":{"cntr":1,"code":4,"descr":"Software reset due to exception/panic","cdf":true,"cpu0":{"code":12, "descr":"Software reset CPU"},"cpu1":{"code":14, "descr":"for APP CPU, reseted by PRO CPU"}},"fs":{"total":"11.80 MBytes", "used":"40.00 KBytes", "free":"11.77 MBytes", "recCntr":0},"perfomance": {"cpu0Load":82, "cpu1Load":0},"mem":{"u8": {"cur": "88.23 KBytes", "min": "79.47 KBytes", "max": "109.73 KBytes", "maxBlock": "72.00 KBytes", "frag":"19%"},"u32": {"cur":"16.04 KBytes"}},"httpServ":{"rps":0,"rpsLatest":1,"rpsMax":3},"mbTcpServ":{"rps":1,"rpsLatest":1,"rpsMax":36},"sysWdtRst": {"cntr":0, "code":0, "descr":"RESET_REASON_NOT_PERF", "date":"2024-05-31", "time":"14:07:18"}}`

Does anybody have an idea how it can be fixed? decoded_86.txt decoded_87.txt decoded_89.txt decoded_90.txt decoded_91.txt

AxelLin commented 5 months ago

@Xiehanxin Any feedback about the log in https://github.com/espressif/esp-idf/issues/13721#issuecomment-2143901081 ?

filzek commented 5 months ago

hi @InterfacerCompany @filzek it seems that it run out of the memory, Could you add a task to periodically use _esp_get_minimum_free_heapsize to print the remaining memory

showMemoryRAMStatus ======================================================= showMemoryRAMStatus The current date/time is: Wed Jun 5 11:16:38 2024 showMemoryRAMStatus There is 15 hardwares ports created showMemoryRAMStatus FreeHeapSize => 2664956 bytes showMemoryRAMStatus Internal Heap Size => 19308 bytes showMemoryRAMStatus =======================================================

the memory is not the problem, as the heap is constant and always have free memory

We use esp32 3.0 wirth psiram enable and alloc all the heap in spiram, so, the internal/default memory is always constant free.

we suspect that BLE driver and Wifi driver sometime runs a concurrence and crash, also we have found some very odd bahvior in the WiFi connection:

1) Using a Deco M5 router in mesh or stand alone with more than 12 devices connected to it the crashes become more frequently. 2) Using a Starlink router the crashes almost doenst happen

So, something related to the WiFi is crashing the boards.

InterfacerCompany commented 4 months ago

Hi guys. I continue facing this problem. I've switched to v5.2.2 - the issue is NOT resolved.

Devices 85,86,87: Crashed task handle: 0x3ffd929c, name: 'wifi', GDB name: 'process 1073582748' Crashed task is not in the interrupt context Panic reason: assert failed: block_trim_free tlsf.c:496 (block_is_free(block) && "block must be free") exccause 0x1d (StoreProhibitedCause)

Device 88: Crashed task handle: 0x3ffb3c28, name: 'mdns', GDB name: 'process 1073429544' Crashed task is not in the interrupt context Panic reason: assert failed: insert_free_block tlsf.c:358 (current && "free list cannot have a null entry") exccause 0x1d (StoreProhibitedCause)

Devices 90,91: Crashed task handle: 0x3ffd8dd4, name: 'wifi', GDB name: 'process 1073581524' Crashed task is not in the interrupt context exccause 0x1c (LoadProhibitedCause)

So, it seems during operation with memory some variables become broken and FW crashes when trying to free a broken pointer : block_trim_free tlsf.c:496 (block_is_free(block) && "block must be free") or some other opperations insert_free_block tlsf.c:358 (current && "free list cannot have a null entry") in case of mdns code.

Here is also decoded core dump files: 85_decoded.txt 86_decoded.txt 87_decoded.txt 88_decoded.txt 90_decoded.txt

Also, it seems that v5.2.2 in the core-dump file, the 'used stack' size for the task is not correct. Examples: v5.2.2 TCB NAME PRIO C/B STACK USED/FREE


0x3ffd929c wifi23/1073582736 1073581360/4760 0x3ffb7c5c IDLE0/1073463552 1073463152/1124 0x3ffb61e4mb_tcp_serv_thread1/1073624992 1073624400/3488 0x3ffbd450 log_thread1/1073468480 1073467968/1524 0x3ffd3b98common_no_blocking_thread1/1073560464 1073560000/2604 0x3ffd5ba8 tiT18/1073568672 1073568144/2540 0x3ffe72b4common_blocking_thread1/1073638368 1073637888/3612 0x3ffd4b70 charger_thread1/1073564512 1073563792/2852 0x3ffb5f84 mb_cli_thread1/1073608656 1073608128/2540 0x3ffdd948 wifi_app_thread1/1073605568 1073604912/2400 0x3ffd70c4 sys_evt20/1073574064 1073573504/3776 0x3ffddda4 ssh_serv_thread1/1073630128 1073628352/3340 0x3ffed3dc nimble_host21/1073664976 1073664416/3528 0x3ffb4ab8 mdns1/1073433264 1073432688/3516 0x3ffb5d48 async_tcp1/1073620896 1073620416/7700 0x3ffb7698 esp_timer22/1073457920 1073457456/3116 0x3ffe7050 btController23/1073655232 1073654720/3064

v5.1.4 TCB NAME PRIO C/B STACK USED/FREE


0x3ffd9228 wifi 23/23 528/5612 0x3ffea560 btController 23/23 512/3060 0x3ffb7698 esp_timer 22/22 464/3116 0x3ffb5d44 async_tcp 1/1 528/7652 0x3ffb5f80 mb_cli_thread 1/1 528/2528 0x3ffd3b24common_no_blocking_thread 1/1 560/2496 0x3ffe66e8common_blocking_thread 1/1 608/3484 0x3ffddaecmb_tcp_serv_thread 1/1 624/3456 0x3ffb7c5c IDLE 0/0 400/1124 0x3ffd4afc charger_thread 1/1 720/2856 0x3ffbd444 log_thread 1/1 512/1520 0x3ffdd8d4 wifi_app_thread 1/1 656/2404 0x3ffd5b34 tiT 18/18 528/2528 0x3ffddd6c ssh_serv_thread 1/1 1776/3340 0x3ffec5f8 nimble_host 21/21 560/3532 0x3ffd7050 sys_evt 20/20 560/3780 0x3ffb3c24 mdns 1/1 528/3552

Can somebody check the decoded core dump files and help me with this problem. Any ideas is welcome ))) Maybe somebody from the esp-idf team is here.

InterfacerCompany commented 4 months ago

Some additional information about my project. I'm trying to keep heap memory as big as possible. Unfortunately, I can't add SPI SRAM to my current HW. So, here are options that are activated to save RAM memory:

  1. FREERTOS_UNICORE - enabled.
  2. ESP32_IRAM_AS_8BIT_ACCESSIBLE_MEMORY - enabled.
  3. BT_NIMBLE_MEM_ALLOC_MODE - BT_NIMBLE_MEM_ALLOC_MODE_IRAM_8BIT
  4. LWIP_TCPIP_CORE_LOCKING - enabled
  5. LWIP_TCPIP_CORE_LOCKING_INPUT - enabled

LWIP_TCPIP_CORE_LOCKING and LWIP_TCPIP_CORE_LOCKING_INPUT are not reducing the heap memory but seems if those activated systems become more stable. Also, I'm using IRAM_8BIT memory for my data buffers. Here is the amount of RAM memory during my system runtime:

"mem":{"u8": {"cur": "87.68 KBytes", "min": "67.14 KBytes", "max": "111.09 KBytes", "maxBlock": "72.00 KBytes", "frag":"18%"},"u32": {"cur":"14.03 KBytes"}} where: u8 - internal heap memory u32 - IRAM_8BIT memory

Does somebody see problems with such configuration?