This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

MLE Parent Response is received but a Child ID Request/Response exchange fails.

Hi everyone,

I am using "nRF5 SDK for Thread and Zigbee 2.0.0" in my project , that includes the libraries of OpenThread (commit 704511c96e0d093139e4b80ef0739ed2d701afb1).

I recompiled the libopenthread-ftd with new defines:

  • OPENTHREAD_CONFIG_ATTACH_BACKOFF_MINIMUM_INTERVAL=300000 # milliseconds or 5 minutes
  • OPENTHREAD_CONFIG_ATTACH_BACKOFF_MAXIMUM_INTERVAL=300000 # milliseconds or 5 minutes

Then two Router devices were created. And they had been working properly. In file "log-ChildId-response-success.txt"  we can see,  (line 111) that Child ID Response has been sent on Mac layer.

After that Sleep End Device was created. As it was expected, the interval between attempts of connection to the Parent was approximately 5 minutes.

Since i turned on one Router device and one Sleep End Device, SED hasn't been able to attach to the Router. In Wireshark (files sed-not-connect-to-router.csv, sed-not-connect-to-router.txt, sed-not-connect-to-router.pcapng) we can see, that SED didn't receive Child ID Response after sending of Child ID Request. Áttempts to attach to Parent in sniffer messages: 8, 40, 70, 100, 131 and so on.

I created the log from my Router device when SED is trying to connect to it. In file "log-ChildId-response-fails.txt" we can see, (line125) that MLE layer was trying to send Child ID Response, but Mac layer did not do that.

Key for wireshark is 0x0f0f0f0f0f0f0f0f0f0f0f0f0f0f0f0f.

I have already found out the following:

  • MeshForwarder::SendMessage() is being called after “Send Child ID Response”.
  • MeshForwarder::ScheduleTransmissionTask() is being called after “Send Child ID Response”.
  • MeshForwarder::SendFrameRequest() isn’t being called after “Send Child ID Response”, because Router waits for receiving message “Data Request”.
  • Router doesn't receive message "Data Request" from SED.
  • Mac::HandleReceivedFrame() isn’t being called after receiving message “Child ID Request”.

Conclusion: Message "Data Request" is lost at radio driver or before.

Is my conclusion right? What should i do to improve this behavior?

Thank you!

This question in openthread-users google group: https://groups.google.com/d/topic/openthread-users/PTS8ZLLgQfM/discussion

Same question in openthread-users google group: https://groups.google.com/d/topic/openthread-users/ALSHBSzoU-k/discussion 

Attachments:

	LOG | 25.5              | 181 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[RX len=063]===============================

	LOG | 25.5              | 182 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 41 D8 B2 01 02 FF FF E1 | 63 B8 56 06 FC 56 26 7F | AX2....ac8V.|V&.

	LOG | 25.5              | 183 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 3B 02 F0 4D 4C 4D 4C EE | 0F 00 15 9B 13 00 00 00 | ;.pMLMLn........

	LOG | 25.5              | 184 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 00 00 00 01 C7 B2 63 56 | E7 6F CA D9 5E 11 5B 48 | ....G2cVgoJY^.[H

	LOG | 25.5              | 185 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 82 1A 41 BA F1 35 FB E9 | 3F ED CF 72 F2 4A 00 .. | ..A:q5{i?mOrrJ..

	LOG | 25.5              | 186 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 25.5              | 187 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Received IPv6 UDP msg, len:84, chksum:ee0f, from:2656fc0656b863e1, sec:no, prio:low, rss:-20.0

	LOG | 25.5              | 188 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:2456:fc06:56b8:63e1]:19788

	LOG | 25.5              | 189 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[ff02:0:0:0:0:0:0:2]:19788

	LOG | 25.5              | 190 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Receive Parent Request (fe80:0:0:0:2456:fc06:56b8:63e1)

	LOG | 25.5              | 191 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Delay Parent Response (fe80:0:0:0:2456:fc06:56b8:63e1)

	LOG | 25.5              | 192 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: aMessage.Free().

	LOG | 25.5              | 193 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: error = 0.

	LOG | 25.8              | 194 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Send delayed message (fe80:0:0:0:2456:fc06:56b8:63e1)

	LOG | 25.8              | 195 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: Message type = 0, subtype = 6.

	LOG | 25.8              | 196 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: error = 0.

	LOG | 25.8              | 197 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Request to start operation "TransmitData"

	LOG | 25.8              | 198 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Starting operation "TransmitData"

	LOG | 25.8              | 199 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[TX len=113]===============================

	LOG | 25.8              | 200 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 61 DC 2C 01 02 E1 63 B8 | 56 06 FC 56 26 78 97 1E | a\,..ac8V.|V&x..

	LOG | 25.8              | 201 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 02 59 20 33 E2 7F 33 F0 | 4D 4C 4D 4C D9 9F 00 15 | .Y 3b.3pMLMLY...

	LOG | 25.8              | 202 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 07 00 00 00 00 00 00 00 | 01 61 8C D7 68 45 64 0C | .........a.WhEd.

	LOG | 25.8              | 203 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 11 73 B1 3B 59 42 D9 66 | C0 A8 E6 3B 49 66 BE 70 | .s1;YBYf@(f;If>p

	LOG | 25.8              | 204 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | B0 5A BF 6A F3 E2 D6 9A | 21 94 FE 42 3A 99 84 50 | 0Z?jsbV.!.~B:..P

	LOG | 25.8              | 205 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 39 E4 B1 09 FF 8E 6F F9 | 46 F4 81 F0 59 1D 69 94 | 9d1...oyFt.pY.i.

	LOG | 25.9              | 206 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 5F 3B A4 44 AA 29 05 BE | B4 03 61 05 8F B2 BC 00 | _;$D*).>4.a..2<.

	LOG | 25.9              | 207 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 00 .. .. .. .. .. .. .. | .. .. .. .. .. .. .. .. | ................

	LOG | 25.9              | 208 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 25.9              | 209 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Sent IPv6 UDP msg, len:129, chksum:d99f, to:2656fc0656b863e1, sec:no, prio:high

	LOG | 25.9              | 210 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:e033:2059:21e:9778]:19788

	LOG | 25.9              | 211 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[fe80:0:0:0:2456:fc06:56b8:63e1]:19788

	LOG | 25.9              | 212 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Finishing operation "TransmitData"

	LOG | 25.9              | 213 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Idle mode: Radio receiving on channel 11

	LOG | 26.3              | 214 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[RX len=088]===============================

	LOG | 26.3              | 215 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 61 DC B3 01 02 78 97 1E | 02 59 20 33 E2 E1 63 B8 | a\3..x...Y 3bac8

	LOG | 26.3              | 216 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 56 06 FC 56 26 7F 33 F0 | 4D 4C 4D 4C 4F 73 00 15 | V.|V&.3pMLMLOs..

	LOG | 26.3              | 217 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 9C 13 00 00 00 00 00 00 | 01 AB E4 DC AE ED AD 87 | .........+d\.m-.

	LOG | 26.3              | 218 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 45 C1 80 5C 6E CD FD EB | D4 BB 3F B8 64 70 3C 40 | EA.\nM}kT;?8dp<@

	LOG | 26.3              | 219 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 9C 98 1C 90 7B 46 6C 5C | AB E9 F4 47 86 98 B8 C3 | ....{Fl\+itG..8C

	LOG | 26.3              | 220 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | FF CC 5F 30 FC CD 4A 00 | .. .. .. .. .. .. .. .. | .L_0|MJ.........

	LOG | 26.3              | 221 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 26.3              | 222 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Received IPv6 UDP msg, len:104, chksum:4f73, from:2656fc0656b863e1, sec:no, prio:low, rss:-21.0

	LOG | 26.3              | 223 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:2456:fc06:56b8:63e1]:19788

	LOG | 26.3              | 224 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[fe80:0:0:0:e033:2059:21e:9778]:19788

	LOG | 26.3              | 225 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Receive Child ID Request (fe80:0:0:0:2456:fc06:56b8:63e1)

	LOG | 27.3              | 226 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_CORE> -CORE----: Non-volatile: Added ChildInfo {rloc:0x9401, extaddr:2656fc0656b863e1, timeout:40, mode:0x0f}

	LOG | 27.3              | 227 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Send Child ID Response (fe80:0:0:0:2456:fc06:56b8:63e1,0x9401)

	LOG | 27.3              | 228 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: aMessage.Free().

	LOG | 27.3              | 229 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: error = 0.

	LOG | 27.3              | 230 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_CORE> -CORE----: Notifier: StateChanged (0x0400) [Child+] 

	LOG | 27.3              | 231 | -> State changed! Flags: 0x00000400 Current role: 4

	LOG | 27.3              | 232 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: Message type = 0, subtype = 6.

	LOG | 27.3              | 233 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: error = 0.

	LOG | 27.3              | 234 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Request to start operation "TransmitData"

	LOG | 27.3              | 235 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Starting operation "TransmitData"

	LOG | 27.3              | 236 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[TX len=086]===============================

	LOG | 27.3              | 237 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 61 DC 2D 01 02 E1 63 B8 | 56 06 FC 56 26 78 97 1E | a\-..ac8V.|V&x..

	LOG | 27.3              | 238 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 02 59 20 33 E2 7F 33 F0 | 4D 4C 4D 4C E9 D0 00 15 | .Y 3b.3pMLMLiP..

	LOG | 27.3              | 239 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 08 00 00 00 00 00 00 00 | 01 99 28 71 E3 92 B5 5A | ..........(qc.5Z

	LOG | 27.3              | 240 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 73 00 82 43 1F 02 96 19 | 3E 12 83 FE E6 A8 0D 02 | s..C....>..~f(..

	LOG | 27.3              | 241 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | ED 54 95 0D 41 85 78 AE | 62 A7 51 A3 78 BC BC AD | mT..A.x.b'Q#x<<-

	LOG | 27.3              | 242 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | FB E4 BB 94 FF 8E .. .. | .. .. .. .. .. .. .. .. | {d;.............

	LOG | 27.3              | 243 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 27.3              | 244 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Sent IPv6 UDP msg, len:102, chksum:e9d0, to:2656fc0656b863e1, sec:no, prio:high

	LOG | 27.3              | 245 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:e033:2059:21e:9778]:19788

	LOG | 27.3              | 246 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[fe80:0:0:0:2456:fc06:56b8:63e1]:19788

	LOG | 27.3              | 247 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Finishing operation "TransmitData"

	LOG | 27.3              | 248 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Idle mode: Radio receiving on channel 11

	LOG | 32.3              | 249 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Send Advertisement (ff02:0:0:0:0:0:0:1)

	LOG | 32.3              | 250 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: Message type = 0, subtype = 6.

	LOG | 32.3              | 251 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_IP6> -IP6-----: error = 0.

	LOG | 32.3              | 252 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Request to start operation "TransmitData"

	LOG | 32.3              | 253 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Starting operation "TransmitData"

	LOG | 32.3              | 254 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[TX len=069]===============================

	LOG | 32.3              | 255 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 41 D8 2E 01 02 FF FF 78 | 97 1E 02 59 20 33 E2 7F | AX.....x...Y 3b.

	LOG | 32.3              | 000 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 3B 01 F0 4D 4C 4D 4C 3A | CE 00 15 09 00 00 00 00 | ;.pMLML:N.......

	LOG | 32.3              | 001 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 00 00 00 01 2B B3 70 28 | FA 68 CA 95 8E 79 C7 3B | ....+3p(zhJ..yG;

	LOG | 32.3              | 002 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | C8 1B D2 78 D4 4D 6F 1E | 3B A8 A5 55 92 30 FA B2 | H.RxTMo.;(U.0z2

	LOG | 32.3              | 003 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 90 15 D4 0D 41 .. .. .. | .. .. .. .. .. .. .. .. | ..T.A...........

	LOG | 32.3              | 004 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 32.3              | 005 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Sent IPv6 UDP msg, len:90, chksum:3ace, to:0xffff, sec:no, prio:high

	LOG | 32.3              | 006 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:e033:2059:21e:9778]:19788

	LOG | 32.3              | 007 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[ff02:0:0:0:0:0:0:1]:19788

	LOG | 32.3              | 008 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Finishing operation "TransmitData"

	LOG | 18.9              | 128 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Send Advertisement (ff02:0:0:0:0:0:0:1)

	LOG | 18.9              | 129 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Request to start operation "TransmitData"

	LOG | 18.9              | 130 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Starting operation "TransmitData"

	LOG | 18.9              | 131 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[TX len=069]===============================

	LOG | 18.9              | 132 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 41 D8 02 01 02 FF FF D0 | FE 11 4F 50 10 C7 C2 7F | AX.....P~.OP.GB.

	LOG | 18.9              | 133 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 3B 01 F0 4D 4C 4D 4C EB | 4F 00 15 06 00 00 00 00 | ;.pMLMLkO.......

	LOG | 18.9              | 134 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 00 00 00 01 87 91 B3 53 | D2 B2 9A 3E 32 49 45 B6 | ......3SR2.>2IE6

	LOG | 18.9              | 135 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 42 06 C5 2A DF 4C 0C 34 | CC 56 83 AE 75 CE D4 C3 | B.E*_L.4LV..uNTC

	LOG | 18.9              | 136 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 15 36 4C 00 00 .. .. .. | .. .. .. .. .. .. .. .. | .6L.............

	LOG | 19.0              | 137 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 19.0              | 138 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Sent IPv6 UDP msg, len:90, chksum:eb4f, to:0xffff, sec:no, prio:high

	LOG | 19.0              | 139 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:c0c7:1050:4f11:fed0]:19788

	LOG | 19.0              | 140 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[ff02:0:0:0:0:0:0:1]:19788

	LOG | 19.0              | 141 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Finishing operation "TransmitData"

	LOG | 19.0              | 142 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Idle mode: Radio receiving on channel 11

	LOG | 26.6              | 143 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[RX len=063]===============================

	LOG | 26.6              | 144 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 41 D8 A7 01 02 FF FF 29 | B3 F8 C5 C4 6C 36 A6 7F | AX'....)3xEDl6&.

	LOG | 26.6              | 145 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 3B 02 F0 4D 4C 4D 4C 4D | B5 00 15 00 00 00 00 00 | ;.pMLMLM5.......

	LOG | 26.6              | 146 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 00 00 00 01 63 0E E0 7A | DD BA 9A DB CC 58 4B 69 | ....c.`z]:.[LXKi

	LOG | 26.6              | 147 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | C5 5C 78 EB 7F 2F A2 93 | 91 5E 3F 42 8C 33 00 .. | E\xk./"..^?B.3..

	LOG | 26.6              | 148 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 26.6              | 149 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Received IPv6 UDP msg, len:84, chksum:4db5, from:a6366cc4c5f8b329, sec:no, prio:low, rss:-43.0

	LOG | 26.6              | 150 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:a436:6cc4:c5f8:b329]:19788

	LOG | 26.6              | 151 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[ff02:0:0:0:0:0:0:2]:19788

	LOG | 26.6              | 152 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Receive Parent Request (fe80:0:0:0:a436:6cc4:c5f8:b329)

	LOG | 26.6              | 153 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Delay Parent Response (fe80:0:0:0:a436:6cc4:c5f8:b329)

	LOG | 26.9              | 154 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Send delayed message (fe80:0:0:0:a436:6cc4:c5f8:b329)

	LOG | 26.9              | 155 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Request to start operation "TransmitData"

	LOG | 26.9              | 156 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Starting operation "TransmitData"

	LOG | 26.9              | 157 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[TX len=113]===============================

	LOG | 26.9              | 158 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 61 DC 03 01 02 29 B3 F8 | C5 C4 6C 36 A6 D0 FE 11 | a\...)3xEDl6&P~.

	LOG | 26.9              | 159 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 4F 50 10 C7 C2 7F 33 F0 | 4D 4C 4D 4C 00 87 00 15 | OP.GB.3pMLML....

	LOG | 26.9              | 160 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 07 00 00 00 00 00 00 00 | 01 A5 99 C5 A9 BD FF B2 | .........)=.2

	LOG | 26.9              | 161 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 3B 6E 07 50 0F 74 08 52 | AF EE 6D D4 F7 90 84 D2 | ;n.P.t.R/nmTw..R

	LOG | 26.9              | 162 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 8D B0 C9 57 97 07 B2 8C | 8E 1D 93 07 F5 AA 63 73 | .0IW..2.....u*cs

	LOG | 26.9              | 163 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | D9 27 78 46 86 C7 02 90 | 9D D8 9F AE B5 59 BA 7D | Y'xF.G...X..5Y:}

	LOG | 26.9              | 164 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | FA 51 36 71 A5 0F 8E 1D | FD A5 1B 1F 52 AE 0B 00 | zQ6q..}.R...

	LOG | 26.9              | 165 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 00 .. .. .. .. .. .. .. | .. .. .. .. .. .. .. .. | ................

	LOG | 26.9              | 166 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 26.9              | 167 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Sent IPv6 UDP msg, len:129, chksum:0087, to:a6366cc4c5f8b329, sec:no, prio:high

	LOG | 26.9              | 168 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:c0c7:1050:4f11:fed0]:19788

	LOG | 26.9              | 169 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[fe80:0:0:0:a436:6cc4:c5f8:b329]:19788

	LOG | 26.9              | 170 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Finishing operation "TransmitData"

	LOG | 26.9              | 171 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Idle mode: Radio receiving on channel 11

	LOG | 27.4              | 172 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[RX len=098]===============================

	LOG | 27.4              | 173 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 61 DC A8 01 02 D0 FE 11 | 4F 50 10 C7 C2 29 B3 F8 | a\(..P~.OP.GB)3x

	LOG | 27.4              | 174 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | C5 C4 6C 36 A6 7F 33 F0 | 4D 4C 4D 4C DA 81 00 15 | EDl6&.3pMLMLZ...

	LOG | 27.4              | 175 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 01 00 00 00 00 00 00 00 | 01 CB F5 EB 8D 09 83 20 | .........Kuk... 

	LOG | 27.4              | 176 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 16 91 0E 42 9B E1 8B CA | 09 DD 80 DF 94 C2 E2 F7 | ...B.a.J.]._.Bbw

	LOG | 27.4              | 177 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | F8 E0 22 01 0E 28 49 76 | 5B 52 47 9B 44 45 E8 4E | x`"..(Iv[RG.DEhN

	LOG | 27.4              | 178 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 8D D5 0C 28 EF FD 3E BD | E8 E2 CA AC 76 DD 57 12 | .U.(o}>=hbJ,v]W.

	LOG | 27.4              | 179 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 32 00 .. .. .. .. .. .. | .. .. .. .. .. .. .. .. | 2...............

	LOG | 27.4              | 180 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 27.4              | 181 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Received IPv6 UDP msg, len:114, chksum:da81, from:a6366cc4c5f8b329, sec:no, prio:low, rss:-45.0

	LOG | 27.4              | 182 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:a436:6cc4:c5f8:b329]:19788

	LOG | 27.4              | 183 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[fe80:0:0:0:c0c7:1050:4f11:fed0]:19788

	LOG | 27.4              | 184 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Receive Child ID Request (fe80:0:0:0:a436:6cc4:c5f8:b329)

	LOG | 27.4              | 185 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Child 0x0000 IPv6 address[1]=fd65:6368:7632:0:ebea:628c:16a6:5236

	LOG | 27.4              | 186 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Child 0x0000 has 1 registered IPv6 address, 1 address stored

	LOG | 27.4              | 187 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_NET_DATA> =========================[remove done len=000]==========================

	LOG | 27.4              | 188 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_NET_DATA> ------------------------------------------------------------------------

	LOG | 28.4              | 189 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_CORE> -CORE----: Non-volatile: Added ChildInfo {rloc:0xcc01, extaddr:a6366cc4c5f8b329, timeout:240, mode:0x04}

	LOG | 28.4              | 190 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Send Child ID Response (fe80:0:0:0:a436:6cc4:c5f8:b329,0xcc01)

	LOG | 28.4              | 191 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_CORE> -CORE----: Notifier: StateChanged (0x0400) [Child+] 

	LOG | 28.4              | 192 | -> State changed! Flags: 0x00000400 Current role: 4

	LOG | 28.4              | 193 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: SrcAddrMatch - Adding addr: a6:36:6c:c4:c5:f8:b3:29 -- OK (0)

	LOG | 28.4              | 194 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: SrcAddrMatch - Enabling

	LOG | 31.9              | 195 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Send Advertisement (ff02:0:0:0:0:0:0:1)

	LOG | 31.9              | 196 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Request to start operation "TransmitData"

	LOG | 31.9              | 197 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Starting operation "TransmitData"

	LOG | 31.9              | 198 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[TX len=069]===============================

	LOG | 31.9              | 199 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 41 D8 04 01 02 FF FF D0 | FE 11 4F 50 10 C7 C2 7F | AX.....P~.OP.GB.

	LOG | 31.9              | 200 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 3B 01 F0 4D 4C 4D 4C 47 | A1 00 15 09 00 00 00 00 | ;.pMLMLG!.......

	LOG | 31.9              | 201 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 00 00 00 01 25 D7 EE A8 | 68 3F 13 91 34 6B 50 F5 | ....Wn(h?..4kPu

	LOG | 31.9              | 202 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 72 76 5D 06 56 89 DC 13 | 16 90 A7 84 13 F1 99 05 | rv].V.\...'..q..

	LOG | 31.9              | 203 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 59 1F E1 57 97 .. .. .. | .. .. .. .. .. .. .. .. | Y.aW............

	LOG | 31.9              | 204 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 31.9              | 205 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Sent IPv6 UDP msg, len:90, chksum:47a1, to:0xffff, sec:no, prio:high

	LOG | 31.9              | 206 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:c0c7:1050:4f11:fed0]:19788

	LOG | 31.9              | 207 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[ff02:0:0:0:0:0:0:1]:19788

	LOG | 31.9              | 208 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Finishing operation "TransmitData"

	LOG | 31.9              | 209 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Idle mode: Radio receiving on channel 11

	LOG | 58.9              | 210 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MLE> -MLE-----: Send Advertisement (ff02:0:0:0:0:0:0:1)

	LOG | 58.9              | 211 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Request to start operation "TransmitData"

	LOG | 58.9              | 212 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Starting operation "TransmitData"

	LOG | 58.9              | 213 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ==============================[TX len=069]===============================

	LOG | 58.9              | 214 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 41 D8 05 01 02 FF FF D0 | FE 11 4F 50 10 C7 C2 7F | AX.....P~.OP.GB.

	LOG | 58.9              | 215 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 3B 01 F0 4D 4C 4D 4C 02 | 59 00 15 0A 00 00 00 00 | ;.pMLML.Y.......

	LOG | 58.9              | 216 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 00 00 00 01 8E FB 6A E2 | CA E9 26 5B E0 A9 B5 1E | .....{jbJi&[`)5.

	LOG | 58.9              | 217 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 43 72 F4 F9 FF 50 4A B0 | 42 FE C4 3B 6C AA C0 7F | Crty.PJ0B~D;l*@.

	LOG | 58.9              | 218 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> | 76 7D 57 57 97 .. .. .. | .. .. .. .. .. .. .. .. | v}WW............

	LOG | 58.9              | 219 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> ------------------------------------------------------------------------

	LOG | 58.9              | 220 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: Sent IPv6 UDP msg, len:90, chksum:0259, to:0xffff, sec:no, prio:high

	LOG | 58.9              | 221 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	src:[fe80:0:0:0:c0c7:1050:4f11:fed0]:19788

	LOG | 58.9              | 222 | -> <OT_LOG_LEVEL_INFO> <OT_LOG_REGION_MAC> -MAC-----: 	dst:[ff02:0:0:0:0:0:0:1]:19788

	LOG | 58.9              | 223 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Finishing operation "TransmitData"

	LOG | 58.9              | 224 | -> <OT_LOG_LEVEL_DEBG> <OT_LOG_REGION_MAC> -MAC-----: Idle mode: Radio receiving on channel 11

sed-not-connect-to-router.txt

sed-not-connect-to-router.csv

sed-not-connect-to-router.pcapng

Parents
  • Hi all,

    I solved the problem I've described above. It was my mistake.

    My project works with co-operative scheduler and uses multiprotocol (openthread+ble) for communication between devices through openthread and between devices and smartphone through ble. Separate task was used for handling softdevice's events, therefore it was polled every time when event had occured.
    I think, events of softdevice haven't been handled in required time, and program behaved as showed in the question above. When softdevice's events are handled in interrupt, SED attaches to Router.

    I apologize for giving you incomplete report.

    Thank you for your help!

Reply
  • Hi all,

    I solved the problem I've described above. It was my mistake.

    My project works with co-operative scheduler and uses multiprotocol (openthread+ble) for communication between devices through openthread and between devices and smartphone through ble. Separate task was used for handling softdevice's events, therefore it was polled every time when event had occured.
    I think, events of softdevice haven't been handled in required time, and program behaved as showed in the question above. When softdevice's events are handled in interrupt, SED attaches to Router.

    I apologize for giving you incomplete report.

    Thank you for your help!

Children
No Data
Related