Running OpenThread Border Router in Docker?

[Izvor]

What are the limitations for running OpenThread Border Router in Docker?

I have not been able to successfully use it to build a Thread network and join Matter devices to it. I would like to be able to setup and run it in a Docker container and use it as if I installed the OTBR software on bare metal.

If I run on bare metal, I can use this command running on another computer to see the service:

avahi-browse -r -t _meshcop._udp

If I run OTBR in Docker and run the above command, I cannot see any services.

It looks like to network traffic from the Docker container isn't properly integrated with the LAN network.

Have anyone successfully done this?

[Marte Myrvold]

Hi,

Did you follow the guide here Thread Border Router? There are steps for running OTBR using Docker there.

Best regards,
Marte

[Izvor]

Yes, I have tried following the steps in that article.

It's a bit unclear to me what this means:

"For development purposes, you can run the OpenThread Border Router on any Linux-based system using a Docker container that already has the Border Router installed. This solution can be used when you are only interested in direct communication between your Border Router and the Thread network. For example, you can use the Docker container when you want to establish IP communication between an application running on Linux (such as the CHIP Tool Matter controller) and an application running on a Thread node."

What exactly are the restrictions are there when running OTBR in a Docker container compared with running it on bare metal? 

[Izvor]

I don't get any errors. Just not able to pair a Matter End Device to the Thread network.

[Marte Myrvold]

Hi,

Are you using chip tool to commission the device? Please share logs from the device, as well as chip tool if you are using that.

Best regards,
Marte

[Izvor]

1) Running OTBR on bare metal

Checking from another computer:

ubuntu@ubuntu:~$ avahi-browse -r -t _meshcop._udp
+ eth0 IPv6 OpenThread BorderRouter #EDEC _meshcop._udp local
+ eth0 IPv4 OpenThread BorderRouter #EDEC _meshcop._udp local
= eth0 IPv6 OpenThread BorderRouter #EDEC _meshcop._udp local
hostname = [otbr.local]
address = [192.168.1.232]
port = [49152]
txt = ["dn=DefaultDomain" "sb=\000\000\000!" "xa=\"��.\019���" "tv=1.3.0" "xp=ޭ\000��\000��" "nn=OpenThread" "mn=BorderRouter" "vn=OpenThread" "id=� U�{H\012��\025�\"��&�" "rv=1"]
= eth0 IPv4 OpenThread BorderRouter #EDEC _meshcop._udp local
hostname = [otbr.local]
address = [192.168.1.232]
port = [49152]
txt = ["dn=DefaultDomain" "sb=\000\000\000!" "xa=\"��.\019���" "tv=1.3.0" "xp=ޭ\000��\000��" "nn=OpenThread" "mn=BorderRouter" "vn=OpenThread" "id=� U�{H\012��\025�\"��&�" "rv=1"]
ubuntu@ubuntu:~$

2) Running OTBR in Docker container.

Checking from another computer:

ubuntu@ubuntu:~$ avahi-browse -r -t _meshcop._udp
ubuntu@ubuntu:~$

If avahi-browse doesn't see the Thread mDNS broadcasts it's even not needed to try the chip-tool pairing.

[Marte Myrvold]

Hi,

Please try following all the steps in the guide and test with chip-tool. If you get errors when commissioning with chip-tool, please upload the logs from chip-tool and the device here.

Best regards,
Marte

[Izvor]

Log from chip-tool:

ubuntu@ubuntu:~/connectedhomeip/out/standalone$ ./chip-tool pairing ble-thread 10 hex:0e08000000000001000035060004001fffe00708fd47c866a2d5bb8d0c0402a0f7f8051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f0410445f2b5ca6f2a93a55ce570a70efeecb000300000f0208111111112222222201021234 20202021 3840
[1706281514.265136][689286:689286] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1706281514.266086][689286:689286] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1706281514.266119][689286:689286] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1706281514.271500][689286:689286] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1706281514.271771][689286:689286] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1706281514.271884][689286:689286] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1706281514.272208][689286:689286] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-FmULtx)
[1706281514.272738][689286:689286] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1706281514.272793][689286:689286] CHIP:DL: NVS set: chip-counters/reboot-count = 55 (0x37)
[1706281514.273360][689286:689286] CHIP:DL: Got Ethernet interface: eth0
[1706281514.273688][689286:689286] CHIP:DL: Found the primary Ethernet interface:eth0
[1706281514.274052][689286:689286] CHIP:DL: Got WiFi interface: wlan0
[1706281514.274118][689286:689286] CHIP:DL: Failed to reset WiFi statistic counts
[1706281514.274169][689286:689286] CHIP:IN: UDP::Init bind&listen port=0
[1706281514.274273][689286:689286] CHIP:IN: UDP::Init bound to port=34300
[1706281514.274294][689286:689286] CHIP:IN: UDP::Init bind&listen port=0
[1706281514.274377][689286:689286] CHIP:IN: UDP::Init bound to port=45241
[1706281514.274395][689286:689286] CHIP:IN: BLEBase::Init - setting/overriding transport
[1706281514.274412][689286:689286] CHIP:IN: TransportMgr initialized
[1706281514.274441][689286:689286] CHIP:FP: Initializing FabricTable from persistent storage
[1706281514.274601][689286:689286] CHIP:TS: Last Known Good Time: 2023-10-23T16:58:40
[1706281514.276013][689286:689286] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xBA8284A0AC0FAA35, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1706281514.277826][689286:689286] CHIP:ZCL: Using ZAP configuration...
[1706281514.279414][689286:689286] CHIP:CTL: System State Initialized...
[1706281514.279543][689286:689286] CHIP:CTL: Setting attestation nonce to random value
[1706281514.279589][689286:689286] CHIP:CTL: Setting CSR nonce to random value
[1706281514.279647][689286:689286] CHIP:IN: UDP::Init bind&listen port=5550
[1706281514.279727][689286:689286] CHIP:IN: UDP::Init bound to port=5550
[1706281514.279747][689286:689286] CHIP:IN: UDP::Init bind&listen port=5550
[1706281514.279814][689286:689286] CHIP:IN: UDP::Init bound to port=5550
[1706281514.279832][689286:689286] CHIP:IN: TransportMgr initialized
[1706281514.280106][689286:689288] CHIP:DL: CHIP task running
[1706281514.280197][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1706281514.280521][689286:689288] CHIP:CTL: Setting attestation nonce to random value
[1706281514.280680][689286:689288] CHIP:CTL: Setting CSR nonce to random value
[1706281514.281481][689286:689288] CHIP:CTL: Generating NOC
[1706281514.282315][689286:689288] CHIP:FP: Validating NOC chain
[1706281514.283889][689286:689288] CHIP:FP: NOC chain validation successful
[1706281514.284039][689286:689288] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1706281514.284068][689286:689288] CHIP:TS: Last Known Good Time: 2023-10-23T16:58:40
[1706281514.284086][689286:689288] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1706281514.284103][689286:689288] CHIP:TS: Retaining current Last Known Good Time
[1706281514.288067][689286:689288] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1706281514.289681][689286:689288] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-23T16:58:40
[1706281514.291099][689286:689288] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: BA8284A0AC0FAA35)
[1706281514.291187][689286:689288] CHIP:IN: UDP::Init bind&listen port=5550
[1706281514.291291][689286:689288] CHIP:IN: UDP::Init bound to port=5550
[1706281514.291312][689286:689288] CHIP:IN: UDP::Init bind&listen port=5550
[1706281514.291383][689286:689288] CHIP:IN: UDP::Init bound to port=5550
[1706281514.291401][689286:689288] CHIP:IN: TransportMgr initialized
[1706281514.304872][689286:689288] CHIP:CTL: Setting thread operational dataset from parameters
[1706281514.304916][689286:689288] CHIP:CTL: Setting attestation nonce to random value
[1706281514.304965][689286:689288] CHIP:CTL: Setting CSR nonce to random value
[1706281514.304998][689286:689288] CHIP:CTL: Commission called for node ID 0x000000000000000A
[1706281514.309376][689286:689287] CHIP:DL: TRACE: Bus acquired for name C-8486
[1706281514.315933][689286:689288] CHIP:DL: PlatformBlueZInit init success
[1706281514.321378][689286:689287] CHIP:BLE: BLE removing known devices.
[1706281514.322793][689286:689287] CHIP:BLE: BLE initiating scan.
[1706281514.362469][689286:689287] CHIP:BLE: New device scanned: 34:25:B4:A0:B9:82
[1706281514.362516][689286:689287] CHIP:BLE: Device discriminator match. Attempting to connect.
[1706281514.883002][689286:689287] CHIP:DL: ConnectDevice complete
[1706281516.013240][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013288][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013311][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013328][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013348][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013364][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013387][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013403][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013425][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0001
[1706281516.013442][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013461][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0001
[1706281516.013476][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013494][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0001
[1706281516.013510][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013531][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0001
[1706281516.013548][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013566][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0001
[1706281516.013581][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013600][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0001
[1706281516.013616][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013636][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service000e
[1706281516.013652][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013670][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service000e
[1706281516.013686][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013704][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service000e
[1706281516.013720][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013741][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013758][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013778][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013794][689286:689287] CHIP:DL: Char1 /org/bluez/hci0/dev_34_25_B4_A0_B9_82/service0015
[1706281516.013817][689286:689287] CHIP:DL: New BLE connection: conn 0xffffa8053ff0, device 34:25:B4:A0:B9:82, path /org/bluez/hci0/dev_34_25_B4_A0_B9_82
[1706281516.013942][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16385
[1706281516.013976][689286:689288] CHIP:DIS: Closing all BLE connections
[1706281516.014053][689286:689288] CHIP:IN: BleConnectionComplete: endPoint 0xaaaab1f9fc88
[1706281516.014434][689286:689288] CHIP:IN: SecureSession[0xffffa0010d00]: Allocated Type:1 LSID:29128
[1706281516.014476][689286:689288] CHIP:SC: Assigned local session key ID 29128
[1706281516.014592][689286:689288] CHIP:EM: <<< [E:23564i S:0 M:65966330] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
[1706281516.014648][689286:689288] CHIP:IN: Message appended to BLE send queue
[1706281516.014674][689286:689288] CHIP:SC: Sent PBKDF param request
[1706281516.441530][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281516.539434][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1706281516.539481][689286:689288] CHIP:BLE: subscribe complete, ep = 0xaaaab1f9fc88
[1706281516.539834][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281516.539928][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281516.539954][689286:689288] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4
[1706281516.539972][689286:689288] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244.
[1706281516.539988][689286:689288] CHIP:BLE: local and remote recv window size = 5
[1706281516.540276][689286:689288] CHIP:IN: BLE EndPoint 0xaaaab1f9fc88 Connection Complete
[1706281516.636535][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281516.638938][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281516.639064][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281516.639203][689286:689288] CHIP:EM: >>> [E:23564i S:0 M:266217851] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
[1706281516.639233][689286:689288] CHIP:EM: Found matching exchange: 23564i, Delegate: 0xffffa000df50
[1706281516.639270][689286:689288] CHIP:SC: Received PBKDF param response
[1706281516.639314][689286:689288] CHIP:SC: Peer assigned session ID 62583
[1706281516.639342][689286:689288] CHIP:SC: Found MRP parameters in the message
[1706281516.644836][689286:689288] CHIP:EM: <<< [E:23564i S:0 M:65966331] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:22 (SecureChannel:PASE_Pake1)
[1706281516.645513][689286:689288] CHIP:SC: Sent spake2p msg1
[1706281516.734048][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281516.784552][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281516.784695][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281516.784865][689286:689288] CHIP:EM: >>> [E:23564i S:0 M:266217852] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
[1706281516.784898][689286:689288] CHIP:EM: Found matching exchange: 23564i, Delegate: 0xffffa000df50
[1706281516.784935][689286:689288] CHIP:SC: Received spake2p msg2
[1706281516.786180][689286:689288] CHIP:EM: <<< [E:23564i S:0 M:65966332] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:24 (SecureChannel:PASE_Pake3)
[1706281516.786555][689286:689288] CHIP:SC: Sent spake2p msg3
[1706281516.880251][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281516.881604][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281516.881927][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281516.882044][689286:689288] CHIP:EM: >>> [E:23564i S:0 M:266217853] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1706281516.882075][689286:689288] CHIP:EM: Found matching exchange: 23564i, Delegate: 0xffffa000df50
[1706281516.882277][689286:689288] CHIP:SC: SecureSession[0xffffa0010d00, LSID:29128]: State change 'kEstablishing' --> 'kActive'
[1706281516.882306][689286:689288] CHIP:IN: SecureSession[0xffffa0010d00]: Activated - Type:1 LSID:29128
[1706281516.882323][689286:689288] CHIP:IN: New secure session activated for device <FFFFFFFB00000000, 0>, LSID:29128 PSID:62583!
[1706281516.882348][689286:689288] CHIP:CTL: Remote device completed SPAKE2+ handshake
[1706281516.882366][689286:689288] CHIP:TOO: Pairing Success
[1706281516.882382][689286:689288] CHIP:TOO: PASE establishment successful
[1706281516.882401][689286:689288] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1706281516.882422][689286:689288] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo'
[1706281516.882439][689286:689288] CHIP:CTL: Sending request for commissioning information
[1706281516.882475][689286:689288] CHIP:DMG: SendReadRequest ReadClient[0xffffa000a2e0]: Sending Read Request
[1706281516.882645][689286:689288] CHIP:EM: <<< [E:23565i S:29128 M:61819004] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:02 (IM:ReadRequest)
[1706281516.883009][689286:689288] CHIP:DMG: MoveToState ReadClient[0xffffa000a2e0]: Moving to [AwaitingIn]
[1706281516.977773][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281516.981236][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281516.981367][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.076040][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281517.076175][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.076353][689286:689288] CHIP:EM: >>> [E:23565i S:29128 M:263416815] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
[1706281517.076388][689286:689288] CHIP:EM: Found matching exchange: 23565i, Delegate: 0xffffa000a2f0
[1706281517.076476][689286:689288] CHIP:DMG: ReportDataMessage =
[1706281517.076498][689286:689288] CHIP:DMG: {
[1706281517.076515][689286:689288] CHIP:DMG: AttributeReportIBs =
[1706281517.076564][689286:689288] CHIP:DMG: [
[1706281517.076585][689286:689288] CHIP:DMG: AttributeReportIB =
[1706281517.076611][689286:689288] CHIP:DMG: {
[1706281517.076631][689286:689288] CHIP:DMG: AttributeDataIB =
[1706281517.076672][689286:689288] CHIP:DMG: {
[1706281517.076698][689286:689288] CHIP:DMG: DataVersion = 0x5a62c680,
[1706281517.076740][689286:689288] CHIP:DMG: AttributePathIB =
[1706281517.076782][689286:689288] CHIP:DMG: {
[1706281517.076824][689286:689288] CHIP:DMG: Endpoint = 0x0,
[1706281517.076867][689286:689288] CHIP:DMG: Cluster = 0x31,
[1706281517.076911][689286:689288] CHIP:DMG: Attribute = 0x0000_0003,
[1706281517.076951][689286:689288] CHIP:DMG: }
[1706281517.076978][689286:689288] CHIP:DMG:
[1706281517.077020][689286:689288] CHIP:DMG: Data = 20,
[1706281517.077059][689286:689288] CHIP:DMG: },
[1706281517.077114][689286:689288] CHIP:DMG:
[1706281517.077137][689286:689288] CHIP:DMG: },
[1706281517.077166][689286:689288] CHIP:DMG:
[1706281517.077185][689286:689288] CHIP:DMG: AttributeReportIB =
[1706281517.077210][689286:689288] CHIP:DMG: {
[1706281517.077230][689286:689288] CHIP:DMG: AttributeDataIB =
[1706281517.077258][689286:689288] CHIP:DMG: {
[1706281517.077285][689286:689288] CHIP:DMG: DataVersion = 0x90880e04,
[1706281517.077314][689286:689288] CHIP:DMG: AttributePathIB =
[1706281517.077344][689286:689288] CHIP:DMG: {
[1706281517.077371][689286:689288] CHIP:DMG: Endpoint = 0x0,
[1706281517.077402][689286:689288] CHIP:DMG: Cluster = 0x28,
[1706281517.077434][689286:689288] CHIP:DMG: Attribute = 0x0000_0004,
[1706281517.077461][689286:689288] CHIP:DMG: }
[1706281517.077488][689286:689288] CHIP:DMG:
[1706281517.077516][689286:689288] CHIP:DMG: Data = 32769,
[1706281517.077542][689286:689288] CHIP:DMG: },
[1706281517.077567][689286:689288] CHIP:DMG:
[1706281517.077587][689286:689288] CHIP:DMG: },
[1706281517.077616][689286:689288] CHIP:DMG:
[1706281517.077635][689286:689288] CHIP:DMG: AttributeReportIB =
[1706281517.077659][689286:689288] CHIP:DMG: {
[1706281517.077680][689286:689288] CHIP:DMG: AttributeDataIB =
[1706281517.077705][689286:689288] CHIP:DMG: {
[1706281517.077728][689286:689288] CHIP:DMG: DataVersion = 0x90880e04,
[1706281517.077757][689286:689288] CHIP:DMG: AttributePathIB =
[1706281517.077783][689286:689288] CHIP:DMG: {
[1706281517.077813][689286:689288] CHIP:DMG: Endpoint = 0x0,
[1706281517.077845][689286:689288] CHIP:DMG: Cluster = 0x28,
[1706281517.077877][689286:689288] CHIP:DMG: Attribute = 0x0000_0002,
[1706281517.077906][689286:689288] CHIP:DMG: }
[1706281517.077937][689286:689288] CHIP:DMG:
[1706281517.077968][689286:689288] CHIP:DMG: Data = 65521,
[1706281517.077994][689286:689288] CHIP:DMG: },
[1706281517.078021][689286:689288] CHIP:DMG:
[1706281517.078041][689286:689288] CHIP:DMG: },
[1706281517.078070][689286:689288] CHIP:DMG:
[1706281517.078088][689286:689288] CHIP:DMG: AttributeReportIB =
[1706281517.078113][689286:689288] CHIP:DMG: {
[1706281517.078133][689286:689288] CHIP:DMG: AttributeDataIB =
[1706281517.078157][689286:689288] CHIP:DMG: {
[1706281517.078183][689286:689288] CHIP:DMG: DataVersion = 0x95f7e87a,
[1706281517.078209][689286:689288] CHIP:DMG: AttributePathIB =
[1706281517.078238][689286:689288] CHIP:DMG: {
[1706281517.078268][689286:689288] CHIP:DMG: Endpoint = 0x0,
[1706281517.078300][689286:689288] CHIP:DMG: Cluster = 0x30,
[1706281517.078331][689286:689288] CHIP:DMG: Attribute = 0x0000_0003,
[1706281517.078360][689286:689288] CHIP:DMG: }
[1706281517.078391][689286:689288] CHIP:DMG:
[1706281517.078421][689286:689288] CHIP:DMG: Data = 0,
[1706281517.078450][689286:689288] CHIP:DMG: },
[1706281517.078477][689286:689288] CHIP:DMG:
[1706281517.078497][689286:689288] CHIP:DMG: },
[1706281517.078524][689286:689288] CHIP:DMG:
[1706281517.078543][689286:689288] CHIP:DMG: AttributeReportIB =
[1706281517.078567][689286:689288] CHIP:DMG: {
[1706281517.078587][689286:689288] CHIP:DMG: AttributeDataIB =
[1706281517.078612][689286:689288] CHIP:DMG: {
[1706281517.078638][689286:689288] CHIP:DMG: DataVersion = 0x95f7e87a,
[1706281517.078683][689286:689288] CHIP:DMG: AttributePathIB =
[1706281517.078711][689286:689288] CHIP:DMG: {
[1706281517.078739][689286:689288] CHIP:DMG: Endpoint = 0x0,
[1706281517.078770][689286:689288] CHIP:DMG: Cluster = 0x30,
[1706281517.078801][689286:689288] CHIP:DMG: Attribute = 0x0000_0002,
[1706281517.078831][689286:689288] CHIP:DMG: }
[1706281517.078861][689286:689288] CHIP:DMG:
[1706281517.078892][689286:689288] CHIP:DMG: Data = 0,
[1706281517.078917][689286:689288] CHIP:DMG: },
[1706281517.078944][689286:689288] CHIP:DMG:
[1706281517.078964][689286:689288] CHIP:DMG: },
[1706281517.078993][689286:689288] CHIP:DMG:
[1706281517.079011][689286:689288] CHIP:DMG: AttributeReportIB =
[1706281517.079037][689286:689288] CHIP:DMG: {
[1706281517.079057][689286:689288] CHIP:DMG: AttributeDataIB =
[1706281517.079082][689286:689288] CHIP:DMG: {
[1706281517.079107][689286:689288] CHIP:DMG: DataVersion = 0x95f7e87a,
[1706281517.079136][689286:689288] CHIP:DMG: AttributePathIB =
[1706281517.079163][689286:689288] CHIP:DMG: {
[1706281517.079192][689286:689288] CHIP:DMG: Endpoint = 0x0,
[1706281517.079224][689286:689288] CHIP:DMG: Cluster = 0x30,
[1706281517.079256][689286:689288] CHIP:DMG: Attribute = 0x0000_0001,
[1706281517.079285][689286:689288] CHIP:DMG: }
[1706281517.079313][689286:689288] CHIP:DMG:
[1706281517.079342][689286:689288] CHIP:DMG: Data =
[1706281517.079369][689286:689288] CHIP:DMG: {
[1706281517.079427][689286:689288] CHIP:DMG: 0x0 = 60,
[1706281517.079459][689286:689288] CHIP:DMG: 0x1 = 900,
[1706281517.079490][689286:689288] CHIP:DMG: },
[1706281517.079519][689286:689288] CHIP:DMG: },
[1706281517.079547][689286:689288] CHIP:DMG:
[1706281517.079567][689286:689288] CHIP:DMG: },
[1706281517.079596][689286:689288] CHIP:DMG:
[1706281517.079615][689286:689288] CHIP:DMG: AttributeReportIB =
[1706281517.079639][689286:689288] CHIP:DMG: {
[1706281517.079659][689286:689288] CHIP:DMG: AttributeDataIB =
[1706281517.079684][689286:689288] CHIP:DMG: {
[1706281517.079709][689286:689288] CHIP:DMG: DataVersion = 0x95f7e87a,
[1706281517.079738][689286:689288] CHIP:DMG: AttributePathIB =
[1706281517.079765][689286:689288] CHIP:DMG: {
[1706281517.079792][689286:689288] CHIP:DMG: Endpoint = 0x0,
[1706281517.079823][689286:689288] CHIP:DMG: Cluster = 0x30,
[1706281517.079854][689286:689288] CHIP:DMG: Attribute = 0x0000_0000,
[1706281517.079884][689286:689288] CHIP:DMG: }
[1706281517.079912][689286:689288] CHIP:DMG:
[1706281517.079942][689286:689288] CHIP:DMG: Data = 0,
[1706281517.079970][689286:689288] CHIP:DMG: },
[1706281517.079997][689286:689288] CHIP:DMG:
[1706281517.080017][689286:689288] CHIP:DMG: },
[1706281517.080045][689286:689288] CHIP:DMG:
[1706281517.080064][689286:689288] CHIP:DMG: AttributeReportIB =
[1706281517.080088][689286:689288] CHIP:DMG: {
[1706281517.080108][689286:689288] CHIP:DMG: AttributeDataIB =
[1706281517.080132][689286:689288] CHIP:DMG: {
[1706281517.080158][689286:689288] CHIP:DMG: DataVersion = 0x5a62c680,
[1706281517.080183][689286:689288] CHIP:DMG: AttributePathIB =
[1706281517.080209][689286:689288] CHIP:DMG: {
[1706281517.080239][689286:689288] CHIP:DMG: Endpoint = 0x0,
[1706281517.080270][689286:689288] CHIP:DMG: Cluster = 0x31,
[1706281517.080301][689286:689288] CHIP:DMG: Attribute = 0x0000_FFFC,
[1706281517.080330][689286:689288] CHIP:DMG: }
[1706281517.080360][689286:689288] CHIP:DMG:
[1706281517.080391][689286:689288] CHIP:DMG: Data = 2,
[1706281517.080419][689286:689288] CHIP:DMG: },
[1706281517.080445][689286:689288] CHIP:DMG:
[1706281517.080465][689286:689288] CHIP:DMG: },
[1706281517.080488][689286:689288] CHIP:DMG:
[1706281517.080506][689286:689288] CHIP:DMG: ],
[1706281517.080553][689286:689288] CHIP:DMG:
[1706281517.080573][689286:689288] CHIP:DMG: SuppressResponse = true,
[1706281517.080592][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281517.080610][689286:689288] CHIP:DMG: }
[1706281517.081345][689286:689288] CHIP:CTL: ----- NetworkCommissioning Features: has Thread. endpointid = 0
[1706281517.081415][689286:689288] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo'
[1706281517.081443][689286:689288] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe'
[1706281517.081468][689286:689288] CHIP:CTL: Performing next commissioning step 'ArmFailSafe'
[1706281517.081489][689286:689288] CHIP:CTL: Arming failsafe (60 seconds)
[1706281517.081546][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281517.081572][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281517.081690][689286:689288] CHIP:EM: <<< [E:23566i S:29128 M:61819005] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281517.082047][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281517.221555][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281517.222973][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281517.223267][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.223433][689286:689288] CHIP:EM: >>> [E:23566i S:29128 M:263416816] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281517.223463][689286:689288] CHIP:EM: Found matching exchange: 23566i, Delegate: 0xffffa000a2e8
[1706281517.223495][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281517.223541][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281517.223560][689286:689288] CHIP:DMG: {
[1706281517.223579][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281517.223597][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281517.223623][689286:689288] CHIP:DMG: [
[1706281517.223642][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281517.223668][689286:689288] CHIP:DMG: {
[1706281517.223688][689286:689288] CHIP:DMG: CommandDataIB =
[1706281517.223718][689286:689288] CHIP:DMG: {
[1706281517.223741][689286:689288] CHIP:DMG: CommandPathIB =
[1706281517.223772][689286:689288] CHIP:DMG: {
[1706281517.223803][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281517.223835][689286:689288] CHIP:DMG: ClusterId = 0x30,
[1706281517.223865][689286:689288] CHIP:DMG: CommandId = 0x1,
[1706281517.223895][689286:689288] CHIP:DMG: },
[1706281517.223926][689286:689288] CHIP:DMG:
[1706281517.223951][689286:689288] CHIP:DMG: CommandFields =
[1706281517.223981][689286:689288] CHIP:DMG: {
[1706281517.224013][689286:689288] CHIP:DMG: 0x0 = 0,
[1706281517.224047][689286:689288] CHIP:DMG: 0x1 = "" (0 chars),
[1706281517.224078][689286:689288] CHIP:DMG: },
[1706281517.224106][689286:689288] CHIP:DMG: },
[1706281517.224133][689286:689288] CHIP:DMG:
[1706281517.224153][689286:689288] CHIP:DMG: },
[1706281517.224177][689286:689288] CHIP:DMG:
[1706281517.224195][689286:689288] CHIP:DMG: ],
[1706281517.224219][689286:689288] CHIP:DMG:
[1706281517.224238][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281517.224256][689286:689288] CHIP:DMG: },
[1706281517.224307][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1706281517.224367][689286:689288] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1706281517.224397][689286:689288] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe'
[1706281517.224415][689286:689288] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1706281517.224439][689286:689288] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory'
[1706281517.224455][689286:689288] CHIP:CTL: Setting Regulatory Config
[1706281517.224471][689286:689288] CHIP:CTL: Device does not support configurable regulatory location
[1706281517.224530][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281517.224570][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281517.224668][689286:689288] CHIP:EM: <<< [E:23567i S:29128 M:61819006] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281517.225009][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281517.225073][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281517.319011][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281517.320485][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281517.320808][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.320991][689286:689288] CHIP:EM: >>> [E:23567i S:29128 M:263416817] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281517.321024][689286:689288] CHIP:EM: Found matching exchange: 23567i, Delegate: 0xffffa0009158
[1706281517.321058][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281517.321126][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281517.321148][689286:689288] CHIP:DMG: {
[1706281517.321167][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281517.321196][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281517.321222][689286:689288] CHIP:DMG: [
[1706281517.321241][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281517.321282][689286:689288] CHIP:DMG: {
[1706281517.321304][689286:689288] CHIP:DMG: CommandDataIB =
[1706281517.321343][689286:689288] CHIP:DMG: {
[1706281517.321372][689286:689288] CHIP:DMG: CommandPathIB =
[1706281517.321406][689286:689288] CHIP:DMG: {
[1706281517.321438][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281517.321478][689286:689288] CHIP:DMG: ClusterId = 0x30,
[1706281517.321518][689286:689288] CHIP:DMG: CommandId = 0x3,
[1706281517.321550][689286:689288] CHIP:DMG: },
[1706281517.321591][689286:689288] CHIP:DMG:
[1706281517.321620][689286:689288] CHIP:DMG: CommandFields =
[1706281517.321658][689286:689288] CHIP:DMG: {
[1706281517.321699][689286:689288] CHIP:DMG: 0x0 = 0,
[1706281517.321734][689286:689288] CHIP:DMG: 0x1 = "" (0 chars),
[1706281517.321775][689286:689288] CHIP:DMG: },
[1706281517.321805][689286:689288] CHIP:DMG: },
[1706281517.321844][689286:689288] CHIP:DMG:
[1706281517.321875][689286:689288] CHIP:DMG: },
[1706281517.321901][689286:689288] CHIP:DMG:
[1706281517.321919][689286:689288] CHIP:DMG: ],
[1706281517.321953][689286:689288] CHIP:DMG:
[1706281517.321972][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281517.321998][689286:689288] CHIP:DMG: },
[1706281517.322060][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1706281517.322097][689286:689288] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0
[1706281517.322136][689286:689288] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory'
[1706281517.322155][689286:689288] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest'
[1706281517.322180][689286:689288] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest'
[1706281517.322197][689286:689288] CHIP:CTL: Sending request for PAI certificate
[1706281517.322222][689286:689288] CHIP:CTL: Sending Certificate Chain request to 0xffffa000df00 device
[1706281517.322289][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281517.322314][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281517.322433][689286:689288] CHIP:EM: <<< [E:23568i S:29128 M:61819007] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281517.322772][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281517.322840][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281517.416539][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281517.419902][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281517.420245][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.517115][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281517.517262][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.612397][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281517.612761][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.612932][689286:689288] CHIP:EM: >>> [E:23568i S:29128 M:263416818] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281517.612963][689286:689288] CHIP:EM: Found matching exchange: 23568i, Delegate: 0xffffa000a2e8
[1706281517.612999][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281517.613045][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281517.613064][689286:689288] CHIP:DMG: {
[1706281517.613140][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281517.613163][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281517.613198][689286:689288] CHIP:DMG: [
[1706281517.613218][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281517.613253][689286:689288] CHIP:DMG: {
[1706281517.613274][689286:689288] CHIP:DMG: CommandDataIB =
[1706281517.613330][689286:689288] CHIP:DMG: {
[1706281517.613363][689286:689288] CHIP:DMG: CommandPathIB =
[1706281517.613395][689286:689288] CHIP:DMG: {
[1706281517.613429][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281517.613462][689286:689288] CHIP:DMG: ClusterId = 0x3e,
[1706281517.613496][689286:689288] CHIP:DMG: CommandId = 0x3,
[1706281517.613526][689286:689288] CHIP:DMG: },
[1706281517.613566][689286:689288] CHIP:DMG:
[1706281517.613592][689286:689288] CHIP:DMG: CommandFields =
[1706281517.613631][689286:689288] CHIP:DMG: {
[1706281517.613671][689286:689288] CHIP:DMG: 0x0 = [
[1706281517.613804][689286:689288] CHIP:DMG: 0x30, 0x82, 0x01, 0xcb, 0x30, 0x82, 0x01, 0x71, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x56, 0xad, 0x82, 0x22, 0xad, 0x94, 0x5b, 0x64, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x30, 0x31, 0x18, 0x30, 0x16, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x0f, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x54, 0x65, 0x73, 0x74, 0x20, 0x50, 0x41, 0x41, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x41, 0x9a, 0x93, 0x15, 0xc2, 0x17, 0x3e, 0x0c, 0x8c, 0x87, 0x6d, 0x03, 0xcc, 0xfc, 0x94, 0x48, 0x52, 0x64, 0x7f, 0x7f, 0xec, 0x5e, 0x50, 0x82, 0xf4, 0x05, 0x99, 0x28, 0xec, 0xa8, 0x94, 0xc5, 0x94, 0x15, 0x13, 0x09, 0xac, 0x63, 0x1e, 0x4c, 0xb0, 0x33, 0x92, 0xaf, 0x68, 0x4b, 0x0b, 0xaf, 0xb7, 0xe6, 0x5b, 0x3b, 0x81, 0x62, 0xc2, 0xf5, 0x2b, 0xf9, 0x31, 0xb8, 0xe7, 0x7a, 0xaa, 0x82, 0xa3, 0x66, 0x30, 0x64, 0x30, 0x12, 0x06, 0x03, 0x55, 0x1d, 0x
[1706281517.613868][689286:689288] CHIP:DMG: ] (463 bytes)
[1706281517.613900][689286:689288] CHIP:DMG: },
[1706281517.613929][689286:689288] CHIP:DMG: },
[1706281517.613957][689286:689288] CHIP:DMG:
[1706281517.613978][689286:689288] CHIP:DMG: },
[1706281517.614002][689286:689288] CHIP:DMG:
[1706281517.614032][689286:689288] CHIP:DMG: ],
[1706281517.614059][689286:689288] CHIP:DMG:
[1706281517.614078][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281517.614105][689286:689288] CHIP:DMG: },
[1706281517.614166][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1706281517.614202][689286:689288] CHIP:CTL: Received certificate chain from the device
[1706281517.614240][689286:689288] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest'
[1706281517.614264][689286:689288] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1706281517.614297][689286:689288] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest'
[1706281517.614315][689286:689288] CHIP:CTL: Sending request for DAC certificate
[1706281517.614332][689286:689288] CHIP:CTL: Sending Certificate Chain request to 0xffffa000df00 device
[1706281517.614410][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281517.614436][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281517.614564][689286:689288] CHIP:EM: <<< [E:23569i S:29128 M:61819008] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281517.614917][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281517.614987][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281517.709020][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281517.712421][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281517.712733][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.810291][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281517.810610][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.905496][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281517.905847][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281517.906060][689286:689288] CHIP:EM: >>> [E:23569i S:29128 M:263416819] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281517.906104][689286:689288] CHIP:EM: Found matching exchange: 23569i, Delegate: 0xffffa0009158
[1706281517.906154][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281517.906217][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281517.906247][689286:689288] CHIP:DMG: {
[1706281517.906274][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281517.906303][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281517.906340][689286:689288] CHIP:DMG: [
[1706281517.906369][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281517.906414][689286:689288] CHIP:DMG: {
[1706281517.906445][689286:689288] CHIP:DMG: CommandDataIB =
[1706281517.906490][689286:689288] CHIP:DMG: {
[1706281517.906531][689286:689288] CHIP:DMG: CommandPathIB =
[1706281517.906578][689286:689288] CHIP:DMG: {
[1706281517.906624][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281517.906672][689286:689288] CHIP:DMG: ClusterId = 0x3e,
[1706281517.906719][689286:689288] CHIP:DMG: CommandId = 0x3,
[1706281517.906764][689286:689288] CHIP:DMG: },
[1706281517.906811][689286:689288] CHIP:DMG:
[1706281517.906853][689286:689288] CHIP:DMG: CommandFields =
[1706281517.906899][689286:689288] CHIP:DMG: {
[1706281517.906946][689286:689288] CHIP:DMG: 0x0 = [
[1706281517.907121][689286:689288] CHIP:DMG: 0x30, 0x82, 0x01, 0xe7, 0x30, 0x82, 0x01, 0x8e, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x69, 0xcd, 0xf1, 0x0d, 0xe9, 0xe5, 0x4e, 0xd1, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x53, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x44, 0x41, 0x43, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x2f, 0x30, 0x78, 0x38, 0x30, 0x30, 0x31, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x02, 0x0c, 0x04, 0x38, 0x30, 0x30, 0x31, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x46, 0x3a, 0xc6, 0x93, 0x42, 0x91, 0x0a, 0x0e, 0x55, 0x88, 0xfc, 0x6f, 0xf5, 0x6b, 0xb6, 0x3e, 0x62, 0xec, 0xce, 0xcb, 0x14, 0x8f, 0x7d, 0x4e, 0xb0, 0x3e, 0xe5, 0x52, 0x60, 0x14, 0x15, 0x76, 0x7d, 0x16, 0xa5, 0xc6, 0x63, 0xf7, 0x93, 0x
[1706281517.907213][689286:689288] CHIP:DMG: ] (491 bytes)
[1706281517.907261][689286:689288] CHIP:DMG: },
[1706281517.907305][689286:689288] CHIP:DMG: },
[1706281517.907351][689286:689288] CHIP:DMG:
[1706281517.907385][689286:689288] CHIP:DMG: },
[1706281517.907426][689286:689288] CHIP:DMG:
[1706281517.907454][689286:689288] CHIP:DMG: ],
[1706281517.907491][689286:689288] CHIP:DMG:
[1706281517.907518][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281517.907546][689286:689288] CHIP:DMG: },
[1706281517.907621][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1706281517.907669][689286:689288] CHIP:CTL: Received certificate chain from the device
[1706281517.907708][689286:689288] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest'
[1706281517.907741][689286:689288] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1706281517.907775][689286:689288] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest'
[1706281517.907799][689286:689288] CHIP:CTL: Sending Attestation Request to the device.
[1706281517.907825][689286:689288] CHIP:CTL: Sending Attestation request to 0xffffa000df00 device
[1706281517.907902][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281517.907939][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281517.908068][689286:689288] CHIP:EM: <<< [E:23570i S:29128 M:61819009] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281517.908549][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281517.908597][689286:689288] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information
[1706281517.908665][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281518.001966][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281518.005219][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281518.005383][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281518.102253][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281518.102533][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281518.199497][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281518.199652][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281518.199839][689286:689288] CHIP:EM: >>> [E:23570i S:29128 M:263416820] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281518.199871][689286:689288] CHIP:EM: Found matching exchange: 23570i, Delegate: 0xffffa000a2e8
[1706281518.199909][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281518.199959][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281518.199979][689286:689288] CHIP:DMG: {
[1706281518.199999][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281518.200020][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281518.200048][689286:689288] CHIP:DMG: [
[1706281518.200069][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281518.200101][689286:689288] CHIP:DMG: {
[1706281518.200124][689286:689288] CHIP:DMG: CommandDataIB =
[1706281518.200149][689286:689288] CHIP:DMG: {
[1706281518.200172][689286:689288] CHIP:DMG: CommandPathIB =
[1706281518.200199][689286:689288] CHIP:DMG: {
[1706281518.200226][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281518.200254][689286:689288] CHIP:DMG: ClusterId = 0x3e,
[1706281518.200281][689286:689288] CHIP:DMG: CommandId = 0x1,
[1706281518.200308][689286:689288] CHIP:DMG: },
[1706281518.200336][689286:689288] CHIP:DMG:
[1706281518.200360][689286:689288] CHIP:DMG: CommandFields =
[1706281518.200387][689286:689288] CHIP:DMG: {
[1706281518.200415][689286:689288] CHIP:DMG: 0x0 = [
[1706281518.200549][689286:689288] CHIP:DMG: 0x15, 0x31, 0x01, 0x1b, 0x02, 0x30, 0x82, 0x02, 0x17, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x02, 0xa0, 0x82, 0x02, 0x08, 0x30, 0x82, 0x02, 0x04, 0x02, 0x01, 0x03, 0x31, 0x0d, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x82, 0x01, 0x70, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x01, 0xa0, 0x82, 0x01, 0x61, 0x04, 0x82, 0x01, 0x5d, 0x15, 0x24, 0x00, 0x01, 0x25, 0x01, 0xf1, 0xff, 0x36, 0x02, 0x05, 0x00, 0x80, 0x05, 0x01, 0x80, 0x05, 0x02, 0x80, 0x05, 0x03, 0x80, 0x05, 0x04, 0x80, 0x05, 0x05, 0x80, 0x05, 0x06, 0x80, 0x05, 0x07, 0x80, 0x05, 0x08, 0x80, 0x05, 0x09, 0x80, 0x05, 0x0a, 0x80, 0x05, 0x0b, 0x80, 0x05, 0x0c, 0x80, 0x05, 0x0d, 0x80, 0x05, 0x0e, 0x80, 0x05, 0x0f, 0x80, 0x05, 0x10, 0x80, 0x05, 0x11, 0x80, 0x05, 0x12, 0x80, 0x05, 0x13, 0x80, 0x05, 0x14, 0x80, 0x05, 0x15, 0x80, 0x05, 0x16, 0x80, 0x05, 0x17, 0x80, 0x05, 0x18, 0x80, 0x05, 0x19, 0x80, 0x05, 0x1a, 0x80, 0x05, 0x1b, 0x80, 0x05, 0x1c, 0x80, 0x05, 0x1d, 0x80, 0x05, 0x1e, 0x80, 0x05, 0x1f, 0x80, 0x05, 0x20, 0x80, 0x05, 0x21, 0x80, 0x05, 0x22, 0x80, 0x05, 0x23, 0x80, 0x05, 0x24, 0x80, 0x05, 0x25, 0x80, 0x05, 0x26, 0x80, 0x05, 0x27, 0x80, 0x05, 0x28, 0x80, 0x05, 0x29, 0x80, 0x05, 0x2a, 0x80, 0x05, 0x2b, 0x80, 0x05, 0x2c, 0x80, 0x05, 0x2d, 0x80, 0x05, 0x2e, 0x80, 0x05, 0x2f, 0x80, 0x05, 0x30, 0x80, 0x05, 0x31, 0x80, 0x05, 0x32, 0x80, 0x05, 0x33, 0x80, 0x05, 0x34, 0x80, 0x05, 0x35, 0x80, 0x05, 0x36, 0x80, 0x05, 0x37, 0x80, 0x05, 0x38, 0x80, 0x05, 0x39, 0x80, 0x05, 0x3a, 0x80, 0x05, 0x3b, 0x80, 0x05, 0x3c, 0x80, 0x05, 0x3d, 0x80, 0x05, 0x3e, 0x80, 0x05, 0x3f, 0x80, 0x05, 0x40, 0x80, 0x05, 0x41, 0x80, 0x05, 0x42, 0x80, 0x05, 0x43, 0x80, 0x
[1706281518.200612][689286:689288] CHIP:DMG: ] (583 bytes)
[1706281518.200640][689286:689288] CHIP:DMG: 0x1 = [
[1706281518.200688][689286:689288] CHIP:DMG: 0xb8, 0x75, 0x3e, 0x68, 0x2f, 0x0c, 0xdc, 0xed, 0x9b, 0x56, 0xb2, 0xc2, 0x70, 0x11, 0x38, 0x73, 0x0d, 0xda, 0xad, 0x45, 0x73, 0xab, 0xb0, 0x7c, 0x10, 0x32, 0xce, 0x9e, 0x4e, 0x1a, 0x6e, 0xe4, 0xf5, 0x3a, 0x4f, 0x8e, 0x53, 0x89, 0x2c, 0x7b, 0x79, 0x5a, 0xdc, 0x50, 0xeb, 0xb6, 0x85, 0x02, 0x35, 0x1a, 0xdb, 0x53, 0x1c, 0x8c, 0x38, 0x9a, 0xc1, 0x84, 0xc8, 0x7a, 0x47, 0xfe, 0x9c, 0x3e,
[1706281518.200723][689286:689288] CHIP:DMG: ] (64 bytes)
[1706281518.200751][689286:689288] CHIP:DMG: },
[1706281518.200781][689286:689288] CHIP:DMG: },
[1706281518.200812][689286:689288] CHIP:DMG:
[1706281518.200836][689286:689288] CHIP:DMG: },
[1706281518.200866][689286:689288] CHIP:DMG:
[1706281518.200888][689286:689288] CHIP:DMG: ],
[1706281518.200918][689286:689288] CHIP:DMG:
[1706281518.200940][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281518.200962][689286:689288] CHIP:DMG: },
[1706281518.201026][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1706281518.201068][689286:689288] CHIP:CTL: Received Attestation Information from the device
[1706281518.201136][689286:689288] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest'
[1706281518.201162][689286:689288] CHIP:CTL: AutoCommissioner setting attestationElements buffer size 583/583
[1706281518.201218][689286:689288] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1706281518.201249][689286:689288] CHIP:CTL: Performing next commissioning step 'AttestationVerification'
[1706281518.201266][689286:689288] CHIP:CTL: Verifying attestation
[1706281518.236663][689286:689288] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device.
[1706281518.236735][689286:689288] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification'
[1706281518.236758][689286:689288] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest'
[1706281518.236785][689286:689288] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest'
[1706281518.236804][689286:689288] CHIP:CTL: Sending CSR request to 0xffffa000df00 device
[1706281518.236883][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281518.236920][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281518.237109][689286:689288] CHIP:EM: <<< [E:23571i S:29128 M:61819010] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281518.237679][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281518.237748][689286:689288] CHIP:CTL: Sent CSR request, waiting for the CSR
[1706281518.237817][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281518.294345][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281518.297858][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281518.298257][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281518.393923][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281518.394123][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281518.394343][689286:689288] CHIP:EM: >>> [E:23571i S:29128 M:263416821] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281518.394381][689286:689288] CHIP:EM: Found matching exchange: 23571i, Delegate: 0xffffa003e138
[1706281518.394425][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281518.394480][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281518.394502][689286:689288] CHIP:DMG: {
[1706281518.394523][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281518.394546][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281518.394577][689286:689288] CHIP:DMG: [
[1706281518.394600][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281518.394632][689286:689288] CHIP:DMG: {
[1706281518.394656][689286:689288] CHIP:DMG: CommandDataIB =
[1706281518.394684][689286:689288] CHIP:DMG: {
[1706281518.394709][689286:689288] CHIP:DMG: CommandPathIB =
[1706281518.394738][689286:689288] CHIP:DMG: {
[1706281518.394767][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281518.394798][689286:689288] CHIP:DMG: ClusterId = 0x3e,
[1706281518.394828][689286:689288] CHIP:DMG: CommandId = 0x5,
[1706281518.394856][689286:689288] CHIP:DMG: },
[1706281518.394886][689286:689288] CHIP:DMG:
[1706281518.394912][689286:689288] CHIP:DMG: CommandFields =
[1706281518.394940][689286:689288] CHIP:DMG: {
[1706281518.394970][689286:689288] CHIP:DMG: 0x0 = [
[1706281518.395094][689286:689288] CHIP:DMG: 0x15, 0x30, 0x01, 0xdd, 0x30, 0x81, 0xda, 0x30, 0x81, 0x81, 0x02, 0x01, 0x00, 0x30, 0x0e, 0x31, 0x0c, 0x30, 0x0a, 0x06, 0x03, 0x55, 0x04, 0x0b, 0x0c, 0x03, 0x43, 0x53, 0x41, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0xaa, 0xff, 0x13, 0x6e, 0x51, 0xb6, 0x82, 0x38, 0x16, 0xfa, 0x87, 0xed, 0xf4, 0x01, 0x03, 0x8c, 0x3a, 0xf8, 0xfb, 0x0f, 0xf7, 0xe8, 0xaf, 0xc8, 0x6b, 0x76, 0x73, 0x36, 0x27, 0x30, 0x00, 0x9a, 0xae, 0xcd, 0xee, 0x45, 0xdb, 0x58, 0x4a, 0x0e, 0xeb, 0x13, 0x95, 0x28, 0x4e, 0x0c, 0xd9, 0xd7, 0x56, 0x96, 0xd3, 0x23, 0x2e, 0xb6, 0x2f, 0xee, 0x86, 0xb2, 0x38, 0xea, 0x61, 0xb3, 0xd6, 0x6e, 0xa0, 0x11, 0x30, 0x0f, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x09, 0x0e, 0x31, 0x02, 0x30, 0x00, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x03, 0x48, 0x00, 0x30, 0x45, 0x02, 0x21, 0x00, 0xf7, 0xdb, 0x62, 0xd6, 0xdd, 0x6d, 0x96, 0x3b, 0x4f, 0x45, 0x89, 0x0c, 0xc9, 0xa5, 0xc2, 0x16, 0x1e, 0xea, 0x08, 0x56, 0x51, 0xcd, 0xc1, 0xa6, 0x50, 0xe7, 0xe0, 0x6b, 0x0e, 0x91, 0xf1, 0x05, 0x02, 0x20, 0x3a, 0x9c, 0xf9, 0x8d, 0x3c, 0x8c, 0x68, 0x18, 0xcb, 0xa9, 0x56, 0x08, 0x0c, 0xfe, 0x5d, 0xf0, 0xdb, 0x60, 0x47, 0x79, 0xd5, 0xd3, 0x3c, 0xe4, 0x0e, 0x61, 0x8d, 0xa3, 0x8c, 0x6f, 0xa5, 0xc6, 0x30, 0x02, 0x20, 0xe6, 0x9f, 0x21, 0x29, 0xef, 0x2d, 0xe1, 0xaf, 0xf3, 0x93, 0xc5, 0xeb, 0x72, 0x62, 0x62, 0xba, 0x9f, 0x30, 0xed, 0x91, 0x86, 0xe9, 0x22, 0x59, 0x1c, 0x90, 0xff, 0x0e, 0xdd, 0x27, 0x06, 0x90, 0x18,
[1706281518.395161][689286:689288] CHIP:DMG: ] (261 bytes)
[1706281518.395198][689286:689288] CHIP:DMG: 0x1 = [
[1706281518.395266][689286:689288] CHIP:DMG: 0x4b, 0xdc, 0x05, 0xf0, 0xaf, 0x01, 0x14, 0x0d, 0xa8, 0xfa, 0xfb, 0x36, 0x5f, 0xba, 0x11, 0xee, 0xc2, 0x4c, 0x7d, 0x02, 0x72, 0x39, 0xa9, 0xee, 0x84, 0xde, 0xab, 0xfe, 0xad, 0x5a, 0x12, 0x5d, 0x13, 0xca, 0x93, 0xc9, 0xca, 0x02, 0x4a, 0x24, 0x72, 0xed, 0x8a, 0x26, 0x8a, 0x3d, 0xb7, 0xcd, 0x44, 0x95, 0x1b, 0x15, 0x6a, 0x56, 0x89, 0x5c, 0x77, 0x13, 0x29, 0x7e, 0x97, 0x84, 0xb7, 0xf6,
[1706281518.395317][689286:689288] CHIP:DMG: ] (64 bytes)
[1706281518.395361][689286:689288] CHIP:DMG: },
[1706281518.395394][689286:689288] CHIP:DMG: },
[1706281518.395429][689286:689288] CHIP:DMG:
[1706281518.395455][689286:689288] CHIP:DMG: },
[1706281518.395487][689286:689288] CHIP:DMG:
[1706281518.395511][689286:689288] CHIP:DMG: ],
[1706281518.395544][689286:689288] CHIP:DMG:
[1706281518.395568][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281518.395617][689286:689288] CHIP:DMG: },
[1706281518.395701][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1706281518.395760][689286:689288] CHIP:CTL: Received certificate signing request from the device
[1706281518.395800][689286:689288] CHIP:CTL: Successfully finished commissioning step 'SendOpCertSigningRequest'
[1706281518.395835][689286:689288] CHIP:CTL: Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR'
[1706281518.395870][689286:689288] CHIP:CTL: Performing next commissioning step 'ValidateCSR'
[1706281518.401706][689286:689288] CHIP:CTL: Successfully finished commissioning step 'ValidateCSR'
[1706281518.401776][689286:689288] CHIP:CTL: Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain'
[1706281518.401809][689286:689288] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain'
[1706281518.401836][689286:689288] CHIP:CTL: Getting certificate chain for the device from the issuer
[1706281518.406245][689286:689288] CHIP:CTL: Verifying Certificate Signing Request
[1706281518.408641][689286:689288] CHIP:CTL: Generating NOC
[1706281518.409005][689286:689288] CHIP:CTL: Providing certificate chain to the commissioner
[1706281518.409041][689286:689288] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status src/controller/ExampleOperationalCredentialsIssuer.cpp:396: Success
[1706281518.409075][689286:689288] CHIP:CTL: Successfully finished commissioning step 'GenerateNOCChain'
[1706281518.409308][689286:689288] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert'
[1706281518.409335][689286:689288] CHIP:CTL: Sending root certificate to the device
[1706281518.409412][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281518.409452][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281518.409607][689286:689288] CHIP:EM: <<< [E:23572i S:29128 M:61819011] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281518.410350][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281518.410447][689286:689288] CHIP:CTL: Sent root certificate to the device
[1706281518.410982][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281518.489576][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281518.635466][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281518.636990][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281518.637190][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281518.637452][689286:689288] CHIP:EM: >>> [E:23572i S:29128 M:263416822] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281518.637492][689286:689288] CHIP:EM: Found matching exchange: 23572i, Delegate: 0xffffa000a2e8
[1706281518.637531][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281518.637583][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281518.637604][689286:689288] CHIP:DMG: {
[1706281518.637625][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281518.637646][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281518.637674][689286:689288] CHIP:DMG: [
[1706281518.637696][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281518.637726][689286:689288] CHIP:DMG: {
[1706281518.637750][689286:689288] CHIP:DMG: CommandStatusIB =
[1706281518.637776][689286:689288] CHIP:DMG: {
[1706281518.637801][689286:689288] CHIP:DMG: CommandPathIB =
[1706281518.637829][689286:689288] CHIP:DMG: {
[1706281518.637857][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281518.637886][689286:689288] CHIP:DMG: ClusterId = 0x3e,
[1706281518.637914][689286:689288] CHIP:DMG: CommandId = 0xb,
[1706281518.637941][689286:689288] CHIP:DMG: },
[1706281518.637972][689286:689288] CHIP:DMG:
[1706281518.637997][689286:689288] CHIP:DMG: StatusIB =
[1706281518.638025][689286:689288] CHIP:DMG: {
[1706281518.638052][689286:689288] CHIP:DMG: status = 0x00 (SUCCESS),
[1706281518.638079][689286:689288] CHIP:DMG: },
[1706281518.638107][689286:689288] CHIP:DMG:
[1706281518.638130][689286:689288] CHIP:DMG: },
[1706281518.638159][689286:689288] CHIP:DMG:
[1706281518.638181][689286:689288] CHIP:DMG: },
[1706281518.638208][689286:689288] CHIP:DMG:
[1706281518.638228][689286:689288] CHIP:DMG: ],
[1706281518.638255][689286:689288] CHIP:DMG:
[1706281518.638276][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281518.638296][689286:689288] CHIP:DMG: },
[1706281518.638352][689286:689288] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1706281518.638384][689286:689288] CHIP:CTL: Device confirmed that it has received the root certificate
[1706281518.638418][689286:689288] CHIP:CTL: Successfully finished commissioning step 'SendTrustedRootCert'
[1706281518.638446][689286:689288] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
[1706281518.638476][689286:689288] CHIP:CTL: Performing next commissioning step 'SendNOC'
[1706281518.638557][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281518.638625][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281518.638784][689286:689288] CHIP:EM: <<< [E:23573i S:29128 M:61819012] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281518.639406][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281518.639478][689286:689288] CHIP:CTL: Sent operational certificate to the device
[1706281518.639548][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281518.733052][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281518.879288][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281518.976756][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281518.978518][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281518.979026][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281518.979261][689286:689288] CHIP:EM: >>> [E:23573i S:29128 M:263416823] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281518.979334][689286:689288] CHIP:EM: Found matching exchange: 23573i, Delegate: 0xffffa003e138
[1706281518.979385][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281518.979451][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281518.979483][689286:689288] CHIP:DMG: {
[1706281518.979527][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281518.979560][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281518.979601][689286:689288] CHIP:DMG: [
[1706281518.979645][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281518.979698][689286:689288] CHIP:DMG: {
[1706281518.979745][689286:689288] CHIP:DMG: CommandDataIB =
[1706281518.979784][689286:689288] CHIP:DMG: {
[1706281518.979832][689286:689288] CHIP:DMG: CommandPathIB =
[1706281518.979874][689286:689288] CHIP:DMG: {
[1706281518.979926][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281518.979971][689286:689288] CHIP:DMG: ClusterId = 0x3e,
[1706281518.980027][689286:689288] CHIP:DMG: CommandId = 0x8,
[1706281518.980068][689286:689288] CHIP:DMG: },
[1706281518.980122][689286:689288] CHIP:DMG:
[1706281518.980160][689286:689288] CHIP:DMG: CommandFields =
[1706281518.980213][689286:689288] CHIP:DMG: {
[1706281518.980256][689286:689288] CHIP:DMG: 0x0 = 0,
[1706281518.980311][689286:689288] CHIP:DMG: 0x1 = 1,
[1706281518.980356][689286:689288] CHIP:DMG: },
[1706281518.980393][689286:689288] CHIP:DMG: },
[1706281518.980448][689286:689288] CHIP:DMG:
[1706281518.980481][689286:689288] CHIP:DMG: },
[1706281518.980535][689286:689288] CHIP:DMG:
[1706281518.980664][689286:689288] CHIP:DMG: ],
[1706281518.980730][689286:689288] CHIP:DMG:
[1706281518.980763][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281518.980793][689286:689288] CHIP:DMG: },
[1706281518.980933][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1706281518.981045][689286:689288] CHIP:CTL: Device returned status 0 on receiving the NOC
[1706281518.981237][689286:689288] CHIP:CTL: Operational credentials provisioned on device 0xffffa000df00
[1706281518.981290][689286:689288] CHIP:TOO: Secure Pairing Success
[1706281518.981317][689286:689288] CHIP:TOO: CASE establishment successful
[1706281518.981353][689286:689288] CHIP:CTL: Successfully finished commissioning step 'SendNOC'
[1706281518.981398][689286:689288] CHIP:CTL: No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks
[1706281518.981427][689286:689288] CHIP:CTL: Commissioning stage next step: 'SendNOC' -> 'ThreadNetworkSetup'
[1706281518.981478][689286:689288] CHIP:CTL: Performing next commissioning step 'ThreadNetworkSetup'
[1706281518.981587][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281518.981649][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281518.981859][689286:689288] CHIP:EM: <<< [E:23574i S:29128 M:61819013] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281518.982511][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281518.982632][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281519.074414][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281519.075936][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281519.076423][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281519.076690][689286:689288] CHIP:EM: >>> [E:23574i S:29128 M:263416824] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281519.076743][689286:689288] CHIP:EM: Found matching exchange: 23574i, Delegate: 0xffffa000a2e8
[1706281519.076795][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281519.076857][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281519.076886][689286:689288] CHIP:DMG: {
[1706281519.076914][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281519.076955][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281519.076994][689286:689288] CHIP:DMG: [
[1706281519.077023][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281519.077064][689286:689288] CHIP:DMG: {
[1706281519.077125][689286:689288] CHIP:DMG: CommandDataIB =
[1706281519.077161][689286:689288] CHIP:DMG: {
[1706281519.077191][689286:689288] CHIP:DMG: CommandPathIB =
[1706281519.077226][689286:689288] CHIP:DMG: {
[1706281519.077266][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281519.077303][689286:689288] CHIP:DMG: ClusterId = 0x31,
[1706281519.077338][689286:689288] CHIP:DMG: CommandId = 0x5,
[1706281519.077373][689286:689288] CHIP:DMG: },
[1706281519.077413][689286:689288] CHIP:DMG:
[1706281519.077448][689286:689288] CHIP:DMG: CommandFields =
[1706281519.077485][689286:689288] CHIP:DMG: {
[1706281519.077524][689286:689288] CHIP:DMG: 0x0 = 0,
[1706281519.077563][689286:689288] CHIP:DMG: 0x2 = 0,
[1706281519.077602][689286:689288] CHIP:DMG: },
[1706281519.077636][689286:689288] CHIP:DMG: },
[1706281519.077675][689286:689288] CHIP:DMG:
[1706281519.077705][689286:689288] CHIP:DMG: },
[1706281519.077742][689286:689288] CHIP:DMG:
[1706281519.077770][689286:689288] CHIP:DMG: ],
[1706281519.077807][689286:689288] CHIP:DMG:
[1706281519.077835][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281519.077862][689286:689288] CHIP:DMG: },
[1706281519.077938][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1706281519.077990][689286:689288] CHIP:CTL: Received NetworkConfig response, networkingStatus=0
[1706281519.078031][689286:689288] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkSetup'
[1706281519.078060][689286:689288] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkSetup' -> 'FailsafeBeforeThreadEnable'
[1706281519.078096][689286:689288] CHIP:CTL: Performing next commissioning step 'FailsafeBeforeThreadEnable'
[1706281519.078141][689286:689288] CHIP:CTL: Arming failsafe (73 seconds)
[1706281519.078222][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281519.078261][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281519.078410][689286:689288] CHIP:EM: <<< [E:23575i S:29128 M:61819014] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281519.078956][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281519.079061][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281519.171754][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281519.173327][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281519.173516][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281519.173757][689286:689288] CHIP:EM: >>> [E:23575i S:29128 M:263416825] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281519.173803][689286:689288] CHIP:EM: Found matching exchange: 23575i, Delegate: 0xffffa003e138
[1706281519.173845][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281519.173903][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281519.173929][689286:689288] CHIP:DMG: {
[1706281519.173953][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281519.173977][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281519.174011][689286:689288] CHIP:DMG: [
[1706281519.174035][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281519.174069][689286:689288] CHIP:DMG: {
[1706281519.174095][689286:689288] CHIP:DMG: CommandDataIB =
[1706281519.174126][689286:689288] CHIP:DMG: {
[1706281519.174153][689286:689288] CHIP:DMG: CommandPathIB =
[1706281519.174184][689286:689288] CHIP:DMG: {
[1706281519.174216][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281519.174249][689286:689288] CHIP:DMG: ClusterId = 0x30,
[1706281519.174281][689286:689288] CHIP:DMG: CommandId = 0x1,
[1706281519.174312][689286:689288] CHIP:DMG: },
[1706281519.174344][689286:689288] CHIP:DMG:
[1706281519.174372][689286:689288] CHIP:DMG: CommandFields =
[1706281519.174403][689286:689288] CHIP:DMG: {
[1706281519.174435][689286:689288] CHIP:DMG: 0x0 = 0,
[1706281519.174471][689286:689288] CHIP:DMG: 0x1 = "" (0 chars),
[1706281519.174504][689286:689288] CHIP:DMG: },
[1706281519.174533][689286:689288] CHIP:DMG: },
[1706281519.174566][689286:689288] CHIP:DMG:
[1706281519.174592][689286:689288] CHIP:DMG: },
[1706281519.174623][689286:689288] CHIP:DMG:
[1706281519.174647][689286:689288] CHIP:DMG: ],
[1706281519.174678][689286:689288] CHIP:DMG:
[1706281519.174702][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281519.174725][689286:689288] CHIP:DMG: },
[1706281519.174793][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1706281519.174842][689286:689288] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1706281519.174880][689286:689288] CHIP:CTL: Successfully finished commissioning step 'FailsafeBeforeThreadEnable'
[1706281519.174904][689286:689288] CHIP:CTL: Commissioning stage next step: 'FailsafeBeforeThreadEnable' -> 'ThreadNetworkEnable'
[1706281519.174936][689286:689288] CHIP:CTL: Performing next commissioning step 'ThreadNetworkEnable'
[1706281519.175019][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281519.175059][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281519.175202][689286:689288] CHIP:EM: <<< [E:23576i S:29128 M:61819015] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281519.175868][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281519.175982][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281519.269286][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281520.733761][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281520.734066][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281520.734385][689286:689288] CHIP:EM: >>> [E:23576i S:29128 M:263416826] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281520.734468][689286:689288] CHIP:EM: Found matching exchange: 23576i, Delegate: 0xffffa000a2e8
[1706281520.734555][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281520.734659][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281520.734714][689286:689288] CHIP:DMG: {
[1706281520.734768][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281520.734825][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281520.734899][689286:689288] CHIP:DMG: [
[1706281520.734955][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281520.735033][689286:689288] CHIP:DMG: {
[1706281520.735093][689286:689288] CHIP:DMG: CommandDataIB =
[1706281520.735164][689286:689288] CHIP:DMG: {
[1706281520.735228][689286:689288] CHIP:DMG: CommandPathIB =
[1706281520.735303][689286:689288] CHIP:DMG: {
[1706281520.735376][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281520.735455][689286:689288] CHIP:DMG: ClusterId = 0x31,
[1706281520.735534][689286:689288] CHIP:DMG: CommandId = 0x7,
[1706281520.735607][689286:689288] CHIP:DMG: },
[1706281520.735684][689286:689288] CHIP:DMG:
[1706281520.735750][689286:689288] CHIP:DMG: CommandFields =
[1706281520.735824][689286:689288] CHIP:DMG: {
[1706281520.735902][689286:689288] CHIP:DMG: 0x0 = 0,
[1706281520.735982][689286:689288] CHIP:DMG: 0x2 = NULL
[1706281520.736060][689286:689288] CHIP:DMG: },
[1706281520.736129][689286:689288] CHIP:DMG: },
[1706281520.736206][689286:689288] CHIP:DMG:
[1706281520.736264][689286:689288] CHIP:DMG: },
[1706281520.736331][689286:689288] CHIP:DMG:
[1706281520.736386][689286:689288] CHIP:DMG: ],
[1706281520.736458][689286:689288] CHIP:DMG:
[1706281520.736513][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281520.736569][689286:689288] CHIP:DMG: },
[1706281520.736705][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1706281520.736794][689286:689288] CHIP:CTL: Received ConnectNetwork response, networkingStatus=0
[1706281520.736866][689286:689288] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkEnable'
[1706281520.736923][689286:689288] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkEnable' -> 'FindOperational'
[1706281520.736984][689286:689288] CHIP:CTL: Performing next commissioning step 'FindOperational'
[1706281520.737034][689286:689288] CHIP:IN: Expiring all sessions for node <000000000000000A, 1>!!
[1706281520.737145][689286:689288] CHIP:CSM: FindOrEstablishSession: PeerId = [1:000000000000000A]
[1706281520.737204][689286:689288] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1706281520.737272][689286:689288] CHIP:DIS: OperationalSessionSetup[1:000000000000000A]: State change 1 --> 2
[1706281520.738022][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281520.937830][689286:689288] CHIP:DIS: Checking node lookup status after 200 ms
[1706281523.315359][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281524.326036][689286:689288] CHIP:BLE: BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:173: CHIP Error 0x00000032: Timeout
[1706281525.801835][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281525.801975][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281528.434133][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281530.920590][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281530.920951][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281533.504170][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281535.991734][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281535.992272][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281538.574554][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281541.060680][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281541.061041][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281543.644177][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281546.130707][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281546.131069][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281548.714229][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281551.200835][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281551.201001][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281551.743143][689286:689288] CHIP:DIS: Timeout waiting for mDNS resolution.
[1706281553.784982][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281556.270777][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281556.270917][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281558.854276][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281561.340802][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281561.340943][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281563.924331][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281565.739399][689286:689288] CHIP:DIS: Checking node lookup status after 45002 ms
[1706281565.739529][689286:689288] CHIP:DIS: OperationalSessionSetup[1:000000000000000A]: operational discovery failed: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:119: CHIP Error 0x00000032: Timeout
[1706281565.739587][689286:689288] CHIP:DIS: Retrying operational DNS-SD discovery. Attempts remaining: 2
[1706281565.740264][689286:689288] CHIP:CTL: Session establishment failed for <000000000000000A, 1>, error: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:119: CHIP Error 0x00000032: Timeout. Next retry expected to get a response to Sigma1 or fail within 60 seconds
[1706281565.740356][689286:689288] CHIP:CTL: Arming failsafe (120 seconds)
[1706281565.740497][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281565.740571][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281565.740839][689286:689288] CHIP:EM: <<< [E:23577i S:29128 M:61819016] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281565.741687][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281565.826066][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281565.828244][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281565.828521][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281565.828822][689286:689288] CHIP:EM: >>> [E:23577i S:29128 M:263416827] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281565.828904][689286:689288] CHIP:EM: Found matching exchange: 23577i, Delegate: 0xffffa003e138
[1706281565.828989][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281565.829151][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281565.829211][689286:689288] CHIP:DMG: {
[1706281565.829265][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281565.829323][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281565.829398][689286:689288] CHIP:DMG: [
[1706281565.829456][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281565.829533][689286:689288] CHIP:DMG: {
[1706281565.829593][689286:689288] CHIP:DMG: CommandDataIB =
[1706281565.829668][689286:689288] CHIP:DMG: {
[1706281565.829733][689286:689288] CHIP:DMG: CommandPathIB =
[1706281565.829817][689286:689288] CHIP:DMG: {
[1706281565.829893][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281565.829974][689286:689288] CHIP:DMG: ClusterId = 0x30,
[1706281565.830054][689286:689288] CHIP:DMG: CommandId = 0x1,
[1706281565.830129][689286:689288] CHIP:DMG: },
[1706281565.830207][689286:689288] CHIP:DMG:
[1706281565.830276][689286:689288] CHIP:DMG: CommandFields =
[1706281565.830355][689286:689288] CHIP:DMG: {
[1706281565.830434][689286:689288] CHIP:DMG: 0x0 = 0,
[1706281565.830519][689286:689288] CHIP:DMG: 0x1 = "" (0 chars),
[1706281565.830598][689286:689288] CHIP:DMG: },
[1706281565.830668][689286:689288] CHIP:DMG: },
[1706281565.830746][689286:689288] CHIP:DMG:
[1706281565.830805][689286:689288] CHIP:DMG: },
[1706281565.830876][689286:689288] CHIP:DMG:
[1706281565.830931][689286:689288] CHIP:DMG: ],
[1706281565.831002][689286:689288] CHIP:DMG:
[1706281565.831057][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281565.831112][689286:689288] CHIP:DMG: },
[1706281565.831252][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1706281565.831339][689286:689288] CHIP:CTL: Status of extending fail-safe for CASE retry: 0
[1706281565.831428][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281565.939873][689286:689288] CHIP:DIS: Checking node lookup status after 200 ms
[1706281568.410150][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281570.895907][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281570.896054][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281573.479378][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281575.965929][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281575.966082][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281578.549428][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281581.035923][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281581.036212][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281583.619659][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281586.107107][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281586.107418][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281588.689509][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281591.175986][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281591.176351][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281593.759525][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281596.246031][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281596.246393][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281596.744072][689286:689288] CHIP:DIS: Timeout waiting for mDNS resolution.
[1706281598.830061][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281601.317203][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281601.317512][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281603.899586][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281606.386101][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281606.386263][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281608.969655][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281610.741564][689286:689288] CHIP:DIS: Checking node lookup status after 45002 ms
[1706281610.741631][689286:689288] CHIP:DIS: OperationalSessionSetup[1:000000000000000A]: operational discovery failed: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:119: CHIP Error 0x00000032: Timeout
[1706281610.741651][689286:689288] CHIP:DIS: Retrying operational DNS-SD discovery. Attempts remaining: 1
[1706281610.741987][689286:689288] CHIP:CTL: Session establishment failed for <000000000000000A, 1>, error: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:119: CHIP Error 0x00000032: Timeout. Next retry expected to get a response to Sigma1 or fail within 60 seconds
[1706281610.742027][689286:689288] CHIP:CTL: Arming failsafe (120 seconds)
[1706281610.742099][689286:689288] CHIP:DMG: ICR moving to [AddingComm]
[1706281610.742126][689286:689288] CHIP:DMG: ICR moving to [AddedComma]
[1706281610.742256][689286:689288] CHIP:EM: <<< [E:23578i S:29128 M:61819017] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1706281610.742745][689286:689288] CHIP:DMG: ICR moving to [CommandSen]
[1706281610.870906][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281610.872354][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281610.872670][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281610.872835][689286:689288] CHIP:EM: >>> [E:23578i S:29128 M:263416828] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1706281610.872868][689286:689288] CHIP:EM: Found matching exchange: 23578i, Delegate: 0xffffa003e138
[1706281610.872902][689286:689288] CHIP:DMG: ICR moving to [ResponseRe]
[1706281610.872948][689286:689288] CHIP:DMG: InvokeResponseMessage =
[1706281610.872966][689286:689288] CHIP:DMG: {
[1706281610.872985][689286:689288] CHIP:DMG: suppressResponse = false,
[1706281610.873003][689286:689288] CHIP:DMG: InvokeResponseIBs =
[1706281610.873028][689286:689288] CHIP:DMG: [
[1706281610.873047][689286:689288] CHIP:DMG: InvokeResponseIB =
[1706281610.873074][689286:689288] CHIP:DMG: {
[1706281610.873124][689286:689288] CHIP:DMG: CommandDataIB =
[1706281610.873148][689286:689288] CHIP:DMG: {
[1706281610.873176][689286:689288] CHIP:DMG: CommandPathIB =
[1706281610.873203][689286:689288] CHIP:DMG: {
[1706281610.873227][689286:689288] CHIP:DMG: EndpointId = 0x0,
[1706281610.873254][689286:689288] CHIP:DMG: ClusterId = 0x30,
[1706281610.873278][689286:689288] CHIP:DMG: CommandId = 0x1,
[1706281610.873303][689286:689288] CHIP:DMG: },
[1706281610.873328][689286:689288] CHIP:DMG:
[1706281610.873350][689286:689288] CHIP:DMG: CommandFields =
[1706281610.873374][689286:689288] CHIP:DMG: {
[1706281610.873400][689286:689288] CHIP:DMG: 0x0 = 0,
[1706281610.873428][689286:689288] CHIP:DMG: 0x1 = "" (0 chars),
[1706281610.873454][689286:689288] CHIP:DMG: },
[1706281610.873476][689286:689288] CHIP:DMG: },
[1706281610.873501][689286:689288] CHIP:DMG:
[1706281610.873521][689286:689288] CHIP:DMG: },
[1706281610.873545][689286:689288] CHIP:DMG:
[1706281610.873563][689286:689288] CHIP:DMG: ],
[1706281610.873588][689286:689288] CHIP:DMG:
[1706281610.873606][689286:689288] CHIP:DMG: InteractionModelRevision = 11
[1706281610.873624][689286:689288] CHIP:DMG: },
[1706281610.873676][689286:689288] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1706281610.873711][689286:689288] CHIP:CTL: Status of extending fail-safe for CASE retry: 0
[1706281610.873742][689286:689288] CHIP:DMG: ICR moving to [AwaitingDe]
[1706281610.941974][689286:689288] CHIP:DIS: Checking node lookup status after 200 ms
[1706281613.454839][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281615.942358][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281615.942664][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281618.524764][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281621.011204][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281621.011346][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281623.594754][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281626.081243][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281626.081388][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281628.664723][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281631.152300][689286:689287] CHIP:DL: Indication received, conn = 0xffffa8053ff0
[1706281631.152609][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1706281633.735153][689286:689288] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1706281634.280560][689286:689286] CHIP:CTL: Shutting down the commissioner
[1706281634.280742][689286:689286] CHIP:DIS: Closing all BLE connections
[1706281634.280777][689286:689286] CHIP:IN: Clearing BLE pending packets.
[1706281634.281291][689286:689286] CHIP:BLE: Auto-closing end point's BLE connection.
[1706281634.281335][689286:689286] CHIP:DL: Closing BLE GATT connection (con 0xffffa8053ff0)
[1706281634.281427][689286:689287] CHIP:DL: BluezDisconnect peer=34:25:B4:A0:B9:82
[1706281636.124572][689286:689286] CHIP:IN: SecureSession[0xffffa0010d00]: MarkForEviction Type:1 LSID:29128
[1706281636.124621][689286:689286] CHIP:SC: SecureSession[0xffffa0010d00, LSID:29128]: State change 'kActive' --> 'kPendingEviction'
[1706281636.124672][689286:689286] CHIP:IN: SecureSession[0xffffa0010d00]: Released - Type:1 LSID:29128
[1706281636.124700][689286:689286] CHIP:CTL: Shutting down the controller
[1706281636.124723][689286:689286] CHIP:DIS: OperationalSessionSetup[1:000000000000000A]: Cancelling incomplete address resolution as device is being deleted.
[1706281636.124775][689286:689286] CHIP:CTL: Device connection failed. Error src/app/OperationalSessionSetup.cpp:464: CHIP Error 0x00000074: The operation has been cancelled
[1706281636.124797][689286:689286] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1706281636.124813][689286:689286] CHIP:FP: Forgetting fabric 0x1
[1706281636.124837][689286:689286] CHIP:TS: Pending Last Known Good Time: 2023-10-23T16:58:40
[1706281636.124893][689286:689287] CHIP:DL: Bluez disconnected
[1706281636.124915][689286:689287] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1706281636.124986][689286:689286] CHIP:TS: Previous Last Known Good Time: 2023-10-23T16:58:40
[1706281636.125004][689286:689286] CHIP:TS: Reverted Last Known Good Time to previous value
[1706281636.125043][689286:689286] CHIP:CTL: Shutting down the commissioner
[1706281636.125183][689286:689286] CHIP:CTL: Shutting down the controller
[1706281636.125202][689286:689286] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1706281636.125350][689286:689286] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1706281636.125446][689286:689286] CHIP:FP: Shutting down FabricTable
[1706281636.125468][689286:689286] CHIP:TS: Pending Last Known Good Time: 2023-10-23T16:58:40
[1706281636.125546][689286:689286] CHIP:TS: Previous Last Known Good Time: 2023-10-23T16:58:40
[1706281636.125563][689286:689286] CHIP:TS: Reverted Last Known Good Time to previous value
[1706281636.125780][689286:689286] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-elk1pw)
[1706281636.126281][689286:689286] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1706281636.126329][689286:689286] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1706281636.126349][689286:689286] CHIP:DL: Inet Layer shutdown
[1706281636.126364][689286:689286] CHIP:DL: BLE shutdown
[1706281636.127818][689286:689286] CHIP:DL: System Layer shutdown
[1706281636.128209][689286:689286] CHIP:TOO: Run command failure: ../../examples/chip-tool/commands/common/CHIPCommand.cpp:588: CHIP Error 0x00000032: Timeout
ubuntu@ubuntu:~/connectedhomeip/out/standalone$

Log from device:

00> [00:00:00.000][silabs ]Starting scheduler
00> [00:00:00.000][silabs ]==================================================
00> [00:00:00.000][silabs ]SiLabs-Sensor starting
00> [00:00:00.000][silabs ]==================================================
00> [00:00:00.000][silabs ]Init CHIP Stack
00> [00:00:00.001][info ][DL] Setting device name to : "SiLabs-Sensor"
00> [00:00:00.001][silabs ]Initializing OpenThread stack
00> [00:00:00.021][info ][DL] OpenThread started: OK
00> [00:00:00.021][info ][DL] Setting OpenThread device type to ROUTER
00> [00:00:00.021][silabs ]Starting OpenThread task
00> [00:00:00.022][info ][SVR] Initializing subscription resumption storage...
00> [00:00:00.023][info ][SVR] Server initializing...
00> [00:00:00.023][detail][FP] Initializing FabricTable from persistent storage
00> [00:00:00.024][info ][TS] Last Known Good Time: [unknown]
00> [00:00:00.024][info ][TS] Setting Last Known Good Time to firmware build time 2023-10-10T16:28:52
00> [00:00:00.025][info ][DMG] AccessControl: initializing
00> [00:00:00.026][info ][DMG] [00:00:02.406][silabs ]App Task started
00> [00:00:30.058][detail][DL] bleAdv Timeout : Start slow advertissment
00> [00:01:04.243][silabs ][INFO] SensorsCallback.UpdateTemperatureMeasurement: reportedTemperature=1900
00> [00:01:04.243][detail][DMG] Endpoint 1, Cluster 0x0000_0402 update version to f6806e2a
00> [00:01:04.243][info ][ZCL] Cluster callback: 0x0000_0402
00> [00:01:09.899][info ][DL] Connect Event for handle : 1
00> [00:01:10.002][info ][DL] evt_UNKNOWN id = 090600a0
00> [00:01:11.464][info ][DL] Char Write Req, char : 23
00> [00:01:11.465][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 9)
00> [00:01:11.465][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:11.465][info ][BLE] local and remote recv window sizes = 5
00> [00:01:11.465][info ][BLE] selected BTP version 4
00> [00:01:11.465][info ][BLE] using BTP fragment sizes rx 244 / tx 244.
00> [00:01:11.562][info ][DL] HandleTXcharCCCDWrite - Config Flags value : 2
00> [00:01:11.562][info ][DL] CHIPoBLE subscribe received
00> [00:01:11.563][info ][DL] _OnPlatformEvent kCHIPoBLESubscribe
00> [00:01:11.563][detail][IN] BLE EndPoint 0x2000eb20 Connection Complete
00> [00:01:11.563][info ][DL] _OnPlatformEvent default: event->Type = 32775
00> [00:01:11.660][info ][DL] Tx Confirmation received
00> [00:01:11.660][info ][DL] stop soft timer
00> [00:01:11.660][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:11.661][info ][DL] Char Write Req, char : 23
00> [00:01:11.661][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 73)
00> [00:01:11.662][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:11.662][info ][EM] >>> [E:23564r S:0 M:65966330] (U) Msg RX from 0:DD2B23349F2E6C22 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
00> [00:01:11.662][detail][EM] Handling via exchange: 23564r, Delegate: 0x2000e188
00> [00:01:11.662][detail][SC] Received PBKDF param request
00> [00:01:11.663][detail][SC] Peer assigned session ID 29128
00> [00:01:11.663][detail][SC] Including MRP parameters in PBKDF param response
00> [00:01:11.664][info ][EM] <<< [E:23564r S:0 M:266217851] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
00> [00:01:11.665][detail][SC] Sent PBKDF param response
00> [00:01:11.665][info ][SVR] Commissioning session establishment step started
00> [00:01:11.757][info ][DL] Tx Confirmation received
00> [00:01:11.757][info ][DL] stop soft timer
00> [00:01:11.757][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:11.758][info ][DL] Char Write Req, char : 23
00> [00:01:11.758][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 97)
00> [00:01:11.759][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:11.759][info ][EM] >>> [E:23564r S:0 M:65966331] (U) Msg RX from 0:DD2B23349F2E6C22 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
00> [00:01:11.759][detail][EM] Found matching exchange: 23564r, Delegate: 0x2000e188
00> [00:01:11.759][detail][SC] Received spake2p msg1
00> [00:01:11.839][info ][EM] <<< [E:23564r S:0 M:266217852] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2)
00> [00:01:11.840][detail][SC] Sent spake2p msg2
00> [00:01:11.903][info ][DL] Tx Confirmation received
00> [00:01:11.903][info ][DL] stop soft timer
00> [00:01:11.904][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:11.905][info ][DL] Char Write Req, char : 23
00> [00:01:11.905][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 64)
00> [00:01:11.905][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:11.905][info ][EM] >>> [E:23564r S:0 M:65966332] (U) Msg RX from 0:DD2B23349F2E6C22 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
00> [00:01:11.906][detail][EM] Found matching exchange: 23564r, Delegate: 0x2000e188
00> [00:01:11.906][detail][SC] Received spake2p msg3
00> [00:01:11.906][detail][SC] Sending status report. Protocol code 0, exchange 23564
00> [00:01:11.907][info ][EM] <<< [E:23564r S:0 M:266217853] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport)
00> [00:01:11.910][info ][SC] SecureSession[0x2000baf0, LSID:62583]: State change 'kEstablishing' --> 'kActive'
00> [00:01:11.911][detail][IN] SecureSession[0x2000baf0]: Activa[00:01:12.000][info ][DL] Tx Confirmation received
00> [00:01:12.000][info ][DL] stop soft timer
00> [00:01:12.001][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:12.002][info ][DL] Char Write Req, char : 23
00> [00:01:12.002][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 136)
00> [00:01:12.003][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:12.003][info ][EM] >>> [E:23565r S:62583 M:61819004] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
00> [00:01:12.004][detail][EM] Handling via exchange: 23565r, Delegate: 0x20008bac
00> [00:01:12.004][detail][IM] Received Read request
00> [00:01:12.006][detail][DMG] IM RH moving to [CanStartReporting]
00> [00:01:12.006][detail][DMG] Building Reports for ReadHandler with LastReportGeneration = lu DirtyGeneration = lu
00> [00:01:12.007][detail][DMG] <RE:Run> Cluster 31, Attribute 3 is dirty
00> [00:01:12.007][detail][DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1)
00> [00:01:12.007][detail][DMG] <RE:Run> Cluster 28, Attribute 4 is dirty
00> [00:01:12.007][detail][DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId[00:01:12.011][info ][EM] <<< [E:23565r S:62583 M:263416815] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData)
00> [00:01:12.012][detail][DMG] <RE> OnReportConfirm: NumReports = 0
00> [00:01:12.012][detail][DMG] <RE> ReportsInFlight = 0 with readHandler 0, RE has no more messages
00> [00:01:12.012][detail][DMG] IM RH moving to [AwaitingDestruction]
00> [00:01:12.021][detail][DMG] All ReadHandler-s are clean, clear GlobalDirtySet
00> [00:01:12.098][info ][DL] Tx Confirmation received
00> [00:01:12.098][info ][DL] stop soft timer
00> [00:01:12.099][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:12.196][info ][DL] Tx Confirmation received
00> [00:01:12.196][info ][DL] stop soft timer
00> [00:01:12.196][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:12.197][info ][DL] Char Write Req, char : 23
00> [00:01:12.197][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 70)
00> [00:01:12.198][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:12.198][info ][EM] >>> [E:23566r S:62583 M:61819005] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:12.199][detail][EM] Handling via exchange: 23566r, Delegate: 0x20008bac
00> [00:01:12.199][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
00> [00:01:12.199][info ][FS] GeneralCommissioning: Received ArmFailSafe (60s)
00> [00:01:12.200][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 95f7e87b
00> [00:01:12.200][info ][ZCL] Cluster callback: 0x0000_0030
00> [00:01:12.200][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:12.200][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:12.200][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:12.200][detail][DMG] Decreasing [00:01:12.342][info ][DL] Tx Confirmation received
00> [00:01:12.342][info ][DL] stop soft timer
00> [00:01:12.342][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:12.343][info ][DL] Char Write Req, char : 23
00> [00:01:12.343][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 75)
00> [00:01:12.343][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:12.344][info ][EM] >>> [E:23567r S:62583 M:61819006] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:12.345][detail][EM] Handling via exchange: 23567r, Delegate: 0x20008bac
00> [00:01:12.345][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002
00> [00:01:12.346][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 95f7e87c
00> [00:01:12.346][info ][ZCL] Cluster callback: 0x0000_0030
00> [00:01:12.346][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:12.346][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:12.346][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:12.346][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
00> [00:01:12.347][info ][EM] <[00:01:12.439][info ][DL] Tx Confirmation received
00> [00:01:12.440][info ][DL] stop soft timer
00> [00:01:12.440][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:12.441][info ][DL] Char Write Req, char : 23
00> [00:01:12.441][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 67)
00> [00:01:12.441][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:12.442][info ][EM] >>> [E:23568r S:62583 M:61819007] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:12.442][detail][EM] Handling via exchange: 23568r, Delegate: 0x20008bac
00> [00:01:12.443][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
00> [00:01:12.443][info ][ZCL] OpCreds: Certificate Chain request received for PAI
00> [00:01:12.443][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:12.443][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:12.444][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:12.444][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
00> [00:01:12.445][info ][EM] <<< [E:23568r S:62583 M:263416818] (S) Msg TX to 0:FFFFFFFB00000000[00:01:12.538][info ][DL] Tx Confirmation received
00> [00:01:12.538][info ][DL] stop soft timer
00> [00:01:12.538][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:12.634][info ][DL] Tx Confirmation received
00> [00:01:12.634][info ][DL] stop soft timer
00> [00:01:12.635][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:12.732][info ][DL] Tx Confirmation received
00> [00:01:12.732][info ][DL] stop soft timer
00> [00:01:12.732][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:12.733][info ][DL] Char Write Req, char : 23
00> [00:01:12.733][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 67)
00> [00:01:12.734][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:12.734][info ][EM] >>> [E:23569r S:62583 M:61819008] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:12.735][detail][EM] Handling via exchange: 23569r, Delegate: 0x20008bac
00> [00:01:12.735][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002
00> [00:01:12.735][info ][ZCL] OpCreds: Certificate Chain request received for DAC
00> [00:01:12.736][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:12.736][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:12.736][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:12.736][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
00> [00:01:12.737][info ][E[00:01:12.830][info ][DL] Tx Confirmation received
00> [00:01:12.830][info ][DL] stop soft timer
00> [00:01:12.830][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:12.927][info ][DL] Tx Confirmation received
00> [00:01:12.927][info ][DL] stop soft timer
00> [00:01:12.927][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:13.025][info ][DL] Tx Confirmation received
00> [00:01:13.025][info ][DL] stop soft timer
00> [00:01:13.025][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:13.026][info ][DL] Char Write Req, char : 23
00> [00:01:13.026][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 99)
00> [00:01:13.027][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:13.027][info ][EM] >>> [E:23570r S:62583 M:61819009] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:13.028][detail][EM] Handling via exchange: 23570r, Delegate: 0x20008bac
00> [00:01:13.028][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000
00> [00:01:13.028][info ][ZCL] OpCreds: Received an AttestationRequest command
00> [00:01:13.035][info ][ZCL] OpCreds: AttestationRequest successful.
00> [00:01:13.035][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:13.035][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:13.035][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:13.035][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
00> [00:01:13.036][info ][EM] <<< [E:23570r S:62583 M:263416820] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
00> [00:01:13.037][detail][DMG] Command handler moving to [CommandSen]
00> [00:01:13.037][detail][DMG] Command handler moving to [AwaitingDe]
00> [00:01:13.123][info ][DL] Tx Confirmation received
00> [00:01:13.123][info ][DL] stop soft timer
00> [00:01:13.123][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:13.219][info ][DL] Tx Confirmation received
00> [00:01:13.220][info ][DL] stop soft timer
00> [00:01:13.220][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:13.317][info ][DL] Tx Confirmation received
00> [00:01:13.317][info ][DL] stop soft timer
00> [00:01:13.317][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:13.319][info ][DL] Char Write Req, char : 23
00> [00:01:13.319][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 99)
00> [00:01:13.319][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:13.320][info ][EM] >>> [E:23571r S:62583 M:61819010] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:13.320][detail][EM] Handling via exchange: 23571r, Delegate: 0x20008bac
00> [00:01:13.321][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004
00> [00:01:13.321][info ][ZCL] OpCreds: Received a CSRRequest command
00> [00:01:13.321][detail][ZCL] OpCreds: Finding fabric with fabricIndex 0x0
00> [00:01:13.334][info ][ZCL] OpCreds: AllocatePendingOperationalKey succeeded
00> [00:01:13.340][info ][ZCL] OpCreds: CSRRequest successful.
00> [00:01:13.340][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:13.340][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:13.340][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:13.340][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
00> [00:01:13.341][info ][EM] <<< [E:23571r S:62583 M:263416821] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
00> [00:01:13.342][detail][DMG] Command handler moving to [CommandSen]
00> [00:01:13.342][detail][DMG] Command handler moving to [AwaitingDe]
00> [00:01:13.415][info ][DL] Tx Confirmation received
00> [00:01:13.415][info ][DL] stop soft timer
00> [00:01:13.415][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:13.512][info ][DL] Tx Confirmation received
00> [00:01:13.512][info ][DL] stop soft timer
00> [00:01:13.512][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:13.515][info ][DL] Char Write Req, char : 23
00> [00:01:13.515][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 244)
00> [00:01:13.515][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:13.659][info ][DL] Char Write Req, char : 23
00> [00:01:13.659][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 56)
00> [00:01:13.660][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:13.660][info ][EM] >>> [E:23572r S:62583 M:61819011] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:13.661][detail][EM] Handling via exchange: 23572r, Delegate: 0x20008bac
00> [00:01:13.661][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B
00> [00:01:13.661][info ][ZCL] OpCreds: Received an AddTrustedRootCertificate command
00> [00:01:13.668][info ][ZCL] OpCreds: AddTrustedRootCertificate successful.
00> [00:01:13.668][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:13.668][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:13.668][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:13.669][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
00> [00:01:13.669][info ][EM] <<< [E:23572r S:62583 M:263416822] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
00> [00:01:13.670][detail][DMG] Command handler moving to [CommandSen]
00> [00:01:13.670][detail][DMG] Command handler moving to [AwaitingDe]
00> [00:01:13.755][info ][DL] Tx Confirmation received
00> [00:01:13.755][info ][DL] stop soft timer
00> [00:01:13.756][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:13.758][info ][DL] Char Write Req, char : 23
00> [00:01:13.758][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 244)
00> [00:01:13.759][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:13.856][info ][DL] Char Write Req, char : 23
00> [00:01:13.856][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 244)
00> [00:01:13.856][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:14.000][info ][DL] Char Write Req, char : 23
00> [00:01:14.000][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 87)
00> [00:01:14.000][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:14.001][info ][EM] >>> [E:23573r S:62583 M:61819012] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:14.002][detail][EM] Handling via exchange: 23573r, Delegate: 0x20008bac
00> [00:01:14.002][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006
00> [00:01:14.002][info ][ZCL] OpCreds: Received an AddNOC command
00> [00:01:14.004][info ][FP] Validating NOC chain
00> [00:01:14.021][info ][FP] NOC chain validation successful
00> [00:01:14.021][info ][FP] Added new fabric at index: 0x1
00> [00:01:14.021][info ][FP] Assigned compressed fabric ID: 0xBA8284A0AC0FAA35, node ID: 0x000000000000000A
00> [00:01:14.022][info ][TS] Last Known Good Time: 2023-10-10T16:28:52
00> [00:01:14.022][info ][TS] New proposed Last Known Good Time: 2021-01-01T00:00:00
00> [00:01:14.022][info ][TS] Retaining current Last Known Good Time
00> [00:01:14.022][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 7604300f
00> [00:01:14.022][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 76043010
00> [00:01:14.033][detail][EVL] LogEvent event number: 0x0000000000000002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x000000000001211A
00> [00:01:14.034][info ][ZCL] OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669
00> [00:01:14.034][detail][DL] Using Thread extended MAC for hostname.
00> [00:01:14.034][info ][DIS] Advertise operational node BA8284A0AC0FAA35-000000000000000A
00> [00:01:14.034][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 76043011
00> [00:01:14.034][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 76043012
00> [00:01:14.035][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:14.035][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:14.035][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:14.035][info ][ZCL] OpCreds: successfully created fabric index 0x1 via AddNOC
00> [00:01:14.035][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
00> [00:01:14.036][info [00:01:14.097][info ][DL] Tx Confirmation received
00> [00:01:14.097][info ][DL] stop soft timer
00> [00:01:14.097][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:14.099][info ][DL] Char Write Req, char : 23
00> [00:01:14.099][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 175)
00> [00:01:14.099][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:14.100][info ][EM] >>> [E:23574r S:62583 M:61819013] (S) Msg RX from 1:FFFFFFFB00000000 [AA35] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:14.101][detail][EM] Handling via exchange: 23574r, Delegate: 0x20008bac
00> [00:01:14.101][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003
00> [00:01:14.102][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:14.102][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:14.103][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:14.103][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 95f7e87d
00> [00:01:14.103][info ][ZCL] Cluster callback: 0x0000_0030
00> [00:01:14.103][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
00> [00:01:14.104][info ][EM] [00:01:14.195][info ][DL] Tx Confirmation received
00> [00:01:14.195][info ][DL] stop soft timer
00> [00:01:14.195][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:14.196][info ][DL] Char Write Req, char : 23
00> [00:01:14.196][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 70)
00> [00:01:14.196][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:14.197][info ][EM] >>> [E:23575r S:62583 M:61819014] (S) Msg RX from 1:FFFFFFFB00000000 [AA35] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:14.197][detail][EM] Handling via exchange: 23575r, Delegate: 0x20008bac
00> [00:01:14.198][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
00> [00:01:14.198][info ][FS] GeneralCommissioning: Received ArmFailSafe (73s)
00> [00:01:14.198][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 95f7e87e
00> [00:01:14.199][info ][ZCL] Cluster callback: 0x0000_0030
00> [00:01:14.199][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:14.199][detail][DMG] Command handler moving to [AddingComm]
00> [00:01:14.199][detail][DMG] Command handler moving to [AddedComma]
00> [00:01:14.199][detail][DMG] Decreasing [00:01:14.291][info ][DL] Tx Confirmation received
00> [00:01:14.292][info ][DL] stop soft timer
00> [00:01:14.292][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:14.293][info ][DL] Char Write Req, char : 23
00> [00:01:14.293][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 78)
00> [00:01:14.293][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:14.294][info ][EM] >>> [E:23576r S:62583 M:61819015] (S) Msg RX from 1:FFFFFFFB00000000 [AA35] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:01:14.294][detail][EM] Handling via exchange: 23576r, Delegate: 0x20008bac
00> [00:01:14.295][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006
00> [00:01:14.317][detail][DMG] Decreasing reference count for CommandHandler, remaining 1
00> [00:01:14.317][info ][DL] _OnPlatformEvent default: event->Type = 32772
00> [00:01:14.319][info ][DL] _OnPlatformEvent default: event->Type = 32777
00> [00:01:14.319][detail][DL] OpenThread State Changed (Flags: 0x111fd11d)
00> [00:01:14.319][detail][DL] Device Role: DETACHED
00> [00:01:14.319][detail][DL] Network Name: OpenThreadDemo
00> [00:01:14.319][detail][DL] PAN Id: 0x1234
00> [00:01:14.319][detail][DL] Extended PAN Id: 0x1111111122222222
00> [00:01:14.320][detail][DL] Channel: 15
00> [00:01:14.320][detail][DL] Mesh Prefix: fd47:c866:a2d5:bb8d:0:0:0:0/64
00> [00:01:14.320][detail][DL] Thread Unicast Addresses:
00> [00:01:14.320][detail][DL] fd47:c866:a2d5:bb8d:6040:aed7:95eb:ec86/64 valid
00> [00:01:14.320][detail][DL] fe80:0:0:0:7c63:33c:b39:4a81/64 valid preferred
00> [00:01:15.774][info ][DL] SRP Client was started, detected server: fd47:c866:a2d5:bb8d:df49:b731:3ec7:717c
00> [00:01:15.775][info ][DL] _OnPlatformEvent default: event->Type = 32777
00> [00:01:15.775][detail][DL] OpenThread State Changed (Flags: 0x200012a4)
00> [00:01:15.775][detail][DL] Device Role: CHILD
00> [00:01:15.775][detail][DL] Partition Id: 0x39FB9696
00> [00:01:15.778][info ][DL] _OnPlatformEvent default: event->Type = 32777
00> [00:01:15.778][detail][DL] Thread Attached updating Multicast address
00> [00:01:15.778][info ][SVR] Joining Multicast groups
00> [00:01:15.779][detail][DL] OpenThread State Changed (Flags: 0x00000001)
00> [00:01:15.779][detail][DL] Thread Unicast Addresses:
00> [00:01:15.779][detail][DL] fd11:22:0:0:171b:1417:af40:ef39/64 valid preferred
00> [00:01:15.780][detail][DL] fd47:c866:a2d5:bb8d:0:ff:fe00:6401/64 valid rloc
00> [00:01:15.780][detail][DL] fd47:c866:a2d5:bb8d:6040:aed7:95eb:ec86/64 valid
00> [00:01:15.780][detail][DL] fe80:0:0:0:7c63:33c:b39:4a81/64 valid preferred
00> [00:01:15.783][info ][DL] _OnPlatformEvent default: event->Type = 32769
00> [00:01:15.783][silabs ]Scheduling OTA Requestor initialization
00> [00:01:15.783][detail][DMG] Command handler moving to [ Preparing]
00> [00:01:15.783][detail][DMG] Command han[00:01:15.785][info ][EM] <<< [E:23576r S:62583 M:263416826] (S) Msg TX to 1:FFFFFFFB00000000 [AA35] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
00> [00:01:15.785][detail][DMG] Command handler moving to [CommandSen]
00> [00:01:15.786][detail][DMG] Command handler moving to [AwaitingDe]
00> [00:01:15.786][info ][DL] _OnPlatformEvent default: event->Type = 32783
00> [00:01:15.786][detail][DL] Using Thread extended MAC for hostname.
00> [00:[00:01:15.852][info ][DL] Tx Confirmation received
00> [00:01:15.852][info ][DL] stop soft timer
00> [00:01:15.853][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:16.522][detail][DL] SRP update succeeded
00> [00:01:16.522][info ][DL] _OnPlatformEvent default: event->Type = 32784
00> [00:01:16.522][info ][SVR] Server initialization complete
00> [00:01:16.522][info ][DIS] Updating services using commissioning mode 0
00> [00:01:16.522][detail][DL] Using Thread extended MAC for hostname.
00> [00:01:16.522][info ][DIS] Advertise operational node BA8284A0AC0FAA35-000000000000000A
00> [00:01:16.523][info ][DL] advertising srp service: BA8284A0AC0FAA35-000000000000000A._matter._tcp
00> [00:01:16.523][info ][DL] _OnPlatformEvent default: event->Type = 32788
00> [00:01:16.532][info ][IM] No subscriptions to resume
00> [00:01:17.380][detail][DL] SRP update succeeded
00> [00:01:18.338][info ][DL] Char Write Req, char : 23
00> [00:01:18.339][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:01:18.339][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:18.785][info ][SWU] Stopping the watchdog timer
00> [00:01:18.785][info ][SWU] Starting the periodic query timer, timeout: 86400 seconds
00> [00:01:18.786][detail][DMG] Endpoint 0, Cluster 0x0000_002A update version to 689f7c79
00> [00:01:18.786][info ][ZCL] Cluster callback: 0x0000_002A
00> [00:01:18.786][detail][DMG] Endpoint 0, Cluster 0x0000_002A update version to 689f7c7a
00> [00:01:18.786][info ][ZCL] Cluster callback: 0x0000_002A
00> [00:01:20.922][info ][DL] Tx Confirmation received
00> [00:01:20.922][info ][DL] stop soft timer
00> [00:01:20.923][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:23.458][info ][DL] Char Write Req, char : 23
00> [00:01:23.458][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:01:23.458][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:26.041][info ][DL] Tx Confirmation received
00> [00:01:26.041][info ][DL] stop soft timer
00> [00:01:26.041][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:28.528][info ][DL] Char Write Req, char : 23
00> [00:01:28.528][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:01:28.529][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:31.112][info ][DL] Tx Confirmation received
00> [00:01:31.112][info ][DL] stop soft timer
00> [00:01:31.112][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:33.598][info ][DL] Char Write Req, char : 23
00> [00:01:33.598][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:01:33.598][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:36.181][info ][DL] Tx Confirmation received
00> [00:01:36.181][info ][DL] stop soft timer
00> [00:01:36.182][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:38.667][info ][DL] Char Write Req, char : 23
00> [00:01:38.668][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:01:38.668][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:41.251][info ][DL] Tx Confirmation received
00> [00:01:41.251][info ][DL] stop soft timer
00> [00:01:41.251][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:43.738][info ][DL] Char Write Req, char : 23
00> [00:01:43.738][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:01:43.739][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:46.322][info ][DL] Tx Confirmation received
00> [00:01:46.322][info ][DL] stop soft timer
00> [00:01:46.322][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:48.808][info ][DL] Char Write Req, char : 23
00> [00:01:48.808][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:01:48.808][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:51.392][info ][DL] Tx Confirmation received
00> [00:01:51.392][info ][DL] stop soft timer
00> [00:01:51.392][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:53.878][info ][DL] Char Write Req, char : 23
00> [00:01:53.878][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:01:53.878][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:01:56.461][info ][DL] Tx Confirmation received
00> [00:01:56.462][info ][DL] stop soft timer
00> [00:01:56.462][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:01:58.948][info ][DL] Char Write Req, char : 23
00> [00:01:58.949][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:01:58.949][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:00.850][info ][DL] Char Write Req, char : 23
00> [00:02:00.850][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 69)
00> [00:02:00.850][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:00.851][info ][EM] >>> [E:23577r S:62583 M:61819016] (S) Msg RX from 1:FFFFFFFB00000000 [AA35] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:02:00.851][detail][EM] Handling via exchange: 23577r, Delegate: 0x20008bac
00> [00:02:00.852][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
00> [00:02:00.852][info ][FS] GeneralCommissioning: Received ArmFailSafe (120s)
00> [00:02:00.852][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 95f7e880
00> [00:02:00.853][info ][ZCL] Cluster callback: 0x0000_0030
00> [00:02:00.853][detail][DMG] Command handler moving to [ Preparing]
00> [00:02:00.853][detail][DMG] Command handler moving to [AddingComm]
00> [00:02:00.853][detail][DMG] Command handler moving to [AddedComma]
00> [00:02:00.853][detail][DMG] Decreasing[00:02:00.854][info ][EM] <<< [E:23577r S:62583 M:263416827] (S) Msg TX to 1:FFFFFFFB00000000 [AA35] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse)
00> [00:02:00.855][detail][DMG] Command handler moving to [CommandSen]
00> [00:02:[00:02:00.947][info ][DL] Tx Confirmation received
00> [00:02:00.947][info ][DL] stop soft timer
00> [00:02:00.948][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:03.433][info ][DL] Char Write Req, char : 23
00> [00:02:03.433][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:03.434][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:04.252][silabs ][INFO] SensorsCallback.UpdateTemperatureMeasurement: reportedTemperature=1887
00> [00:02:04.252][detail][DMG] Endpoint 1, Cluster 0x0000_0402 update version to f6806e2b
00> [00:02:04.252][info ][ZCL] Cluster callback: 0x0000_0402
00> [00:02:06.017][info ][DL] Tx Confirmation received
00> [00:02:06.017][info ][DL] stop soft timer
00> [00:02:06.017][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:08.503][info ][DL] Char Write Req, char : 23
00> [00:02:08.503][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:08.503][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:11.087][info ][DL] Tx Confirmation received
00> [00:02:11.087][info ][DL] stop soft timer
00> [00:02:11.087][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:13.574][info ][DL] Char Write Req, char : 23
00> [00:02:13.574][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:13.574][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:16.157][info ][DL] Tx Confirmation received
00> [00:02:16.158][info ][DL] stop soft timer
00> [00:02:16.158][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:18.644][info ][DL] Char Write Req, char : 23
00> [00:02:18.644][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:18.644][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:19.410][info ][DL] _OnPlatformEvent default: event->Type = 32777
00> [00:02:19.410][detail][DL] OpenThread State Changed (Flags: 0x00000064)
00> [00:02:19.410][detail][DL] Device Role: ROUTER
00> [00:02:21.227][info ][DL] Tx Confirmation received
00> [00:02:21.227][info ][DL] stop soft timer
00> [00:02:21.228][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:23.713][info ][DL] Char Write Req, char : 23
00> [00:02:23.713][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:23.714][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:26.297][info ][DL] Tx Confirmation received
00> [00:02:26.297][info ][DL] stop soft timer
00> [00:02:26.297][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:28.784][info ][DL] Char Write Req, char : 23
00> [00:02:28.784][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:28.784][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:31.368][info ][DL] Tx Confirmation received
00> [00:02:31.368][info ][DL] stop soft timer
00> [00:02:31.368][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:33.854][info ][DL] Char Write Req, char : 23
00> [00:02:33.854][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:33.854][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:36.438][info ][DL] Tx Confirmation received
00> [00:02:36.438][info ][DL] stop soft timer
00> [00:02:36.438][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:38.924][info ][DL] Char Write Req, char : 23
00> [00:02:38.924][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:38.924][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:41.507][info ][DL] Tx Confirmation received
00> [00:02:41.507][info ][DL] stop soft timer
00> [00:02:41.508][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:43.994][info ][DL] Char Write Req, char : 23
00> [00:02:43.995][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:43.995][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:45.847][info ][DL] Char Write Req, char : 23
00> [00:02:45.847][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 69)
00> [00:02:45.847][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:45.848][info ][EM] >>> [E:23578r S:62583 M:61819017] (S) Msg RX from 1:FFFFFFFB00000000 [AA35] --- Type 0001:08 (IM:InvokeCommandRequest)
00> [00:02:45.848][detail][EM] Handling via exchange: 23578r, Delegate: 0x20008bac
00> [00:02:45.849][detail][DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000
00> [00:02:45.849][info ][FS] GeneralCommissioning: Received ArmFailSafe (120s)
00> [00:02:45.849][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 95f7e881
00> [00:02:45.849][info ][ZCL] Cluster callback: 0x0000_0030
00> [00:02:45.850][detail][DMG] Command handler moving to [ Preparing]
00> [00:02:45.850][detail][DMG] Command handler moving to [AddingComm]
00> [00:02:45.850][detail][DMG] Command handler moving to [AddedComma]
00> [00:02:45.850][detail][DMG] Decreasing reference count for CommandHandler, remaining 0
00> [00:02:45.851][info ][EM] <<< [E:23578r S:62583 M:263416828] (S) Msg TX to 1:FFFFFFFB00000000 [AA35] [BLE] --[00:02:45.993][info ][DL] Tx Confirmation received
00> [00:02:45.993][info ][DL] stop soft timer
00> [00:02:45.993][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:48.479][info ][DL] Char Write Req, char : 23
00> [00:02:48.479][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:48.479][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:51.063][info ][DL] Tx Confirmation received
00> [00:02:51.063][info ][DL] stop soft timer
00> [00:02:51.063][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:53.549][info ][DL] Char Write Req, char : 23
00> [00:02:53.549][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:53.549][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:02:56.133][info ][DL] Tx Confirmation received
00> [00:02:56.133][info ][DL] stop soft timer
00> [00:02:56.133][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:02:58.620][info ][DL] Char Write Req, char : 23
00> [00:02:58.620][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:02:58.620][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:03:01.203][info ][DL] Tx Confirmation received
00> [00:03:01.203][info ][DL] stop soft timer
00> [00:03:01.204][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:03:03.689][info ][DL] Char Write Req, char : 23
00> [00:03:03.690][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:03:03.690][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:03:04.252][silabs ][INFO] SensorsCallback.UpdateTemperatureMeasurement: reportedTemperature=1875
00> [00:03:04.252][detail][DMG] Endpoint 1, Cluster 0x0000_0402 update version to f6806e2c
00> [00:03:04.252][info ][ZCL] Cluster callback: 0x0000_0402
00> [00:03:06.273][info ][DL] Tx Confirmation received
00> [00:03:06.273][info ][DL] stop soft timer
00> [00:03:06.274][info ][DL] _OnPlatformEvent kCHIPoBLEIndicateConfirm
00> [00:03:08.759][info ][DL] Char Write Req, char : 23
00> [00:03:08.759][detail][DL] Write request/command received for CHIPoBLE RX characteristic (con 1, len 3)
00> [00:03:08.760][info ][DL] _OnPlatformEvent kCHIPoBLEWriteReceived
00> [00:03:09.393][info ][DL] HandleTXcharCCCDWrite - Config Flags value : 0
00> [00:03:09.393][info ][DL] CHIPoBLE unsubscribe received
00> [00:03:09.393][info ][DL] _OnPlatformEvent kCHIPoBLEUnsubscribe
00> [00:03:09.394][detail][IN] Clearing BLE pending packets.
00> [00:03:09.394][info ][BLE] Releasing end point's BLE connection back to application.
00> [00:03:11.197][info ][DL] Disconnect Event for handle : 1
00> [00:03:11.197][info ][DL] BLE GATT connection closed (con 1, reason 4115)
00> [00:03:11.198][info ][DL] _OnPlatformEvent kCHIPoBLEConnectionError
00> [00:04:02.527][silabs ][ERROR] DS2480B::ReadSerialByte: ReadBytes bytesRead=2.
00> [00:04:02.527][silabs ][ERROR] OneWire::Reset: Failed.
00> [00:04:02.527][silabs ][ERROR] DS18B20::TemperatureConversion: Call to OneWire::Reset #1 failed.
00> [00:04:02.527][silabs ][ERROR] DS18B20::MeasureTemperature: Call to TemperatureConversion failed.
00> [00:04:45.850][info ][FS] Fail-safe timer expired
00> [00:04:45.850][info ][DL] _OnPlatformEvent default: event->Type = 32782
00> [00:04:45.850][error ][SVR] Failsafe timer expired
00> [00:04:45.850][detail][IN] SecureSession[0x2000baf0]: MarkForEviction Type:1 LSID:62583
00> [00:04:45.850][info ][SC] SecureSession[0x2000baf0, LSID:62583]: State change 'kActive' --> 'kPendingEviction'
00> [00:04:45.850][detail][IN] SecureSession[0x2000baf0]: Released - Type:1 LSID:62583
00> [00:04:45.850][error ][SVR] Commissioning failed (attempt 1): 32
00> [00:04:45.851][detail][IN] SecureSession[0x2000baf0]: Allocated Type:1 LSID:62585
00> [00:04:45.851][detail][SC] Assigned local session key ID 62585
00> [00:04:45.852][detail][SC] Waiting for PBKDF param request
00> [00:04:45.852][info ][DIS] Updating services using commissioning mode 1
00> [00:04:45.852][detail][DL] Using Thread extended MAC for hostname.
00> [00:04:45.852][info ][DIS] Advertise operational node BA8284A0AC0FAA35-000000000000000A
00> [00:04:45.852][detail][DL] Using Thread extended MAC for hostname.
00> [00:04:45.853][info ][DIS] Advertise[00:04:45.861][detail][DMG] Endpoint 0, Cluster 0x0000_003E update version to 76043014
00> [00:04:45.891][info ][TS] Pending Last Known Good Time: 2023-10-10T16:28:52
00> [00:04:45.892][info ][TS] Previous Last Known Good Time: 2023-10-10T16:28:52
00> [00:04:45.892][info ][TS] Reverted Last Known Good Time to previous value
00> [00:04:45.892][detail][EVL] LogEvent event number: 0x0000000000000004 priority: 1, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x2 Sys timestamp: 0x0000000000045CAD
00> [00:04:45.892][detail][DMG] All ReadHandler-s are clean, clear GlobalDirtySet
00> [00:04:45.893][error ][FP] Warning: metadata not found during delete of fabric 0x1
00> [00:04:45.894][error ][ZCL] OpCreds: failed to delete fabric at index 1: d8
00> [00:04:45.894][detail][DMG] Endpoint 0, Cluster 0x0000_0030 update version to 95f7e882
00> [00:04:45.894][info ][ZCL] Cluster callback: 0x0000_0030
00> [00:04:45.895][detail][ZCL] Failsafe timeout, tell platform driver to revert network credentials.
00> [00:04:45.895][info ][NP] Reverting Thread operational dataset
00> [00:04:45.900][info ][FS] Fail-safe cleanly disarmed
00> [00:04:45.900][detail][DL] Start BLE advertissement
00> [00:04:45.903][info ][DL] _OnPlatformEvent default: event->Type = 32772
00> [00:04:45.903][info ][DL] _OnPlatformEvent default: event->Type = 32777
00> [00:04:45.903][detail][DL] OpenThread State Changed (Flags: 0x11002046)
00> [00:04:45.903][detail][DL] Device Role: DISABLED
00> [00:04:45.903][detail][DL] Thread Unicast Addresses:
00> [00:04:45.904][detail][DL] fd11:22:0:0:171b:1417:af40:ef39/64 valid preferred
00> [00:04:45.904][info ][DL] _OnPlatformEvent default: event->Type = 32769
00> [00:05:04.243][silabs ][INFO] SensorsCallback.UpdateTemperatureMeasurement: reportedTemperature=2018
00> [00:05:04.243][detail][DMG] Endpoint 1, Cluster 0x0000_0402 update version to f6806e2d
00> [00:05:04.243][info ][ZCL] Cluster callback: 0x0000_0402
00> [00:05:15.903][detail][DL] bleAdv Timeout : Start slow advertissment
00> [00:06:04.252][silabs ][INFO] SensorsCallback.UpdateTemperatureMeasurement: reportedTemperature=2062
00> [00:06:04.252][detail][DMG] Endpoint 1, Cluster 0x0000_0402 update version to f6806e2e
00> [00:06:04.252][info ][ZCL] Cluster callback: 0x0000_0402

[Marte Myrvold]

When posting long logs, please use the Insert->Code functionality to help us keep devzone tidy.

This time I edited your comment to fix it, but remember to do this yourself in the future. Thanks!

I will look through your logs and get back to you.

[Marte Myrvold]

I see from your logs that you are not running any of our Matter samples. Are you getting the same issue with our Matter samples as well? You can find a list of samples here: Matter samples.

Which board are you using?

[Izvor]

You don't seem to understand the issue. The issue is not related to the board running the Matter End Device, but it's related to the OpenThread Border Router running in a Docker container and the RCP. The RCP board is the nRF52840 USB Dongle.

Why don't you try to re-produce in your environement?

[Marte Myrvold]

I tried to reproduce the issue last week using the nRF52840 DK and our light bulb sample, but I did not get any issues.

The commissioning fails during operational discovery, which is the step where the chip-tool uses DNS-SD to discover the device and its IP address. This issue could occur due to network issues or incorrect configuration of the Thread network, but I cannot say for certain that it is not due to the device when you are testing with a third party device and/or code.

For the RCP, did you use the co-processor sample in the nRF Connect SDK and build it with overlays for USB? I have attached the hex file I used for the RCP when testing. You can use the nRF Connect Programmer app to program the dongle.

Are you running chip-tool on the same computer as the docker OTBR, or on a separate computer?

Please share the output you get when checking the status of the OTBR and Thread node, i.e. steps 10 and 11 in the guide for running OTBR using docker:

10. Check the status of the OpenThread Border Router by executing the following command:

sudo docker exec -it otbr sh -c "sudo service otbr-agent status"

11. Check the status of the Thread node running inside the Docker:

sudo docker exec -it otbr sh -c "sudo ot-ctl state"

4617.zephyr.hex

[Izvor]

"I tried to reproduce the issue last week using the nRF52840 DK and our light bulb sample, but I did not get any issues."

Can you describe your lab setup?

"Are you running chip-tool on the same computer as the docker OTBR, or on a separate computer?"

On a separate computer.