espressif / esp-idf

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

esp_mesh_send() is blocked forever in router-less environment (IDFGH-5330) #7084

Closed dshil closed 3 years ago

dshil commented 3 years ago

Environment

Problem Description

I am experimenting with router-less setup. I use examples/mesh/internal_communication almost unmodified. The only difference is that in main function during the initialization phase I added the following lines:

    bool root = false;
    if (root) {
      ESP_ERROR_CHECK_WITHOUT_ABORT(esp_mesh_set_type(MESH_ROOT));
    } else {
      ESP_ERROR_CHECK_WITHOUT_ABORT(esp_mesh_fix_root(true));
    }

and I commented the following lines:

    /* router */
    cfg.channel = CONFIG_MESH_CHANNEL;
    cfg.router.ssid_len = strlen(CONFIG_MESH_ROUTER_SSID);
    memcpy((uint8_t *) &cfg.router.ssid, CONFIG_MESH_ROUTER_SSID, cfg.router.ssid_len);
    memcpy((uint8_t *) &cfg.router.password, CONFIG_MESH_ROUTER_PASSWD,
           strlen(CONFIG_MESH_ROUTER_PASSWD));

and put esp_mesh_comm_p2p_start() into the following block:

    switch (event_id) {
    case MESH_EVENT_STARTED: {
        esp_mesh_get_id(&id);
        ESP_LOGI(MESH_TAG, "<MESH_EVENT_MESH_STARTED>ID:"MACSTR"", MAC2STR(id.addr));
        is_mesh_connected = false;
        mesh_layer = esp_mesh_get_layer();

        esp_mesh_comm_p2p_start();
    }

For one device I set root variable to true and for another one is to false. Thus I have 1 root and 1 node element in the mesh network. All other parts of the code are untouched. When I start the mesh network devices are recognized by each other:

Root

ESPPORT=/dev/ttyUSB1  pmake monitor
Note: idf_monitor.py will attempt to set baud rate automatically. To specify a baud rate, set the ESPBAUD environment variable.
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:4
load:0x3fff0034,len:7084
load:0x40078000,len:13704
load:0x40080400,len:4000
entry 0x40080688
I (29) boot: ESP-IDF v4.2-beta1-dirty 2nd stage bootloader
I (29) boot: compile time 14:53:38
I (29) boot: chip revision: 1
I (33) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (40) boot.esp32: SPI Speed      : 40MHz
I (44) boot.esp32: SPI Mode       : DIO
I (49) boot.esp32: SPI Flash Size : 2MB
I (54) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (63) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) boot_comm: chip revision: 1, min. application chip revision: 0
I (104) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1a0c8 (106696) map
I (153) esp_image: segment 1: paddr=0x0002a0f0 vaddr=0x3ffb0000 size=0x03880 ( 14464) load
I (159) esp_image: segment 2: paddr=0x0002d978 vaddr=0x40080000 size=0x00404 (  1028) load
I (160) esp_image: segment 3: paddr=0x0002dd84 vaddr=0x40080404 size=0x02294 (  8852) load
I (173) esp_image: segment 4: paddr=0x00030020 vaddr=0x400d0020 size=0x9d60c (644620) map
I (423) esp_image: segment 5: paddr=0x000cd634 vaddr=0x40082698 size=0x13444 ( 78916) load
I (469) boot: Loaded app from partition at offset 0x10000
I (469) boot: Disabling RNG early entropy source...
I (470) cpu_start: Pro cpu up.
I (473) cpu_start: Application information:
I (478) cpu_start: Project name:     internal_communication
I (485) cpu_start: App version:      v4.4-dev-1404-gc13afea63-dirty
I (492) cpu_start: Compile time:     May 28 2021 14:54:01
I (498) cpu_start: ELF file SHA256:  a4519c345ae02a82...
I (504) cpu_start: ESP-IDF:          v4.2-beta1-dirty
I (509) cpu_start: Starting app cpu, entry point is 0x400815e4
I (0) cpu_start: App cpu up.
I (520) heap_init: Initializing. RAM available for dynamic allocation:
I (527) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (533) heap_init: At 3FFBAC90 len 00025370 (148 KiB): DRAM
I (539) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (545) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (552) heap_init: At 40095ADC len 0000A524 (41 KiB): IRAM
I (558) cpu_start: Pro cpu start user code
I (576) spi_flash: detected chip: generic
I (577) spi_flash: flash io: dio
W (577) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (587) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (753) wifi:wifi driver task: 3ffc38e0, prio:23, stack:6656, core=0
I (753) system_api: Base MAC address is not set
I (753) system_api: read default base MAC address from EFUSE
I (773) wifi:wifi firmware version: 8ee1f07
I (773) wifi:wifi certification version: v7.0
I (773) wifi:config NVS flash: enabled
I (773) wifi:config nano formating: disabled
I (783) wifi:Init data frame dynamic rx buffer num: 32
I (783) wifi:Init management frame dynamic rx buffer num: 32
I (793) wifi:Init management short buffer num: 32
I (793) wifi:Init dynamic tx buffer num: 32
I (803) wifi:Init static rx buffer size: 1600
I (803) wifi:Init static rx buffer num: 10
I (803) wifi:Init dynamic rx buffer num: 32
I (903) phy: phy_version: 4370, 4e803b3, Aug 11 2020, 14:18:07, 0, 0
D (903) wifi:filter: set rx policy=0
I (903) wifi:mode : sta (24:6f:28:f0:10:80) + softAP (24:6f:28:f0:10:81)
D (903) wifi:filter: set rx policy=1
D (903) wifi:connect status 0 -> 0
D (913) wifi:filter: set rx policy=9
I (913) wifi:Total power save buffer number: 16
I (923) wifi:Init max length of beacon: 752/752
I (923) wifi:Init max length of beacon: 752/752
I (933) mesh: <nvs>read layer:0, err:0x1102
I (933) mesh: <nvs>read assoc:0, err:0x1102
I (933) wifi:Set ps type: 1

I (933) mesh: [IO]disable self-organizing<reconnect>
I (943) mesh: [CONFIG]invalid router settings, ssid_len:0, ssid:, bssid:00:00:00:00:00:00
D (953) wifi:filter: set rx policy=10
D (953) wifi:filter: set rx policy=9
I (963) wifi:Total power save buffer number: 16
D (993) wifi:ap recv deauth/disassoc from sta ff:ff:ff:ff:ff:ff, reason:14
D (1023) wifi:ap recv assoc/reassoc request
I (1023) wifi:new:<1,1>, old:<1,1>, ap:<1,1>, sta:<0,0>, prof:1
D (1023) wifi:bss=0x3ffca2cc, resp=16 join
I (1023) wifi:station: 24:6f:28:f0:0d:5c join, AID=1, bgn, 40U
D (1033) wifi:join success, ap send assoc response
D (1703) wifi:connect status 0 -> 0
D (1703) wifi:filter: set rx policy=8
I (1703) wifi:station: 24:6f:28:f0:0d:5c leave, AID = 1, bss_flags is 134243, bss:0x3ffca2cc
I (1713) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<0,0>, prof:1
I (1723) wifi:Set ps type: 0

I (1723) mesh: (api)not connect, layer:-1, nwk_change_reason:1
I (1723) wifi:(api)new network duty, type:request, update:0, nwk[duty:12, duration_mins:-1, rule:0, master(00:00:00:00:00:00)], root_nwk_duty:12, running:100

I (1733) mesh_main: <MESH_EVENT_MESH_STARTED>ID:77:77:77:77:77:77
I (1733) mesh: [MANUAL]designated as root and router is not set
W (1743) mesh_main: [#RX:1/1][L:1] parent:00:00:00:00:00:00, receive from 24:6f:28:f0:10:80, size:1460, heap:165076, flag:0[err:0x0, proto:0, tos:0]
I (1753) wifi:(api)set device duty, type:request, duty:10, nwk[duty:12, duration_mins:-1, rule:0, master(00:00:00:00:00:00)], root_nwk_duty:12, running:100
I (1773) mesh: (api)not connect, layer:1, nwk_change_reason:1
I (1783) wifi:(api)new network duty, type:request, update:0, nwk[duty:10, duration_mins:-1, rule:0, master(00:00:00:00:00:00)], root_nwk_duty:12, running:100

I (1803) mesh_main: mesh starts successfully, heap:163980, root fixed<0>(tree), ps:1

D (1803) wifi:ap recv assoc/reassoc request
I (1813) wifi:new:<1,1>, old:<1,0>, ap:<1,1>, sta:<0,0>, prof:1
D (1813) wifi:bss=0x3ffd7404, resp=16 join
I (1823) wifi:station: 24:6f:28:f0:0d:5c join, AID=1, bgn, 40U
D (1823) wifi:join success, ap send assoc response
I (1833) mesh_main: <MESH_EVENT_PS_CHILD_DUTY>cidx:0, 24:6f:28:f0:0d:5c, duty:10
W (1853) mesh_main: <MESH_EVENT_ROUTING_TABLE_ADD>add 1, new:2, layer:1
I (1853) mesh_main: <MESH_EVENT_CHILD_CONNECTED>aid:1, 24:6f:28:f0:0d:5c
W (2743) mesh_main: [#RX:2/2][L:1] parent:00:00:00:00:00:00, receive from 24:6f:28:f0:10:80, size:1460, heap:163980, flag:0[err:0x0, proto:0, tos:0]
D (4673) wifi:ap recv deauth/disassoc from sta 24:6f:28:f0:0d:5c, reason:8
I (4673) wifi:station: 24:6f:28:f0:0d:5c leave, AID = 1, bss_flags is 134243, bss:0x3ffd7404
I (4673) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<0,0>, prof:1
I (4683) wifi:(master)rmv_child_num:1, (0)24:6f:28:f0:0d:5d, (master)00:00:00:00:00:00
I (4693) mesh_main: <MESH_EVENT_CHILD_DISCONNECTED>aid:1, 24:6f:28:f0:0d:5c
I (4693) mesh: [scan]new scanning time:600ms, beacon interval:500ms
W (4693) mesh_main: <MESH_EVENT_ROUTING_TABLE_REMOVE>remove 1, new:1, layer:1
D (13073) wifi:ap recv deauth/disassoc from sta ff:ff:ff:ff:ff:ff, reason:3
D (13083) wifi:ap recv assoc/reassoc request
I (13083) wifi:new:<1,1>, old:<1,0>, ap:<1,1>, sta:<0,0>, prof:1
D (13083) wifi:bss=0x3ffbc29c, resp=16 join
I (13083) wifi:station: 24:6f:28:f0:0d:5c join, AID=1, bgn, 40U
D (13093) wifi:join success, ap send assoc response
I (13103) mesh_main: <MESH_EVENT_PS_CHILD_DUTY>cidx:0, 24:6f:28:f0:0d:5c, duty:10
W (13113) mesh_main: <MESH_EVENT_ROUTING_TABLE_ADD>add 1, new:2, layer:1
I (13113) mesh_main: <MESH_EVENT_CHILD_CONNECTED>aid:1, 24:6f:28:f0:0d:5c

Node

ESPPORT=/dev/ttyUSB0  pmake monitor
Note: idf_monitor.py will attempt to set baud rate automatically. To specify a baud rate, set the ESPBAUD environment variable.
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:4
load:0x3fff0034,len:7084
load:0x40078000,len:13704
load:0x40080400,len:4000
entry 0x40080688
I (29) boot: ESP-IDF v4.2-beta1-dirty 2nd stage bootloader
I (29) boot: compile time 14:53:38
I (29) boot: chip revision: 1
I (33) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (40) boot.esp32: SPI Speed      : 40MHz
I (44) boot.esp32: SPI Mode       : DIO
I (49) boot.esp32: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) boot_comm: chip revision: 1, min. application chip revision: 0
I (103) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1a0c8 (106696) map
I (153) esp_image: segment 1: paddr=0x0002a0f0 vaddr=0x3ffb0000 size=0x03880 ( 14464) load
I (159) esp_image: segment 2: paddr=0x0002d978 vaddr=0x40080000 size=0x00404 (  1028) load
I (160) esp_image: segment 3: paddr=0x0002dd84 vaddr=0x40080404 size=0x02294 (  8852) load
I (173) esp_image: segment 4: paddr=0x00030020 vaddr=0x400d0020 size=0x9d5bc (644540) map
I (423) esp_image: segment 5: paddr=0x000cd5e4 vaddr=0x40082698 size=0x13444 ( 78916) load
I (469) boot: Loaded app from partition at offset 0x10000
I (469) boot: Disabling RNG early entropy source...
I (470) cpu_start: Pro cpu up.
I (473) cpu_start: Application information:
I (478) cpu_start: Project name:     internal_communication
I (484) cpu_start: App version:      v4.4-dev-1404-gc13afea63-dirty
I (491) cpu_start: Compile time:     May 28 2021 14:54:01
I (497) cpu_start: ELF file SHA256:  97eb604036c4c933...
I (503) cpu_start: ESP-IDF:          v4.2-beta1-dirty
I (509) cpu_start: Starting app cpu, entry point is 0x400815e4
I (0) cpu_start: App cpu up.
I (520) heap_init: Initializing. RAM available for dynamic allocation:
I (526) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (533) heap_init: At 3FFBAC90 len 00025370 (148 KiB): DRAM
I (539) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (545) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (552) heap_init: At 40095ADC len 0000A524 (41 KiB): IRAM
I (558) cpu_start: Pro cpu start user code
I (576) spi_flash: detected chip: generic
I (577) spi_flash: flash io: dio
W (577) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (587) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (733) wifi:wifi driver task: 3ffc38e0, prio:23, stack:6656, core=0
I (733) system_api: Base MAC address is not set
I (733) system_api: read default base MAC address from EFUSE
I (753) wifi:wifi firmware version: 8ee1f07
I (753) wifi:wifi certification version: v7.0
I (753) wifi:config NVS flash: enabled
I (753) wifi:config nano formating: disabled
I (763) wifi:Init data frame dynamic rx buffer num: 32
I (763) wifi:Init management frame dynamic rx buffer num: 32
I (773) wifi:Init management short buffer num: 32
I (773) wifi:Init dynamic tx buffer num: 32
I (783) wifi:Init static rx buffer size: 1600
I (783) wifi:Init static rx buffer num: 10
I (783) wifi:Init dynamic rx buffer num: 32
I (883) phy: phy_version: 4370, 4e803b3, Aug 11 2020, 14:18:07, 0, 0
I (883) wifi:mode : sta (24:6f:28:f0:0d:5c) + softAP (24:6f:28:f0:0d:5d)
I (883) wifi:Total power save buffer number: 16
I (883) wifi:Init max length of beacon: 752/752
I (893) wifi:Init max length of beacon: 752/752
I (903) mesh: <nvs>read layer:0, err:0x1102
I (903) mesh: <nvs>read assoc:0, err:0x1102
I (903) wifi:Set ps type: 1

I (903) mesh: [CONFIG]invalid router settings, ssid_len:0, ssid:, bssid:00:00:00:00:00:00
I (923) wifi:Total power save buffer number: 16
I (1643) wifi:mode : sta (24:6f:28:f0:0d:5c)
I (1643) mesh_main: <MESH_EVENT_MESH_STARTED>ID:77:77:77:77:77:77
I (1643) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x2, need_scan_router:0x0, look_for_nwk_count:0
I (1643) wifi:(api)set device duty, type:request, duty:10, nwk[duty:12, duration_mins:-1, rule:0, master(00:00:00:00:00:00)], root_nwk_duty:12, running:12I (1643) mesh_main: layer:-1, rtableSize:1, DISCONNECT

I (1673) mesh: (api)not connect, layer:-1, nwk_change_reason:1
I (1673) wifi:(api)new network duty, type:request, update:0, nwk[duty:10, duration_mins:-1, rule:0, master(00:00:00:00:00:00)], root_nwk_duty:12, running:10

I (1693) mesh_main: mesh starts successfully, heap:168856, root fixed<0>(tree), ps:1

I (8183) mesh: find root:ESPM_F01080, root_cap:1(max:300), new channel:1, old channel:0
I (8183) mesh: [FIND][ch:0]AP:17, otherID:0, MAP:1, idle:0, candidate:0, root:1[00:00:00:00:00:00][FIXED-ROOT]
I (8183) mesh: [FIND:1]find a network, channel:1, cfg<channel:0, router:, 00:00:00:00:00:00>

I (8193) wifi:mode : sta (24:6f:28:f0:0d:5c) + softAP (24:6f:28:f0:0d:5d)
W (8203) wifi:<MESH AP>adjust channel:1, secondary channel offset:1(40U)
I (8213) wifi:Total power save buffer number: 16
I (8193) mesh_main: <MESH_EVENT_FIND_NETWORK>new channel:1, router BSSID:00:00:00:00:00:00
I (8513) mesh: [SCAN][ch:1]AP:3, other(ID:0, RD:0), MAP:1, idle:0, candidate:1, root:1, topMAP:0[c:0,i:0][00:00:00:00:00:00][FIXED-ROOT]<>
I (8513) mesh: 7333[selection]try rssi_threshold:-78, backoff times:0, max:5<-78,-82,-85>
I (8523) mesh: [DONE]connect to parent:ESPM_F01080, channel:1, rssi:-37, 24:6f:28:f0:10:81[layer:1, assoc:0], my_vote_num:0/voter_num:0, rc[00:00:00:00:00:00/-120/0]
I (10043) wifi:new:<1,1>, old:<1,1>, ap:<1,1>, sta:<1,1>, prof:1
I (10043) wifi:state: init -> auth (b0)
I (10043) wifi:state: auth -> assoc (0)
I (10073) wifi:state: assoc -> run (10)
I (10073) mesh: <MESH_NWK_MIE_CHANGE><><><><ROOT ADDR><><><>
I (10073) mesh: <MESH_NWK_ROOT_ADDR>from assoc, layer:2, root_addr:24:6f:28:f0:10:81, root_cap:1
I (10073) mesh: <MESH_NWK_ROOT_ADDR>idle, layer:2, root_addr:24:6f:28:f0:10:81, conflict_roots.num:0<>
I (10083) wifi:connected with ESPM_F01080, aid = 1, channel 1, 40U, bssid = 24:6f:28:f0:10:81
I (10093) wifi:security: WPA2-PSK, phy: bgn, rssi: -37
I (10103) mesh_main: <MESH_EVENT_ROOT_ADDRESS>root address:24:6f:28:f0:10:81
I (10103) wifi:Set ps type: 1

I (10103) mesh: [scan]new scanning time:600ms, beacon interval:500ms
I (10113) mesh: 1990<arm>parent monitor, my layer:2(cap:6)(node), interval:7574ms, retries:1<normal connected>
I (10123) mesh_main: <MESH_EVENT_PARENT_CONNECTED>layer:0-->2, parent:24:6f:28:f0:10:81<layer2>, ID:77:77:77:77:77:77, duty:0
I (10133) mesh_main: <MESH_EVENT_TODS_REACHABLE>state:0
I (10143) mesh_main: <MESH_EVENT_ROOT_ADDRESS>root address:24:6f:28:f0:10:81
I (11673) mesh_main: layer:2, rtableSize:1, NODE
I (12473) wifi:pm start, type: 1

I (12773) wifi:(tbtt)new duty:10, tsf offset:3081us
I (12983) wifi:AP's beacon interval = 512000 us, DTIM period = 1
I (17883) mesh: 5118<active>parent layer:1(node), channel:1, rssi:-37, assoc:0(cnx rssi threshold:-120)my_assoc:0
I (19383) mesh: 5909<scan>parent layer:1, rssi:-38, assoc:1(cnx rssi threshold:-120)
I (19383) mesh: [SCAN][ch:1]AP:1, other(ID:0, RD:0), MAP:1, idle:0, candidate:1, root:1, topMAP:0[c:2,i:2][00:00:00:00:00:00][FIXED-ROOT]<weak>
I (19393) mesh: 7333[weak]try rssi_threshold:-120, backoff times:0, max:5<-78,-82,-85>
I (19403) mesh: 701[monitor]no change, parent:24:6f:28:f0:10:81, rssi:-38
I (19403) mesh: 1990<arm>parent monitor, my layer:2(cap:6)(node), interval:7663ms, retries:2<>
I (21673) mesh_main: layer:2, rtableSize:1, NODE
I (27263) mesh: 5118<active>parent layer:1(node), channel:1, rssi:-37, assoc:1(cnx rssi threshold:-120)my_assoc:0
I (28763) mesh: 5909<scan>parent layer:1, rssi:-37, assoc:1(cnx rssi threshold:-120)
I (28763) mesh: [SCAN][ch:1]AP:1, other(ID:0, RD:0), MAP:1, idle:0, candidate:1, root:1, topMAP:0[c:0,i:2][00:00:00:00:00:00][FIXED-ROOT]<weak>
I (28773) mesh: 7333[weak]try rssi_threshold:-120, backoff times:0, max:5<-78,-82,-85>
I (28783) mesh: 701[monitor]no change, parent:24:6f:28:f0:10:81, rssi:-37
I (28793) mesh: 1990<arm>parent monitor, my layer:2(cap:6)(node), interval:11049ms, retries:3<>
I (31673) mesh_main: layer:2, rtableSize:1, NODE
I (40113) mesh: 5118<active>parent layer:1(node), channel:1, rssi:-37, assoc:1(cnx rssi threshold:-120)my_assoc:0
I (41613) mesh: 5909<scan>parent layer:1, rssi:-36, assoc:1(cnx rssi threshold:-120)
I (41613) mesh: [SCAN][ch:1]AP:1, other(ID:0, RD:0), MAP:1, idle:0, candidate:1, root:1, topMAP:0[c:2,i:2][00:00:00:00:00:00][FIXED-ROOT]<weak>
I (41623) mesh: 7333[weak]try rssi_threshold:-120, backoff times:0, max:5<-78,-82,-85>
I (41633) mesh: 701[monitor]no change, parent:24:6f:28:f0:10:81, rssi:-36
I (41643) mesh: 1990<arm>parent monitor, my layer:2(cap:6)(node), interval:380088ms, retries:3<>
I (41673) mesh_main: layer:2, rtableSize:1, NODE
I (51673) mesh_main: layer:2, rtableSize:1, NODE
I (61673) mesh_main: layer:2, rtableSize:1, NODE
I (71673) mesh_main: layer:2, rtableSize:1, NODE

Then I added a few logs to clarify the issue:

            ESP_LOGI(MESH_TAG, "before send to= " MACSTR "", MAC2STR(route_table[i].addr));
            err = esp_mesh_send(&route_table[i], &data, MESH_DATA_P2P, NULL, 0);
            ESP_LOGI(MESH_TAG, "after send to= " MACSTR "", MAC2STR(route_table[i].addr));

I expect that root element will send data to each element in the network but instead it was blocked forever.

I (22953) mesh_main: before send to= 24:6f:28:f0:0d:5c
I (122903) mesh: [scan]new scanning time:600ms, beacon interval:1200ms

From the other side when I provide correct router settings all work as expected. Could somebody clarify is it the expected or not? Probably @dongdong004, @ESP-iPENCIL. At the end I want be able to send data from node to root and from root to node without the router.

shenjun7 commented 3 years ago

Please update IDF version to v4.2(d9ec7df3) or v4.3(639e7ad4). All devices in the network shall use esp_mesh_fix_root(true) to keep the same fixed root setting.

dshil commented 3 years ago

Hi @shenjun7 and thanks for your reply. I checkout to v4.3 and apply the same patch mentioned above:

diff --git a/examples/mesh/internal_communication/main/mesh_main.c b/examples/mesh/internal_communication/main/mesh_main.c
index 6275acde3..bf96897de 100644
--- a/examples/mesh/internal_communication/main/mesh_main.c
+++ b/examples/mesh/internal_communication/main/mesh_main.c
@@ -101,7 +101,9 @@ void esp_mesh_p2p_tx_main(void *arg)
         }

         for (i = 0; i < route_table_size; i++) {
-            err = esp_mesh_send(&route_table[i], &data, MESH_DATA_P2P, NULL, 0);
+            ESP_LOGI(MESH_TAG, "before send to= " MACSTR "", MAC2STR(route_table[i].addr));
+            err = esp_mesh_send(&route_table[i], &data, MESH_DATA_NONBLOCK | MESH_DATA_P2P, NULL, 0);
+            ESP_LOGI(MESH_TAG, "after send to= " MACSTR "", MAC2STR(route_table[i].addr));
             if (err) {
                 ESP_LOGE(MESH_TAG,
                          "[ROOT-2-UNICAST:%d][L:%d]parent:"MACSTR" to "MACSTR", heap:%d[err:0x%x, proto:%d, tos:%d]",
@@ -188,6 +190,8 @@ void mesh_event_handler(void *arg, esp_event_base_t event_base,
         ESP_LOGI(MESH_TAG, "<MESH_EVENT_MESH_STARTED>ID:"MACSTR"", MAC2STR(id.addr));
         is_mesh_connected = false;
         mesh_layer = esp_mesh_get_layer();
+
+        esp_mesh_comm_p2p_start();
     }
     break;
     case MESH_EVENT_STOPPED: {
@@ -247,7 +251,6 @@ void mesh_event_handler(void *arg, esp_event_base_t event_base,
         if (esp_mesh_is_root()) {
             esp_netif_dhcpc_start(netif_sta);
         }
-        esp_mesh_comm_p2p_start();
     }
     break;
     case MESH_EVENT_PARENT_DISCONNECTED: {
@@ -399,37 +402,24 @@ void app_main(void)
     ESP_ERROR_CHECK(esp_event_handler_register(IP_EVENT, IP_EVENT_STA_GOT_IP, &ip_event_handler, NULL));
     ESP_ERROR_CHECK(esp_wifi_set_storage(WIFI_STORAGE_FLASH));
     ESP_ERROR_CHECK(esp_wifi_start());
+
     /*  mesh initialization */
     ESP_ERROR_CHECK(esp_mesh_init());
     ESP_ERROR_CHECK(esp_event_handler_register(MESH_EVENT, ESP_EVENT_ANY_ID, &mesh_event_handler, NULL));
-    /*  set mesh topology */
-    ESP_ERROR_CHECK(esp_mesh_set_topology(CONFIG_MESH_TOPOLOGY));
-    /*  set mesh max layer according to the topology */
-    ESP_ERROR_CHECK(esp_mesh_set_max_layer(CONFIG_MESH_MAX_LAYER));
-    ESP_ERROR_CHECK(esp_mesh_set_vote_percentage(1));
-    ESP_ERROR_CHECK(esp_mesh_set_xon_qsize(128));
-#ifdef CONFIG_MESH_ENABLE_PS
-    /* Enable mesh PS function */
-    ESP_ERROR_CHECK(esp_mesh_enable_ps());
-    /* better to increase the associate expired time, if a small duty cycle is set. */
-    ESP_ERROR_CHECK(esp_mesh_set_ap_assoc_expire(60));
-    /* better to increase the announce interval to avoid too much management traffic, if a small duty cycle is set. */
-    ESP_ERROR_CHECK(esp_mesh_set_announce_interval(600, 3300));
-#else
-    /* Disable mesh PS function */
-    ESP_ERROR_CHECK(esp_mesh_disable_ps());
-    ESP_ERROR_CHECK(esp_mesh_set_ap_assoc_expire(10));
-#endif
+
+    ESP_ERROR_CHECK_WITHOUT_ABORT(esp_mesh_fix_root(true));
+
+    bool root = false;
+    if (root) {
+      ESP_ERROR_CHECK_WITHOUT_ABORT(esp_mesh_set_type(MESH_ROOT));
+    } else {
+      ESP_ERROR_CHECK_WITHOUT_ABORT(esp_mesh_set_type(MESH_NODE));
+    }
+
     mesh_cfg_t cfg = MESH_INIT_CONFIG_DEFAULT();
     /* mesh ID */
     memcpy((uint8_t *) &cfg.mesh_id, MESH_ID, 6);
-    /* router */
-    cfg.channel = CONFIG_MESH_CHANNEL;
-    cfg.router.ssid_len = strlen(CONFIG_MESH_ROUTER_SSID);
-    memcpy((uint8_t *) &cfg.router.ssid, CONFIG_MESH_ROUTER_SSID, cfg.router.ssid_len);
-    memcpy((uint8_t *) &cfg.router.password, CONFIG_MESH_ROUTER_PASSWD,
-           strlen(CONFIG_MESH_ROUTER_PASSWD));
-    /* mesh softAP */
     ESP_ERROR_CHECK(esp_mesh_set_ap_authmode(CONFIG_MESH_AP_AUTHMODE));
     cfg.mesh_ap.max_connection = CONFIG_MESH_AP_CONNECTIONS;
     memcpy((uint8_t *) &cfg.mesh_ap.password, CONFIG_MESH_AP_PASSWD,
@@ -437,13 +427,4 @@ void app_main(void)
     ESP_ERROR_CHECK(esp_mesh_set_config(&cfg));
     /* mesh start */
     ESP_ERROR_CHECK(esp_mesh_start());
-#ifdef CONFIG_MESH_ENABLE_PS
-    /* set the device active duty cycle. (default:12, MESH_PS_DEVICE_DUTY_REQUEST) */
-    ESP_ERROR_CHECK(esp_mesh_set_active_duty_cycle(CONFIG_MESH_PS_DEV_DUTY, CONFIG_MESH_PS_DEV_DUTY_TYPE));
-    /* set the network active duty cycle. (default:12, -1, MESH_PS_NETWORK_DUTY_APPLIED_ENTIRE) */
-    ESP_ERROR_CHECK(esp_mesh_set_network_duty_cycle(CONFIG_MESH_PS_NWK_DUTY, CONFIG_MESH_PS_NWK_DUTY_DURATION, CONFIG_MESH_PS_NWK_DUTY_RULE));
-#endif
-    ESP_LOGI(MESH_TAG, "mesh starts successfully, heap:%d, %s<%d>%s, ps:%d\n",  esp_get_minimum_free_heap_size(),
-             esp_mesh_is_root_fixed() ? "root fixed" : "root not fixed",
-             esp_mesh_get_topology(), esp_mesh_get_topology() ? "(chain)":"(tree)", esp_mesh_is_ps_enabled());
 }

Nothing changed, I have the same result, esp_mesh_send is blocked forever even if I setup esp_mesh_fix_root(true) for all devices (root and non-roots) as you suggested previously:

I (3842) wifi:station: 24:6f:28:f0:0d:5c join, AID=1, bgn, 40U
I (3842) mesh_main: <MESH_EVENT_PS_CHILD_DUTY>cidx:0, 24:6f:28:f0:0d:5c, duty:12
W (3862) mesh_main: <MESH_EVENT_ROUTING_TABLE_ADD>add 1, new:2, layer:1
I (3862) mesh_main: <MESH_EVENT_CHILD_CONNECTED>aid:1, 24:6f:28:f0:0d:5c
I (4762) mesh_main: before send to= 24:6f:28:f0:10:80
W (4762) mesh_main: [#RX:4/4][L:1] parent:00:00:00:00:00:00, receive from 24:6f:28:f0:10:80, size:1460, heap:171432, flag:0[err:0x0, proto:0, tos:0]
I (4762) mesh_main: after send to= 24:6f:28:f0:10:80
I (4772) mesh_main: before send to= 24:6f:28:f0:0d:5c
shenjun7 commented 3 years ago

Please tell me the specific commit number.

dshil commented 3 years ago

@shenjun7 I use the same as you suggested, v4.3(639e7ad)

dshil commented 3 years ago

Hi @shenjun7, any updates?

shenjun7 commented 3 years ago

The root cause has been found. We will merge it to master first and then backport to the release/v4.x.

dshil commented 3 years ago

Hi @shenjun7, any news?

shenjun7 commented 3 years ago

The bug has been fixed in gitlab and is waiting to be synchronized to github.

dshil commented 3 years ago

Hi @shenjun7, how long normally does it take for the bug fix to be synchronized with github repo?

Alvin1Zhang commented 3 years ago

Thanks for reporting, and sorry for late reply. Fix on master branch is available https://github.com/espressif/esp-idf/commit/d93849baf86b6de5f08a03ae6aa7006dac58a93b. We are back porting the fix to release/4.3 and release/4.2 branches.

dshil commented 3 years ago

Hi @Alvin1Zhang, thanks for the feedback, very helpful. Is it possible to get an approximate timeline when fix will be available in release branches?

Alvin1Zhang commented 3 years ago

Thanks for reporting, and sorry for late reply. Fix on master branch is available https://github.com/espressif/esp-idf/commit/de92d7e15f1033e7c21050a547820db005a733a9, feel free to reopen if the issue still happens.

dshil commented 3 years ago

Hi @Alvin1Zhang, thanks everybody involved into fixing this issue. I am very appreciate it. Waiting for the back-port to release/v4.2.

Alvin1Zhang commented 2 years ago

@dshil Thanks for reporting and sorry for the very slow turnaround, fix on release/4.2 is available at https://github.com/espressif/esp-idf/commit/f4a2c5b520b621ed2d9e05f0d75112f248c02732 and fix on release/4.3 is https://github.com/espressif/esp-idf/commit/de92d7e15f1033e7c21050a547820db005a733a9.