Mesh level not correct. (AEGHB-903)
Opened this issue · 4 comments
Checklist
- Checked the issue tracker for similar issues to ensure this is not a duplicate
- Read the documentation to confirm the issue is not addressed there and your configuration is set correctly
- Tested with the latest version to ensure the issue hasn't been fixed
How often does this bug occurs?
often
Expected behavior
I have 11 nodes. I make realtime diagram nodes hierachy (every 10 seconds nodes send heartbeat which contains mesh level.
[Number 1] - realtime Mesh Level. In [...] second string - parent node. Help me please.
Thank you!
Actual behavior (suspected bug)
Nodes 404CCA57F03C and 404CCA5E6D48 Mesh Level 1, but have parent Node 5432040C2100. Its problem (((.
Error logs or terminal output
No response
Steps to reproduce the behavior
Mesh build
Project release version
master
System architecture
Intel/AMD 64-bit (modern PC, older Mac)
Operating system
Windows
Operating system version
Windows 11
Shell
CMD
Additional context
No response
What is the mesh lite version (commit) used? Are there logs for Nodes 404CCA57F03C, 404CCA5E6D48 and Node 5432040C2100?
ESP-ROM:esp32c6-20220919
Build:Sep 19 2022
rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x40875720,len:0x1954
load:0x4086c110,len:0x10a4
load:0x4086e610,len:0x3810
entry 0x4086c180
I (23) boot: ESP-IDF v5.3.2-dirty 2nd stage bootloader
I (24) boot: compile time Dec 6 2024 09:31:17
I (24) boot: chip revision: v0.0
I (27) boot: efuse block revision: v0.2
I (32) boot.esp32c6: SPI Speed : 80MHz
I (36) boot.esp32c6: SPI Mode : DIO
I (41) boot.esp32c6: SPI Flash Size : 4MB
I (46) boot: Enabling RNG early entropy source...
I (51) boot: Partition Table:
I (55) boot: ## Label Usage Type ST Offset Length
I (62) boot: 0 sec_cert unknown 3f 06 00009000 00007000
I (69) boot: 1 nvs WiFi data 01 02 00010000 00008000
I (77) boot: 2 otadata OTA data 01 00 00018000 00002000
I (84) boot: 3 phy_init RF data 01 01 0001a000 00001000
I (92) boot: 4 solo WiFi data 01 02 0001b000 00003000
I (99) boot: 5 ota_0 OTA app 00 10 00020000 001db000
I (107) boot: 6 ota_1 OTA app 00 11 00200000 001db000
I (114) boot: 7 fctry WiFi data 01 02 003f8000 00008000
I (122) boot: End of partition table
I (126) esp_image: segment 0: paddr=00200020 vaddr=42150020 size=4d3c0h (316352) map
I (189) esp_image: segment 1: paddr=0024d3e8 vaddr=40800000 size=02c30h ( 11312) load
I (197) esp_image: segment 2: paddr=00250020 vaddr=42000020 size=146168h (1335656) map
I (428) esp_image: segment 3: paddr=00396190 vaddr=40802c30 size=1fbcch (129996) load
I (461) esp_image: segment 4: paddr=003b5d64 vaddr=40822800 size=043b0h ( 17328) load
I (475) boot: Loaded app from partition at offset 0x200000
I (475) boot: Disabling RNG early entropy source...
I (487) cpu_start: Unicore app
I (496) cpu_start: Pro cpu start user code
I (496) cpu_start: cpu freq: 160000000 Hz
I (496) app_init: Application information:
I (499) app_init: Project name: solo_sensor_v1
I (504) app_init: App version: 1.0.2_f4a097d
I (510) app_init: Compile time: Dec 6 2024 16:18:15
I (516) app_init: ELF file SHA256: 38f9e6216...
I (521) app_init: ESP-IDF: v5.3.2-dirty
I (526) efuse_init: Min chip rev: v0.0
I (531) efuse_init: Max chip rev: v0.99
I (536) efuse_init: Chip rev: v0.0
I (541) heap_init: Initializing. RAM available for dynamic allocation:
I (548) heap_init: At 4082F050 len 0004D5C0 (309 KiB): RAM
I (554) heap_init: At 4087C610 len 00002F54 (11 KiB): RAM
I (560) heap_init: At 500018D0 len 00002718 (9 KiB): RTCRAM
I (567) spi_flash: detected chip: generic
I (571) spi_flash: flash io: dio
W (575) spi_flash: Detected size(8192k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (589) sleep: Configure to isolate all GPIO pins in sleep state
I (595) sleep: Enable automatic switching of GPIO sleep configuration
I (602) coexist: coex firmware version: cbb41d7
I (617) coexist: coexist rom version 5b8dcfa
I (617) main_task: Started on CPU0
I (617) main_task: Calling app_main()
I (617) uart: queue free spaces: 20
W (617) dali: Solo ESP32C6 DALI driver initialized
I (1627) led_indicator: LED Indicator Version: 0.9.3
I (1627) gpio: GPIO[8]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
I (1627) led_indicator: Indicator create successfully. type:LED Strips mode, hardware_data:0x40837320, blink_lists:custom
W (1637) main: app_main 138 app_main const heap 300736
W (1647) main: free heap 300736, minimum 300736
I (1657) main: Load SOLO configuration success.
I (1657) bridge_common: esp-iot-bridge version: 0.11.9
I (1657) pp: pp rom version: 5b8dcfa
I (1667) net80211: net80211 rom version: 5b8dcfa
I (1677) wifi:wifi driver task: 4083bdac, prio:23, stack:6656, core=0
I (1677) wifi:wifi firmware version: b0fd6006b
I (1677) wifi:wifi certification version: v7.0
I (1687) wifi:config NVS flash: enabled
I (1687) wifi:config nano formating: disabled
I (1687) wifi:mac_version:HAL_MAC_ESP32AX_761,ut_version:N, band:0x1
I (1697) wifi:Init data frame dynamic rx buffer num: 32
I (1707) wifi:Init static rx mgmt buffer num: 8
I (1707) wifi:Init management short buffer num: 32
I (1707) wifi:Init dynamic tx buffer num: 32
I (1717) wifi:Init static tx FG buffer num: 2
I (1717) wifi:Init static rx buffer size: 1700 (rxctrl:92, csi:512)
I (1727) wifi:Init static rx buffer num: 10
I (1727) wifi:Init dynamic rx buffer num: 32
I (1737) wifi_init: rx ba win: 6
I (1737) wifi_init: accept mbox: 6
I (1737) wifi_init: tcpip mbox: 32
I (1747) wifi_init: udp mbox: 6
I (1747) wifi_init: tcp mbox: 6
I (1757) wifi_init: tcp tx win: 5760
I (1757) wifi_init: tcp rx win: 5760
I (1757) wifi_init: tcp mss: 624
I (1767) wifi_init: WiFi IRAM OP enabled
I (1767) wifi_init: WiFi RX IRAM OP enabled
I (1777) wifi_init: WiFi SLP IRAM OP enabled
I (1777) phy_init: phy_version 320,348a293,Sep 3 2024,16:33:12
W (1847) wifi:ACK_TAB0 :0x 90a0b, QAM16:0x9 (24Mbps), QPSK:0xa (12Mbps), BPSK:0xb (6Mbps)
W (1847) wifi:CTS_TAB0 :0x 90a0b, QAM16:0x9 (24Mbps), QPSK:0xa (12Mbps), BPSK:0xb (6Mbps)
W (1847) wifi:(agc)0x600a7128:0xd200da06, min.avgNF:0xce->0xd2(dB), RCalCount:0xc, min.RRssi:0xa06(-95.62)
W (1857) wifi:(TB)WDEV_PWR_TB_MCS0:19
W (1867) wifi:(TB)WDEV_PWR_TB_MCS1:19
W (1867) wifi:(TB)WDEV_PWR_TB_MCS2:19
W (1867) wifi:(TB)WDEV_PWR_TB_MCS3:19
W (1877) wifi:(TB)WDEV_PWR_TB_MCS4:19
W (1877) wifi:(TB)WDEV_PWR_TB_MCS5:19
W (1877) wifi:(TB)WDEV_PWR_TB_MCS6:18
W (1887) wifi:(TB)WDEV_PWR_TB_MCS7:18
W (1887) wifi:(TB)WDEV_PWR_TB_MCS8:17
W (1887) wifi:(TB)WDEV_PWR_TB_MCS9:15
W (1897) wifi:(TB)WDEV_PWR_TB_MCS10:15
W (1897) wifi:(TB)WDEV_PWR_TB_MCS11:15
I (1897) wifi:11ax coex: WDEVAX_PTI0(0x55777555), WDEVAX_PTI1(0x00003377).
I (1907) wifi:mode : null
W (1907) wifi:(he)deattach, ap, phymode:11bgn
I (1917) wifi:mode : softAP (40:4c:ca:57:f0:3d)
I (1917) wifi:Total power save buffer number: 16
I (1927) wifi:Init max length of beacon: 752/752
I (1927) wifi:Init max length of beacon: 752/752
I (1937) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.4.1
Add netif ap with f4a097d(commit id)
I (1947) bridge_common: netif list add success
I (1947) bridge_common: [WIFI_AP_DEF ]
I (1957) bridge_common: Set ip info:192.168.5.1
W (1957) bridge_wifi: SoftAP IP network segment has changed, deauth all station
I (1967) wifi:Disabled PMF config for SoftAP
I (1967) wifi:Total power save buffer number: 16
I (1977) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.5.1
I (1987) bridge_common: [WIFI_AP_DEF ]Name Server1: 114.114.114.114
I (1987) bridge_common: DHCPS Restart, deauth all station
Add netif sta with f4a097d(commit id)
I (1997) bridge_common: netif list add success
W (2007) wifi:(he)attach, station, phymode:11ax
I (2007) wifi:mode : sta (40:4c:ca:57:f0:3c) + softAP (40:4c:ca:57:f0:3d)
I (2017) wifi:enable tsf
W (2017) wifi:(he)deattach, station, phymode:11bgn
W (2027) wifi:11ax mode can not work under phy bw 40M, the sta phymode changed to 11N
E (2027) NVS: Failed to read IP info from NVS
I (2037) wifi:Disabled PMF config for STA
I (2037) bridge_wifi: [esp_bridge_wifi_set_config] sta ssid: SOLO_MESH password: 12345678
W (2047) wifi:Password length matches WPA2 standards, authmode threshold changes from OPEN to WPA2
I (2057) wifi:set country: cc=JP schan=1 nchan=14 policy=1
I (2057) bridge_wifi: [esp_bridge_wifi_set_config] softap ssid: NODE_57f03d password: 87654321
I (2367) wifi:Total power save buffer number: 16
I (2377) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.5.1
I (2377) bridge_wifi: SoftAP config changed, deauth all station
I (2377) Mesh-Lite: esp-mesh-lite component version: 1.0.0
I (2387) ESPNOW: espnow [version: 1.0] init
I (2387) [vendor_ie]: Mesh-Lite commit id: 7e45e27
I (2397) [vendor_ie]: Mesh ID: 77
W (2397) wifi:Haven't to connect to a suitable AP now!
I (2407) [ESP_Mesh_Lite_Comm]: msg action add success
I (2417) [ESP_Mesh_Lite_Comm]: Bind Socket 54, port 6364
I (2417) [ESP_Mesh_Lite_Comm]: Bind Socket 55, port 6363
I (2427) [ESP_Mesh_Lite_Comm]: Bind Socket 56, port 6366
I (2427) [ESP_Mesh_Lite_Comm]: Bind Socket 57, port 6365
W (2597) ESP_Mesh_Lite_OTA: SHA-256 for current firmware: 40bb46b71d1109e4da5cd519f10e957a48e403c0eeebff3ae71df6b013af59bf
I (2597) [ESP_Mesh_Lite_Comm]: msg action add success
I (2607) [mesh-lite-espnow]: Start espnow task
I (2617) Mesh-Lite: Mesh-Lite connecting
I (2617) [vendor_ie]: esp_mesh_lite_wifi_scan_start return ESP_OK
I (2627) [ESP_Mesh_Lite_Comm]: msg action add success
I (2637) solo_work_queue: Work Queue created.
I (2637) mqtt: Initialising MQTT
I (2637) esp_rmaker_mqtt_budget: MQTT Budgeting initialised. Default: 100, Max: 1024, Revive count: 1, Revive period: 5
I (2647) app_solo: SOLO Initialised.
I (2657) esp_solo_node: Node ID ----- 404CCA57F03C
I (2657) esp_solo_node: Node attribute MeshDevice created
I (2667) esp_solo_system_service: System service enabled.
I (2667) solo_ota_using_topics: OTA enabled with Topics
I (2677) ota: OTA state = -1
I (2677) solo_time: Initializing SNTP. Using the SNTP server: pool.ntp.org
I (2687) esp_solo_time_service: Time service enabled
I (2697) solo_time: SNTP already initialized.
I (2707) heap_metrics: free:0x2c000 lfb:0x27000 min_free_ever:0x2c000
W (2707) wifi:Haven't to connect to a suitable AP now!
I (2707) temperature_sensor: Range [-10°C ~ 80°C], error < 1°C
W (2717) wifi:Haven't to connect to a suitable AP now!
I (2727) esp_diag_var_data_pt_write: ts: 2231890, type: 1, index: 4, value type: 5, value len: 4, value[00000000]
I (2737) monitor: Enabling Command-Response Module.
I (2737) cmd_resp: Registered command 1
I (2747) diag_core: =========================================
I (2747) diag_core: Insights enabled for Node ID 404CCA57F03C
I (2757) diag_core: =========================================
I (2767) esp_solo_core: Starting RainMaker Work Queue task
I (2767) solo_work_queue: SOLO Work Queue task started.
W (2777) wifi:Haven't to connect to a suitable AP now!
I (2777) esp_now: Start espnow task
I (2787) app_wifi: Already provisioned, starting Wi-Fi STA
I (2787) wifi_prov_scheme_ble: BLE memory released
I (2797) solo_mesh: mesh service enabled
I (2797) cmd_resp: Registered command 0
E (2807) cmd_resp: Handler for command 3 already exists.
I (2807) main_task: Returned from app_main()
I (3517) [vendor_ie]: Mesh-Lite Scan done
W (3517) wifi:Haven't to connect to a suitable AP now!
I (3517) [vendor_ie]: now parent node : bssid:11:00:00:00:30:00, rssi:-108, level:-1
I (3527) [vendor_ie]: update parent node: bssid:54:32:04:0c:21:01, rssi:-42, level:1
I (3547) [vendor_ie]: Got NODE_0c2101
I (3547) [vendor_ie]: bssid: 54:32:04:0c:21:01, level: 2
I (3547) [vendor_ie]: RTC store: temp_mesh_id:255; ssid:NODE_0c2101; bssid:54:32:04:0c:21:01; crc:1506783678
W (3557) wifi:Password length matches WPA2 standards, authmode threshold changes from OPEN to WPA2
I (3567) [vendor_ie]: wifi_cfg NODE_0c2101 router_config SOLO_MESH
W (3577) wifi:(itwt)itwt_stop_process!
I (3577) [vendor_ie]: esp_mesh_lite_wifi_connect return ESP_OK
I (3717) chip: CPU load: 17%
I (4717) chip: CPU load: 1%
I (5687) wifi:new:<13,0>, old:<13,0>, ap:<13,0>, sta:<13,0>, prof:13, snd_ch_cfg:0x0
I (5687) wifi:(connect)dot11_authmode:0x3, pairwise_cipher:0x3, group_cipher:0x3
I (5697) wifi:state: init -> auth (0xb0)
I (5697) wifi:state: auth -> assoc (0x0)
I (5707) wifi:Association refused temporarily time 1500, comeback time 1600 (TUs)
I (5717) chip: CPU load: 32%
I (6717) chip: CPU load: 1%
I (7347) wifi:state: assoc -> assoc (0x0)
I (7397) wifi:state: assoc -> run (0x10)
I (7397) wifi:(trc)phytype:CBW20-SGI, snr:56, maxRate:144, highestRateIdx:0
W (7397) wifi:(trc)band:2G, phymode:3, highestRateIdx:0, lowestRateIdx:11, dataSchedTableSize:14
I (7407) wifi:(trc)band:2G, rate(S-MCS7, rateIdx:0), ampdu(rate:S-MCS7, schedIdx(0, stop:8)), snr:56, ampduState:wait operational
I (7417) wifi:ifidx:0, rssi:-40, nf:-96, phytype(0x3, CBW20-SGI), phymode(0x3, 11bgn), max_rate:144, he:0, vht:0, ht:1
I (7427) wifi:(ht)max.RxAMPDULenExponent:0(8191 bytes), MMSS:0(no restriction)
I (7447) wifi:connected with NODE_0c2101, aid = 1, channel 13, BW20, bssid = 54:32:04:0c:21:01
I (7447) wifi:security: WPA2-PSK, phy:11bgn, rssi:-40, cipher(pairwise:0x3, group:0x3), pmf:1,
I (7457) wifi:pm start, type: 1, twt_start:0
I (7457) wifi:pm start, type:1, aid:0x1, trans-BSSID:54:32:04:0c:21:01, BSSID[5]:0x1, mbssid(max-indicator:0, index:0), he:0
I (7467) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
I (7477) wifi:set rx beacon pti, rx_bcn_pti: 10, bcn_timeout: 25000, mt_pti: 10, mt_time: 10000
I (7487) wifi:[ADDBA]TX addba request, tid:0, dialogtoken:1, bufsize:64, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x0)
I (7497) wifi:[ADDBA]TX addba request, tid:7, dialogtoken:2, bufsize:64, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x20)
I (7507) wifi:[ADDBA]TX addba request, tid:5, dialogtoken:3, bufsize:64, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x0)
I (7517) wifi:dp: 2, bi: 102400, li: 4, scale listen interval from 307200 us to 409600 us
I (7527) wifi:AP's beacon interval = 102400 us, DTIM period = 2
I (7537) wifi:[ADDBA]RX addba response, status:0, tid:0/tb:1(0xa1), bufsize:6, batimeout:0, txa_wnd:6
I (7537) wifi:[ADDBA]RX addba response, status:1
I (7547) wifi:[ADDBA]RX addba response, status:1
I (7557) esp_diag_var_data_pt_write: ts: 7062225, type: 1, index: 0, value type: 11, value len: 11, value[4e4f44455f306332313031]
I (7567) esp_diag_var_data_pt_write: ts: 7071874, type: 1, index: 1, value type: 13, value len: 6, value[5432040c2101]
I (7577) esp_diag_var_data_pt_write: ts: 7083213, type: 1, index: 2, value type: 2, value len: 1, value[0d]
I (7587) esp_diag_var_data_pt_write: ts: 7093790, type: 1, index: 3, value type: 2, value len: 1, value[03]
I (7607) Mesh-Lite: netif network segment conflict check
I (7717) chip: CPU load: 20%
I (8547) esp_netif_handlers: sta ip: 192.168.5.2, mask: 255.255.255.0, gw: 192.168.5.1
W (8547) bridge_wifi: Connected with IP Address:192.168.5.2
I (8547) bridge_common: [WIFI_AP_DEF ]Name Server1: 192.168.240.1
I (8557) bridge_common: [WIFI_AP_DEF ]
I (8557) bridge_common: IP Address:192.168.4.1
I (8567) bridge_common: GW Address:192.168.4.1
I (8567) bridge_common: NM Address:255.255.255.0
I (8577) bridge_common: ip reallocate new:192.168.4.1
W (8577) bridge_wifi: SoftAP IP network segment has changed, deauth all station
I (8587) [vendor_ie]: RTC store: temp_mesh_id:191; ssid:NODE_0c2101; bssid:54:32:04:0c:21:01; crc:44681661
W (8597) solo_mesh: Got IP, channels: [13,0], layer: 2, self mac: 40:4c:ca:57:f0:3c, parent bssid: 54:32:04:0c:21:01, parent rssi: -39, free heap: 170164
I (8617) mqtt: Publishing to node/404CCA57F03C/d
W (8617) mqtt_client: Publish: Losing qos0 data when client not connected
E (8627) mqtt: MQTT Publish failed
I (8627) esp_diag_var_data_pt_write: ts: 8140458, type: 1, index: 12, value type: 12, value len: 4, value[c0a80502]
I (8637) esp_diag_var_data_pt_write: ts: 8149774, type: 1, index: 13, value type: 12, value len: 4, value[ffffff00]
I (8647) esp_diag_var_data_pt_write: ts: 8160768, type: 1, index: 14, value type: 12, value len: 4, value[c0a80501]
W (8637) wifi:idx:0, ifx:0, tid:0, TAHI:0x1000121, TALO:0xc043254, (ssn:0, win:64, cur_ssn:0), CONF:0xc0000005
I (8677) esp_diag_var_data_pt_write: ts: 8182658, type: 1, index: 6, value type: 2, value len: 1, value[07]
I (8687) esp_diag_var_data_pt_write: ts: 8192704, type: 1, index: 7, value type: 2, value len: 1, value[01]
I (8697) esp_diag_var_data_pt_write: ts: 8203112, type: 1, index: 8, value type: 2, value len: 1, value[01]
I (8707) esp_diag_var_data_pt_write: ts: 8213651, type: 1, index: 10, value type: 2, value len: 1, value[07]
I (8717) esp_diag_var_data_pt_write: ts: 8224033, type: 1, index: 11, value type: 2, value len: 1, value[02]
I (8727) solo_cmd_resp: Enabling Command-Response Module.
I (8727) esp_solo_node: Node attribute cmd-resp created
I (8737) mqtt: Connecting to MQTT broker [192.168.240.1]
I (8747) esp_solo_core: Waiting for MQTT connection
I (8747) chip: CPU load: 21%
I (8797) mqtt: MQTT Connected
I (8797) app_solo: SOLO_MQTT_EVENT_CONNECTED.
I (8797) solo_cmd_resp: Checking for pending commands.
I (8797) mqtt: Publishing to node/404CCA57F03C/out
I (8807) esp_solo_node_config: Generated Node config of length 2718
I (8807) mqtt: Publishing to node/404CCA57F03C/config
Mesh-Lite commit id: 7e45e27
I don't have another log, because devices don't have debug interfaces.
I was very lucky to catch this situation on the debug board )))
Based on the provided logs, there is a log entry: solo_mesh: Got IP, channels: [13,0], layer: 2, self mac: 40:4c:ca:57:f0:3c, parent bssid: 54:32:04:0c:21:01, parent rssi: -39, free heap: 170164. It seems that the layer display is correct.