[ESP32S3] v4.4 WIFI losing connectivity temporarily or permanently without apparent reason (IDFGH-12977)

Answers checklist.

[X] I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
[X] I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
[X] I have searched the issue tracker for a similar issue and not found a similar issue.

General issue report
@zhangyanjiaoesp
based on 27ec26d2d3f44bbde5da14c7fdfc82226d567874
To reproduce

Add ping functionality and periodc wifi dumps to main task instead of letting it die:

    esp_ping_config_t ping_config = ESP_PING_DEFAULT_CONFIG();
    IP4_ADDR(&ping_config.target_addr, 8,8,8,8);          // target IP address
    ping_config.count = ESP_PING_COUNT_INFINITE;    // ping in infinite mode, esp_ping_stop can stop it
    ping_config.timeout_ms = 3000;

    /* set callback functions */
    esp_ping_callbacks_t cbs;
    cbs.on_ping_success = test_on_ping_success;
    cbs.on_ping_timeout = test_on_ping_timeout;
    cbs.on_ping_end = test_on_ping_end;
    cbs.cb_args = "foo";  // arguments that will feed to all callback functions, can be NULL

    esp_ping_handle_t ping;
    esp_ping_new_session(&ping_config, &cbs, &ping);
    esp_ping_start(ping);

#define DUMP_INTERVAL_MS (1000*60*2)
    int64_t last_dump = 0;
    while (true) {
        if((os_time_get_timestamp() - last_dump) >= DUMP_INTERVAL_MS) {
            last_dump = os_time_get_timestamp();
            esp_wifi_statis_dump(0xFFFF);
        }
        os_thread_sleep(1000);
    }

static void test_on_ping_success(esp_ping_handle_t hdl, void *args)
{
    // optionally, get callback arguments
    // const char* str = (const char*) args;
    // printf("%s\r\n", str); // "foo"
    uint8_t ttl;
    uint16_t seqno;
    uint32_t elapsed_time, recv_len;
    ip_addr_t target_addr;
    esp_ping_get_profile(hdl, ESP_PING_PROF_SEQNO, &seqno, sizeof(seqno));
    esp_ping_get_profile(hdl, ESP_PING_PROF_TTL, &ttl, sizeof(ttl));
    esp_ping_get_profile(hdl, ESP_PING_PROF_IPADDR, &target_addr, sizeof(target_addr));
    esp_ping_get_profile(hdl, ESP_PING_PROF_SIZE, &recv_len, sizeof(recv_len));
    esp_ping_get_profile(hdl, ESP_PING_PROF_TIMEGAP, &elapsed_time, sizeof(elapsed_time));
    ESP_LOGW(TAG, "%d bytes from %s icmp_seq=%d ttl=%d time=%d ms",
           recv_len, ipaddr_ntoa(&target_addr), seqno, ttl, elapsed_time);
}

static void test_on_ping_timeout(esp_ping_handle_t hdl, void *args)
{
    uint16_t seqno;
    ip_addr_t target_addr;
    esp_ping_get_profile(hdl, ESP_PING_PROF_SEQNO, &seqno, sizeof(seqno));
    esp_ping_get_profile(hdl, ESP_PING_PROF_IPADDR, &target_addr, sizeof(target_addr));
    ESP_LOGW(TAG, "From %s icmp_seq=%d timeout", ipaddr_ntoa(&target_addr), seqno);
}

static void test_on_ping_end(esp_ping_handle_t hdl, void *args)
{
    uint32_t transmitted;
    uint32_t received;
    uint32_t total_time_ms;

    esp_ping_get_profile(hdl, ESP_PING_PROF_REQUEST, &transmitted, sizeof(transmitted));
    esp_ping_get_profile(hdl, ESP_PING_PROF_REPLY, &received, sizeof(received));
    esp_ping_get_profile(hdl, ESP_PING_PROF_DURATION, &total_time_ms, sizeof(total_time_ms));
    ESP_LOGW(TAG, "%d packets transmitted, %d received, time %dms", transmitted, received, total_time_ms);
}

Connect to mobile hostspot wifi

Put phone simcard to 2G.

Wait

The issue happens in the ROOT. Once the root is affected, the issue is propagated to all children.

The issue is either temporary or permanent. When permanent, the only way to recover is to reboot.

espressif_wifi_dump_3.txt
espressif_wifi_dump.txt
espressif_wifi_dump_2.txt
Other related issues with similar behavior:
https://github.com/espressif/esp-idf/issues/8953
https://github.com/espressif/esp-idf/issues/10506

@Espressif-liuuuu @zhangyanjiaoesp @nishanth-radja  Do you have any finding in above log?

@KonssnoK Are you using the ip_internal_network example? In your logs, it show the ping timeout, but it can't confirm the wifi connection is down. Can you capture packets for this ?

@KonssnoK Are you using the ip_internal_network example? In your logs, it show the ping timeout, but it can't confirm the wifi connection is down. Can you capture packets for this ?

@zhangyanjiaoesp yes the base is the ip_internal_network example.
how would you check if the wifi connection is down? apart from seeing no packets are sent/receive.
Also, how would you get the packets ? Wireshark connected to a sniffer?

So @zhangyanjiaoesp   i was able to generate one strange behavior, even if it's not exacly the one reported in this issue.
With the same code  (v4.4 top of c0e0af03d153d2c157d1d420831ab33d48888768 )
you can apply patches 1 2 3, which enable monitoring and pinging
03_ip_internal.patch
02_if_dumps.patch
01_packets_dump.patch
by randomly detaching/attaching the layer 2 device i was able to reach this state, where the L2 device is never able to communicate with L1
timeout_l2.txt
I got an extract of L1 too (i would say MESH_EVENT_CHILD_CONNECTED )
ESP-IDF_test.txt

interestingly enough to recover the L2 device i had to reboot both devices

@zhangyanjiaoesp
again by simply resetting the 2 devices in different ways, i was able to trigger another case in which one device does not work anymore until reboot.
to be noted: once this device is failing, rebooting the other device makes it fail too.
timeout_reset1.txt
timeout_reset2.txt

@KonssnoK please provide your sdkconfig file, and you are using PSRAM, right?

sdkconfig.txt
@zhangyanjiaoesp here it is

@zhangyanjiaoesp i reproduced with a Google Pixel8.
not getting the IP - strange, would mean the IP service is stuck 🤔

@zhangyanjiaoesp i moved to 3 devices and trying to replicate but for now without success..

and as soon as i wrote that, something strange happened again:
dev3 is not able to connect
dev2.txt
disconnected_dev3.txt
dev1.txt

one hour in:
W (6444006) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:5334

W (13189216) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:10955

this is instead the log of device1 getting stuck and not trying to connect to the mesh anymore
dev1_stuck.txt

and as soon as i wrote that, something strange happened again: dev3 is not able to connect
dev2.txt
disconnected_dev3.txt
dev1.txt
I (42466) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<1,1>, prof:1
W (43196) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:0
W (44396) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:1
W (45596) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:2
W (46796) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:3
W (47996) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:4
W (49196) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:5

(devices are 30cm apart fom each other)
it seems it goes on forever W (1983596) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:1617

@KonssnoK In the log, I see that initially communication among the three devices was normal, and then you restarted device2 and device3？
And in the logs of device2 and device3, there are logs showing I (42466) wifi:state: run -> init (2c0), this means the wifi connection is disconnected. The wifi disconnection will cause the W (6444006) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:5334. But I can't find why the wifi disconnect.  Can you use wireshark to capture packets of the device1/2/3, and send the logs and captures to me? In the log, please display the absolute time.
And I have using the Google Pixel5 mobile to test, but I didn't reproduce the problem.

and as soon as i wrote that, something strange happened again: dev3 is not able to connect
dev2.txt
disconnected_dev3.txt
dev1.txt
I (42466) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<1,1>, prof:1
W (43196) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:0
W (44396) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:1
W (45596) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:2
W (46796) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:3
W (47996) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:4
W (49196) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:5

(devices are 30cm apart fom each other)
it seems it goes on forever W (1983596) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:1617

@KonssnoK In the log, I see that initially communication among the three devices was normal, and then you restarted device2 and device3？ And in the logs of device2 and device3, there are logs showing I (42466) wifi:state: run -> init (2c0), this means the wifi connection is disconnected. The wifi disconnection will cause the W (6444006) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:5334. But I can't find why the wifi disconnect. Can you use wireshark to capture packets of the device1/2/3, and send the logs and captures to me? In the log, please display the absolute time.
And I have using the Google Pixel5 mobile to test, but I didn't reproduce the problem.

@zhangyanjiaoesp
today i have no way to use wireshark.
the only way to recover that device was to reboot it again.
Yes, to trigger the issue i simply randomly restarted devices.
i'm not sure on how to display absolute time considering the logs are in close sourced files.
I understand the wifi is disconnected, but i would expect it to retry a connection once disconnected 🤔

Yes, to trigger the issue i simply randomly restarted devices

Ok, I will try to restart the device and test again.

@zhangyanjiaoesp in my experience slow data rates help achieving the issues.
Please put your phone cell technology to 2G or go to "developer options" networking "network download rate limit" and put the minimum.

240619dev3.txt
240619dev1.txt
240619dev2.txt
@zhangyanjiaoesp i rebooed the root device and it went offline.
After a while device 3 managed to change status and directly connect as the root.
the other 2 remain disconnected
240619dev3_2.txt
240619dev1_2.txt
240619dev2_2.txt

@zhangyanjiaoesp i tried also today to replicate, to verify if this is consistent:

phone on rate limiter 128kbps
keep devices off until dev1 root
dev 2 3 as children
reboot dev 1
dev 1 blocked , dev 2 3 blocked

it's quite easy to create issues in this configuration, please let me know if you manage.
240620dev3.txt
240620dev1.txt
240620dev2.txt

@KonssnoK I'm sorry, I have an urgent task recently. I will test your issue next week.

@zhangyanjiaoesp sure, i'll concentrate on another issue meanwhile

and as soon as i wrote that, something strange happened again: dev3 is not able to connect
dev2.txt disconnected_dev3.txt dev1.txt
I (42466) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<1,1>, prof:1
W (43196) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:0
W (44396) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:1
W (45596) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:2
W (46796) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:3
W (47996) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:4
W (49196) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:5

(devices are 30cm apart fom each other)
it seems it goes on forever W (1983596) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:1617

@KonssnoK I have reproduced this issue by rebooting the root device, and I have found the root cause, the following wifi libs can solve the problem. Please replace the wifi libs and test again.
wifi_lib_s3_0625.zip (wifi firmware version: f736b07)
For the other issues, I still can't reproduce them although I randomly reboot the device2/3.

@KonssnoK I have reproduced this issue by rebooting the root device, and I have found the root cause

What's the root cause?

and as soon as i wrote that, something strange happened again: dev3 is not able to connect
dev2.txt disconnected_dev3.txt dev1.txt
I (42466) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<1,1>, prof:1
W (43196) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:0
W (44396) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:1
W (45596) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:2
W (46796) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:3
W (47996) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:4
W (49196) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:5

(devices are 30cm apart fom each other)
it seems it goes on forever W (1983596) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:43, timeout_count:1617

@KonssnoK I have reproduced this issue by rebooting the root device, and I have found the root cause, the following wifi libs can solve the problem. Please replace the wifi libs and test again. wifi_lib_s3_0625.zip (wifi firmware version: f736b07)
For the other issues, I still can't reproduce them although I randomly reboot the device2/3.

@zhangyanjiaoesp sure I will try them.
Should this unblock devices from avoid reconnection?
Because we are currently seeing this kind of issues a bit everywhere on the field.
Thanks

@zhangyanjiaoesp i changed the library but i see no difference in the behavior of the children 🤔
240625dev1_1.txt
240625dev3_1.txt
240625dev2_1.txt

@zhangyanjiaoesp i changed the library but i see no difference in the behavior of the children 🤔 240625dev1_1.txt 240625dev3_1.txt 240625dev2_1.txt
EDIT: i think this might have been related to the fact that the 4th device, which was acting as root, was not updated yet with latest libraries. I will now retry in the nominal configuration

It's wired. Here is device2 log on my side when the root rebooting.
device2.txt

So @zhangyanjiaoesp i was able to generate one strange behavior, even if it's not exacly the one reported in this issue.
With the same code (v4.4 top of c0e0af0 )
you can apply patches 1 2 3, which enable monitoring and pinging
03_ip_internal.patch 02_if_dumps.patch 01_packets_dump.patch

@KonssnoK My test is based on the ip_internal_network example and added the above patch. And I noticed this print W (106224) mesh_hand: Triggering DYNAMIC MESH handover in your logs. You used a different test code, right?

So @zhangyanjiaoesp i was able to generate one strange behavior, even if it's not exacly the one reported in this issue.
With the same code (v4.4 top of c0e0af0 )
you can apply patches 1 2 3, which enable monitoring and pinging
03_ip_internal.patch 02_if_dumps.patch 01_packets_dump.patch

@KonssnoK My test is based on the ip_internal_network example and added the above patch. And I noticed this print W (106224) mesh_hand: Triggering DYNAMIC MESH handover in your logs. You used a different test code, right?

yes sorry it's an evolution of your code.
I will put back the old one and reproduce again

dev1 is now blocked in a
I (135890) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:2 loop
240625dev2_3.txt
240625dev1_3.txt
240625dev3_3.txt

with the same procedure another issue appeared:

generation of 2 networks that do not merge back together
dev1 and dev3 are both ROOT and do not try to merge together

240625dev1_5.txt
240625dev2_5.txt
240625dev3_5.txt

another case of dev1 getting stuck after reset.
the reset was hold for some seconds before releasing (i don't always just press/release)
240625dev2_6.txt
240625dev1_6.txt
240625dev3_6.txt

@zhangyanjiaoesp
last example of this issue:
240625dev3_7.txt
240625dev1_7.txt
240625dev2_7.txt
now i'll go back to the other one while you fix this

dev1 is now blocked in a I (135890) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:2 loop
240625dev2_3.txt 240625dev1_3.txt 240625dev3_3.txt

When the root device is connecting to the router, and the disconnect reason is 2 (auth expire), then the root will continue to reconnect to the router. So you see the I (135890) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:2 log loop. User should handle this case in the application layer.
By the way, I (50960) wifi:state: auth -> init (200) this log indicates the device sends auth request, but the router doesn't reply auth response. It's strange why the router doesn't reply auth response. Could it have something to do with the hotspot used? Do you have this problem if you use another hotspot or router？

dev1 is now blocked in a I (135890) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:2 loop
240625dev2_3.txt 240625dev1_3.txt 240625dev3_3.txt

When the root device is connecting to the router, and the disconnect reason is 2 (auth expire), then the root will continue to reconnect to the router. So you see the I (135890) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:2 log loop. User should handle this case in the application layer. By the way, I (50960) wifi:state: auth -> init (200) this log indicates the device sends auth request, but the router doesn't reply auth response. It's strange why the router doesn't reply auth response. Could it have something to do with the hotspot used? Do you have this problem if you use another hotspot or router？

how should the user handle this error?
and why is it reported continuously alternated to the error 205?

with the same procedure another issue appeared:

generation of 2 networks that do not merge back together
dev1 and dev3 are both ROOT and do not try to merge together

240625dev1_5.txt 240625dev2_5.txt 240625dev3_5.txt

By default, it allows more than one root existing in one mesh network. Please call esp_mesh_allow_root_conflicts(false) to disable it.

how should the user handle this error?

For example, if the auth fails because the router moved its position, user can call esp_mesh_waive_root() to change a better root.

and why is it reported continuously alternated to the error 205?

When connects fail,  sta will add this AP to a blacklist, and reason code 205 indicates scan fail due to the AP is in blacklist, after this the AP will be removed from the blacklist. So you will see the reason code is 2/205 loop.

with the same procedure another issue appeared:

generation of 2 networks that do not merge back together
dev1 and dev3 are both ROOT and do not try to merge together

240625dev1_5.txt 240625dev2_5.txt 240625dev3_5.txt

By default, it allows more than one root existing in one mesh network. Please call esp_mesh_allow_root_conflicts(false) to disable it.

@zhangyanjiaoesp should this be called on all devices or only on root? when should it be called ? before mesh_start?

with the same procedure another issue appeared:

generation of 2 networks that do not merge back together
dev1 and dev3 are both ROOT and do not try to merge together

240625dev1_5.txt 240625dev2_5.txt 240625dev3_5.txt

By default, it allows more than one root existing in one mesh network. Please call esp_mesh_allow_root_conflicts(false) to disable it.

@zhangyanjiaoesp should this be called on all devices or only on root? when should it be called ? before mesh_start?

Call it before mesh start on all devices.

Is it the STA blacklisting the AP or or the AP blacklisting the STA?

The STA add the AP to STA's blacklist.

something like this for the waiving?
    case MESH_EVENT_PARENT_DISCONNECTED: {
        mesh_event_disconnected_t *disconnected = (mesh_event_disconnected_t *)event_data;
        ESP_LOGI(MESH_TAG,
                 "<MESH_EVENT_PARENT_DISCONNECTED>reason:%d",
                 disconnected->reason);
        mesh_layer = esp_mesh_get_layer();
        mesh_netifs_stop();

        if (esp_mesh_is_root() && disconnected->reason == WIFI_REASON_CONNECTION_FAIL){
            esp_mesh_waive_root();
        }
    }

yes

@zhangyanjiaoesp calling esp_mesh_waive_root always returns error
ESP_ERR_MESH_DISCARD
and the device remains stuck.
Patch for latest code
04_waive_root.patch

@KonssnoK
ESP_ERR_MESH_DISCARD this error indicates that the softAP doesn't have children. In your auth failure scenario, I think we should first confirm why the hotspot does not reply auth response. Have you tested on another hotspot or router?

@KonssnoK
ESP_ERR_MESH_DISCARD this error indicates that the softAP doesn't have children. In your auth failure scenario, I think we should first confirm why the hotspot does not reply auth response. Have you tested on another hotspot or router?

No I updated the code and retried with the changes. I will go back to testing with the Samsung phone.
In any case, it should work any router/phone 🤔,
A different behavior in the AP should be handled in any case correctly by the STA

with samsung phone:

device2 gets stuck

W (435697) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:26, no_wnd_count:0, timeout_count:244
240627dev1_1.txt
240627dev3_1.txt
240627dev2_1.txt

@zhangyanjiaoesp
the failed auth does not happen on the samsung phone but dev2 apparently gets stuck as a child.
240627dev3_2.txt
240627dev1_2.txt
240627dev2_2.txt
but on the Google phone what should be done when the root gets into a 2 205 error loop? Of course it doesn't have children because the rest of the network reshape by itself. What should be done to make it recover and search for other devices?

@KonssnoK
Please use this wifi lib to see whether the 2/205 error loop can be solved, thanks.
wifi_lib_s3_0627.zip (wifi firmware version: ace69bc)

@zhangyanjiaoesp i confirm i'm currently not able to reproduce the 2/205 infinite loop :)
Did you find another error ?
I will continue to try to reproduce

@zhangyanjiaoesp i confirm i'm currently not able to reproduce the 2/205 infinite loop on the pixel phone :) Did you find another error ?

yes, I change the wifi code. For some routers, if the STA is powered off and restarted, the router still records the connection status of the STA, so when the STA is connected again to send the auth request, the router will not reply the auth response. In this case, we first send a deauth packet before the STA sends the auth request, so that the router can clear the previous connection state, and then the STA can send the auth request to the normal connection.

@zhangyanjiaoesp currently the only bug I am able to reproduce is a child device becoming stuck on W (155190) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:0, timeout_count:123
On the root node i cannot trigger much with the new library

dev3 root
dev1 stuck

240627dev2_3.txt 240627dev1_3.txt 240627dev3_3.txt
for reference, it seems that it's not that easy to trigger this error on the child as it was before the 0625 library, so it could be that the library fix of 0625 is not complete

OK, I will follow up to solve this problem.

ok thanks, meanwhile i will continue some testing to see if something else appears.

For now i saw that sometimes a device gets completely stuck (like a deadlock) but I have no idea how to replicate, and from the logs it's impossible to understand why
I will also move to the other ticket because fixed root seemed to trigger the same issue, but it could be once again that  the current fix is not final

apparently i cannot continue on the other issues until this is fixed.
@zhangyanjiaoesp do you have any way to check when this issue was introduced?
I would like to understand if this was always there (and means slow rate is a trigger we didn't check) or if instead it was introduced by a commit, and we could rollback devices in the field

@KonssnoK
I have added some debug log for the stuck issue, please use the new wifi lib to test, thanks.
wifi_lib_s3_debug_0701.zip
wifi firmware version: fbf47d3

@zhangyanjiaoesp dev1 is stuck here without printing anything but
>>>mesh_nwk_task_main,5572, nwk.state = 21
240701dev1_1.txt
240701dev2_1.txt
240701dev3_1.txt

one thing i don't understand is that when i press reset on dev2 or dev3 (with dev1 root), also the other 2 devices stop sending data completely for some time. Is this expected? It seems like the timeout of the device i'm resetting is blocking the parent, which for 3 devices isn't much, but if i think at 6 devices per node, means a huge lag for no reason...

@zhangyanjiaoesp dev1 is stuck here without printing anything but >>>mesh_nwk_task_main,5572, nwk.state = 21
240701dev1_1.txt 240701dev2_1.txt 240701dev3_1.txt
more logs of dev1 once stuck
I (157009) wifi:station: 7c:df:a1:e2:7b:84 leave, AID = 1, bss_flags is 658531, bss:0x3fcb8f24
I (157009) wifi:new:<11,0>, old:<11,2>, ap:<11,2>, sta:<11,2>, prof:11
I (186309) mesh: >>>8415[nwk]pending[0], state:MESH_NWK_TIMER
>>>mesh_nwk_task_main,3768, nwk.state = 21
>>>mesh_nwk_task_main,5572, nwk.state = 21
I (216309) mesh: >>>8415[nwk]pending[0], state:MESH_NWK_TIMER
>>>mesh_nwk_task_main,3768, nwk.state = 21
>>>mesh_nwk_task_main,5572, nwk.state = 21
I (246309) mesh: >>>8415[nwk]pending[0], state:MESH_NWK_TIMER
>>>mesh_nwk_task_main,3768, nwk.state = 21
>>>mesh_nwk_task_main,5572, nwk.state = 21
I (276309) mesh: >>>8415[nwk]pending[0], state:MESH_NWK_TIMER
>>>mesh_nwk_task_main,3768, nwk.state = 21
>>>mesh_nwk_task_main,5572, nwk.state = 21

You didn't reproduce the stuck issue on W (155190) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:0,  but stuck on a new case, right? It seems that the wifi task stop running.

for reference, it seems that it's not that easy to trigger this error on the child as it was before the 0625 library, so it could be that the library fix of 0625 is not complete

Can you confirm that this problem would not occurred without the change in 0625 library?

Since we have more logs in this lib I tried it also with our code that uses both fixed root and dynamic one.
There seem to be serious issues.
240701dev1_3_alt.txt
240701dev2_3_alt.txt
yes,
i did not reproduce the W (155190) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:0 yet, i'll resume it now
no, also before 0625 i had devices getting stuck without printing anything. The way to recover was rebooting them.

@zhangyanjiaoesp here is the infinite loop W (155190) mesh: [mesh_schedule.c,3131] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1, no_wnd_count:0 with library 0701
240701dev1_4.txt
240701dev3_4.txt
240701dev2_4.txt

@KonssnoK Can you capture the wifi packets via the Wireshark?

@KonssnoK
add more debug log in this wifi lib:
wifi_lib_s3_0701_2.zip
wifi firmware version: a93bcab

@zhangyanjiaoesp
extension .pcapng
test1.txt

@zhangyanjiaoesp once again both dev1 and dev2 are stuck
240701dev1_5.txt
240701dev3_5.txt
240701dev2_5.txt
Wireshark file
.pcapng
test2.txt

@KonssnoK
Can you print the tasks information when the stuck issue happen? you can refer the following code.
To include the core ID info, you should enable the FREERTOS_VTASKLIST_INCLUDE_COREID option in menuconfig.

/** 'tasks' command prints the list of tasks and related information */
#if WITH_TASKS_INFO
static int tasks_info(int argc, char *argv)
{
const size_t bytes_per_task = 40; / see vTaskList description */
char *task_list_buffer = malloc(uxTaskGetNumberOfTasks() * bytes_per_task);
if (task_list_buffer == NULL) {
ESP_LOGE(TAG, "failed to allocate buffer for vTaskList output");
return 1;
}
fputs("Task Name\tStatus\tPrio\tHWM\tTask#", stdout);
#ifdef CONFIG_FREERTOS_VTASKLIST_INCLUDE_COREID
fputs("\tAffinity", stdout);
#endif
fputs("\n", stdout);
vTaskList(task_list_buffer);
fputs(task_list_buffer, stdout);
free(task_list_buffer);
return 0;
}
static void register_tasks(void)
{
const esp_console_cmd_t cmd = {
.command = "tasks",
.help = "Get information about running tasks",
.hint = NULL,
.func = &tasks_info,
};
ESP_ERROR_CHECK( esp_console_cmd_register(&cmd) );
}
#endif // WITH_TASKS_INFO

https://github.com/espressif/esp-idf/blob/a9d0f22193acdf47a5a4db36832ae7068818962b/examples/system/console/advanced/components/cmd_system/cmd_system.c#L159

Wireshark file
.pcapng
test2.txt

By the way, the capture is on channel 10, but the mesh network is on channel 1,( (10669) mesh: [DONE]connect to router:KI, channel:1, rssi:-37, d2:0f:7d:8a:8b:29[layer:0, assoc:0],) so there's no valid information in the capture.

i will print it periodically because i have no idea on how to know when the issue occurs.
Yeah, I will redo the capturing on the right channel.

Here are the logs with task status
240702dev1_1.txt
240702dev2_1.txt
240702dev3_1.txt
Currently I can-t use Wireshark

@KonssnoK
please use the new wifi lib to test, and add the patch.
wifi_lib_s3_0702.zip
wifi firmware version: 43cf051
0001-add-debug-log-in-event-loop.zip

dev2 stuck with lib 0702
240702dev3_2.txt
240702dev2_2.txt
240702dev1_2.txt

W (274340) ping: From <IP_ADDRESS> icmp_seq=68 timeout
W (275030) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:253, no_wnd_count:0, timeout_count:0
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (275240) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
W (276230) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:253, no_wnd_count:0, timeout_count:1
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (277430) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:253, no_wnd_count:0, timeout_count:2
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (277680) mesh: 5162<active>parent layer:1(node), channel:4, rssi:-3, assoc:0(cnx rssi threshold:-120)my_assoc:0
W (278630) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:253, no_wnd_count:0, timeout_count:3
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
>>>wifi_event_post,2241
I (279180) wifi:state: run -> init (6c0)
>>>ieee80211_sta_new_state,253
>>>ieee80211_sta_new_state,371
>>>cnx_sta_leave,2006
I (279190) wifi:pm stop, total sleep time: 0 us / 8461895 us

I (279190) wifi:<ba-del>idx
I (279190) wifi:new:<4,0>, old:<4,1>, ap:<4,1>, sta:<4,1>, prof:4
>>>ieee80211_sta_new_state,559, post disconnect evt
>>>wifi_event_post,2241
W (279830) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:253, no_wnd_count:0, timeout_count:4
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)

@KonssnoK please use this new patch to test, thanks.
0002-add-debug-log-in-event-loop.zip

i flashed the 3 devices aand started them, they are currently in a strange state where nobody can connect..
240703dev3_1.txt
240703dev1_1.txt
240703dev2_1.txt
dev2 reports

d,2638, (1, 1, 0)
I (156290) mesh: 1316[recv]invalid child 7c:df:a1:e1:6a:d8
I (156290) mesh: 1316[recv]invalid child 7c:df:a1:e1:6a:d8
I (156580) mesh: 1316[recv]invalid child 7c:df:a1:e1:6a:d8
I (156580) mesh: 1316[recv]invalid child 7c:df:a1:e1:6a:d8
I (156580) mesh: 1813[XON]async, from child 7c:df:a1:e1:6a:d8
W (157070) mesh: [mesh_schedule.c

dev3 is in an infinite loop

>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)

dev1 fails to send any data

E (192294) wifi_netif: TXW
W (192894) ping: From <IP_ADDRESS> icmp_seq=48 timeout
E (193894) ping_sock: send error=0

I try to recover them..

@zhangyanjiaoesp  I'm not sure if the issue triggered with this code, i do have an infinite loop of
W (100970) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:3, no_wnd_count:43, timeout_count:0
but the counter resets, and no device is able to connect ever, limiter or no limiter
240703dev2_2.txt
240703dev3_2.txt
240703dev1_2.txt

i'm trying to remove the patches and go back tot a functional environment, something is off

ok i had to reboot my phone somehow to recover connectivity.
@zhangyanjiaoesp  here are the logs of a stuck device
240703dev3_3.txt

more logs,
dev1 without eventloop patch (i'm recompiling for this device)
dev2 in deadlock
dev3 in infinite  >>>mesh_xon_process_disconnected,2638, (1, 1, 0) loop
240703dev3_4.txt
240703dev2_4.txt
240703dev1_4.txt

i see that the eventloop is not running anymore and therefore not handling events, interesting..

more logs
dev1 stuck on
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
dev2 in deadlock
dev3 ok
240703dev1_6.txt
240703dev3_6.txt
240703dev2_6.txt

ok i had to reboot my phone somehow to recover connectivity.
@zhangyanjiaoesp here are the logs of a stuck device
240703dev3_3.txt

@KonssnoK In this log, it seems that the esp_event_loop_run() didn't return when it handles the id=7 mesh event (MESH_EVENT_PARENT_CONNECTED). Are you using the mesh example or your own code? If it's your own code, please check why the mesh_event_handler() didn't return when handling the MESH_EVENT_PARENT_CONNECTED event.

@zhangyanjiaoesp i'm using the espressif code with the patches i posted above, nothing else

ip_internal_3.patch
ip_internal_2.patch
ip_internal_1.patch
ip_internal_4.patch
here are the changes to the original example

i added a couple of prints following your example,
the system gets block between these lines:
        ESP_LOGI(TAG, ">>>%s,%d\n",__func__,__LINE__);
        netif_sta = create_mesh_link_sta();
        // now we create a mesh driver and attach it to the existing netif
        mesh_netif_driver_t driver = mesh_create_if_driver(false, false);
        if (driver == NULL) {
            ESP_LOGE(TAG, "Failed to create wifi interface handle");
            return ESP_FAIL;
        }
        esp_netif_attach(netif_sta, driver);
        start_mesh_link_sta();
        // If we have a AP on NODE -> stop and remove it!
        if (netif_ap) {
            esp_netif_action_disconnected(netif_ap, NULL, 0, NULL);
            mesh_delete_if_driver(esp_netif_get_io_driver(netif_ap));
            esp_netif_destroy(netif_ap);
            netif_ap = NULL;
        }
        ESP_LOGI(TAG, ">>>%s,%d\n",__func__,__LINE__);

added more logs, the block is coming from
esp_netif_action_connected(netif_sta, NULL, 0, NULL);
240703dev3_8.txt

more digging, adding more logs
dhcp_discover(): dhcp state is DISCOVER
dhcp_discover: making request
dhcp_discover: sendto(DISCOVER, IP_ADDR_BROADCAST, LWIP_IANA_PORT_DHCP_SERVER)
I (230951) esp_netif_lwip: SENDW mesh_link_sta  350 FFFFFFFFFFFF7CDFA1E27B84080045000150011200004011788C00000000FFFFFFFF00440043013C283A010106004F43B9EF00000000000000000000000000000000000000007CDFA1E27B840000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E27B84370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000

the block is actually on
esp_err_t esp_netif_transmit_wrap(esp_netif_t *esp_netif, void *data, size_t len, void *pbuf)
{
    ...
    ESP_LOGI(TAG,"SENDW %10s %4d %s", esp_netif->if_desc, len, buf);
    ...
    return (esp_netif->driver_transmit_wrap)(esp_netif->driver_handle, data, len, pbuf);
}

@zhangyanjiaoesp we are back to the Mesh library as source of blocking

@KonssnoK Does calling the esp_mesh_send_block_time()API solve the problem?

i think the issue might have happened and the timeout recovered the situation
240703dev2_10.txt

I (139081) mesh_mqtt: Other event id:7
I (139091) event: >>>esp_event_loop_run,630

W (139941) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:141, no_wnd_count:0, timeout_count:0
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (140891) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
W (141141) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:141, no_wnd_count:0, timeout_count:1
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (142341) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:141, no_wnd_count:0, timeout_count:2
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (143541) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:141, no_wnd_count:0, timeout_count:3
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (143901) event: >>>esp_event_post_to,848, evt base = WIFI_MESH_EVENT, evt id = 36

I (143911) event: >>>esp_event_post_to,898, send to q

I (143911) event: >>>esp_event_post_to,919

W (144741) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:141, no_wnd_count:0, timeout_count:4
E (144741) mesh_netif: Send with err code 16394 ESP_ERR_MESH_TIMEOUT
I (144741) esp_netif_lwip: SENDW mesh_link_sta   42 FFFFFFFFFFFF7CDFA1E27B84080600010800060400017CDFA1E27B840A0000030000000000000A000001
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (145571) wifi:state: run -> init (6c0)
>>>ieee80211_sta_new_state,253
>>>ieee80211_sta_new_state,371
>>>cnx_sta_leave,2006
I (145571) wifi:pm stop, total sleep time: 0 us / 9075657 us

I (145571) wifi:<ba-del>idx
I (145571) wifi:new:<11,0>, old:<11,2>, ap:<11,2>, sta:<11,2>,prof:11
>>>ieee80211_sta_new_state,559, post disconnect evt
>>>wifi_event_post,2241
I (145591) event: >>>esp_event_post_to,848, evt base = WIFI_EVENT, evt id = 5

I (145591) event: >>>esp_event_post_to,898, send to q

I (145601) event: >>>esp_event_post_to,919

W (145961) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:142, no_wnd_count:0, timeout_count:5
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (147161) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:142, no_wnd_count:0, timeout_count:6
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (147971) mesh: 5162<active>parent layer:1(node), channel:11,rssi:-8, assoc:0(cnx rssi threshold:-120)my_assoc:0
W (148361) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:142, no_wnd_count:0, timeout_count:7
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
>>>wifi_event_post,2241
I (149481) event: >>>esp_event_post_to,848, evt base = WIFI_EVENT, evt id = 1

I (149481) event: >>>esp_event_post_to,898, send to q

I (149481) event: >>>esp_event_post_to,919

W (149561) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:142, no_wnd_count:0, timeout_count:8
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (150761) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:142, no_wnd_count:0, timeout_count:9
E (150761) mesh_netif: Send with err code 16394 ESP_ERR_MESH_TIMEOUT
I (150761) esp_netif_lwip: SENDW mesh_link_sta   42 FFFFFFFFFFFF7CDFA1E27B84080600010800060400017CDFA1E27B840A0000030000000000000A000003
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (151981) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:143, no_wnd_count:0, timeout_count:10
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (153181) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:143, no_wnd_count:0, timeout_count:11
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (153761) ping: From <IP_ADDRESS> icmp_seq=55 timeout
W (154381) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:143, no_wnd_count:0, timeout_count:12
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (155581) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:143, no_wnd_count:0, timeout_count:13
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (156781) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:143, no_wnd_count:0, timeout_count:14
E (156781) mesh_netif: Send with err code 16394 ESP_ERR_MESH_TIMEOUT
I (156781) esp_netif_lwip: SENDW mesh_link_sta   42 FFFFFFFFFFFF7CDFA1E27B84080600010800060400017CDFA1E27B840A0000030000000000000A000001
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (158001) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:144, no_wnd_count:0, timeout_count:15
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (159201) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:144, no_wnd_count:0, timeout_count:16
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (160401) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:144, no_wnd_count:0, timeout_count:17
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (161601) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:144, no_wnd_count:0, timeout_count:18
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (162801) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:144, no_wnd_count:0, timeout_count:19
E (162801) mesh_netif: Send with err code 16394 ESP_ERR_MESH_TIMEOUT
I (162801) event: >>>esp_event_loop_run,640

I (162811) event: >>>esp_event_loop_run,575,base = WIFI_MESH_EVENT, id = 36

I (162821) event: >>>esp_event_loop_run,599

>>>mesh_wifi_event_cb,8045
I (162821) mesh: WIFI_EVENT_MESH_ROUTER, non-root
I (162831) mesh: WIFI_EVENT_MESH_ROUTER, last:WIFI_EVENT_STA_CONNECTED[STOP], reason:2
>>>mesh_wifi_event_cb,8063
>>>mesh_wifi_event_cb,8387, new_state = 44
I (162841) event: >>>esp_event_loop_run,640

i increased the timeout to 30sec
dev2 stuck in deadlock
240703dev2_11.txt

more logs,
with 30seconds it-s more clear what is happening:

device gets stuck on sending udp
after 30 seconds it goes into timeout and even_loop recovers

I (1096820) mesh_netif: >>>start_mesh_link_sta,328

dhcp_discover(): dhcp state is DISCOVER
I (1096840) esp_netif_lwip: SENDW mesh_link_sta  350 FFFFFFFFFFFF7CDFA1E16AD808004500015003A70000401175F700000000FFFFFFFF00440043013C725701010600550027D300000000000000000000000000000000000000007CDFA1E16AD80000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E16AD8370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1098100) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:6
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (1098110) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (1098110) mesh_mqtt: sent publish returned msg_id=38621
I (1098210) event: >>>esp_event_post_to,848, evt base = MQTT_EVENTS, evt id = 7

I (1098210) event: >>>esp_event_post_to,881

I (1098210) event: >>>esp_event_post_to,891, send to q

I (1098210) event: >>>esp_event_post_to,919

I (1098220) event: >>>esp_event_loop_run,575,base = MQTT_EVENTS, id = 7

I (1098230) event: >>>esp_event_loop_run,599

I (1098230) mesh_mqtt: Other event id:7
I (1098240) event: >>>esp_event_loop_run,630

W (1098990) ping: From <IP_ADDRESS> icmp_seq=382 timeout
W (1099300) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:7
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (1100110) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
W (1100500) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:8
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1101700) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:9
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (1102570) wifi:bcn_timeout,ap_probe_send_start
>>>wifi_event_post,2241
I (1102570) event: >>>esp_event_post_to,848, evt base = WIFI_EVENT, evt id = 21

I (1102580) event: >>>esp_event_post_to,898, send to q

I (1102580) event: >>>esp_event_post_to,919

I (1102860) wifi:AP's beacon interval = 102400 us, DTIM period= 1
I (1102860) event: >>>esp_event_post_to,848, evt base = WIFI_MESH_EVENT, evt id = 36

I (1102860) event: >>>esp_event_post_to,898, send to q

I (1102870) event: >>>esp_event_post_to,919

W (1102900) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:10
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1104100) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:11
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1105300) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:12
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (1106490) mesh: 5162<active>parent layer:1(node), channel:11, rssi:1, assoc:0(cnx rssi threshold:-120)my_assoc:0
W (1106500) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:13
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1107710) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:14
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
>>>wifi_event_post,2241
I (1108000) event: >>>esp_event_post_to,848, evt base = WIFI_EVENT, evt id = 1

I (1108000) event: >>>esp_event_post_to,898, send to q

I (1108000) event: >>>esp_event_post_to,919

W (1108910) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:15
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1110110) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:16
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
I (1111120) wifi:state: run -> init (6c0)
>>>ieee80211_sta_new_state,253
>>>ieee80211_sta_new_state,371
>>>cnx_sta_leave,2006
I (1111130) wifi:pm stop, total sleep time: 0 us / 14581097 us

I (1111130) wifi:new:<11,0>, old:<11,2>, ap:<11,2>, sta:<11,2>, prof:11
>>>ieee80211_sta_new_state,559, post disconnect evt
>>>wifi_event_post,2241
I (1111140) event: >>>esp_event_post_to,848, evt base = WIFI_EVENT, evt id = 5

I (1111150) event: >>>esp_event_post_to,898, send to q

I (1111160) event: >>>esp_event_post_to,919

W (1111310) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:17
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1112510) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:18
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1113710) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:19
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1114910) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:20
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1116110) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:21
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1117310) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:22
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1118510) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:23
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1119710) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:24
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1120910) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:25
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1122110) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:26
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1123310) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:27
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1124510) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:28
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1125710) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:29
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1126910) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:30
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
W (1128110) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:1046, no_wnd_count:0, timeout_count:31
E (1128110) mesh_netif: Send with err code 16394 ESP_ERR_MESH_TIMEOUT
I (1128110) mesh_netif: >>>start_mesh_link_sta,330

I (1128120) mesh_netif: >>>mesh_netifs_start,460

I (1128120) event: >>>esp_event_post_to,848, evt base = IP_EVENT, evt id = 1

I (1128120) event: >>>esp_event_loop_run,640

I (1128130) event: >>>esp_event_post_to,898, send to q

240703dev3_12.txt

@zhangyanjiaoesp how should we tackle this ?

for reference, i tried the same patches but with our own dynamic/fixed root code and it's impossible to form a dynamic mesh after building a fixed one with latest library and code.
This was working before, we are missing something else.

@KonssnoK
Here is the logic of the stuck issue.

The red font indicates the problem:

When the device connects to a parent, it call esp_mesh_send() to send the dhcp discover. The esp_mesh_send() function is a blocking API by default, it will return only if the sending complete.
When sending the mesh data, the xon window is used up, then the device need to apply for window from the parent. If the xon request timeout, it will try to request again until the lifetime expires or disconnection.
Initially, we relied on the disconnect event to solve the xon timeout infinite loop problem, but now because the connect event never returns, disconnect time has no chance to execute. So we call esp_mesh_send_block_time() to let the packet lifetime expires, then the xon timeout infinite loop can stop, and the esp_mesh_send() can return after a period of time.

@zhangyanjiaoesp thanks for the diagram.
Then,

how do we solve this? esp_mesh_send_block_time ? If yes, it means that by default the mesh should have a timeout, because we are making the nominal example fail
Are there more changes that we have to do to fix this issue?
When will you push the library fix to the v4.4?
What can we do about the deadlocks that sometimes occurred while trying to replicate?
Should we move to the next issue?

@KonssnoK

how do we solve this? esp_mesh_send_block_time ? If yes, it means that by default the mesh should have a timeout, because we are making the nominal example fail

Yes, call esp_mesh_send_block_time() to solve the problem. We will also consider adding this API in the example code.

Are there more changes that we have to do to fix this issue?

We will add two changes for this problem:

Periodically send null data(30s), thus when the parent reboot, the device can use null data to disconnect from the parent and then reconnect. This can solve the xon timeout loop via the disconnect event.
Sending deauth packet before the first auth when the device reboot, this can solve the router not reply auth response issue.

When will you push the library fix to the v4.4?

We regret to inform you that v4.4 has end of life, the final version is v4.4.8, but considering that your project has already done a lot of deployment and testing on v4.4, we will update the current fixes to v4.4. If possible, we recommend that you update to v5.0 and later version.

What can we do about the deadlocks that sometimes occurred while trying to replicate?

Most of the mesh deadlock issues I've encountered so far are caused by esp_mesh_send() blocking, so I recommend setting a lifetime for the send function. After this risk is eliminated, we can analyze it concretely when we encounter deadlock problems.

Should we move to the next issue?

Yes, I think we can.

@zhangyanjiaoesp

Yes, call esp_mesh_send_block_time() to solve the problem. We will also consider adding this API in the example code.

yes apparently this is always needed

We will add two changes for this problem:
1. Periodically send null data(30s), thus when the parent reboot, the device can use null data to disconnect from the parent and then reconnect. This can solve the xon timeout loop via the disconnect event.

2. Sending deauth packet before the first auth when the device reboot, this can solve the router not reply auth response issue.

remember that null data was causing memory leaks on 5.2 and had to be removed
9ddbd6cb0a46a96b475e1d8eaee6e43427ea2371 esp_wifi
so please check that memory is freed correctly.

We regret to inform you that v4.4 has end of life, the final version is v4.4.8, but considering that your project has already done a lot of deployment and testing on v4.4, we will update the current fixes to v4.4. If possible, we recommend that you update to v5.0 and later version.

we are actively working on moving to 5.2, but it won't happen for some months still.
Also the release process for 4.4-based software is easier than deploying a new toolchain on the field.
How long before we can have a fix on the branch?

Most of the mesh deadlock issues I've encountered so far are caused by esp_mesh_send() blocking, so I recommend setting a lifetime for the send function. After this risk is eliminated, we can analyze it concretely when we encounter deadlock problems.

well some of the logs i posted above are deadlocks happening with the timeout set
see
240703dev2_11.txt

Yes, I think we can.

cool

@KonssnoK Does calling the esp_mesh_send_block_time()API solve the problem?

i increased the timeout to 30sec
dev2 stuck in deadlock 240703dev2_11.txt

@KonssnoK
It seems the MESH_EVENT_PARENT_DISCONNECTED handle code didn't return.

@zhangyanjiaoesp for the connection problem using esp_mesh_send_block_time solves the DHCP getting stuck on the esp_mesh_send
about the disconnected event not returning, no idea what could be wrong there... there are no esp_mesh_send i imagine...
can esp_mesh_get_layer be blocking?

@zhangyanjiaoesp also, i think there is a main flaw in your flowchart..
esp_events task should never be used to run blocking functions or you risk blocking safety critical tasks.
The correct architectural approach of the handlers should be something like:
// Called by esp_events
static void callback_timer_mesh_connected(void* param)
{
    error_t r = xTaskNotify(&self->thread, NET_EVENT_ISOLATED_NOIP_TIMEOUT);
    if (SYS_OK != r) {
        ESP_LOGE(TAG, "%s::xTaskNotify() error %d\n", TAG, r);
    }
}

can you please check that the mesh library does not block the esp_event task? this would be very concerning for some safety high priority tasks we might have running in background

@zhangyanjiaoesp now that the connection is more or less stable, i see some other issues on the children, which goes back to the initial topic of this issue
pinging is periodically timings out on children nodes for no reason:

W (3252087) ping: From <IP_ADDRESS> icmp_seq=1793 timeout
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (3253957) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (3253957) mesh_mqtt: sent publish returned msg_id=875
I (3255957) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (3255957) mesh_mqtt: sent publish returned msg_id=59620
W (3256137) ping: From <IP_ADDRESS> icmp_seq=1794 timeout
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (3257957) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (3257957) mesh_mqtt: sent publish returned msg_id=36927
I (3259957) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (3259957) mesh_mqtt: sent publish returned msg_id=50698
W (3260137) ping: From <IP_ADDRESS> icmp_seq=1795 timeout
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (3261957) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (3261957) mesh_mqtt: sent publish returned msg_id=21878
I (3263957) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (3263957) mesh_mqtt: sent publish returned msg_id=56650
W (3264137) ping: From <IP_ADDRESS> icmp_seq=1796 timeout
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (3265177) ping: 64 bytes from <IP_ADDRESS> icmp_seq=1797 ttl=113 time=31 ms
I (3265957) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (3265957) mesh_mqtt: sent publish returned msg_id=63227
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (3266217) ping: 64 bytes from <IP_ADDRESS> icmp_seq=1798 ttl=113 time=27 ms
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (3267247) ping: 64 bytes from <IP_ADDRESS> icmp_seq=1799 ttl=113 time=29 ms
I (3267957) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (3267957) mesh_mqtt: sent publish returned msg_id=33342
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (3268277) ping: 64 bytes from <IP_ADDRESS> icmp_seq=1800 ttl=113 time=28 ms
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (3269307) ping: 64 bytes from <IP_ADDRESS> icmp_seq=1801 ttl=113 time=28 ms
I (3269957) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (3269957) mesh_mqtt: sent publish returned msg_id=1903
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (3270327) ping: 64 bytes from <IP_ADDRESS> icmp_seq=1802 ttl=113 time=21 ms
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)

@zhangyanjiaoesp what is the difference between
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
and
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
?
i currently have the timeouts only when there is 1 1 2

@zhangyanjiaoesp what is the difference between
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
and
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
?
i currently have the timeouts only when there is 1 1 2 (but maybe it's not related)

@KonssnoK It's seems not related to this log, the problem should have happened before this.

@zhangyanjiaoesp well the issue is intermittent,
but for now i've seen it only when the discovery is in 1 1 2 instead of 1 1 0
I'm still trying to find a way to replicate

@zhangyanjiaoesp could you tell me what that 2 is ?
attached log of the issue
240705dev1_1.txt

system is working
at some point big packet
multiple timeouts
system recovers after a while

W (751006) ping: 64 bytes from <IP_ADDRESS> icmp_seq=461 ttl=113 time=21 ms
W (751006) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200007255B47CCD014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (752016) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03DA000040015CB60A0000020808080808006955B47CCE014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (752046) ping: 64 bytes from <IP_ADDRESS> icmp_seq=462 ttl=113 time=16 ms
W (752046) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200007155B47CCE014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (752176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (752176) mesh_mqtt: sent publish returned msg_id=5552
I (753056) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03DB000040015CB50A0000020808080808006855B47CCF014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (753106) ping: 64 bytes from <IP_ADDRESS> icmp_seq=463 ttl=113 time=31 ms
W (753106) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200007055B47CCF014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
W (753326) esp_netif_lwip: RECV  mesh_link_sta  590 FFFFFFFFFFFF7CDFA1FFA515080045000240027B000040116C320A000001FFFFFFFF00430044022C9A43020106002009660400008000000000000A00000200000000000000007CDFA1E16AD800000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000638253633501020104FFFF0000330400001C2036040A00000103040A0000010608C0A89E69C23303381C040A00FFFF1A0205DC1F01002B06010400000002FF000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
W (753426) esp_netif_lwip: RECV  mesh_link_sta  590 FFFFFFFFFFFF7CDFA1FFA515080045000240027C000040116C310A000001FFFFFFFF00430044022C9743020106002009660400008000000000000A00000200000000000000007CDFA1E16AD800000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000638253633501050104FFFF0000330400001C2036040A00000103040A0000010608C0A89E69C23303381C040A00FFFF1A0205DC1F01002B06010400000002FF000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
I (754106) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03DC000040015CB40A0000020808080808006755B47CD0014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (754146) ping: 64 bytes from <IP_ADDRESS> icmp_seq=464 ttl=113 time=26 ms
W (754146) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200006F55B47CD0014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (754176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (754176) mesh_mqtt: sent publish returned msg_id=46262
I (755156) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03DD000040015CB30A0000020808080808006655B47CD1014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (756176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (756176) mesh_mqtt: sent publish returned msg_id=45513
I (756696) esp_netif_lwip: SENDW mesh_link_sta   94 7CDFA1FFA5157CDFA1E2A30408004500005003DE000040068F680A000002898753D9CCE3075B39E89781DBB7B89A50181667A28500003226000E2F746F7069632F69705F6D65736868CE6C617965723A2D312049503A31302E302E302E33
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (758176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (758176) mesh_mqtt: sent publish returned msg_id=33473
W (758176) ping: From <IP_ADDRESS> icmp_seq=465 timeout
I (759176) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03DF000040015CB10A0000020808080808006555B47CD2014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (760176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (760176) mesh_mqtt: sent publish returned msg_id=36691
I (762176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (762176) mesh_mqtt: sent publish returned msg_id=20501
W (762196) ping: From <IP_ADDRESS> icmp_seq=466 timeout
I (763196) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03E0000040015CB00A0000020808080808006455B47CD3014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (764176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (764176) mesh_mqtt: sent publish returned msg_id=24636
I (766176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (766176) mesh_mqtt: sent publish returned msg_id=18326
W (766206) ping: From <IP_ADDRESS> icmp_seq=467 timeout
I (767206) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03E1000040015CAF0A0000020808080808006355B47CD4014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (768176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (768176) mesh_mqtt: sent publish returned msg_id=24141
I (768706) esp_netif_lwip: SENDW mesh_link_sta   94 7CDFA1FFA5157CDFA1E2A30408004500005003E2000040068F640A000002898753D9CCE3075B39E89781DBB7B89A50181667A28500003226000E2F746F7069632F69705F6D65736868CE6C617965723A2D312049503A31302E302E302E33
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (770176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (770176) mesh_mqtt: sent publish returned msg_id=56253
W (770226) ping: From <IP_ADDRESS> icmp_seq=468 timeout
I (771226) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03E3000040015CAD0A0000020808080808006255B47CD5014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (772176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (772176) mesh_mqtt: sent publish returned msg_id=43805
I (774176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (774176) mesh_mqtt: sent publish returned msg_id=53465
W (774246) ping: From <IP_ADDRESS> icmp_seq=469 timeout
I (775246) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03E4000040015CAC0A0000020808080808006155B47CD6014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (776176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (776176) mesh_mqtt: sent publish returned msg_id=34108
I (778176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (778176) mesh_mqtt: sent publish returned msg_id=32640
W (778256) ping: From <IP_ADDRESS> icmp_seq=470 timeout
I (779256) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03E5000040015CAB0A0000020808080808006055B47CD7014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (780176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (780176) mesh_mqtt: sent publish returned msg_id=45040
I (780636) esp_netif_lwip: SENDW mesh_link_sta   42 FFFFFFFFFFFF7CDFA1E2A304080600010800060400017CDFA1E2A3040A0000020000000000000A000002
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (780976) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A0000020000494B747A360E4142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (781416) esp_netif_lwip: SENDW mesh_link_sta   54 7CDFA1FFA5157CDFA1E2A30408004500002803E6000040068F880A000002898753D9C028075BD854FAF798207715501480169E510000
W>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
 (781416) esp_netif_lwip: RECV  mesh_link_sta   58 7CDFA1E2A3047CDFA1FFA51508004500002CC02940002A06A940898753D90A000002075BC02898207711D854FAF75018FA3D2A3300004002B9F0
I (782176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (782176) mesh_mqtt: sent publish returned msg_id=55695
W (783056) esp_netif_lwip: RECV  mesh_link_sta   54 7CDFA1E2A3047CDFA1FFA515080045000028000040002A06696E898753D90A000002075BC028982077110000000050040000F1C80000
W (783976) ping: From <IP_ADDRESS> icmp_seq=471 timeout
I (784176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (784176) mesh_mqtt: sent publish returned msg_id=9245
I (784976) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03E7000040015CA90A0000020808080808005F55B47CD8014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (785096) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A0000020000484B747A370E4142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
W (785116) ping: 64 bytes from <IP_ADDRESS> icmp_seq=472 ttl=113 time=118 ms
W (785116) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200006755B47CD8014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
W (785746) ping: Task Name      Status  Prio    HWM     Task#   Affinity
W (785746) ping: main                   X       1       1340    4       0
IDLE1           R       0       788     6       1
IDLE0           R       0       784     5       0
tiT             B       18      552     8       -1
ping            B       2       416     16      -1
mqtt task       B       5       552     18      -1
mqtt_task       B       5       3720    20      -1
netif rx task   B       5       916     17      -1
check button ta B       5       956     19      -1
Tmr Svc         B       1       1400    7       0
ipc1            B       24      772     2       1
sys_evt         B       20      3664    9       0
MTXON           B       13      764     13      -1
MRX             B       13      592     14      -1
esp_timer       S       22      4520    3       0
MNWK            B       15      900     15      1
MTX             B       13      1128    12      -1
wifi            B       23      3836    10      0
MTXBLK          B       7       1324    11      -1
ipc0            B       24      768     1       0

I (786126) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03E8000040015CA80A0000020808080808005E55B47CD9014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (786176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (786176) mesh_mqtt: sent publish returned msg_id=28283
W (786216) ping: 64 bytes from <IP_ADDRESS> icmp_seq=473 ttl=113 time=76 ms
W (786216) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200006655B47CD9014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
W (786946) esp_netif_lwip: RECV  mesh_link_sta   54 7CDFA1E2A3047CDFA1FFA515080045000028000140006A06296D898753D90A000002075BC02898207711D854FAF7501400001E6C0000
I (787226) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03E9000040015CA70A0000020808080808005D55B47CDA014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (787266) ping: 64 bytes from <IP_ADDRESS> icmp_seq=474 ttl=113 time=27 ms
W (787266) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200006555B47CDA014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (788176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (788176) mesh_mqtt: sent publish returned msg_id=63810
I (788276) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03EA000040015CA60A0000020808080808005C55B47CDB014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (788376) ping: 64 bytes from <IP_ADDRESS> icmp_seq=475 ttl=113 time=78 ms
W (788376) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200006455B47CDB014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
W (788936) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A0000020000474B747A380E4142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (789376) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03EB000040015CA50A0000020808080808005B55B47CDC014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (789556) ping: 64 bytes from <IP_ADDRESS> icmp_seq=476 ttl=113 time=161 ms
W (789556) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200006355B47CDC014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (790176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (790176) mesh_mqtt: sent publish returned msg_id=286
I (790556) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03EC000040015CA40A0000020808080808005A55B47CDD014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (790596) ping: 64 bytes from <IP_ADDRESS> icmp_seq=477 ttl=113 time=25 ms
W (790596) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200006255B47CDD014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (791606) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03ED000040015CA30A0000020808080808005955B47CDE014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (791656) ping: 64 bytes from <IP_ADDRESS> icmp_seq=478 ttl=113 time=32 ms
W (791656) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200006155B47CDE014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (792176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (792176) mesh_mqtt: sent publish returned msg_id=12881
I (792656) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03EE000040015CA20A0000020808080808005855B47CDF014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (792716) esp_netif_lwip: SENDW mesh_link_sta   94 7CDFA1FFA5157CDFA1E2A30408004500005003EF000040068F570A000002898753D9CCE3075B39E89781DBB7B89A50181667A28500003226000E2F746F7069632F69705F6D65736868CE6C617965723A2D312049503A31302E302E302E33
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (792746) ping: 64 bytes from <IP_ADDRESS> icmp_seq=479 ttl=113 time=77 ms
W (792756) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200006055B47CDF014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
W (792936) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A0000020000464B747A390E4142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (793756) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03F0000040015CA00A0000020808080808005755B47CE0014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (793856) ping: 64 bytes from <IP_ADDRESS> icmp_seq=480 ttl=113 time=76 ms
W (793856) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200005F55B47CE0014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (794176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (794176) mesh_mqtt: sent publish returned msg_id=59276
I (794856) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03F1000040015C9F0A0000020808080808005655B47CE1014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (794896) ping: 64 bytes from <IP_ADDRESS> icmp_seq=481 ttl=113 time=21 ms
W (794896) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200005E55B47CE1014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (795896) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03F2000040015C9E0A0000020808080808005555B47CE2014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (795946) ping: 64 bytes from <IP_ADDRESS> icmp_seq=482 ttl=113 time=33 ms
W (795956) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200005D55B47CE2014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (796176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (796176) mesh_mqtt: sent publish returned msg_id=34076
I (796956) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03F3000040015C9D0A0000020808080808005455B47CE3014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (796986) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A0000020000454B747A3A0E4142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
W (796996) ping: 64 bytes from <IP_ADDRESS> icmp_seq=483 ttl=113 time=26 ms
W (796996) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200005C55B47CE3014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (798006) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03F4000040015C9C0A0000020808080808005355B47CE4014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (798176) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
W (801026) ping: From <IP_ADDRESS> icmp_seq=484 timeout
I (802026) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03F5000040015C9B0A0000020808080808005255B47CE5014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (805046) ping: From <IP_ADDRESS> icmp_seq=485 timeout
I (806046) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03F6000040015C9A0A0000020808080808005155B47CE6014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (807726) TRANSPORT_BASE: TCP Poll timeout or error, errno=Connection already in progress, fd=55, timeout_ms=10000
E (807726) MQTT_CLIENT: Writing didn't complete in specified timeout: errno=119
I (807726) mesh_mqtt: MQTT_EVENT_ERROR
E (807736) MQTT_CLIENT: Error to resend data
I (807736) mesh_mqtt: MQTT_EVENT_DISCONNECTED
I (807746) mesh_mqtt: sent publish returned msg_id=25807
W (809066) ping: From <IP_ADDRESS> icmp_seq=486 timeout
I (809746) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (809746) mesh_mqtt: sent publish returned msg_id=38902
I (810066) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03F7000040015C990A0000020808080808005055B47CE7014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (811746) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (811746) mesh_mqtt: sent publish returned msg_id=33110
W (813086) ping: From <IP_ADDRESS> icmp_seq=487 timeout
I (813746) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (813746) mesh_mqtt: sent publish returned msg_id=31085
I (814086) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03F8000040015C980A0000020808080808004F55B47CE8014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (815746) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (815746) mesh_mqtt: sent publish returned msg_id=24848
W (817126) ping: From <IP_ADDRESS> icmp_seq=488 timeout
I (817746) mesh_mqtt: Other event id:7
I (817746) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (817746) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C03F9000040068F710A000002898753D9CCE4075B45C1F16400000000600216809222000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (818126) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03FA000040015C960A0000020808080808004E55B47CE9014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (819226) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C03FB000040068F6F0A000002898753D9CCE4075B45C1F16400000000600216809222000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (820736) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C03FC000040068F6E0A000002898753D9CCE4075B45C1F16400000000600216809222000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (821146) ping: From <IP_ADDRESS> icmp_seq=489 timeout
I (822146) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C03FD000040015C930A0000020808080808004D55B47CEA014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (822246) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C03FE000040068F6C0A000002898753D9CCE4075B45C1F16400000000600216809222000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (823756) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C03FF000040068F6B0A000002898753D9CCE4075B45C1F16400000000600216809222000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (825166) ping: From <IP_ADDRESS> icmp_seq=490 timeout
I (825266) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C0400000040068F6A0A000002898753D9CCE4075B45C1F16400000000600216809222000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (826166) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C0401000040015C8F0A0000020808080808004C55B47CEB014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (826776) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C0402000040068F680A000002898753D9CCE4075B45C1F16400000000600216809222000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
E (827766) esp-tls: [sock=55] select() timeout
E (827766) TRANSPORT_BASE: Failed to open a new connection: 32774
E (827766) MQTT_CLIENT: Error transport connect
I (827766) mesh_mqtt: MQTT_EVENT_ERROR
I (827776) mesh_mqtt: MQTT_EVENT_DISCONNECTED
I (827776) mesh_mqtt: sent publish returned msg_id=29523
W (829176) ping: From <IP_ADDRESS> icmp_seq=491 timeout
I (829786) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (829786) mesh_mqtt: sent publish returned msg_id=37359
I (830176) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C0403000040015C8D0A0000020808080808004B55B47CEC014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (831786) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (831786) mesh_mqtt: sent publish returned msg_id=45736
W (833196) ping: From <IP_ADDRESS> icmp_seq=492 timeout
I (833786) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (833786) mesh_mqtt: sent publish returned msg_id=35333
I (834196) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C0404000040015C8C0A0000020808080808004A55B47CED014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (835786) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (835786) mesh_mqtt: sent publish returned msg_id=15996
W (837216) ping: From <IP_ADDRESS> icmp_seq=493 timeout
I (837786) mesh_mqtt: Other event id:7
I (837786) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (837786) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C0405000040068F650A000002898753D9CCE5075BC459FC610000000060021680088C000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (838216) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E2A30408004500005C0406000040015C8A0A0000020808080808004955B47CEE014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (839286) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C0407000040068F630A000002898753D9CCE5075BC459FC610000000060021680088C000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (840636) esp_netif_lwip: SENDW mesh_link_sta   42 FFFFFFFFFFFF7CDFA1E2A304080600010800060400017CDFA1E2A3040A0000020000000000000A000002
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (840736) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E2A3047CDFA1FFA51508004580005C0000000071012F10080808080A00000200001F4B747A600E4142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (840796) esp_netif_lwip: SENDW mesh_link_sta   58 7CDFA1FFA5157CDFA1E2A30408004500002C0408000040068F620A000002898753D9CCE5075BC459FC610000000060021680088C000002040270
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (840806) esp_netif_lwip: SENDW mesh_link_sta   94 7CDFA1FFA5157CDFA1E2A3040800450000500409000040068F3D0A000002898753D9CCE3075B39E89781DBB7B89A50181667A28500003226000E2F746F7069632F69705F6D65736868CE6C617965723A2D312049503A31302E302E302E33
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (841016) esp_netif_lwip: SENDW mesh_link_sta   54 7CDFA1FFA5157CDFA1E2A304080045000028040A000040068F640A000002898753D9CCE5075BC459FC62D14876AF50101680D4FC0000
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)

240705dev2_2.txt
another log of a device, this time i added back also the event_loop logs

@KonssnoK

@zhangyanjiaoesp could you tell me what that 2 is in >>>mesh_xon_process_disconnected,2638, (1, 1, 2) ?
attached log of the issue
240705dev1_1.txt

I have told you that you don't need to care this log, I add was added only to debug the timeout issue. This log will be displayed whenever mesh data is sent. And 2 is an internal variable that indicates whether enable mesh reconnect (0 is enable, 1 is disable, 2 is adaptive).
I see this in  your logs, it seems you call esp_mesh_set_self_organized(true, true) in your application, so the last argument becomes 2. ( >>>mesh_xon_process_disconnected,2638, (1, 1, 2) )

For the ping timeout issue, it looks like the device didn't get IP address, when it get IP address, the ping timeout disappear.

@zhangyanjiaoesp ok thanks for the explanation.
I'm not sure it's related to DHCP, if you check the last attached log there si nothing about DHCP during the timeouts.

i repost it here:
[240705dev2_3.txt](https://github.com/user-attachments/files/16111163/240705dev2_3.txt)

W (12488923) ping: 64 bytes from <IP_ADDRESS> icmp_seq=9881 ttl=113 time=22 ms
W (12488923) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E27B847CDFA1FFA51508004580005C0000000071012F10080808080A0000020000F630647C99264142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
W (12489463) esp_netif_lwip: RECV  mesh_link_sta  106 7CDFA1E27B847CDFA1FFA51508004580005C0000000071012F10080808080A0000020000D757747AA8014142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
I (12489923) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E27B8408004500005C4EB90000400111D70A000002080808080800ED30647C9A264142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (12492943) ping: From <IP_ADDRESS> icmp_seq=9882 timeout
I (12493943) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1FFA5157CDFA1E27B8408004500005C4EBA0000400111D60A000002080808080800EC30647C9B264142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (12494863) TRANSPORT_BASE: TCP Poll timeout or error, errno=Connection already in progress, fd=55, timeout_ms=10000
E (12494863) MQTT_CLIENT: Writing didn't complete in specified timeout: errno=119
I (12494863) event: >>>esp_event_post_to,848, evt base = MQTT_EVENTS, evt id = 0

@zhangyanjiaoesp i was able to take logs from 2 devices that went offline completely and their root.
What i see is that there is a channel switch and after that the children are not able to communicate anymore with the external world.
Is this expected?
240708dev2_1.txt
240708dev3_1.txt
240708dev1_1.txt

W (9623095) ping: 64 bytes from <IP_ADDRESS> icmp_seq=7191 ttl=115 time=199 ms
I (9623525) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (9623525) esp_netif_lwip: SENDW mesh_link_sta   93 7CDFA1E2A3057CDFA1E16AD808004500004F3F730000400653D30A000003898753D9FE03075B515FD3B2AC289A0F501815104BAC00003225000E2F746F7069632F69705F6D6573686A9D6C617965723A322049503A31302E302E302E33
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (9623545) mesh_mqtt: sent publish returned msg_id=27293
I (9624135) esp_netif_lwip: SENDW mesh_link_sta  106 7CDFA1E2A3057CDFA1E16AD808004500005C3F7400004001211B0A000003080808080800173CBC7B181C4142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F80
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (9625105) esp_netif_lwip: SENDW mesh_link_sta   93 7CDFA1E2A3057CDFA1E16AD808004500004F3F750000400653D10A000003898753D9FE03075B515FD3B2AC289A0F501815104BAC00003225000E2F746F7069632F69705F6D6573686A9D6C617965723A322049503A31302E302E302E33
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (9625545) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (9625545) mesh_mqtt: sent publish returned msg_id=55498
I (9626485) mesh: 5162<active>parent layer:1(node), channel:13, rssi:-5, assoc:2(cnx rssi threshold:-120)my_assoc:0
W (9627155) ping: From <IP_ADDRESS> icmp_seq=7192 timeout
I (9627545) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (9627545) mesh_mqtt: sent publish returned msg_id=11571
>>>wifi_event_post,2241
>>>mesh_wifi_event_cb,8045
I (9627985) mesh: WIFI_EVENT_SCAN_DONE, non-root
I (9627985) mesh: WIFI_EVENT_SCAN_DONE, last:WIFI_EVENT_MESH_CHANNEL_SWITCH[STOP], reason:2
>>>mesh_wifi_event_cb,8063
>>>mesh_wifi_event_cb,8387, new_state = 7
W (9627995) wifi:scan number is 0

in the root log i do not see any log that regards channel, and this is why it continues to work apparently...

@KonssnoK

I'm not sure the issue i'm referring to it's related to DHCP, if you check the last attached log there is nothing about DHCP during the last timeouts (line 6600+).
i repost it here: 240705dev2_3.txt

yes, this log can't be determined to be a DHCP problem.

What i see is that there is a channel switch and after that the children are not able to communicate anymore with the external world.
Is this expected?
240708dev2_1.txt 240708dev3_1.txt 240708dev1_1.txt

These logs seem to be related to DHCP again, neither device2 nor device3 got the IP address and kept sending dhcp discover.
In order to confirm the problem, suggest you capture the packets of the devices using the wireshark.
device2:
I (6553787) wifi:new:<13,2>, old:<13,0>, ap:<13,2>, sta:<13,0>, prof:13
I (6553797) wifi:state: init -> auth (b0)
I (6553807) wifi:state: auth -> assoc (0)
I (6553817) wifi:new:<13,2>, old:<13,2>, ap:<13,2>, sta:<13,2>, prof:13
I (6553817) wifi:state: assoc -> run (10)
>>>mesh_wifi_event_cb,8045
I (6553817) mesh: WIFI_EVENT_MESH_IE_CHANGE, non-root
I (6553827) mesh: WIFI_EVENT_MESH_IE_CHANGE, last:WIFI_EVENT_STA_DISCONNECTED[STOP], reason:2
>>>mesh_wifi_event_cb,I (6553837) wifi:connected with ESPM_E2A304, aid = 1, channel 13, 40D, bssid = 7c:df:a1:e2:a3:05
I (6553847) wifi:security: WPA2-PSK, phy: bgn, rssi: -55
I (6553857) wifi:pm start, type: 0

I (6553857) wifi:set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 0, mt_pti: 25000, mt_time: 10000
>>>wifi_event_post,2241
8063
>>>mesh_wifi_event_cb,8387, new_state = 20
>>>mesh_wifi_event_cb,8045
I (6553867) mesh: <MESH_NWK_MIE_CHANGE><><><><ROOT ADDR><><><>
I (6553867) mesh: WIFI_EVENT_STA_CONNECTED, non-root
I (6553877) mesh: <MESH_NWK_ROOT_ADDR>from assoc, layer:2, root_addr:7c:df:a1:e2:a3:05, root_cap:2
I (6553877) mesh: WIFI_EVENT_STA_CONNECTED, last:WIFI_EVENT_MESH_IE_CHANGE[STOP], reason:2
>>>mesh_wifi_event_cb,8063
>>>mesh_wifi_event_cb,8387, new_state = 9
I (6553887) mesh: <MESH_NWK_ROOT_ADDR>idle, layer:2, root_addr:7c:df:a1:e2:a3:05, conflict_roots.num:0<>
I (6553897) wifi:AP's beacon interval = 102400 us, DTIM period = 1
dhcp_discover(): dhcp state is DISCOVER
I (6553927) esp_netif_lwip: SENDW        sta  350 FFFFFFFFFFFF7CDFA1E27B840800450001502C60000040114D3E00000000FFFFFFFF00440043013C035001010600CBA9627300000000000000000000000000000000000000007CDFA1E27B840000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E27B84370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000
E (6553987) wifi_netif: TXW
I (6553987) mesh_main: <MESH_EVENT_ROOT_ADDRESS>root address:7c:df:a1:e2:a3:05
>>>mesh_wifi_event_cb,8045
I (6553987) mesh: 2004<arm>parent monitor, my layer:2(cap:6)(node), interval:7453ms, retries:1<normal connected>
I (6553997) mesh: WIFI_EVENT_MESH_PARENT_ASSOCIE, non-root
I (6554017) mesh: WIFI_EVENT_MESH_PARENT_ASSOCIE, last:WIFI_EVENT_STA_CONNECTED[STOP], reason:2
>>>mesh_wifi_event_cb,8063
>>>mesh_wifi_event_cb,8387, new_state = 13
I (6554027) mesh: 5122<assoc>parent layer:1, channel:13, rssi:-54, assoc:2, rssi threshold<-78,-82,-85>
I (6554027) mesh_main: <MESH_EVENT_PARENT_CONNECTED>layer:2-->2, parent:7c:df:a1:e2:a3:05<layer2>, ID:77:77:77:77:77:76
dhcp_release_and_stop(): dhcp state is OFF
I (6554057) mesh_netif: It was a wifi station removing stuff
dhcp_discover(): dhcp state is DISCOVER
......
...... (omit the middle)
dhcp_discover(): dhcp state is DISCOVER
I (6675527) esp_netif_lwip: SENDW mesh_link_sta  350 FFFFFFFFFFFF7CDFA1E27B840800450001502C81000040114D1D00000000FFFFFFFF00440043013CDA2A01010600817CD5C500000000000000000000000000000000000000007CDFA1E27B840000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E27B84370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (6676077) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (6676077) mesh_mqtt: sent publish returned msg_id=5562
W (6676737) ping: From <IP_ADDRESS> icmp_seq=5061 timeout
>>>mesh_wifi_event_cb,8045
I (6677497) mesh: WIFI_EVENT_MESH_PARENT_ASSOCIE, non-root
I (6677497) mesh: WIFI_EVENT_MESH_PARENT_ASSOCIE, last:WIFI_EVENT_MESH_MAP_BEACON[STOP], reason:2
>>>mesh_wifi_event_cb,8063
>>>mesh_wifi_event_cb,8387, new_state = 13
I (6677507) mesh: 5122<assoc>parent layer:1, channel:13, rssi:-48, assoc:2, rssi threshold<-78,-82,-85>
E (6677737) ping_sock: send error=0
I (6678077) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (6678077) mesh_mqtt: sent publish returned msg_id=13144
dhcp_discover(): dhcp state is DISCOVER
I (6679587) esp_netif_lwip: SENDW mesh_link_sta  350 FFFFFFFFFFFF7CDFA1E27B840800450001502C82000040114D1C00000000FFFFFFFF00440043013CDA2A01010600817CD5C500000000000000000000000000000000000000007CDFA1E27B840000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E27B84370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
I (6680077) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (6680077) mesh_mqtt: sent publish returned msg_id=53083
W (6680737) ping: From <IP_ADDRESS> icmp_seq=5062 timeout
E (6681737) ping_sock: send error=0
I (6682077) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (6682077) mesh_mqtt: sent publish returned msg_id=24572
ClearCommError failed (PermissionError(13, 'Access is denied.', None, 5))
Waiting for the device to reconnect........................................

device3:
I (9652615) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:2
I (9652625) wifi:new:<13,2>, old:<13,0>, ap:<13,2>, sta:<13,0>, prof:13
I (9652645) wifi:state: init -> auth (b0)
I (9652655) wifi:state: auth -> assoc (0)
I (9652665) wifi:new:<13,2>, old:<13,2>, ap:<13,2>, sta:<13,2>, prof:13
I (9652665) wifi:state: assoc -> run (10)
>>>mesh_wifi_event_cb,8045
I (9652675) mesh: WIFI_EVENT_MESH_IE_CHANGE, non-root
I (9652675) mesh: WIFI_EVENT_MESH_IE_CHANGE, last:WIFI_EVENT_STA_DISCONNECTED[STOP], reason:2
>>>mesh_wifi_event_cb,8063
>>>mesh_wifi_I (9652675) wifi:connected with ESPM_E2A304, aid = 2, channel 13, 40event_cb,8387, new_state = 20
D, bssid = 7c:df:a1:e2:a3:05
I (9652695) mesh: <MESH_NWK_MIE_CHANGE><><><><ROOT ADDR><><><>
I (9652695) wifi:I (9652705) mesh: <MESH_NWK_ROOT_ADDR>from assoc, layer:2, root_addr:7c:df:a1:e2:a3:05, root_cap:2
security: WPA2-PSK, phy: bgn, rssi: -5
I (9652715) wifi:pm start, type: 0

I (9652715) wifi:set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 0, mt_pti: 25000, mt_time: 10000
>>>wifi_event_post,2241
>>>mesh_wifi_event_cb,8045
I (9652725) mesh: <MESH_NWK_ROOT_ADDR>idle, layer:2, root_addr:7c:df:a1:e2:a3:05, conflict_roots.num:0<>
I (9652735) mesh: WIFI_EVENT_STA_CONNECTED, non-root
I (9652745) mesh: WIFI_EVENT_STA_CONNECTED, last:WIFI_EVENT_MESH_IE_CHANGE[STOP], reason:2
>>>mesh_wifi_event_cb,8063
>>>mesh_wifi_event_cb,8387, new_state = 9
dhcp_discover(): dhcp state is DISCOVER
I (9652765) esp_netif_lwip: SENDW        sta  350 FFFFFFFFFFFF7CDFA1E16AD80800450001503F7E000040113A2000000000FFFFFFFF00440043013C83120101060082CBE94C00000000000000000000000000000000000000007CDFA1E16AD80000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E16AD8370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000
E (9652825) wifi_netif: TXW
I (9652835) mesh_main: <MESH_EVENT_ROOT_ADDRESS>root address:7c:df:a1:e2:a3:05
I (9652835) mesh: 2004<arm>parent monitor, my layer:2(cap:6)(node), interval:11758ms, retries:1<normal connected>
I (9652855) mesh_main: <MESH_EVENT_PARENT_CONNECTED>layer:2-->2, parent:7c:df:a1:e2:a3:05<layer2>, ID:77:77:77:77:77:76
I (9652855) wifi:dhcp_release_and_stop(): dhcp state is OFF
AP's beacon interval = 307200 us, DTIM period = 1
I (9652875) mesh_netif: It was a wifi station removing stuff
dhcp_discover(): dhcp state is DISCOVER
I (9652885) esp_netif_lwip: SENDW mesh_link_sta  350 FFFFFFFFFFFF7CDFA1E16AD80800450001503F7F000040113A1F00000000FFFFFFFF00440043013CA32A01010600883DC3C200000000000000000000000000000000000000007CDFA1E16AD80000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E16AD8370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
W (9652955) mesh_hand: Start checking DYNAMIC ROOT delayed tasks
W (9652955) mesh_main: <MESH_EVENT_TODS_REACHABLE>state:0
W (9653075) ping: From <IP_ADDRESS> icmp_seq=7196 timeout
dhcp_discover(): dhcp state is DISCOVER
I (9653455) esp_netif_lwip: SENDW mesh_link_sta  350 FFFFFFFFFFFF7CDFA1E16AD80800450001503F80000040113A1E00000000FFFFFFFF00440043013CA32A01010600883DC3C200000000000000000000000000000000000000007CDFA1E16AD80000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E16AD8370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
......
...... (omit the middle)
dhcp_discover(): dhcp state is DISCOVER
I (9795145) esp_netif_lwip: SENDW mesh_link_sta  350 FFFFFFFFFFFF7CDFA1E16AD80800450001503FA20000401139FC00000000FFFFFFFF00440043013CA32A01010600883DC3C200000000000000000000000000000000000000007CDFA1E16AD80000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E16AD8370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
E (9795205) ping_sock: send error=0
I (9797065) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (9797065) mesh_mqtt: sent publish returned msg_id=35685
W (9798205) ping: From <IP_ADDRESS> icmp_seq=7230 timeout
I (9799065) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (9799065) mesh_mqtt: sent publish returned msg_id=65072
dhcp_discover(): dhcp state is DISCOVER
I (9799205) esp_netif_lwip: SENDW mesh_link_sta  350 FFFFFFFFFFFF7CDFA1E16AD80800450001503FA30000401139FB00000000FFFFFFFF00440043013CA32A01010600883DC3C200000000000000000000000000000000000000007CDFA1E16AD80000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000063825363350101390205DC0C096573707265737369663D07017CDFA1E16AD8370401031C06FF00000000000000000000000000000000000000000000000000000000000000000000
>>>mesh_xon_process_disconnected,2638, (1, 1, 2)
E (9799265) ping_sock: send error=0
ClearCommError failed (PermissionError(13, 'Access is denied.', None, 5))
Waiting for the device to reconnect...................................................................

@zhangyanjiaoesp i will put logs in the DHCPS of the root

@zhangyanjiaoesp here is the log of the root with DHCPS logs.
I see it receives the discovery packets when the children get stuck but i'm not sure why it's not answering.
I'll check it out but maybe you have already an idea?
240709dev1_1.txt

@zhangyanjiaoesp i got the pcap and the logs.
For this single issue i reduced the number of devices to 2
extension .pcapng
0709run5.txt
240709dev1_5.txt
240709dev3_5.txt

@zhangyanjiaoesp i got the pcap and the logs. Taken on channel 11, which should be the right one. For this single issue i reduced the number of devices to 2
extension .pcapng 0709run5.txt
240709dev1_5.txt 240709dev3_5.txt
ps: do you have a wireshark decoder for esp mesh protocol?

@KonssnoK In the pcap file, the data packets after wifi connection is encrypted, you can refer this to set the wireshark, thus the dhcp packets can be shown in plaintext in the captures.
For the mesh data, default is encrypted, if you want to set it to unencrypted, you can change the code as the following.

By the way, you can open the debug log in dhcp client also. And there are two many logs in the file, now that we have resolved some issues, it is recommended to remove the printing of statistic, tasks info, and packet dump(youu added in your patch) to make log analysis easier.

@zhangyanjiaoesp i think the issue might be related to the dhcps start/stop.
If the UDP pcb would be wrong, it would make sense that the root won't be able to provide packets anymore.
240709dev1_7.txt
I can remove some logs, yes, but still i don't know where to look exactly

@zhangyanjiaoesp here is another set of logs with the issue
changes:

i removed most of the logs
i added some logs in netif dhcps
i had to change some logs of received data because they were not informative enough

to trigger

this triggers on the root, so i simply kept the current root offline until the other device became root

issues:

dhcps stuck.
routing table sending one byte less of what is expected.

    if (data->data[0] == CMD_ROUTE_TABLE) {
        int size =  data->size - 1;
        if (s_route_table_lock == NULL || size%6 != 0) {
            ESP_LOGE(MESH_TAG, "CMD_ROUTE_TABLE: Unexpected size %d", size);
            return;
        }

240710dev1_1.txt
240710dev3_1.txt
all this is happening on the root device.
The child device, dev3, was kept in reset right before the issue occurred, meaning that it could not have be the one with the issue

@zhangyanjiaoesp do you have any idea on how to check on this issue? what could break the ap interface 🤔

EDIT: by keeping the hotspot off long enough the root started scanning again for wifi, and upon reconnection it solved the issue.
This suggests it's something related to netif, because it got re-initialized from the hotspot being off
240710dev3_2.txt
240710dev1_2.txt

@KonssnoK In these logs, when the dhcp discover loop occur, the device1 is root, and the device3 is layer2 node
device3 send dhcp request:
dhcp_discover(): dhcp state is DISCOVER
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
E (995216) mesh_main: CMD_ROUTE_TABLE: Unexpected size 12
W (996306) ping: From <IP_ADDRESS> icmp_seq=249 timeout
E (997236) mesh_main: CMD_ROUTE_TABLE: Unexpected size 12
E (997306) ping_sock: send error=0
dhcp_discover(): dhcp state is DISCOVER

device1 send dhcp offer:
I (1974309) mesh_netif: Root received: from: ff:ff:ff:ff:ff:ff to 7c:df:a1:e1:6a:d8 size: 350
dhcps: handle_dhcp-> receive a packet
dhcps: handle_dhcp malloc_len=548 rx_len=308dhcps: handle_dhcp-> p->tot_len = 308
dhcps: handle_dhcp-> p->len = 308
dhcps: handle_dhcp-> parse_msg(p)
dhcps: len = 68
dhcps: (s16_t)*optptr = 53
dhcps: (s16_t)*optptr = 57
dhcps: (s16_t)*optptr = 12
dhcps: (s16_t)*optptr = 61
dhcps: (s16_t)*optptr = 55
dhcps: (s16_t)*optptr = 255
dhcps: DHCPD_STATE_OFFER
dhcps: return s.state = 1
dhcps: xid changed
dhcps: client_address.addr = 200000a
dhcps: handle_dhcp-> DHCPD_STATE_OFFER
udhcp: send_offer>>p->ref = 1
dhcps: send_offer>>pbuf_alloc succeed
dhcps: send_offer>>p->tot_len = 548
dhcps: send_offer>>p->len = 548
dhcps: send_offer>>udp_sendto result 0
udhcp: send_offer>>free pbuf
dhcps: handle_dhcp-> pbuf_free(p)

After a while both device Triggering DYNAMIC MESH handover, and then the device3 change to be root node, device1 change to be layer2 node, and the dhcp success.
device3:
W (1120176) mesh_hand: Triggering DYNAMIC MESH handover
I (1120176) mesh: [IO]enable self-organizing, search parent<reconnect>
I (1120186) mesh: mesh_schedule.c 2533 null args
>>>wifi_event_post,2241
I (1120196) mesh: [IO]enable self-organizing, search parent<adaptive>
W (1120196) mesh_hand: scan_done: found 0, fixed_root 0, has_parent 0
I (1120196) mesh: <MESH_NWK_SCAN_REQ_PASSIVE>unexpected, unprocessed previous scan by parent selection
W (1120206) mesh_hand: All nodes have bad connection, allow any RSSI.
I (1120226) mesh_main: <MESH_EVENT_ROOT_FIXED>not fixed
W (1120226) mesh_hand: Triggering DYNAMIC MESH handover
>>>mesh_wifi_event_cb,8045
I (1120236) mesh: WIFI_EVENT_SCAN_DONE, non-root
I (1120236) mesh: WIFI_EVENT_SCAN_DONE, last:WIFI_EVENT_SCAN_DONE[STOP], reason:0
>>>mesh_wifi_event_cb,8063
I (1120246) mesh: <WIFI_EVENT_SCAN_DONE>status:fail, num:0, id:141
>>>mesh_wifi_event_cb,8387, new_state = 7
W (1120256) wifi:scan number is 0
I (1120266) mesh: [SCAN][ch:11]AP:0, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:2,i:2][d2:0f:7d:8a:8b:29]<>
I (1120276) mesh: [FAIL][1]root:0, fail:1, normal:0, <pre>backoff:0
----- skip some logs -----
I (1159116) mesh: [DONE]connect to router:KI, channel:11, rssi:-12, d2:0f:7d:8a:8b:29[layer:0, assoc:0], my_vote_num:2/voter_num:2,rc[7c:df:a1:e1:6a:d9/-34/2]
I (1159216) wifi:new:<11,2>, old:<11,2>, ap:<11,2>, sta:<11,0>, prof:11
I (1159706) wifi:state: init -> auth (b0)
I (1159716) wifi:state: auth -> assoc (0)
I (1159726) wifi:state: assoc -> run (10)
I (1159836) wifi:connected with KI, aid = 1, channel 11, BW20, bssid = d2:0f:7d:8a:8b:29
I (1159836) wifi:security: WPA2-PSK, phy: bgn, rssi: -26
I (1159846) wifi:pm start, type: 0
I (1159846) wifi:set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 0, mt_pti: 25000, mt_time: 10000
I (1159906) mesh_main: <MESH_EVENT_PARENT_CONNECTED>layer:2-->1, parent:d2:0f:7d:8a:8b:29<ROOT>, ID:77:77:77:77:77:76
dhcps: handle_dhcp-> receive a packet
dhcps: handle_dhcp malloc_len=548 rx_len=308dhcps: handle_dhcp-> p->tot_len = 308
dhcps: handle_dhcp-> p->len = 308
dhcps: handle_dhcp-> parse_msg(p)
dhcps: len = 68
dhcps: (s16_t)*optptr = 53
dhcps: (s16_t)*optptr = 57
dhcps: (s16_t)*optptr = 12
dhcps: (s16_t)*optptr = 61
dhcps: (s16_t)*optptr = 55
dhcps: (s16_t)*optptr = 255
dhcps: DHCPD_STATE_OFFER
dhcps: return s.state = 1
dhcps: xid changed
dhcps: client_address.addr = 200000a
dhcps: handle_dhcp-> DHCPD_STATE_OFFER
udhcp: send_offer>>p->ref = 1
dhcps: send_offer>>pbuf_alloc succeed
dhcps: send_offer>>p->tot_len = 548
dhcps: send_offer>>p->len = 548
dhcps: send_offer>>udp_sendto result 0
udhcp: send_offer>>free pbuf
dhcps: handle_dhcp-> pbuf_free(p)
I (1161816) mesh_netif: Root received: from: ff:ff:ff:ff:ff:ff to 7c:df:a1:e2:a3:04 size: 350
dhcps: handle_dhcp-> receive a packet
dhcps: handle_dhcp malloc_len=548 rx_len=308dhcps: handle_dhcp-> p->tot_len = 308
dhcps: handle_dhcp-> p->len = 308
dhcps: handle_dhcp-> parse_msg(p)
dhcps: len = 68
dhcps: (s16_t)*optptr = 53
dhcps: (s16_t)*optptr = 57
dhcps: (s16_t)*optptr = 50
dhcps: DHCP_OPTION_REQ_IPADDR = 0 ok
dhcps: (s16_t)*optptr = 61
dhcps: (s16_t)*optptr = 54
dhcps: (s16_t)*optptr = 55
dhcps: (s16_t)*optptr = 12
dhcps: (s16_t)*optptr = 255
dhcps: return s.state = 3
dhcps: xid changed
dhcps: client_address.addr = 200000a
dhcps: handle_dhcp-> DHCPD_STATE_ACK
udhcp: send_ack>>p->ref = 1
dhcps: send_ack>>pbuf_alloc succeed
dhcps: send_ack>>p->tot_len = 548
dhcps: send_ack>>p->len = 548

device1:
W (2039649) mesh_hand: Triggering DYNAMIC MESH handover
I (2039649) mesh: [IO]enable self-organizing, search parent<reconnect>
I (2039659) mesh: mesh_schedule.c 2533 null args
>>>wifi_event_post,2241
I (2039659) mesh: [IO]enable self-organizing, search parent<adaptive>
W (2039669) mesh_hand: scan_done: found 0, fixed_root 0, has_parent 0
I (2039669) mesh: <MESH_NWK_SCAN_REQ_PASSIVE>unexpected, unprocessed previous scan by parent selection
W (2039679) mesh_hand: All nodes have bad connection, allow any RSSI.
I (2039689) mesh_main: <MESH_EVENT_ROOT_FIXED>not fixed
W (2039699) mesh_hand: Triggering DYNAMIC MESH handover
>>>mesh_wifi_event_cb,8045
I (2039709) mesh: WIFI_EVENT_SCAN_DONE, non-root
I (2039709) mesh: WIFI_EVENT_SCAN_DONE, last:WIFI_EVENT_SCAN_DONE[STOP], reason:2
>>>mesh_wifi_event_cb,8063
I (2039719) mesh: <WIFI_EVENT_SCAN_DONE>status:fail, num:0, id:136
>>>mesh_wifi_event_cb,8387, new_state = 7
W (2039729) wifi:scan number is 0
I (2039729) mesh: [SCAN][ch:11]AP:0, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][00:00:00:00:00:00]<>
I (2039749) mesh: [FAIL][1]root:0, fail:1, normal:0, <pre>backoff:0
---------- skip some logs ----------
I (2080499) mesh: [DONE]connect to parent:ESPM_E16AD8, channel:11, rssi:-18, 7c:df:a1:e1:6a:d9[layer:1, assoc:0], my_vote_num:0/voter_num:0, rc[00:00:00:00:00:00/-26/2]
I (2080699) wifi:new:<11,2>, old:<11,2>, ap:<11,2>, sta:<11,2>, prof:11
I (2081279) wifi:state: init -> auth (b0)
I (2081289) wifi:state: auth -> assoc (0)
I (2081309) wifi:state: assoc -> run (10)
>>>mesh_wifi_event_cb,8045
I (2081309) mesh: WIFI_EVENT_MESH_IE_CHANGE, non-root
I (2081309) mesh: WIFI_EVENT_MESH_IE_CHANGE, last:WIFI_EVENT_SCAN_DONE[STOP], reason:2
>>>mesh_wifi_event_cb,8063
>>>mesh_wifi_event_cb,8387, new_state = 20
I (2081319) mesh: <MESH_NWK_MIE_CHANGE><><><><><ROOT LOST><><>
I (2081329) mesh_main: <MESH_EVENT_NETWORK_STATE>is_rootless:0
I (2081329) wifi:connected with ESPM_E16AD8, aid = 1, channel 11, 40D, bssid = 7c:df:a1:e1:6a:d9
I (2081349) wifi:security: WPA2-PSK, phy: bgn, rssi: -15
I (2081349) wifi:pm start, type: 0

I (2081349) wifi:set rx beacon pti, rx_bcn_pti: 0, bcn_timeout: 0, mt_pti: 25000, mt_time: 10000
>>>wifi_event_post,2241
>>>mesh_wifi_event_cb,8045
I (2081369) mesh: WIFI_EVENT_STA_CONNECTED, non-root
I (2081369) mesh: WIFI_EVENT_STA_CONNECTED, last:WIFI_EVENT_MESH_IE_CHANGE[STOP], reason:2
>>>mesh_wifi_event_cb,8063
>>>mesh_wifi_event_cb,8387, new_state = 9
dhcp_discover(): dhcp state is DISCOVER
I (2081389) mesh: 2004<arm>parent monitor, my layer:2(cap:6)(node), interval:8587ms, retries:1<normal connected>
I (2081399) mesh_main: <MESH_EVENT_PARENT_CONNECTED>layer:1-->2, parent:7c:df:a1:e1:6a:d9<layer2>, ID:77:77:77:77:77:76
dhcp_release_and_stop(): dhcp state is OFF
I (2081409) mesh_netif: It was a wifi station removing stuff
E (2081409) ping_sock: send error=0
W (2081419) esp_netif_lwip: esp_netif_start_api 0x3fced6e0
dhcp_discover(): dhcp state is DISCOVER
I (2081449) wifi:<ba-add>idx:0 (ifx:0, 7c:df:a1:e1:6a:d9), tid:5, ssn:0, winSize:64
W (2081459) mesh_hand: Start checking DYNAMIC ROOT delayed tasks
W (2081459) mesh_main: <MESH_EVENT_TODS_REACHABLE>state:0
dhcp_select(): dhcp state is REQUESTING
I (2081629) wifi:AP's beacon interval = 307200 us, DTIM period = 1
I (2081649) mesh: 5122<assoc>parent layer:1, channel:11, rssi:-15, assoc:1, rssi threshold<-78,-82,-85>
dhcp_check(): dhcp state is CHECKING
dhcp_check(): dhcp state is CHECKING
I (2082459) mesh_main: <IP_EVENT_STA_GOT_IP>IP:<IP_ADDRESS>

@KonssnoK when the dhcp discover loop issue happen, the dhcp server can send dhcp offer successfully, but the dhcp client didn't respond, can you open the dhcp debug log by enabling the menuconfig Component config -> LWIP -> Enable LWIP Debug -> Enable DHCP state tracking/Enable DHCP debug messages ?

@zhangyanjiaoesp here are the logs of dhcp from dev3 stuck
240711dev3_1.txt
240711dev1_1.txt

this log adds dumped interface packets, but there are no corrupted packet received in this case
240711dev1_2.txt
240711dev3_2.txt

i recreated the issue,
this time i had also wireshark monitoring and no crypto functions
240711dev3_3.txt
240711dev1_3.txt
wireshark
0711run3.txt

@zhangyanjiaoesp i think the packet sent as answer to the discovery request is not sent out from the device

I (555790) esp_netif_lwip: SENDW        sta  590 FFFFFFFFFFFF7CDFA1E2A304080045000240031600004011116AC0A8A385FFFFFFFFCED40044022C1236020106009309D11200008000000000000A00000200000000000000007CDFA1E16AD800000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000638253633501020104FFFF0000330400001C2036040A00000103040A0000010604C0A8A35A1C040A00FFFF1A0205DC1F01002B06010400000002FF00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000
I (555860) mesh_main: Tried to publish layer:1 IP:<IP_ADDRESS>

i can't see a broadcast with size higher than 500B in the wireshark logs.
This goes well with my theory that the dhcps_pcb is not working properly

@KonssnoK what about you close the AMPDU TX/RX in the menuconfig ?

@zhangyanjiaoesp
I did that... i was able to trigger again an infinite counter loop 😱
240711dev3_4.txt
and you can see the timeouts every 30 seconds, so that is not what is blocking the mesh anymore

here is the error again without AMPDU
240711dev1_5.txt
240711dev3_5.txt
pcap is too big for github
.pcapng

@zhangyanjiaoesp I did that... i was able to trigger again an infinite counter loop 😱
240711dev3_4.txt
and you can see the timeouts every 30 seconds, so that is not what is blocking the mesh anymore

When the loop happen, the device receive deauth packet, and disconnect from parent, but the mesh didn't handle the MESH_EVENT_PARENT_DISCONNECTED event.
I (73876) wifi:state: run -> init (6c0)
>>>iee>>>2e1__to__pr_cest_,isc
ate,3718638, st,_n, _)
>>>cnx_sta_leave,2006
I (73886) wifi:pm stop, total sleep time: 0 us / 6142472 us

I (73886) wifi:new:<11,0>, old:<11,2>, ap:<11,2>, sta:<11,2>, prof:11
>>>ieee80211_sta_new_state,559, post disconnect evt
>>>wifi_event_post,2241
I (74206) mesh: 5162<active>parent layer:1(node), channel:11, rssi:-15, assoc:0(cnx rssi threshold:-120)my_assoc:0
I (74456) mesh_main: Tried to publish layer:2 IP:<IP_ADDRESS>
I (74456) mesh_mqtt: sent publish returned msg_id=23785
W (75086) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:69, no_wnd_count:0, timeout_count:0
>>>mesh_xon_process_disconnected,2638, (1, 1, 0)
>>>wifi_event_post,2241

In normal case, the log should be:
>>I (59396) wifi:state: run -> init (6c0)
>>>ieee80211_sta_new_state,253
>>>ieee80211_sta_new_state,371
>>>cnx_sta_leave,2006
I (59406) wifi:pm stop, total sleep time: 0 us / 11945616 us
I (59416) wifi:new:<11,0>, old:<11,2>, ap:<11,2>, sta:<11,2>, prof:11
>>>ieee80211_sta_new_state,559, post disconnect evt
>>>wifi_event_post,2241
>mesh_wifi_event_cb,8063
>>>mesh_wifi_event_cb,8387, new_state = 7
>>>mesh_wifi_event_cb,8045
I (59436) mesh: WIFI_EVENT_STA_DISCONNECTED, non-root
I (59456) mesh: WIFI_EVENT_STA_DISCONNECTED, last:WIFI_EVENT_SCAN_DONE[STOP], reason:2
>>>mesh_wifi_event_cb,8161
>>>mesh_wifi_event_cb,8387, new_state = 10
I (59486) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:6
I (59486) mesh: [wifi]disconnected reason:6(non-authenticated STA), continuous:1/max:12, non-root, vote(,stopped)<><>
I (59496) wifi:new:<11,2>, old:<11,0>, ap:<11,2>, sta:<11,2>, prof:11
W (60036) mesh: [mesh_schedule.c,3132] [WND-RX]max_wnd:2, 1200 ms timeout, seqno:0, xseqno:61, no_wnd_count:0, timeout_count:4
>>>mesh_xon_process_disconnected,2638, (0, 1, 0)
I (60036) mesh: <drop>drop packet, disconnected
E (60036) mesh_netif: Send with err code 16395 ESP_ERR_MESH_DISCONNECTED

In the pcap file, the data packets after wifi connection is encrypted, you can refer this to set the wireshark, thus the dhcp packets can be shown in plaintext in the captures.

@KonssnoK Please set the wireshark to decrypt the 802.11 packets, because if we cannot see the decrypted data packet, we cannot obtain useful information from the captured packets.

here,
there is only 1 dhcp discovery request in the pcap, which is when i reset the child device.
No answer nor new discoveries are registered by wireshark
.pcapng
0712run1.txt
240712dev1_1.txt
240712dev3_1.txt

@zhangyanjiaoesp
one thing that was not clear is the fact that the AP of the mesh are in the form of "ESPM_" and apparently wireshark cannot decrypt by putting only the password.
Here are the decrypted packets
240712dev3_2.txt
240712dev1_2.txt
.pcapng
0712run2.txt

@zhangyanjiaoesp
the code of DHCPS is quite anonymous ... from what i understand, it works by using the same buffer for request and reply.
At the same time the transaction id is not touched in the code, meaning whatever is received should be sent back
    m->hops = 0;
//        os_memcpy((char *) xid, (char *) m->xid, sizeof(m->xid));
    m->secs = 0;