espressif / esp-idf

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

ESP_ERR_MESH_NO_MEMORY (IDFGH-12414) #13438

Open Leadrive opened 3 months ago

Leadrive commented 3 months ago

Answers checklist.

IDF version.

v4.4.6

Espressif SoC revision.

ESP32-S3

Operating System used.

Linux

How did you build your project?

Command line with idf.py

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

None

Development Kit.

ESP32-S3

Power Supply used.

USB

What is the expected behavior?

不出现ESP_ERR_MESH_NO_MEMORY

What is the actual behavior?

之前也有人反馈此问题,但没有人解决。https://github.com/espressif/esp-mdf/issues/315 症状是这样的,esp_mesh_send,如果返回ESP_ERR_MESH_TIMEOUT,大约持续10几次,就会开始不断出现ESP_ERR_MESH_NO_MEMORY,然后就一直无法正常运行了,此时堆内存这些都是有的,推测就是mesh库没把发送失败的清除,导致积压。 从应用角度来看,此时并没有收到MESH_EVENT_CHILD_DISCONNECTED, MESH_EVENT_PARENT_DISCONNECTED之类的断开消息,肯定会认为mesh是正常的,还是会不断发送。 root端的日志,看起来很正常,没报任何异常

node端的日志

I (537592) [app_main, 43]: Receive binary data, cmd:1, num:235, size:1200
I (537598) [handle_mesh_update, 123]: Flash write success, dataLen:1200, num:235, UpdateTotalNum:1611
I (542126) [mesh_netif, 225]: Sending to root, dest addr: ff:ff:ff:ff:ff:ff, size: 42
E (542126) [mesh_netif, 226]: Send with err code 16394 ESP_ERR_MESH_TIMEOUT
E (542514) [handle_read_data, 75]: HandleReadData, msgId:643, cmdId:29 already timeout:1 s
I (542539) [mesh_node, 150]: NodeWriteExec, now:1711008757, data: xxxx                                                                                                                                                                                               
I (543113) [app_main, 43]: Receive binary data, cmd:1, num:236, size:1200
I (543119) [handle_mesh_update, 123]: Flash write success, dataLen:1200, num:236, UpdateTotalNum:1611
E (546100) [handle_read_data, 75]: HandleReadData, msgId:645, cmdId:29 already timeout:1 s
W (547492) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:9, 1800 ms timeout, seqno:0, xseqno:433, no_wnd_count:0, timeout_count:0
E (548684) [handle_read_data, 75]: HandleReadData, msgId:646, cmdId:29 already timeout:1 s
E (548696) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:647, cmdId:101, endTime:1711008762, now:1711008763
E (548700) [handle_message, 139]: HandleCommonContent, split error, content=, num=1
I (559026) [mesh_node, 150]: NodeWriteExec, now:1711008773, data: xxxx                                                                                                                                                                                                          
I (559934) [app_main, 43]: Receive binary data, cmd:1, num:237, size:1200
I (559939) [handle_mesh_update, 123]: Flash write success, dataLen:1200, num:237, UpdateTotalNum:1611
I (559979) [mesh_node, 150]: NodeWriteExec, now:1711008774, data: xxxxx                                                                                                                                                                                                                        
I (561183) [app_main, 43]: Receive binary data, cmd:1, num:238, size:1200
I (561188) [handle_mesh_update, 123]: Flash write success, dataLen:1200, num:238, UpdateTotalNum:1611
I (561191) [mesh_node, 150]: NodeWriteExec, now:1711008775, data: xxxxx 
W (566768) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (566768) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:656, cmdId:101
W (571874) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (571874) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:657, cmdId:29
W (576980) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (576980) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:658, cmdId:29
E (577085) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:659, cmdId:29, endTime:1711008789, now:1711008791
E (577088) [handle_message, 286]: code=0
E (577091) [func, 40]: Offline...now:1711008791, from:HandleDeviceHeartbeatContent
W (582087) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (582087) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:660, cmdId:29
E (582192) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:661, cmdId:29, endTime:1711008795, now:1711008796
E (582194) [handle_message, 286]: code=0
E (582198) [func, 40]: Offline...now:1711008796, from:HandleDeviceHeartbeatContent
W (587194) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (587194) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:662, cmdId:29
W (592300) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (592300) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:663, cmdId:29
E (592405) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:664, cmdId:29, endTime:1711008804, now:1711008807
E (592408) [handle_message, 286]: code=0
E (592411) [func, 40]: Offline...now:1711008807, from:HandleDeviceHeartbeatContent
W (597408) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (597409) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:665, cmdId:29
E (597514) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:666, cmdId:29, endTime:1711008810, now:1711008812
E (597517) [handle_message, 286]: code=0
E (597520) [func, 40]: Offline...now:1711008812, from:HandleDeviceHeartbeatContent
I (602516) [mesh_netif, 225]: Sending to root, dest addr: ff:ff:ff:ff:ff:ff, size: 42
E (602516) [mesh_netif, 226]: Send with err code 16394 ESP_ERR_MESH_TIMEOUT
W (607522) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (607522) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:667, cmdId:29
E (607627) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:668, cmdId:29, endTime:1711008816, now:1711008822
E (607629) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:669, cmdId:29, endTime:1711008819, now:1711008822
E (607642) [handle_message, 286]: code=0
E (607645) [func, 40]: Offline...now:1711008822, from:HandleDeviceHeartbeatContent
E (607654) [handle_message, 286]: code=0
E (607658) [func, 40]: Offline...now:1711008822, from:HandleDeviceHeartbeatContent
W (612642) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (612642) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:670, cmdId:29
E (612747) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:671, cmdId:29, endTime:1711008825, now:1711008827
E (612749) [handle_message, 286]: code=0
E (612753) [func, 40]: Offline...now:1711008827, from:HandleDeviceHeartbeatContent
W (617749) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (617749) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:672, cmdId:29
E (617854) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:673, cmdId:29, endTime:1711008831, now:1711008832
E (617857) [handle_message, 286]: code=0
E (617860) [func, 40]: Offline...now:1711008832, from:HandleDeviceHeartbeatContent
W (622857) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (622857) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:674, cmdId:29
W (627963) [mesh_internal, 34]: MeshSendData, err=<ESP_ERR_MESH_TIMEOUT>
E (627963) [mesh_node, 162]: <ESP_ERR_MESH_TIMEOUT> nodeWriteTask, msgId:675, cmdId:29
E (628068) [mesh_node, 127]: NodeWriteExec, timeout, send fail message, msgId:676, cmdId:29, endTime:1711008840, now:1711008843
W (628071) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021023
E (628080) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:677, cmdId:29
E (628089) [handle_message, 286]: code=0
E (628094) [func, 40]: Offline...now:1711008843, from:HandleDeviceHeartbeatContent
I (628133) mesh: 5117<assoc>parent layer:1, channel:1, rssi:-31, assoc:1, rssi threshold<-78,-82,-85>
W (628190) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (628190) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:678, cmdId:29
W (629500) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (629500) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:679, cmdId:29
W (632489) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (632489) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:680, cmdId:29
W (635479) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (635479) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:681, cmdId:29
W (638949) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (638950) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:682, cmdId:29
W (641940) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (641940) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:683, cmdId:29
W (644930) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (644930) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:684, cmdId:29
W (647920) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (647920) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:685, cmdId:29
W (651030) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (651030) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:686, cmdId:29
W (654020) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (654020) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:687, cmdId:29
W (657011) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (657012) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:688, cmdId:29
W (660121) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (660121) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:689, cmdId:29
I (661440) [mesh_netif, 225]: Sending to root, dest addr: ff:ff:ff:ff:ff:ff, size: 42
E (661441) [mesh_netif, 226]: Send with err code 16391 ESP_ERR_MESH_NO_MEMORY
W (663111) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (663111) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:690, cmdId:29
W (666101) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (666101) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:691, cmdId:29
W (669091) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (669091) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:692, cmdId:29
W (672202) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (672203) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:693, cmdId:29
W (675192) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (675192) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:694, cmdId:29
W (678182) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (678182) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:695, cmdId:29
W (681172) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (681172) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:696, cmdId:29
W (684178) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (684179) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:697, cmdId:29
W (687288) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=58919, 外部堆=2017095
E (687289) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:698, cmdId:29
W (690278) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=61315, 外部堆=2019491
E (690279) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:699, cmdId:29
W (693274) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=59203, 外部堆=2017379
E (693275) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:700, cmdId:29
W (696277) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=64551, 外部堆=2022727
E (696278) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:701, cmdId:29
W (699279) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=65271, 外部堆=2023447
E (699280) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:702, cmdId:29
W (702389) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (702390) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:703, cmdId:29
W (705380) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (705380) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:704, cmdId:29
W (708370) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (708370) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:705, cmdId:29
W (711373) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (711374) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:706, cmdId:29
W (714003) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (714004) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:707, cmdId:29
W (716993) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (716993) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:708, cmdId:29
W (719989) [mesh_internal, 32]: MeshSendData, err=<ESP_ERR_MESH_NO_MEMORY>, 内部堆=63463, 外部堆=2021639
E (719989) [mesh_node, 162]: <ESP_ERR_MESH_NO_MEMORY> nodeWriteTask, msgId:709, cmdId:29
I (721440) [mesh_netif, 225]: Sending to root, dest addr: ff:ff:ff:ff:ff:ff, size: 42

Steps to reproduce.

故障重现,可能人为在root节点连接的路由器上,制造网络连接不顺,或时断时续,可能容易复现此错误。

Debug Logs.

No response

More Information.

No response

Leadrive commented 3 months ago

建议你们买一个这路由器TY-6201A试下,中国电信送的,闲鱼几十元 一个,这路由器跟esp32相克 b

Leadrive commented 3 months ago

esp_wifi_set_ps设置为省电模式,比较容易复现此问题,省电时,经常超时。

mhdong commented 3 months ago

Hi @Leadrive 同款路由器已购买,后面我们会尝试本地复现问题并解决。

AxelLin commented 1 month ago

Hi @Leadrive 同款路由器已购买,后面我们会尝试本地复现问题并解决。

@mhdong Any update?

zhangyanjiaoesp commented 1 month ago

@Leadrive Can you provide a demo to test?

MosamXu commented 3 weeks ago

ESP32-S3 V5.2.2 也有同样的问题

zhangyanjiaoesp commented 3 weeks ago

@MosamXu Can you provide a demo to test?