Matter v2.2.0 unable to android commission, with "pairing failed"

Ive been trying the last few Sdk versions to evaluate the matter examples without luck. With 2.2 released yesterday I jumped on that hoping it would clear up my issue, but no dice.

22.04 ubuntu with nrf-docker with v2.2.0, programmed the rcp and the matter light bulb example
rpi 3b+ setup like the 2.2 docs say ot-br-posix @ 0895ad5
I have the android chiptool associated with the 2.2 tag

Im unable to commission ble over thread, with "pairing failed" in android chiptool

My logs on the nrf52840 dk get to here before "I: 137257 [FS]Fail-safe timer expired"

D: 110318 [DMG]Decreasing reference count for CommandHandler, remaining 1
D: 110324 [DL]OpenThread State Changed (Flags: 0x1006c100)
D: 110330 [DL] Network Name: OpenThread
D: 110333 [DL] PAN Id: 0x46A7
D: 110336 [DL] Extended PAN Id: 0x0747C2C1E3CB1D09
D: 110341 [DL] Channel: 16
D: 110344 [DL] Mesh Prefix: fdde:ad00:beef::/64
D: 110348 [DL]OpenThread State Changed (Flags: 0x1100101d)
D: 110354 [DL] Device Role: DETACHED
D: 110358 [DL] Thread Unicast Addresses:
D: 110362 [DL] fdde:ad00:beef:0:a3c1:30d8:5d26:74f3/64 valid
D: 110368 [DL] fe80::94f5:b84b:42a5:9b84/64 valid preferred
D: 112781 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 112875 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 115350 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 117858 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 117915 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 120390 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 122898 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 122956 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

My logs on the pi are verbose, but something that stands out, but doesnt google anywhere else is a "Failed to process Child ID Request: Security"

Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:33.813 [W] Mle-----------: Failed to process Child ID Request: Security
Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:33.953 [I] Mac-----------: Frame tx attempt 16/16 failed, error:NoAck, len:126, seqnum:31, type:Data, src:6ae4f275a2ab4472, dst:beada8f9f39cdb0a, sec:yes, ackreq:yes
Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:33.953 [N] MeshForwarder-: Failed to send IPv6 UDP msg, len:313, chksum:62da, ecn:no, to:beada8f9f39cdb0a, sec:yes, error:NoAck, prio:net
Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:33.953 [N] MeshForwarder-: src:[fe80:0:0:0:68e4:f275:a2ab:4472]:19788
Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:33.953 [N] MeshForwarder-: dst:[fe80:0:0:0:bcad:a8f9:f39c:db0a]:19788
Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:33.992 [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:bcb5, ecn:no, from:beada8f9f39cdb0a, sec:no, prio:net, rss:-69.0
Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:33.992 [I] MeshForwarder-: src:[fe80:0:0:0:bcad:a8f9:f39c:db0a]:19788
Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:33.992 [I] MeshForwarder-: dst:[fe80:0:0:0:68e4:f275:a2ab:4472]:19788
Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:33.992 [W] Mle-----------: Failed to process UDP: Duplicated
Dec 08 01:02:47 raspberrypi otbr-agent[27385]: 05:29:34.036 [I] MeshForwarder-: Received IPv6 UDP msg, len:104, chksum:bcb5, ecn:no, from:beada8f9f39cdb0a, sec:no, prio:net, rss:-69.0

Any idea what this could be?

Thanks

Parents

0 Jacob over 2 years ago

Also trying the binaries tagged v2.2.0 from my 22.04 linux machine

./chip-tool-release pairing ble-thread 1 hex:0e080000000000010000000300001035060004001fffe002080747c2c1e3cb1d090708fdf836fbbeb82ddc05104afbfca008bdb5d9e39ba9665b65222b030f4f70656e5468726561642d34366137010246a70410277bd96fb2ca2ca217f807412464fb790c0402a0f7f8 20202021 3840

Looks about the same on the device with `I: 145206 [FS]Fail-safe timer expired`

But the rcp logs are a lot of this

Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.680 [I] MeshForwarder-: src:[fe80:0:0:0:b493:aef0:b93c:8565]:19788
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.680 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:1]:19788
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.681 [W] Mle-----------: Failed to process UDP: Duplicated
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.785 [I] MeshForwarder-: Received IPv6 UDP msg, len:90, chksum:12c9, ecn:no, from:b693aef0b93c8565, sec:no, prio:net, rss:-68.0
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.786 [I] MeshForwarder-: src:[fe80:0:0:0:b493:aef0:b93c:8565]:19788
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.786 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:1]:19788
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.786 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:b493:aef0:b93c:8565,0x9c00)
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.786 [N] Mle-----------: Different partition (peer:636139611, local:1204658966)
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.786 [I] Settings------: Read ChildInfo {rloc:0xbc05, extaddr:b693aef0b93c8565, timeout:240, mode:0x0f, version:4}
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.806 [I] Settings------: Removed ChildInfo {rloc:0xbc05, extaddr:b693aef0b93c8565, timeout:240, mode:0x0f, version:4}
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.806 [I] Mle-----------: Failed to process Advertisement: Drop
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.806 [I] Notifier------: StateChanged (0x00000800) [Child-]
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.817 [I] MeshForwarder-: Received IPv6 UDP msg, len:90, chksum:12c9, ecn:no, from:b693aef0b93c8565, sec:no, prio:net, rss:-69.0
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.817 [I] MeshForwarder-: src:[fe80:0:0:0:b493:aef0:b93c:8565]:19788
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.817 [I] MeshForwarder-: dst:[ff02:0:0:0:0:0:0:1]:19788
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.817 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:b493:aef0:b93c:8565,0x9c00)
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.817 [N] Mle-----------: Different partition (peer:636139611, local:1204658966)
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.818 [I] Mle-----------: Failed to process Advertisement: Drop
Dec 08 01:36:22 raspberrypi otbr-agent[27385]: 06:03:08.902 [I] MeshForwarder-: Received IPv6 UDP msg, len:90, chksum:12c9, ecn:no, from:b693aef0b93c8565, sec:no, prio:net, rss:-68.0

```

Also I thought either of the discover commands would find the pi or the device, but they dont, both time out?

sudo ./chip-tool-release discover commissioners
sudo ./chip-tool-release discover commissionables

service browser finds `_meshcop._udp` at rasperrypi.local with an fd07 address which is pingable by net analzyer

avahi on my linux host finds meshcop though with a failed to resolve and no ipv6 address, but the fd07 from android pings fine from there as well

avahi-browse -r -t _meshcop._udp
+ wlp0s20f3 IPv6 OpenThread BorderRouter #4472 _meshcop._udp local
+ wlp0s20f3 IPv4 OpenThread BorderRouter #4472 _meshcop._udp local
= wlp0s20f3 IPv6 OpenThread BorderRouter #4472 _meshcop._udp local
hostname = [raspberrypi.local]
address = [192.168.1.130]
port = [49155]
txt = ["dn=DefaultDomain" "bb=\240\191" "sq=b" "pt=\022\163\205G" "at=\000\000\000\000\000\001\000\000" "sb=\000\000\001\177" "xa=j\228\242u\162\171Dr" "tv=1.3.0" "xp=\007G\194\193\227\203\029\009" "nn=OpenThread-46a7" "mn=BorderRouter" "vn=OpenThread" "rv=1"]
Failed to resolve service 'OpenThread BorderRouter #4472' of type '_meshcop._udp' in domain 'local': Timeout reached

```

Reply