Mesh back and forth seems to break connection

[kaushalyasat]

Hi,

We have one customer having two CoAP hosts and some CoAP clients in the form of wireless sensors. The sensors are paired to a single host. The pairing is actually in the app level, where the sensor discovers the network IP of the host in pairing host. All the devices have the same PANID and network key.

Recently we have seen a scenario where some sensors seemingly stopped communication with the paired host. By looking at the RSSI graphs, we thought is this caused by a sensor constantly swinging back and forth between two hosts (one host acting as a router). We dont have access to the CLI interface of the hosts as this is a remote site. We see the Sensor RSSI reported back. This is its RSSI with the router/leader immediately connected to at the time.  

Any ideas?

Cheers,

Kaushalya

[Edvin]

Hello,

Can you please try to capture a sniffer trace using the nRF Sniffer for 802154?

What do you mean by "swinging back and forth between two hosts"? Do you mean that it (an End Device, I assume) keeps changing between two routers?

Does it ever re-enter the network, or does it disconnect completely?

Do the nodes move around (physically)? Or are the nodes more or less stationary?

Best regards,

Edvin

[Christina Holman]

Are nRF Sniffer for 802154 ok? run 3

[Edvin]

Hello Kaushalya,

kaushalyasat said:

Normally when it powers up it connects to the network and change it's state to a router/leader. But this time it stayed on as a child!

As you can see in the Openthread documentation, the network will strive to keep the number of routers below 15, if it is feasible. This is in order to be able to expand the network in any direction (physically) when needed. Therefore, if there are no devices that need to attach to your new device, and you already have a large amount of routers, there is no need to promote that device to a router. 

kaushalyasat said:

I guess a FTD will remain a child as long as no child connects to it, am I correct?

Yes, as long as there is a decent coverage of routers in the area of the new child. 

kaushalyasat said:

I can see that in 'coap_send_request (...)' function, it is hard coded to be non-ack type (COAP_TYPE_NON_CON). I dont know if there is a way to request with confirmation using any API. 

Suppose I clone this 'coap_send_request (...)' and modify it to send ACK packet, then I would need to pass a call back with it to know the ack is successful or not?

If there are too few routers in the network, it will promote some of them to routers, so that the network is ready to accept new child nodes.

kaushalyasat said:

This is possible. Our understanding is even it takes time to renegotiate new paths, it should be ok as we are sending temperature info in every 30 sec. Even if the rerout takes couple of minutes, it should be ok. But the issue is once the sensor's (SED)  data is lost, it remains so for days.

Child supervision will not prevent nodes from dropping out of the network. It will just make it easier to detect whether it has happened or not.

...

I am surprised that it doesn't take into account whether you provide a callback function or not, and that you could specify whether the coap_send_request() should be acked or not. But you are right, you can clone this function, and tell it to use COAP_TYPE_CON. Then you can also provide a coap_reply_t reply_cb, which will trigger when the callback occurs. I believe the node will automatically retransmit messages that are not acked, but you can use this while debugging.

...

I agree that it shouldn't happen. If the connection to the parent is lost (because it is powered off), then the child should try to reconnect to the network through some other node. 

kaushalyasat said:

After a while it 'auto-healed' by itself and my provisioning packets are now received by the SED.

I would say that this is the expected behavior (from all other than the router that suddenly disconnected), don't you agree? 

You don't happen to have any logs from the router that suddenly greyed out?

Best regards,

Edvin

[kaushalyasat]

Hi Edvin,

Sorry I forgot to attach the pcap log. 

5633.May-30-prov success and fail.pcapng

Edvin said:

Child supervision will not prevent nodes from dropping out of the network. It will just make it easier to detect whether it has happened or not.

From what we have seen, its not the node dropping off. The nodes (SEDs) are sending their data out to the associated parent. I think the issue is the parent gets into some error state all of a sudden and stops sending these packets any further. 

Edvin said:

I would say that this is the expected behavior (from all other than the router that suddenly disconnected), don't you agree?

What puzzles me is how long it took for the problematic router to be healed. Also this 'healing' happened when I connect to the console, so dont know if that had any effect. As this is a rare event, very difficult to deep diagnose.

This is what I saw from the log while I was connecting to router 0x9400.

Fullscreen 7181.0x9400 log.txt Download

uart:~$ ot rloc16
9400
Done
uart:~$ [01:02:20.614,807] <inf> [I] ChildSupervsn-: sec sinse ast sup 3
[01:02:20.614,898] <inf> [I] ChildSupervsn-: sec sinse ast sup 26
[01:02:20.615,020] <inf> [I] ChildSupervsn-: sec sinse ast sup 12
[01:02:21.614,929] <inf> [I] ChildSupervsn-: sec sinse ast sup 4
[01:02:21.615,020] <inf> [I] ChildSupervsn-: sec sinse ast sup 27
[01:02:21.615,142] <inf> [I] ChildSupervsn-: sec sinse ast sup 13
[01:02:20.614,807] <inf> [I] ChildSupervsn-: sec sinse ast sup 3
[01:02:20.614,898] <inf> [I] ChildSupervsn-: sec sinse ast sup 26
[01:02:20.615,020] <inf> [I] ChildSupervsn-: sec sinse ast sup 12
[01:02:21.614,929] <inf> [I] ChildSupervsn-: sec sinse ast sup 4
[01:02:21.615,020] <inf> [I] ChildSupervsn-: sec sinse ast sup 27
[01:02:21.615,142] <inf> [I] ChildSupervsn-: sec sinse ast sup 13
uart:~$ [01:02:22.614,013] <inf> [I] ChildSupervsn-: sec sinse ast sup 5
[01:02:22.614,135] <inf> [I] ChildSupervsn-: sec sinse ast sup 28
[01:02:22.614,227] <inf> [I] ChildSupervsn-: sec sinse ast sup 14
[01:02:23.036,102] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:3b0a, ecn:no, from:b20fec7a52d53c7b, sec:no, prio:net, rss:-36.0
[01:02:23.036,346] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:b00f:ec7a:52d5:3c7b]:19788
[01:02:23.036,621] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:22.614,013] <inf> [I] ChildSupervsn-: sec sinse ast sup 5
[01:02:22.614,135] <inf> [I] ChildSupervsn-: sec sinse ast sup 28
[01:02:22.614,227] <inf> [I] ChildSupervsn-: sec sinse ast sup 14
[01:02:23.036,102] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:3b0a, ecn:no, from:b20fec7a52d53c7b, sec:no, prio:net, rss:-36.0
[01:02:23.036,346] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:b00f:ec7a:52d5:3c7b]:19788
[01:02:23.036,621] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
uart:~$ [01:02:23.037,536] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:b00f:ec7a:52d5:3c7b,0xa000)
[01:02:23.618,133] <inf> [I] ChildSupervsn-: sec sinse ast sup 6
[01:02:23.618,255] <inf> [I] ChildSupervsn-: sec sinse ast sup 29
[01:02:23.618,347] <inf> [I] ChildSupervsn-: sec sinse ast sup 15
[01:02:23.037,536] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:b00f:ec7a:52d5:3c7b,0xa000)
[01:02:23.618,133] <inf> [I] ChildSupervsn-: sec sinse ast sup 6
[01:02:23.618,255] <inf> [I] ChildSupervsn-: sec sinse ast sup 29
[01:02:23.618,347] <inf> [I] ChildSupervsn-: sec sinse ast sup 15
uart:~$ [01:02:24.182,678] <inf> coap_server: No temp data
[01:02:24.367,675] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:43c7, ecn:no, from:fa6c34f384a1c343, sec:no, prio:net, rss:-55.0
[01:02:24.367,980] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:f86c:34f3:84a1:c343]:19788
[01:02:24.368,255] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:24.369,171] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:f86c:34f3:84a1:c343,0xc000)
[01:02:24.619,262] <inf> [I] Mle-----------: Child timeout expired
[01:02:24.182,678] <inf> coap_server: No temp data
[01:02:24.367,675] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:43c7, ecn:no, from:fa6c34f384a1c343, sec:no, prio:net, rss:-55.0
[01:02:24.367,980] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:f86c:34f3:84a1:c343]:19788
[01:02:24.368,255] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:24.369,171] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:f86c:34f3:84a1:c343,0xc000)
[01:02:24.619,262] <inf> [I] Mle-----------: Child timeout expired
uart:~$ [01:02:24.619,506] <inf> [I] ChildSupervsn-: sec sinse ast sup 7
[01:02:24.619,781] <inf> [I] ChildSupervsn-: Sending supervision message to child 0x9423
[01:02:24.619,903] <inf> [I] ChildSupervsn-: sec sinse ast sup 16
[01:02:24.737,060] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:bc85, ecn:no, from:8a6694118ee9ea9a, sec:no, prio:net, rss:-28.0
[01:02:24.737,304] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:8866:9411:8ee9:ea9a]:19788
[01:02:24.619,506] <inf> [I] ChildSupervsn-: sec sinse ast sup 7
[01:02:24.619,781] <inf> [I] ChildSupervsn-: Sending supervision message to child 0x9423
[01:02:24.619,903] <inf> [I] ChildSupervsn-: sec sinse ast sup 16
[01:02:24.737,060] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:bc85, ecn:no, from:8a6694118ee9ea9a, sec:no, prio:net, rss:-28.0
[01:02:24.737,304] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:8866:9411:8ee9:ea9a]:19788
uart:~$ [01:02:24.737,579] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:24.738,555] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:8866:9411:8ee9:ea9a,0xd400)
[01:02:24.761,047] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:67, chksum:79f8, ecn:no, from:0x3000, sec:yes, prio:net, rss:-69.0
[01:02:24.761,505] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:3000]:61631
[01:02:24.761,749] <inf> [I] MeshForwarder-:     dst:[fdde:ad00:beef:0:0:ff:fe00:9400]:61631
[01:02:24.737,579] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:24.738,555] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:8866:9411:8ee9:ea9a,0xd400)
[01:02:24.761,047] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:67, chksum:79f8, ecn:no, from:0x3000, sec:yes, prio:net, rss:-69.0
[01:▒鲊ƪ▒▒▒<inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:3000]:61631
[01:02:24.884,674] <▒[01:02:30.194,885] <inf> coap_server: No temp data
[01:02:30.616,546] <inf> [I] ChildSupervsn-: sec sinse ast sup 13
[01:02:30.616,668] <inf> [I] ChildSupervsn-: sec sinse ast sup 6
[01:02:30.616,790] <inf> [I] ChildSupervsn-: sec sinse ast sup 22
[01:02:30.194,885] <inf> coap_server: No temp data
[01:02:30.616,546] <inf> [I] ChildSupervsn-: sec sinse ast sup 13
[01:02:30.616,668] <inf> [I] ChildSupervsn-: sec sinse ast sup 6
[01:02:30.616,790] <inf> [I] ChildSupervsn-: sec sinse ast sup 22
uart:~$ [01:02:31.618,682] <inf> [I] ChildSupervsn-: sec sinse ast sup 14
[01:02:31.618,835] <inf> [I] ChildSupervsn-: sec sinse ast sup 7
[01:02:31.618,927] <inf> [I] ChildSupervsn-: sec sinse ast sup 23
[01:02:32.256,805] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:83, chksum:700a, ecn:no, from:02e3e52c9bcab9d9, sec:yes, prio:net, rss:-61.0
[01:02:32.257,049] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:e3:e52c:9bca:b9d9]:19788
[01:02:31.618,682] <inf> [I] ChildSupervsn-: sec sinse ast sup 14
[01:02:31.618,835] <inf> [I] ChildSupervsn-: sec sinse ast sup 7
[01:02:31.618,927] <inf> [I] ChildSupervsn-: sec sinse ast sup 23
[01:02:32.256,805] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:83, chksum:700a, ecn:no, from:02e3e52c9bcab9d9, sec:yes, prio:net, rss:-61.0
[01:02:32.257,049] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:e3:e52c:9bca:b9d9]:19788
uart:~$ [01:02:32.257,324] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:32.614,807] <inf> [I] ChildSupervsn-: sec sinse ast sup 15
[01:02:32.614,898] <inf> [I] ChildSupervsn-: sec sinse ast sup 8
[01:02:32.615,020] <inf> [I] ChildSupervsn-: sec sinse ast sup 24
[01:02:32.257,324] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:32.614,807] <inf> [I] ChildSupervsn-: sec sinse ast sup 15
[01:02:32.614,898] <inf> [I] ChildSupervsn-: sec sinse ast sup 8
[01:02:32.615,020] <inf> [I] ChildSupervsn-: sec sinse ast sup 24
uart:~$ [01:02:33.614,959] <inf> [I] ChildSupervsn-: sec sinse ast sup 16
[01:02:33.615,081] <inf> [I] ChildSupervsn-: sec sinse ast sup 9
[01:02:33.615,173] <inf> [I] ChildSupervsn-: sec sinse ast sup 25
[01:02:34.616,088] <inf> [I] ChildSupervsn-: sec sinse ast sup 17
[01:02:34.616,180] <inf> [I] ChildSupervsn-: sec sinse ast sup 10
[01:02:34.616,302] <inf> [I] ChildSupervsn-: sec sinse ast sup 26
[01:02:33.614,959] <inf> [I] ChildSupervsn-: sec sinse ast sup 16
[01:02:33.615,081] <inf> [I] ChildSupervsn-: sec sinse ast sup 9
[01:02:33.615,173] <inf> [I] ChildSupervsn-: sec sinse ast sup 25
[01:02:34.616,088] <inf> [I] ChildSupervsn-: sec sinse ast sup 17
[01:02:34.616,180] <inf> [I] ChildSupervsn-: sec sinse ast sup 10
[01:02:34.616,302] <inf> [I] ChildSupervsn-: sec sinse ast sup 26
uart:~$ ot [01:02:35.619,232] <inf> [I] ChildSupervsn-: sec sinse ast sup 18
[01:02:35.619,354] <inf> [I] ChildSupervsn-: sec sinse ast sup 11
[01:02:35.619,445] <inf> [I] ChildSupervsn-: sec sinse ast sup 27
[01:02:35.914,001] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:e695, ecn:no, from:768ec5ba1e5e09c6, sec:no, prio:net, rss:-56.0
[01:02:35.914,245] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:748e:c5ba:1e5e:9c6]:19788
[01:02:35.914,489] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:35.619,232] <inf> [I] ChildSupervsn-: sec sinse ast sup 18
uart:~$ ot [01:02:35.915,466] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:748e:c5ba:1e5e:9c6,0xc800)
[01:02:35.619,354] <inf> [I] ChildSupervsn-: sec sinse ast sup 11
[01:02:35.619,445] <inf> [I] ChildSupervsn-: sec sinse ast sup 27
uart:~$ ot [01:02:36.206,848] <inf> coap_server: No temp data
[01:02:36.621,368] <inf> [I] ChildSupervsn-: sec sinse ast sup 19
[01:02:35.914,001] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:e695, ecn:no, from:768ec5ba1e5e09c6, sec:no, prio:net, rss:-56.0
uart:~$ ot [01:02:36.621,520] <inf> [I] ChildSupervsn-: sec sinse ast sup 12
[01:02:36.621,612] <inf> [I] ChildSupervsn-: sec sinse ast sup 28
[01:02:35.914,245] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:748e:c5ba:1e5e:9c6]:19788
[01:02:35.914,489] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:35.915,466] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:748e:c5ba:1e5e:9c6,0xc800)
[01:02:36.206,848] <inf> coap_server: No temp data
[01:02:36.621,368] <inf> [I] ChildSupervsn-: sec sinse ast sup 19
[01:02:36.621,520] <inf> [I] ChildSupervsn-: sec sinse ast sup 12
[01:02:36.621,612] <inf> [I] ChildSupervsn-: sec sinse ast sup 28
uart:~$ ot chil[01:02:37.620,513] <inf> [I] ChildSupervsn-: sec sinse ast sup 20
[01:02:37.620,635] <inf> [I] ChildSupervsn-: sec sinse ast sup 13
[01:02:37.620,727] <inf> [I] ChildSupervsn-: sec sinse ast sup 29
[01:02:38.503,753] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:95, chksum:f385, ecn:no, from:0x941a, sec:yes, prio:normal, rss:-47.0
[01:02:38.504,028] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:fbd0:8244:b15b:7c56]:37410
[01:02:37.620,513] <inf> [I] ChildSupervsn-: sec sinse ast sup 20
uart:~$ ot chil[01:02:38.504,302] <inf> [I] MeshForwarder-:     dst:[fdde:ad00:beef:0:ba0d:8101:b6b1:47f9]:5683
[01:02:37.620,635] <inf> [I] ChildSupervsn-: sec sinse ast sup 13
[01:02:37.620,727] <inf> [I] ChildSupervsn-: sec sinse ast sup 29
uart:~$ ot chil[01:02:38.510,009] <inf> [I] MeshForwarder-: Sent IPv6 UDP msg, len:95, chksum:f385, ecn:no, to:0xc800, sec:yes, prio:normal
[01:02:38.503,753] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:95, chksum:f385, ecn:no, from:0x941a, sec:yes, prio:normal, rss:-47.0
uart:~$ ot chil[01:02:38.510,284] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:fbd0:8244:b15b:7c56]:37410
[01:02:38.510,528] <inf> [I] MeshForwarder-:     dst:[fdde:ad00:beef:0:ba0d:8101:b6b1:47f9]:5683
[01:02:38.504,028] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:fbd0:8244:b15b:7c56]:37410
uart:~$ ot chil[01:02:38.567,596] <inf> [I] DataPollHandlr: Rx data poll, src:0x941a, qed_msgs:0, rss:-46, ack-fp:0
[01:02:38.504,302] <inf> [I] MeshForwarder-:     dst:[fdde:ad00:beef:0:ba0d:8101:b6b1:47f9]:5683
uart:~$ ot chil[01:02:38.617,645] <inf> [I] ChildSupervsn-: sec sinse ast sup 21
[01:02:38.510,009] <inf> [I] MeshForwarder-: Sent IPv6 UDP msg, len:95, chksum:f385, ecn:no, to:0xc800, sec:yes, prio:normal
uart:~$ ot chil[01:02:38.617,767] <inf> [I] ChildSupervsn-: sec sinse ast sup 14
[01:02:38.617,980] <inf> [I] ChildSupervsn-: Sending supervision message to child 0x941b
[01:02:38.510,284] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:fbd0:8244:b15b:7c56]:37410
uart:~$ ot chil[01:02:38.756,408] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:67, chksum:dabb, ecn:no, from:0x3000, sec:yes, prio:net, rss:-73.0
[01:02:38.510,528] <inf> [I] MeshForwarder-:     dst:[fdde:ad00:beef:0:ba0d:8101:b6b1:47f9]:5683
[01:02:38.567,596] <inf> [I] DataPollHandlr: Rx data poll, src:0x941a, qed_msgs:0, rss:-46, ack-fp:0
uart:~$ ot chil[01:02:38.756,652] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:3000]:61631
[01:02:38.617,645] <inf> [I] ChildSupervsn-: sec sinse ast sup 21
uart:~$ ot child[01:02:38.756,927] <inf> [I] MeshForwarder-:     dst:[fdde:ad00:beef:0:0:ff:fe00:9400]:61631
[01:02:38.617,767] <inf> [I] ChildSupervsn-: sec sinse ast sup 14
uart:~$ ot child[01:02:38.757,354] <inf> [I] NetDiag-------: Received DiagGetRequest from fdde:ad00:beef:0:0:ff:fe00:3000
[01:02:38.617,980] <inf> [I] ChildSupervsn-: Sending supervision message to child 0x941b
[01:02:38.756,408] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:67, chksum:dabb, ecn:no, from:0x3000, sec:yes, prio:net, rss:-73.0
uart:~$ ot child[01:02:38.764,831] <inf> [I] MeshForwarder-: Sent IPv6 UDP msg, len:116, chksum:f6d0, ecn:no, to:0x3000, sec:yes, prio:normal
[01:02:38.756,652] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:3000]:61631
uart:~$ ot child[01:02:38.765,136] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:9400]:61631
[01:02:38.756,927] <inf> [I] MeshForwarder-:     dst:[fdde:ad00:beef:0:0:ff:fe00:9400]:61631
uart:~$ ot child[01:02:38.765,411] <inf> [I] MeshForwarder-:     dst:[fdde:ad00:beef:0:0:ff:fe00:3000]:61631
[01:02:38.757,354] <inf> [I] NetDiag-------: Received DiagGetRequest from fdde:ad00:beef:0:0:ff:fe00:3000
uart:~$ ot child[01:02:38.814,727] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:9670, ecn:no, from:c2e03dbce20f9792, sec:no, prio:net, rss:-21.0
[01:02:38.764,831] <inf> [I] MeshForwarder-: Sent IPv6 UDP msg, len:116, chksum:f6d0, ecn:no, to:0x3000, sec:yes, prio:normal
uart:~$ ot child[01:02:38.815,032] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:c0e0:3dbc:e20f:9792]:19788
[01:02:38.765,136] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:9400]:61631
uart:~$ ot child[01:02:38.815,277] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:38.816,192] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c0e0:3dbc:e20f:9792,0x9800)
[01:02:38.765,411] <inf> [I] MeshForwarder-:     dst:[fdde:ad00:beef:0:0:ff:fe00:3000]:61631
[01:02:38.814,727] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:9670, ecn:no, from:c2e03dbce20f9792, sec:no, prio:net, rss:-21.0
uart:~$ ot child[01:02:38.961,761] <inf> [I] DataPollHandlr: Rx data poll, src:0x941b, qed_msgs:1, rss:-65, ack-fp:1
[01:02:38.815,032] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:c0e0:3dbc:e20f:9792]:19788
[01:02:38.815,277] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:38.816,192] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c0e0:3dbc:e20f:9792,0x9800)
[01:02:38.961,761] <inf> [I] DataPollHandlr: Rx data poll, src:0x941b, qed_msgs:1, rss:-65, ack-fp:1
uart:~$ ot child [01:02:39.616,790] <inf> [I] ChildSupervsn-: sec sinse ast sup 22
[01:02:39.616,912] <inf> [I] ChildSupervsn-: sec sinse ast sup 15
[01:02:39.617,004] <inf> [I] ChildSupervsn-: sec sinse ast sup 1
[01:02:40.620,971] <inf> [I] ChildSupervsn-: sec sinse ast sup 23
[01:02:40.621,093] <inf> [I] ChildSupervsn-: sec sinse ast sup 16
[01:02:40.621,185] <inf> [I] ChildSupervsn-: sec sinse ast sup 2
[01:02:39.616,790] <inf> [I] ChildSupervsn-: sec sinse ast sup 22
uart:~$ ot child tab[01:02:41.107,147] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:ec14, ecn:no, from:ca14168e1d0ab00d, sec:no, prio:net, rss:-69.0
[01:02:41.107,513] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:c814:168e:1d0a:b00d]:19788
[01:02:41.107,971] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
--- 1 messages dropped ---
[01:02:39.616,912] <inf> [I] ChildSupervsn-: sec sinse ast sup 15
[01:02:39.617,004] <inf> [I] ChildSupervsn-: sec sinse ast sup 1
uart:~$ ot child tab[01:02:41.108,978] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c814:168e:1d0a:b00d,0x1c00)
[01:02:40.620,971] <inf> [I] ChildSupervsn-: sec sinse ast sup 23
uart:~$ ot child tab[01:02:41.623,107] <inf> [I] ChildSupervsn-: sec sinse ast sup 24
[01:02:40.621,093] <inf> [I] ChildSupervsn-: sec sinse ast sup 16
uart:~$ ot child tab[01:02:41.623,199] <inf> [I] ChildSupervsn-: sec sinse ast sup 17
[01:02:40.621,185] <inf> [I] ChildSupervsn-: sec sinse ast sup 2
uart:~$ ot child tab[01:02:41.623,321] <inf> [I] ChildSupervsn-: sec sinse ast sup 3
[01:02:41.107,513] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:c814:168e:1d0a:b00d]:19788
uart:~$ ot child tab[01:02:42.218,536] <inf> coap_server: No temp data
[01:02:41.107,971] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:41.108,978] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c814:168e:1d0a:b00d,0x1c00)
[01:02:41.623,107] <inf> [I] ChildSupervsn-: sec sinse ast sup 24
[01:02:41.623,199] <inf> [I] ChildSupervsn-: sec sinse ast sup 17
[01:02:41.623,321] <inf> [I] ChildSupervsn-: sec sinse ast sup 3
[01:02:42.218,536] <inf> coap_server: No temp data
uart:~$ ot child table[01:02:42.579,925] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:15a7, ecn:no, from:62521c7deb161193, sec:no, prio:net, rss:-29.0
[01:02:42.580,200] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:6052:1c7d:eb16:1193]:19788
[01:02:42.580,474] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:42.581,634] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:6052:1c7d:eb16:1193,0x2c00)
[01:02:42.579,925] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:15a7, ecn:no, from:62521c7deb161193, sec:no, prio:net, rss:-29.0
uart:~$ ot child table[01:02:42.627,227] <inf> [I] ChildSupervsn-: sec sinse ast sup 25
[01:02:42.627,349] <inf> [I] ChildSupervsn-: sec sinse ast sup 18
[01:02:42.580,200] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:6052:1c7d:eb16:1193]:19788
uart:~$ ot child table[01:02:42.627,441] <inf> [I] ChildSupervsn-: sec sinse ast sup 4
[01:02:43.629,608] <inf> [I] ChildSupervsn-: sec sinse ast sup 26
[01:02:42.580,474] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
uart:~$ ot child table[01:02:43.629,730] <inf> [I] ChildSupervsn-: sec sinse ast sup 19
[01:02:42.581,634] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:6052:1c7d:eb16:1193,0x2c00)
uart:~$ ot child table[01:02:43.629,821] <inf> [I] ChildSupervsn-: sec sinse ast sup 5
[01:02:42.627,227] <inf> [I] ChildSupervsn-: sec sinse ast sup 25
[01:02:42.627,349] <inf> [I] ChildSupervsn-: sec sinse ast sup 18
[01:02:42.627,441] <inf> [I] ChildSupervsn-: sec sinse ast sup 4
[01:02:43.629,608] <inf> [I] ChildSupervsn-: sec sinse ast sup 26
[01:02:43.629,730] <inf> [I] ChildSupervsn-: sec sinse ast sup 19
[01:02:43.629,821] <inf> [I] ChildSupervsn-: sec sinse ast sup 5
uart:~$ ot child table
| ID  | RLOC16 | Timeout    | Age        | LQ In | C_VN |R|D|N|Ver|CSL|QMsgCnt| Extended MAC     |
+-----+--------+------------+------------+-------+------+-+-+-+---+---+-------+------------------+
|  26 | 0x941a |        240 |          5 |     3 |  225 |0|0|0|  4| 0 |     0 | 2646710567a57593 |
|  35 | 0x9423 |        240 |         19 |     3 |  225 |0|0|0|  4| 0 |     0 | 76bcc914f4f0de22 |
|  27 | 0x941b |        240 |          5 |     3 |  225 |0|0|0|  4| 0 |     0 | 664d9a2a076dabbd |

Done
uart:~$ [01:02:44.629,699] <inf> [I] ChildSupervsn-: sec sinse ast sup 27
[01:02:44.629,821] <inf> [I] ChildSupervsn-: sec sinse ast sup 20
[01:02:44.629,943] <inf> [I] ChildSupervsn-: sec sinse ast sup 6
[01:02:45.630,828] <inf> [I] ChildSupervsn-: sec sinse ast sup 28
[01:02:45.630,920] <inf> [I] ChildSupervsn-: sec sinse ast sup 21
[01:02:45.631,042] <inf> [I] ChildSupervsn-: sec sinse ast sup 7
[01:02:44.629,699] <inf> [I] ChildSupervsn-: sec sinse ast sup 27
[01:02:44.629,821] <inf> [I] ChildSupervsn-: sec sinse ast sup 20
[01:02:44.629,943] <inf> [I] ChildSupervsn-: sec sinse ast sup 6
[01:02:45.630,828] <inf> [I] ChildSupervsn-: sec sinse ast sup 28
[01:02:45.630,920] <inf> [I] ChildSupervsn-: sec sinse ast sup 21
[01:02:45.631,042] <inf> [I] ChildSupervsn-: sec sinse ast sup 7
uart:~$ [01:02:46.630,004] <inf> [I] ChildSupervsn-: sec sinse ast sup 29
[01:02:46.630,126] <inf> [I] ChildSupervsn-: sec sinse ast sup 22
[01:02:46.630,218] <inf> [I] ChildSupervsn-: sec sinse ast sup 8
[01:02:47.631,225] <inf> [I] ChildSupervsn-: Sending supervision message to child 0x941a
[01:02:47.631,317] <inf> [I] ChildSupervsn-: sec sinse ast sup 23
[01:02:47.631,408] <inf> [I] ChildSupervsn-: sec sinse ast sup 9
[01:02:46.630,004] <inf> [I] ChildSupervsn-: sec sinse ast sup 29
[01:02:46.630,126] <inf> [I] ChildSupervsn-: sec sinse ast sup 22
[01:02:46.630,218] <inf> [I] ChildSupervsn-: sec sinse ast sup 8
[01:02:47.631,225] <inf> [I] ChildSupervsn-: Sending supervision message to child 0x941a
[01:02:47.631,317] <inf> [I] ChildSupervsn-: sec sinse ast sup 23
[01:02:47.631,408] <inf> [I] ChildSupervsn-: sec sinse ast sup 9
uart:~$ [01:02:48.229,797] <inf> coap_server: No temp data
[01:02:48.571,228] <inf> [I] DataPollHandlr: Rx data poll, src:0x941a, qed_msgs:1, rss:-46, ack-fp:1
[01:02:48.633,331] <inf> [I] ChildSupervsn-: sec sinse ast sup 1
[01:02:48.633,453] <inf> [I] ChildSupervsn-: sec sinse ast sup 24
[01:02:48.633,544] <inf> [I] ChildSupervsn-: sec sinse ast sup 10
[01:02:49.060,882] <inf> [I] Mle-----------: Send Announce on channel 18
[01:02:49.067,108] <inf> [I] MeshForwarder-: Sent IPv6 UDP msg, len:83, chksum:81d4, ecn:no, to:0xffff, sec:yes, prio:net
[01:02:48.229,797] <inf> coap_server: No temp data
[01:02:48.571,228] <inf> [I] DataPollHandlr: Rx data poll, src:0x941a, qed_msgs:1, rss:-46, ack-fp:1
[01:02:48.633,331] <inf> [I] ChildSupervsn-: sec sinse ast sup 1
[01:02:48.633,453] <inf> [I] ChildSupervsn-: sec sinse ast sup 24
[01:02:48.633,544] <inf> [I] ChildSupervsn-: sec sinse ast sup 10
[01:02:49.060,882] <inf> [I] Mle-----------: Send Announce on channel 18
[01:02:49.067,108] <inf> [I] MeshForwarder-: Sent IPv6 UDP msg, len:83, chksum:81d4, ecn:no, to:0xffff, sec:yes, prio:net
uart:~$ [01:02:49.067,413] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:28aa:8ef9:4725:83eb]:19788
[01:02:49.067,657] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:49.067,413] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:28aa:8ef9:4725:83eb]:19788
[01:02:49.067,657] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
uart:~$ [01:02:49.636,566] <inf> [I] ChildSupervsn-: sec sinse ast sup 2
[01:02:49.636,688] <inf> [I] ChildSupervsn-: sec sinse ast sup 25
[01:02:49.636,779] <inf> [I] ChildSupervsn-: sec sinse ast sup 11
[01:02:49.995,086] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:1ae2, ecn:no, from:8a6694118ee9ea9a, sec:no, prio:net, rss:-29.0
[01:02:49.995,330] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:8866:9411:8ee9:ea9a]:19788
[01:02:49.636,566] <inf> [I] ChildSupervsn-: sec sinse ast sup 2
[01:02:49.636,688] <inf> [I] ChildSupervsn-: sec sinse ast sup 25
[01:02:49.636,779] <inf> [I] ChildSupervsn-: sec sinse ast sup 11
[01:02:49.995,086] <inf> [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:1ae2, ecn:no, from:8a6694118ee9ea9a, sec:no, prio:net, rss:-29.0
[01:02:49.995,330] <inf> [I] MeshForwarder-:     src:[fe80:0:0:0:8866:9411:8ee9:ea9a]:19788
uart:~$ [01:02:49.995,574] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:49.996,551] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:8866:9411:8ee9:ea9a,0xd400)
[01:02:50.639,709] <inf> [I] ChildSupervsn-: sec sinse ast sup 3
[01:02:50.639,801] <inf> [I] ChildSupervsn-: sec sinse ast sup 26
[01:02:50.639,923] <inf> [I] ChildSupervsn-: sec sinse ast sup 12
[01:02:49.995,574] <inf> [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
[01:02:49.996,551] <inf> [I] Mle-----------: Receive Advertisement (fe80:0:0:0:8866:9411:8ee9:ea9a,0xd400)
[01:02:50.639,709] <inf> [I] ChildSupervsn-: sec sinse ast sup 3
[01:02:50.639,801] <inf> [I] ChildSupervsn-: sec sinse ast sup 26
[01:02:50.639,923] <inf> [I] ChildSupervsn-: sec sinse ast sup 12
uart:~$ [01:02:51.643,859] <inf> [I] ChildSupervsn-: sec sinse ast sup 4
[01:02:51.644,012] <inf> [I] ChildSupervsn-: sec sinse ast sup 27
[01:02:51.644,104] <inf> [I] ChildSupervsn-: sec sinse ast sup 13
[01:02:52.190,673] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0x7400, sec:yes, prio:normal, rss:-18.0
--- 10 messages dropped ---
[01:02:52.233,032] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
--- 29 messages dropped ---
[01:02:52.262,115] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
--- 39 messages dropped ---
[01:02:51.643,859] <inf> [I] ChildSupervsn-: sec sinse ast sup 4
[01:02:51.644,012] <inf> [I] ChildSupervsn-: sec sinse ast sup 27
[01:02:51.644,104] <inf> [I] ChildSupervsn-: sec sinse ast sup 13
[01:02:52.190,673] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0x7400, sec:yes, prio:normal, rss:-18.0
[01:02:52.233,032] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.262,115] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
uart:~$ --- 10 messages dropped ---
[01:02:52.279,785] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0xc000, sec:yes, prio:normal, rss:-44.0
[01:02:52.280,029] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.280,273] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.282,165] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0x2c00, sec:yes, prio:normal, rss:-28.0
--- 10 messages dropped ---
[01:02:52.279,785] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0xc000, sec:yes, prio:normal, rss:-44.0
[01:02:52.280,029] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.280,273] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.282,165] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0x2c00, sec:yes, prio:normal, rss:-28.0
uart:~$ [01:02:52.282,440] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.282,684] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.286,926] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0xb000, sec:yes, prio:normal, rss:-52.0
[01:02:52.287,200] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.287,445] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.282,440] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.282,684] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.286,926] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0xb000, sec:yes, prio:normal, rss:-52.0
[01:02:52.287,200] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.287,445] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
uart:~$ [01:02:52.289,855] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0x1c00, sec:yes, prio:normal, rss:-68.0
[01:02:52.290,100] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.290,496] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.292,724] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0xa000, sec:yes, prio:normal, rss:-35.0
[01:02:52.292,999] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.289,855] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0x1c00, sec:yes, prio:normal, rss:-68.0
[01:02:52.290,100] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.290,496] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.292,724] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0xa000, sec:yes, prio:normal, rss:-35.0
[01:02:52.292,999] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
uart:~$ [01:02:52.293,273] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.296,020] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0x0800, sec:yes, prio:normal, rss:-67.0
[01:02:52.296,264] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.296,539] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.302,520] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0xc800, sec:yes, prio:normal, rss:-54.0
[01:02:52.293,273] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.296,020] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0x0800, sec:yes, prio:normal, rss:-67.0
[01:02:52.296,264] <inf> [I] MeshForwarder-:     src:[fdde:ad00:beef:0:0:ff:fe00:7400]
[01:02:52.296,539] <inf> [I] MeshForwarder-:     dst:[ff03:0:0:0:0:0:0:2]
[01:02:52.302,520] <inf> [I] MeshForwarder-: Received IPv6 HopOpts msg, len:86, chksum:0000, ecn:no, from:0xc800, sec:yeK▒ɥ▒▒r▒ɵ▒▒▒ rss:-54.0
uart:~$▒▒▒▒▒▒m▒8Duart▒ [01:02:52.302▒▒] ▒▒l:▒▒  ▒▒▒▒

Also, is there a way to detach from a parent and start a renegotiate to connect to a different router? I tried 'ot detach', 'ot thread stop' and 'ot  thread start' from the SED. But I think since the SED is still in the child table of the first parent, all that happens is that I get a new RLOC. I guess if I wait 240 sec timeout, and try thread stop/start, I might get connected to a new router. What do you think?

Cheers,

Kaushalya

[Edvin]

kaushalyasat said:

From what we have seen, its not the node dropping off. The nodes (SEDs) are sending their data out to the associated parent. I think the issue is the parent gets into some error state all of a sudden and stops sending these packets any further. 

But the supervision messages are only between the child and it's parent, so this message is not routed to any other routers than the parent itself. Right?

kaushalyasat said:

What puzzles me is how long it took for the problematic router to be healed. Also this 'healing' happened when I connect to the console, so dont know if that had any effect. As this is a rare event, very difficult to deep diagnose.

How long did it take?

kaushalyasat said:

This is what I saw from the log while I was connecting to router 0x9400.

So this is the log from the router. When did it crash? (timestamp?)

kaushalyasat said:

I guess if I wait 240 sec timeout, and try thread stop/start, I might get connected to a new router. What do you think?

I would assume it does. But I guess the main issue here is that this is not happening at all times, right?

[kaushalyasat]

Hi Edvin,

Sorry about my delay, I was not well past couple of days and only now back in work.

Edvin said:

But the supervision messages are only between the child and it's parent, so this message is not routed to any other routers than the parent itself. Right?

No the message is send to another router. The parent is just routing it through. 

I think we have identified a potential pitfall in openthread networks. That is partitioning. We think our failure mechanism can be explained by that. 

Think of two routers and a set of sensors (SEDs). If both routers are in the same partition, then no issues. But for whatever reason one router lost its connection to the other, then there will be two network partitions. The problem happens when the Sensors can still reach both routers. If a sensor that is sensing data the router1 suddenly lost its connection and connected to router2, the data path will be broken, but the Sensor will happily stay in the current connection until another MLE session decide to connect back to router1. The issue is for the MLE protocol, every router in range is a potential parent, but this may not work for application data.

It looks like we cant constrain the MLE process to limit the parent search to its own partition. We can implement a two way handshake from application level and initiate another MLE session from the Sensor, but there is no guarantee that it may not choose a parent from a different partition.

Edvin said:

So this is the log from the router. When did it crash? (timestamp?)

Sorry Edvin, as this happened when we were not at office, we dont know exactly at what time this happened. So it may be very diff to extract it from the log.

Cheers,

Kaushalya

[Edvin]

Hello Kaushalya,

Interesting. If the parents split into two different networks, then there will exist two different networks with the same credentials, not able to communicate with one another. And it is not possible to connect the two networks using a SED device.

The solution is "simple". You need to make sure that if you struggle with that the two partitions of the network can't reach one another, you need to add another router that can reach both the network partitions (so that they are no longer separate partitions). 

I believe this is where we started this conversation. I remember asking for state changes to see if a router became leader (which it will if part of the network splits out in it's own partition). 

Is it an option to add another router making sure the network doesn't split into two partitions?

Best regards,

Edvin

[kaushalyasat]

Hi Edvin,

The issue we see here is actually not partitioning, but the SEDs cant seem to proactively dislodge from a router and do a MLE reattach to another. There is no guarantee that the SED will not be connected to the same router again. From the Thread standpoint this may be a perfectly valid scenario, but its a killer or non-recoverable error for us. 

Does 'Search for a better parent' feature pick up a new router ?

Now we are implementing two solutions.

1. Make the partitionID available in our dashboard for each router. It the commissioning stage we make sure all routers form a single partition. If not we introduce additional routers until we can get a single partition.

2. Instead of a single big network, we implement networks per router. We have one main router in a installation and if we need to bring in more, we commission them with main router, so that they all have same network credentials as the main router. Similarly the SEDs will be commissioned in. At the point of commissioning we will have a single contagious network per installation. This way, meshing will be limited within that network.

The only other issue this doesn't solve is a one case a test user reported, where he says he didn't have no  more than one router in his system at all times, but he saw his sensors disconnecting. As this is only single case we have reported, we will park this scenario till we have more conclusive data.

What do you think?

Cheers,

Kaushalya

[Edvin]

If you don't have a stable Thread network, I am not sure whether Openthread is really the best protocol, but I guess it is a bit late to change this now?

1: I think that sounds like a good idea, as it would make sure that your entire network is in one partition. However, it seems like this is not 100% going to work, since most of the time, you get all messages as expected, but after some months, the network suddenly splits. Perhaps caused by some added radio noise in the area. This means that this may not be detected during installation. But it could perhaps be used to detect the partitioning. I don't know whether both partitions have internet access, and hence, whether they can report that they are on a separate partition. You are more familiar with the setup, and can say whether this would work or not.

2: Are you saying that you have two networks that each router will be part of? One small network between itself and the sensors, and one other "big" network with all the routers and the gateway? I am not sure how this would solve it if the big network struggles with partitioning. Then you will still not be able to reach all the sensors from the small networks.

If the issue is that there is no 100% stable route between the sensor and the gateway, then adding more routers seems like adding more routers is the way to go. The key is to understand when this is the case, and your proposal #1 would perhaps help with this?

Best regards,

Edvin

[kaushalyasat]

Edvin said:

Are you saying that you have two networks that each router will be part of? One small network between itself and the sensors, and one other "big" network with all the routers and the gateway?

Not exactly. We need a router per installation. This installation is like a home. Then the sensors in that property shall be commissioned to that router. If certain sensors are out of reach, we provision a range extender (another router) to bridge the gap. All in all, the entire property shall have a single network. 

The neighboring property, say this is a multi-storey apartment building, will have another network on their own as I mentioned before. So each property will have a small network of their own. This way a sensor of one property shall not mesh to a router in another property, which could yield to partitioning.

Still a partition could happen inside a property due to some radio disturbance later on. All the property owner need to do is 

1. power cycle each sensor that has disconnected.

2. or worst case power cycle the router/routers. 

Also as we report partitionID of each router to a dashboard, we can remotely detect that there is partitioning inside a property, as all the routers that belong to a property are grouped together. Only primary router will be connected to internet and if we cant see other routers, that means they are partitioned. 

I have had a discussion with OpenThread GIT group and their opinion is the partitioning and the SEDs behaviors are as part of the OpenThread spec. But I think this behavior is not correct as it can yield to non-recoverable communication failures in the network. Even if we detect partitioning in the SEDs, there is nothing application level program can do to connect to a different parent.

Only way I can think of is the routers to detect partitioning and do a individual network restart until a single partition is made. If after couple of cycles still not resolvable then the primary router should report this to the user and the dashboard. Then human intervention is needed to commission another router to resolve.

Cheers,

Kaushalya