Route request traffic (TZ-869)

[grebenyuk51]

Question

In my Zigbee network there is 32 devices. 28 routers. 16 routers are ESP32-C6. Once every 20-30 seconds in sniffer I can see broadcast messages "Route Request, Dst: 0x0000, Src: 0x....[ESP32-c6 router address]". And this traffic generates only ESP32 devices. Another devices (such as Tuya) don't send such messages. What is the purpose of this messages? is it possible to control frequency of this messages?

Additional context.

No response

[xieqinan]

@grebenyuk51 ,

Which version of the ESP-Zigbee-SDK is being used in your project? Could you please try again with version 1.3.1 of the ESP-Zigbee-SDK?

[grebenyuk51]

Updated to 1.3.1 and have new statistics. You can view file. Network Key for decryption: 35:3c:10:53:c4:55:3f:ce:f3:5b:ec:4c:8c:eb:19:0e
new statistics.zip
For 50 minutes of monitoring ESP32 routers did 82 route requests and another devices did 0 (zero)

In that moments, when network busy with "Route Request" all commands freezes

Some useful information about devices

<style> </style>

ieeeAddr	shortAddr	Chip
0x404ccafffe4aac90	0x24C0	ESP32
0xf082c0fffedd1c68	0x94B4	Tuya
0x3425b4fffecb5c39	0x7786	Tuya
0x385cfbfffe743887	0x9867	Tuya
0xe0798dfffe51e778	0x7D5B	Tuya
0xa4c138b09089f0e5	0xA8D5	Tuya
0xdc8e95fffe45cacf	0x219D	Tuya
0x385cfbfffe96dde7	0xF225	Tuya
0x385cfbfffef31d3b	0xEB99	Tuya
0xa49e69fffe052a69	0x606A	Tuya
0xa49e69fffe01344e	0x2769	Tuya
0x385cfbfffe901404	0x4B44	Tuya
0xa49e69fffe012a0f	0xAB31	Tuya
0xe0798dfffe51e885	0xA2C	Tuya
0xa4c13813ff646f3f	0x9AED	Tuya
0x404ccafffe446ff4	0x58F4	ESP32
0x404ccafffe429980	0xD81C	ESP32
0x404ccafffe42b610	0x1B96	ESP32
0x404ccafffe42b350	0xFE5	ESP32
0x404ccafffe42b5b8	0x8799	ESP32
0x404ccafffe42b328	0xE3F3	ESP32
0x404ccafffe42b2f0	0x70BF	ESP32
0x404ccafffe42b5bc	0x725D	ESP32
0x404ccafffe42b088	0xDF8D	ESP32
0x404ccafffe42b594	0x8B20	ESP32
0x404ccafffe42b34c	0xC13E	ESP32
0x404ccafffe42b028	0xD1E3	ESP32
0x404ccafffe42b318	0xE789	ESP32
0x404ccafffe42b5c0	0x7EFA	ESP32
0x404ccafffe42b2fc	0x335B	ESP32

If you need some more info just ask

[grebenyuk51]

One more thing! In logs I see in moments of rote requests

ZBOSS: nwk/nwk_main.c:1399   Unable to route!, get_discovery_route 0
ZBOSS: nwk/nwk_main.c:1399   Unable to route!, get_discovery_route 0

Also something about RREC, but I not sure if this applicable to this issue
Need to send RREC prior to send a packet

[grebenyuk51]

@xieqinan, is there any news?

[xieqinan]

@grebenyuk51,

Based on the statistics, it seems that the route request phenomenon is reasonable. If a device wants to send a packet to another device but does not know the address of the target device, the sender must broadcast a route request to discover the address. All devices that can hear the broadcast frame will forward it, which is why you see many route requests in the sniffer. Therefore, you can call esp_zb_nwk_get_next_neighbor() and esp_zb_nwk_get_next_route() to get network neighbor information before the sender reports a message to the coordinator (0x0000). If 0x0000 is not present, the route request is necessary, and forwarding by other devices is also necessary. However, there are two points of concern that I need to verify in the next stage:

• Some devices may forward the same route request multiple times.
• The route request (0x0000) command may be sent multiple times by a device every 600 seconds (the 0x0000 address may expire in the neighbor table).

I will verify these issues and get back to you as soon as possible.

[simonborje]

Hi @xieqinan, are there any updates on the investigation?
I have also noticed that ESP based routers sometimes forward route requests multiple times. I ran a test with the latest SDK version 1.4.0 on two ESP32-C6 devices, one as coordinator and the other (id 0x5023) running the HA_color_dimmable_light example. There are also several IKEA zigbee lamps in the network. It looks like the ESP light sometimes end up forwarding multiple route requests within a very short period of time.

[grebenyuk51]

@xieqinan
I have updated to 1.4.1 recently and have some questions

Q1:
As far as I understand there are 4 types of routing mechanisms in ZigBee:

1. Table Routing
2. Broadcast Routing
3. Multicast Routing
4. Many-to-One/Source Routing
   When I see "Route request" in Sniffer this is Broadcast Routing. Am I right?

Q2:
Coordinator once per some time (e.g. 1 minute) initiates Many-to-One routing and creates routes from every node to Coordinator. And if I have only Node-Coordinator communication all routes will be store in routing tables, thus Nodes don't have to discover routes to Coordinator. Am I right?

Q3:
If for Q1 and Q2 answers are "Yes", so why I can see Route Discovery Node-Node? See attached file, ~251 second (Network Key for decryption: 79:16:28:b9:8c:82:89:10:10:4d:87:9b:2c:0e:01:fc)
for_github.zip

[grebenyuk51]

@xieqinan
Let me clarify my question
To my mind, device tries each of the following steps (in this order) until something succeeds:

1. If destination is our own Node Addr, send message using local loopback (no packets emitted).
2. If we are an end device, just pass the message to our parent as the first hop.
3. If destination is one of our end device children, deliver it directly to the child (holding it in the MAC indirect queue until next poll from child if the destination is a sleepy end device).
4. If a source route was found earlier (first step), use that.
5. If we already have a route table entry giving us the next hop (which could have come from a prior route discovery or a prior Many To One Route Request event by the concentrator), just use that.
6. If the destination is in our neighbor table, just send directly to him (assuming an implicit 1-hop route).
7. If still no next hop, fail delivery

In my case (only Coordinator-Node or Node-Coordinator communication) device can use case 5. If my assumption is wrong, please correct me

[grebenyuk51]

@xieqinan

The route request (0x0000) command may be sent multiple times by a device every 600 seconds (the 0x0000 address may expire in the neighbor table).

Q1: In logs though iterating esp_zb_nwk_route_info_t I see only 60 seconds. Furthermore, the type of expiry is uint8_t (255 max), is this correct? uint8_t can't store 600 seconds

Q2: In almost every 10 seconds I can see different next_hop_addr to 0x0000 dst (Coordinator). All devices is my network haven't changed their places for several weeks to now, and all devices works 24/7. Why does this situation happen? I assume that Path Cost Field (metric for measuring quality of a route) the same for 0x4dbf/0x013d/0x74b4 because they are placed on my desk close to each other (distance: current device ->[10cm]-> 0x4dbf/0x013d/0x74b4; current device ->[5m]-> coordinator)

I (44588) ROUTING: err=0, itr=1
dest_addr=0x0000
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (44608) ROUTING: err=0, itr=2
dest_addr=0x7897
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (44618) ROUTING: err=0, itr=3
dest_addr=0x5f77
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (44638) ROUTING: err=261, itr=65535
dest_addr=0x5f77
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
...[10 seconds]...
I (55418) ROUTING: err=0, itr=1
dest_addr=0x0000
next_hop_addr=0x013d
status=0
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=59
I (55428) ROUTING: err=261, itr=65535
dest_addr=0x0000
next_hop_addr=0x013d
status=0
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=59
...[10 seconds]...
I (66208) ROUTING: err=0, itr=1
dest_addr=0x0000
next_hop_addr=0x013d
status=0
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=58
I (66218) ROUTING: err=0, itr=2
dest_addr=0x283a
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (66228) ROUTING: err=261, itr=65535
dest_addr=0x283a
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
...[10 seconds]...
I (77008) ROUTING: err=0, itr=1
dest_addr=0x0000
next_hop_addr=0x013d
status=0
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=58
I (77018) ROUTING: err=0, itr=2
dest_addr=0x7897
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (77038) ROUTING: err=0, itr=3
dest_addr=0x5f77
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (77048) ROUTING: err=261, itr=65535
dest_addr=0x5f77
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
...[10 seconds]...
I (87828) ROUTING: err=0, itr=1
dest_addr=0x0000
next_hop_addr=0x013d
status=0
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=58
I (87838) ROUTING: err=0, itr=2
dest_addr=0x283a
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (87858) ROUTING: err=261, itr=65535
dest_addr=0x283a
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
...[10 seconds]...
I (98638) ROUTING: err=0, itr=1
dest_addr=0x0000
next_hop_addr=0x013d
status=0
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=58
I (98648) ROUTING: err=0, itr=2
dest_addr=0x5f77
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (98668) ROUTING: err=261, itr=65535
dest_addr=0x5f77
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
...[10 seconds]...
I (109448) ROUTING: err=0, itr=1
dest_addr=0x0000
next_hop_addr=0x013d
status=0
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=58
I (109458) ROUTING: err=0, itr=2
dest_addr=0x5f77
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (109478) ROUTING: err=0, itr=3
dest_addr=0x7897
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (109498) ROUTING: err=261, itr=65535
dest_addr=0x7897
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
...[10 seconds]...
I (120288) ROUTING: err=0, itr=1
dest_addr=0x0000
next_hop_addr=0x013d
status=0
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=58
I (120288) ROUTING: err=0, itr=3
dest_addr=0xd487
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (120308) ROUTING: err=261, itr=65535
dest_addr=0xd487
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
...[10 seconds]...
I (131088) ROUTING: err=0, itr=1
dest_addr=0x0000
next_hop_addr=0x74b4
status=0
no_route_cache=0
many_to_one=1
route_record_required=1
group_id=0
expiry=60
I (131098) ROUTING: err=0, itr=2
dest_addr=0x5f77
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (131108) ROUTING: err=0, itr=3
dest_addr=0xfffc
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60
I (131128) ROUTING: err=261, itr=65535
dest_addr=0xfffc
next_hop_addr=0x4dbf
status=1
no_route_cache=0
many_to_one=0
route_record_required=0
group_id=0
expiry=60

[xieqinan]

@grebenyuk51,

I have identified the cause of this issue, which is triggered by the link symmetry mechanism implemented by the stack. For example, consider three neighboring devices A, B, and C. If A receives a packet from C that has been relayed by B in certain situations, A might mistakenly assume that C has migrated to B, even though A could physically communicate with B in one hop. As a result, A will send a route request to discover C.

As we know, when a many-to-one route request is sent by the router, it indicates that the router will act as a network concentrator and will enable route recording to route messages. Based on this theory, we can typically refer to the figure below for analysis.

In the figure, the coordinator acts as a concentrator and uses the many-to-one route request to establish the route path from itself to the 0x7efa router. However, due to the 0x7efa router missing the many-to-one route request from the coordinator in certain traffic scenarios, the request is relayed by another device. As a result, the route path to 0x7efa from the coordinator is not direct. When 0x7efa receives the relayed packet from the coordinator, the link symmetry mechanism is triggered, causing a route request to be initiated. You can regard the mechanism as a bug, it has been reported to ZBOSS, and I will provide an update once it is confirmed.

Hope it help.

[grebenyuk51]

@xieqinan
Thank you for your help! Looking forward for news

[grebenyuk51]

@xieqinan, is there any news?

[xieqinan]

@grebenyuk51 ,

We have reproduced the above issue and are currently testing some fixes. We will notify you once these fixes are released.

[xieqinan]

@grebenyuk51 ,

We've optimized network routing performance in esp-zigbee-sdk v1.5.1. Could you please test it again with this version?

[grebenyuk51]

@xieqinan,
I've been testing update (1.6.0) for several days. Now traffic much much much better. I can see hours without Route Request!
Now I see Many-to-One once per 120 seconds (from Coordinator) and rarely Route Request from ESP32-based routers🎉
Huge work!💪

But still not perfect. Look at new file. Key is the same: 79:16:28:b9:8c:82:89:10:10:4d:87:9b:2c:0e:01:fc
TZ-869_1.6.0.zip
Apply filter "(frame.time_relative > 4050) && (zbee_nwk.addr == 0xcd5b)"
Time 4103 0xCD5B (ESP32-C6 Router, 1.6.0 zb-lib) reported attribute
4114 Route Request from 0xCD5B
4127 Route Request from 0xCD5B
4157 Route Request from 0xCD5B
[0x5D50, 0x38B6, 0xD487 also ESP32-C6 Routers with 1.6.0 zb-lib]

One more use-case:
TZ-869_1.6.0_86dd.zip
0x86DD (ESP32-C6 Router, 1.6.0 zb-lib) didn't communicate with Coordinator 600 sec, Coordinator tried to Read attribute (Z2M Ping feature) and before response 0x86DD generated Route Request
[0x283A also ESP32-C6 Routers with 1.6.0 zb-lib]
0x86DD received Read Attribute Request and knew how to send Response (throw 0x283A, he received request throw this Router)

Unfortunately, I cannot provide logs from devices cos I lost them :( I'll try collect logs and sniff traffic

[grebenyuk51]

@xieqinan, 新年快乐! is there any news?
I have new file. A lot of Route Requests during OTA update. OTA from Coordinator and ZB-device send Route Request to... Coordinator! Very strange situation. SDK 1.6.2

github_ota_TZ-869.zip
Key is the same: 79:16:28:b9:8c:82:89:10:10:4d:87:9b:2c:0e:01:fc

[grebenyuk51]

@xieqinan, @chshu
One more example of Route Request situation

Here is network map

Z10 (0x67C6, ESP32-C6) sends OnOff Request to Coordinator 0x0000, then Coordinator sends this request to 3B3 (0x1411, Tuya)

Every time before 0x67C6 sends OnOff Request it generates Route Request. In network nothing changed. All devices are connected, all devices at the same place. And every time route is the same. SDK 1.6.2. My network has been working for several weeks until now
github_TZ-869-OnOff_Test.zip

Key is the same: 79:16:28:b9:8c:82:89:10:10:4d:87:9b:2c:0e:01:fc
if you need more logs or information, just say and I try to get it. This Route Requests cause very noticeable lags in OnOff Requests
0x67C6 has MAX_CHILDREN=32, by the way

Code of the project sorry for messy code :)

[xieqinan]

@grebenyuk51 ,

Thanks for the information. We have optimized esp-zigbee-sdk v1.6.3 to reduce excessive route discovery in network traffic. Please test again with the latest version.