Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Can't restart mesh once stopped (IDFGH-14433) #15213

Open
3 tasks done
leenowell opened this issue Jan 15, 2025 · 36 comments
Open
3 tasks done

Can't restart mesh once stopped (IDFGH-14433) #15213

leenowell opened this issue Jan 15, 2025 · 36 comments
Assignees
Labels
Status: In Progress Work is in progress Type: Bug bugs in IDF

Comments

@leenowell
Copy link

Answers checklist.

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

IDF version.

ESP-IDF v5.5-dev-1050-gb5ac4fbdf9

Espressif SoC revision.

ESP32-D0WDQ6 (revision v0.0)

Operating System used.

Linux

How did you build your project?

Eclipse IDE

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

None

Development Kit.

ESP WROOM 32

Power Supply used.

USB

What is the expected behavior?

If I stop the mesh I can restart it later

What is the actual behavior?

If I call esp_mesh_start I get an ESP_ERR_MESH_NOT_INIT error. Calling esp_mesh_init before esp_mesh_start I then get ESP_ERR_MESH_NOT_CONI.

So I think the sequence should be
esp_mesh_init
esp_mesh_set_config
esp_mesh_start

However, now I get ESP_ERR_MESH_NOT_ALLOWED when I call esp_mesh_set_config.

Steps to reproduce.

  1. Start the mesh with an invalid password
  2. Wait for MESH_EVENT_NO_PARENT_FOUND
  3. Once received call esp_mesh_stop()
  4. Create a new thread to handle the smart config
  5. Once received ssid/ password start the mesh again - see the "actual behaviour box" for what I have tried
    ...

Debug Logs.

No response

More Information.

This thread I posted on the forum has more detail if needed http://esp32.io/viewtopic.php?f=21&p=142998.

Essentially, I am trying to get smart config and mesh to work together so smart config is invoked if no parent is found. Since you can't call and wifi APIs when the mesh is working I am stopping the mesh, running smart config to get the ssid/ password and then trying to start the mesh again with the new details. Not the best scenario as the 2 should work together but seems like the only option - other than my workaround for this which is to restart the device.

@leenowell leenowell added the Type: Bug bugs in IDF label Jan 15, 2025
@github-actions github-actions bot changed the title Can't restart mesh once stopped Can't restart mesh once stopped (IDFGH-14433) Jan 15, 2025
@espressif-bot espressif-bot added the Status: Opened Issue is new label Jan 15, 2025
@zhangyanjiaoesp
Copy link
Collaborator

However, now I get ESP_ERR_MESH_NOT_ALLOWED when I call esp_mesh_set_config.

@leenowell This log indicates that the mesh network has not stopped. Could you provide the log after calling mesh stop?

@leenowell
Copy link
Author

@zhangyanjiaoesp as requested this is the log from when I received MESH_EVENT_NO_PARENT_FOUND

`
I (21738) mesh_node: MeshNodeEvent: <MESH_EVENT_NO_PARENT_FOUND>scan times:60
I (21748) mesh: <MESH_NWK_PARENT_DISCONNECTED>non-root, need_reselect:1
I (21748) HomeIoT: cbOnMeshNoParent: Parent has gone setting Meshconnected to false
I (21748) wifi_node: wifi_node_smart_config_task: calling esp_mesh_stop
I (21788) wifi:Set ps type: 0, coexist: 0

I (21788) mesh: 452
W (21788) mesh: [mesh.c,455] vendor ie
W (21788) mesh: [mesh.c,458] send block
W (21798) mesh: [mesh.c,461] rx task
W (21798) mesh: [mesh_schedule.c,2118] tx
I (21798) mesh: 1941xon(req:0, rsp:0), mgmt:0, bcast:0, down:0, donw-be:0, ps(active:0, tx:0)
W (21808) mesh: [mesh_schedule.c,2751] xon
W (21808) mesh: [mesh_schedule.c,2524] MESH_STOP_EVENT_BIT_TX
I (21818) mesh: 1973up:0, up-be:0, ps(active:0, tx:0)
W (21818) mesh: [mesh_schedule.c,2525] tx
W (21828) mesh: [mesh_schedule.c,3252] MESH_STOP_EVENT_BIT_XON
W (21828) mesh: [mesh.c,464] tx task
W (21838) mesh: [mesh_schedule.c,3253] xon
I (21838) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (21848) mesh: <WIFI_EVENT_SCAN_DONE>status:fail, num:3, id:188
I (21858) mesh: [S2]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-47
I (21858) mesh: find router:[ssid_len:6]Lounge, rssi:-47, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (21878) mesh: [S2]ignore Lounge, channel:11 due to different auth mode(3) from mine(open)
I (21878) mesh: [FIND][ch:11]AP:3, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (21888) mesh: [FIND:61]fail to find a network, channel:0, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (21898) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:62
I (22028) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (22028) mesh: [S1]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-45
I (22028) mesh: find router:[ssid_len:6]Lounge, rssi:-45, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (22038) mesh: [S1]ignore Lounge, channel:11 due to different auth mode(3) from mine(open)
I (22048) mesh: [FIND][ch:11]AP:1, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (22058) mesh: [FIND:62]fail to find a network, channel:0, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (22068) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:63
I (22378) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (22378) mesh: [S2]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-45
I (22378) mesh: find router:[ssid_len:6]Lounge, rssi:-45, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (22388) mesh: [S2]ignore Lounge, channel:11 due to different auth mode(3) from mine(open)
I (22398) mesh: [FIND][ch:11]AP:3, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (22408) mesh: [FIND:63]fail to find a network, channel:0, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (22418) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:64
I (22548) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (22548) mesh: [S1]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-45
I (22548) mesh: find router:[ssid_len:6]Lounge, rssi:-45, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (22558) mesh: [S1]ignore Lounge, channel:11 due to different auth mode(3) from mine(open)
I (22568) mesh: [FIND][ch:11]AP:1, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (22578) mesh: [FIND:64]fail to find a network, channel:0, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (22588) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:65
I (22898) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (22898) mesh: [S2]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-46
I (22898) mesh: find router:[ssid_len:6]Lounge, rssi:-46, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (22908) mesh: [S2]ignore Lounge, channel:11 due to different auth mode(3) from mine(open)
I (22918) mesh: [FIND][ch:11]AP:3, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (22928) mesh: [FIND:65]fail to find a network, channel:0, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (22938) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:66
I (23068) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (23068) mesh: [S1]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-45
I (23068) mesh: find router:[ssid_len:6]Lounge, rssi:-45, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (23078) mesh: [S1]ignore Lounge, channel:11 due to different auth mode(3) from mine(open)
I (23078) mesh: [FIND][ch:11]AP:1, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (23088) mesh: [FIND:66]fail to find a network, channel:0, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (23098) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:67
I (23408) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (23408) mesh: [S2]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-46
I (23418) mesh: find router:[ssid_len:6]Lounge, rssi:-46, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (23428) mesh: [S2]ignore Lounge, channel:11 due to different auth mode(3) from mine(open)
I (23428) mesh: [FIND][ch:11]AP:3, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (23438) mesh: [FIND:67]fail to find a network, channel:0, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (23448) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:68
I (23578) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (23578) mesh: [S1]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-45
I (23578) mesh: find router:[ssid_len:6]Lounge, rssi:-45, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (23588) mesh: [S1]ignore Lounge, channel:11 due to different auth mode(3) from mine(open)
I (23598) mesh: [FIND][ch:11]AP:1, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (23608) mesh: [FIND:68]fail to find a network, channel:0, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (23618) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:69
I (23928) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (23928) mesh: [S2]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-45
I (23928) mesh: find router:[ssid_len:6]Lounge, rssi:-45, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (23938) mesh: [S2]ignore Lounge, channel:11 due to different auth mode(3) from mine(open)
I (23948) mesh: [FIND][ch:11]AP:3, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (23958) mesh: [FIND:69]fail to find a network, channel:0, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (23968) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:70
W (24038) mesh: [mesh.c,467] nwk task
W (24038) mesh: [mesh.c,472] route
W (24038) mesh: [mesh.c,477] free mesh_myself_mbox
W (24038) mesh: [mesh.c,482] free mesh_tcpip_mbox
W (24038) mesh: [mesh.c,486] is_receiving:0
W (24048) mesh: [mesh.c,497] free mesh_xmit_state_mbox
W (24048) mesh: [mesh.c,514] nvs task
I (24058) mesh: 556
I (24058) mesh_node: MeshNodeEvent: <MESH_EVENT_STOPPED>
I (24058) wifi_node: wifi_node_smart_config_task: after esp_mesh_stop
I (24068) wifi_node: wifi_node_smart_config_task: setting SC type
I (24078) wifi_node: wifi_node_smart_config_task: starting SC
I (24078) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (24128) smartconfig: SC version: V3.0.2
I (28948) wifi:ic_enable_sniffer
I (28948) smartconfig: Start to find channel...
I (28948) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (28948) wifi_node: SmartConfigEvent: Scan done
I (29098) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (29248) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (29398) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (29558) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (29708) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (29858) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (30008) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (30158) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (30308) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (30458) wifi_node: WIFINodeEvent: Unknown WiFi event [43]`

@zhangyanjiaoesp
Copy link
Collaborator

zhangyanjiaoesp commented Jan 16, 2025

W (24038) mesh: [mesh.c,467] nwk task
W (24038) mesh: [mesh.c,472] route
W (24038) mesh: [mesh.c,477] free mesh_myself_mbox
W (24038) mesh: [mesh.c,482] free mesh_tcpip_mbox
W (24038) mesh: [mesh.c,486] is_receiving:0
W (24048) mesh: [mesh.c,497] free mesh_xmit_state_mbox
W (24048) mesh: [mesh.c,514] nvs task
I (24058) mesh: 556
I (24058) mesh_node: MeshNodeEvent: <MESH_EVENT_STOPPED>

This log seems that the mesh has successfully stopped. It’s strange that you encountered a failure when setting the config. I tested it locally, and after stopping, calling init -> config -> start() successfully starts the mesh. Below is my log. Could you provide your test demo for further investigation?

I (11999) mesh_main: >>try to stop mesh
I (12009) wifi:Set ps type: 0, coexist: 0

I (12019) mesh: 452<stop>
W (12019) mesh: [mesh.c,455] <stop>vendor ie
W (12019) mesh: [mesh.c,458] <stop>send block
W (12029) mesh: [mesh.c,461] <stop>rx task
W (12029) mesh: [mesh_schedule.c,2118] <break>tx
I (12039) mesh: 1941<flush>xon(req:0, rsp:0), mgmt:0, bcast:0, down:0, donw-be:0, ps(active:0, tx:0)
W (12039) mesh: [mesh_schedule.c,2524] <done>MESH_STOP_EVENT_BIT_TX
W (12049) mesh: [mesh_schedule.c,2525] <stop>tx
W (12049) mesh: [mesh_schedule.c,2751] <break>xon
I (12059) mesh: 1973<flush>up:0, up-be:0, ps(active:0, tx:0)
W (12059) mesh: [mesh_schedule.c,3252] <done>MESH_STOP_EVENT_BIT_XON
W (12069) mesh: [mesh_schedule.c,3253] <stop>xon
W (12069) mesh: [mesh.c,464] <stop>tx task
W (14409) mesh: [mesh.c,467] <stop>nwk task
W (14409) mesh: [mesh.c,472] <stop>route
W (14409) mesh: [mesh.c,477] <stop>free mesh_myself_mbox
W (14409) mesh: [mesh.c,482] <stop>free mesh_tcpip_mbox
W (14409) mesh: [mesh.c,486] <stop>is_receiving:0
W (14419) mesh: [mesh.c,497] <stop>free mesh_xmit_state_mbox
W (14419) mesh: [mesh.c,514] <stop>nvs task
I (14479) wifi:Total power save buffer number: 16
I (14479) mesh: 556<end>
I (14479) mesh_main: <MESH_EVENT_STOPPED>
I (14479) mesh_main: >>>try to restart mesh
I (14479) mesh: <nvs>read layer:0
I (14479) mesh: <nvs>read assoc:0, err:0x1102
I (14489) main_task: Returned from app_main()
I (14539) wifi:Total power save buffer number: 16
I (14799) wifi:mode : sta (1c:9d:c2:41:30:84)
I (14809) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:1
I (14809) mesh_main: <MESH_EVENT_MESH_STARTED>ID:77:77:77:77:77:76
I (19019) mesh: [S21]test123, ac:84:c6:7e:31:2b, channel:5, rssi:-28
I (19019) mesh: find router:[ssid_len:8]test123, rssi:-28, ac:84:c6:7e:31:2b(encrypted), new channel:5, old channel:0
I (19029) mesh: [FIND][ch:0]AP:50, otherID:0, MAP:0, idle:0, candidate:0, root:0[ac:84:c6:7e:31:2b]router found
I (19029) mesh: [FIND:1]find a network, channel:5, cfg<channel:0, router:test123, 00:00:00:00:00:00>

I (19039) wifi:mode : sta (1c:9d:c2:41:30:84) + softAP (1c:9d:c2:41:30:85)
W (19049) wifi:<MESH AP>adjust channel:1, secondary channel offset:1(40U)
I (19059) wifi:Total power save buffer number: 16
I (19059) wifi:Init max length of beacon: 752/752
I (19069) wifi:Init max length of beacon: 752/752
I (19069) mesh_main: <MESH_EVENT_FIND_NETWORK>new channel:5, router BSSID:00:00:00:00:00:00
W (19079) wifi:<MESH AP>adjust channel:5, secondary channel offset:1(40U)
I (19089) wifi:Total power save buffer number: 16
I (19389) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:0][ac:84:c6:7e:31:2b]router found<>
I (19389) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-28], mine:0, voter:0
I (19399) mesh: 1369, vote myself, router rssi:-28 > voted rc_rssi:-120

@espressif-bot espressif-bot added Status: In Progress Work is in progress and removed Status: Opened Issue is new labels Jan 16, 2025
@leenowell
Copy link
Author

In your example did you restart immediately after the esp_mesh_stop() call returns or wait for the mesh to be stopped (e.g. when received MESH_EVENT_STOPPED)? Reason I ask is that in my scenario I did the following

  1. on MESH_EVENT_NO_PARENT call esp_mesh_stop then start a new task to launch smart config
  2. When that task receives SC_EVENT_GOT_SSID_PSWD try to restart the mesh with init->set config->start mesh

Therefore it would have had sufficient time to fully stop whilst SC was running.

I need to get my code from backup to reproduce it so tried to quickly change the internal comms mesh example but stopping the mesh on MESH_EVENT_NO_PARENT then trying to start it immediately afterwards I intermittently get

`
I (19487) mesh_main: <MESH_EVENT_NO_PARENT_FOUND>scan times:60
I (19497) mesh: <MESH_NWK_PARENT_DISCONNECTED>non-root, need_reselect:1
I (19507) mesh_main: STOPPING MESH
I (19517) wifi:Set ps type: 0, coexist: 0

I (19517) mesh: 452
W (19527) mesh: [mesh.c,455] vendor ie
W (19527) mesh: [mesh.c,458] send block
W (19527) mesh: [mesh.c,461] rx task
W (19537) mesh: [mesh_schedule.c,2751] xon
W (19537) mesh: [mesh_schedule.c,2118] tx
I (19537) mesh: 1973up:0, up-be:0, ps(active:0, tx:0)
I (19547) mesh: 1941xon(req:0, rsp:0), mgmt:0, bcast:0, down:0, donw-be:0, ps(active:0, tx:0)
W (19547) mesh: [mesh_schedule.c,3252] MESH_STOP_EVENT_BIT_XON
W (19557) mesh: [mesh.c,464] tx task
W (19557) mesh: [mesh_schedule.c,2524] MESH_STOP_EVENT_BIT_TX
W (19577) mesh: [mesh_schedule.c,2525] tx
W (19567) mesh: [mesh_schedule.c,3253] xon
W (21767) mesh: [mesh.c,467] nwk task
W (21767) mesh: [mesh.c,472] route
W (21767) mesh: [mesh.c,477] free mesh_myself_mbox
W (21767) mesh: [mesh.c,482] free mesh_tcpip_mbox
W (21767) mesh: [mesh.c,486] is_receiving:0
W (21777) mesh: [mesh.c,497] free mesh_xmit_state_mbox
W (21777) mesh: [mesh.c,514] nvs task
I (21787) mesh: 556
I (21787) mesh_main: MESH STOPPED
I (21787) mesh_main: STARTING MESH
I (21797) wifi:mode : sta (24:0a:c4:82:6f:1c) + softAP (24:0a:c4:82:6f:1d)
I (21807) wifi:Total power save buffer number: 16
I (21807) wifi:Init max length of beacon: 752/752
I (21807) wifi:Init max length of beacon: 752/752
I (21827) mesh: read layer:1
I (21827) mesh: read assoc:0
I (21837) wifi:Total power save buffer number: 16
I (22097) wifi:mode : sta (24:0a:c4:82:6f:1c)
Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled.

Core 0 register dump:
PC : 0x401716d7 PS : 0x00060d30 A0 : 0x801717da A1 : 0x3ffbf5a0
A2 : 0x3ffbe89c A3 : 0x3ffbf5b0 A4 : 0x00000006 A5 : 0xffffffff
A6 : 0x00000005 A7 : 0x00000000 A8 : 0x80171719 A9 : 0x00000006
A10 : 0x3f410d91 A11 : 0x3ffc3170 A12 : 0x00000009 A13 : 0x3ffafba8
A14 : 0x00000000 A15 : 0x3f4030ed SAR : 0x00000015 EXCCAUSE: 0x0000001c
EXCVADDR: 0x00000006 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000

Backtrace: 0x401716d4:0x3ffbf5a0 0x401717d7:0x3ffbf5f0

ELF file SHA256: 54368c912

Rebooting...
ets Jun 8 2016 00:22:57

`

Waiting to restart after the mesh stopped event I get

`
I (14787) mesh_main: <MESH_EVENT_NO_PARENT_FOUND>scan times:60
I (14807) mesh: <MESH_NWK_PARENT_DISCONNECTED>non-root, need_reselect:1
I (14807) mesh_main: STOPPING MESH
I (14817) wifi:Set ps type: 0, coexist: 0

I (14817) mesh: 452
W (14827) mesh: [mesh.c,455] vendor ie
W (14827) mesh: [mesh.c,458] send block
W (14827) mesh: [mesh.c,461] rx task
W (14837) mesh: [mesh_schedule.c,2118] tx
W (14837) mesh: [mesh_schedule.c,2751] xon
I (14837) mesh: 1941xon(req:0, rsp:0), mgmt:0, bcast:0, down:0, donw-be:0, ps(active:0, tx:0)
I (14847) mesh: 1973up:0, up-be:0, ps(active:0, tx:0)
W (14857) mesh: [mesh_schedule.c,2524] MESH_STOP_EVENT_BIT_TX
W (14857) mesh: [mesh.c,464] tx task
W (14857) mesh: [mesh_schedule.c,3252] MESH_STOP_EVENT_BIT_XON
W (14867) mesh: [mesh_schedule.c,2525] tx
W (14877) mesh: [mesh_schedule.c,3253] xon
W (17067) mesh: [mesh.c,467] nwk task
W (17067) mesh: [mesh.c,472] route
W (17067) mesh: [mesh.c,477] free mesh_myself_mbox
W (17067) mesh: [mesh.c,482] free mesh_tcpip_mbox
W (17067) mesh: [mesh.c,486] is_receiving:0
W (17077) mesh: [mesh.c,497] free mesh_xmit_state_mbox
W (17077) mesh: [mesh.c,514] nvs task
I (17087) mesh: 556
I (17087) mesh_main: MESH STOPPED
E (22067) task_wdt: Task watchdog got triggered. The following tasks/users did not reset the watchdog in time:
E (22067) task_wdt: - IDLE0 (CPU 0)
E (22067) task_wdt: Tasks currently running:
E (22067) task_wdt: CPU 0: sys_evt
E (22067) task_wdt: CPU 1: IDLE1
E (22067) task_wdt: Print CPU 0 (current core) backtrace

Backtrace: 0x400D9DC8:0x3FFB20A0 0x400831B1:0x3FFB20D0 0x40171767:0x3FFBF5A0 0x401717D3:0x3FFBF5F0

`

@leenowell
Copy link
Author

Hi @zhangyanjiaoesp

I have double checked the code and I actually restarted in the mesh in the wifi event handler when I received WIFI_EVENT_STA_CONNECTED.

`
void temp_mesh_start(void)
{
// Initialise Mesh
ESP_LOGI(MESH_TAG,"MeshStart: About to init the mesh");
ESP_ERROR_CHECK(esp_mesh_init());
ESP_ERROR_CHECK(esp_event_handler_register(MESH_EVENT, ESP_EVENT_ANY_ID, &mesh_node_event_handler, NULL));

// Setup Mesh config
mesh_cfg_t cfg = MESH_INIT_CONFIG_DEFAULT();
memcpy((uint8_t *) &cfg.mesh_id, CONFIG_MESH_ID, 6);
// cfg.event_cb = &mesh_node_event_handler;

cfg.channel = mesh_config_data.nMeshChannelNumber;
cfg.router.ssid_len = strlen(mesh_config_data.sSSID);
memcpy((uint8_t *) &cfg.router.ssid, mesh_config_data.sSSID, strlen(mesh_config_data.sSSID)+1);
memcpy((uint8_t *) &cfg.router.password, mesh_config_data.sPassword, strlen(mesh_config_data.sPassword)+1);

/* 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, strlen(CONFIG_MESH_AP_PASSWD));
ESP_ERROR_CHECK(esp_mesh_set_config(&cfg));

ESP_LOGI(MESH_TAG,"MeshStart: About to start the mesh SSID [%s] Password [%s]", mesh_config_data.sSSID,mesh_config_data.sPassword);

/* mesh start */
ESP_ERROR_CHECK(esp_mesh_start());
ESP_LOGI(MESH_TAG, "MeshStart: Mesh started successfully, heap:%ld, %s\n",  esp_get_free_heap_size(), esp_mesh_is_root_fixed() ? "root fixed" : "root not fixed");

`

@zhangyanjiaoesp
Copy link
Collaborator

@leenowell So this issue has been solved?

@leenowell
Copy link
Author

leenowell commented Jan 17, 2025

@zhangyanjiaoesp Unfortunately not, the issue is still there.

As a temporary work around so I can continue my project I have to do the following

  1. start the Mesh and get no parent event
  2. stop the Mesh
  3. Do SmartConfig
  4. Store the ssid/ password/ channel in nvs
  5. restart the device
  6. When the device starts read the info from nvs
  7. Starting the mesh.

The other side of this is that it seems you can't run SmartConfig whilst the mesh is running. I am not sure if this is another bug or this is intended and the only way to use SmartConfig and Mesh is to fully stop the Mesh and restart it. If it is intended I think there is probably a feature request to better integrate the 2.

@zhangyanjiaoesp
Copy link
Collaborator

@leenowell
Can you provide more logs about calling esp_mesh_set_self_organized(0, 0) before smart config start?

Image

Is there more logs after this ?

Image

@leenowell
Copy link
Author

@zhangyanjiaoesp Happy to redo the code to run the test. Just want to double check what you want me to test. Is the following correct?

  1. Start the mesh
  2. on the mesh no parent event start the smart config task
  3. in that task esp_set_self_organised(0,0) then kick off smart config

Is that correct?

@zhangyanjiaoesp
Copy link
Collaborator

zhangyanjiaoesp commented Jan 17, 2025

@leenowell

Image

This is just what I saw in your comment from this link(http://esp32.io/viewtopic.php?f=21&p=142998). I don't know what your testing scenario was like at that time.

  1. Start the mesh
  2. on the mesh no parent event start the smart config task
  3. in that task esp_set_self_organised(0,0) then kick off smart config

This seems to be ok

@leenowell
Copy link
Author

Hi @zhangyanjiaoesp

In my test I gave the correct SSID and channel but wrong password. Oddly it generated MESH_EVENT_PARENT_DISCONNECTED instead of MESH_EVENT_NO_PARENT_FOUND. This is the full log

`
ets Jun 8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_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:6328
load:0x40078000,len:15828
load:0x40080400,len:3860
entry 0x40080638
I (27) boot: ESP-IDF v5.5-dev-1050-gb5ac4fbdf9 2nd stage bootloader
I (27) boot: compile time Jan 15 2025 18:25:44
I (27) boot: Multicore bootloader
I (30) boot: chip revision: v0.0
I (33) boot.esp32: SPI Speed : 40MHz
I (36) boot.esp32: SPI Mode : DIO
I (40) boot.esp32: SPI Flash Size : 2MB
I (43) boot: Enabling RNG early entropy source...
I (48) boot: Partition Table:
I (50) boot: ## Label Usage Type ST Offset Length
I (57) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (63) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (70) boot: 2 factory factory app 00 00 00010000 00177000
I (76) boot: 3 coredump Unknown data 01 03 00187000 00010000
I (83) boot: End of partition table
I (86) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=27898h (161944) map
I (149) esp_image: segment 1: paddr=000378c0 vaddr=3ff80000 size=0001ch ( 28) load
I (149) esp_image: segment 2: paddr=000378e4 vaddr=3ffb0000 size=044e4h ( 17636) load
I (159) esp_image: segment 3: paddr=0003bdd0 vaddr=40080000 size=04248h ( 16968) load
I (167) esp_image: segment 4: paddr=00040020 vaddr=400d0020 size=baee4h (765668) map
I (430) esp_image: segment 5: paddr=000faf0c vaddr=40084248 size=1371ch ( 79644) load
I (472) boot: Loaded app from partition at offset 0x10000
I (472) boot: Disabling RNG early entropy source...
I (483) cpu_start: Multicore app
I (491) cpu_start: Pro cpu start user code
I (491) cpu_start: cpu freq: 160000000 Hz
I (491) app_init: Application information:
I (491) app_init: Project name: HomeIoT
I (495) app_init: App version: 1
I (499) app_init: Compile time: Jan 15 2025 18:25:02
I (504) app_init: ELF file SHA256: 9bfc081f3...
I (508) app_init: ESP-IDF: v5.5-dev-1050-gb5ac4fbdf9
I (513) efuse_init: Min chip rev: v0.0
I (517) efuse_init: Max chip rev: v3.99
I (521) efuse_init: Chip rev: v0.0
I (525) heap_init: Initializing. RAM available for dynamic allocation:
I (532) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (537) heap_init: At 3FFBA438 len 00025BC8 (150 KiB): DRAM
I (542) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (547) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (553) heap_init: At 40097964 len 0000869C (33 KiB): IRAM
I (559) spi_flash: detected chip: gd
I (561) spi_flash: flash io: dio
W (564) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (577) esp_core_dump_flash: Init core dump to flash
I (582) esp_core_dump_flash: Found partition 'coredump' @ 187000 65536 bytes
I (621) esp_core_dump_flash: Core dump data checksum is correct
I (621) esp_core_dump_flash: Found core dump 24324 bytes in flash @ 0x187000
I (623) main_task: Started on CPU0
I (633) main_task: Calling app_main()
I (633) TestNode: app_main: Starting Node but waiting first
I (5633) TestNode: app_main: Starting Node now
I (5673) HomeIoT: InitNode: Starting Wifi
I (5683) wifi:wifi driver task: 3ffc3910, prio:23, stack:6656, core=0
I (5703) wifi:wifi firmware version: 34d97ea27
I (5703) wifi:wifi certification version: v7.0
I (5703) wifi:config NVS flash: enabled
I (5703) wifi:config nano formatting: disabled
I (5703) wifi:Init data frame dynamic rx buffer num: 32
I (5713) wifi:Init static rx mgmt buffer num: 5
I (5713) wifi:Init management short buffer num: 32
I (5723) wifi:Init dynamic tx buffer num: 32
I (5723) wifi:Init static rx buffer size: 1600
I (5723) wifi:Init static rx buffer num: 10
I (5733) wifi:Init dynamic rx buffer num: 32
I (5733) wifi_init: rx ba win: 6
I (5733) wifi_init: accept mbox: 6
I (5743) wifi_init: tcpip mbox: 32
I (5743) wifi_init: udp mbox: 6
I (5743) wifi_init: tcp mbox: 6
I (5753) wifi_init: tcp tx win: 5760
I (5753) wifi_init: tcp rx win: 5760
I (5753) wifi_init: tcp mss: 1440
I (5763) wifi_init: WiFi IRAM OP enabled
I (5763) wifi_init: WiFi RX IRAM OP enabled
Done esp_wifi_initAbout to call esp_wifi_startI (5773) phy_init: phy_version 4840,02e0d70,Sep 2 2024,19:39:07
I (5853) wifi:mode : sta (24:0a:c4:82:6f:1c)
I (5853) wifi:enable tsf
I (5853) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (5863) main_task: Returned from app_main()
I (5863) wifi_node: WIFINodeEvent: WiFi started
I (5863) HomeIoT: cbOnWifiStarted: Wifi started ok
I (5873) HomeIoT: cbOnWifiStarted: Starting ESPNow
I (5873) ESPNOW: espnow [version: 2.0] init
I (5883) node_config: GetNodeConfigString: Reading config data for [SSID]
I (5883) node_config: ConfigureNode: Read SSID [Lounge]
I (5893) node_config: GetNodeConfigString: Reading config data for [PASSWORD]
I (5893) node_config: ConfigureNode: Read PASSWORD [LChicago1561!:)]
I (5903) node_config: GetNodeConfigInt: Reading config data for [CHANNEL]
I (5913) node_config: GetNodeConfigInt: Read CHANNEL [11]
I (5913) HomeIoT: cbOnWifiStarted: Got config from flash
I (5923) HomeIoT: cbOnWifiStarted: Starting Mesh ssid[Lounge] password[TESTING] channel[11]
I (5923) mesh_node: MeshStart: About to init the mesh
I (5933) wifi:mode : sta (24:0a:c4:82:6f:1c) + softAP (24:0a:c4:82:6f:1d)
I (5943) wifi:Total power save buffer number: 16
I (5943) wifi:Init max length of beacon: 752/752
I (5953) wifi:Init max length of beacon: 752/752
I (5963) mesh: read layer:0
I (5963) mesh: read assoc:0
I (5963) wifi:Set ps type: 0, coexist: 0

I (5963) mesh_node: MeshStart: SSID len [6]
I (5973) wifi:Total power save buffer number: 16
I (6233) mesh_node: MeshStart: About to start the mesh SSID [Lounge] Password [TESTING] Channel[11]
I (6233) wifi:mode : sta (24:0a:c4:82:6f:1c)
I (6253) mesh_node: MeshStart: Mesh started successfully, heap:176672, root not fixed

I (6253) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x1, need_scan_router:0x0, look_for_nwk_count:1
I (6253) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (6263) wifi_node: WIFINodeEvent: Unknown WiFi event [12]
I (6263) wifi_node: WIFINodeEvent: Unknown WiFi event [13]
I (6273) wifi_node: WIFINodeEvent: Unknown WiFi event [12]
I (6273) wifi_node: WIFINodeEvent: Unknown WiFi event [13]
I (6283) mesh_node: MeshNodeEvent: <MESH_EVENT_MESH_STARTED>ID:77:77:77:77:77:77
I (6553) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (6553) mesh: [S2]Lounge, f0:86:20:13:b4:33, channel:11, rssi:-49
I (6563) mesh: find router:[ssid_len:6]Lounge, rssi:-49, f0:86:20:13:b4:33(encrypted), new channel:11, old channel:0
I (6563) mesh: [FIND][ch:11]AP:3, otherID:0, MAP:0, idle:0, candidate:0, root:0[f0:86:20:13:b4:33]router found
I (6573) mesh: [FIND:1]find a network, channel:11, cfg<channel:11, router:Lounge, 00:00:00:00:00:00>

I (6583) mesh_node: MeshNodeEvent: <MESH_EVENT_FIND_NETWORK>new channel:11, router BSSID:00:00:00:00:00:00
I (6583) wifi:mode : sta (24:0a:c4:82:6f:1c) + softAP (24:0a:c4:82:6f:1d)
W (6603) wifi:adjust channel:11, secondary channel offset:2(40D)
I (6613) wifi:Total power save buffer number: 16
I (6613) wifi:Init max length of beacon: 752/752
I (6623) wifi:Init max length of beacon: 752/752
W (6633) wifi:adjust channel:11, secondary channel offset:2(40D)
I (6643) wifi:Total power save buffer number: 16
I (6643) wifi_node: WIFINodeEvent: Unknown WiFi event [12]
I (6643) wifi_node: WIFINodeEvent: Unknown WiFi event [13]
I (6643) wifi_node: WIFINodeEvent: Unknown WiFi event [12]
I (6943) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (6943) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:0][f0:86:20:13:b4:33]router found<>
I (6953) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-50], mine:0, voter:0
I (6953) mesh: 1369, vote myself, router rssi:-50 > voted rc_rssi:-120
I (6963) mesh: [SCAN:1/10]rc[128][24:0a:c4:82:6f:1d,-50], self[24:0a:c4:82:6f:1c,-50,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (7283) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (7283) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][f0:86:20:13:b4:33]router found<>
I (7283) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-48], mine:0, voter:0
I (7293) mesh: [SCAN:2/10]rc[128][24:0a:c4:82:6f:1d,-49], self[24:0a:c4:82:6f:1c,-48,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (7603) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (7613) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][f0:86:20:13:b4:33]router found<>
I (7613) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-48], mine:0, voter:0
I (7623) mesh: [SCAN:3/10]rc[128][24:0a:c4:82:6f:1d,-48], self[24:0a:c4:82:6f:1c,-48,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (7933) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (7943) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][f0:86:20:13:b4:33]router found<>
I (7943) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-50], mine:0, voter:0
I (7953) mesh: [SCAN:4/10]rc[128][24:0a:c4:82:6f:1d,-48], self[24:0a:c4:82:6f:1c,-50,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (8263) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (8263) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][f0:86:20:13:b4:33]router found<>
I (8273) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-48], mine:0, voter:0
I (8283) mesh: [SCAN:5/10]rc[128][24:0a:c4:82:6f:1d,-48], self[24:0a:c4:82:6f:1c,-48,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (8593) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (8593) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][f0:86:20:13:b4:33]router found<>
I (8603) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-51], mine:0, voter:0
I (8613) mesh: [SCAN:6/10]rc[128][24:0a:c4:82:6f:1d,-48], self[24:0a:c4:82:6f:1c,-51,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (8923) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (8923) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][f0:86:20:13:b4:33]router found<>
I (8933) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-50], mine:0, voter:0
I (8933) mesh: [SCAN:7/10]rc[128][24:0a:c4:82:6f:1d,-48], self[24:0a:c4:82:6f:1c,-50,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (9253) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (9253) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][f0:86:20:13:b4:33]router found<>
I (9263) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-51], mine:0, voter:0
I (9263) mesh: [SCAN:8/10]rc[128][24:0a:c4:82:6f:1d,-48], self[24:0a:c4:82:6f:1c,-51,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (9583) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (9583) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][f0:86:20:13:b4:33]router found<>
I (9593) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-51], mine:0, voter:0
I (9593) mesh: [SCAN:9/10]rc[128][24:0a:c4:82:6f:1d,-48], self[24:0a:c4:82:6f:1c,-51,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (9913) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (9913) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][f0:86:20:13:b4:33]router found<>
I (9923) mesh: 1331[SCAN]init rc[24:0a:c4:82:6f:1d,-47], mine:0, voter:0
I (9923) mesh: [SCAN:10/10]rc[128][24:0a:c4:82:6f:1d,-47], self[24:0a:c4:82:6f:1c,-47,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:0.90][128,1,24:0a:c4:82:6f:1d]

I (9943) mesh: [DONE]connect to router:Lounge, channel:11, rssi:-47, f0:86:20:13:b4:33[layer:0, assoc:0], my_vote_num:1/voter_num:1, rc[24:0a:c4:82:6f:1d/-47/1]
I (9963) wifi:new:<11,2>, old:<11,2>, ap:<11,2>, sta:<11,0>, prof:11, snd_ch_cfg:0x0
I (9973) wifi:state: init -> auth (0xb0)
I (9973) wifi:state: auth -> assoc (0x0)
I (9983) wifi:state: assoc -> run (0x10)
I (12983) wifi:state: run -> init (0xf00)
I (12993) wifi:new:<11,0>, old:<11,2>, ap:<11,2>, sta:<11,0>, prof:11, snd_ch_cfg:0x0
I (12993) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (12993) wifi_node: WIFINodeEvent: WiFi started
I (12993) wifi_node: WIFINodeEvent: Unknown WiFi event [5]
I (13003) mesh_node: MeshNodeEvent: <MESH_EVENT_PARENT_DISCONNECTED>reason:15
I (13003) mesh: [wifi]disconnected reason:15(4-way handshake timeout), continuous:1/max:12, root, vote(,stopped)<><>
I (13013) HomeIoT: cbOnMeshNoParent: Parent has gone setting Meshconnected to false
I (13023) HomeIoT: wifi_node_smart_config_task: Stopping self organise mode
I (13033) mesh: [IO]disable self-organizing
I (13043) HomeIoT: wifi_node_smart_config_task: setting Smart Config type
I (13043) HomeIoT: wifi_node_smart_config_task: starting Smart Config
I (13053) smartconfig: smartconfig errno -1@sc_sniffer.c 573
I (13053) wifi_node: WIFINodeEvent: WiFi started
I (13063) wifi_node: WIFINodeEvent: Unknown WiFi event [5]
I (13063) mesh_node: MeshNodeEvent: <MESH_EVENT_PARENT_DISCONNECTED>reason:106
I (13063) mesh: [wifi]disconnected reason:106(scan fail), continuous:2/max:12, root, vote(,stopped)<><>
I (13073) HomeIoT: cbOnMeshNoParent: Parent has gone setting Meshconnected to false
I (13093) HomeIoT: wifi_node_smart_config_task: Stopping self organise mode
I (13103) smartconfig: SC version: V3.0.2
I (13103) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (13103) smartconfig: scan status 1
I (13163) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (13163) smartconfig: scan status 4
I (13213) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (13213) mesh: <mesh_nwk_task_main,4597>parent is setg_is_wifi_connecting:0, g_is_wifi_disconnecting:0, g_mesh_stop_reconnection:1
I (13213) mesh: [IO]disable self-organizing
I (13213) mesh_node: MeshNodeEvent: <MESH_EVENT_STOP_RECONNECTION>
I (13223) HomeIoT: wifi_node_smart_config_task: setting Smart Config type
ESP_ERROR_CHECK failed: esp_err_t 0xffffffff (ESP_FAIL) at 0x400d9b92
file: "./main/HomeIoT.c" line 110
func: wifi_node_smart_config_task
expression: esp_smartconfig_set_type(SC_TYPE_ESPTOUCH)

abort() was called at PC 0x400897af on core 1

Backtrace: 0x40081add:0x3ffd7ad0 0x400897b9:0x3ffd7af0 0x4009145d:0x3ffd7b10 0x400897af:0x3ffd7b80 0x400d9b92:0x3ffd7bb0 0x4008a25d:0x3ffd7be0

ELF file SHA256: 9bfc081f3

I (12788) esp_core_dump_flash: Save core dump to flash...
I (12794) esp_core_dump_flash: Erase flash 24576 bytes @ 0x187000
I (13156) esp_core_dump_flash: Write end offset 0x5f04, check sum length 4
I (13156) esp_core_dump_flash: Core dump has been saved to flash.
CPU halted.

`

@zhangyanjiaoesp
Copy link
Collaborator

@leenowell
I have tested locally, based on the ip_internal_network example, and changed the code as the following, the smartconfig can get ssid and password successfully, PTAL.

Image

Image

The log is:

I (8643) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (8643) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-26], mine:0, voter:0
I (8643) mesh: [SCAN:10/10]rc[128][1c:9d:c2:41:30:85,-25], self[1c:9d:c2:41:30:84,-26,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (8683) mesh: <nvs>write layer:0
I (8683) mesh: [DONE]connect to router:test_zyj, channel:5, rssi:-26, ac:84:c6:7e:31:2b[layer:0, assoc:0], my_vote_num:1/voter_num:1, rc[1c:9d:c2:41:30:85/-25/1]
I (8733) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<5,0>, prof:5, snd_ch_cfg:0x0
I (8733) wifi:state: init -> auth (0xb0)
I (8763) wifi:state: auth -> assoc (0x0)
I (8793) wifi:state: assoc -> run (0x10)
I (11803) wifi:state: run -> init (0xf00)
I (11813) wifi:new:<5,0>, old:<5,1>, ap:<5,1>, sta:<5,0>, prof:5, snd_ch_cfg:0x0
I (11813) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:15
I (11813) mesh: [wifi]disconnected reason:15(4-way handshake timeout), continuous:1/max:12, root, vote(,stopped)<><>
I (11823) mesh: [IO]disable self-organizing<stop reconnect>
I (11823) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it
I (11823) mesh_main: wifi_node_smart_config_task: setting SC type
I (11843) mesh_main: wifi_node_smart_config_task: starting SC
I (11843) smartconfig: smartconfig errno -1@sc_sniffer.c 573
I (11853) mesh: [wifi]disconnected reason:106(scan fail), continuous:2/max:12, root, vote(,stopped)<><>
I (11853) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:106
I (11903) smartconfig: SC version: V3.0.2
I (11903) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (11903) smartconfig: scan status 1
I (11953) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (11953) smartconfig: scan status 4
I (12003) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (12003) mesh: <mesh_nwk_task_main,4597>parent is set<stop reconnect>g_is_wifi_connecting:0, g_is_wifi_disconnecting:0, g_mesh_stop_reconnection:1
I (12003) mesh: [IO]disable self-organizing<stop reconnect>
I (12013) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it
I (12013) mesh_main: <MESH_EVENT_STOP_RECONNECTION>
I (14793) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (17633) wifi:ic_enable_sniffer
I (17633) smartconfig: Start to find channel...
I (141413) smartconfig: TYPE: ESPTOUCH
I (141413) smartconfig: T|PHONE MAC:d4:1a:3f:32:39:c1
I (141413) smartconfig: T|AP MAC:ac:84:c6:7e:31:2b
I (141413) smartconfig: Found channel on 5-0. Start to get ssid and password...
I (145643) smartconfig: T|pswd: 12345678
I (145643) smartconfig: T|ssid: test_zyj
I (145643) smartconfig: T|bssid: ac:84:c6:7e:31:2b
I (145643) wifi:ic_disable_sniffer

@leenowell
Copy link
Author

@zhangyanjiaoesp thanks for getting back to me.

I thought the internal network example doesn't connect to a router? If so, are you able to test with one that does please? Also, I notice you call esp_mesh_disconnect before esp_mesh_set_self_organised is this required as I think in the docs it just says to call esp_mesh_set_self_organised. Finally where did you call esp_mesh_set_self_organised to put it back into self organised mode?

Oddly the smartconfig errors are still logged too but as you say it does seem to get the smartconfig info. Does it then reconnect to the router with it and the mesh continues to work?

@zhangyanjiaoesp
Copy link
Collaborator

zhangyanjiaoesp commented Jan 20, 2025

@leenowell

  1. I was just testing how to stop the mesh from continuing scan and reconnection operations when the mesh connection fails, and then initiate SmartConfig. After obtaining the SSID and password, I assume you have already handled this in your program, so I didn’t write the corresponding code and test it.
    You can add the disconnect handle code to your code, and test again.

Also, I notice you call esp_mesh_disconnect before esp_mesh_set_self_organised is this required as I think in the docs it just says to call esp_mesh_set_self_organised

We need to analyze specific problems on a case-by-case basis, as the examples in the documentation cannot cover all scenarios.

Finally where did you call esp_mesh_set_self_organised to put it back into self organised mode?

The back to self organised code is here, same to your code.

Image

@leenowell
Copy link
Author

leenowell commented Jan 20, 2025

Hi @zhangyanjiaoesp

Feels like we are making some progress - thanks.

I added esp_mesh_disconnect() as per your example and that seems to have fixed the core dump issue. However similar to what you are seeing (I think?) the whole thing seems to hang once the SmartConfig has received the SSID/ PWD and I never get a SC_EVENT_SEND_ACK_DONE event.

For ease I moved the code into the smart config task function as follows

`
void wifi_node_smart_config_task (void *parm)
{
// DEBUGGING - commented out these 2 lines to replace with the subsequent 2 to set self org (0,0)
// ESP_LOGI(LOG_TAG, "wifi_node_smart_config_task: Stopping the mesh");
// esp_mesh_stop();

ESP_LOGI(LOG_TAG, "wifi_node_smart_config_task: Stopping self organise mode");
esp_mesh_disconnect();
esp_mesh_set_self_organized(0,0);

EventBits_t uxBits;

ESP_LOGI(LOG_TAG, "wifi_node_smart_config_task: setting Smart Config type");
ESP_ERROR_CHECK( esp_smartconfig_set_type(SC_TYPE_ESPTOUCH) );
smartconfig_start_config_t cfg = SMARTCONFIG_START_CONFIG_DEFAULT();

ESP_LOGI(LOG_TAG, "wifi_node_smart_config_task: starting Smart Config");
ESP_ERROR_CHECK( esp_smartconfig_start(&cfg) );

// LEE - replaced the one below with simple loop for now until bug fixed as can't return from a task as causes fatal error
while (1)
{
	vTaskDelay(10 * 1000 / portTICK_PERIOD_MS);
}

}
`

This is the log (I removed a load of Wifi Event [43] lines to save space

I (20309) mesh_node: MeshNodeEvent: <MESH_EVENT_NO_PARENT_FOUND>scan times:60
I (20319) mesh: <MESH_NWK_PARENT_DISCONNECTED>non-root, need_reselect:1
I (20329) HomeIoT: cbOnMeshNoParent: Parent has gone setting Meshconnected to false
I (20339) HomeIoT: wifi_node_smart_config_task: Stopping self organise mode
I (20439) mesh: <MESH_NWK_LOOK_FOR_NETWORK>channelcfg:1 is allowed to switch, do a full channel scan
I (20439) mesh: [IO]disable self-organizing
I (20439) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it
I (20439) HomeIoT: wifi_node_smart_config_task: setting Smart Config type
I (20449) HomeIoT: wifi_node_smart_config_task: starting Smart Config
I (20459) smartconfig: smartconfig errno -1@sc_sniffer.c 573
I (20469) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (20469) mesh: <WIFI_EVENT_SCAN_DONE>status:fail, num:0, id:188
I (20519) smartconfig: SC version: V3.0.2
I (20519) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (22929) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (25349) wifi:ic_enable_sniffer
I (25349) smartconfig: Start to find channel...
I (25349) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (25349) HomeIoT: SmartConfigEvent: Scan done
I (25499) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
I (25649) wifi_node: WIFINodeEvent: Unknown WiFi event [43]
......
I (51739) smartconfig: TYPE: ESPTOUCH
I (51739) smartconfig: T|AP MAC: f0:86:20:13:b4:33
I (51739) smartconfig: Found channel on 11-0. Start to get ssid and password...
I (51739) HomeIoT: SmartConfigEvent: Found channel
I (54579) smartconfig: T|pswd: PASSWORD!
I (54579) smartconfig: T|ssid: Lounge
I (54579) wifi:ic_disable_sniffer
I (54579) HomeIoT: SmartConfigEvent: Got SSID and password
I (54579) HomeIoT: SC_EVENT_GOT_SSID_PSWD: event <2> Received router info so storing it ssid [Lounge] password [PASSWORD!] channel [11]
I (54599) node_config: GetNodeConfigString: Reading config data for [SSID]
I (54599) node_config: ConfigureNode: Config item not found [SSID]
I (54609) node_config: SetNodeConfigString: Value changed setting config data for [SSID] to [Lounge] : existing flash value []
I (54619) node_config: GetNodeConfigString: Reading config data for [PASSWORD]
I (54629) node_config: ConfigureNode: Config item not found [PASSWORD]
I (54629) node_config: SetNodeConfigString: Value changed setting config data for [PASSWORD] to [PASSWORD!] : existing flash value []
I (54649) node_config: GetNodeConfigInt: Reading config data for [CHANNEL]
I (54649) node_config: GetNodeConfigInt: Config iten not found [CHANNEL]
I (54659) node_config: SetNodeConfigInt: Value changed setting config data for [CHANNEL] to [11] : existing flash value [0]
I (54669) HomeIoT: SC_EVENT_GOT_SSID_PSWD: Smart config finished OK

@leenowell
Copy link
Author

leenowell commented Jan 20, 2025

Hi @zhangyanjiaoesp

I have been doing some more testing and discovered the following

  1. Adding SmartConfig to the internal communication mesh example doesn't work either. I start the smart config task on MESH_EVENT_NO_PARENT then once I get the SSID/ Password event I then tried your suggestion of stopping smart config and setting self organised to 1,1. Here is the smart config task code

`
void wifi_node_smart_config_task (void *parm)
{
// DEBUGGING - commented out these 2 lines to replace with the subsequent 2 to set self org (0,0)
// ESP_LOGI(LOG_TAG, "wifi_node_smart_config_task: Stopping the mesh");
// esp_mesh_stop();

ESP_LOGI(LOG_TAG, "wifi_node_smart_config_task: Stopping self organise mode");
esp_mesh_disconnect();
esp_mesh_set_self_organized(0,0);

EventBits_t uxBits;

ESP_LOGI(LOG_TAG, "wifi_node_smart_config_task: setting Smart Config type");
ESP_ERROR_CHECK( esp_smartconfig_set_type(SC_TYPE_ESPTOUCH) );
smartconfig_start_config_t cfg = SMARTCONFIG_START_CONFIG_DEFAULT();

ESP_LOGI(LOG_TAG, "wifi_node_smart_config_task: starting Smart Config");
ESP_ERROR_CHECK( esp_smartconfig_start(&cfg) );

// LEE - replaced the one below with simple loop for now until bug fixed as can't return from a task as causes fatal error
while (1)
{
	vTaskDelay(10 * 1000 / portTICK_PERIOD_MS);
}

}
`
and the code for trying to get it working again

`
case SC_EVENT_GOT_SSID_PSWD:
ESP_LOGI(LOG_TAG, "SmartConfigEvent: Got SSID and password");

		uint8_t nChannel = 0;
		wifi_second_chan_t secChannel = 0;
		ESP_ERROR_CHECK(esp_wifi_get_channel(&nChannel, &secChannel));

        smartconfig_event_got_ssid_pswd_t *evt = (smartconfig_event_got_ssid_pswd_t *) event_data;

		ESP_LOGI(LOG_TAG, "SC_EVENT_GOT_SSID_PSWD: event <%ld> Received router info so storing it ssid [%s] password [%s]", event_id, evt->ssid, evt->password);

		ESP_LOGI(LOG_TAG, "SC_EVENT_GOT_SSID_PSWD: Smart config finished OK");
		
		esp_smartconfig_stop();
		esp_mesh_set_self_organized(1,1);
		esp_mesh_connect();

    break;

`

and the log

I (14813) mesh_main: <MESH_EVENT_NO_PARENT_FOUND>scan times:60 I (14823) mesh: <MESH_NWK_PARENT_DISCONNECTED>non-root, need_reselect:1 I (14833) mesh_main: LEE starting smart config task I (14843) SmartConfig: wifi_node_smart_config_task: Stopping self organise mode I (14853) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it I (14853) mesh: [IO]disable self-organizing<stop reconnect> I (14863) SmartConfig: wifi_node_smart_config_task: setting Smart Config type I (14863) SmartConfig: wifi_node_smart_config_task: starting Smart Config I (14873) smartconfig: smartconfig errno -1@sc_sniffer.c 573 I (14883) mesh: <WIFI_EVENT_SCAN_DONE>status:fail, num:2, id:188 I (14933) smartconfig: SC version: V3.0.2 I (14933) smartconfig: smartconfig errno -1@sc_sniffer.c 535 I (17343) smartconfig: smartconfig errno -1@sc_sniffer.c 535 I (19763) wifi:ic_enable_sniffer I (19763) smartconfig: Start to find channel... I (20003) smartconfig: TYPE: ESPTOUCH I (20003) smartconfig: T|AP MAC: f0:86:20:13:b4:33 I (20003) smartconfig: Found channel on 11-0. Start to get ssid and password... I (23603) smartconfig: T|pswd: PASSWORD! I (23603) smartconfig: T|ssid: Lounge I (23603) wifi:ic_disable_sniffer

It hangs here nothing else logged.

2 .I tried calling esp_smartconfig_stop and that didn't seem to make any difference and it continued to hang
3. If I call one of the following mesh commands after getting the password then processing continues as opposed to it "hanging as before"- esp_mesh_set_router- esp_mesh_set_self_organized

  • esp_mesh_connect

However none connect to the router and end up in a stream of the following

I (29798) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (29798) mesh: [SCAN][ch:1]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:0,i:0][00:00:00:00:00:00]<>
I (29808) mesh: [FAIL][2]root:0, fail:2, normal:0,

backoff:0

  1. I tried the following combination of calls with the logs below but again all end up with the same stream of errors

`
a. smart config stop then self organistation (1,1)
I (29619) HomeIoT: cbOnSmartConfigEvent: About to stop smart config
I (29629) HomeIoT: cbOnSmartConfigEvent: About to go back to self organise mode
I (29629) mesh: [IO]enable self-organizing, search parent
I (29939) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (29939) mesh: [SCAN][ch:1]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:0,i:0][00:00:00:00:00:00]<>
I (29949) mesh: [FAIL][1]root:0, fail:1, normal:0,

backoff:0

b. smart config stop; mesh set router then self organistation (1,1)
I (29499) HomeIoT: SC_EVENT_GOT_SSID_PSWD: Smart config finished OK
I (29499) HomeIoT: cbOnSmartConfigEvent: About to stop smart config
I (29509) HomeIoT: cbOnSmartConfigEvent: About to set router ssid[Lounge] password[LChicago156E1!] ssid_len[6]
I (29519) HomeIoT: cbOnSmartConfigEvent: About to go back to self organise mode
I (29529) mesh: [IO]enable self-organizing, search parent
I (29839) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (29839) mesh: [SCAN][ch:1]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:0,i:0][00:00:00:00:00:00]<>
I (29839) mesh: [FAIL][1]root:0, fail:1, normal:0,

backoff:0

c. smart config stop; mesh set router; self organistation (1,1) then mesh connect
I (29919) HomeIoT: SC_EVENT_GOT_SSID_PSWD: Smart config finished OK
I (29919) HomeIoT: cbOnSmartConfigEvent: About to stop smart config
I (29929) HomeIoT: cbOnSmartConfigEvent: About to set router ssid[Lounge] password[LChicago156E1!] ssid_len[6]
I (29939) HomeIoT: cbOnSmartConfigEvent: About to go back to self organise mode
I (29949) mesh: [IO]enable self-organizing, search parent
I (29949) HomeIoT: cbOnSmartConfigEvent: About call mesh connect
I (29959) mesh: <MESH_NWK_PARENT_DISCONNECTED>already reconnecting, ignore it, stop_reconnection:2
I (30259) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (30259) mesh: [SCAN][ch:1]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:0,i:0][00:00:00:00:00:00]<>
I (30259) mesh: [FAIL][1]root:0, fail:1, normal:0,

backoff:0

d. only self organisation (1,1)
I (29168) HomeIoT: SC_EVENT_GOT_SSID_PSWD: Smart config finished OK
I (29168) HomeIoT: cbOnSmartConfigEvent: About to go back to self organise mode
I (29178) mesh: [IO]enable self-organizing, search parent
I (29488) wifi_node: WIFINodeEvent: Unknown WiFi event [1]
I (29488) mesh: [SCAN][ch:1]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:0,i:0][00:00:00:00:00:00]<>
I (29488) mesh: [FAIL][1]root:0, fail:1, normal:0,

backoff:0

`

@zhangyanjiaoesp
Copy link
Collaborator

@leenowell
I have added the following code, and test again, after getting the SSID and password, the mesh can connect to the router.

if (event_base == SC_EVENT && event_id == SC_EVENT_GOT_SSID_PSWD) {
        ESP_LOGI(MESH_TAG, "Got SSID and password");

        smartconfig_event_got_ssid_pswd_t *evt = (smartconfig_event_got_ssid_pswd_t *)event_data;
        uint8_t ssid[33] = { 0 };
        uint8_t password[65] = { 0 };


        memcpy(ssid, evt->ssid, sizeof(evt->ssid));
        memcpy(password, evt->password, sizeof(evt->password));
        ESP_LOGI(MESH_TAG, "SSID:%s", ssid);
        ESP_LOGI(MESH_TAG, "PASSWORD:%s", password);

        mesh_router_t router = {0};
        router.ssid_len = strlen((const char *)ssid);
        memcpy(router.ssid, ssid, router.ssid_len);
        memcpy(router.password, password, strlen((const char *)password));

        esp_smartconfig_stop();
        esp_mesh_set_router(&router);
        esp_mesh_set_self_organized(1,1);
        esp_mesh_connect();
    }

The log is here, after 60 times fail, the mesh connect successfully.

I (8713) mesh: [DONE]connect to router:test_zyj, channel:5, rssi:-27, ac:84:c6:7e:31:2b[layer:0, assoc:0], my_vote_num:1/voter_num:1, rc[1c:9d:c2:41:30:85/-27/1]
I (8763) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<5,0>, prof:5, snd_ch_cfg:0x0
I (8763) wifi:state: init -> auth (0xb0)
I (8793) wifi:state: auth -> assoc (0x0)
I (8803) wifi:state: assoc -> run (0x10)
I (11803) wifi:state: run -> init (0xf00)
I (11863) wifi:new:<5,0>, old:<5,1>, ap:<5,1>, sta:<5,0>, prof:5, snd_ch_cfg:0x0
I (11863) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:15
I (11863) mesh: [wifi]disconnected reason:15(4-way handshake timeout), continuous:1/max:12, root, vote(,stopped)<><>
I (11873) mesh: [IO]disable self-organizing<stop reconnect>
I (11873) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it
I (11873) mesh_main: wifi_node_smart_config_task: setting SC type
I (11893) mesh_main: wifi_node_smart_config_task: starting SC
I (11893) smartconfig: smartconfig errno -1@sc_sniffer.c 573
I (11903) mesh: [wifi]disconnected reason:106(scan fail), continuous:2/max:12, root, vote(,stopped)<><>
I (11903) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:106
I (11953) smartconfig: SC version: V3.0.2
I (11953) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (11953) smartconfig: scan status 1
I (12003) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (12003) smartconfig: scan status 4
I (12053) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (12053) mesh: <mesh_nwk_task_main,4597>parent is set<stop reconnect>g_is_wifi_connecting:0, g_is_wifi_disconnecting:0, g_mesh_stop_reconnection:1
I (12053) mesh: [IO]disable self-organizing<stop reconnect>
I (12063) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it
I (12063) mesh_main: <MESH_EVENT_STOP_RECONNECTION>
I (14843) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (17683) wifi:ic_enable_sniffer
I (17683) smartconfig: Start to find channel...
I (17683) mesh_main: Scan done
I (23733) smartconfig: TYPE: ESPTOUCH
I (23733) smartconfig: T|AP MAC: ac:84:c6:7e:31:2b
I (23733) smartconfig: Found channel on 5-0. Start to get ssid and password...
I (23743) mesh_main: Found channel
I (25153) smartconfig: T|pswd: 12345678
I (25153) smartconfig: T|ssid: test_zyj
I (25153) smartconfig: T|bssid: ac:84:c6:7e:31:2b
I (25153) wifi:ic_disable_sniffer
I (25163) mesh_main: Got SSID and password
I (25163) mesh_main: SSID:test_zyj
I (25163) mesh_main: PASSWORD:12345678
I (25243) mesh: [IO]enable self-organizing, search parent<adaptive>
I (25253) mesh: <MESH_NWK_PARENT_DISCONNECTED>already reconnecting, ignore it, stop_reconnection:2
I (25553) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (25553) mesh: [FAIL][1]root:0, fail:1, normal:0, <pre>backoff:0

I (25853) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (25863) mesh: [FAIL][2]root:0, fail:2, normal:0, <pre>backoff:0

I (26163) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (26163) mesh: [FAIL][3]root:0, fail:3, normal:0, <pre>backoff:0

I (26293) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (26293) mesh: [FAIL][4]root:0, fail:4, normal:0, <pre>backoff:0

I (26603) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (26603) mesh: [FAIL][5]root:0, fail:5, normal:0, <pre>backoff:0

I (26913) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (26913) mesh: [FAIL][6]root:0, fail:6, normal:0, <pre>backoff:0

I (27033) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (27033) mesh: [FAIL][7]root:0, fail:7, normal:0, <pre>backoff:0

I (27343) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (27343) mesh: [FAIL][8]root:0, fail:8, normal:0, <pre>backoff:0

I (27653) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (27653) mesh: [FAIL][9]root:0, fail:9, normal:0, <pre>backoff:0

I (27783) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (27783) mesh: [FAIL][10]root:0, fail:10, normal:0, <pre>backoff:0

I (28083) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (28093) mesh: [FAIL][11]root:0, fail:11, normal:0, <pre>backoff:0

I (28393) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (28393) mesh: [FAIL][12]root:0, fail:12, normal:0, <pre>backoff:0

I (28523) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (28523) mesh: [FAIL][13]root:0, fail:13, normal:0, <pre>backoff:0

I (28833) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (28833) mesh: [FAIL][14]root:0, fail:14, normal:0, <pre>backoff:0

I (29143) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (29143) mesh: [FAIL][15]root:0, fail:15, normal:0, <pre>backoff:0

I (29263) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (29263) mesh: [FAIL][16]root:0, fail:16, normal:0, <pre>backoff:0

I (29573) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (29573) mesh: [FAIL][17]root:0, fail:17, normal:0, <pre>backoff:0

I (29883) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (29883) mesh: [FAIL][18]root:0, fail:18, normal:0, <pre>backoff:0

I (30013) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (30013) mesh: [FAIL][19]root:0, fail:19, normal:0, <pre>backoff:0

I (30323) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (30323) mesh: [FAIL][20]root:0, fail:20, normal:0, <pre>backoff:0

I (30623) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (30623) mesh: [FAIL][21]root:0, fail:21, normal:0, <pre>backoff:0

I (30753) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (30753) mesh: [FAIL][22]root:0, fail:22, normal:0, <pre>backoff:0

I (31063) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (31063) mesh: [FAIL][23]root:0, fail:23, normal:0, <pre>backoff:0

I (31373) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (31373) mesh: [FAIL][24]root:0, fail:24, normal:0, <pre>backoff:0

I (31503) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (31503) mesh: [FAIL][25]root:0, fail:25, normal:0, <pre>backoff:0

I (31803) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (31803) mesh: [FAIL][26]root:0, fail:26, normal:0, <pre>backoff:0

I (32113) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (32113) mesh: [FAIL][27]root:0, fail:27, normal:0, <pre>backoff:0

I (32243) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (32243) mesh: [FAIL][28]root:0, fail:28, normal:0, <pre>backoff:0

I (32553) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (32553) mesh: [FAIL][29]root:0, fail:29, normal:0, <pre>backoff:0

I (32863) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (32863) mesh: [FAIL][30]root:0, fail:30, normal:0, <pre>backoff:0

I (32983) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (32983) mesh: [FAIL][31]root:0, fail:31, normal:0, <pre>backoff:0

I (33293) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (33293) mesh: [FAIL][32]root:0, fail:32, normal:0, <pre>backoff:0

I (33603) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (33603) mesh: [FAIL][33]root:0, fail:33, normal:0, <pre>backoff:0

I (33733) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (33733) mesh: [FAIL][34]root:0, fail:34, normal:0, <pre>backoff:0

I (34043) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (34043) mesh: [FAIL][35]root:0, fail:35, normal:0, <pre>backoff:0

I (34343) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (34343) mesh: [FAIL][36]root:0, fail:36, normal:0, <pre>backoff:0

I (34473) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (34473) mesh: [FAIL][37]root:0, fail:37, normal:0, <pre>backoff:0

I (34783) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (34783) mesh: [FAIL][38]root:0, fail:38, normal:0, <pre>backoff:0

I (35093) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (35093) mesh: [FAIL][39]root:0, fail:39, normal:0, <pre>backoff:0

I (35223) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (35223) mesh: [FAIL][40]root:0, fail:40, normal:0, <pre>backoff:0

I (35523) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (35523) mesh: [FAIL][41]root:0, fail:41, normal:0, <pre>backoff:0

I (35833) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (35833) mesh: [FAIL][42]root:0, fail:42, normal:0, <pre>backoff:0

I (35963) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (35963) mesh: [FAIL][43]root:0, fail:43, normal:0, <pre>backoff:0

I (36273) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (36273) mesh: [FAIL][44]root:0, fail:44, normal:0, <pre>backoff:0

I (36583) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (36583) mesh: [FAIL][45]root:0, fail:45, normal:0, <pre>backoff:0

I (36703) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (36703) mesh: [FAIL][46]root:0, fail:46, normal:0, <pre>backoff:0

I (37013) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (37013) mesh: [FAIL][47]root:0, fail:47, normal:0, <pre>backoff:0

I (37323) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (37323) mesh: [FAIL][48]root:0, fail:48, normal:0, <pre>backoff:0

I (37453) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (37453) mesh: [FAIL][49]root:0, fail:49, normal:0, <pre>backoff:0

I (37763) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (37763) mesh: [FAIL][50]root:0, fail:50, normal:0, <pre>backoff:0

I (38063) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (38063) mesh: [FAIL][51]root:0, fail:51, normal:0, <pre>backoff:0

I (38193) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (38193) mesh: [FAIL][52]root:0, fail:52, normal:0, <pre>backoff:0

I (38503) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (38503) mesh: [FAIL][53]root:0, fail:53, normal:0, <pre>backoff:0

I (38813) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (38813) mesh: [FAIL][54]root:0, fail:54, normal:0, <pre>backoff:0

I (38943) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (38943) mesh: [FAIL][55]root:0, fail:55, normal:0, <pre>backoff:0

I (39243) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (39243) mesh: [FAIL][56]root:0, fail:56, normal:0, <pre>backoff:0

I (39553) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (39553) mesh: [FAIL][57]root:0, fail:57, normal:0, <pre>backoff:0

I (39683) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (39683) mesh: [FAIL][58]root:0, fail:58, normal:0, <pre>backoff:0

I (39993) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (39993) mesh: [FAIL][59]root:0, fail:59, normal:0, <pre>backoff:0

I (40303) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]<>
I (40303) mesh: [FAIL][60]root:0, fail:60, normal:0, <pre>backoff:0

I (40303) mesh: <MESH_NWK_PARENT_SELECTION>no parent found, set ROOTLESS, scan times:60, heap:171960
I (40313) mesh: <MESH_NWK_PARENT_SELECTION>channel<cfg:0> is allowed to switch, do a full channel scan
I (40313) mesh_main: <MESH_EVENT_NO_PARENT_FOUND>scan times:60
I (40323) wifi:mode : sta (1c:9d:c2:41:30:84)
I (40343) mesh_main: <MESH_EVENT_NETWORK_STATE>is_rootless:1
I (40343) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:1
I (44553) mesh: [S1]test_zyj, ac:84:c6:7e:31:2b, channel:5, rssi:-31
I (44553) mesh: find router:[ssid_len:8]test_zyj, rssi:-31, ac:84:c6:7e:31:2b(encrypted), new channel:5, old channel:0
I (44563) mesh: [FIND][ch:0]AP:66, otherID:0, MAP:0, idle:0, candidate:0, root:0[ac:84:c6:7e:31:2b]router found
I (44573) mesh: [FIND:1]find a network, channel:5, cfg<channel:0, router:test_zyj, 00:00:00:00:00:00>

I (44583) wifi:mode : sta (1c:9d:c2:41:30:84) + softAP (1c:9d:c2:41:30:85)
W (44593) wifi:<MESH AP>adjust channel:5, secondary channel offset:1(40U)
I (44593) wifi:Total power save buffer number: 16
I (44603) wifi:Init max length of beacon: 752/752
I (44603) wifi:Init max length of beacon: 752/752
I (44583) mesh_main: <MESH_EVENT_FIND_NETWORK>new channel:5, router BSSID:00:00:00:00:00:00
W (44623) wifi:<MESH AP>adjust channel:5, secondary channel offset:1(40U)
I (44633) wifi:Total power save buffer number: 16
I (44933) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:0][ac:84:c6:7e:31:2b]router found<>
I (44933) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-31], mine:0, voter:0
I (44943) mesh: 1369, vote myself, router rssi:-31 > voted rc_rssi:-120
I (44943) mesh: [SCAN:1/10]rc[128][1c:9d:c2:41:30:85,-30], self[1c:9d:c2:41:30:84,-31,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (45263) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][ac:84:c6:7e:31:2b]router found<>
I (45263) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-29], mine:0, voter:0
I (45273) mesh: [SCAN:2/10]rc[128][1c:9d:c2:41:30:85,-29], self[1c:9d:c2:41:30:84,-29,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (45583) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][ac:84:c6:7e:31:2b]router found<>
I (45593) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-31], mine:0, voter:0
I (45593) mesh: [SCAN:3/10]rc[128][1c:9d:c2:41:30:85,-29], self[1c:9d:c2:41:30:84,-31,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (45913) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][ac:84:c6:7e:31:2b]router found<>
I (45913) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-30], mine:0, voter:0
I (45923) mesh: [SCAN:4/10]rc[128][1c:9d:c2:41:30:85,-29], self[1c:9d:c2:41:30:84,-30,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (46233) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][ac:84:c6:7e:31:2b]router found<>
I (46233) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-30], mine:0, voter:0
I (46243) mesh: [SCAN:5/10]rc[128][1c:9d:c2:41:30:85,-29], self[1c:9d:c2:41:30:84,-30,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (46563) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][ac:84:c6:7e:31:2b]router found<>
I (46563) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-31], mine:0, voter:0
I (46573) mesh: [SCAN:6/10]rc[128][1c:9d:c2:41:30:85,-29], self[1c:9d:c2:41:30:84,-31,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (46883) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][ac:84:c6:7e:31:2b]router found<>
I (46883) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-30], mine:0, voter:0
I (46893) mesh: [SCAN:7/10]rc[128][1c:9d:c2:41:30:85,-29], self[1c:9d:c2:41:30:84,-30,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (47213) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][ac:84:c6:7e:31:2b]router found<>
I (47213) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-30], mine:0, voter:0
I (47213) mesh: [SCAN:8/10]rc[128][1c:9d:c2:41:30:85,-29], self[1c:9d:c2:41:30:84,-30,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (47533) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][ac:84:c6:7e:31:2b]router found<>
I (47533) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-29], mine:0, voter:0
I (47543) mesh: [SCAN:9/10]rc[128][1c:9d:c2:41:30:85,-29], self[1c:9d:c2:41:30:84,-29,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (47863) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][ac:84:c6:7e:31:2b]router found<>
I (47863) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-30], mine:0, voter:0
I (47863) mesh: [SCAN:10/10]rc[128][1c:9d:c2:41:30:85,-29], self[1c:9d:c2:41:30:84,-30,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (47883) mesh: [DONE]connect to router:test_zyj, channel:5, rssi:-27, ac:84:c6:7e:31:2b[layer:0, assoc:0], my_vote_num:1/voter_num:1, rc[1c:9d:c2:41:30:85/-29/1]
I (48223) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<5,0>, prof:5, snd_ch_cfg:0x0
I (48223) wifi:state: init -> auth (0xb0)
I (48243) wifi:state: auth -> assoc (0x0)
I (48253) wifi:state: assoc -> run (0x10)
I (48303) wifi:connected with test_zyj, aid = 2, channel 5, BW20, bssid = ac:84:c6:7e:31:2b
I (48303) wifi:security: WPA2-PSK, phy: bgn, rssi: -31
I (48303) wifi:pm start, type: 0

I (48303) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
I (48323) mesh: [scan]new scanning time:600ms, beacon interval:300ms
I (48343) mesh: <nvs>write layer:1
I (48343) mesh: <flush>upstream packets, connections(max):6, waiting:0, upQ:0
I (48343) mesh_main: <MESH_EVENT_PARENT_CONNECTED>layer:0-->1, parent:ac:84:c6:7e:31:2b<ROOT>, ID:77:77:77:77:77:76
I (48353) mesh_netif: Already wifi station, no need to do anything
I (48343) mesh: <flush>root

@leenowell
Copy link
Author

leenowell commented Jan 21, 2025

Hi @zhangyanjiaoesp

Great news you have got it working - which example did you use? I have tried your fix on the internal_communication example because this was most like my scenario and it doesn't work. Mine doesn't connect after the 60 attempts and triggers smart config again. I have attached the source code - I had to give them .txt extensions as it wouldn't let me upload otherwise.

smart_config_h.txt
smart_config_c.txt
mesh_main_c.txt

So feels like we are close to finding the problem if we compare what you did with mine. One difference I noticed is that your log shows you getting a MESH_EVENT_PARENT_DISCONNECTED when the first attempt fails whereas mine gets a MESH_EVENT_NO_PARENT_FOUND. Then yours gets a MESH_EVENT_NO_PARENT_FOUND after you set the new ssid/ password mine also gets MESH_EVENT_NO_PARENT_FOUND but this then triggers smart config again!

This is my log I have removed the repeated logs during the 60 retries.

`
ets Jun 8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_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:6328
load:0x40078000,len:15828
load:0x40080400,len:3860
entry 0x40080638
I (27) boot: ESP-IDF v5.5-dev-1050-gb5ac4fbdf9 2nd stage bootloader
I (27) boot: compile time Jan 20 2025 14:49:47
I (27) boot: Multicore bootloader
I (30) boot: chip revision: v0.0
I (33) boot.esp32: SPI Speed : 40MHz
I (36) boot.esp32: SPI Mode : DIO
I (40) boot.esp32: SPI Flash Size : 2MB
I (43) boot: Enabling RNG early entropy source...
I (48) boot: Partition Table:
I (50) boot: ## Label Usage Type ST Offset Length
I (57) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (63) boot: 1 phy_init RF data 01 01 0000f000 00001000
I (70) boot: 2 factory factory app 00 00 00010000 00100000
I (76) boot: End of partition table
I (80) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=22ad0h (142032) map
I (136) esp_image: segment 1: paddr=00032af8 vaddr=3ff80000 size=0001ch ( 28) load
I (136) esp_image: segment 2: paddr=00032b1c vaddr=3ffb0000 size=03f44h ( 16196) load
I (146) esp_image: segment 3: paddr=00036a68 vaddr=40080000 size=095b0h ( 38320) load
I (162) esp_image: segment 4: paddr=00040020 vaddr=400d0020 size=ae864h (714852) map
I (407) esp_image: segment 5: paddr=000ee88c vaddr=400895b0 size=0c998h ( 51608) load
I (438) boot: Loaded app from partition at offset 0x10000
I (438) boot: Disabling RNG early entropy source...
I (448) cpu_start: Multicore app
I (456) cpu_start: Pro cpu start user code
I (456) cpu_start: cpu freq: 160000000 Hz
I (456) app_init: Application information:
I (456) app_init: Project name: internal_communication
I (462) app_init: App version: 1
I (465) app_init: Compile time: Jan 20 2025 15:44:17
I (470) app_init: ELF file SHA256: b1cfb4150...
I (474) app_init: ESP-IDF: v5.5-dev-1050-gb5ac4fbdf9
I (480) efuse_init: Min chip rev: v0.0
I (484) efuse_init: Max chip rev: v3.99
I (488) efuse_init: Chip rev: v0.0
I (492) heap_init: Initializing. RAM available for dynamic allocation:
I (498) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (503) heap_init: At 3FFB9FB8 len 00026048 (152 KiB): DRAM
I (508) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (514) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (519) heap_init: At 40095F48 len 0000A0B8 (40 KiB): IRAM
I (526) spi_flash: detected chip: gd
I (528) spi_flash: flash io: dio
W (531) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (544) main_task: Started on CPU0
I (554) main_task: Calling app_main()
I (604) wifi:wifi driver task: 3ffc22e8, prio:23, stack:6656, core=0
I (624) wifi:wifi firmware version: 34d97ea27
I (624) wifi:wifi certification version: v7.0
I (624) wifi:config NVS flash: enabled
I (624) wifi:config nano formatting: disabled
I (624) wifi:Init data frame dynamic rx buffer num: 32
I (634) wifi:Init static rx mgmt buffer num: 5
I (634) wifi:Init management short buffer num: 32
I (644) wifi:Init dynamic tx buffer num: 32
I (644) wifi:Init static rx buffer size: 1600
I (644) wifi:Init static rx buffer num: 10
I (654) wifi:Init dynamic rx buffer num: 32
I (654) wifi_init: rx ba win: 6
I (654) wifi_init: accept mbox: 6
I (664) wifi_init: tcpip mbox: 32
I (664) wifi_init: udp mbox: 6
I (664) wifi_init: tcp mbox: 6
I (674) wifi_init: tcp tx win: 5760
I (674) wifi_init: tcp rx win: 5760
I (674) wifi_init: tcp mss: 1440
I (674) wifi_init: WiFi IRAM OP enabled
I (684) wifi_init: WiFi RX IRAM OP enabled
I (684) phy_init: phy_version 4840,02e0d70,Sep 2 2024,19:39:07
I (764) wifi:mode : sta (24:0a:c4:82:6f:1c)
I (774) wifi:enable tsf
I (774) wifi:mode : sta (24:0a:c4:82:6f:1c) + softAP (24:0a:c4:82:6f:1d)
I (774) wifi:Total power save buffer number: 16
I (784) wifi:Init max length of beacon: 752/752
I (784) wifi:Init max length of beacon: 752/752
I (794) mesh: read layer:0
I (794) mesh: read assoc:0
I (794) wifi:Set ps type: 1, coexist: 0

I (804) wifi:Total power save buffer number: 16
I (1064) wifi:mode : sta (24:0a:c4:82:6f:1c)
I (1084) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x1, need_scan_router:0x0, look_for_nwk_count:1
I (1084) mesh_main: <MESH_EVENT_MESH_STARTED>ID:77:77:77:77:77:77
I (1084) mesh_main: mesh starts successfully, heap:167148, root not fixed<0>(tree), ps:1
I (1094) main_task: Returned from app_main()
I (1384) mesh: [FIND][ch:11]AP:3, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (1384) mesh: [FIND:1]fail to find a network, channel:0, cfg<channel:11, router:ROUTER_SSID, 00:00:00:00:00:00>

I (1394) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:2
I (1524) mesh: [FIND][ch:11]AP:0, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (1524) mesh: [FIND:2]fail to find a network, channel:0, cfg<channel:11, router:ROUTER_SSID, 00:00:00:00:00:00>
..........................

I (14344) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:59
I (14654) mesh: [FIND][ch:11]AP:3, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (14654) mesh: [FIND:59]fail to find a network, channel:0, cfg<channel:11, router:ROUTER_SSID, 00:00:00:00:00:00>

I (14654) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:60
I (14794) mesh: [FIND][ch:11]AP:0, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (14794) mesh: [FIND:60]fail to find a network, channel:0, cfg<channel:11, router:ROUTER_SSID, 00:00:00:00:00:00>

I (14794) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:61
I (14804) mesh: <MESH_NWK_LOOK_FOR_NETWORK>no parent found, set ROOTLESS, scan times:60, heap:177420
I (14814) mesh: <MESH_NWK_LOOK_FOR_NETWORK>routercfg:00:00:00:00:00:00 is allowed to switch, find routers with SSID:ROUTER_SSID
I (14814) mesh_main: <MESH_EVENT_NO_PARENT_FOUND>scan times:60
I (14824) mesh: <MESH_NWK_PARENT_DISCONNECTED>non-root, need_reselect:1
I (14834) mesh_main: LEE starting smart config task
I (14844) mesh: <MESH_NWK_LOOK_FOR_NETWORK>channelcfg:11 is allowed to switch, do a full channel scan
I (14844) SmartConfig: wifi_node_smart_config_task: Stopping self organise mode
I (14864) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it
I (14864) mesh: [IO]disable self-organizing
I (14874) SmartConfig: wifi_node_smart_config_task: setting Smart Config type
I (14884) SmartConfig: wifi_node_smart_config_task: starting Smart Config
I (14884) smartconfig: smartconfig errno -1@sc_sniffer.c 573
I (14894) mesh: <WIFI_EVENT_SCAN_DONE>status:fail, num:0, id:188
I (14944) smartconfig: SC version: V3.0.2
I (14944) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (17354) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (19774) wifi:ic_enable_sniffer
I (19774) smartconfig: Start to find channel...
I (19774) SmartConfig: SmartConfigEvent: Scan done
I (23344) smartconfig: TYPE: ESPTOUCH
I (23344) smartconfig: T|AP MAC: f0:86:20:13:b4:33
I (23344) smartconfig: Found channel on 11-0. Start to get ssid and password...
I (23344) SmartConfig: SmartConfigEvent: Found channel
I (26054) smartconfig: T|pswd: PASSWORD:)
I (26054) smartconfig: T|ssid: Lounge
I (26054) wifi:ic_disable_sniffer
I (26054) SmartConfig: Got SSID and password
I (26054) SmartConfig: SSID:Lounge
I (26054) SmartConfig: PASSWORD:PASSWORD:)
I (26064) mesh: [IO]enable self-organizing, search parent
I (26074) mesh: <MESH_NWK_PARENT_DISCONNECTED>already reconnecting, ignore it, stop_reconnection:2
I (26374) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:0,i:0][00:00:00:00:00:00]<>
I (26374) mesh: [FAIL][1]root:0, fail:1, normal:0,

backoff:0

I (26674) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:0,i:0][00:00:00:00:00:00]<>
I (26684) mesh: [FAIL][2]root:0, fail:2, normal:0,

backoff:0

................

I (41124) mesh: [SCAN][ch:11]AP:3, other(ID:0, RD:0), MAP:0, idle:0, candidate:0, root:0, topMAP:0[c:0,i:0][00:00:00:00:00:00]<>
I (41124) mesh: [FAIL][60]root:0, fail:60, normal:0,

backoff:0

I (41134) mesh: <MESH_NWK_PARENT_SELECTION>no parent found, set ROOTLESS, scan times:60, heap:172788
I (41144) mesh: <MESH_NWK_PARENT_SELECTION>channelcfg:11 is allowed to switch, do a full channel scan
I (41144) mesh_main: <MESH_EVENT_NO_PARENT_FOUND>scan times:60
I (41154) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:62
I (41154) mesh_main: LEE starting smart config task
I (41164) SmartConfig: wifi_node_smart_config_task: Stopping self organise mode
I (41164) mesh_main: <MESH_EVENT_NETWORK_STATE>is_rootless:1
I (41174) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it
I (41184) mesh: [IO]disable self-organizing
I (41194) SmartConfig: wifi_node_smart_config_task: setting Smart Config type
I (41194) SmartConfig: wifi_node_smart_config_task: starting Smart Config
I (41204) smartconfig: smartconfig errno -1@sc_sniffer.c 573
I (41214) mesh: <WIFI_EVENT_SCAN_DONE>status:fail, num:1, id:249
I (41264) smartconfig: SC version: V3.0.2
I (41264) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (43674) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (46094) wifi:ic_enable_sniffer
I (46094) smartconfig: Start to find channel...
I (46094) SmartConfig: SmartConfigEvent: Scan done

`

I guess once we have this working it seems there are 3 potential bugs

  1. The sc_sniffer.c error logs. I can't find sc_sniffer.c on my system so can see what these are about
  2. Smart config doesn't generate a SC_EVENT_SEND_ACK_DONE and doesn't tell the ESPTouch client it was successful
  3. After given the correct SSID and Password why does it then scan 60 times to failure before then connecting

Good progress and thanks for your help. Now we have a simple case on one of the examples hopefully we can work out where the bug is.

@zhangyanjiaoesp
Copy link
Collaborator

@leenowell

  1. I'm using the ip_internal_network example, not the internal_communication example, but I think both should be ok.
  2. When I set a wrong password, I got the MESH_NWK_PARENT_DISCONNECTED event, so I call the smartconfig task in the MESH_NWK_PARENT_DISCONNECTED event. So, when the mesh fails 60 times and reports the "MESH_EVENT_NO_PARENT_FOUND" event, it will continue run the mesh code, reselect a parent and then reconnect successfully.
  3. The question is: Why do you get the "MESH_EVENT_NO_PARENT_FOUND" event when setting the wrong password?

@leenowell
Copy link
Author

@zhangyanjiaoesp

Yes exactly very odd. Would you be able to try it with the internal_communication example your side please so we can rule out environmental/ SDK version issues or whether there is a difference between the 2 examples which is causing the problem.

For the ip_internal_network example did you simply add smart config task on PARENT_DISCONNECTED and then add the change of SSID. password code in the smart config? If you can confirm, I can try your test my end too to see what happens.

@zhangyanjiaoesp
Copy link
Collaborator

zhangyanjiaoesp commented Jan 21, 2025

@leenowell here is my test code

mesh_main-14433.txt

@leenowell
Copy link
Author

@zhangyanjiaoesp is this the correct file as I can't find any smart config or the code you mentioned above?

@zhangyanjiaoesp
Copy link
Collaborator

@zhangyanjiaoesp is this the correct file as I can't find any smart config or the code you mentioned above?

Sorry, have updated with the correct file

@leenowell
Copy link
Author

Thanks. I will run some tests on this one and let you know how I do. Are you able to test the internal_communication one your side please? I wonder if the difference is that your test doesn't attempt to connect to the router prior to doing the smart config?

@leenowell
Copy link
Author

@zhangyanjiaoesp I created a clean version of ip_internal_network and copy and pasted your mesh_main code into main.c. I did not set any of the config just used the defaults. Curiously I still get MESH_EVENT_NO_PARENT_FOUND

`
I (14668) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:60
I (14798) mesh: [FIND][ch:1]AP:0, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (14798) mesh: [FIND:60]fail to find a network, channel:0, cfg<channel:1, router:ROUTER_SSID, 00:00:00:00:00:00>

I (14808) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:61
I (14818) mesh: <MESH_NWK_LOOK_FOR_NETWORK>no parent found, set ROOTLESS, scan times:60, heap:181880
I (14828) mesh: <MESH_NWK_LOOK_FOR_NETWORK>routercfg:00:00:00:00:00:00 is allowed to switch, find routers with SSID:ROUTER_SSID
I (14828) mesh_main: <MESH_EVENT_NO_PARENT_FOUND>scan times:60
I (14838) mesh: <MESH_NWK_PARENT_DISCONNECTED>non-root, need_reselect:1
I (15148) mesh: [FIND][ch:1]AP:1, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (15148) mesh: [FIND:61]fail to find a network, channel:0, cfg<channel:1, router:ROUTER_SSID, 00:00:00:00:00:00>

I (15158) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x1, look_for_nwk_count:62
I (15288) mesh: [FIND][ch:1]AP:0, otherID:0, MAP:0, idle:0, candidate:0, root:0[00:00:00:00:00:00]
I (15288) mesh: [FIND:62]fail to find a network, channel:0, cfg<channel:1, router:ROUTER_SSID, 00:00:00:00:00:00>

`

Logically though if it is a single node with no router to connect to nor another ESP mesh node then wouldn't we expect MESH_EVENT_NO_PARENT_FOUND to be the event on start up?

Wonder if this is a version difference. For me idf.py --version returns ESP-IDF v5.5-dev-1050-gb5ac4fbdf9

@leenowell
Copy link
Author

Hi @zhangyanjiaoesp

I have done a lot more testing to try and narrow down where the problem is and suspect there may be a few underlying bugs/ issues here. Firstly the good news, I added a flag to stop the smart config being kicked off when the second MESH_EVENT_NO_PARENT_FOUND is received and it does the second 60 attempt scan then connects to the router. Not a real fix but at least we are getting somewhere :).

I have tried a number of things out and gone through the various logs and found the following

  1. The SC_EVENT_SEND_ACK_DONE never gets received and the ESPTouch app doesn't get an acknowledgement. Could be related to the sc_sniffer errors?
  2. After the smart config has received the password and we try and get the mesh reconnected, the scan for 60 attempts is on channel 1 whereas the smart config got channel 11 (at least in my case). I wonder if these 2 are related in that the smart config doesn't fully complete for some reason and therefore the details aren't being passed to the subsequent scan.
  3. I believe the first MESH_EVENT_NO_PARENT_FOUND received is the correct event if the node has never connected to the router nor another mesh node (i.e. our example). The issue is that we get a second one after the second 60 attempt scan. I wonder if we found out why it was doing the second scan and prevented that whether we won't then receive the second one. Again could be related to the previous 2?
  4. I believe you were getting MESH_EVENT_PARENT_DISCONNECTED and I am getting MESH_EVENT_NO_PARENT_FOUND on startup is because you had the correct SSID and channel but incorrect password. All my details were incorrect. I run some tests and only the combination of SSID/ Channels gets MESH_EVENT_PARENT_DISCONNECTED. Assuming MESH_EVENT_NO_PARENT_FOUND means not parent was ever found (as opposed to I had one and now it is gone) this I think must be a bug in the framework as in neither scenario did the node connect to the parent.

Have you been able to find anything your side?

@zhangyanjiaoesp
Copy link
Collaborator

@leenowell
1.

I created a clean version of ip_internal_network and copy and pasted your mesh_main code into main.c. I did not set any of the config just used the defaults. Curiously I still get MESH_EVENT_NO_PARENT_FOUND

If you use the default setting, the router ssid is ROUTER_SSID, and the paswword is ROUTER_PASSWD, of cause you got MESH_EVENT_NO_PARENT_FOUND, because there is no such AP in your environment.
Image

However, when you initially described the issue, you only mentioned using an invalid password. So, during my tests, I always set the correct SSID but an incorrect password, which resulted in a MESH_EVENT_PARENT_DISCONNECTED.

Image

The SC_EVENT_SEND_ACK_DONE never gets received and the ESPTouch app doesn't get an acknowledgement. Could be related to the sc_sniffer errors?

The SC_EVENT_SEND_ACK_DONE is sent in the sc_ack_send_task() function within the smartconfig_ack.c file. In your case, after obtaining the SSID and password through SmartConfig in the SC_EVENT_GOT_SSID_PSWD event, esp_smartconfig_stop() is called. As a result, subsequent SmartConfig operations will not be executed.

@zhangyanjiaoesp
Copy link
Collaborator

@leenowell
If we set the bssid for the router, we can avoid the 60 connection failures and connect successfully directly. Below are my code and log.

Image

I (733) phy_init: phy_version 4840,02e0d70,Sep  2 2024,19:39:07
I (823) wifi:mode : sta (1c:9d:c2:41:30:84) + softAP (1c:9d:c2:41:30:85)
I (823) wifi:enable tsf
I (823) wifi:Total power save buffer number: 16
I (823) wifi:Init max length of beacon: 752/752
I (823) wifi:Init max length of beacon: 752/752
I (843) mesh: <nvs>read layer:1
I (843) mesh: <nvs>read assoc:0
I (853) wifi:Total power save buffer number: 16
I (1113) wifi:mode : sta (1c:9d:c2:41:30:84)
I (1133) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:1
I (1133) mesh_main: <MESH_EVENT_MESH_STARTED>ID:77:77:77:77:77:76
I (1133) mesh_main: mesh starts successfully, heap:177100, root not fixed
I (1143) main_task: Returned from app_main()
I (5343) mesh: [S21]test_zyj, ac:84:c6:7e:31:2b, channel:5, rssi:-22
I (5343) mesh: find router:[ssid_len:8]test_zyj, rssi:-22, ac:84:c6:7e:31:2b(encrypted), new channel:5, old channel:0
I (5353) mesh: [FIND][ch:0]AP:46, otherID:0, MAP:0, idle:0, candidate:0, root:0[ac:84:c6:7e:31:2b]router found
I (5353) mesh: [FIND:1]find a network, channel:5, cfg<channel:0, router:test_zyj, 00:00:00:00:00:00>

I (5363) wifi:mode : sta (1c:9d:c2:41:30:84) + softAP (1c:9d:c2:41:30:85)
W (5373) wifi:<MESH AP>adjust channel:1, secondary channel offset:1(40U)
I (5383) wifi:Total power save buffer number: 16
I (5383) wifi:Init max length of beacon: 752/752
I (5393) wifi:Init max length of beacon: 752/752
I (5363) mesh_main: <MESH_EVENT_FIND_NETWORK>new channel:5, router BSSID:00:00:00:00:00:00
W (5403) wifi:<MESH AP>adjust channel:5, secondary channel offset:1(40U)
I (5413) wifi:Total power save buffer number: 16
I (5713) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (5713) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-21], mine:0, voter:0
I (5723) mesh: 1369, vote myself, router rssi:-21 > voted rc_rssi:-120
I (5733) mesh: [SCAN:1/10]rc[128][1c:9d:c2:41:30:85,-21], self[1c:9d:c2:41:30:84,-21,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (6043) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (6043) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-21], mine:0, voter:0
I (6053) mesh: [SCAN:2/10]rc[128][1c:9d:c2:41:30:85,-21], self[1c:9d:c2:41:30:84,-21,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (6373) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (6373) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-20], mine:0, voter:0
I (6373) mesh: [SCAN:3/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-20,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (6693) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (6693) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-20], mine:0, voter:0
I (6703) mesh: [SCAN:4/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-20,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (7013) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (7023) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-20], mine:0, voter:0
I (7023) mesh: [SCAN:5/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-20,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (7343) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (7343) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-21], mine:0, voter:0
I (7353) mesh: [SCAN:6/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-21,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (7663) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (7663) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-22], mine:0, voter:0
I (7673) mesh: [SCAN:7/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-22,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (7993) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (7993) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-19], mine:0, voter:0
I (8003) mesh: [SCAN:8/10]rc[128][1c:9d:c2:41:30:85,-19], self[1c:9d:c2:41:30:84,-19,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (8313) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (8313) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-21], mine:0, voter:0
I (8323) mesh: [SCAN:9/10]rc[128][1c:9d:c2:41:30:85,-19], self[1c:9d:c2:41:30:84,-21,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (8643) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (8643) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-22], mine:0, voter:0
I (8643) mesh: [SCAN:10/10]rc[128][1c:9d:c2:41:30:85,-19], self[1c:9d:c2:41:30:84,-22,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (8683) mesh: <nvs>write layer:0
I (8683) mesh: [DONE]connect to router:test_zyj, channel:5, rssi:-22, ac:84:c6:7e:31:2b[layer:0, assoc:0], my_vote_num:1/voter_num:1, rc[1c:9d:c2:41:30:85/-19/1]
I (8763) wifi:new:<5,1>, old:<5,1>, ap:<5,1>, sta:<5,0>, prof:5, snd_ch_cfg:0x0
I (8763) wifi:state: init -> auth (0xb0)
I (8783) wifi:state: auth -> assoc (0x0)
I (8813) wifi:state: assoc -> run (0x10)
I (11823) wifi:state: run -> init (0xf00)
I (11833) wifi:new:<5,0>, old:<5,1>, ap:<5,1>, sta:<5,0>, prof:5, snd_ch_cfg:0x0
I (11833) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:15
I (11833) mesh: [wifi]disconnected reason:15(4-way handshake timeout), continuous:1/max:12, root, vote(,stopped)<><>
I (11843) mesh: [IO]disable self-organizing<stop reconnect>
I (11843) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it
I (11843) mesh_main: wifi_node_smart_config_task: setting SC type
I (11863) mesh_main: wifi_node_smart_config_task: starting SC
I (11863) smartconfig: smartconfig errno -1@sc_sniffer.c 573
I (11873) mesh: [wifi]disconnected reason:106(scan fail), continuous:2/max:12, root, vote(,stopped)<><>
I (11873) mesh_main: <MESH_EVENT_PARENT_DISCONNECTED>reason:106
I (11923) smartconfig: SC version: V3.0.2
I (11923) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (11923) smartconfig: scan status 1
I (11973) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (11973) smartconfig: scan status 4
I (12023) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (12023) mesh: <mesh_nwk_task_main,4597>parent is set<stop reconnect>g_is_wifi_connecting:0, g_is_wifi_disconnecting:0, g_mesh_stop_reconnection:1
I (12023) mesh: [IO]disable self-organizing<stop reconnect>
I (12033) mesh: <MESH_NWK_PARENT_DISCONNECTED>already disconnected, ignore it
I (12033) mesh_main: <MESH_EVENT_STOP_RECONNECTION>
I (14813) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (17653) wifi:ic_enable_sniffer
I (17663) smartconfig: Start to find channel...
I (17663) mesh_main: Scan done
I (20083) smartconfig: TYPE: ESPTOUCH
I (20083) smartconfig: T|AP MAC: ac:84:c6:7e:31:2b
I (20083) smartconfig: Found channel on 5-0. Start to get ssid and password...
I (20083) mesh_main: Found channel
I (20353) smartconfig: TYPE: ESPTOUCH
I (20363) smartconfig: Found channel on 5-0. Start to get ssid and password...
I (20363) mesh_main: Found channel
I (22803) smartconfig: T|pswd: 12345678
I (22803) smartconfig: T|ssid: test_zyj
I (22803) smartconfig: T|bssid: ac:84:c6:7e:31:2b
I (22803) wifi:ic_disable_sniffer
I (22813) mesh_main: Got SSID and password
I (22813) mesh_main: SSID:test_zyj
I (22813) mesh_main: PASSWORD:12345678
I (22903) mesh: [IO]enable self-organizing, search parent<adaptive>
I (22903) mesh: <MESH_NWK_PARENT_DISCONNECTED>already reconnecting, ignore it, stop_reconnection:2
I (23203) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (23203) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-22], mine:0, voter:0
I (23213) mesh: 1369, vote myself, router rssi:-22 > voted rc_rssi:-120
I (23213) mesh: [SCAN:1/10]rc[128][1c:9d:c2:41:30:85,-21], self[1c:9d:c2:41:30:84,-22,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (23533) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (23533) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-22], mine:0, voter:0
I (23543) mesh: [SCAN:2/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-22,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (23853) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (23863) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-23], mine:0, voter:0
I (23863) mesh: [SCAN:3/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-23,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (24183) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (24183) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-23], mine:0, voter:0
I (24193) mesh: [SCAN:4/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-23,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (24503) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (24503) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-20], mine:0, voter:0
I (24513) mesh: [SCAN:5/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-20,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (24833) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (24833) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-23], mine:0, voter:0
I (24843) mesh: [SCAN:6/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-23,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (25153) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (25153) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-20], mine:0, voter:0
I (25163) mesh: [SCAN:7/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-20,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (25483) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (25483) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-21], mine:0, voter:0
I (25483) mesh: [SCAN:8/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-21,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (25803) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (25803) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-22], mine:0, voter:0
I (25813) mesh: [SCAN:9/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-22,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (26133) mesh: [SCAN][ch:5]AP:1, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][ac:84:c6:7e:31:2b]router found<>
I (26133) mesh: 1331[SCAN]init rc[1c:9d:c2:41:30:85,-21], mine:0, voter:0
I (26133) mesh: [SCAN:10/10]rc[128][1c:9d:c2:41:30:85,-20], self[1c:9d:c2:41:30:84,-21,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,1c:9d:c2:41:30:85]

I (26153) mesh: [DONE]connect to router:test_zyj, channel:5, rssi:-22, ac:84:c6:7e:31:2b[layer:0, assoc:0], my_vote_num:1/voter_num:1, rc[1c:9d:c2:41:30:85/-20/1]
I (26573) wifi:new:<5,0>, old:<5,0>, ap:<5,0>, sta:<5,0>, prof:5, snd_ch_cfg:0x0
I (26573) wifi:state: init -> auth (0xb0)
I (26603) wifi:state: auth -> assoc (0x0)
I (26643) wifi:state: assoc -> run (0x10)
I (26733) wifi:connected with test_zyj, aid = 3, channel 5, BW20, bssid = ac:84:c6:7e:31:2b
I (26733) wifi:security: WPA2-PSK, phy: bgn, rssi: -21
I (26743) wifi:pm start, type: 0

I (26743) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
I (26753) mesh: [scan]new scanning time:600ms, beacon interval:300ms
I (26773) mesh: <nvs>write layer:1
I (26773) mesh: <flush>upstream packets, connections(max):6, waiting:0, upQ:0
I (26773) mesh_main: <MESH_EVENT_PARENT_CONNECTED>layer:0-->1, parent:ac:84:c6:7e:31:2b<ROOT>, ID:77:77:77:77:77:76
I (26773) mesh: <flush>root

@leenowell
Copy link
Author

Hi @zhangyanjiaoesp

Thanks very much for your reply. I have applied your suggestions to the internal communications examples. Firstly the good news is removing the smart config stop means I get the smart config ACK event and that comes after the node has successfully connected to the router which is probably why it never appeared before. Having said that, the ESPTouch app never gets the ack and fails.

I added the BSSID code you suggested but for me bssid_set is false

`
mesh_router_t router = {0};
router.ssid_len = strlen((const char *)ssid);
memcpy(router.ssid, ssid, router.ssid_len);
memcpy(router.password, password, strlen((const char *)password));
router.allow_router_switch = true;

		if (evt->bssid_set)
		{
			ESP_LOGI( LOG_TAG, "SC_EVENT_GOT_SSID_PSWD: BSSID is set so setting it");
			memcpy(router.bssid, evt->bssid, 6);
		}	
		else
		{
			ESP_LOGI( LOG_TAG, "SC_EVENT_GOT_SSID_PSWD: BSSID is NOT SET so setting as blank");
			memset(router.bssid, '\0', 6);
		}

`

Log is
`
I (14884) SmartConfig: wifi_node_smart_config_task: starting Smart Config
I (14894) smartconfig: smartconfig errno -1@sc_sniffer.c 573
I (14894) mesh: <WIFI_EVENT_SCAN_DONE>status:fail, num:0, id:188
I (14944) smartconfig: SC version: V3.0.2
I (14944) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (17354) smartconfig: smartconfig errno -1@sc_sniffer.c 535
I (19774) wifi:ic_enable_sniffer
I (19774) smartconfig: Start to find channel...
I (19774) SmartConfig: SmartConfigEvent: Scan done
I (19944) smartconfig: TYPE: ESPTOUCH
I (19944) smartconfig: T|AP MAC: f0:86:20:13:b4:33
I (19944) smartconfig: Found channel on 11-0. Start to get ssid and password...
I (19954) SmartConfig: SmartConfigEvent: Found channel
I (22064) smartconfig: T|pswd: LChicago156E:)
I (22064) smartconfig: T|ssid: Lounge
I (22064) wifi:ic_disable_sniffer
I (22064) SmartConfig: Got SSID and password
I (22064) SmartConfig: SSID:Lounge
I (22064) SmartConfig: PASSWORD:PWD:)
I (22074) SmartConfig: SC_EVENT_GOT_SSID_PSWD: BSSID is NOT SET so setting as blank

`

In the log I see the AP MAC address coming through although this isn't quite the same as the BSSID shown on the ESPTouch app (the last byte is 32 rather than 33 on the app). I am using the ESPTouch app on Android (app version 2.3.3 and ESP Touch version 1.1.1) what are you using?

@leenowell
Copy link
Author

Hi @zhangyanjiaoesp

I have tried a few more tests to help get to the bottom of the bug. If I hard code the router config BSSID to be the same as the one logged by smart config then I get the same results as you and the extra scan does not happen. If I set it but to different BSSID then it does the extra scan

So, I think we are looking at a few different potential framework bugs

  1. If BSSID isn't populated but SSID and Password is then it shouldn't do the extra scan and we should see the same behaviour as we do when BSSID is populated. I believe BSSID is not mandatory for smart config hence the is_set entry.
  2. The BSSID displayed on the ESPTouch app is not what it sends to the node running smart config
  3. The is_set is not being set even though we can see the BSSID has been sent in the log
  4. If you send correct SSID, channel but incorrect password at start up, mesh should trigger MESH_EVENT_NO_PARENT as it has never connected to a parent (same way if you send incorrect SSID/ channel) rather than MESH_EVENT_PARENT_DISCONNECTED.
  5. Smart config completes correctly but ESPTouch says it fails. I tried using an app I created using a smart config library I found and it appears to complete correctly although I can't say for sure this is the case as it is in the library. So maybe it is an ESPTouch bug - would be interested to see what you used for your test.

What do you think?

@zhangyanjiaoesp
Copy link
Collaborator

@leenowell
1.

I am using the ESPTouch app on Android (app version 2.3.3 and ESP Touch version 1.1.1) what are you using?

I'm using the ESPTouch app on ios (app version 2.3.0 and ESP Touch version 1.1.0)
2.

  1. If BSSID isn't populated but SSID and Password is then it shouldn't do the extra scan and we should see the same behaviour as we do when BSSID is populated. I believe BSSID is not mandatory for smart config hence the is_set entry.

No, the BSSID is important, because there might be multiple APs with the same SSID in the environment. We rely on the BSSID to ensure that the AP we connect to is the one we actually want to connect to.

The BSSID displayed on the ESPTouch app is not what it sends to the node running smart config
The is_set is not being set even though we can see the BSSID has been sent in the log

The BSSID displayed on the ESPTouch app is that send to node. I don't know why your BSSID displayed on the ESPTouch app is not same with the BSSID in the logs.
If the BSSID is correct, the bssid_set will be set.

If you send correct SSID, channel but incorrect password at start up, mesh should trigger MESH_EVENT_NO_PARENT as it has never connected to a parent (same way if you send incorrect SSID/ channel) rather than MESH_EVENT_PARENT_DISCONNECTED.

If the SSID is correct ,but password is incorrect, the event should be MESH_EVENT_PARENT_DISCONNECTED, because we can find the AP during the scanning phase, but connect fail when changing the EAPOL packets. MESH_EVENT_NO_PARENT indicates that the AP can't be found during the scanning phase.

@leenowell
Copy link
Author

leenowell commented Jan 22, 2025

@zhangyanjiaoesp

@leenowell 1.

I am using the ESPTouch app on Android (app version 2.3.3 and ESP Touch version 1.1.1) what are you using?

I'm using the ESPTouch app on ios (app version 2.3.0 and ESP Touch version 1.1.0) 2.

I tried the smart config example and my ESP Touch app doesn't get the ack back and fails despite sending the details correctly, the node connecting to the router and I received the ACK event. Does yours do the same or is it a bug in the Android version?

  1. If BSSID isn't populated but SSID and Password is then it shouldn't do the extra scan and we should see the same behaviour as we do when BSSID is populated. I believe BSSID is not mandatory for smart config hence the is_set entry.

No, the BSSID is important, because there might be multiple APs with the same SSID in the environment. We rely on the BSSID to ensure that the AP we connect to is the one we actually want to connect to.

I agree it is needed if you only want to attach to a specific router but mesh doesn't require it on either initial start or when you give it new router information. Without the BSSID on start when you give it the correct SSID and password it just connects to any of the ones it finds. The same should happen when we change the router information rather than it doing a random scan on channel 1. The wifi docs seem to confirm this - https://docs.espressif.com/projects/esp-idf/en/stable/esp32/api-guides/wifi.html. Also, I checked the smart config example and it doesn't set the BSSID at all and connects immediately to the router - doesn't even do the short scan the mesh does (i.e. the one that actually connects not the 60 attempt one)

The BSSID displayed on the ESPTouch app is not what it sends to the node running smart config
The is_set is not being set even though we can see the BSSID has been sent in the log

The BSSID displayed on the ESPTouch app is that send to node. I don't know why your BSSID displayed on the ESPTouch app is not same with the BSSID in the logs.

After some further testing I think I know what the issue is. If the phone switched to a different BSSID then I believe the screen updates to the new BSSID but what gets sent is the old BSSID, It could be the other way around but I am pretty sure that is the problem. Should I raise this as a separate issue or are you able to raise it internally?

If the BSSID is correct, the bssid_set will be set.

I double checked the documentation (https://docs.espressif.com/projects/esp-idf/en/stable/esp32/api-reference/network/esp_smartconfig.html) and it says that bssid_set on the smartconfig_event_got_ssid_pswd_t event structure will be set if the bssid is set rather than it is set and it is the correct one. At this point, we haven't called esp_mesh_set_router yet so in theory it wouldn't be able to check it until after the call. Having said that, even with a correct BSSID being sent from the ESPTouch app (seen in the smart config log) bssid_set isn't set. Therefore if the mesh has already checked the BSSID one assumes it has also confirmed the SSID if not the password at this point. So it seems odd that it doesn't just connect automatically rather than us having to call esp_mesh_set_router and then that will check the details?

If you send correct SSID, channel but incorrect password at start up, mesh should trigger MESH_EVENT_NO_PARENT as it has never connected to a parent (same way if you send incorrect SSID/ channel) rather than MESH_EVENT_PARENT_DISCONNECTED.

If the SSID is correct ,but password is incorrect, the event should be MESH_EVENT_PARENT_DISCONNECTED, because we can find the AP during the scanning phase, but connect fail when changing the EAPOL packets. MESH_EVENT_NO_PARENT indicates that the AP can't be found during the scanning phase.

Is there a document that describes which event is triggered when? The documentation is a bit ambiguous

MESH_EVENT_PARENT_DISCONNECTED - parent is disconnected on station interface
MESH_EVENT_NO_PARENT_FOUND - no parent found

@leenowell
Copy link
Author

@zhangyanjiaoesp

Sorry I forgot to ask. Have you managed to look into the errors we see in our smart config logs?

I have checked the smart config example and it doesn't have them so must be something to do with the mesh integration?

@leenowell
Copy link
Author

@zhangyanjiaoesp

I have updated my earlier comment on bssid_set - sorry I had forgotten I had hard coded the BSSID to test if it stopped the extra 60 scans. I run some further tests and can confirm that whilst the bssid appears in the ESPTouch app and comes through to the smart config logs and is one of the 2 BSSIDs of the router (the ESPTouch issue sending a different one is still there) bssid_set is not set and bssid is set to 0's

@zhangyanjiaoesp
Copy link
Collaborator

@leenowell
1.

smartconfig errno -1@sc_sniffer.c 573
smartconfig errno -1@sc_sniffer.c 535

These two errors are not significant and can be ignored. When SmartConfig starts, it first stops scanning and disconnects the Wi-Fi connection. These two logs indicate that the scan has already been stopped and the connection has been disconnected beforehand.

it says that bssid_set on the smartconfig_event_got_ssid_pswd_t event structure will be set if the bssid is set rather than it is set and it is the correct one. At this point, we haven't called esp_mesh_set_router yet so in theory it wouldn't be able to check it until after the call.

I think you're confused. The bssid_set variable is obtained from the provisioning message returned by SmartConfig. Whether this variable is set is determined by parsing the SmartConfig provisioning packet. This has nothing to do with calling the esp_mesh_set_router API.

Is there a document that describes which event is triggered when? The documentation is a bit ambiguous

MESH_EVENT_PARENT_DISCONNECTED - parent is disconnected on station interface
MESH_EVENT_NO_PARENT_FOUND - no parent found

For the MESH_EVENT_NO_PARENT_FOUND event, I think it can be understood literally, that is, there is no parent/app that can be connected, and there is no further documentation explanation. For the MESH_EVENT_PARENT_DISCONNECTED event, it was triggered by the WIFI_EVENT_STA_DISCONNECTED event on WiFi, which can be referred to in the following document:
https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-guides/wifi.html#wifi-event-sta-disconnected

the ESPTouch issue sending a different one is still there

We have never encountered this issue before, and I have tested it with the Android version without any problem. And even if this bssid is not set, it doesn't matter, the subsequent connection of the mesh can still be successful, it just takes some extra time.

@leenowell
Copy link
Author

Hi @zhangyanjiaoesp

Thanks very much for your reply it helped a lot. I have run some more tests and think we are getting close :)

  1. Regarding the ESPTouch issue I believe I have discovered the issue. My router is dual band with each band having a different BSSID. So the issue arises when the phone is connected to the 5GHz band (which will be the default). When the node scans for the smart config, the BSSID in the log is the 2.4GHz one. Does this mean that smart config won't send either BSSID through? I guess Smart Config could just use the BSSID it already has if BSSID is not sent (assuming it is not mandatory for the protocol) or it is 0 (if it is mandatory)?
  2. The smart config example seems to work much better in this scenario than when using it with mesh. In the smart config example if you give it an incorrect BSSID, it still connects immediately and doesn't do the big scan that the mesh does. Is there a way to do the same on Mesh or maybe there is a bug on the mesh? This is the log from the smart config example with incorrect BSSID

`
I (772) smartconfig: SC version: V3.0.2
I (5602) wifi:ic_enable_sniffer
I (5602) smartconfig: Start to find channel...
I (5612) smartconfig_example: Scan done
I (11902) smartconfig: TYPE: ESPTOUCH
I (11902) smartconfig: T|AP MAC: f0:86:20:13:b4:33
I (11902) smartconfig: Found channel on 11-0. Start to get ssid and password...
I (11912) smartconfig_example: Found channel
I (13522) smartconfig: T|pswd: PWD:)
I (13522) smartconfig: T|ssid: Lounge
I (13522) wifi:ic_disable_sniffer
I (13522) smartconfig_example: Got SSID and password
I (13532) smartconfig_example: SSID:Lounge
I (13532) smartconfig_example: PASSWORD:PWD:)
W (13542) wifi:Password length matches WPA2 standards, authmode threshold changes from OPEN to WPA2
I (13842) wifi:new:<11,0>, old:<11,0>, ap:<255,255>, sta:<11,0>, prof:11, snd_ch_cfg:0x0
I (13842) wifi:state: init -> auth (0xb0)
I (13842) wifi:state: auth -> assoc (0x0)
I (13852) wifi:state: assoc -> run (0x10)
I (13872) wifi:connected with Lounge, aid = 3, channel 11, BW20, bssid = f0:86:20:13:b4:33
I (13872) wifi:security: WPA2-PSK, phy: bgn, rssi: -41
I (13882) wifi:pm start, type: 1

I (13882) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
I (13902) wifi:idx:0 (ifx:0, f0:86:20:13:b4:33), tid:0, ssn:2, winSize:64
I (13912) wifi:AP's beacon interval = 102400 us, DTIM period = 3
I (14912) esp_netif_handlers: sta ip: 192.168.1.124, mask: 255.255.255.0, gw: 192.168.1.1
I (14912) smartconfig_example: WiFi Connected to ap
I (17972) smartconfig_example: Smart Config ACK done
`

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Status: In Progress Work is in progress Type: Bug bugs in IDF
Projects
None yet
Development

No branches or pull requests

4 participants