First time matter / thread setup. Pairing failed

Configuration Matter/Thread
1

Don’t know what I’m doing. First time, bought a slzb-mr1u and a aqara light bulb, eve smart plug (both matter over thread).

POE powering the mr1u. typical generic install of OTBR and matter in HA.

I think i ran into a lot of frustration trying to understand iOS and sync credentials. I’m not sure if it’s the issue that I’m dealing with here.

Basically right now when I try to pair a device, nothing happens. I can see my iPhone go from “Connecting…” to “Setting up” to eventually it failing with Pairing failed.

Occassionally I get a thread border router not found. And I believe that’s my crendentials being out of sync, if I reboot my iPhone, it’ll get back into sync again.

Matter log, OTBR log, MR1U log all silent.Except for OTBR i do get random errors and connection resets and parsing.

I am 99% sure initial setup OTBR would get the notice to start commisioning a device, but nothing happens or it fails for some reason, I lost the log and can’t remember.

I decided to uninstall everything and start clean. Which is where I am at, nothing works, no real logs.

The below is the most info I am getting from OTBR. There was a point where nothing happened even when I tried to pair.

00:07:12.942 [N] Mle-----------: Different partition (peer:1141433592, local:162511740)
00:07:12.943 [N] Mle-----------: Attach attempt 0, BetterPartition
00:07:13.289 [W] P-HdlcIntface-: Error decoding hdlc frame: Parse
00:07:14.132 [W] P-HdlcIntface-: Error decoding hdlc frame: Parse
00:07:15.764 [W] P-HdlcIntface-: Error decoding hdlc frame: Parse
00:07:17.066 [W] P-HdlcIntface-: Error decoding hdlc frame: Parse
00:07:18.408 [W] P-HdlcIntface-: Error decoding hdlc frame: Parse
00:07:19.074 [N] Mle-----------: Different partition (peer:1141433592, local:162511740)

as mentioned i’m also convinced i have stale left over issues from uninstalling and reinstalling matter server, OTBR. I might even just nuke my entire HA install.

2

I had the same issues with my first Matter setup and it basically came down to an incorrectly setup IPv6 config. Make sure you get that sorted first.

3 
s6-rc: info: service otbr-agent-configure successfully started
s6-rc: info: service otbr-agent-rest-discovery: starting
[14:08:42] INFO: Successfully sent discovery information to Home Assistant.
s6-rc: info: service otbr-agent-rest-discovery successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
00:00:07.072 [W] P-RadioSpinel-: radio tx timeout
00:00:07.072 [W] P-RadioSpinel-: RCP failure detected
00:00:07.072 [W] P-RadioSpinel-: Trying to recover (1/2)
00:00:07.132 [N] P-RadioSpinel-: RCP recovery is done
00:00:07.134 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:00:07.134 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:00:26.103 [N] Mle-----------: RLOC16 5c00 -> fffe
00:00:26.554 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
00:00:33.054 [N] RouterTable---: Allocate router id 23
00:00:33.054 [N] Mle-----------: RLOC16 fffe -> 5c00
00:00:33.058 [N] Mle-----------: Role detached -> leader
00:00:33.058 [N] Mle-----------: Partition ID 0x6dc03a2d
[NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!
00:00:37.594 [W] DuaManager----: Failed to perform next registration: NotFound
00:00:38.612 [W] P-RadioSpinel-: radio tx timeout
00:00:38.612 [W] P-RadioSpinel-: RCP failure detected
00:00:38.612 [W] P-RadioSpinel-: Trying to recover (1/2)
00:00:38.672 [N] P-RadioSpinel-: RCP recovery is done
00:00:38.674 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:00:38.674 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)

it sure looks like something is wrong with my radio? I’ve tried reflashing the radio , and the OS on the SLZB-MR1U.

i’ve tried holding the button to factory reset (it does nothing, it doesn’t power/boot if i hold the button, and no matter if I hold it forever it never resets or blinks leds to indicate anything).

I’ll investigate the ipv6.

but i do see a lot of radio errors or partitioning. If i check the counters on the device for activity, it looks okay. It moves (tx & rx) but rx side seems low in numbers.

4

I tried on a Android tablet, and it fails also saying “Can’t reach device” “make sure your phone is connected to Wi-Fi”

[NOTE]-AGENT---: Thread interface: wpan0
[NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///tmp/ttyOTBR?uart-baudrate=460800&uart-init-deassert
[NOTE]-AGENT---: Radio URL: trel://enp6s18
[NOTE]-ILS-----: Infra link selected: enp6s18
tiocmbic: Inappropriate ioctl for device
49d.17:08:24.189 [C] P-SpinelDrive-: Software reset co-processor successfully
49d.17:08:24.214 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
49d.17:08:24.214 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:00:00.063 [N] RoutingManager: BR ULA prefix: fddb:6faf:98f::/48 (loaded)
00:00:00.063 [N] RoutingManager: Local on-link prefix: fddb:9a9f:1bac:64fb::/64
00:00:00.077 [N] Mle-----------: Role disabled -> detached
00:00:00.079 [N] P-Netif-------: Changing interface state to up.
00:00:00.085 [W] P-Netif-------: Failed to process request#2: No such process
00:00:00.086 [W] P-Netif-------: Failed to process request#6: No such process
s6-rc: info: service otbr-agent successfully started
s6-rc: info: service otbr-agent-configure: starting
Done
s6-rc: info: service otbr-agent-configure successfully started
s6-rc: info: service otbr-agent-rest-discovery: starting
[14:08:42] INFO: Successfully sent discovery information to Home Assistant.
s6-rc: info: service otbr-agent-rest-discovery successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
00:00:07.072 [W] P-RadioSpinel-: radio tx timeout
00:00:07.072 [W] P-RadioSpinel-: RCP failure detected
00:00:07.072 [W] P-RadioSpinel-: Trying to recover (1/2)
00:00:07.132 [N] P-RadioSpinel-: RCP recovery is done
00:00:07.134 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:00:07.134 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:00:26.103 [N] Mle-----------: RLOC16 5c00 -> fffe
00:00:26.554 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
00:00:33.054 [N] RouterTable---: Allocate router id 23
00:00:33.054 [N] Mle-----------: RLOC16 fffe -> 5c00
00:00:33.058 [N] Mle-----------: Role detached -> leader
00:00:33.058 [N] Mle-----------: Partition ID 0x6dc03a2d
[NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!
00:00:37.594 [W] DuaManager----: Failed to perform next registration: NotFound
00:00:38.612 [W] P-RadioSpinel-: radio tx timeout
00:00:38.612 [W] P-RadioSpinel-: RCP failure detected
00:00:38.612 [W] P-RadioSpinel-: Trying to recover (1/2)
00:00:38.672 [N] P-RadioSpinel-: RCP recovery is done
00:00:38.674 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:00:38.674 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:00:48.236 [W] P-RadioSpinel-: radio tx timeout
00:00:48.236 [W] P-RadioSpinel-: RCP failure detected
00:00:48.236 [W] P-RadioSpinel-: Trying to recover (1/2)
00:00:48.293 [N] P-RadioSpinel-: RCP recovery is done
00:00:48.294 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:00:48.294 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:08:04.863 [W] P-RadioSpinel-: radio tx timeout
00:08:04.863 [W] P-RadioSpinel-: RCP failure detected
00:08:04.863 [W] P-RadioSpinel-: Trying to recover (1/2)
00:08:04.924 [N] P-RadioSpinel-: RCP recovery is done
00:08:04.967 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:08:04.967 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:10:47.348 [N] RouterTable---: Allocate router id 31
00:11:53.328 [W] P-RadioSpinel-: radio tx timeout
00:11:53.328 [W] P-RadioSpinel-: RCP failure detected
00:11:53.328 [W] P-RadioSpinel-: Trying to recover (1/2)
00:11:53.391 [N] P-RadioSpinel-: RCP recovery is done
00:11:53.393 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:11:53.393 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:12:25.359 [W] P-RadioSpinel-: Handle transmit done failed: ChannelAccessFailure
00:12:25.361 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:83, chksum:77b3, ecn:no, to:0x7c00, sec:yes, error:ChannelAccessFailure, prio:normal, radio:15.4
00:12:25.361 [N] MeshForwarder-:     src:[fd5e:c990:ba5:de9d:9b71:6330:ca47:6bfe]:53536
00:12:25.361 [N] MeshForwarder-:     dst:[fd5e:c990:ba5:de9d:7fb7:4950:9d32:22b4]:49155
00:13:52.180 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:cddb, ecn:no, to:66d33f10bd9f45e7, sec:no, error:NoAck, prio:net, radio:15.4
00:13:52.180 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:13:52.180 [N] MeshForwarder-:     dst:[fe80:0:0:0:64d3:3f10:bd9f:45e7]:19788
00:13:53.362 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:6a28, ecn:no, to:66d33f10bd9f45e7, sec:no, error:NoAck, prio:net, radio:15.4
00:13:53.362 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:13:53.362 [N] MeshForwarder-:     dst:[fe80:0:0:0:64d3:3f10:bd9f:45e7]:19788
00:13:53.923 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:7d28, ecn:no, to:66d33f10bd9f45e7, sec:no, error:NoAck, prio:net, radio:15.4
00:13:53.923 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:13:53.923 [N] MeshForwarder-:     dst:[fe80:0:0:0:64d3:3f10:bd9f:45e7]:19788
00:14:04.146 [W] P-RadioSpinel-: radio tx timeout
00:14:04.146 [W] P-RadioSpinel-: RCP failure detected
00:14:04.146 [W] P-RadioSpinel-: Trying to recover (1/2)
00:14:04.204 [N] P-RadioSpinel-: RCP recovery is done
00:14:04.206 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:14:04.206 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:15:26.626 [N] RouterTable---: Release router id 31
00:24:46.735 [W] P-RadioSpinel-: radio tx timeout
00:24:46.735 [W] P-RadioSpinel-: RCP failure detected
00:24:46.735 [W] P-RadioSpinel-: Trying to recover (1/2)
00:24:46.793 [N] P-RadioSpinel-: RCP recovery is done
00:24:46.795 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:24:46.795 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:25:45.965 [N] RouterTable---: Allocate router id 25
00:27:13.866 [W] P-RadioSpinel-: radio tx timeout
00:27:13.866 [W] P-RadioSpinel-: RCP failure detected
00:27:13.866 [W] P-RadioSpinel-: Trying to recover (1/2)
00:27:13.923 [N] P-RadioSpinel-: RCP recovery is done
00:27:13.964 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:27:13.964 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:27:29.388 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:40a4, ecn:no, to:761dcb730ec22940, sec:no, error:NoAck, prio:net, radio:15.4
00:27:29.388 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:27:29.388 [N] MeshForwarder-:     dst:[fe80:0:0:0:741d:cb73:ec2:2940]:19788
00:27:30.468 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:cf35, ecn:no, to:761dcb730ec22940, sec:no, error:NoAck, prio:net, radio:15.4
00:27:30.468 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:27:30.468 [N] MeshForwarder-:     dst:[fe80:0:0:0:741d:cb73:ec2:2940]:19788
00:27:31.528 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:ec6a, ecn:no, to:761dcb730ec22940, sec:no, error:NoAck, prio:net, radio:15.4
00:27:31.528 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:27:31.528 [N] MeshForwarder-:     dst:[fe80:0:0:0:741d:cb73:ec2:2940]:19788
00:27:44.632 [N] RouterTable---: Allocate router id 54
00:29:04.561 [N] RouterTable---: Release router id 25
00:30:02.405 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:8973, ecn:no, to:aaf860f6ab5058fd, sec:no, error:NoAck, prio:net, radio:15.4
00:30:02.405 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:30:02.405 [N] MeshForwarder-:     dst:[fe80:0:0:0:a8f8:60f6:ab50:58fd]:19788
00:30:03.678 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:02e7, ecn:no, to:aaf860f6ab5058fd, sec:no, error:NoAck, prio:net, radio:15.4
00:30:03.678 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:30:03.678 [N] MeshForwarder-:     dst:[fe80:0:0:0:a8f8:60f6:ab50:58fd]:19788
00:30:04.547 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:5ab2, ecn:no, to:aaf860f6ab5058fd, sec:no, error:NoAck, prio:net, radio:15.4
00:30:04.547 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:30:04.547 [N] MeshForwarder-:     dst:[fe80:0:0:0:a8f8:60f6:ab50:58fd]:19788
00:30:21.578 [W] P-RadioSpinel-: radio tx timeout
00:30:21.578 [W] P-RadioSpinel-: RCP failure detected
00:30:21.578 [W] P-RadioSpinel-: Trying to recover (1/2)
00:30:21.637 [N] P-RadioSpinel-: RCP recovery is done
00:30:21.637 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:129, chksum:07fc, ecn:no, to:268e77f31eaeec87, sec:no, error:Abort, prio:net, radio:15.4
00:30:21.637 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:30:21.637 [N] MeshForwarder-:     dst:[fe80:0:0:0:248e:77f3:1eae:ec87]:19788
00:30:21.639 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:30:21.639 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:31:30.956 [N] RouterTable---: Allocate router id 25
00:31:34.902 [W] P-RadioSpinel-: radio tx timeout
00:31:34.902 [W] P-RadioSpinel-: RCP failure detected
00:31:34.902 [W] P-RadioSpinel-: Trying to recover (1/2)
00:31:34.961 [N] P-RadioSpinel-: RCP recovery is done
00:31:34.963 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:31:34.963 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:31:37.541 [N] RouterTable---: Release router id 54
00:31:39.962 [W] P-RadioSpinel-: radio tx timeout
00:31:39.962 [W] P-RadioSpinel-: RCP failure detected
00:31:39.962 [W] P-RadioSpinel-: Trying to recover (1/2)
00:31:40.019 [N] P-RadioSpinel-: RCP recovery is done
00:31:40.020 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:73, chksum:1269, ecn:no, to:0x5c04, sec:yes, error:Abort, prio:net, radio:15.4
00:31:40.020 [N] MeshForwarder-:     src:[fd5e:c990:ba5:de9d:0:ff:fe00:5c00]:61631
00:31:40.020 [N] MeshForwarder-:     dst:[fd5e:c990:ba5:de9d:0:ff:fe00:5c04]:61631
00:31:40.021 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:31:40.021 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:31:40.247 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:73, chksum:1269, ecn:no, to:0x5c04, sec:yes, error:NoAck, prio:net, radio:15.4
00:31:40.247 [N] MeshForwarder-:     src:[fd5e:c990:ba5:de9d:0:ff:fe00:5c00]:61631
00:31:40.247 [N] MeshForwarder-:     dst:[fd5e:c990:ba5:de9d:0:ff:fe00:5c04]:61631
00:33:45.149 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:a99d, ecn:no, to:268e77f31eaeec87, sec:no, error:NoAck, prio:net, radio:15.4
00:33:45.149 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:33:45.149 [N] MeshForwarder-:     dst:[fe80:0:0:0:248e:77f3:1eae:ec87]:19788
00:33:46.254 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:d86e, ecn:no, to:268e77f31eaeec87, sec:no, error:NoAck, prio:net, radio:15.4
00:33:46.254 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:33:46.254 [N] MeshForwarder-:     dst:[fe80:0:0:0:248e:77f3:1eae:ec87]:19788
00:33:46.722 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:96, chksum:2a21, ecn:no, to:268e77f31eaeec87, sec:no, error:NoAck, prio:net, radio:15.4
00:33:46.722 [N] MeshForwarder-:     src:[fe80:0:0:0:5cff:a7d5:97a1:63f4]:19788
00:33:46.722 [N] MeshForwarder-:     dst:[fe80:0:0:0:248e:77f3:1eae:ec87]:19788
00:34:12.796 [N] RouterTable---: Allocate router id 60
00:34:24.613 [W] P-RadioSpinel-: radio tx timeout
00:34:24.613 [W] P-RadioSpinel-: RCP failure detected
00:34:24.613 [W] P-RadioSpinel-: Trying to recover (1/2)
00:34:24.672 [N] P-RadioSpinel-: RCP recovery is done
00:34:24.714 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:34:24.714 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:35:17.343 [W] P-RadioSpinel-: radio tx timeout
00:35:17.343 [W] P-RadioSpinel-: RCP failure detected
00:35:17.343 [W] P-RadioSpinel-: Trying to recover (1/2)
00:35:17.400 [N] P-RadioSpinel-: RCP recovery is done
00:35:17.442 [C] P-RadioSpinel-: RCP => [C] Platform------: Reset info: 0x3 (EXT)
00:35:17.442 [C] P-RadioSpinel-: RCP => [C] Platform------: Extended Reset info: 0x301 (PIN)
00:35:19.512 [N] RouterTable---: Release router id 25

full logs more or less. I just feel heavily my MR1U is faulty? I’ve tried flashing different firmware on the radio AND the device. I’ll try the other radio…

But can anyone help confirm what may be going on here?