Matter Over Thread完整体验记录

        csa原本预计秋季要正式发布的matter到目前还没声音,目前从小道消息反馈估计可能又要延后了。近期也看到不少国内厂家跟进发布matter方案,如国产芯片esp32, telink,终端厂商aqara等都陆续有matter方案宣传出来。

        之前手头只有mg21板子,跑不了matter节点,当时只跑了matter网关需要用到的otbr。近期拿到了mg24板子,重新体验下整个matter over thread的流程。

        一、硬件先决条件

                1、matter节点,这里使用的是efr32mg24

                2、matter网关,这里使用的是树莓派4B

        二、软件先决条件

                1、基于matter仓库编译出来matter节点

                       构建可以参考Matter(CHIP)环境搭建_iot-lorawan的博客-优快云博客

                       仓库里有针对不同芯片平台的编译说明文档,整个过程建议需要科学上网处理下,编译过程只要是提示找不到文件之类的一般都是仓库下载不全导致。

                2、基于openthread编译出来obtr,用于网关段运行openthread边界路由功能

                        构建可以参考构建Matter Over Thread网关 BorderRouter_iot-lorawan的博客-优快云博客

                        同样整个过程建议需要科学上网处理

                3、基于matter仓库编译出来的chiptool,用于作为matter网络里的matter controller

                        直接参考官方的build参考构建。可不用编译直接运行的执行文件

https://download.youkuaiyun.com/download/hydfxy2018/86609121

                4、网关运行obtr要用到的rcp设备,不同厂商平台openthread都有提供对应的rcp构建仓库,GitHub - openthread/ot-efr32: OpenThread on Silicon Labs EFR32 examples.

        三、完整过程

               1、openthread组建网络,可以通过cli或者web

                2、获取thread网络信息


ubuntu@ubuntu:~$ sudo ot-ctl dataset active -x
0e080000000000010000000300000f35060004001fffe0020811111111222222220708fd7f58bddf499921051000112233445566778899aabbccddeeff030e4f70656                     e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8
Done

                3、烧录matter节点固件到mg24板子

                4、网关上运行chiptool进行配网

ubuntu@ubuntu:~$  ./chip-tool-debug pairing ble-thread 1 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fd7f58bddf499921051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8 20202021 3840
[1663741340.350495][2433:2433] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1663741340.350952][2433:2433] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1663741340.351106][2433:2433] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1663741340.351209][2433:2433] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1663741340.351509][2433:2433] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-1BnMZb)
[1663741340.352026][2433:2433] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1663741340.352075][2433:2433] CHIP:DL: NVS set: chip-counters/reboot-count = 6 (0x6)
[1663741340.352622][2433:2433] CHIP:DL: Got Ethernet interface: eth0
[1663741340.352947][2433:2433] CHIP:DL: Found the primary Ethernet interface:eth0
[1663741340.353293][2433:2433] CHIP:DL: Got WiFi interface: wlan0
[1663741340.353351][2433:2433] CHIP:DL: Failed to reset WiFi statistic counts
[1663741340.353401][2433:2433] CHIP:IN: UDP::Init bind&listen port=0
[1663741340.353497][2433:2433] CHIP:IN: UDP::Init bound to port=38911
[1663741340.353522][2433:2433] CHIP:IN: UDP::Init bind&listen port=0
[1663741340.353598][2433:2433] CHIP:IN: UDP::Init bound to port=57137
[1663741340.353619][2433:2433] CHIP:IN: BLEBase::Init - setting/overriding transport
[1663741340.353664][2433:2433] CHIP:IN: TransportMgr initialized
[1663741340.353701][2433:2433] CHIP:FP: Initializing FabricTable from persistent storage
[1663741340.353841][2433:2433] CHIP:TS: Last Known Good Time: 2022-09-15T11:07:06
[1663741340.354262][2433:2433] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x1AE61EA264E81D69, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1663741340.358935][2433:2433] CHIP:ZCL: Using ZAP configuration...
[1663741340.363399][2433:2433] CHIP:DL: Avahi client registered
[1663741340.364873][2433:2433] CHIP:CTL: System State Initialized...
[1663741340.365011][2433:2433] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1663741340.365071][2433:2433] CHIP:CTL: Setting attestation nonce to random value
[1663741340.365131][2433:2433] CHIP:CTL: Setting CSR nonce to random value
[1663741340.365390][2433:2442] CHIP:DL: CHIP task running
[1663741340.365606][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1663741340.365726][2433:2442] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1663741340.365770][2433:2442] CHIP:CTL: Setting attestation nonce to random value
[1663741340.365902][2433:2442] CHIP:CTL: Setting CSR nonce to random value
[1663741340.369233][2433:2442] CHIP:CTL: Generating NOC
[1663741340.370671][2433:2442] CHIP:FP: Validating NOC chain
[1663741340.372869][2433:2442] CHIP:FP: NOC chain validation successful
[1663741340.373058][2433:2442] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1663741340.373094][2433:2442] CHIP:TS: Last Known Good Time: 2022-09-15T11:07:06
[1663741340.373120][2433:2442] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1663741340.373143][2433:2442] CHIP:TS: Retaining current Last Known Good Time
[1663741340.378433][2433:2442] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1663741340.380746][2433:2442] CHIP:TS: Committing Last Known Good Time to storage: 2022-09-15T11:07:06
[1663741340.387026][2433:2442] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x0000000000000000
[1663741340.456812][2433:2442] CHIP:IN: SecureSession[0xffffa0020d20]: Allocated Type:1 LSID:15207
[1663741340.456956][2433:2442] CHIP:SC: Assigned local session key ID 15207
[1663741340.457095][2433:2442] CHIP:SC: Including MRP parameters in PBKDF param request
[1663741340.457226][2433:2442] CHIP:IN: Prepared unauthenticated message 0xffffb2ffbdd8 to 0x0000000000000000 (0)  of type 0x20 and protocolId (0, 0) on exchange 51163i with MessageCounter:102454460.
[1663741340.457315][2433:2442] CHIP:IN: Sending unauthenticated msg 0xffffb2ffbdd8 with MessageCounter:102454460 to 0x0000000000000000 at monotonic time: 000000000006D9EB msec
[1663741340.457384][2433:2442] CHIP:IN: Message appended to BLE send queue
[1663741340.457435][2433:2442] CHIP:SC: Sent PBKDF param request
[1663741340.457492][2433:2442] CHIP:CTL: Setting thread operational dataset from parameters
[1663741340.457538][2433:2442] CHIP:CTL: Setting attempt thread scan from parameters
[1663741340.457584][2433:2442] CHIP:CTL: Setting attestation nonce to random value
[1663741340.457740][2433:2442] CHIP:CTL: Setting CSR nonce to random value
[1663741340.457846][2433:2442] CHIP:CTL: Commission called for node ID 0x0000000000000001
[1663741340.458223][2433:2443] CHIP:DL: TRACE: Bluez mainloop starting Thread
[1663741340.458705][2433:2440] CHIP:DL: TRACE: Bus acquired for name C-0981
[1663741340.467988][2433:2442] CHIP:DL: PlatformBlueZInit init success
[1663741340.474037][2433:2440] CHIP:BLE: BLE removing known devices.
[1663741340.475655][2433:2440] CHIP:BLE: BLE initiating scan.
[1663741340.506106][2433:2440] CHIP:BLE: Device 9C:19:C2:2A:81:5B does not look like a CHIP device.
[1663741340.513693][2433:2440] CHIP:BLE: New device scanned: B4:3A:31:29:D7:0A
[1663741340.513755][2433:2440] CHIP:BLE: Device discriminator match. Attempting to connect.
[1663741340.517133][2433:2440] CHIP:BLE: Scan complete notification without an active scan.
[1663741340.735994][2433:2440] CHIP:DL: ConnectDevice complete
[1663741341.402993][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0001
[1663741341.403042][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403069][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0001
[1663741341.403089][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403110][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0001
[1663741341.403129][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403156][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0001
[1663741341.403175][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403196][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0001
[1663741341.403214][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403235][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0001
[1663741341.403252][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403277][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service000e
[1663741341.403295][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403316][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service000e
[1663741341.403334][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403354][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service000e
[1663741341.403372][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403397][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0001
[1663741341.403415][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403436][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0001
[1663741341.403454][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403475][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0001
[1663741341.403492][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403516][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403534][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403556][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403574][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403599][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403617][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403640][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403657][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403679][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403697][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403721][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service000e
[1663741341.403739][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403760][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service000e
[1663741341.403779][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403799][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service000e
[1663741341.403817][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403843][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service000e
[1663741341.403860][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403881][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service000e
[1663741341.403898][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403919][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service000e
[1663741341.403937][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403960][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service001d
[1663741341.403978][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.403999][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service001d
[1663741341.404016][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.404037][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service001d
[1663741341.404055][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.404078][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.404095][2433:2440] CHIP:DL: Char1 /org/bluez/hci0/dev_B4_3A_31_29_D7_0A/service0015
[1663741341.404125][2433:2440] CHIP:DL: New BLE connection 0xffffa8043980, device B4:3A:31:29:D7:0A, path /org/bluez/hci0/dev_B4_3A_31_29_D7_0A
[1663741341.404230][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16385
[1663741341.404269][2433:2442] CHIP:IN: BleConnectionComplete: endPoint 0xaaaad284d328
[1663741341.658485][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741341.756560][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1663741341.756646][2433:2442] CHIP:BLE: subscribe complete, ep = 0xaaaad284d328
[1663741341.757047][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741341.757217][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741341.757280][2433:2442] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4
[1663741341.757330][2433:2442] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244.
[1663741341.757373][2433:2442] CHIP:BLE: local and remote recv window size = 5
[1663741341.757560][2433:2442] CHIP:IN: BLE EndPoint 0xaaaad284d328 Connection Complete
[1663741341.853140][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741341.856154][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741341.856348][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741341.856544][2433:2442] CHIP:EM: Received message of type 0x21 with protocolId (0, 0) and MessageCounter:131632001 on exchange 51163i
[1663741341.856613][2433:2442] CHIP:EM: Found matching exchange: 51163i, Delegate: 0xffffa0022a60
[1663741341.856693][2433:2442] CHIP:SC: Received PBKDF param response
[1663741341.856773][2433:2442] CHIP:SC: Peer assigned session ID 5923
[1663741341.856842][2433:2442] CHIP:SC: Found MRP parameters in the message
[1663741341.869041][2433:2442] CHIP:IN: Prepared unauthenticated message 0xffffb2ffb968 to 0x0000000000000000 (0)  of type 0x22 and protocolId (0, 0) on exchange 51163i with MessageCounter:102454461.
[1663741341.869097][2433:2442] CHIP:IN: Sending unauthenticated msg 0xffffb2ffb968 with MessageCounter:102454461 to 0x0000000000000000 at monotonic time: 000000000006DF6F msec
[1663741341.869211][2433:2442] CHIP:SC: Sent spake2p msg1
[1663741341.950880][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741343.805866][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741343.806101][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741343.806306][2433:2442] CHIP:EM: Received message of type 0x23 with protocolId (0, 0) and MessageCounter:131632002 on exchange 51163i
[1663741343.806373][2433:2442] CHIP:EM: Found matching exchange: 51163i, Delegate: 0xffffa0022a60
[1663741343.806451][2433:2442] CHIP:SC: Received spake2p msg2
[1663741343.809437][2433:2442] CHIP:IN: Prepared unauthenticated message 0xffffb2ffbaa8 to 0x0000000000000000 (0)  of type 0x24 and protocolId (0, 0) on exchange 51163i with MessageCounter:102454462.
[1663741343.809529][2433:2442] CHIP:IN: Sending unauthenticated msg 0xffffb2ffbaa8 with MessageCounter:102454462 to 0x0000000000000000 at monotonic time: 000000000006E703 msec
[1663741343.809746][2433:2442] CHIP:SC: Sent spake2p msg3
[1663741343.900928][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741343.902735][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741343.902938][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741343.903142][2433:2442] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:131632003 on exchange 51163i
[1663741343.903211][2433:2442] CHIP:EM: Found matching exchange: 51163i, Delegate: 0xffffa0022a60
[1663741343.903369][2433:2442] CHIP:SC: SecureSession[0xffffa0020d20]: Moving from state 'kEstablishing' --> 'kActive'
[1663741343.903428][2433:2442] CHIP:IN: SecureSession[0xffffa0020d20]: Activated - Type:1 LSID:15207
[1663741343.903487][2433:2442] CHIP:IN: New secure session activated for device <FFFFFFFB00000000, 0>, LSID:15207 PSID:5923!
[1663741343.903546][2433:2442] CHIP:CTL: Remote device completed SPAKE2+ handshake
[1663741343.903592][2433:2442] CHIP:TOO: Pairing Success
[1663741343.903632][2433:2442] CHIP:TOO: PASE establishment successful
[1663741343.903739][2433:2442] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1663741343.903795][2433:2442] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo'
[1663741343.903853][2433:2442] CHIP:CTL: Sending request for commissioning information
[1663741343.903966][2433:2442] CHIP:DMG: SendReadRequest ReadClient[0xffffa002e6b0]: Sending Read Request
[1663741343.904210][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffb2b8 to 0xFFFFFFFB00000000 (0)  of type 0x2 and protocolId (0, 1) on exchange 51164i with MessageCounter:205829679.
[1663741343.904295][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffb2b8 with MessageCounter:205829679 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006E762 msec
[1663741343.904485][2433:2442] CHIP:DMG: MoveToState ReadClient[0xffffa002e6b0]: Moving to [AwaitingIn]
[1663741343.998597][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741344.050654][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.050846][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.145867][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.146052][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.146264][2433:2442] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:66789529 on exchange 51164i
[1663741344.146333][2433:2442] CHIP:EM: Found matching exchange: 51164i, Delegate: 0xffffa002e6c0
[1663741344.147119][2433:2442] CHIP:DMG: ReportDataMessage =
[1663741344.147194][2433:2442] CHIP:DMG: {
[1663741344.147243][2433:2442] CHIP:DMG:        AttributeReportIBs =
[1663741344.147312][2433:2442] CHIP:DMG:        [
[1663741344.147365][2433:2442] CHIP:DMG:                AttributeReportIB =
[1663741344.147444][2433:2442] CHIP:DMG:                {
[1663741344.147500][2433:2442] CHIP:DMG:                        AttributeDataIB =
[1663741344.147579][2433:2442] CHIP:DMG:                        {
[1663741344.147692][2433:2442] CHIP:DMG:                                DataVersion = 0x8d8d3b04,
[1663741344.147786][2433:2442] CHIP:DMG:                                AttributePathIB =
[1663741344.147865][2433:2442] CHIP:DMG:                                {
[1663741344.147946][2433:2442] CHIP:DMG:                                        Endpoint = 0x0,
[1663741344.148028][2433:2442] CHIP:DMG:                                        Cluster = 0x31,
[1663741344.148126][2433:2442] CHIP:DMG:                                        Attribute = 0x0000_0003,
[1663741344.148207][2433:2442] CHIP:DMG:                                }
[1663741344.148290][2433:2442] CHIP:DMG:
[1663741344.148365][2433:2442] CHIP:DMG:                                Data = 20,
[1663741344.148438][2433:2442] CHIP:DMG:                        },
[1663741344.148518][2433:2442] CHIP:DMG:
[1663741344.148576][2433:2442] CHIP:DMG:                },
[1663741344.148659][2433:2442] CHIP:DMG:
[1663741344.148710][2433:2442] CHIP:DMG:                AttributeReportIB =
[1663741344.148784][2433:2442] CHIP:DMG:                {
[1663741344.148843][2433:2442] CHIP:DMG:                        AttributeDataIB =
[1663741344.148905][2433:2442] CHIP:DMG:                        {
[1663741344.148970][2433:2442] CHIP:DMG:                                DataVersion = 0x72a4b579,
[1663741344.149045][2433:2442] CHIP:DMG:                                AttributePathIB =
[1663741344.149122][2433:2442] CHIP:DMG:                                {
[1663741344.149200][2433:2442] CHIP:DMG:                                        Endpoint = 0x0,
[1663741344.149271][2433:2442] CHIP:DMG:                                        Cluster = 0x28,
[1663741344.149351][2433:2442] CHIP:DMG:                                        Attribute = 0x0000_0004,
[1663741344.149430][2433:2442] CHIP:DMG:                                }
[1663741344.149497][2433:2442] CHIP:DMG:
[1663741344.149578][2433:2442] CHIP:DMG:                                Data = 32773,
[1663741344.149703][2433:2442] CHIP:DMG:                        },
[1663741344.149787][2433:2442] CHIP:DMG:
[1663741344.149854][2433:2442] CHIP:DMG:                },
[1663741344.149937][2433:2442] CHIP:DMG:
[1663741344.149989][2433:2442] CHIP:DMG:                AttributeReportIB =
[1663741344.150050][2433:2442] CHIP:DMG:                {
[1663741344.150108][2433:2442] CHIP:DMG:                        AttributeDataIB =
[1663741344.150176][2433:2442] CHIP:DMG:                        {
[1663741344.150251][2433:2442] CHIP:DMG:                                DataVersion = 0x72a4b579,
[1663741344.150325][2433:2442] CHIP:DMG:                                AttributePathIB =
[1663741344.150402][2433:2442] CHIP:DMG:                                {
[1663741344.150474][2433:2442] CHIP:DMG:                                        Endpoint = 0x0,
[1663741344.150556][2433:2442] CHIP:DMG:                                        Cluster = 0x28,
[1663741344.150639][2433:2442] CHIP:DMG:                                        Attribute = 0x0000_0002,
[1663741344.150718][2433:2442] CHIP:DMG:                                }
[1663741344.150792][2433:2442] CHIP:DMG:
[1663741344.150863][2433:2442] CHIP:DMG:                                Data = 65521,
[1663741344.150929][2433:2442] CHIP:DMG:                        },
[1663741344.150998][2433:2442] CHIP:DMG:
[1663741344.151053][2433:2442] CHIP:DMG:                },
[1663741344.151134][2433:2442] CHIP:DMG:
[1663741344.151188][2433:2442] CHIP:DMG:                AttributeReportIB =
[1663741344.151255][2433:2442] CHIP:DMG:                {
[1663741344.151309][2433:2442] CHIP:DMG:                        AttributeDataIB =
[1663741344.151376][2433:2442] CHIP:DMG:                        {
[1663741344.151453][2433:2442] CHIP:DMG:                                DataVersion = 0x8d0747c8,
[1663741344.151529][2433:2442] CHIP:DMG:                                AttributePathIB =
[1663741344.151605][2433:2442] CHIP:DMG:                                {
[1663741344.151684][2433:2442] CHIP:DMG:                                        Endpoint = 0x0,
[1663741344.151765][2433:2442] CHIP:DMG:                                        Cluster = 0x30,
[1663741344.151848][2433:2442] CHIP:DMG:                                        Attribute = 0x0000_0003,
[1663741344.151921][2433:2442] CHIP:DMG:                                }
[1663741344.152003][2433:2442] CHIP:DMG:
[1663741344.152083][2433:2442] CHIP:DMG:                                Data = 0,
[1663741344.152154][2433:2442] CHIP:DMG:                        },
[1663741344.152225][2433:2442] CHIP:DMG:
[1663741344.152284][2433:2442] CHIP:DMG:                },
[1663741344.152363][2433:2442] CHIP:DMG:
[1663741344.152414][2433:2442] CHIP:DMG:                AttributeReportIB =
[1663741344.152485][2433:2442] CHIP:DMG:                {
[1663741344.152544][2433:2442] CHIP:DMG:                        AttributeDataIB =
[1663741344.152610][2433:2442] CHIP:DMG:                        {
[1663741344.152686][2433:2442] CHIP:DMG:                                DataVersion = 0x8d0747c8,
[1663741344.152756][2433:2442] CHIP:DMG:                                AttributePathIB =
[1663741344.152831][2433:2442] CHIP:DMG:                                {
[1663741344.152910][2433:2442] CHIP:DMG:                                        Endpoint = 0x0,
[1663741344.152987][2433:2442] CHIP:DMG:                                        Cluster = 0x30,
[1663741344.153054][2433:2442] CHIP:DMG:                                        Attribute = 0x0000_0002,
[1663741344.153133][2433:2442] CHIP:DMG:                                }
[1663741344.153213][2433:2442] CHIP:DMG:
[1663741344.153293][2433:2442] CHIP:DMG:                                Data = 0,
[1663741344.153367][2433:2442] CHIP:DMG:                        },
[1663741344.153446][2433:2442] CHIP:DMG:
[1663741344.153504][2433:2442] CHIP:DMG:                },
[1663741344.153587][2433:2442] CHIP:DMG:
[1663741344.153666][2433:2442] CHIP:DMG:                AttributeReportIB =
[1663741344.153743][2433:2442] CHIP:DMG:                {
[1663741344.153798][2433:2442] CHIP:DMG:                        AttributeDataIB =
[1663741344.153870][2433:2442] CHIP:DMG:                        {
[1663741344.153946][2433:2442] CHIP:DMG:                                DataVersion = 0x8d0747c8,
[1663741344.154006][2433:2442] CHIP:DMG:                                AttributePathIB =
[1663741344.154068][2433:2442] CHIP:DMG:                                {
[1663741344.154159][2433:2442] CHIP:DMG:                                        Endpoint = 0x0,
[1663741344.154226][2433:2442] CHIP:DMG:                                        Cluster = 0x30,
[1663741344.154311][2433:2442] CHIP:DMG:                                        Attribute = 0x0000_0001,
[1663741344.154389][2433:2442] CHIP:DMG:                                }
[1663741344.154458][2433:2442] CHIP:DMG:
[1663741344.154521][2433:2442] CHIP:DMG:                                Data =
[1663741344.154598][2433:2442] CHIP:DMG:                                {
[1663741344.154698][2433:2442] CHIP:DMG:                                        0x0 = 60,
[1663741344.154784][2433:2442] CHIP:DMG:                                        0x1 = 900,
[1663741344.154860][2433:2442] CHIP:DMG:                                },
[1663741344.154923][2433:2442] CHIP:DMG:                        },
[1663741344.154991][2433:2442] CHIP:DMG:
[1663741344.155045][2433:2442] CHIP:DMG:                },
[1663741344.155128][2433:2442] CHIP:DMG:
[1663741344.155179][2433:2442] CHIP:DMG:                AttributeReportIB =
[1663741344.155251][2433:2442] CHIP:DMG:                {
[1663741344.155312][2433:2442] CHIP:DMG:                        AttributeDataIB =
[1663741344.155385][2433:2442] CHIP:DMG:                        {
[1663741344.155453][2433:2442] CHIP:DMG:                                DataVersion = 0x8d0747c8,
[1663741344.155527][2433:2442] CHIP:DMG:                                AttributePathIB =
[1663741344.155590][2433:2442] CHIP:DMG:                                {
[1663741344.155668][2433:2442] CHIP:DMG:                                        Endpoint = 0x0,
[1663741344.155738][2433:2442] CHIP:DMG:                                        Cluster = 0x30,
[1663741344.155805][2433:2442] CHIP:DMG:                                        Attribute = 0x0000_0000,
[1663741344.155873][2433:2442] CHIP:DMG:                                }
[1663741344.155909][2433:2442] CHIP:DMG:
[1663741344.155943][2433:2442] CHIP:DMG:                                Data = 0,
[1663741344.155971][2433:2442] CHIP:DMG:                        },
[1663741344.155999][2433:2442] CHIP:DMG:
[1663741344.156024][2433:2442] CHIP:DMG:                },
[1663741344.156059][2433:2442] CHIP:DMG:
[1663741344.156081][2433:2442] CHIP:DMG:                AttributeReportIB =
[1663741344.156116][2433:2442] CHIP:DMG:                {
[1663741344.156141][2433:2442] CHIP:DMG:                        AttributeDataIB =
[1663741344.156172][2433:2442] CHIP:DMG:                        {
[1663741344.156202][2433:2442] CHIP:DMG:                                DataVersion = 0x8d8d3b04,
[1663741344.156234][2433:2442] CHIP:DMG:                                AttributePathIB =
[1663741344.156266][2433:2442] CHIP:DMG:                                {
[1663741344.156300][2433:2442] CHIP:DMG:                                        Endpoint = 0x0,
[1663741344.156336][2433:2442] CHIP:DMG:                                        Cluster = 0x31,
[1663741344.156371][2433:2442] CHIP:DMG:                                        Attribute = 0x0000_FFFC,
[1663741344.156405][2433:2442] CHIP:DMG:                                }
[1663741344.156439][2433:2442] CHIP:DMG:
[1663741344.156474][2433:2442] CHIP:DMG:                                Data = 2,
[1663741344.156505][2433:2442] CHIP:DMG:                        },
[1663741344.156538][2433:2442] CHIP:DMG:
[1663741344.156562][2433:2442] CHIP:DMG:                },
[1663741344.156591][2433:2442] CHIP:DMG:
[1663741344.156612][2433:2442] CHIP:DMG:        ],
[1663741344.156672][2433:2442] CHIP:DMG:
[1663741344.156695][2433:2442] CHIP:DMG:        SuppressResponse = true,
[1663741344.156720][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741344.156742][2433:2442] CHIP:DMG: }
[1663741344.157535][2433:2442] CHIP:CTL: ----- NetworkCommissioning Features: has Thread. endpointid = 0
[1663741344.157609][2433:2442] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo'
[1663741344.157658][2433:2442] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe'
[1663741344.157689][2433:2442] CHIP:CTL: Performing next commissioning step 'ArmFailSafe'
[1663741344.157708][2433:2442] CHIP:CTL: Arming failsafe (60 seconds)
[1663741344.157797][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741344.157827][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741344.157935][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffaf78 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51165i with MessageCounter:205829680.
[1663741344.157977][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffaf78 with MessageCounter:205829680 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006E860 msec
[1663741344.158094][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741344.242241][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741344.244111][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.244311][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.244564][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789530 on exchange 51165i
[1663741344.244668][2433:2442] CHIP:EM: Found matching exchange: 51165i, Delegate: 0xffffa8044a18
[1663741344.244744][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741344.244861][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741344.244915][2433:2442] CHIP:DMG: {
[1663741344.244964][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741344.245015][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741344.245106][2433:2442] CHIP:DMG:        [
[1663741344.245156][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741344.245324][2433:2442] CHIP:DMG:                {
[1663741344.245392][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741344.245458][2433:2442] CHIP:DMG:                        {
[1663741344.245528][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741344.245774][2433:2442] CHIP:DMG:                                {
[1663741344.245894][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741344.245975][2433:2442] CHIP:DMG:                                        ClusterId = 0x30,
[1663741344.246073][2433:2442] CHIP:DMG:                                        CommandId = 0x1,
[1663741344.246148][2433:2442] CHIP:DMG:                                },
[1663741344.246298][2433:2442] CHIP:DMG:
[1663741344.246375][2433:2442] CHIP:DMG:                                CommandFields =
[1663741344.246448][2433:2442] CHIP:DMG:                                {
[1663741344.246546][2433:2442] CHIP:DMG:                                        0x0 = 0,
[1663741344.246715][2433:2442] CHIP:DMG:                                        0x1 = "" (0 chars),
[1663741344.246827][2433:2442] CHIP:DMG:                                },
[1663741344.246897][2433:2442] CHIP:DMG:                        },
[1663741344.246999][2433:2442] CHIP:DMG:
[1663741344.247138][2433:2442] CHIP:DMG:                },
[1663741344.247249][2433:2442] CHIP:DMG:
[1663741344.247302][2433:2442] CHIP:DMG:        ],
[1663741344.247373][2433:2442] CHIP:DMG:
[1663741344.247454][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741344.247581][2433:2442] CHIP:DMG: },
[1663741344.247760][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1663741344.247968][2433:2442] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1663741344.248067][2433:2442] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe'
[1663741344.248121][2433:2442] CHIP:CTL: No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks
[1663741344.248164][2433:2442] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1663741344.248225][2433:2442] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory'
[1663741344.248269][2433:2442] CHIP:CTL: Setting Regulatory Config
[1663741344.248338][2433:2442] CHIP:CTL: Device does not support configurable regulatory location
[1663741344.248562][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741344.248648][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741344.248889][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffaad8 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51166i with MessageCounter:205829681.
[1663741344.249012][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffaad8 with MessageCounter:205829681 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006E8BB msec
[1663741344.249367][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741344.249626][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741344.339799][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741344.341707][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.341914][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.342170][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789531 on exchange 51166i
[1663741344.342238][2433:2442] CHIP:EM: Found matching exchange: 51166i, Delegate: 0xffffa0020588
[1663741344.342314][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741344.342413][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741344.342466][2433:2442] CHIP:DMG: {
[1663741344.342518][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741344.342570][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741344.342639][2433:2442] CHIP:DMG:        [
[1663741344.342689][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741344.342773][2433:2442] CHIP:DMG:                {
[1663741344.342828][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741344.342893][2433:2442] CHIP:DMG:                        {
[1663741344.342963][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741344.343042][2433:2442] CHIP:DMG:                                {
[1663741344.343124][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741344.343208][2433:2442] CHIP:DMG:                                        ClusterId = 0x30,
[1663741344.343290][2433:2442] CHIP:DMG:                                        CommandId = 0x3,
[1663741344.343367][2433:2442] CHIP:DMG:                                },
[1663741344.343449][2433:2442] CHIP:DMG:
[1663741344.343521][2433:2442] CHIP:DMG:                                CommandFields =
[1663741344.343598][2433:2442] CHIP:DMG:                                {
[1663741344.343680][2433:2442] CHIP:DMG:                                        0x0 = 0,
[1663741344.343767][2433:2442] CHIP:DMG:                                        0x1 = "" (0 chars),
[1663741344.343849][2433:2442] CHIP:DMG:                                },
[1663741344.343922][2433:2442] CHIP:DMG:                        },
[1663741344.344004][2433:2442] CHIP:DMG:
[1663741344.344062][2433:2442] CHIP:DMG:                },
[1663741344.344128][2433:2442] CHIP:DMG:
[1663741344.344176][2433:2442] CHIP:DMG:        ],
[1663741344.344242][2433:2442] CHIP:DMG:
[1663741344.344294][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741344.344344][2433:2442] CHIP:DMG: },
[1663741344.344469][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1663741344.344542][2433:2442] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0
[1663741344.344602][2433:2442] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory'
[1663741344.344649][2433:2442] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest'
[1663741344.344704][2433:2442] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest'
[1663741344.344748][2433:2442] CHIP:CTL: Sending request for PAI certificate
[1663741344.344790][2433:2442] CHIP:CTL: Sending Certificate Chain request to 0xffffa0022a10 device
[1663741344.345187][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741344.345345][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741344.345515][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffaa18 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51167i with MessageCounter:205829682.
[1663741344.345599][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffaa18 with MessageCounter:205829682 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006E91B msec
[1663741344.345891][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741344.346020][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741344.437477][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741344.441067][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.441265][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.538161][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.538438][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.633235][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.633432][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.633725][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789532 on exchange 51167i
[1663741344.633791][2433:2442] CHIP:EM: Found matching exchange: 51167i, Delegate: 0xffffa8044a18
[1663741344.633872][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741344.633968][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741344.634021][2433:2442] CHIP:DMG: {
[1663741344.634072][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741344.634124][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741344.634193][2433:2442] CHIP:DMG:        [
[1663741344.634243][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741344.634320][2433:2442] CHIP:DMG:                {
[1663741344.634380][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741344.634454][2433:2442] CHIP:DMG:                        {
[1663741344.634524][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741344.634606][2433:2442] CHIP:DMG:                                {
[1663741344.634687][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741344.634770][2433:2442] CHIP:DMG:                                        ClusterId = 0x3e,
[1663741344.634851][2433:2442] CHIP:DMG:                                        CommandId = 0x3,
[1663741344.634928][2433:2442] CHIP:DMG:                                },
[1663741344.635008][2433:2442] CHIP:DMG:
[1663741344.635080][2433:2442] CHIP:DMG:                                CommandFields =
[1663741344.635157][2433:2442] CHIP:DMG:                                {
[1663741344.635236][2433:2442] CHIP:DMG:                                        0x0 = [
[1663741344.635515][2433:2442] CHIP:DMG:                                                        0x30, 0x82, 0x1, 0xcb, 0x30, 0x82, 0x1, 0x71, 0xa0, 0x3, 0x2, 0x1, 0x2, 0x2, 0x8, 0x56, 0xad, 0x82, 0x22, 0xad, 0x94, 0x5b, 0x64, 0x30, 0xa, 0x6, 0x8, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x4, 0x3, 0x2, 0x30, 0x30, 0x31, 0x18, 0x30, 0x16, 0x6, 0x3, 0x55, 0x4, 0x3, 0xc, 0xf, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x54, 0x65, 0x73, 0x74, 0x20, 0x50, 0x41, 0x41, 0x31, 0x14, 0x30, 0x12, 0x6, 0xa, 0x2b, 0x6, 0x1, 0x4, 0x1, 0x82, 0xa2, 0x7c, 0x2, 0x1, 0xc, 0x4, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0xd, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0xf, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x6, 0x3, 0x55, 0x4, 0x3, 0xc, 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, 0x6, 0xa, 0x2b, 0x6, 0x1, 0x4, 0x1, 0x82, 0xa2, 0x7c, 0x2, 0x1, 0xc, 0x4, 0x46, 0x46, 0x46, 0x31, 0x30, 0x59, 0x30, 0x13, 0x6, 0x7, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x2, 0x1, 0x6, 0x8, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x3, 0x1, 0x7, 0x3, 0x42, 0x0, 0x4, 0x41, 0x9a, 0x93, 0x15, 0xc2, 0x17, 0x3e, 0xc, 0x8c, 0x87, 0x6d, 0x3, 0xcc, 0xfc, 0x94, 0x48, 0x52, 0x64, 0x7f, 0x7f, 0xec, 0x5e, 0x50, 0x82, 0xf4, 0x5, 0x99, 0x28, 0xec, 0xa8, 0x94, 0xc5, 0x94, 0x15, 0x13, 0x9, 0xac, 0x63, 0x1e, 0x4c, 0xb0, 0x33, 0x92, 0xaf, 0x68, 0x4b, 0xb, 0xaf, 0xb7, 0xe6, 0x5b, 0x3b, 0x81, 0x62, 0xc2, 0xf5, 0x2b, 0xf9, 0x31, 0xb8, 0xe7, 0x7a, 0xaa, 0x82, 0xa3, 0x66, 0x30, 0x64, 0x30, 0x12, 0x6, 0x3, 0x55, 0x1d, 0x13, 0x1, 0x1, 0xff, 0x4, 0x8, 0x30, 0x6, 0x1, 0x1, 0xff, 0x2, 0x1,
[1663741344.635687][2433:2442] CHIP:DMG:                                        ] (463 bytes)
[1663741344.635770][2433:2442] CHIP:DMG:                                },
[1663741344.635844][2433:2442] CHIP:DMG:                        },
[1663741344.635924][2433:2442] CHIP:DMG:
[1663741344.635982][2433:2442] CHIP:DMG:                },
[1663741344.636052][2433:2442] CHIP:DMG:
[1663741344.636102][2433:2442] CHIP:DMG:        ],
[1663741344.636166][2433:2442] CHIP:DMG:
[1663741344.636218][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741344.636268][2433:2442] CHIP:DMG: },
[1663741344.636401][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1663741344.636470][2433:2442] CHIP:CTL: Received certificate chain from the device
[1663741344.636530][2433:2442] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest'
[1663741344.636582][2433:2442] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1663741344.636640][2433:2442] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest'
[1663741344.636686][2433:2442] CHIP:CTL: Sending request for DAC certificate
[1663741344.636727][2433:2442] CHIP:CTL: Sending Certificate Chain request to 0xffffa0022a10 device
[1663741344.636840][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741344.636901][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741344.637060][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffaa28 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51168i with MessageCounter:205829683.
[1663741344.637143][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffaa28 with MessageCounter:205829683 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006EA3F msec
[1663741344.637327][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741344.637448][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741344.729798][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741344.733572][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.733829][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.830463][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.830641][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.926164][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741344.926360][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741344.926617][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789533 on exchange 51168i
[1663741344.926688][2433:2442] CHIP:EM: Found matching exchange: 51168i, Delegate: 0xffffa8044dc8
[1663741344.926767][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741344.926864][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741344.926918][2433:2442] CHIP:DMG: {
[1663741344.926967][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741344.927018][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741344.927087][2433:2442] CHIP:DMG:        [
[1663741344.927145][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741344.927225][2433:2442] CHIP:DMG:                {
[1663741344.927280][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741344.927351][2433:2442] CHIP:DMG:                        {
[1663741344.927413][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741344.927495][2433:2442] CHIP:DMG:                                {
[1663741344.927577][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741344.927647][2433:2442] CHIP:DMG:                                        ClusterId = 0x3e,
[1663741344.927715][2433:2442] CHIP:DMG:                                        CommandId = 0x3,
[1663741344.927792][2433:2442] CHIP:DMG:                                },
[1663741344.927873][2433:2442] CHIP:DMG:
[1663741344.927932][2433:2442] CHIP:DMG:                                CommandFields =
[1663741344.928002][2433:2442] CHIP:DMG:                                {
[1663741344.928060][2433:2442] CHIP:DMG:                                        0x0 = [
[1663741344.928346][2433:2442] CHIP:DMG:                                                        0x30, 0x82, 0x1, 0xe8, 0x30, 0x82, 0x1, 0x8e, 0xa0, 0x3, 0x2, 0x1, 0x2, 0x2, 0x8, 0x6f, 0xdc, 0xb6, 0xed, 0x6, 0xf3, 0x58, 0xf9, 0x30, 0xa, 0x6, 0x8, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x4, 0x3, 0x2, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x6, 0x3, 0x55, 0x4, 0x3, 0xc, 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, 0x6, 0xa, 0x2b, 0x6, 0x1, 0x4, 0x1, 0x82, 0xa2, 0x7c, 0x2, 0x1, 0xc, 0x4, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0xd, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0xf, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x53, 0x31, 0x25, 0x30, 0x23, 0x6, 0x3, 0x55, 0x4, 0x3, 0xc, 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, 0x6, 0xa, 0x2b, 0x6, 0x1, 0x4, 0x1, 0x82, 0xa2, 0x7c, 0x2, 0x1, 0xc, 0x4, 0x46, 0x46, 0x46, 0x31, 0x31, 0x14, 0x30, 0x12, 0x6, 0xa, 0x2b, 0x6, 0x1, 0x4, 0x1, 0x82, 0xa2, 0x7c, 0x2, 0x2, 0xc, 0x4, 0x38, 0x30, 0x30, 0x35, 0x30, 0x59, 0x30, 0x13, 0x6, 0x7, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x2, 0x1, 0x6, 0x8, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x3, 0x1, 0x7, 0x3, 0x42, 0x0, 0x4, 0x7e, 0xf2, 0xf1, 0x8, 0x2b, 0x2a, 0x56, 0x4a, 0x5, 0x44, 0xc0, 0xa6, 0x13, 0xd2, 0x1b, 0x15, 0x75, 0x0, 0x55, 0x2d, 0x3, 0x5f, 0x23, 0x2, 0x25, 0x2f, 0xce, 0xe8, 0x1d, 0x6e, 0xc6, 0x74, 0x17, 0x34, 0x18, 0xa9, 0x4a, 0x88, 0xdb, 0x73, 0x74, 0x15, 0x58, 0xc9, 0xfc, 0x8a, 0xc9, 0x34, 0x9e, 0xf6, 0x7e, 0x3e
[1663741344.928520][2433:2442] CHIP:DMG:                                        ] (492 bytes)
[1663741344.928612][2433:2442] CHIP:DMG:                                },
[1663741344.928678][2433:2442] CHIP:DMG:                        },
[1663741344.928740][2433:2442] CHIP:DMG:
[1663741344.928792][2433:2442] CHIP:DMG:                },
[1663741344.928857][2433:2442] CHIP:DMG:
[1663741344.928906][2433:2442] CHIP:DMG:        ],
[1663741344.928971][2433:2442] CHIP:DMG:
[1663741344.929023][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741344.929072][2433:2442] CHIP:DMG: },
[1663741344.929207][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1663741344.929275][2433:2442] CHIP:CTL: Received certificate chain from the device
[1663741344.929330][2433:2442] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest'
[1663741344.929389][2433:2442] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1663741344.929448][2433:2442] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest'
[1663741344.929492][2433:2442] CHIP:CTL: Sending Attestation Request to the device.
[1663741344.929539][2433:2442] CHIP:CTL: Sending Attestation request to 0xffffa0022a10 device
[1663741344.929701][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741344.929770][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741344.929933][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffa9e8 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51169i with MessageCounter:205829684.
[1663741344.930015][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffa9e8 with MessageCounter:205829684 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006EB64 msec
[1663741344.930205][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741344.930277][2433:2442] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information
[1663741344.930381][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741345.022118][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741345.026121][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741345.026331][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741345.123211][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741345.123418][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741345.220329][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741345.220500][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741345.220744][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789534 on exchange 51169i
[1663741345.220805][2433:2442] CHIP:EM: Found matching exchange: 51169i, Delegate: 0xffffa8045118
[1663741345.220874][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741345.220964][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741345.221010][2433:2442] CHIP:DMG: {
[1663741345.221053][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741345.221097][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741345.221158][2433:2442] CHIP:DMG:        [
[1663741345.221201][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741345.221269][2433:2442] CHIP:DMG:                {
[1663741345.221316][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741345.221372][2433:2442] CHIP:DMG:                        {
[1663741345.221415][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741345.221488][2433:2442] CHIP:DMG:                                {
[1663741345.221551][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741345.221621][2433:2442] CHIP:DMG:                                        ClusterId = 0x3e,
[1663741345.221736][2433:2442] CHIP:DMG:                                        CommandId = 0x1,
[1663741345.221800][2433:2442] CHIP:DMG:                                },
[1663741345.221873][2433:2442] CHIP:DMG:
[1663741345.221927][2433:2442] CHIP:DMG:                                CommandFields =
[1663741345.221994][2433:2442] CHIP:DMG:                                {
[1663741345.222050][2433:2442] CHIP:DMG:                                        0x0 = [
[1663741345.222306][2433:2442] CHIP:DMG:                                                        0x15, 0x31, 0x1, 0x1d, 0x2, 0x30, 0x82, 0x2, 0x19, 0x6, 0x9, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0xd, 0x1, 0x7, 0x2, 0xa0, 0x82, 0x2, 0xa, 0x30, 0x82, 0x2, 0x6, 0x2, 0x1, 0x3, 0x31, 0xd, 0x30, 0xb, 0x6, 0x9, 0x60, 0x86, 0x48, 0x1, 0x65, 0x3, 0x4, 0x2, 0x1, 0x30, 0x82, 0x1, 0x71, 0x6, 0x9, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0xd, 0x1, 0x7, 0x1, 0xa0, 0x82, 0x1, 0x62, 0x4, 0x82, 0x1, 0x5e, 0x15, 0x24, 0x0, 0x1, 0x25, 0x1, 0xf1, 0xff, 0x36, 0x2, 0x5, 0x0, 0x80, 0x5, 0x1, 0x80, 0x5, 0x2, 0x80, 0x5, 0x3, 0x80, 0x5, 0x4, 0x80, 0x5, 0x5, 0x80, 0x5, 0x6, 0x80, 0x5, 0x7, 0x80, 0x5, 0x8, 0x80, 0x5, 0x9, 0x80, 0x5, 0xa, 0x80, 0x5, 0xb, 0x80, 0x5, 0xc, 0x80, 0x5, 0xd, 0x80, 0x5, 0xe, 0x80, 0x5, 0xf, 0x80, 0x5, 0x10, 0x80, 0x5, 0x11, 0x80, 0x5, 0x12, 0x80, 0x5, 0x13, 0x80, 0x5, 0x14, 0x80, 0x5, 0x15, 0x80, 0x5, 0x16, 0x80, 0x5, 0x17, 0x80, 0x5, 0x18, 0x80, 0x5, 0x19, 0x80, 0x5, 0x1a, 0x80, 0x5, 0x1b, 0x80, 0x5, 0x1c, 0x80, 0x5, 0x1d, 0x80, 0x5, 0x1e, 0x80, 0x5, 0x1f, 0x80, 0x5, 0x20, 0x80, 0x5, 0x21, 0x80, 0x5, 0x22, 0x80, 0x5, 0x23, 0x80, 0x5, 0x24, 0x80, 0x5, 0x25, 0x80, 0x5, 0x26, 0x80, 0x5, 0x27, 0x80, 0x5, 0x28, 0x80, 0x5, 0x29, 0x80, 0x5, 0x2a, 0x80, 0x5, 0x2b, 0x80, 0x5, 0x2c, 0x80, 0x5, 0x2d, 0x80, 0x5, 0x2e, 0x80, 0x5, 0x2f, 0x80, 0x5, 0x30, 0x80, 0x5, 0x31, 0x80, 0x5, 0x32, 0x80, 0x5, 0x33, 0x80, 0x5, 0x34, 0x80, 0x5, 0x35, 0x80, 0x5, 0x36, 0x80, 0x5, 0x37, 0x80, 0x5, 0x38, 0x80, 0x5, 0x39, 0x80, 0x5, 0x3a, 0x80, 0x5, 0x3b, 0x80, 0x5, 0x3c, 0x80, 0x5, 0x3d, 0x80, 0x5, 0x3e, 0x80, 0x5, 0x3f, 0x80, 0x5, 0x40, 0x80, 0x5, 0x41, 0x80, 0x5, 0x42, 0x80, 0x5, 0x43, 0x80, 0x5, 0x44, 0x80, 0x5, 0x45, 0x80, 0x5, 0x46, 0x80, 0x5, 0x47, 0x80, 0x5, 0x48, 0x80, 0x5, 0x49, 0x80, 0x5, 0x4a, 0x80, 0x5, 0
[1663741345.222447][2433:2442] CHIP:DMG:                                        ] (585 bytes)
[1663741345.222512][2433:2442] CHIP:DMG:                                        0x1 = [
[1663741345.222615][2433:2442] CHIP:DMG:                                                        0xde, 0x86, 0xd, 0xd4, 0x5b, 0xa1, 0xbb, 0x4f, 0x23, 0xf3, 0x57, 0xeb, 0x5d, 0xaa, 0xd9, 0x5c, 0x13, 0x6, 0x55, 0x8e, 0x63, 0x92, 0x27, 0x3f, 0x5a, 0xa5, 0xb0, 0x23, 0x54, 0x10, 0x12, 0x98, 0xe7, 0x1b, 0xf7, 0x3b, 0xeb, 0x28, 0x51, 0x76, 0xd, 0x8a, 0x39, 0x35, 0x8a, 0x39, 0x1a, 0xd5, 0xc1, 0xd9, 0x24, 0x3e, 0x2a, 0x35, 0x30, 0x99, 0xdb, 0xd, 0x37, 0xb8, 0x65, 0xc1, 0xd9, 0xe2,
[1663741345.222702][2433:2442] CHIP:DMG:                                        ] (64 bytes)
[1663741345.222771][2433:2442] CHIP:DMG:                                },
[1663741345.222834][2433:2442] CHIP:DMG:                        },
[1663741345.222906][2433:2442] CHIP:DMG:
[1663741345.222952][2433:2442] CHIP:DMG:                },
[1663741345.223013][2433:2442] CHIP:DMG:
[1663741345.223056][2433:2442] CHIP:DMG:        ],
[1663741345.223114][2433:2442] CHIP:DMG:
[1663741345.223158][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741345.223200][2433:2442] CHIP:DMG: },
[1663741345.223320][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1663741345.223383][2433:2442] CHIP:CTL: Received Attestation Information from the device
[1663741345.223435][2433:2442] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest'
[1663741345.223546][2433:2442] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1663741345.223600][2433:2442] CHIP:CTL: Performing next commissioning step 'AttestationVerification'
[1663741345.223639][2433:2442] CHIP:CTL: Verifying attestation
[1663741345.232344][2433:2442] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device.
[1663741345.232396][2433:2442] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification'
[1663741345.232418][2433:2442] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest'
[1663741345.232446][2433:2442] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest'
[1663741345.232468][2433:2442] CHIP:CTL: Sending CSR request to 0xffffa0022a10 device
[1663741345.232544][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741345.232577][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741345.232689][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ff9fe8 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51170i with MessageCounter:205829685.
[1663741345.232731][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ff9fe8 with MessageCounter:205829685 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006EC93 msec
[1663741345.232849][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741345.232883][2433:2442] CHIP:CTL: Sent CSR request, waiting for the CSR
[1663741345.232936][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741345.314465][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741345.318632][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741345.318832][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741345.414914][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741345.415169][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741345.415488][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789535 on exchange 51170i
[1663741345.415572][2433:2442] CHIP:EM: Found matching exchange: 51170i, Delegate: 0xffffa8045278
[1663741345.415667][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741345.415776][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741345.415835][2433:2442] CHIP:DMG: {
[1663741345.415887][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741345.415949][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741345.416022][2433:2442] CHIP:DMG:        [
[1663741345.416079][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741345.416164][2433:2442] CHIP:DMG:                {
[1663741345.416226][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741345.416304][2433:2442] CHIP:DMG:                        {
[1663741345.416379][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741345.416459][2433:2442] CHIP:DMG:                                {
[1663741345.416543][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741345.416630][2433:2442] CHIP:DMG:                                        ClusterId = 0x3e,
[1663741345.416716][2433:2442] CHIP:DMG:                                        CommandId = 0x5,
[1663741345.416795][2433:2442] CHIP:DMG:                                },
[1663741345.416872][2433:2442] CHIP:DMG:
[1663741345.416949][2433:2442] CHIP:DMG:                                CommandFields =
[1663741345.417030][2433:2442] CHIP:DMG:                                {
[1663741345.417113][2433:2442] CHIP:DMG:                                        0x0 = [
[1663741345.417368][2433:2442] CHIP:DMG:                                                        0x15, 0x30, 0x1, 0xdd, 0x30, 0x81, 0xda, 0x30, 0x81, 0x81, 0x2, 0x1, 0x0, 0x30, 0xe, 0x31, 0xc, 0x30, 0xa, 0x6, 0x3, 0x55, 0x4, 0xb, 0xc, 0x3, 0x43, 0x53, 0x41, 0x30, 0x59, 0x30, 0x13, 0x6, 0x7, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x2, 0x1, 0x6, 0x8, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x3, 0x1, 0x7, 0x3, 0x42, 0x0, 0x4, 0x2e, 0xb4, 0x8f, 0xea, 0x1f, 0x96, 0x45, 0xcd, 0xc0, 0x5f, 0x28, 0xa7, 0xbe, 0x25, 0x1, 0x27, 0x9e, 0x40, 0xf4, 0x74, 0x8d, 0x75, 0x8b, 0x23, 0x5b, 0xc9, 0xa3, 0x6e, 0x23, 0x4c, 0xdc, 0xc4, 0xd6, 0xe2, 0xcf, 0x93, 0xa4, 0x4c, 0x63, 0x69, 0xe9, 0x2c, 0x8, 0x39, 0x32, 0x73, 0xa9, 0x46, 0xd7, 0xd0, 0x16, 0x8b, 0xa6, 0x79, 0x60, 0x50, 0x95, 0xa3, 0xc1, 0x2a, 0xad, 0x90, 0x2b, 0xbf, 0xa0, 0x11, 0x30, 0xf, 0x6, 0x9, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0xd, 0x1, 0x9, 0xe, 0x31, 0x2, 0x30, 0x0, 0x30, 0xa, 0x6, 0x8, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x4, 0x3, 0x2, 0x3, 0x48, 0x0, 0x30, 0x45, 0x2, 0x20, 0x17, 0xe6, 0x63, 0xec, 0x66, 0x4c, 0xc1, 0x18, 0x8d, 0x52, 0x8c, 0x4c, 0x9a, 0x88, 0xb9, 0xdc, 0xd, 0x64, 0xbe, 0x62, 0x83, 0x69, 0x37, 0x3c, 0xbc, 0xde, 0xab, 0x33, 0x2b, 0xe, 0x1d, 0x7c, 0x2, 0x21, 0x0, 0xf6, 0xd5, 0xe4, 0xd8, 0x27, 0x87, 0x51, 0x7d, 0xfa, 0x8d, 0x56, 0xda, 0x8, 0xad, 0x21, 0x69, 0x7c, 0x58, 0x54, 0x9e, 0x59, 0xea, 0x8a, 0x47, 0x19, 0xbe, 0xe4, 0xc3, 0x9, 0xb9, 0xc2, 0x49, 0x30, 0x2, 0x20, 0xd6, 0x4f, 0xc0, 0xcb, 0xf0, 0x71, 0x74, 0x11, 0x73, 0xbb, 0xcd, 0x3b, 0xb0, 0x56, 0xfd, 0x98, 0x64, 0x17, 0x57, 0xdd, 0x28, 0x3d, 0x2c, 0xd5, 0x31, 0x5e, 0xe4, 0x33, 0x9c, 0x2c, 0x40, 0x8, 0x18,
[1663741345.417537][2433:2442] CHIP:DMG:                                        ] (261 bytes)
[1663741345.417624][2433:2442] CHIP:DMG:                                        0x1 = [
[1663741345.417827][2433:2442] CHIP:DMG:                                                        0xbe, 0xf3, 0xde, 0xef, 0xd4, 0xdf, 0x73, 0xf6, 0x4a, 0x7a, 0xd7, 0xd, 0x28, 0x97, 0x8b, 0x5b, 0x6c, 0x5c, 0xb, 0xb1, 0xc5, 0xe5, 0x58, 0x24, 0xc5, 0x16, 0x9b, 0x5a, 0xca, 0x71, 0x46, 0xa6, 0x97, 0x7a, 0x11, 0x2a, 0xe1, 0xd3, 0x9, 0x99, 0xd5, 0x37, 0xd5, 0x3d, 0xf9, 0x26, 0xc3, 0xe0, 0x58, 0xc1, 0xdc, 0x3a, 0xfb, 0xb0, 0x95, 0x26, 0x91, 0xcf, 0x8e, 0xd2, 0xea, 0xe1, 0x97, 0x36,
[1663741345.417943][2433:2442] CHIP:DMG:                                        ] (64 bytes)
[1663741345.418034][2433:2442] CHIP:DMG:                                },
[1663741345.418111][2433:2442] CHIP:DMG:                        },
[1663741345.418198][2433:2442] CHIP:DMG:
[1663741345.418257][2433:2442] CHIP:DMG:                },
[1663741345.418331][2433:2442] CHIP:DMG:
[1663741345.418381][2433:2442] CHIP:DMG:        ],
[1663741345.418450][2433:2442] CHIP:DMG:
[1663741345.418503][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741345.418562][2433:2442] CHIP:DMG: },
[1663741345.418707][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1663741345.418783][2433:2442] CHIP:CTL: Received certificate signing request from the device
[1663741345.418847][2433:2442] CHIP:CTL: Successfully finished commissioning step 'SendOpCertSigningRequest'
[1663741345.418897][2433:2442] CHIP:CTL: Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR'
[1663741345.418956][2433:2442] CHIP:CTL: Performing next commissioning step 'ValidateCSR'
[1663741345.420245][2433:2442] CHIP:CTL: Successfully finished commissioning step 'ValidateCSR'
[1663741345.420296][2433:2442] CHIP:CTL: Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain'
[1663741345.420325][2433:2442] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain'
[1663741345.420348][2433:2442] CHIP:CTL: Getting certificate chain for the device from the issuer
[1663741345.420622][2433:2442] CHIP:CTL: Verifying Certificate Signing Request
[1663741345.421530][2433:2442] CHIP:CTL: Generating NOC
[1663741345.421924][2433:2442] CHIP:CTL: Providing certificate chain to the commissioner
[1663741345.421964][2433:2442] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/ExampleOperationalCredentialsIssuer.cpp:396: Success
[1663741345.421996][2433:2442] CHIP:CTL: Successfully finished commissioning step 'GenerateNOCChain'
[1663741345.422182][2433:2442] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert'
[1663741345.422210][2433:2442] CHIP:CTL: Sending root certificate to the device
[1663741345.422287][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741345.422333][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741345.422450][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ff9838 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51171i with MessageCounter:205829686.
[1663741345.422492][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ff9838 with MessageCounter:205829686 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006ED50 msec
[1663741345.422614][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741345.422650][2433:2442] CHIP:CTL: Sent root certificate to the device
[1663741345.423011][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741345.510108][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741345.606979][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741345.608763][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741345.608924][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741345.609133][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789536 on exchange 51171i
[1663741345.609190][2433:2442] CHIP:EM: Found matching exchange: 51171i, Delegate: 0xffffa8045118
[1663741345.609250][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741345.609326][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741345.609368][2433:2442] CHIP:DMG: {
[1663741345.609406][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741345.609445][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741345.609495][2433:2442] CHIP:DMG:        [
[1663741345.609533][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741345.609595][2433:2442] CHIP:DMG:                {
[1663741345.609679][2433:2442] CHIP:DMG:                        CommandStatusIB =
[1663741345.609735][2433:2442] CHIP:DMG:                        {
[1663741345.609789][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741345.609851][2433:2442] CHIP:DMG:                                {
[1663741345.609912][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741345.609971][2433:2442] CHIP:DMG:                                        ClusterId = 0x3e,
[1663741345.610033][2433:2442] CHIP:DMG:                                        CommandId = 0xb,
[1663741345.610092][2433:2442] CHIP:DMG:                                },
[1663741345.610158][2433:2442] CHIP:DMG:
[1663741345.610211][2433:2442] CHIP:DMG:                                StatusIB =
[1663741345.610270][2433:2442] CHIP:DMG:                                {
[1663741345.610332][2433:2442] CHIP:DMG:                                        status = 0x00 (SUCCESS),
[1663741345.610392][2433:2442] CHIP:DMG:                                },
[1663741345.610451][2433:2442] CHIP:DMG:
[1663741345.610503][2433:2442] CHIP:DMG:                        },
[1663741345.610563][2433:2442] CHIP:DMG:
[1663741345.610606][2433:2442] CHIP:DMG:                },
[1663741345.610658][2433:2442] CHIP:DMG:
[1663741345.610696][2433:2442] CHIP:DMG:        ],
[1663741345.610744][2433:2442] CHIP:DMG:
[1663741345.610784][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741345.610821][2433:2442] CHIP:DMG: },
[1663741345.610920][2433:2442] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1663741345.610964][2433:2442] CHIP:CTL: Device confirmed that it has received the root certificate
[1663741345.611009][2433:2442] CHIP:CTL: Successfully finished commissioning step 'SendTrustedRootCert'
[1663741345.611045][2433:2442] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
[1663741345.611088][2433:2442] CHIP:CTL: Performing next commissioning step 'SendNOC'
[1663741345.611190][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741345.611250][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741345.611428][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffaa28 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51172i with MessageCounter:205829687.
[1663741345.611493][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffaa28 with MessageCounter:205829687 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006EE0D msec
[1663741345.611649][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741345.611707][2433:2442] CHIP:CTL: Sent operational certificate to the device
[1663741345.611783][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741345.704772][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741345.802137][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741345.899608][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741345.901802][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741345.902004][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741345.902261][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789537 on exchange 51172i
[1663741345.902330][2433:2442] CHIP:EM: Found matching exchange: 51172i, Delegate: 0xffffa8045278
[1663741345.902407][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741345.902501][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741345.902554][2433:2442] CHIP:DMG: {
[1663741345.902604][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741345.902656][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741345.902724][2433:2442] CHIP:DMG:        [
[1663741345.902775][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741345.902859][2433:2442] CHIP:DMG:                {
[1663741345.902913][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741345.902989][2433:2442] CHIP:DMG:                        {
[1663741345.903046][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741345.903149][2433:2442] CHIP:DMG:                                {
[1663741345.903230][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741345.903314][2433:2442] CHIP:DMG:                                        ClusterId = 0x3e,
[1663741345.903397][2433:2442] CHIP:DMG:                                        CommandId = 0x8,
[1663741345.903475][2433:2442] CHIP:DMG:                                },
[1663741345.903557][2433:2442] CHIP:DMG:
[1663741345.903629][2433:2442] CHIP:DMG:                                CommandFields =
[1663741345.903692][2433:2442] CHIP:DMG:                                {
[1663741345.903774][2433:2442] CHIP:DMG:                                        0x0 = 0,
[1663741345.903855][2433:2442] CHIP:DMG:                                        0x1 = 1,
[1663741345.903953][2433:2442] CHIP:DMG:                                },
[1663741345.904027][2433:2442] CHIP:DMG:                        },
[1663741345.904101][2433:2442] CHIP:DMG:
[1663741345.904158][2433:2442] CHIP:DMG:                },
[1663741345.904229][2433:2442] CHIP:DMG:
[1663741345.904278][2433:2442] CHIP:DMG:        ],
[1663741345.904350][2433:2442] CHIP:DMG:
[1663741345.904401][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741345.904450][2433:2442] CHIP:DMG: },
[1663741345.904585][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1663741345.904657][2433:2442] CHIP:CTL: Device returned status 0 on receiving the NOC
[1663741345.904708][2433:2442] CHIP:CTL: Operational credentials provisioned on device 0xffffa0022a10
[1663741345.904753][2433:2442] CHIP:TOO: Secure Pairing Success
[1663741345.904793][2433:2442] CHIP:TOO: CASE establishment successful
[1663741345.904845][2433:2442] CHIP:CTL: Successfully finished commissioning step 'SendNOC'
[1663741345.904894][2433:2442] CHIP:CTL: Commissioning stage next step: 'SendNOC' -> 'ThreadNetworkSetup'
[1663741345.904950][2433:2442] CHIP:CTL: Performing next commissioning step 'ThreadNetworkSetup'
[1663741345.905070][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741345.907840][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741345.908057][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffaa58 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51173i with MessageCounter:205829688.
[1663741345.908143][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffaa58 with MessageCounter:205829688 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006EF36 msec
[1663741345.908346][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741345.908478][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741345.997320][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741345.999249][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741345.999458][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741345.999711][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789538 on exchange 51173i
[1663741345.999780][2433:2442] CHIP:EM: Found matching exchange: 51173i, Delegate: 0xffffa8045118
[1663741345.999855][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741345.999952][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741346.000004][2433:2442] CHIP:DMG: {
[1663741346.000055][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741346.000108][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741346.000176][2433:2442] CHIP:DMG:        [
[1663741346.000227][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741346.000291][2433:2442] CHIP:DMG:                {
[1663741346.000346][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741346.000421][2433:2442] CHIP:DMG:                        {
[1663741346.000483][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741346.000554][2433:2442] CHIP:DMG:                                {
[1663741346.000634][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741346.000717][2433:2442] CHIP:DMG:                                        ClusterId = 0x31,
[1663741346.000799][2433:2442] CHIP:DMG:                                        CommandId = 0x5,
[1663741346.000876][2433:2442] CHIP:DMG:                                },
[1663741346.000958][2433:2442] CHIP:DMG:
[1663741346.001029][2433:2442] CHIP:DMG:                                CommandFields =
[1663741346.001106][2433:2442] CHIP:DMG:                                {
[1663741346.001188][2433:2442] CHIP:DMG:                                        0x0 = 0,
[1663741346.001261][2433:2442] CHIP:DMG:                                        0x2 = 0,
[1663741346.001342][2433:2442] CHIP:DMG:                                },
[1663741346.001416][2433:2442] CHIP:DMG:                        },
[1663741346.001490][2433:2442] CHIP:DMG:
[1663741346.001548][2433:2442] CHIP:DMG:                },
[1663741346.001619][2433:2442] CHIP:DMG:
[1663741346.001717][2433:2442] CHIP:DMG:        ],
[1663741346.001786][2433:2442] CHIP:DMG:
[1663741346.001838][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741346.001888][2433:2442] CHIP:DMG: },
[1663741346.002019][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1663741346.004660][2433:2442] CHIP:CTL: Received NetworkConfig response, networkingStatus=0
[1663741346.004745][2433:2442] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkSetup'
[1663741346.004794][2433:2442] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkSetup' -> 'ThreadNetworkEnable'
[1663741346.004854][2433:2442] CHIP:CTL: Performing next commissioning step 'ThreadNetworkEnable'
[1663741346.004985][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741346.005053][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741346.005232][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffaac8 to 0xFFFFFFFB00000000 (0)  of type 0x8 and protocolId (0, 1) on exchange 51174i with MessageCounter:205829689.
[1663741346.005318][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffaac8 with MessageCounter:205829689 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000006EF97 msec
[1663741346.005514][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741346.005700][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741346.094862][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1663741347.022609][2433:2440] CHIP:DL: Indication received, conn = 0xffffa8043980
[1663741347.022836][2433:2442] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1663741347.023101][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:66789539 on exchange 51174i
[1663741347.023172][2433:2442] CHIP:EM: Found matching exchange: 51174i, Delegate: 0xffffa8045278
[1663741347.023249][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741347.023349][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741347.023403][2433:2442] CHIP:DMG: {
[1663741347.023456][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741347.023508][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741347.023577][2433:2442] CHIP:DMG:        [
[1663741347.023627][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741347.023712][2433:2442] CHIP:DMG:                {
[1663741347.023767][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741347.023834][2433:2442] CHIP:DMG:                        {
[1663741347.023900][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741347.023980][2433:2442] CHIP:DMG:                                {
[1663741347.024061][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741347.024147][2433:2442] CHIP:DMG:                                        ClusterId = 0x31,
[1663741347.024229][2433:2442] CHIP:DMG:                                        CommandId = 0x7,
[1663741347.024308][2433:2442] CHIP:DMG:                                },
[1663741347.024393][2433:2442] CHIP:DMG:
[1663741347.024464][2433:2442] CHIP:DMG:                                CommandFields =
[1663741347.024547][2433:2442] CHIP:DMG:                                {
[1663741347.024633][2433:2442] CHIP:DMG:                                        0x0 = 0,
[1663741347.024718][2433:2442] CHIP:DMG:                                        0x2 = NULL
[1663741347.024801][2433:2442] CHIP:DMG:                                },
[1663741347.024874][2433:2442] CHIP:DMG:                        },
[1663741347.024955][2433:2442] CHIP:DMG:
[1663741347.025013][2433:2442] CHIP:DMG:                },
[1663741347.025083][2433:2442] CHIP:DMG:
[1663741347.025133][2433:2442] CHIP:DMG:        ],
[1663741347.025198][2433:2442] CHIP:DMG:
[1663741347.025251][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741347.025300][2433:2442] CHIP:DMG: },
[1663741347.025431][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1663741347.025504][2433:2442] CHIP:CTL: Received ConnectNetwork response, networkingStatus=0
[1663741347.025567][2433:2442] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkEnable'
[1663741347.025613][2433:2442] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkEnable' -> 'FindOperational'
[1663741347.025723][2433:2442] CHIP:CTL: Performing next commissioning step 'FindOperational'
[1663741347.025772][2433:2442] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001]
[1663741347.025820][2433:2442] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1663741347.025882][2433:2442] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1663741347.025940][2433:2442] CHIP:DIS: Resolving 1AE61EA264E81D69:0000000000000001 ...
[1663741347.027972][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741347.226517][2433:2442] CHIP:DIS: Checking node lookup status after 200 ms
[1663741347.461318][2433:2440] CHIP:DL: Bluez disconnected
[1663741347.461379][2433:2440] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1663741347.461564][2433:2442] CHIP:IN: Clearing BLE pending packets.
[1663741349.231429][2433:2442] CHIP:DL: Avahi resolve found
[1663741349.231567][2433:2442] CHIP:DIS: Node ID resolved for 1AE61EA264E81D69:0000000000000001
[1663741349.231621][2433:2442] CHIP:DIS:        Hostname: 022130C08F33A479
[1663741349.231684][2433:2442] CHIP:DIS:        IP Address #1: fd92:c8ce:db14:1:db8d:9389:8bcd:eb41
[1663741349.231736][2433:2442] CHIP:DIS:        Port: 5540
[1663741349.231783][2433:2442] CHIP:DIS:        Mrp Interval idle: 5000 ms
[1663741349.231830][2433:2442] CHIP:DIS:        Mrp Interval active: 2000 ms
[1663741349.231876][2433:2442] CHIP:DIS:        TCP Supported: 0
[1663741349.232949][2433:2442] CHIP:DIS: Lookup clearing interface for non LL address
[1663741349.233014][2433:2442] CHIP:DIS: UDP:[fd92:c8ce:db14:1:db8d:9389:8bcd:eb41%eth0]:5540: new best score: 6
[1663741349.233066][2433:2442] CHIP:DIS: Checking node lookup status after 2207 ms
[1663741349.233131][2433:2442] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fd92:c8ce:db14:1:db8d:9389:8bcd:eb41]:5540 while in state 2
[1663741349.233183][2433:2442] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3
[1663741349.233419][2433:2442] CHIP:IN: SecureSession[0xffffa002e860]: Allocated Type:2 LSID:15208
[1663741349.233496][2433:2442] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001
[1663741349.234799][2433:2442] CHIP:SC: Including MRP parameters
[1663741349.235051][2433:2442] CHIP:IN: Prepared unauthenticated message 0xffffa00344c8 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 51175i with MessageCounter:102454463.
[1663741349.235142][2433:2442] CHIP:IN: Sending unauthenticated msg 0xffffa00344c8 with MessageCounter:102454463 to 0x0000000000000000 at monotonic time: 000000000006FC35 msec
[1663741349.235483][2433:2442] CHIP:SC: Sent Sigma1 msg
[1663741349.235547][2433:2442] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4
[1663741349.410394][2433:2442] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:131632004 on exchange 51175i
[1663741349.410475][2433:2442] CHIP:EM: Found matching exchange: 51175i, Delegate: 0xffffa0032f18
[1663741349.410552][2433:2442] CHIP:EM: Rxd Ack; Removing MessageCounter:102454463 from Retrans Table on exchange 51175i
[1663741349.410603][2433:2442] CHIP:EM: Removed CHIP MessageCounter:102454463 from RetransTable on exchange 51175i
[1663741349.592497][2433:2442] CHIP:EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:131632005 on exchange 51175i
[1663741349.592580][2433:2442] CHIP:EM: Found matching exchange: 51175i, Delegate: 0xffffa0032f18
[1663741349.592632][2433:2442] CHIP:EM: CHIP MessageCounter:102454463 not in RetransTable on exchange 51175i
[1663741349.592713][2433:2442] CHIP:SC: Received Sigma2 msg
[1663741349.592781][2433:2442] CHIP:SC: Peer assigned session session ID 5924
[1663741349.599462][2433:2442] CHIP:SC: Found MRP parameters in the message
[1663741349.599698][2433:2442] CHIP:SC: Sending Sigma3
[1663741349.600544][2433:2442] CHIP:EM: Piggybacking Ack for MessageCounter:131632005 on exchange: 51175i
[1663741349.600634][2433:2442] CHIP:IN: Prepared unauthenticated message 0xffffa0030c48 to 0x0000000000000000 (0)  of type 0x32 and protocolId (0, 0) on exchange 51175i with MessageCounter:102454464.
[1663741349.600709][2433:2442] CHIP:IN: Sending unauthenticated msg 0xffffa0030c48 with MessageCounter:102454464 to 0x0000000000000000 at monotonic time: 000000000006FDA3 msec
[1663741349.601020][2433:2442] CHIP:SC: Sent Sigma3 msg
[1663741349.828469][2433:2442] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:131632006 on exchange 51175i
[1663741349.828556][2433:2442] CHIP:EM: Found matching exchange: 51175i, Delegate: 0xffffa0032f18
[1663741349.828635][2433:2442] CHIP:EM: Rxd Ack; Removing MessageCounter:102454464 from Retrans Table on exchange 51175i
[1663741349.828688][2433:2442] CHIP:EM: Removed CHIP MessageCounter:102454464 from RetransTable on exchange 51175i
[1663741349.854379][2433:2442] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:131632007 on exchange 51175i
[1663741349.854450][2433:2442] CHIP:EM: Found matching exchange: 51175i, Delegate: 0xffffa0032f18
[1663741349.854500][2433:2442] CHIP:EM: CHIP MessageCounter:102454464 not in RetransTable on exchange 51175i
[1663741349.854574][2433:2442] CHIP:SC: Success status report received. Session was established
[1663741349.873277][2433:2442] CHIP:SC: SecureSession[0xffffa002e860]: Moving from state 'kEstablishing' --> 'kActive'
[1663741349.873355][2433:2442] CHIP:IN: SecureSession[0xffffa002e860]: Activated - Type:2 LSID:15208
[1663741349.873399][2433:2442] CHIP:IN: New secure session activated for device <0000000000000001, 1>, LSID:15208 PSID:5924!
[1663741349.873450][2433:2442] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5
[1663741349.873559][2433:2442] CHIP:CTL: Successfully finished commissioning step 'FindOperational'
[1663741349.873607][2433:2442] CHIP:CTL: Commissioning stage next step: 'FindOperational' -> 'SendComplete'
[1663741349.873700][2433:2442] CHIP:CTL: Performing next commissioning step 'SendComplete'
[1663741349.873809][2433:2442] CHIP:DMG: ICR moving to [AddingComm]
[1663741349.873863][2433:2442] CHIP:DMG: ICR moving to [AddedComma]
[1663741349.874226][2433:2442] CHIP:IN: Prepared secure message 0xffffa002fdd8 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 51176i with MessageCounter:246421608.
[1663741349.874304][2433:2442] CHIP:IN: Sending encrypted msg 0xffffa002fdd8 with MessageCounter:246421608 to 0x0000000000000001 (1) at monotonic time: 000000000006FEB4 msec
[1663741349.874740][2433:2442] CHIP:DMG: ICR moving to [CommandSen]
[1663741349.874839][2433:2442] CHIP:EM: Sending Standalone Ack for MessageCounter:131632007 on exchange 51175i
[1663741349.874915][2433:2442] CHIP:IN: Prepared unauthenticated message 0xffffb2ffbad8 to 0x0000000000000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 51175i with MessageCounter:102454465.
[1663741349.874981][2433:2442] CHIP:IN: Sending unauthenticated msg 0xffffb2ffbad8 with MessageCounter:102454465 to 0x0000000000000000 at monotonic time: 000000000006FEB5 msec
[1663741349.875167][2433:2442] CHIP:EM: Flushed pending ack for MessageCounter:131632007 on exchange 51175i
[1663741349.948406][2433:2442] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:43077365 on exchange 51176i
[1663741349.948485][2433:2442] CHIP:EM: Found matching exchange: 51176i, Delegate: 0xffffa8045118
[1663741349.948577][2433:2442] CHIP:EM: Rxd Ack; Removing MessageCounter:246421608 from Retrans Table on exchange 51176i
[1663741349.948625][2433:2442] CHIP:EM: Removed CHIP MessageCounter:246421608 from RetransTable on exchange 51176i
[1663741349.948693][2433:2442] CHIP:DMG: ICR moving to [ResponseRe]
[1663741349.948790][2433:2442] CHIP:DMG: InvokeResponseMessage =
[1663741349.948835][2433:2442] CHIP:DMG: {
[1663741349.948878][2433:2442] CHIP:DMG:        suppressResponse = false,
[1663741349.948931][2433:2442] CHIP:DMG:        InvokeResponseIBs =
[1663741349.948993][2433:2442] CHIP:DMG:        [
[1663741349.949040][2433:2442] CHIP:DMG:                InvokeResponseIB =
[1663741349.949123][2433:2442] CHIP:DMG:                {
[1663741349.949179][2433:2442] CHIP:DMG:                        CommandDataIB =
[1663741349.949251][2433:2442] CHIP:DMG:                        {
[1663741349.949316][2433:2442] CHIP:DMG:                                CommandPathIB =
[1663741349.949375][2433:2442] CHIP:DMG:                                {
[1663741349.949438][2433:2442] CHIP:DMG:                                        EndpointId = 0x0,
[1663741349.949511][2433:2442] CHIP:DMG:                                        ClusterId = 0x30,
[1663741349.949582][2433:2442] CHIP:DMG:                                        CommandId = 0x5,
[1663741349.949688][2433:2442] CHIP:DMG:                                },
[1663741349.949754][2433:2442] CHIP:DMG:
[1663741349.949809][2433:2442] CHIP:DMG:                                CommandFields =
[1663741349.949876][2433:2442] CHIP:DMG:                                {
[1663741349.949947][2433:2442] CHIP:DMG:                                        0x0 = 0,
[1663741349.950021][2433:2442] CHIP:DMG:                                        0x1 = "" (0 chars),
[1663741349.950092][2433:2442] CHIP:DMG:                                },
[1663741349.950150][2433:2442] CHIP:DMG:                        },
[1663741349.950219][2433:2442] CHIP:DMG:
[1663741349.950269][2433:2442] CHIP:DMG:                },
[1663741349.950330][2433:2442] CHIP:DMG:
[1663741349.950372][2433:2442] CHIP:DMG:        ],
[1663741349.950423][2433:2442] CHIP:DMG:
[1663741349.950466][2433:2442] CHIP:DMG:        InteractionModelRevision = 1
[1663741349.950508][2433:2442] CHIP:DMG: },
[1663741349.950626][2433:2442] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005
[1663741349.950690][2433:2442] CHIP:CTL: Received CommissioningComplete response, errorCode=0
[1663741349.950736][2433:2442] CHIP:CTL: Successfully finished commissioning step 'SendComplete'
[1663741349.950775][2433:2442] CHIP:CTL: Commissioning stage next step: 'SendComplete' -> 'Cleanup'
[1663741349.950825][2433:2442] CHIP:CTL: Performing next commissioning step 'Cleanup'
[1663741349.950867][2433:2442] CHIP:DIS: Closing all BLE connections
[1663741349.950961][2433:2442] CHIP:CTL: Successfully finished commissioning step 'Cleanup'
[1663741349.951015][2433:2442] CHIP:TOO: Device commissioning completed with success
[1663741349.951127][2433:2442] CHIP:DMG: ICR moving to [AwaitingDe]
[1663741349.951188][2433:2442] CHIP:EM: Sending Standalone Ack for MessageCounter:43077365 on exchange 51176i
[1663741349.951285][2433:2442] CHIP:IN: Prepared secure message 0xffffb2ffbae8 to 0x0000000000000001 (1)  of type 0x10 and protocolId (0, 0) on exchange 51176i with MessageCounter:246421609.
[1663741349.951344][2433:2442] CHIP:IN: Sending encrypted msg 0xffffb2ffbae8 with MessageCounter:246421609 to 0x0000000000000001 (1) at monotonic time: 000000000006FF01 msec
[1663741349.951534][2433:2442] CHIP:EM: Flushed pending ack for MessageCounter:43077365 on exchange 51176i
[1663741349.952001][2433:2433] CHIP:CTL: Shutting down the commissioner
[1663741349.952057][2433:2433] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1663741349.952091][2433:2433] CHIP:CTL: Shutting down the controller
[1663741349.952169][2433:2433] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1663741349.952202][2433:2433] CHIP:IN: SecureSession[0xffffa002e860]: MarkForEviction Type:2 LSID:15208
[1663741349.952234][2433:2433] CHIP:SC: SecureSession[0xffffa002e860]: Moving from state 'kActive' --> 'kPendingEviction'
[1663741349.952327][2433:2433] CHIP:IN: SecureSession[0xffffa002e860]: Released - Type:2 LSID:15208
[1663741349.952381][2433:2433] CHIP:FP: Forgetting fabric 0x1
[1663741349.952431][2433:2433] CHIP:TS: Pending Last Known Good Time: 2022-09-15T11:07:06
[1663741349.952627][2433:2433] CHIP:TS: Previous Last Known Good Time: 2022-09-15T11:07:06
[1663741349.952663][2433:2433] CHIP:TS: Reverted Last Known Good Time to previous value
[1663741349.952722][2433:2433] CHIP:CTL: Shutting down the commissioner
[1663741349.952754][2433:2433] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1663741349.952798][2433:2433] CHIP:CTL: Shutting down the controller
[1663741349.952826][2433:2433] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1663741349.954171][2433:2433] CHIP:DMG: IM WH moving to [Uninitialized]
[1663741349.954230][2433:2433] CHIP:DMG: IM WH moving to [Uninitialized]
[1663741349.954257][2433:2433] CHIP:DMG: IM WH moving to [Uninitialized]
[1663741349.954285][2433:2433] CHIP:DMG: IM WH moving to [Uninitialized]
[1663741349.954317][2433:2433] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1663741349.954446][2433:2433] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1663741349.954502][2433:2433] CHIP:IN: SecureSession[0xffffa0020d20]: MarkForEviction Type:1 LSID:15207
[1663741349.954540][2433:2433] CHIP:SC: SecureSession[0xffffa0020d20]: Moving from state 'kActive' --> 'kPendingEviction'
[1663741349.954573][2433:2433] CHIP:IN: SecureSession[0xffffa0020d20]: Released - Type:1 LSID:15207
[1663741349.954966][2433:2433] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-eDwZBb)
[1663741349.955910][2433:2433] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1663741349.955995][2433:2433] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1663741349.956031][2433:2433] CHIP:DL: Inet Layer shutdown
[1663741349.956061][2433:2433] CHIP:DL: BLE shutdown
[1663741349.958867][2433:2433] CHIP:DL: System Layer shutdown
ubuntu@ubuntu:~$

                5、chiptool对mg24进行开关控制可以看到板子的灯接收toggle进行亮灭

ubuntu@ubuntu:~$ ./chip-tool-debug onoff toggle 1 1
[1663739325.440261][2794:2794] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1663739325.440706][2794:2794] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1663739325.440854][2794:2794] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1663739325.440957][2794:2794] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1663739325.441243][2794:2794] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-dfmnlv)
[1663739325.441805][2794:2794] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1663739325.441861][2794:2794] CHIP:DL: NVS set: chip-counters/reboot-count = 7 (0x7)
[1663739325.442403][2794:2794] CHIP:DL: Got Ethernet interface: eth0
[1663739325.442728][2794:2794] CHIP:DL: Found the primary Ethernet interface:eth0
[1663739325.443075][2794:2794] CHIP:DL: Got WiFi interface: wlan0
[1663739325.443131][2794:2794] CHIP:DL: Failed to reset WiFi statistic counts
[1663739325.443184][2794:2794] CHIP:IN: UDP::Init bind&listen port=0
[1663739325.443282][2794:2794] CHIP:IN: UDP::Init bound to port=50378
[1663739325.443304][2794:2794] CHIP:IN: UDP::Init bind&listen port=0
[1663739325.443379][2794:2794] CHIP:IN: UDP::Init bound to port=56626
[1663739325.443399][2794:2794] CHIP:IN: BLEBase::Init - setting/overriding transport
[1663739325.443417][2794:2794] CHIP:IN: TransportMgr initialized
[1663739325.443453][2794:2794] CHIP:FP: Initializing FabricTable from persistent storage
[1663739325.443592][2794:2794] CHIP:TS: Last Known Good Time: 2022-09-15T11:07:06
[1663739325.444020][2794:2794] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xCB3A6D59D8894038, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1663739325.447292][2794:2794] CHIP:ZCL: Using ZAP configuration...
[1663739325.451229][2794:2794] CHIP:DL: Avahi client registered
[1663739325.452431][2794:2794] CHIP:CTL: System State Initialized...
[1663739325.452548][2794:2794] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1663739325.452600][2794:2794] CHIP:CTL: Setting attestation nonce to random value
[1663739325.452649][2794:2794] CHIP:CTL: Setting CSR nonce to random value
[1663739325.452934][2794:2799] CHIP:DL: CHIP task running
[1663739325.453135][2794:2799] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1663739325.453206][2794:2799] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1663739325.453243][2794:2799] CHIP:CTL: Setting attestation nonce to random value
[1663739325.453350][2794:2799] CHIP:CTL: Setting CSR nonce to random value
[1663739325.456067][2794:2799] CHIP:CTL: Generating NOC
[1663739325.457250][2794:2799] CHIP:FP: Validating NOC chain
[1663739325.460014][2794:2799] CHIP:FP: NOC chain validation successful
[1663739325.460256][2794:2799] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1663739325.460304][2794:2799] CHIP:TS: Last Known Good Time: 2022-09-15T11:07:06
[1663739325.460338][2794:2799] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1663739325.460369][2794:2799] CHIP:TS: Retaining current Last Known Good Time
[1663739325.466224][2794:2799] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1663739325.468380][2794:2799] CHIP:TS: Committing Last Known Good Time to storage: 2022-09-15T11:07:06
[1663739325.477438][2794:2799] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x0000000000000000
[1663739325.490542][2794:2799] CHIP:TOO: Sending command to node 0x1
[1663739325.490609][2794:2799] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001]
[1663739325.490647][2794:2799] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1663739325.490695][2794:2799] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1663739325.490739][2794:2799] CHIP:DIS: Resolving CB3A6D59D8894038:0000000000000001 ...
[1663739325.493130][2794:2799] CHIP:DL: Avahi resolve found
[1663739325.493252][2794:2799] CHIP:DIS: Node ID resolved for CB3A6D59D8894038:0000000000000001
[1663739325.493290][2794:2799] CHIP:DIS:        Hostname: 26DF39156B1BB0BD
[1663739325.493332][2794:2799] CHIP:DIS:        IP Address #1: fd92:c8ce:db14:1:f5f6:4f4:9ae2:4c01
[1663739325.493364][2794:2799] CHIP:DIS:        Port: 5540
[1663739325.493395][2794:2799] CHIP:DIS:        Mrp Interval idle: 5000 ms
[1663739325.493424][2794:2799] CHIP:DIS:        Mrp Interval active: 2000 ms
[1663739325.493455][2794:2799] CHIP:DIS:        TCP Supported: 0
[1663739325.494374][2794:2799] CHIP:DIS: Lookup clearing interface for non LL address
[1663739325.494420][2794:2799] CHIP:DIS: UDP:[fd92:c8ce:db14:1:f5f6:4f4:9ae2:4c01%eth0]:5540: new best score: 6
[1663739325.494454][2794:2799] CHIP:DIS: Checking node lookup status after 3 ms
[1663739325.494483][2794:2799] CHIP:DIS: Keeping DNSSD lookup active
[1663739325.691153][2794:2799] CHIP:DIS: Checking node lookup status after 200 ms
[1663739325.691248][2794:2799] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fd92:c8ce:db14:1:f5f6:4f4:9ae2:4c01]:5540 while in state 2
[1663739325.691300][2794:2799] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3
[1663739325.691543][2794:2799] CHIP:IN: SecureSession[0xffff9c0210a0]: Allocated Type:2 LSID:64991
[1663739325.691620][2794:2799] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001
[1663739325.693058][2794:2799] CHIP:SC: Including MRP parameters
[1663739325.693309][2794:2799] CHIP:IN: Prepared unauthenticated message 0xffff9c020a68 to 0x0000000000000000 (0)  of type 0x30 and protocolId (0, 0) on exchange 11496i with MessageCounter:247697173.
[1663739325.693396][2794:2799] CHIP:IN: Sending unauthenticated msg 0xffff9c020a68 with MessageCounter:247697173 to 0x0000000000000000 at monotonic time: 00000000000B9A57 msec
[1663739325.693801][2794:2799] CHIP:SC: Sent Sigma1 msg
[1663739325.693979][2794:2799] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4
[1663739325.792909][2794:2799] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:40500220 on exchange 11496i
[1663739325.792999][2794:2799] CHIP:EM: Found matching exchange: 11496i, Delegate: 0xffff9c022c98
[1663739325.793077][2794:2799] CHIP:EM: Rxd Ack; Removing MessageCounter:247697173 from Retrans Table on exchange 11496i
[1663739325.793134][2794:2799] CHIP:EM: Removed CHIP MessageCounter:247697173 from RetransTable on exchange 11496i
[1663739325.924909][2794:2799] CHIP:EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:40500221 on exchange 11496i
[1663739325.924984][2794:2799] CHIP:EM: Found matching exchange: 11496i, Delegate: 0xffff9c022c98
[1663739325.925036][2794:2799] CHIP:EM: CHIP MessageCounter:247697173 not in RetransTable on exchange 11496i
[1663739325.925104][2794:2799] CHIP:SC: Received Sigma2 msg
[1663739325.925162][2794:2799] CHIP:SC: Peer assigned session session ID 47157
[1663739325.932162][2794:2799] CHIP:SC: Found MRP parameters in the message
[1663739325.932274][2794:2799] CHIP:SC: Sending Sigma3
[1663739325.933244][2794:2799] CHIP:EM: Piggybacking Ack for MessageCounter:40500221 on exchange: 11496i
[1663739325.933359][2794:2799] CHIP:IN: Prepared unauthenticated message 0xffff9c01dae8 to 0x0000000000000000 (0)  of type 0x32 and protocolId (0, 0) on exchange 11496i with MessageCounter:247697174.
[1663739325.933613][2794:2799] CHIP:IN: Sending unauthenticated msg 0xffff9c01dae8 with MessageCounter:247697174 to 0x0000000000000000 at monotonic time: 00000000000B9B48 msec
[1663739325.935022][2794:2799] CHIP:SC: Sent Sigma3 msg
[1663739326.310802][2794:2799] CHIP:IN: Received a duplicate message with MessageCounter:40500221 on exchange 11496i
[1663739326.310879][2794:2799] CHIP:EM: Received message of type 0x31 with protocolId (0, 0) and MessageCounter:40500221 on exchange 11496i
[1663739326.310926][2794:2799] CHIP:EM: Found matching exchange: 11496i, Delegate: 0xffff9c022c98
[1663739326.310970][2794:2799] CHIP:EM: Forcing tx of solitary ack for duplicate MessageCounter:40500221 on exchange 11496i
[1663739326.311012][2794:2799] CHIP:EM: Sending Standalone Ack for MessageCounter:40500221 on exchange 11496i
[1663739326.311088][2794:2799] CHIP:IN: Prepared unauthenticated message 0xffffb22c7b28 to 0x0000000000000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 11496i with MessageCounter:247697175.
[1663739326.311424][2794:2799] CHIP:IN: Sending unauthenticated msg 0xffffb22c7b28 with MessageCounter:247697175 to 0x0000000000000000 at monotonic time: 00000000000B9CC1 msec
[1663739326.320846][2794:2799] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:40500222 on exchange 11496i
[1663739326.320916][2794:2799] CHIP:EM: Found matching exchange: 11496i, Delegate: 0xffff9c022c98
[1663739326.320979][2794:2799] CHIP:EM: Rxd Ack; Removing MessageCounter:247697174 from Retrans Table on exchange 11496i
[1663739326.321013][2794:2799] CHIP:EM: Removed CHIP MessageCounter:247697174 from RetransTable on exchange 11496i
[1663739326.330878][2794:2799] CHIP:EM: Received message of type 0x40 with protocolId (0, 0) and MessageCounter:40500223 on exchange 11496i
[1663739326.330951][2794:2799] CHIP:EM: Found matching exchange: 11496i, Delegate: 0xffff9c022c98
[1663739326.331000][2794:2799] CHIP:EM: CHIP MessageCounter:247697174 not in RetransTable on exchange 11496i
[1663739326.331071][2794:2799] CHIP:SC: Success status report received. Session was established
[1663739326.334933][2794:2799] CHIP:SC: SecureSession[0xffff9c0210a0]: Moving from state 'kEstablishing' --> 'kActive'
[1663739326.335006][2794:2799] CHIP:IN: SecureSession[0xffff9c0210a0]: Activated - Type:2 LSID:64991
[1663739326.335044][2794:2799] CHIP:IN: New secure session activated for device <0000000000000001, 1>, LSID:64991 PSID:47157!
[1663739326.335085][2794:2799] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5
[1663739326.335169][2794:2799] CHIP:TOO: Sending cluster (0x00000006) command (0x00000002) on endpoint 1
[1663739326.335249][2794:2799] CHIP:DMG: ICR moving to [AddingComm]
[1663739326.335313][2794:2799] CHIP:DMG: ICR moving to [AddedComma]
[1663739326.335483][2794:2799] CHIP:IN: Prepared secure message 0xffff9c01cbb8 to 0x0000000000000001 (1)  of type 0x8 and protocolId (0, 1) on exchange 11497i with MessageCounter:93865479.
[1663739326.335551][2794:2799] CHIP:IN: Sending encrypted msg 0xffff9c01cbb8 with MessageCounter:93865479 to 0x0000000000000001 (1) at monotonic time: 00000000000B9CDA msec
[1663739326.336489][2794:2799] CHIP:DMG: ICR moving to [CommandSen]
[1663739326.336661][2794:2799] CHIP:EM: Sending Standalone Ack for MessageCounter:40500223 on exchange 11496i
[1663739326.336741][2794:2799] CHIP:IN: Prepared unauthenticated message 0xffffb22c7ad8 to 0x0000000000000000 (0)  of type 0x10 and protocolId (0, 0) on exchange 11496i with MessageCounter:247697176.
[1663739326.336805][2794:2799] CHIP:IN: Sending unauthenticated msg 0xffffb22c7ad8 with MessageCounter:247697176 to 0x0000000000000000 at monotonic time: 00000000000B9CDB msec
[1663739326.337010][2794:2799] CHIP:EM: Flushed pending ack for MessageCounter:40500223 on exchange 11496i
[1663739326.440970][2794:2799] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:132422517 on exchange 11497i
[1663739326.441046][2794:2799] CHIP:EM: Found matching exchange: 11497i, Delegate: 0xffff9c020908
[1663739326.441115][2794:2799] CHIP:EM: Rxd Ack; Removing MessageCounter:93865479 from Retrans Table on exchange 11497i
[1663739326.441163][2794:2799] CHIP:EM: Removed CHIP MessageCounter:93865479 from RetransTable on exchange 11497i
[1663739326.441233][2794:2799] CHIP:DMG: ICR moving to [ResponseRe]
[1663739326.441324][2794:2799] CHIP:DMG: InvokeResponseMessage =
[1663739326.441376][2794:2799] CHIP:DMG: {
[1663739326.441422][2794:2799] CHIP:DMG:        suppressResponse = false,
[1663739326.441470][2794:2799] CHIP:DMG:        InvokeResponseIBs =
[1663739326.441612][2794:2799] CHIP:DMG:        [
[1663739326.441664][2794:2799] CHIP:DMG:                InvokeResponseIB =
[1663739326.441742][2794:2799] CHIP:DMG:                {
[1663739326.441815][2794:2799] CHIP:DMG:                        CommandStatusIB =
[1663739326.441925][2794:2799] CHIP:DMG:                        {
[1663739326.441993][2794:2799] CHIP:DMG:                                CommandPathIB =
[1663739326.442058][2794:2799] CHIP:DMG:                                {
[1663739326.442134][2794:2799] CHIP:DMG:                                        EndpointId = 0x1,
[1663739326.442205][2794:2799] CHIP:DMG:                                        ClusterId = 0x6,
[1663739326.442274][2794:2799] CHIP:DMG:                                        CommandId = 0x2,
[1663739326.442335][2794:2799] CHIP:DMG:                                },
[1663739326.442411][2794:2799] CHIP:DMG:
[1663739326.442473][2794:2799] CHIP:DMG:                                StatusIB =
[1663739326.442541][2794:2799] CHIP:DMG:                                {
[1663739326.442610][2794:2799] CHIP:DMG:                                        status = 0x00 (SUCCESS),
[1663739326.442675][2794:2799] CHIP:DMG:                                },
[1663739326.442734][2794:2799] CHIP:DMG:
[1663739326.442795][2794:2799] CHIP:DMG:                        },
[1663739326.442864][2794:2799] CHIP:DMG:
[1663739326.442914][2794:2799] CHIP:DMG:                },
[1663739326.442975][2794:2799] CHIP:DMG:
[1663739326.443018][2794:2799] CHIP:DMG:        ],
[1663739326.443073][2794:2799] CHIP:DMG:
[1663739326.443117][2794:2799] CHIP:DMG:        InteractionModelRevision = 1
[1663739326.443158][2794:2799] CHIP:DMG: },
[1663739326.443270][2794:2799] CHIP:DMG: Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
[1663739326.443347][2794:2799] CHIP:DMG: ICR moving to [AwaitingDe]
[1663739326.443441][2794:2799] CHIP:EM: Sending Standalone Ack for MessageCounter:132422517 on exchange 11497i
[1663739326.443568][2794:2799] CHIP:IN: Prepared secure message 0xffffb22c7ae8 to 0x0000000000000001 (1)  of type 0x10 and protocolId (0, 0) on exchange 11497i with MessageCounter:93865480.
[1663739326.443639][2794:2799] CHIP:IN: Sending encrypted msg 0xffffb22c7ae8 with MessageCounter:93865480 to 0x0000000000000001 (1) at monotonic time: 00000000000B9D46 msec
[1663739326.443856][2794:2799] CHIP:EM: Flushed pending ack for MessageCounter:132422517 on exchange 11497i
[1663739326.444177][2794:2794] CHIP:CTL: Shutting down the commissioner
[1663739326.444238][2794:2794] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1663739326.444273][2794:2794] CHIP:CTL: Shutting down the controller
[1663739326.444305][2794:2794] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1663739326.444336][2794:2794] CHIP:IN: SecureSession[0xffff9c0210a0]: MarkForEviction Type:2 LSID:64991
[1663739326.444369][2794:2794] CHIP:SC: SecureSession[0xffff9c0210a0]: Moving from state 'kActive' --> 'kPendingEviction'
[1663739326.444403][2794:2794] CHIP:IN: SecureSession[0xffff9c0210a0]: Released - Type:2 LSID:64991
[1663739326.444441][2794:2794] CHIP:FP: Forgetting fabric 0x1
[1663739326.444488][2794:2794] CHIP:TS: Pending Last Known Good Time: 2022-09-15T11:07:06
[1663739326.444706][2794:2794] CHIP:TS: Previous Last Known Good Time: 2022-09-15T11:07:06
[1663739326.444744][2794:2794] CHIP:TS: Reverted Last Known Good Time to previous value
[1663739326.444807][2794:2794] CHIP:CTL: Shutting down the commissioner
[1663739326.444840][2794:2794] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1663739326.444870][2794:2794] CHIP:CTL: Shutting down the controller
[1663739326.444898][2794:2794] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1663739326.446507][2794:2794] CHIP:DMG: IM WH moving to [Uninitialized]
[1663739326.446576][2794:2794] CHIP:DMG: IM WH moving to [Uninitialized]
[1663739326.446616][2794:2794] CHIP:DMG: IM WH moving to [Uninitialized]
[1663739326.446652][2794:2794] CHIP:DMG: IM WH moving to [Uninitialized]
[1663739326.446694][2794:2794] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1663739326.446851][2794:2794] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1663739326.447258][2794:2794] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-piGjUr)
[1663739326.448067][2794:2794] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1663739326.448153][2794:2794] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1663739326.448187][2794:2794] CHIP:DL: Inet Layer shutdown
[1663739326.448214][2794:2794] CHIP:DL: BLE shutdown
[1663739326.448241][2794:2794] CHIP:DL: System Layer shutdown
ubuntu@ubuntu:~$

                mg24的log

 

        

        

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值