Not able to commission matter over thread light app on nrf5340dk board with OTBR using chip-tool

Hi Team,

I am trying to commission the matter over thread light app on nrf5340dk with my OTBR using chip-tool but getting below error every time.

[1738239977.716] [9682:9684] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1738239977.716] [9682:9684] [CTL] Device returned status 0 on receiving the NOC
[1738239977.716] [9682:9684] [CTL] Operational credentials provisioned on device 0x7b14fc069c70
[1738239977.716] [9682:9684] [TOO] Secure Pairing Success
[1738239977.716] [9682:9684] [TOO] CASE establishment successful
[1738239977.716] [9682:9684] [CTL] Successfully finished commissioning step 'SendNOC'
[1738239977.716] [9682:9684] [CTL] No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks
[1738239977.716] [9682:9684] [CTL] Commissioning stage next step: 'SendNOC' -> 'ThreadNetworkSetup'
[1738239977.716] [9682:9684] [CTL] Performing next commissioning step 'ThreadNetworkSetup'
[1738239977.716] [9682:9684] [DMG] ICR moving to [AddingComm]
[1738239977.716] [9682:9684] [DMG] ICR moving to [AddedComma]
[1738239977.716] [9682:9684] [EM] <<< [E:43512i S:15387 M:61570474] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:276)
[1738239977.716] [9682:9684] [DMG] ICR moving to [AwaitingRe]
[1738239977.716] [9682:9684] [DMG] ICR moving to [AwaitingDe]
[1738239977.805] [9682:9684] [DL] HandlePlatformSpecificBLEEvent 16389
[1738239977.894] [9682:9684] [DL] HandlePlatformSpecificBLEEvent 16389
[1738239977.942] [9682:9683] [DL] Indication received, conn = 0x7b14f003c7f0
[1738239977.942] [9682:9684] [DL] HandlePlatformSpecificBLEEvent 16391
[1738239977.942] [9682:9684] [EM] >>> [E:43512i S:15387 M:110255702] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
[1738239977.942] [9682:9684] [EM] Found matching exchange: 43512i, Delegate: 0x7b14fc036408
[1738239977.942] [9682:9684] [DMG] ICR moving to [ResponseRe]
[1738239977.942] [9682:9684] [DMG] InvokeResponseMessage =
[1738239977.942] [9682:9684] [DMG] {
[1738239977.942] [9682:9684] [DMG] 	suppressResponse = false, 
[1738239977.942] [9682:9684] [DMG] 	InvokeResponseIBs =
[1738239977.942] [9682:9684] [DMG] 	[
[1738239977.942] [9682:9684] [DMG] 		InvokeResponseIB =
[1738239977.942] [9682:9684] [DMG] 		{
[1738239977.942] [9682:9684] [DMG] 			CommandDataIB =
[1738239977.942] [9682:9684] [DMG] 			{
[1738239977.942] [9682:9684] [DMG] 				CommandPathIB =
[1738239977.942] [9682:9684] [DMG] 				{
[1738239977.942] [9682:9684] [DMG] 					EndpointId = 0x0,
[1738239977.942] [9682:9684] [DMG] 					ClusterId = 0x31,
[1738239977.942] [9682:9684] [DMG] 					CommandId = 0x5,
[1738239977.942] [9682:9684] [DMG] 				},
[1738239977.942] [9682:9684] [DMG] 				
[1738239977.942] [9682:9684] [DMG] 				CommandFields = 
[1738239977.942] [9682:9684] [DMG] 				{
[1738239977.942] [9682:9684] [DMG] 					0x0 = 1 (unsigned), 
[1738239977.942] [9682:9684] [DMG] 				},
[1738239977.942] [9682:9684] [DMG] 			},
[1738239977.942] [9682:9684] [DMG] 			
[1738239977.942] [9682:9684] [DMG] 		},
[1738239977.942] [9682:9684] [DMG] 		
[1738239977.942] [9682:9684] [DMG] 	],
[1738239977.942] [9682:9684] [DMG] 	
[1738239977.942] [9682:9684] [DMG] 	InteractionModelRevision = 11
[1738239977.943] [9682:9684] [DMG] },
[1738239977.943] [9682:9684] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1738239977.943] [9682:9684] [CTL] Received NetworkConfig response, networkingStatus=1
[1738239977.943] [9682:9684] [CTL] Error on commissioning step 'ThreadNetworkSetup': 'src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error'
[1738239977.943] [9682:9684] [CTL] Going from commissioning step 'ThreadNetworkSetup' with lastErr = 'src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error' -> 'Cleanup'
[1738239977.943] [9682:9684] [CTL] Performing next commissioning step 'Cleanup' with completion status = 'src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error'
[1738239977.943] [9682:9684] [CTL] Successfully finished commissioning step 'Cleanup'
[1738239977.943] [9682:9684] [CTL] Commissioning complete for node ID 0x0000000000002221: src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error
[1738239977.943] [9682:9684] [TOO] Device commissioning Failure: src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error
[1738239977.943] [9682:9684] [TOO] Run command failure: src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error

OTBR is running on NXP's FRDM-RW612. I am able to successfully commission the OTBR using chip-tool.

I am able to commission and control the light app on nrf5340dk using NXP Matter Tool mobile app via OTBR but when I am trying everything with chip-tool not able to commission nrf5340dk

Does anyone have any idea what could be the reason?

Thank you,

Bhavya

Top Replies

0 Marte Myrvold 5 months ago
Hi Bhavya,

Do you have the full logs from the chip-tool and the nRF5340 DK?

Can you check if the router advertisement guard is enabled on the computer you are running the chip-tool on? Please run the following command in a terminal and share the result:

sudo sysctl net.ipv6.conf | grep accept_ra

Best regards,
Marte
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

0 Bhavya Mathukiya 5 months ago in reply to Marte Myrvold

Hi Marte Myrvold

Here is the result of sudo sysctl net.ipv6.conf | grep accept_ra

bhavya@acer:~$ sudo sysctl net.ipv6.conf | grep accept_ra
[sudo] password for bhavya: 
net.ipv6.conf.all.accept_ra = 1
net.ipv6.conf.all.accept_ra_defrtr = 1
net.ipv6.conf.all.accept_ra_from_local = 0
net.ipv6.conf.all.accept_ra_min_hop_limit = 1
net.ipv6.conf.all.accept_ra_min_lft = 0
net.ipv6.conf.all.accept_ra_mtu = 1
net.ipv6.conf.all.accept_ra_pinfo = 1
net.ipv6.conf.all.accept_ra_rt_info_max_plen = 0
net.ipv6.conf.all.accept_ra_rt_info_min_plen = 0
net.ipv6.conf.all.accept_ra_rtr_pref = 1
net.ipv6.conf.default.accept_ra = 1
net.ipv6.conf.default.accept_ra_defrtr = 1
net.ipv6.conf.default.accept_ra_from_local = 0
net.ipv6.conf.default.accept_ra_min_hop_limit = 1
net.ipv6.conf.default.accept_ra_min_lft = 0
net.ipv6.conf.default.accept_ra_mtu = 1
net.ipv6.conf.default.accept_ra_pinfo = 1
net.ipv6.conf.default.accept_ra_rt_info_max_plen = 0
net.ipv6.conf.default.accept_ra_rt_info_min_plen = 0
net.ipv6.conf.default.accept_ra_rtr_pref = 1
net.ipv6.conf.docker0.accept_ra = 0
net.ipv6.conf.docker0.accept_ra_defrtr = 1
net.ipv6.conf.docker0.accept_ra_from_local = 0
net.ipv6.conf.docker0.accept_ra_min_hop_limit = 1
net.ipv6.conf.docker0.accept_ra_min_lft = 0
net.ipv6.conf.docker0.accept_ra_mtu = 1
net.ipv6.conf.docker0.accept_ra_pinfo = 1
net.ipv6.conf.docker0.accept_ra_rt_info_max_plen = 0
net.ipv6.conf.docker0.accept_ra_rt_info_min_plen = 0
net.ipv6.conf.docker0.accept_ra_rtr_pref = 1
net.ipv6.conf.enp3s0.accept_ra = 0
net.ipv6.conf.enp3s0.accept_ra_defrtr = 1
net.ipv6.conf.enp3s0.accept_ra_from_local = 0
net.ipv6.conf.enp3s0.accept_ra_min_hop_limit = 1
net.ipv6.conf.enp3s0.accept_ra_min_lft = 0
net.ipv6.conf.enp3s0.accept_ra_mtu = 1
net.ipv6.conf.enp3s0.accept_ra_pinfo = 1
net.ipv6.conf.enp3s0.accept_ra_rt_info_max_plen = 0
net.ipv6.conf.enp3s0.accept_ra_rt_info_min_plen = 0
net.ipv6.conf.enp3s0.accept_ra_rtr_pref = 1
net.ipv6.conf.lo.accept_ra = 1
net.ipv6.conf.lo.accept_ra_defrtr = 1
net.ipv6.conf.lo.accept_ra_from_local = 0
net.ipv6.conf.lo.accept_ra_min_hop_limit = 1
net.ipv6.conf.lo.accept_ra_min_lft = 0
net.ipv6.conf.lo.accept_ra_mtu = 1
net.ipv6.conf.lo.accept_ra_pinfo = 1
net.ipv6.conf.lo.accept_ra_rt_info_max_plen = 0
net.ipv6.conf.lo.accept_ra_rt_info_min_plen = 0
net.ipv6.conf.lo.accept_ra_rtr_pref = 1
net.ipv6.conf.otbr0.accept_ra = 0
net.ipv6.conf.otbr0.accept_ra_defrtr = 1
net.ipv6.conf.otbr0.accept_ra_from_local = 0
net.ipv6.conf.otbr0.accept_ra_min_hop_limit = 1
net.ipv6.conf.otbr0.accept_ra_min_lft = 0
net.ipv6.conf.otbr0.accept_ra_mtu = 1
net.ipv6.conf.otbr0.accept_ra_pinfo = 1
net.ipv6.conf.otbr0.accept_ra_rt_info_max_plen = 0
net.ipv6.conf.otbr0.accept_ra_rt_info_min_plen = 0
net.ipv6.conf.otbr0.accept_ra_rtr_pref = 1
net.ipv6.conf.wlp0s20f3.accept_ra = 0
net.ipv6.conf.wlp0s20f3.accept_ra_defrtr = 1
net.ipv6.conf.wlp0s20f3.accept_ra_from_local = 0
net.ipv6.conf.wlp0s20f3.accept_ra_min_hop_limit = 1
net.ipv6.conf.wlp0s20f3.accept_ra_min_lft = 0
net.ipv6.conf.wlp0s20f3.accept_ra_mtu = 1
net.ipv6.conf.wlp0s20f3.accept_ra_pinfo = 1
net.ipv6.conf.wlp0s20f3.accept_ra_rt_info_max_plen = 0
net.ipv6.conf.wlp0s20f3.accept_ra_rt_info_min_plen = 0
net.ipv6.conf.wlp0s20f3.accept_ra_rtr_pref = 1

Best regards,

Bhavya

0 Marte Myrvold 5 months ago in reply to Bhavya Mathukiya
Hi Bhavya,

The router advertisement guard is enabled based on the output. You can see this by looking at the line with accept_ra. If it is 0, it means that the RA guard is enabled.

You can disable it with the following commands:

sudo sysctl -w net.ipv6.conf.wlp0s20f3.accept_ra=1 sudo sysctl -w net.ipv6.conf.wlp0s20f3.accept_ra_rt_info_max_plen=64

sudo sysctl -w net.ipv6.conf.enp3s0.accept_ra=1 sudo sysctl -w net.ipv6.conf.enp3s0.accept_ra_rt_info_max_plen=64

The first two commands are to disable it for the Wi-Fi network interface, wlp0s20f3, and the two last are to disable it for the Ethernet network interface, enp3s0.

Please try commissioning again after disabling the RA guard. Make sure to delete the chip-tool cache before retrying with

rm -r /tmp/chip_*

Best regards,
Marte
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

0 Bhavya Mathukiya 5 months ago in reply to Marte Myrvold

Hi Marte Myrvold

Thank you for this quick response. I have enabled the router advertisement using the commands you provided and verified it using sudo sysctl net.ipv6.conf | grep accept_ra but the issue still exists. Sharing logs of nrf5340dk and chip-tool for your reference.

nrf5340dk log

uart:~$ 
uart:~$ I: 28573 [DL]Current number of connections: 1/1
I: 28578 [DL]BLE connection established (ConnId: 0x00)
I: 28584 [DL]CHIPoBLE advertising stopped
I: 28587 [DL]NFC Tag emulation stopped
D: 29893 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 29900 [BLE]local and remote recv window sizes = 5
I: 29904 [BLE]selected BTP version 4
I: 29908 [BLE]using BTP fragment sizes rx 244 / tx 244.
D: 29982 [DL]ConnId: 0x00, New CCCD value: 0x0002
D: 29987 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 6)
D: 29994 [IN]BLE EndPoint 0x2000ff10 Connection Complete
I: 29999 [DL]CHIPoBLE connection established (ConnId: 0x00, GATT MTU: 247)
D: 30072 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 30080 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 30088 [EM]>>> [E:41458r S:0 M:109742634] (U) Msg RX from 0:64610A5A414C673F [0000] to 0000000000000000 --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98)
I: 30103 [EM]<<< [E:41458r S:0 M:144542832] (U) Msg TX from 0000000000000000 to 0:64610A5A414C673F [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154)
D: 30118 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 159)
I: 30126 [SVR]Commissioning session establishment step started
D: 30207 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 30215 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 30223 [EM]>>> [E:41458r S:0 M:109742635] (U) Msg RX from 0:64610A5A414C673F [0000] to 0000000000000000 --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92)
I: 30357 [EM]<<< [E:41458r S:0 M:144542833] (U) Msg TX from 0000000000000000 to 0:64610A5A414C673F [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127)
D: 30371 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 132)
E: 30379 [DL]Long dispatch time: 164 ms, for event type 16388
D: 30432 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 30440 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 30448 [EM]>>> [E:41458r S:0 M:109742636] (U) Msg RX from 0:64610A5A414C673F [0000] to 0000000000000000 --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59)
I: 30462 [EM]<<< [E:41458r S:0 M:144542834] (U) Msg TX from 0000000000000000 to 0:64610A5A414C673F [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
D: 30477 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 35)
I: 30487 [SC]SecureSession[0x200046c0, LSID:9533]: State change 'kEstablishing' --> 'kActive'
D: 30495 [IN]SecureSession[0x200046c0]: Activated - Type:1 LSID:9533
D: 30501 [IN]New secure session activated for device <FFFFFFFB00000000, 0>, LSID:9533 PSID:50401!
I: 30510 [SVR]Commissioning completed session establishment step
I: 30516 [DIS]Updating services using commissioning mode 0
E: 30521 [DIS]Failed to remove advertised services: 3
E: 30526 [DIS]Failed to finalize service update: 3
D: 30530 [DL]CHIPoBLE advertising set to off
I: 30534 [SVR]Device completed Rendezvous process
D: 30567 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 30575 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 30584 [EM]>>> [E:41459r S:9533 M:220804404] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:131)
D: 30597 [IM]Received Read request
I: 30607 [EM]<<< [E:41459r S:9533 M:67719675] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:258)
D: 30620 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 30702 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 30710 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 21)
D: 30792 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 30800 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 30809 [EM]>>> [E:41460r S:9533 M:220804405] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:02 (IM:ReadRequest) (B:106)
D: 30822 [IM]Received Read request
E: 30827 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0002err = 5c3
E: 30838 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0001err = 5c3
E: 30849 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0000err = 5c3
E: 30861 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0007err = 5c3
E: 30872 [DMG]Fail to retrieve data, roll back and encode status on clusterId: 0x0000_0046, attributeId: 0x0000_0006err = 5c3
I: 30885 [EM]<<< [E:41460r S:9533 M:67719676] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) (B:180)
D: 30898 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 185)
D: 30972 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 30980 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 30988 [EM]>>> [E:41461r S:9533 M:220804406] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
I: 31003 [FS]GeneralCommissioning: Received ArmFailSafe (60s)
I: 31010 [EM]<<< [E:41461r S:9533 M:67719677] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
D: 31024 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 31107 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 31115 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 31123 [EM]>>> [E:41462r S:9533 M:220804407] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:70)
I: 31140 [EM]<<< [E:41462r S:9533 M:67719678] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
D: 31155 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 31242 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 31250 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 31258 [EM]>>> [E:41463r S:9533 M:220804408] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
I: 31273 [ZCL]OpCreds: Certificate Chain request received for PAI
I: 31282 [EM]<<< [E:41463r S:9533 M:67719679] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:527)
D: 31297 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 31377 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 31385 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 31467 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 31475 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48)
D: 31557 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 31565 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 31573 [EM]>>> [E:41464r S:9533 M:220804409] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
I: 31588 [ZCL]OpCreds: Certificate Chain request received for DAC
I: 31597 [EM]<<< [E:41464r S:9533 M:67719680] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:556)
D: 31612 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 31737 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 31745 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 31827 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 31835 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77)
D: 31917 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 31925 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 31933 [EM]>>> [E:41465r S:9533 M:220804410] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
I: 31948 [ZCL]OpCreds: Received an AttestationRequest command
I: 31983 [ZCL]OpCreds: AttestationRequest successful.
I: 31992 [EM]<<< [E:41465r S:9533 M:67719681] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:716)
D: 32007 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 32097 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 32105 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 32187 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 32195 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 237)
D: 32277 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 32285 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 32293 [EM]>>> [E:41466r S:9533 M:220804411] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
I: 32308 [ZCL]OpCreds: Received a CSRRequest command
I: 32368 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
I: 32402 [ZCL]OpCreds: CSRRequest successful.
I: 32409 [EM]<<< [E:41466r S:9533 M:67719682] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:392)
D: 32424 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
E: 32431 [DL]Long dispatch time: 146 ms, for event type 16388
D: 32502 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 32510 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 155)
D: 32637 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 32645 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 32728 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 32737 [EM]>>> [E:41467r S:9533 M:220804412] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:293)
I: 32752 [ZCL]OpCreds: Received an AddTrustedRootCertificate command
I: 32811 [ZCL]OpCreds: AddTrustedRootCertificate successful.
I: 32818 [EM]<<< [E:41467r S:9533 M:67719683] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
D: 32832 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68)
E: 32840 [DL]Long dispatch time: 112 ms, for event type 16388
D: 32907 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 32915 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 32999 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 33088 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 33098 [EM]>>> [E:41468r S:9533 M:220804413] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:567)
I: 33113 [ZCL]OpCreds: Received an AddNOC command
I: 33119 [FP]Validating NOC chain
I: 33230 [FP]NOC chain validation successful
I: 33234 [FP]Added new fabric at index: 0x1
I: 33238 [FP]Assigned compressed fabric ID: 0xF95A1D9E373DF80B, node ID: 0x0000000000002221
I: 33246 [TS]Last Known Good Time: 2023-10-14T01:16:48
I: 33251 [TS]New proposed Last Known Good Time: 2021-01-01T00:00:00
I: 33257 [TS]Retaining current Last Known Good Time
I: 33273 [ZCL]OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669
D: 33281 [DL]Using Thread extended MAC for hostname.
I: 33286 [DIS]Advertise operational node F95A1D9E373DF80B-0000000000002221
E: 33293 [SVR]Operational advertising failed: 3
I: 33297 [ZCL]OpCreds: successfully created fabric index 0x1 via AddNOC
I: 33305 [EM]<<< [E:41468r S:9533 M:67719684] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [F80B] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
D: 33319 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
E: 33327 [DL]Long dispatch time: 239 ms, for event type 16388
D: 33402 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 33410 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 33493 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 33502 [EM]>>> [E:41469r S:9533 M:220804414] (S) Msg RX from 1:FFFFFFFB00000000 [F80B] to 0000000000000000 --- Type 0001:08 (IM:InvokeCommandRequest) (B:287)
I: 33518 [EM]<<< [E:41469r S:9533 M:67719685] (S) Msg TX from 0000000000000000 to 1:FFFFFFFB00000000 [F80B] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
D: 33532 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 68)
D: 33627 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 36102 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 38610 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 38667 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 41142 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 43650 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 43707 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 46182 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 48690 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 48747 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 51222 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)

uart:~$ D: 53730 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 53832 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 56307 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 58814 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 58872 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 61347 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
D: 63854 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 3)
D: 63912 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)

chip-tool log

>>> pairing ble-thread 0x2221 0e08000000000001000000030000164a0300001835060004001fffe00208b259765e36f15bf00708fd7c41ce3d2120bd05100d2d9619b628ad20c51cb905b4059c75030f4f70656e5468726561642d626336630102bc6c041021e09647f0703f06ccbaa010424147450c0402a0f7f8 20202021 3840
[1738749234.283] [63313:63313] [TOO] Command: pairing ble-thread 0x2221 0e08000000000001000000030000164a0300001835060004001fffe00208b259765e36f15bf00708fd7c41ce3d2120bd05100d2d9619b628ad20c51cb905b4059c75030f4f70656e5468726561642d626336630102bc6c041021e09647f0703f06ccbaa010424147450c0402a0f7f8 20202021 3840 
[1738749234.284] [63313:63315] [CTL] Setting thread operational dataset from parameters
[1738749234.284] [63313:63315] [CTL] Setting attestation nonce to random value
[1738749234.284] [63313:63315] [CTL] Setting CSR nonce to random value
[1738749234.284] [63313:63315] [CTL] Commission called for node ID 0x0000000000002221
[1738749234.284] [63313:63314] [BLE] BLE removing known devices
[1738749234.285] [63313:63314] [BLE] BLE initiating scan
[1738749234.391] [63313:63315] [BLE] ChipDeviceScanner has started scanning!
[1738749234.391] [63313:63315] [DL] Long dispatch time: 107 ms, for event type 3
[1738749234.403] [63313:63314] [BLE] Device 2D:5A:DB:DE:D3:7B does not look like a CHIP device.
[1738749234.406] [63313:63314] [BLE] Device 62:AC:4D:D2:B2:7B does not look like a CHIP device.
[1738749234.410] [63313:63314] [BLE] Device 00:96:3E:84:85:E0 does not look like a CHIP device.
[1738749234.429] [63313:63314] [BLE] New device scanned: CB:BB:49:38:C6:93
[1738749234.429] [63313:63314] [BLE] Device discriminator match. Attempting to connect.
[1738749234.434] [63313:63314] [BLE] ChipDeviceScanner has stopped scanning!
[1738749234.534] [63313:63314] [DL] ConnectDevice complete
[1738749234.534] [63313:63314] [BLE] New device connected: CB:BB:49:38:C6:93
[1738749235.404] [63313:63314] [DL] CHIP service found
[1738749235.404] [63313:63314] [DL] Valid C1 characteristic found
[1738749235.404] [63313:63314] [DL] Valid C2 characteristic found
[1738749235.404] [63313:63314] [DL] New BLE connection: conn=0x763dc8014430 device=CB:BB:49:38:C6:93 path=/org/bluez/hci0/dev_CB_BB_49_38_C6_93
[1738749235.404] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16387
[1738749235.404] [63313:63315] [DIS] Closing all BLE connections
[1738749235.404] [63313:63315] [IN] BleConnectionComplete: endPoint 0x5cf2f9894a80
[1738749235.405] [63313:63315] [IN] SecureSession[0x763dd4033ab0]: Allocated Type:1 LSID:50401
[1738749235.405] [63313:63315] [SC] Assigned local session key ID 50401
[1738749235.405] [63313:63315] [EM] <<< [E:41458i S:0 M:109742634] (U) Msg TX from 64610A5A414C673F to 0:0000000000000000 [0000] [BLE] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) (B:98)
[1738749235.405] [63313:63315] [IN] Message appended to BLE send queue
[1738749235.405] [63313:63315] [SC] Sent PBKDF param request [II:500ms AI:300ms AT:4000ms)
[1738749235.840] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749235.932] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749235.933] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16390
[1738749235.933] [63313:63315] [BLE] subscribe complete, ep = 0x5cf2f9894a80
[1738749235.933] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749235.933] [63313:63315] [BLE] peripheral chose BTP version 4; central expected between 4 and 4
[1738749235.933] [63313:63315] [BLE] using BTP fragment sizes rx 244 / tx 244.
[1738749235.933] [63313:63315] [BLE] local and remote recv window size = 5
[1738749235.933] [63313:63315] [IN] BLE EndPoint 0x5cf2f9894a80 Connection Complete
[1738749236.020] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749236.069] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749236.069] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749236.069] [63313:63315] [EM] >>> [E:41458i S:0 M:144542832] (U) Msg RX from 0:0000000000000000 [0000] to 64610A5A414C673F --- Type 0000:21 (SecureChannel:PBKDFParamResponse) (B:154)
[1738749236.069] [63313:63315] [EM] Found matching exchange: 41458i, Delegate: 0x763dd4034dc8
[1738749236.069] [63313:63315] [SC] Received PBKDF param response
[1738749236.069] [63313:63315] [SC] Peer assigned session ID 9533
[1738749236.069] [63313:63315] [SC] Found MRP parameters in the message
[1738749236.071] [63313:63315] [EM] <<< [E:41458i S:0 M:109742635] (U) Msg TX from 64610A5A414C673F to 0:0000000000000000 [0000] [BLE] --- Type 0000:22 (SecureChannel:PASE_Pake1) (B:92)
[1738749236.072] [63313:63315] [SC] Sent spake2p msg1
[1738749236.156] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749236.292] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749236.293] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749236.293] [63313:63315] [EM] >>> [E:41458i S:0 M:144542833] (U) Msg RX from 0:0000000000000000 [0000] to 64610A5A414C673F --- Type 0000:23 (SecureChannel:PASE_Pake2) (B:127)
[1738749236.293] [63313:63315] [EM] Found matching exchange: 41458i, Delegate: 0x763dd4034dc8
[1738749236.293] [63313:63315] [SC] Received spake2p msg2
[1738749236.294] [63313:63315] [EM] <<< [E:41458i S:0 M:109742636] (U) Msg TX from 64610A5A414C673F to 0:0000000000000000 [0000] [BLE] --- Type 0000:24 (SecureChannel:PASE_Pake3) (B:59)
[1738749236.298] [63313:63315] [SC] Sent spake2p msg3
[1738749236.380] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749236.426] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749236.427] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749236.427] [63313:63315] [EM] >>> [E:41458i S:0 M:144542834] (U) Msg RX from 0:0000000000000000 [0000] to 64610A5A414C673F --- Type 0000:40 (SecureChannel:StatusReport) (B:30)
[1738749236.427] [63313:63315] [EM] Found matching exchange: 41458i, Delegate: 0x763dd4034dc8
[1738749236.427] [63313:63315] [SC] SecureSession[0x763dd4033ab0, LSID:50401]: State change 'kEstablishing' --> 'kActive'
[1738749236.427] [63313:63315] [IN] SecureSession[0x763dd4033ab0]: Activated - Type:1 LSID:50401
[1738749236.427] [63313:63315] [IN] New secure session activated for device <FFFFFFFB00000000, 0>, LSID:50401 PSID:9533!
[1738749236.427] [63313:63315] [CTL] Remote device completed SPAKE2+ handshake
[1738749236.427] [63313:63315] [TOO] Pairing Success
[1738749236.427] [63313:63315] [TOO] PASE establishment successful
[1738749236.427] [63313:63315] [CTL] Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1738749236.427] [63313:63315] [CTL] Performing next commissioning step 'ReadCommissioningInfo'
[1738749236.427] [63313:63315] [CTL] Sending read request for commissioning information
[1738749236.427] [63313:63315] [DMG] SendReadRequest ReadClient[0x763ddc03ccf0]: Sending Read Request
[1738749236.427] [63313:63315] [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
[1738749236.427] [63313:63315] [EM] <<< [E:41459i S:50401 M:220804404] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:02 (IM:ReadRequest) (B:131)
[1738749236.429] [63313:63315] [DMG] MoveToState ReadClient[0x763ddc03ccf0]: Moving to [AwaitingIn]
[1738749236.429] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 32792
[1738749236.517] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749236.564] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749236.564] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749236.651] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749236.651] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749236.651] [63313:63315] [EM] >>> [E:41459i S:50401 M:67719675] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:05 (IM:ReportData) (B:258)
[1738749236.651] [63313:63315] [EM] Found matching exchange: 41459i, Delegate: 0x763ddc03cd00
[1738749236.652] [63313:63315] [DMG] ReportDataMessage =
[1738749236.652] [63313:63315] [DMG] {
[1738749236.652] [63313:63315] [DMG] 	AttributeReportIBs =
[1738749236.652] [63313:63315] [DMG] 	[
[1738749236.652] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.652] [63313:63315] [DMG] 		{
[1738749236.652] [63313:63315] [DMG] 			AttributeDataIB =
[1738749236.652] [63313:63315] [DMG] 			{
[1738749236.652] [63313:63315] [DMG] 				DataVersion = 0xc40e343b,
[1738749236.652] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.652] [63313:63315] [DMG] 				{
[1738749236.652] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.652] [63313:63315] [DMG] 					Cluster = 0x31,
[1738749236.652] [63313:63315] [DMG] 					Attribute = 0x0000_0003,
[1738749236.652] [63313:63315] [DMG] 				}
[1738749236.652] [63313:63315] [DMG] 					
[1738749236.652] [63313:63315] [DMG] 				Data = 20 (unsigned), 
[1738749236.652] [63313:63315] [DMG] 			},
[1738749236.652] [63313:63315] [DMG] 			
[1738749236.652] [63313:63315] [DMG] 		},
[1738749236.652] [63313:63315] [DMG] 		
[1738749236.652] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.652] [63313:63315] [DMG] 		{
[1738749236.652] [63313:63315] [DMG] 			AttributeDataIB =
[1738749236.652] [63313:63315] [DMG] 			{
[1738749236.652] [63313:63315] [DMG] 				DataVersion = 0x7a258ccb,
[1738749236.652] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.652] [63313:63315] [DMG] 				{
[1738749236.652] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.652] [63313:63315] [DMG] 					Cluster = 0x28,
[1738749236.652] [63313:63315] [DMG] 					Attribute = 0x0000_0004,
[1738749236.652] [63313:63315] [DMG] 				}
[1738749236.652] [63313:63315] [DMG] 					
[1738749236.652] [63313:63315] [DMG] 				Data = 32773 (unsigned), 
[1738749236.652] [63313:63315] [DMG] 			},
[1738749236.652] [63313:63315] [DMG] 			
[1738749236.652] [63313:63315] [DMG] 		},
[1738749236.652] [63313:63315] [DMG] 		
[1738749236.652] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.652] [63313:63315] [DMG] 		{
[1738749236.652] [63313:63315] [DMG] 			AttributeDataIB =
[1738749236.652] [63313:63315] [DMG] 			{
[1738749236.652] [63313:63315] [DMG] 				DataVersion = 0x7a258ccb,
[1738749236.652] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.652] [63313:63315] [DMG] 				{
[1738749236.652] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.652] [63313:63315] [DMG] 					Cluster = 0x28,
[1738749236.652] [63313:63315] [DMG] 					Attribute = 0x0000_0002,
[1738749236.652] [63313:63315] [DMG] 				}
[1738749236.652] [63313:63315] [DMG] 					
[1738749236.652] [63313:63315] [DMG] 				Data = 65521 (unsigned), 
[1738749236.652] [63313:63315] [DMG] 			},
[1738749236.652] [63313:63315] [DMG] 			
[1738749236.652] [63313:63315] [DMG] 		},
[1738749236.652] [63313:63315] [DMG] 		
[1738749236.652] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.652] [63313:63315] [DMG] 		{
[1738749236.652] [63313:63315] [DMG] 			AttributeDataIB =
[1738749236.652] [63313:63315] [DMG] 			{
[1738749236.652] [63313:63315] [DMG] 				DataVersion = 0x9b896d25,
[1738749236.652] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.652] [63313:63315] [DMG] 				{
[1738749236.652] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.652] [63313:63315] [DMG] 					Cluster = 0x30,
[1738749236.652] [63313:63315] [DMG] 					Attribute = 0x0000_0003,
[1738749236.652] [63313:63315] [DMG] 				}
[1738749236.652] [63313:63315] [DMG] 					
[1738749236.652] [63313:63315] [DMG] 				Data = 0 (unsigned), 
[1738749236.652] [63313:63315] [DMG] 			},
[1738749236.652] [63313:63315] [DMG] 			
[1738749236.652] [63313:63315] [DMG] 		},
[1738749236.652] [63313:63315] [DMG] 		
[1738749236.652] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.652] [63313:63315] [DMG] 		{
[1738749236.652] [63313:63315] [DMG] 			AttributeDataIB =
[1738749236.652] [63313:63315] [DMG] 			{
[1738749236.652] [63313:63315] [DMG] 				DataVersion = 0x9b896d25,
[1738749236.652] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.652] [63313:63315] [DMG] 				{
[1738749236.652] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.652] [63313:63315] [DMG] 					Cluster = 0x30,
[1738749236.652] [63313:63315] [DMG] 					Attribute = 0x0000_0002,
[1738749236.652] [63313:63315] [DMG] 				}
[1738749236.652] [63313:63315] [DMG] 					
[1738749236.652] [63313:63315] [DMG] 				Data = 0 (unsigned), 
[1738749236.652] [63313:63315] [DMG] 			},
[1738749236.652] [63313:63315] [DMG] 			
[1738749236.652] [63313:63315] [DMG] 		},
[1738749236.652] [63313:63315] [DMG] 		
[1738749236.652] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.652] [63313:63315] [DMG] 		{
[1738749236.652] [63313:63315] [DMG] 			AttributeDataIB =
[1738749236.652] [63313:63315] [DMG] 			{
[1738749236.652] [63313:63315] [DMG] 				DataVersion = 0x9b896d25,
[1738749236.652] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.652] [63313:63315] [DMG] 				{
[1738749236.652] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.652] [63313:63315] [DMG] 					Cluster = 0x30,
[1738749236.652] [63313:63315] [DMG] 					Attribute = 0x0000_0001,
[1738749236.652] [63313:63315] [DMG] 				}
[1738749236.652] [63313:63315] [DMG] 					
[1738749236.652] [63313:63315] [DMG] 				Data = 
[1738749236.653] [63313:63315] [DMG] 				{
[1738749236.653] [63313:63315] [DMG] 					0x0 = 60 (unsigned), 
[1738749236.653] [63313:63315] [DMG] 					0x1 = 900 (unsigned), 
[1738749236.653] [63313:63315] [DMG] 				},
[1738749236.653] [63313:63315] [DMG] 			},
[1738749236.653] [63313:63315] [DMG] 			
[1738749236.653] [63313:63315] [DMG] 		},
[1738749236.653] [63313:63315] [DMG] 		
[1738749236.653] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.653] [63313:63315] [DMG] 		{
[1738749236.653] [63313:63315] [DMG] 			AttributeDataIB =
[1738749236.653] [63313:63315] [DMG] 			{
[1738749236.653] [63313:63315] [DMG] 				DataVersion = 0x9b896d25,
[1738749236.653] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.653] [63313:63315] [DMG] 				{
[1738749236.653] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.653] [63313:63315] [DMG] 					Cluster = 0x30,
[1738749236.653] [63313:63315] [DMG] 					Attribute = 0x0000_0000,
[1738749236.653] [63313:63315] [DMG] 				}
[1738749236.653] [63313:63315] [DMG] 					
[1738749236.653] [63313:63315] [DMG] 				Data = 0 (unsigned), 
[1738749236.653] [63313:63315] [DMG] 			},
[1738749236.653] [63313:63315] [DMG] 			
[1738749236.653] [63313:63315] [DMG] 		},
[1738749236.653] [63313:63315] [DMG] 		
[1738749236.653] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.653] [63313:63315] [DMG] 		{
[1738749236.653] [63313:63315] [DMG] 			AttributeDataIB =
[1738749236.653] [63313:63315] [DMG] 			{
[1738749236.653] [63313:63315] [DMG] 				DataVersion = 0xc40e343b,
[1738749236.653] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.653] [63313:63315] [DMG] 				{
[1738749236.653] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.653] [63313:63315] [DMG] 					Cluster = 0x31,
[1738749236.653] [63313:63315] [DMG] 					Attribute = 0x0000_FFFC,
[1738749236.653] [63313:63315] [DMG] 				}
[1738749236.653] [63313:63315] [DMG] 					
[1738749236.653] [63313:63315] [DMG] 				Data = 2 (unsigned), 
[1738749236.653] [63313:63315] [DMG] 			},
[1738749236.653] [63313:63315] [DMG] 			
[1738749236.653] [63313:63315] [DMG] 		},
[1738749236.653] [63313:63315] [DMG] 		
[1738749236.653] [63313:63315] [DMG] 	],
[1738749236.653] [63313:63315] [DMG] 	
[1738749236.653] [63313:63315] [DMG] 	SuppressResponse = true, 
[1738749236.653] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749236.653] [63313:63315] [DMG] }
[1738749236.653] [63313:63315] [CTL] Successfully finished commissioning step 'ReadCommissioningInfo'
[1738749236.653] [63313:63315] [CTL] Commissioning stage next step: 'ReadCommissioningInfo' -> 'ReadCommissioningInfo2'
[1738749236.653] [63313:63315] [CTL] Performing next commissioning step 'ReadCommissioningInfo2'
[1738749236.653] [63313:63315] [DMG] SendReadRequest ReadClient[0x763ddc03fbf0]: Sending Read Request
[1738749236.653] [63313:63315] [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
[1738749236.653] [63313:63315] [EM] <<< [E:41460i S:50401 M:220804405] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:02 (IM:ReadRequest) (B:106)
[1738749236.653] [63313:63315] [DMG] MoveToState ReadClient[0x763ddc03fbf0]: Moving to [AwaitingIn]
[1738749236.741] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749236.832] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749236.832] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749236.832] [63313:63315] [EM] >>> [E:41460i S:50401 M:67719676] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:05 (IM:ReportData) (B:180)
[1738749236.832] [63313:63315] [EM] Found matching exchange: 41460i, Delegate: 0x763ddc03fc00
[1738749236.832] [63313:63315] [DMG] ReportDataMessage =
[1738749236.832] [63313:63315] [DMG] {
[1738749236.832] [63313:63315] [DMG] 	AttributeReportIBs =
[1738749236.832] [63313:63315] [DMG] 	[
[1738749236.832] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.832] [63313:63315] [DMG] 		{
[1738749236.832] [63313:63315] [DMG] 			AttributeStatusIB =
[1738749236.832] [63313:63315] [DMG] 			{
[1738749236.832] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.832] [63313:63315] [DMG] 				{
[1738749236.832] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.832] [63313:63315] [DMG] 					Cluster = 0x46,
[1738749236.832] [63313:63315] [DMG] 					Attribute = 0x0000_0002,
[1738749236.832] [63313:63315] [DMG] 				}
[1738749236.832] [63313:63315] [DMG] 					
[1738749236.832] [63313:63315] [DMG] 				StatusIB =
[1738749236.832] [63313:63315] [DMG] 				{
[1738749236.832] [63313:63315] [DMG] 					status = 0xc3 (UNSUPPORTED_CLUSTER),
[1738749236.833] [63313:63315] [DMG] 				},
[1738749236.833] [63313:63315] [DMG] 				
[1738749236.833] [63313:63315] [DMG] 			},
[1738749236.833] [63313:63315] [DMG] 			
[1738749236.833] [63313:63315] [DMG] 		},
[1738749236.833] [63313:63315] [DMG] 		
[1738749236.833] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.833] [63313:63315] [DMG] 		{
[1738749236.833] [63313:63315] [DMG] 			AttributeStatusIB =
[1738749236.833] [63313:63315] [DMG] 			{
[1738749236.833] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.833] [63313:63315] [DMG] 				{
[1738749236.833] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.833] [63313:63315] [DMG] 					Cluster = 0x46,
[1738749236.833] [63313:63315] [DMG] 					Attribute = 0x0000_0001,
[1738749236.833] [63313:63315] [DMG] 				}
[1738749236.833] [63313:63315] [DMG] 					
[1738749236.833] [63313:63315] [DMG] 				StatusIB =
[1738749236.833] [63313:63315] [DMG] 				{
[1738749236.833] [63313:63315] [DMG] 					status = 0xc3 (UNSUPPORTED_CLUSTER),
[1738749236.833] [63313:63315] [DMG] 				},
[1738749236.833] [63313:63315] [DMG] 				
[1738749236.833] [63313:63315] [DMG] 			},
[1738749236.833] [63313:63315] [DMG] 			
[1738749236.833] [63313:63315] [DMG] 		},
[1738749236.833] [63313:63315] [DMG] 		
[1738749236.833] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.833] [63313:63315] [DMG] 		{
[1738749236.833] [63313:63315] [DMG] 			AttributeStatusIB =
[1738749236.833] [63313:63315] [DMG] 			{
[1738749236.833] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.833] [63313:63315] [DMG] 				{
[1738749236.833] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.833] [63313:63315] [DMG] 					Cluster = 0x46,
[1738749236.833] [63313:63315] [DMG] 					Attribute = 0x0000_0000,
[1738749236.833] [63313:63315] [DMG] 				}
[1738749236.833] [63313:63315] [DMG] 					
[1738749236.833] [63313:63315] [DMG] 				StatusIB =
[1738749236.833] [63313:63315] [DMG] 				{
[1738749236.833] [63313:63315] [DMG] 					status = 0xc3 (UNSUPPORTED_CLUSTER),
[1738749236.833] [63313:63315] [DMG] 				},
[1738749236.833] [63313:63315] [DMG] 				
[1738749236.833] [63313:63315] [DMG] 			},
[1738749236.833] [63313:63315] [DMG] 			
[1738749236.833] [63313:63315] [DMG] 		},
[1738749236.833] [63313:63315] [DMG] 		
[1738749236.833] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.833] [63313:63315] [DMG] 		{
[1738749236.833] [63313:63315] [DMG] 			AttributeStatusIB =
[1738749236.833] [63313:63315] [DMG] 			{
[1738749236.833] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.833] [63313:63315] [DMG] 				{
[1738749236.833] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.833] [63313:63315] [DMG] 					Cluster = 0x46,
[1738749236.833] [63313:63315] [DMG] 					Attribute = 0x0000_0007,
[1738749236.833] [63313:63315] [DMG] 				}
[1738749236.833] [63313:63315] [DMG] 					
[1738749236.833] [63313:63315] [DMG] 				StatusIB =
[1738749236.833] [63313:63315] [DMG] 				{
[1738749236.833] [63313:63315] [DMG] 					status = 0xc3 (UNSUPPORTED_CLUSTER),
[1738749236.833] [63313:63315] [DMG] 				},
[1738749236.833] [63313:63315] [DMG] 				
[1738749236.833] [63313:63315] [DMG] 			},
[1738749236.833] [63313:63315] [DMG] 			
[1738749236.833] [63313:63315] [DMG] 		},
[1738749236.833] [63313:63315] [DMG] 		
[1738749236.833] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.833] [63313:63315] [DMG] 		{
[1738749236.833] [63313:63315] [DMG] 			AttributeStatusIB =
[1738749236.833] [63313:63315] [DMG] 			{
[1738749236.833] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.833] [63313:63315] [DMG] 				{
[1738749236.833] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.833] [63313:63315] [DMG] 					Cluster = 0x46,
[1738749236.833] [63313:63315] [DMG] 					Attribute = 0x0000_0006,
[1738749236.833] [63313:63315] [DMG] 				}
[1738749236.833] [63313:63315] [DMG] 					
[1738749236.833] [63313:63315] [DMG] 				StatusIB =
[1738749236.833] [63313:63315] [DMG] 				{
[1738749236.833] [63313:63315] [DMG] 					status = 0xc3 (UNSUPPORTED_CLUSTER),
[1738749236.833] [63313:63315] [DMG] 				},
[1738749236.833] [63313:63315] [DMG] 				
[1738749236.833] [63313:63315] [DMG] 			},
[1738749236.833] [63313:63315] [DMG] 			
[1738749236.833] [63313:63315] [DMG] 		},
[1738749236.833] [63313:63315] [DMG] 		
[1738749236.833] [63313:63315] [DMG] 		AttributeReportIB =
[1738749236.833] [63313:63315] [DMG] 		{
[1738749236.833] [63313:63315] [DMG] 			AttributeDataIB =
[1738749236.833] [63313:63315] [DMG] 			{
[1738749236.833] [63313:63315] [DMG] 				DataVersion = 0x9b896d25,
[1738749236.833] [63313:63315] [DMG] 				AttributePathIB =
[1738749236.833] [63313:63315] [DMG] 				{
[1738749236.833] [63313:63315] [DMG] 					Endpoint = 0x0,
[1738749236.833] [63313:63315] [DMG] 					Cluster = 0x30,
[1738749236.833] [63313:63315] [DMG] 					Attribute = 0x0000_0004,
[1738749236.833] [63313:63315] [DMG] 				}
[1738749236.833] [63313:63315] [DMG] 					
[1738749236.833] [63313:63315] [DMG] 				Data = true, 
[1738749236.833] [63313:63315] [DMG] 			},
[1738749236.833] [63313:63315] [DMG] 			
[1738749236.833] [63313:63315] [DMG] 		},
[1738749236.833] [63313:63315] [DMG] 		
[1738749236.833] [63313:63315] [DMG] 	],
[1738749236.833] [63313:63315] [DMG] 	
[1738749236.833] [63313:63315] [DMG] 	SuppressResponse = true, 
[1738749236.833] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749236.833] [63313:63315] [DMG] }
[1738749236.834] [63313:63315] [CTL] ----- NetworkCommissioning Features: has Thread. endpointid = 0
[1738749236.834] [63313:63315] [SVR] OnReadCommissioningInfo - vendorId=0xFFF1 productId=0x8005
[1738749236.834] [63313:63315] [SVR] OnReadCommissioningInfo ICD - IdleModeDuration=0 activeModeDuration=0 activeModeThreshold=0
[1738749236.834] [63313:63315] [CTL] Successfully finished commissioning step 'ReadCommissioningInfo2'
[1738749236.834] [63313:63315] [CTL] Commissioning stage next step: 'ReadCommissioningInfo2' -> 'ArmFailSafe'
[1738749236.834] [63313:63315] [CTL] Performing next commissioning step 'ArmFailSafe'
[1738749236.834] [63313:63315] [CTL] Arming failsafe (60 seconds)
[1738749236.834] [63313:63315] [DMG] ICR moving to [AddingComm]
[1738749236.834] [63313:63315] [DMG] ICR moving to [AddedComma]
[1738749236.834] [63313:63315] [EM] <<< [E:41461i S:50401 M:220804406] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:65)
[1738749236.834] [63313:63315] [DMG] ICR moving to [AwaitingRe]
[1738749236.920] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749236.968] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749236.968] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749236.968] [63313:63315] [EM] >>> [E:41461i S:50401 M:67719677] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1738749236.968] [63313:63315] [EM] Found matching exchange: 41461i, Delegate: 0x763dd4014078
[1738749236.968] [63313:63315] [DMG] ICR moving to [ResponseRe]
[1738749236.968] [63313:63315] [DMG] InvokeResponseMessage =
[1738749236.968] [63313:63315] [DMG] {
[1738749236.968] [63313:63315] [DMG] 	suppressResponse = false, 
[1738749236.968] [63313:63315] [DMG] 	InvokeResponseIBs =
[1738749236.968] [63313:63315] [DMG] 	[
[1738749236.968] [63313:63315] [DMG] 		InvokeResponseIB =
[1738749236.968] [63313:63315] [DMG] 		{
[1738749236.968] [63313:63315] [DMG] 			CommandDataIB =
[1738749236.968] [63313:63315] [DMG] 			{
[1738749236.968] [63313:63315] [DMG] 				CommandPathIB =
[1738749236.968] [63313:63315] [DMG] 				{
[1738749236.968] [63313:63315] [DMG] 					EndpointId = 0x0,
[1738749236.968] [63313:63315] [DMG] 					ClusterId = 0x30,
[1738749236.968] [63313:63315] [DMG] 					CommandId = 0x1,
[1738749236.968] [63313:63315] [DMG] 				},
[1738749236.968] [63313:63315] [DMG] 				
[1738749236.968] [63313:63315] [DMG] 				CommandFields = 
[1738749236.968] [63313:63315] [DMG] 				{
[1738749236.968] [63313:63315] [DMG] 					0x0 = 0 (unsigned), 
[1738749236.968] [63313:63315] [DMG] 					0x1 = "" (0 chars), 
[1738749236.968] [63313:63315] [DMG] 				},
[1738749236.968] [63313:63315] [DMG] 			},
[1738749236.968] [63313:63315] [DMG] 			
[1738749236.968] [63313:63315] [DMG] 		},
[1738749236.968] [63313:63315] [DMG] 		
[1738749236.968] [63313:63315] [DMG] 	],
[1738749236.968] [63313:63315] [DMG] 	
[1738749236.968] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749236.968] [63313:63315] [DMG] },
[1738749236.968] [63313:63315] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1738749236.968] [63313:63315] [CTL] Received ArmFailSafe response errorCode=0
[1738749236.968] [63313:63315] [CTL] Successfully finished commissioning step 'ArmFailSafe'
[1738749236.968] [63313:63315] [CTL] Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1738749236.968] [63313:63315] [CTL] Performing next commissioning step 'ConfigRegulatory'
[1738749236.968] [63313:63315] [CTL] Setting Regulatory Config
[1738749236.968] [63313:63315] [CTL] Device does not support configurable regulatory location
[1738749236.969] [63313:63315] [DMG] ICR moving to [AddingComm]
[1738749236.969] [63313:63315] [DMG] ICR moving to [AddedComma]
[1738749236.969] [63313:63315] [EM] <<< [E:41462i S:50401 M:220804407] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:70)
[1738749236.969] [63313:63315] [DMG] ICR moving to [AwaitingRe]
[1738749236.969] [63313:63315] [DMG] ICR moving to [AwaitingDe]
[1738749237.055] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749237.101] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749237.102] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749237.102] [63313:63315] [EM] >>> [E:41462i S:50401 M:67719678] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1738749237.102] [63313:63315] [EM] Found matching exchange: 41462i, Delegate: 0x763dd403c038
[1738749237.102] [63313:63315] [DMG] ICR moving to [ResponseRe]
[1738749237.102] [63313:63315] [DMG] InvokeResponseMessage =
[1738749237.102] [63313:63315] [DMG] {
[1738749237.102] [63313:63315] [DMG] 	suppressResponse = false, 
[1738749237.102] [63313:63315] [DMG] 	InvokeResponseIBs =
[1738749237.102] [63313:63315] [DMG] 	[
[1738749237.102] [63313:63315] [DMG] 		InvokeResponseIB =
[1738749237.102] [63313:63315] [DMG] 		{
[1738749237.102] [63313:63315] [DMG] 			CommandDataIB =
[1738749237.102] [63313:63315] [DMG] 			{
[1738749237.102] [63313:63315] [DMG] 				CommandPathIB =
[1738749237.102] [63313:63315] [DMG] 				{
[1738749237.102] [63313:63315] [DMG] 					EndpointId = 0x0,
[1738749237.102] [63313:63315] [DMG] 					ClusterId = 0x30,
[1738749237.102] [63313:63315] [DMG] 					CommandId = 0x3,
[1738749237.102] [63313:63315] [DMG] 				},
[1738749237.102] [63313:63315] [DMG] 				
[1738749237.102] [63313:63315] [DMG] 				CommandFields = 
[1738749237.102] [63313:63315] [DMG] 				{
[1738749237.102] [63313:63315] [DMG] 					0x0 = 0 (unsigned), 
[1738749237.102] [63313:63315] [DMG] 					0x1 = "" (0 chars), 
[1738749237.102] [63313:63315] [DMG] 				},
[1738749237.102] [63313:63315] [DMG] 			},
[1738749237.102] [63313:63315] [DMG] 			
[1738749237.102] [63313:63315] [DMG] 		},
[1738749237.102] [63313:63315] [DMG] 		
[1738749237.102] [63313:63315] [DMG] 	],
[1738749237.102] [63313:63315] [DMG] 	
[1738749237.102] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749237.102] [63313:63315] [DMG] },
[1738749237.102] [63313:63315] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1738749237.102] [63313:63315] [CTL] Received SetRegulatoryConfig response errorCode=0
[1738749237.102] [63313:63315] [CTL] Successfully finished commissioning step 'ConfigRegulatory'
[1738749237.102] [63313:63315] [CTL] Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest'
[1738749237.102] [63313:63315] [CTL] Performing next commissioning step 'SendPAICertificateRequest'
[1738749237.102] [63313:63315] [CTL] Sending request for PAI certificate
[1738749237.102] [63313:63315] [CTL] Sending Certificate Chain request to 0x763dd4034d70 device
[1738749237.102] [63313:63315] [DMG] ICR moving to [AddingComm]
[1738749237.102] [63313:63315] [DMG] ICR moving to [AddedComma]
[1738749237.102] [63313:63315] [EM] <<< [E:41463i S:50401 M:220804408] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
[1738749237.102] [63313:63315] [DMG] ICR moving to [AwaitingRe]
[1738749237.102] [63313:63315] [DMG] ICR moving to [AwaitingDe]
[1738749237.190] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749237.238] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749237.238] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749237.328] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749237.328] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749237.416] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749237.416] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749237.416] [63313:63315] [EM] >>> [E:41463i S:50401 M:67719679] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:527)
[1738749237.416] [63313:63315] [EM] Found matching exchange: 41463i, Delegate: 0x763dd4014078
[1738749237.416] [63313:63315] [DMG] ICR moving to [ResponseRe]
[1738749237.416] [63313:63315] [DMG] InvokeResponseMessage =
[1738749237.416] [63313:63315] [DMG] {
[1738749237.416] [63313:63315] [DMG] 	suppressResponse = false, 
[1738749237.416] [63313:63315] [DMG] 	InvokeResponseIBs =
[1738749237.416] [63313:63315] [DMG] 	[
[1738749237.416] [63313:63315] [DMG] 		InvokeResponseIB =
[1738749237.416] [63313:63315] [DMG] 		{
[1738749237.416] [63313:63315] [DMG] 			CommandDataIB =
[1738749237.416] [63313:63315] [DMG] 			{
[1738749237.416] [63313:63315] [DMG] 				CommandPathIB =
[1738749237.416] [63313:63315] [DMG] 				{
[1738749237.416] [63313:63315] [DMG] 					EndpointId = 0x0,
[1738749237.416] [63313:63315] [DMG] 					ClusterId = 0x3e,
[1738749237.416] [63313:63315] [DMG] 					CommandId = 0x3,
[1738749237.416] [63313:63315] [DMG] 				},
[1738749237.416] [63313:63315] [DMG] 				
[1738749237.416] [63313:63315] [DMG] 				CommandFields = 
[1738749237.416] [63313:63315] [DMG] 				{
[1738749237.416] [63313:63315] [DMG] 					0x0 = [
[1738749237.416] [63313:63315] [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
[1738749237.416] [63313:63315] [DMG] 					] (463 bytes)
[1738749237.416] [63313:63315] [DMG] 				},
[1738749237.416] [63313:63315] [DMG] 			},
[1738749237.416] [63313:63315] [DMG] 			
[1738749237.416] [63313:63315] [DMG] 		},
[1738749237.416] [63313:63315] [DMG] 		
[1738749237.416] [63313:63315] [DMG] 	],
[1738749237.416] [63313:63315] [DMG] 	
[1738749237.416] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749237.416] [63313:63315] [DMG] },
[1738749237.416] [63313:63315] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1738749237.416] [63313:63315] [CTL] Received certificate chain from the device
[1738749237.416] [63313:63315] [CTL] Successfully finished commissioning step 'SendPAICertificateRequest'
[1738749237.416] [63313:63315] [CTL] Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1738749237.416] [63313:63315] [CTL] Performing next commissioning step 'SendDACCertificateRequest'
[1738749237.416] [63313:63315] [CTL] Sending request for DAC certificate
[1738749237.416] [63313:63315] [CTL] Sending Certificate Chain request to 0x763dd4034d70 device
[1738749237.417] [63313:63315] [DMG] ICR moving to [AddingComm]
[1738749237.417] [63313:63315] [DMG] ICR moving to [AddedComma]
[1738749237.417] [63313:63315] [EM] <<< [E:41464i S:50401 M:220804409] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:62)
[1738749237.417] [63313:63315] [DMG] ICR moving to [AwaitingRe]
[1738749237.417] [63313:63315] [DMG] ICR moving to [AwaitingDe]
[1738749237.506] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749237.599] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749237.599] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749237.689] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749237.689] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749237.776] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749237.776] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749237.776] [63313:63315] [EM] >>> [E:41464i S:50401 M:67719680] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:556)
[1738749237.776] [63313:63315] [EM] Found matching exchange: 41464i, Delegate: 0x763dd403c038
[1738749237.776] [63313:63315] [DMG] ICR moving to [ResponseRe]
[1738749237.776] [63313:63315] [DMG] InvokeResponseMessage =
[1738749237.776] [63313:63315] [DMG] {
[1738749237.776] [63313:63315] [DMG] 	suppressResponse = false, 
[1738749237.776] [63313:63315] [DMG] 	InvokeResponseIBs =
[1738749237.776] [63313:63315] [DMG] 	[
[1738749237.776] [63313:63315] [DMG] 		InvokeResponseIB =
[1738749237.776] [63313:63315] [DMG] 		{
[1738749237.776] [63313:63315] [DMG] 			CommandDataIB =
[1738749237.776] [63313:63315] [DMG] 			{
[1738749237.776] [63313:63315] [DMG] 				CommandPathIB =
[1738749237.776] [63313:63315] [DMG] 				{
[1738749237.776] [63313:63315] [DMG] 					EndpointId = 0x0,
[1738749237.776] [63313:63315] [DMG] 					ClusterId = 0x3e,
[1738749237.776] [63313:63315] [DMG] 					CommandId = 0x3,
[1738749237.776] [63313:63315] [DMG] 				},
[1738749237.776] [63313:63315] [DMG] 				
[1738749237.776] [63313:63315] [DMG] 				CommandFields = 
[1738749237.776] [63313:63315] [DMG] 				{
[1738749237.776] [63313:63315] [DMG] 					0x0 = [
[1738749237.776] [63313:63315] [DMG] 							0x30, 0x82, 0x01, 0xe8, 0x30, 0x82, 0x01, 0x8e, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x6f, 0xdc, 0xb6, 0xed, 0x06, 0xf3, 0x58, 0xf9, 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, 0x35, 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, 0x35, 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, 0x7e, 0xf2, 0xf1, 0x08, 0x2b, 0x2a, 0x56, 0x4a, 0x05, 0x44, 0xc0, 0xa6, 0x13, 0xd2, 0x1b, 0x15, 0x75, 0x00, 0x55, 0x2d, 0x03, 0x5f, 0x23, 0x02, 0x25, 0x2f, 0xce, 0xe8, 0x1d, 0x6e, 0xc6, 0x74, 0x17, 0x34, 0x18, 0xa9, 0x4a, 0x88, 0xdb, 0x
[1738749237.776] [63313:63315] [DMG] 					] (492 bytes)
[1738749237.776] [63313:63315] [DMG] 				},
[1738749237.776] [63313:63315] [DMG] 			},
[1738749237.776] [63313:63315] [DMG] 			
[1738749237.776] [63313:63315] [DMG] 		},
[1738749237.776] [63313:63315] [DMG] 		
[1738749237.776] [63313:63315] [DMG] 	],
[1738749237.776] [63313:63315] [DMG] 	
[1738749237.776] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749237.776] [63313:63315] [DMG] },
[1738749237.776] [63313:63315] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1738749237.776] [63313:63315] [CTL] Received certificate chain from the device
[1738749237.777] [63313:63315] [CTL] Successfully finished commissioning step 'SendDACCertificateRequest'
[1738749237.777] [63313:63315] [CTL] Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1738749237.777] [63313:63315] [CTL] Performing next commissioning step 'SendAttestationRequest'
[1738749237.777] [63313:63315] [CTL] Sending Attestation Request to the device.
[1738749237.777] [63313:63315] [CTL] Sending Attestation request to 0x763dd4034d70 device
[1738749237.777] [63313:63315] [DMG] ICR moving to [AddingComm]
[1738749237.777] [63313:63315] [DMG] ICR moving to [AddedComma]
[1738749237.777] [63313:63315] [EM] <<< [E:41465i S:50401 M:220804410] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
[1738749237.777] [63313:63315] [DMG] ICR moving to [AwaitingRe]
[1738749237.777] [63313:63315] [CTL] Sent Attestation request, waiting for the Attestation Information
[1738749237.777] [63313:63315] [DMG] ICR moving to [AwaitingDe]
[1738749237.865] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749237.958] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749237.958] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749238.051] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749238.051] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749238.138] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749238.138] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749238.138] [63313:63315] [EM] >>> [E:41465i S:50401 M:67719681] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:716)
[1738749238.138] [63313:63315] [EM] Found matching exchange: 41465i, Delegate: 0x763dd4014078
[1738749238.138] [63313:63315] [DMG] ICR moving to [ResponseRe]
[1738749238.138] [63313:63315] [DMG] InvokeResponseMessage =
[1738749238.138] [63313:63315] [DMG] {
[1738749238.138] [63313:63315] [DMG] 	suppressResponse = false, 
[1738749238.138] [63313:63315] [DMG] 	InvokeResponseIBs =
[1738749238.138] [63313:63315] [DMG] 	[
[1738749238.138] [63313:63315] [DMG] 		InvokeResponseIB =
[1738749238.138] [63313:63315] [DMG] 		{
[1738749238.138] [63313:63315] [DMG] 			CommandDataIB =
[1738749238.138] [63313:63315] [DMG] 			{
[1738749238.138] [63313:63315] [DMG] 				CommandPathIB =
[1738749238.138] [63313:63315] [DMG] 				{
[1738749238.138] [63313:63315] [DMG] 					EndpointId = 0x0,
[1738749238.138] [63313:63315] [DMG] 					ClusterId = 0x3e,
[1738749238.138] [63313:63315] [DMG] 					CommandId = 0x1,
[1738749238.138] [63313:63315] [DMG] 				},
[1738749238.138] [63313:63315] [DMG] 				
[1738749238.138] [63313:63315] [DMG] 				CommandFields = 
[1738749238.138] [63313:63315] [DMG] 				{
[1738749238.138] [63313:63315] [DMG] 					0x0 = [
[1738749238.139] [63313:63315] [DMG] 							0x15, 0x31, 0x01, 0x1d, 0x02, 0x30, 0x82, 0x02, 0x19, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x02, 0xa0, 0x82, 0x02, 0x0a, 0x30, 0x82, 0x02, 0x06, 0x02, 0x01, 0x03, 0x31, 0x0d, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x82, 0x01, 0x71, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x01, 0xa0, 0x82, 0x01, 0x62, 0x04, 0x82, 0x01, 0x5e, 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
[1738749238.139] [63313:63315] [DMG] 					] (585 bytes)
[1738749238.139] [63313:63315] [DMG] 					0x1 = [
[1738749238.139] [63313:63315] [DMG] 							0x8b, 0x4f, 0x83, 0x4e, 0x60, 0x51, 0xce, 0xd6, 0xb0, 0x52, 0xfa, 0x78, 0xd8, 0x24, 0xe7, 0xc1, 0x41, 0x4d, 0x5d, 0x26, 0xaf, 0x93, 0x3d, 0x5c, 0x94, 0x7d, 0x9a, 0xb5, 0x4c, 0x1e, 0xc6, 0xd7, 0xb3, 0x55, 0x2a, 0x76, 0x78, 0x25, 0x6b, 0x24, 0x59, 0xf9, 0x7e, 0x01, 0xcb, 0x64, 0xac, 0x34, 0x70, 0xc9, 0x4c, 0x3f, 0x2d, 0xb0, 0xc4, 0x0e, 0x66, 0x19, 0x6e, 0x0c, 0x4e, 0xdd, 0x2a, 0x04, 
[1738749238.139] [63313:63315] [DMG] 					] (64 bytes)
[1738749238.139] [63313:63315] [DMG] 				},
[1738749238.139] [63313:63315] [DMG] 			},
[1738749238.139] [63313:63315] [DMG] 			
[1738749238.139] [63313:63315] [DMG] 		},
[1738749238.139] [63313:63315] [DMG] 		
[1738749238.139] [63313:63315] [DMG] 	],
[1738749238.139] [63313:63315] [DMG] 	
[1738749238.139] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749238.139] [63313:63315] [DMG] },
[1738749238.139] [63313:63315] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1738749238.139] [63313:63315] [CTL] Received Attestation Information from the device
[1738749238.139] [63313:63315] [CTL] Successfully finished commissioning step 'SendAttestationRequest'
[1738749238.139] [63313:63315] [CTL] AutoCommissioner setting attestationElements buffer size 585/585
[1738749238.139] [63313:63315] [CTL] Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1738749238.139] [63313:63315] [CTL] Performing next commissioning step 'AttestationVerification'
[1738749238.139] [63313:63315] [CTL] Verifying attestation
[1738749238.150] [63313:63315] [CTL] Successfully finished commissioning step 'AttestationVerification'
[1738749238.150] [63313:63315] [CTL] Commissioning stage next step: 'AttestationVerification' -> 'AttestationRevocationCheck'
[1738749238.150] [63313:63315] [CTL] Performing next commissioning step 'AttestationRevocationCheck'
[1738749238.150] [63313:63315] [CTL] Verifying device's DAC chain revocation status
[1738749238.150] [63313:63315] [CTL] Successfully validated 'Attestation Information' command received from the device.
[1738749238.150] [63313:63315] [CTL] Successfully finished commissioning step 'AttestationRevocationCheck'
[1738749238.150] [63313:63315] [CTL] Commissioning stage next step: 'AttestationRevocationCheck' -> 'SendOpCertSigningRequest'
[1738749238.150] [63313:63315] [CTL] Performing next commissioning step 'SendOpCertSigningRequest'
[1738749238.150] [63313:63315] [CTL] Sending CSR request to 0x763dd4034d70 device
[1738749238.150] [63313:63315] [DMG] ICR moving to [AddingComm]
[1738749238.150] [63313:63315] [DMG] ICR moving to [AddedComma]
[1738749238.150] [63313:63315] [EM] <<< [E:41466i S:50401 M:220804411] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:94)
[1738749238.151] [63313:63315] [DMG] ICR moving to [AwaitingRe]
[1738749238.151] [63313:63315] [CTL] Sent CSR request, waiting for the CSR
[1738749238.151] [63313:63315] [DMG] ICR moving to [AwaitingDe]
[1738749238.225] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749238.363] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749238.363] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749238.498] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749238.498] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749238.498] [63313:63315] [EM] >>> [E:41466i S:50401 M:67719682] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:392)
[1738749238.498] [63313:63315] [EM] Found matching exchange: 41466i, Delegate: 0x763dd403c038
[1738749238.498] [63313:63315] [DMG] ICR moving to [ResponseRe]
[1738749238.498] [63313:63315] [DMG] InvokeResponseMessage =
[1738749238.498] [63313:63315] [DMG] {
[1738749238.498] [63313:63315] [DMG] 	suppressResponse = false, 
[1738749238.498] [63313:63315] [DMG] 	InvokeResponseIBs =
[1738749238.498] [63313:63315] [DMG] 	[
[1738749238.498] [63313:63315] [DMG] 		InvokeResponseIB =
[1738749238.498] [63313:63315] [DMG] 		{
[1738749238.498] [63313:63315] [DMG] 			CommandDataIB =
[1738749238.498] [63313:63315] [DMG] 			{
[1738749238.498] [63313:63315] [DMG] 				CommandPathIB =
[1738749238.498] [63313:63315] [DMG] 				{
[1738749238.498] [63313:63315] [DMG] 					EndpointId = 0x0,
[1738749238.498] [63313:63315] [DMG] 					ClusterId = 0x3e,
[1738749238.498] [63313:63315] [DMG] 					CommandId = 0x5,
[1738749238.498] [63313:63315] [DMG] 				},
[1738749238.498] [63313:63315] [DMG] 				
[1738749238.498] [63313:63315] [DMG] 				CommandFields = 
[1738749238.498] [63313:63315] [DMG] 				{
[1738749238.498] [63313:63315] [DMG] 					0x0 = [
[1738749238.498] [63313:63315] [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, 0xcb, 0xde, 0xe1, 0x33, 0xe8, 0x96, 0x94, 0x8c, 0x5a, 0x08, 0xf9, 0xe5, 0xfa, 0x2e, 0x6e, 0xea, 0x3f, 0xbd, 0xa8, 0x50, 0x0e, 0xfd, 0x66, 0xa0, 0x53, 0x0c, 0xec, 0x8b, 0xc7, 0xad, 0x1c, 0xa0, 0xe5, 0xba, 0xc6, 0x07, 0x30, 0x2f, 0x89, 0x17, 0x28, 0x71, 0xda, 0x5b, 0xf6, 0x12, 0x41, 0x8e, 0x1c, 0x46, 0xd5, 0x08, 0x39, 0xb5, 0x54, 0x97, 0xc8, 0x20, 0x88, 0xf4, 0xa0, 0x98, 0xd8, 0x54, 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, 0xf8, 0xd1, 0x4f, 0x0f, 0x7b, 0xae, 0x18, 0x79, 0x4e, 0x6d, 0x06, 0x9c, 0x35, 0x1a, 0xc5, 0xe8, 0x9c, 0x0a, 0xc5, 0x73, 0x96, 0x46, 0x1f, 0xa9, 0x73, 0xb7, 0x80, 0xa3, 0x20, 0xbb, 0x61, 0xf6, 0x02, 0x20, 0x70, 0xec, 0x2a, 0x0b, 0xb8, 0xea, 0xec, 0x4c, 0xcd, 0xf9, 0xc8, 0x32, 0x52, 0xa3, 0x8e, 0x37, 0xfa, 0x88, 0x60, 0x5b, 0x8f, 0xf8, 0x89, 0x1b, 0x84, 0x7c, 0x5b, 0xfc, 0x00, 0xe5, 0x6a, 0x9e, 0x30, 0x02, 0x20, 0x4c, 0x8d, 0x33, 0xf0, 0x3a, 0x67, 0xaf, 0xce, 0xc6, 0xd0, 0x9f, 0x55, 0x7c, 0x99, 0x0d, 0xb2, 0xb1, 0x09, 0x86, 0xad, 0xd8, 0x87, 0x4c, 0x2f, 0x4d, 0xc4, 0x52, 0x99, 0xdb, 0x43, 0xe4, 0xdc, 0x18, 
[1738749238.498] [63313:63315] [DMG] 					] (261 bytes)
[1738749238.498] [63313:63315] [DMG] 					0x1 = [
[1738749238.498] [63313:63315] [DMG] 							0x4c, 0x53, 0x8c, 0xf0, 0x39, 0x70, 0xb2, 0xf7, 0x40, 0xc7, 0xac, 0x6e, 0xc1, 0xb3, 0xa8, 0xdc, 0x0b, 0x99, 0x01, 0xf3, 0x62, 0x8e, 0x37, 0x41, 0x78, 0xa4, 0x61, 0xac, 0x37, 0xf5, 0xf9, 0xc9, 0xa9, 0xce, 0x23, 0xbc, 0x81, 0xa3, 0xda, 0x7e, 0x1f, 0x50, 0x22, 0x93, 0xb4, 0xa7, 0xef, 0x25, 0x86, 0x07, 0x84, 0x4b, 0x7a, 0xaf, 0x7a, 0x9c, 0xb6, 0xb5, 0xb5, 0xc5, 0xe9, 0x2c, 0xbe, 0x2b, 
[1738749238.498] [63313:63315] [DMG] 					] (64 bytes)
[1738749238.498] [63313:63315] [DMG] 				},
[1738749238.498] [63313:63315] [DMG] 			},
[1738749238.498] [63313:63315] [DMG] 			
[1738749238.498] [63313:63315] [DMG] 		},
[1738749238.498] [63313:63315] [DMG] 		
[1738749238.498] [63313:63315] [DMG] 	],
[1738749238.498] [63313:63315] [DMG] 	
[1738749238.498] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749238.498] [63313:63315] [DMG] },
[1738749238.498] [63313:63315] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1738749238.498] [63313:63315] [CTL] Received certificate signing request from the device
[1738749238.498] [63313:63315] [CTL] Successfully finished commissioning step 'SendOpCertSigningRequest'
[1738749238.498] [63313:63315] [CTL] Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR'
[1738749238.498] [63313:63315] [CTL] Performing next commissioning step 'ValidateCSR'
[1738749238.500] [63313:63315] [CTL] Successfully finished commissioning step 'ValidateCSR'
[1738749238.500] [63313:63315] [CTL] Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain'
[1738749238.500] [63313:63315] [CTL] Performing next commissioning step 'GenerateNOCChain'
[1738749238.500] [63313:63315] [CTL] Getting certificate chain for the device from the issuer
[1738749238.502] [63313:63315] [CTL] Verifying Certificate Signing Request
[1738749238.503] [63313:63315] [CTL] Generating NOC
[1738749238.503] [63313:63315] [CTL] Providing certificate chain to the commissioner
[1738749238.503] [63313:63315] [CTL] Received callback from the CA for NOC Chain generation. Status src/controller/ExampleOperationalCredentialsIssuer.cpp:395: Success
[1738749238.503] [63313:63315] [CTL] Successfully finished commissioning step 'GenerateNOCChain'
[1738749238.503] [63313:63315] [CTL] Performing next commissioning step 'SendTrustedRootCert'
[1738749238.503] [63313:63315] [CTL] Sending root certificate to the device
[1738749238.503] [63313:63315] [DMG] ICR moving to [AddingComm]
[1738749238.503] [63313:63315] [DMG] ICR moving to [AddedComma]
[1738749238.503] [63313:63315] [EM] <<< [E:41467i S:50401 M:220804412] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:293)
[1738749238.505] [63313:63315] [DMG] ICR moving to [AwaitingRe]
[1738749238.505] [63313:63315] [CTL] Sent root certificate to the device
[1738749238.505] [63313:63315] [DMG] ICR moving to [AwaitingDe]
[1738749238.588] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749238.676] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749238.766] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749238.766] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749238.766] [63313:63315] [EM] >>> [E:41467i S:50401 M:67719683] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
[1738749238.766] [63313:63315] [EM] Found matching exchange: 41467i, Delegate: 0x763dd4014078
[1738749238.766] [63313:63315] [DMG] ICR moving to [ResponseRe]
[1738749238.766] [63313:63315] [DMG] InvokeResponseMessage =
[1738749238.766] [63313:63315] [DMG] {
[1738749238.766] [63313:63315] [DMG] 	suppressResponse = false, 
[1738749238.766] [63313:63315] [DMG] 	InvokeResponseIBs =
[1738749238.766] [63313:63315] [DMG] 	[
[1738749238.766] [63313:63315] [DMG] 		InvokeResponseIB =
[1738749238.766] [63313:63315] [DMG] 		{
[1738749238.766] [63313:63315] [DMG] 			CommandStatusIB =
[1738749238.766] [63313:63315] [DMG] 			{
[1738749238.766] [63313:63315] [DMG] 				CommandPathIB =
[1738749238.766] [63313:63315] [DMG] 				{
[1738749238.766] [63313:63315] [DMG] 					EndpointId = 0x0,
[1738749238.766] [63313:63315] [DMG] 					ClusterId = 0x3e,
[1738749238.766] [63313:63315] [DMG] 					CommandId = 0xb,
[1738749238.766] [63313:63315] [DMG] 				},
[1738749238.766] [63313:63315] [DMG] 				
[1738749238.766] [63313:63315] [DMG] 				StatusIB =
[1738749238.766] [63313:63315] [DMG] 				{
[1738749238.766] [63313:63315] [DMG] 					status = 0x00 (SUCCESS),
[1738749238.766] [63313:63315] [DMG] 				},
[1738749238.766] [63313:63315] [DMG] 				
[1738749238.766] [63313:63315] [DMG] 			},
[1738749238.766] [63313:63315] [DMG] 			
[1738749238.766] [63313:63315] [DMG] 		},
[1738749238.766] [63313:63315] [DMG] 		
[1738749238.766] [63313:63315] [DMG] 	],
[1738749238.766] [63313:63315] [DMG] 	
[1738749238.766] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749238.766] [63313:63315] [DMG] },
[1738749238.766] [63313:63315] [DMG] Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1738749238.766] [63313:63315] [CTL] Device confirmed that it has received the root certificate
[1738749238.767] [63313:63315] [CTL] Successfully finished commissioning step 'SendTrustedRootCert'
[1738749238.767] [63313:63315] [CTL] Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
[1738749238.767] [63313:63315] [CTL] Performing next commissioning step 'SendNOC'
[1738749238.767] [63313:63315] [DMG] ICR moving to [AddingComm]
[1738749238.767] [63313:63315] [DMG] ICR moving to [AddedComma]
[1738749238.767] [63313:63315] [EM] <<< [E:41468i S:50401 M:220804413] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:567)
[1738749238.767] [63313:63315] [DMG] ICR moving to [AwaitingRe]
[1738749238.767] [63313:63315] [CTL] Sent operational certificate to the device
[1738749238.767] [63313:63315] [DMG] ICR moving to [AwaitingDe]
[1738749238.855] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749238.945] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749239.037] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749239.265] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749239.265] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749239.265] [63313:63315] [EM] >>> [E:41468i S:50401 M:67719684] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:66)
[1738749239.265] [63313:63315] [EM] Found matching exchange: 41468i, Delegate: 0x763dd403c038
[1738749239.265] [63313:63315] [DMG] ICR moving to [ResponseRe]
[1738749239.265] [63313:63315] [DMG] InvokeResponseMessage =
[1738749239.265] [63313:63315] [DMG] {
[1738749239.265] [63313:63315] [DMG] 	suppressResponse = false, 
[1738749239.265] [63313:63315] [DMG] 	InvokeResponseIBs =
[1738749239.265] [63313:63315] [DMG] 	[
[1738749239.265] [63313:63315] [DMG] 		InvokeResponseIB =
[1738749239.265] [63313:63315] [DMG] 		{
[1738749239.265] [63313:63315] [DMG] 			CommandDataIB =
[1738749239.265] [63313:63315] [DMG] 			{
[1738749239.265] [63313:63315] [DMG] 				CommandPathIB =
[1738749239.265] [63313:63315] [DMG] 				{
[1738749239.265] [63313:63315] [DMG] 					EndpointId = 0x0,
[1738749239.265] [63313:63315] [DMG] 					ClusterId = 0x3e,
[1738749239.265] [63313:63315] [DMG] 					CommandId = 0x8,
[1738749239.265] [63313:63315] [DMG] 				},
[1738749239.265] [63313:63315] [DMG] 				
[1738749239.265] [63313:63315] [DMG] 				CommandFields = 
[1738749239.265] [63313:63315] [DMG] 				{
[1738749239.265] [63313:63315] [DMG] 					0x0 = 0 (unsigned), 
[1738749239.265] [63313:63315] [DMG] 					0x1 = 1 (unsigned), 
[1738749239.265] [63313:63315] [DMG] 				},
[1738749239.265] [63313:63315] [DMG] 			},
[1738749239.265] [63313:63315] [DMG] 			
[1738749239.265] [63313:63315] [DMG] 		},
[1738749239.265] [63313:63315] [DMG] 		
[1738749239.265] [63313:63315] [DMG] 	],
[1738749239.265] [63313:63315] [DMG] 	
[1738749239.265] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749239.265] [63313:63315] [DMG] },
[1738749239.265] [63313:63315] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1738749239.265] [63313:63315] [CTL] Device returned status 0 on receiving the NOC
[1738749239.265] [63313:63315] [CTL] Operational credentials provisioned on device 0x763dd4034d70
[1738749239.265] [63313:63315] [TOO] Secure Pairing Success
[1738749239.265] [63313:63315] [TOO] CASE establishment successful
[1738749239.265] [63313:63315] [CTL] Successfully finished commissioning step 'SendNOC'
[1738749239.265] [63313:63315] [CTL] No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks
[1738749239.265] [63313:63315] [CTL] Commissioning stage next step: 'SendNOC' -> 'ThreadNetworkSetup'
[1738749239.265] [63313:63315] [CTL] Performing next commissioning step 'ThreadNetworkSetup'
[1738749239.266] [63313:63315] [DMG] ICR moving to [AddingComm]
[1738749239.266] [63313:63315] [DMG] ICR moving to [AddedComma]
[1738749239.266] [63313:63315] [EM] <<< [E:41469i S:50401 M:220804414] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest) (B:287)
[1738749239.266] [63313:63315] [DMG] ICR moving to [AwaitingRe]
[1738749239.266] [63313:63315] [DMG] ICR moving to [AwaitingDe]
[1738749239.351] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749239.440] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749239.488] [63313:63314] [DL] Indication received, conn = 0x763dc8014430
[1738749239.488] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16391
[1738749239.488] [63313:63315] [EM] >>> [E:41469i S:50401 M:67719685] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 --- Type 0001:09 (IM:InvokeCommandResponse) (B:63)
[1738749239.488] [63313:63315] [EM] Found matching exchange: 41469i, Delegate: 0x763dd4014078
[1738749239.488] [63313:63315] [DMG] ICR moving to [ResponseRe]
[1738749239.488] [63313:63315] [DMG] InvokeResponseMessage =
[1738749239.488] [63313:63315] [DMG] {
[1738749239.489] [63313:63315] [DMG] 	suppressResponse = false, 
[1738749239.489] [63313:63315] [DMG] 	InvokeResponseIBs =
[1738749239.489] [63313:63315] [DMG] 	[
[1738749239.489] [63313:63315] [DMG] 		InvokeResponseIB =
[1738749239.489] [63313:63315] [DMG] 		{
[1738749239.489] [63313:63315] [DMG] 			CommandDataIB =
[1738749239.489] [63313:63315] [DMG] 			{
[1738749239.489] [63313:63315] [DMG] 				CommandPathIB =
[1738749239.489] [63313:63315] [DMG] 				{
[1738749239.489] [63313:63315] [DMG] 					EndpointId = 0x0,
[1738749239.489] [63313:63315] [DMG] 					ClusterId = 0x31,
[1738749239.489] [63313:63315] [DMG] 					CommandId = 0x5,
[1738749239.489] [63313:63315] [DMG] 				},
[1738749239.489] [63313:63315] [DMG] 				
[1738749239.489] [63313:63315] [DMG] 				CommandFields = 
[1738749239.489] [63313:63315] [DMG] 				{
[1738749239.489] [63313:63315] [DMG] 					0x0 = 1 (unsigned), 
[1738749239.489] [63313:63315] [DMG] 				},
[1738749239.490] [63313:63315] [DMG] 			},
[1738749239.490] [63313:63315] [DMG] 			
[1738749239.490] [63313:63315] [DMG] 		},
[1738749239.490] [63313:63315] [DMG] 		
[1738749239.490] [63313:63315] [DMG] 	],
[1738749239.490] [63313:63315] [DMG] 	
[1738749239.490] [63313:63315] [DMG] 	InteractionModelRevision = 11
[1738749239.490] [63313:63315] [DMG] },
[1738749239.490] [63313:63315] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1738749239.490] [63313:63315] [CTL] Received NetworkConfig response, networkingStatus=1
[1738749239.490] [63313:63315] [CTL] Error on commissioning step 'ThreadNetworkSetup': 'src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error'
[1738749239.490] [63313:63315] [CTL] Going from commissioning step 'ThreadNetworkSetup' with lastErr = 'src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error' -> 'Cleanup'
[1738749239.490] [63313:63315] [CTL] Performing next commissioning step 'Cleanup' with completion status = 'src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error'
[1738749239.490] [63313:63315] [CTL] Successfully finished commissioning step 'Cleanup'
[1738749239.490] [63313:63315] [CTL] Commissioning complete for node ID 0x0000000000002221: src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error
[1738749239.490] [63313:63315] [TOO] Device commissioning Failure: src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error
[1738749239.490] [63313:63315] [TOO] Run command failure: src/controller/CHIPDeviceController.cpp:2775: CHIP Error 0x000000AC: Internal error
[1738749239.490] [63313:63315] [DMG] ICR moving to [AwaitingDe]
[1738749242.051] [63313:63315] [DL] HandlePlatformSpecificBLEEvent 16389
[1738749244.527] [63313:63314] [DL] Indication received, conn = 0x763dc8014430

Can you please check if anything is missing?

Best regards,

Bhavya

+1 Marte Myrvold 5 months ago in reply to Bhavya Mathukiya
Hi Bhavya,

The NetworkingStatus field of the NetworkConfigResponse is OutOfRange (1) and not Success (0).

[1738749239.490] [63313:63315] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005 [1738749239.490] [63313:63315] [CTL] Received NetworkConfig response, networkingStatus=1

This means that the network identifier was invalid, for example that it was empty, too long, etc.

This could happen if an invalid dataset is used to commission the device. In your case, it could be because you are missing hex: before the dataset in the pairing command. Please try the following command instead and see if that works:

pairing ble-thread 0x2221 hex:0e08000000000001000000030000164a0300001835060004001fffe00208b259765e36f15bf00708fd7c41ce3d2120bd05100d2d9619b628ad20c51cb905b4059c75030f4f70656e5468726561642d626336630102bc6c041021e09647f0703f06ccbaa010424147450c0402a0f7f8 20202021 3840

I also recommend looking at the Working with the CHIP Tool documentation for how to issue chip-tool commands.

Best regards,
Marte
Cancel
Vote Up +1 Vote Down

Sign in to reply

Reject Answer

Cancel