Hi,
When I use the sample of Lock,commissioning is OK.When I use the sample of window Covering debug mode ,commissioning is err.The following is the log of OTBR:
Best regards,
Danny zhang
Hi,
When I use the sample of Lock,commissioning is OK.When I use the sample of window Covering debug mode ,commissioning is err.The following is the log of OTBR:
Best regards,
Danny zhang
Hi,
The txt file is garbled. Even if I try to convert to UTF8, Big5, or GBK, it's still the same. Please upload it again or insert it as code.
Regards,
Amanda H.
login as: ubuntu [email protected]'s password: Welcome to Ubuntu 20.04.5 LTS (GNU/Linux 5.4.0-1080-raspi aarch64) * Documentation: https://help.ubuntu.com * Management: https://landscape.canonical.com * Support: https://ubuntu.com/advantage System information as of Thu Feb 23 01:32:26 UTC 2023 System load: 0.56 Usage of /: 13.5% of 28.94GB Memory usage: 6% Swap usage: 0% Temperature: 54.0 C Processes: 159 Users logged in: 1 IPv4 address for docker0: 172.17.0.1 IPv4 address for eth0: 192.125.7.128 IPv6 address for eth0: fdcc:d717:194b:46a0:e65f:1ff:fea1:f55f IPv4 address for otbr0: 172.18.0.1 IPv6 address for otbr0: fd11:db8:1::1 * Introducing Expanded Security Maintenance for Applications. Receive updates to over 25,000 software packages with your Ubuntu Pro subscription. Free for personal use. https://ubuntu.com/pro Expanded Security Maintenance for Applications is not enabled. 0 updates can be applied immediately. Enable ESM Apps to receive additional future security updates. See https://ubuntu.com/esm or run: sudo pro status New release '22.04.1 LTS' available. Run 'do-release-upgrade' to upgrade to it. Last login: Thu Feb 23 01:30:49 2023 from 192.125.7.143 ubuntu@ubuntu:~$ sudo docker exec -it otbr sh -c "sudo ot-ctl dataset active -x" 0e080000000000010000000300000f35060004001fffe0020811111111222222220708fddb89809c688d7c051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8 Done ubuntu@ubuntu:~$ 0e080000000000010000000300000f35060004001fffe0020811111111222222220708fddb89809c688d7c051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8 0e080000000000010000000300000f35060004001fffe0020811111111222222220708fddb89809c688d7c051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8: command not found ubuntu@ubuntu:~$ ./chip-tool-debug pairing ble-thread 1234 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fddb89809c688d7c051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8 20202021 3840 -bash: ./chip-tool-debug: No such file or directory ubuntu@ubuntu:~$ cd chip-tool/ ubuntu@ubuntu:~/chip-tool$ ./chip-tool-debug pairing ble-thread 1234 hex:0e080000000000010000000300000f35060004001fffe0020811111111222222220708fddb89809c688d7c051000112233445566778899aabbccddeeff030e4f70656e54687265616444656d6f010212340410445f2b5ca6f2a93a55ce570a70efeecb0c0402a0f7f8 20202021 3840 [1677116165.966184][2434:2434] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1677116165.966422][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_kvs-DMN99f) [1677116165.966576][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1677116165.966907][2434:2434] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1677116165.967026][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-WUgXjf) [1677116165.967134][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1677116165.967206][2434:2434] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1677116165.967291][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_config.ini-6qPUXd) [1677116165.967382][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1677116165.967448][2434:2434] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1677116165.967533][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-LdT8wd) [1677116165.967624][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1677116165.967801][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-PgI9yf) [1677116165.968232][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1677116165.968277][2434:2434] CHIP:DL: NVS set: chip-factory/unique-id = "544E9BD0F029BC48" [1677116165.968392][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-hl0kJf) [1677116165.969093][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1677116165.969140][2434:2434] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1677116165.969259][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-s7YtKf) [1677116165.969794][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1677116165.969841][2434:2434] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1677116165.969965][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-iQQ3Xf) [1677116165.970284][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1677116165.970320][2434:2434] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1677116165.970466][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-nw5mWe) [1677116165.971522][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1677116165.971570][2434:2434] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1677116165.971763][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-bkysOd) [1677116165.972277][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1677116165.972325][2434:2434] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1677116165.972445][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_config.ini-sHaKVe) [1677116165.972725][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1677116165.972761][2434:2434] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1677116165.972858][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_config.ini-QHtoue) [1677116165.973787][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1677116165.973829][2434:2434] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1677116165.974340][2434:2434] CHIP:DL: Got Ethernet interface: eth0 [1677116165.974672][2434:2434] CHIP:DL: Found the primary Ethernet interface:eth0 [1677116165.975039][2434:2434] CHIP:DL: Got WiFi interface: wlan0 [1677116165.975090][2434:2434] CHIP:DL: Failed to reset WiFi statistic counts [1677116165.975145][2434:2434] CHIP:IN: UDP::Init bind&listen port=0 [1677116165.975263][2434:2434] CHIP:IN: UDP::Init bound to port=42562 [1677116165.975288][2434:2434] CHIP:IN: UDP::Init bind&listen port=0 [1677116165.975358][2434:2434] CHIP:IN: UDP::Init bound to port=36582 [1677116165.975379][2434:2434] CHIP:IN: BLEBase::Init - setting/overriding transport [1677116165.975397][2434:2434] CHIP:IN: TransportMgr initialized [1677116165.975538][2434:2434] CHIP:FP: Initializing FabricTable from persistent storage [1677116165.975662][2434:2434] CHIP:TS: Last Known Good Time: [unknown] [1677116165.975690][2434:2434] CHIP:TS: Setting Last Known Good Time to firmware build time 2022-11-30T10:20:26 [1677116165.978948][2434:2434] CHIP:ZCL: Using ZAP configuration... [1677116165.983028][2434:2434] CHIP:DL: Avahi client registered [1677116165.984576][2434:2434] CHIP:CTL: System State Initialized... [1677116165.986171][2434:2434] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1677116165.989318][2434:2434] CHIP:CTL: Setting attestation nonce to random value [1677116165.989395][2434:2434] CHIP:CTL: Setting CSR nonce to random value [1677116165.989700][2434:2441] CHIP:DL: CHIP task running [1677116165.989920][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 32784 [1677116165.990386][2434:2441] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1677116165.990441][2434:2441] CHIP:CTL: Setting attestation nonce to random value [1677116165.990583][2434:2441] CHIP:CTL: Setting CSR nonce to random value [1677116165.991095][2434:2441] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: ../../examples/chip-tool/config/PersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage [1677116165.994678][2434:2441] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: ../../examples/chip-tool/config/PersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage [1677116165.996098][2434:2441] CHIP:CTL: Generating RCAC [1677116166.000506][2434:2441] CHIP:CTL: Generating ICAC [1677116166.001674][2434:2441] CHIP:CTL: Generating NOC [1677116166.002683][2434:2441] CHIP:FP: Validating NOC chain [1677116166.004572][2434:2441] CHIP:FP: NOC chain validation successful [1677116166.006966][2434:2441] CHIP:FP: Added new fabric at index: 0x1 [1677116166.006995][2434:2441] CHIP:FP: Assigned compressed fabric ID: 0x76A23B1FF96B9178, node ID: 0x000000000001B669 [1677116166.007022][2434:2441] CHIP:TS: Last Known Good Time: 2022-11-30T10:20:26 [1677116166.007042][2434:2441] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1677116166.007060][2434:2441] CHIP:TS: Retaining current Last Known Good Time [1677116166.008466][2434:2441] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1677116166.010850][2434:2441] CHIP:TS: Committing Last Known Good Time to storage: 2022-11-30T10:20:26 [1677116166.013152][2434:2441] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x0000000000000000 [1677116166.030692][2434:2441] CHIP:IN: SecureSession[0xffff6801d9f0]: Allocated Type:1 LSID:45493 [1677116166.030755][2434:2441] CHIP:SC: Assigned local session key ID 45493 [1677116166.030879][2434:2441] CHIP:SC: Including MRP parameters in PBKDF param request [1677116166.030961][2434:2441] CHIP:EM: <<< [E:45461i M:30975915] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) [1677116166.031030][2434:2441] CHIP:IN: (U) Sending msg 30975915 to IP address 'BLE' [1677116166.031065][2434:2441] CHIP:IN: Message appended to BLE send queue [1677116166.031093][2434:2441] CHIP:SC: Sent PBKDF param request [1677116166.031128][2434:2441] CHIP:CTL: Setting thread operational dataset from parameters [1677116166.031152][2434:2441] CHIP:CTL: Setting attempt thread scan from parameters [1677116166.031177][2434:2441] CHIP:CTL: Setting attestation nonce to random value [1677116166.031229][2434:2441] CHIP:CTL: Setting CSR nonce to random value [1677116166.031282][2434:2441] CHIP:CTL: Commission called for node ID 0x00000000000004D2 [1677116166.031507][2434:2442] CHIP:DL: TRACE: Bluez mainloop starting Thread [1677116166.031698][2434:2439] CHIP:DL: TRACE: Bus acquired for name C-0982 [1677116166.043040][2434:2441] CHIP:DL: PlatformBlueZInit init success [1677116166.050856][2434:2439] CHIP:BLE: BLE removing known devices. [1677116166.052418][2434:2439] CHIP:BLE: BLE initiating scan. [1677116166.076329][2434:2439] CHIP:BLE: Device 45:95:5F:1E:B6:BC does not look like a CHIP device. [1677116166.088707][2434:2439] CHIP:BLE: Device 7C:CA:D7:5F:29:24 does not look like a CHIP device. [1677116166.105824][2434:2439] CHIP:BLE: Device 52:95:69:57:85:C9 does not look like a CHIP device. [1677116166.119958][2434:2439] CHIP:BLE: Device C3:34:9F:71:B9:91 does not look like a CHIP device. [1677116166.122209][2434:2439] CHIP:BLE: Device DB:18:3C:38:6E:6A does not look like a CHIP device. [1677116166.124223][2434:2439] CHIP:BLE: Device 4A:A3:6E:6D:43:34 does not look like a CHIP device. [1677116166.145873][2434:2439] CHIP:BLE: Device EB:19:61:E1:53:99 does not look like a CHIP device. [1677116166.147546][2434:2439] CHIP:BLE: Device FB:EE:DC:3F:B7:7C does not look like a CHIP device. [1677116166.149353][2434:2439] CHIP:BLE: Device DE:5D:38:D8:99:E1 does not look like a CHIP device. [1677116166.154544][2434:2439] CHIP:BLE: Device 6D:21:EA:2A:EC:2A does not look like a CHIP device. [1677116166.155927][2434:2439] CHIP:BLE: Device 7A:41:E3:0A:92:86 does not look like a CHIP device. [1677116166.160295][2434:2439] CHIP:BLE: Device 5C:77:E4:A1:D1:E6 does not look like a CHIP device. [1677116166.191178][2434:2439] CHIP:BLE: Device 13:0C:68:4D:26:BA does not look like a CHIP device. [1677116166.203266][2434:2439] CHIP:BLE: Device 78:4B:1C:3F:B4:A9 does not look like a CHIP device. [1677116166.215553][2434:2439] CHIP:BLE: Device C5:D4:17:6B:AC:05 does not look like a CHIP device. [1677116166.217213][2434:2439] CHIP:BLE: Device 46:5F:FA:8A:BA:EA does not look like a CHIP device. [1677116166.227651][2434:2439] CHIP:BLE: New device scanned: F5:55:C7:0C:46:79 [1677116166.227711][2434:2439] CHIP:BLE: Device discriminator match. Attempting to connect. [1677116166.231641][2434:2439] CHIP:BLE: Scan complete notification without an active scan. [1677116166.765611][2434:2439] CHIP:DL: ConnectDevice complete [1677116168.792036][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0001 [1677116168.792099][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792162][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0001 [1677116168.792190][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792222][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0001 [1677116168.792247][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792292][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0001 [1677116168.792319][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792350][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0001 [1677116168.792376][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792407][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0001 [1677116168.792459][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792497][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792523][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792590][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792616][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792649][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792687][2434:2439] CHIP:DL: Char1 /org/bluez/hci0/dev_F5_55_C7_0C_46_79/service0010 [1677116168.792726][2434:2439] CHIP:DL: New BLE connection 0xffff740572f0, device F5:55:C7:0C:46:79, path /org/bluez/hci0/dev_F5_55_C7_0C_46_79 [1677116168.792864][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16385 [1677116168.792939][2434:2441] CHIP:IN: BleConnectionComplete: endPoint 0xaaaaaea6d1c8 [1677116169.396897][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116169.495074][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1677116169.495158][2434:2441] CHIP:BLE: subscribe complete, ep = 0xaaaaaea6d1c8 [1677116169.543388][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116169.543595][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116169.543665][2434:2441] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4 [1677116169.543716][2434:2441] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244. [1677116169.543762][2434:2441] CHIP:BLE: local and remote recv window size = 5 [1677116169.543946][2434:2441] CHIP:IN: BLE EndPoint 0xaaaaaea6d1c8 Connection Complete [1677116169.690191][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116169.788948][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116169.789171][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116169.789387][2434:2441] CHIP:EM: >>> [E:45461i M:260332604] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) [1677116169.789464][2434:2441] CHIP:EM: Found matching exchange: 45461i, Delegate: 0xffff68024320 [1677116169.789548][2434:2441] CHIP:SC: Received PBKDF param response [1677116169.789632][2434:2441] CHIP:SC: Peer assigned session ID 28497 [1677116169.790077][2434:2441] CHIP:SC: Found MRP parameters in the message [1677116169.799526][2434:2441] CHIP:EM: <<< [E:45461i M:30975916] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1) [1677116169.799590][2434:2441] CHIP:IN: (U) Sending msg 30975916 to IP address 'BLE' [1677116169.799707][2434:2441] CHIP:SC: Sent spake2p msg1 [1677116169.932945][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116171.787825][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116171.788065][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116171.788329][2434:2441] CHIP:EM: >>> [E:45461i M:260332605] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2) [1677116171.788406][2434:2441] CHIP:EM: Found matching exchange: 45461i, Delegate: 0xffff68024320 [1677116171.788486][2434:2441] CHIP:SC: Received spake2p msg2 [1677116171.791587][2434:2441] CHIP:EM: <<< [E:45461i M:30975917] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3) [1677116171.791686][2434:2441] CHIP:IN: (U) Sending msg 30975917 to IP address 'BLE' [1677116171.791862][2434:2441] CHIP:SC: Sent spake2p msg3 [1677116171.882784][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116171.884640][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116171.884851][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116171.885067][2434:2441] CHIP:EM: >>> [E:45461i M:260332606] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) [1677116171.885141][2434:2441] CHIP:EM: Found matching exchange: 45461i, Delegate: 0xffff68024320 [1677116171.885312][2434:2441] CHIP:SC: SecureSession[0xffff6801d9f0]: Moving from state 'kEstablishing' --> 'kActive' [1677116171.885372][2434:2441] CHIP:IN: SecureSession[0xffff6801d9f0]: Activated - Type:1 LSID:45493 [1677116171.885420][2434:2441] CHIP:IN: New secure session activated for device <FFFFFFFB00000000, 0>, LSID:45493 PSID:28497! [1677116171.885477][2434:2441] CHIP:CTL: Remote device completed SPAKE2+ handshake [1677116171.885523][2434:2441] CHIP:TOO: Pairing Success [1677116171.885564][2434:2441] CHIP:TOO: PASE establishment successful [1677116171.885665][2434:2441] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo' [1677116171.885723][2434:2441] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo' [1677116171.885768][2434:2441] CHIP:CTL: Sending request for commissioning information [1677116171.885881][2434:2441] CHIP:DMG: SendReadRequest ReadClient[0xffff680362c0]: Sending Read Request [1677116171.886122][2434:2441] CHIP:EM: <<< [E:45462i M:258977202] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) [1677116171.886208][2434:2441] CHIP:IN: (S) Sending msg 258977202 on secure session with LSID: 45493 [1677116171.886384][2434:2441] CHIP:DMG: MoveToState ReadClient[0xffff680362c0]: Moving to [AwaitingIn] [1677116171.980711][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116171.984238][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116171.984397][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116172.082977][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116172.083199][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116172.083438][2434:2441] CHIP:EM: >>> [E:45462i M:121797160] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) [1677116172.083514][2434:2441] CHIP:EM: Found matching exchange: 45462i, Delegate: 0xffff680362d0 [1677116172.084108][2434:2441] CHIP:DMG: ReportDataMessage = [1677116172.084217][2434:2441] CHIP:DMG: { [1677116172.084259][2434:2441] CHIP:DMG: AttributeReportIBs = [1677116172.084318][2434:2441] CHIP:DMG: [ [1677116172.084364][2434:2441] CHIP:DMG: AttributeReportIB = [1677116172.084436][2434:2441] CHIP:DMG: { [1677116172.084493][2434:2441] CHIP:DMG: AttributeDataIB = [1677116172.084553][2434:2441] CHIP:DMG: { [1677116172.084616][2434:2441] CHIP:DMG: DataVersion = 0xb8f55c73, [1677116172.084694][2434:2441] CHIP:DMG: AttributePathIB = [1677116172.084763][2434:2441] CHIP:DMG: { [1677116172.084827][2434:2441] CHIP:DMG: Endpoint = 0x0, [1677116172.084891][2434:2441] CHIP:DMG: Cluster = 0x31, [1677116172.084965][2434:2441] CHIP:DMG: Attribute = 0x0000_0003, [1677116172.085032][2434:2441] CHIP:DMG: } [1677116172.085103][2434:2441] CHIP:DMG: [1677116172.085174][2434:2441] CHIP:DMG: Data = 20, [1677116172.085238][2434:2441] CHIP:DMG: }, [1677116172.085308][2434:2441] CHIP:DMG: [1677116172.085356][2434:2441] CHIP:DMG: }, [1677116172.085425][2434:2441] CHIP:DMG: [1677116172.085471][2434:2441] CHIP:DMG: AttributeReportIB = [1677116172.085533][2434:2441] CHIP:DMG: { [1677116172.085584][2434:2441] CHIP:DMG: AttributeDataIB = [1677116172.085650][2434:2441] CHIP:DMG: { [1677116172.085705][2434:2441] CHIP:DMG: DataVersion = 0x2aa8ae58, [1677116172.085775][2434:2441] CHIP:DMG: AttributePathIB = [1677116172.085841][2434:2441] CHIP:DMG: { [1677116172.085910][2434:2441] CHIP:DMG: Endpoint = 0x0, [1677116172.085976][2434:2441] CHIP:DMG: Cluster = 0x28, [1677116172.086035][2434:2441] CHIP:DMG: Attribute = 0x0000_0004, [1677116172.086103][2434:2441] CHIP:DMG: } [1677116172.086161][2434:2441] CHIP:DMG: [1677116172.086223][2434:2441] CHIP:DMG: Data = 32784, [1677116172.086275][2434:2441] CHIP:DMG: }, [1677116172.086335][2434:2441] CHIP:DMG: [1677116172.086385][2434:2441] CHIP:DMG: }, [1677116172.086455][2434:2441] CHIP:DMG: [1677116172.086501][2434:2441] CHIP:DMG: AttributeReportIB = [1677116172.086560][2434:2441] CHIP:DMG: { [1677116172.086608][2434:2441] CHIP:DMG: AttributeDataIB = [1677116172.086655][2434:2441] CHIP:DMG: { [1677116172.086703][2434:2441] CHIP:DMG: DataVersion = 0x2aa8ae58, [1677116172.086751][2434:2441] CHIP:DMG: AttributePathIB = [1677116172.086815][2434:2441] CHIP:DMG: { [1677116172.086886][2434:2441] CHIP:DMG: Endpoint = 0x0, [1677116172.086960][2434:2441] CHIP:DMG: Cluster = 0x28, [1677116172.087033][2434:2441] CHIP:DMG: Attribute = 0x0000_0002, [1677116172.087087][2434:2441] CHIP:DMG: } [1677116172.087166][2434:2441] CHIP:DMG: [1677116172.087231][2434:2441] CHIP:DMG: Data = 65521, [1677116172.087283][2434:2441] CHIP:DMG: }, [1677116172.087335][2434:2441] CHIP:DMG: [1677116172.087382][2434:2441] CHIP:DMG: }, [1677116172.087449][2434:2441] CHIP:DMG: [1677116172.087494][2434:2441] CHIP:DMG: AttributeReportIB = [1677116172.087554][2434:2441] CHIP:DMG: { [1677116172.087601][2434:2441] CHIP:DMG: AttributeDataIB = [1677116172.087665][2434:2441] CHIP:DMG: { [1677116172.087732][2434:2441] CHIP:DMG: DataVersion = 0x754b3fe3, [1677116172.087785][2434:2441] CHIP:DMG: AttributePathIB = [1677116172.087845][2434:2441] CHIP:DMG: { [1677116172.087913][2434:2441] CHIP:DMG: Endpoint = 0x0, [1677116172.087972][2434:2441] CHIP:DMG: Cluster = 0x30, [1677116172.088039][2434:2441] CHIP:DMG: Attribute = 0x0000_0003, [1677116172.088094][2434:2441] CHIP:DMG: } [1677116172.088184][2434:2441] CHIP:DMG: [1677116172.088267][2434:2441] CHIP:DMG: Data = 0, [1677116172.088331][2434:2441] CHIP:DMG: }, [1677116172.088400][2434:2441] CHIP:DMG: [1677116172.088453][2434:2441] CHIP:DMG: }, [1677116172.088524][2434:2441] CHIP:DMG: [1677116172.088569][2434:2441] CHIP:DMG: AttributeReportIB = [1677116172.088630][2434:2441] CHIP:DMG: { [1677116172.088681][2434:2441] CHIP:DMG: AttributeDataIB = [1677116172.088744][2434:2441] CHIP:DMG: { [1677116172.088805][2434:2441] CHIP:DMG: DataVersion = 0x754b3fe3, [1677116172.088869][2434:2441] CHIP:DMG: AttributePathIB = [1677116172.088936][2434:2441] CHIP:DMG: { [1677116172.088997][2434:2441] CHIP:DMG: Endpoint = 0x0, [1677116172.089058][2434:2441] CHIP:DMG: Cluster = 0x30, [1677116172.089130][2434:2441] CHIP:DMG: Attribute = 0x0000_0002, [1677116172.089195][2434:2441] CHIP:DMG: } [1677116172.089267][2434:2441] CHIP:DMG: [1677116172.089337][2434:2441] CHIP:DMG: Data = 0, [1677116172.089395][2434:2441] CHIP:DMG: }, [1677116172.089452][2434:2441] CHIP:DMG: [1677116172.089493][2434:2441] CHIP:DMG: }, [1677116172.089562][2434:2441] CHIP:DMG: [1677116172.089607][2434:2441] CHIP:DMG: AttributeReportIB = [1677116172.089670][2434:2441] CHIP:DMG: { [1677116172.089712][2434:2441] CHIP:DMG: AttributeDataIB = [1677116172.089767][2434:2441] CHIP:DMG: { [1677116172.089834][2434:2441] CHIP:DMG: DataVersion = 0x754b3fe3, [1677116172.089894][2434:2441] CHIP:DMG: AttributePathIB = [1677116172.089961][2434:2441] CHIP:DMG: { [1677116172.090030][2434:2441] CHIP:DMG: Endpoint = 0x0, [1677116172.090090][2434:2441] CHIP:DMG: Cluster = 0x30, [1677116172.090172][2434:2441] CHIP:DMG: Attribute = 0x0000_0001, [1677116172.090234][2434:2441] CHIP:DMG: } [1677116172.090305][2434:2441] CHIP:DMG: [1677116172.090370][2434:2441] CHIP:DMG: Data = [1677116172.090429][2434:2441] CHIP:DMG: { [1677116172.090519][2434:2441] CHIP:DMG: 0x0 = 60, [1677116172.090579][2434:2441] CHIP:DMG: 0x1 = 900, [1677116172.090649][2434:2441] CHIP:DMG: }, [1677116172.090713][2434:2441] CHIP:DMG: }, [1677116172.090784][2434:2441] CHIP:DMG: [1677116172.090834][2434:2441] CHIP:DMG: }, [1677116172.090906][2434:2441] CHIP:DMG: [1677116172.090950][2434:2441] CHIP:DMG: AttributeReportIB = [1677116172.091012][2434:2441] CHIP:DMG: { [1677116172.091062][2434:2441] CHIP:DMG: AttributeDataIB = [1677116172.091125][2434:2441] CHIP:DMG: { [1677116172.091191][2434:2441] CHIP:DMG: DataVersion = 0x754b3fe3, [1677116172.091244][2434:2441] CHIP:DMG: AttributePathIB = [1677116172.091310][2434:2441] CHIP:DMG: { [1677116172.091378][2434:2441] CHIP:DMG: Endpoint = 0x0, [1677116172.091452][2434:2441] CHIP:DMG: Cluster = 0x30, [1677116172.091510][2434:2441] CHIP:DMG: Attribute = 0x0000_0000, [1677116172.091569][2434:2441] CHIP:DMG: } [1677116172.091628][2434:2441] CHIP:DMG: [1677116172.091697][2434:2441] CHIP:DMG: Data = 0, [1677116172.091760][2434:2441] CHIP:DMG: }, [1677116172.091817][2434:2441] CHIP:DMG: [1677116172.091875][2434:2441] CHIP:DMG: }, [1677116172.091941][2434:2441] CHIP:DMG: [1677116172.091986][2434:2441] CHIP:DMG: AttributeReportIB = [1677116172.092049][2434:2441] CHIP:DMG: { [1677116172.092100][2434:2441] CHIP:DMG: AttributeDataIB = [1677116172.092180][2434:2441] CHIP:DMG: { [1677116172.092237][2434:2441] CHIP:DMG: DataVersion = 0xb8f55c73, [1677116172.092296][2434:2441] CHIP:DMG: AttributePathIB = [1677116172.092361][2434:2441] CHIP:DMG: { [1677116172.092424][2434:2441] CHIP:DMG: Endpoint = 0x0, [1677116172.092498][2434:2441] CHIP:DMG: Cluster = 0x31, [1677116172.092570][2434:2441] CHIP:DMG: Attribute = 0x0000_FFFC, [1677116172.092631][2434:2441] CHIP:DMG: } [1677116172.092701][2434:2441] CHIP:DMG: [1677116172.092890][2434:2441] CHIP:DMG: Data = 2, [1677116172.092950][2434:2441] CHIP:DMG: }, [1677116172.093020][2434:2441] CHIP:DMG: [1677116172.093066][2434:2441] CHIP:DMG: }, [1677116172.093122][2434:2441] CHIP:DMG: [1677116172.093165][2434:2441] CHIP:DMG: ], [1677116172.093274][2434:2441] CHIP:DMG: [1677116172.093321][2434:2441] CHIP:DMG: SuppressResponse = true, [1677116172.093367][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116172.093410][2434:2441] CHIP:DMG: } [1677116172.094888][2434:2441] CHIP:CTL: ----- NetworkCommissioning Features: has Thread. endpointid = 0 [1677116172.094990][2434:2441] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo' [1677116172.095016][2434:2441] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe' [1677116172.095041][2434:2441] CHIP:CTL: Performing next commissioning step 'ArmFailSafe' [1677116172.095057][2434:2441] CHIP:CTL: Arming failsafe (60 seconds) [1677116172.095171][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116172.095197][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116172.095288][2434:2441] CHIP:EM: <<< [E:45463i M:258977203] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116172.095320][2434:2441] CHIP:IN: (S) Sending msg 258977203 on secure session with LSID: 45493 [1677116172.095410][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116172.261772][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116172.263611][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116172.263812][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116172.264080][2434:2441] CHIP:EM: >>> [E:45463i M:121797161] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116172.264211][2434:2441] CHIP:EM: Found matching exchange: 45463i, Delegate: 0xffff74058278 [1677116172.264297][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116172.264398][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116172.264453][2434:2441] CHIP:DMG: { [1677116172.264504][2434:2441] CHIP:DMG: suppressResponse = false, [1677116172.264558][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116172.264629][2434:2441] CHIP:DMG: [ [1677116172.264680][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116172.264763][2434:2441] CHIP:DMG: { [1677116172.264823][2434:2441] CHIP:DMG: CommandDataIB = [1677116172.264898][2434:2441] CHIP:DMG: { [1677116172.264966][2434:2441] CHIP:DMG: CommandPathIB = [1677116172.265044][2434:2441] CHIP:DMG: { [1677116172.265118][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116172.265189][2434:2441] CHIP:DMG: ClusterId = 0x30, [1677116172.265272][2434:2441] CHIP:DMG: CommandId = 0x1, [1677116172.265349][2434:2441] CHIP:DMG: }, [1677116172.265423][2434:2441] CHIP:DMG: [1677116172.265484][2434:2441] CHIP:DMG: CommandFields = [1677116172.265560][2434:2441] CHIP:DMG: { [1677116172.265642][2434:2441] CHIP:DMG: 0x0 = 0, [1677116172.265733][2434:2441] CHIP:DMG: 0x1 = "" (0 chars), [1677116172.265802][2434:2441] CHIP:DMG: }, [1677116172.265874][2434:2441] CHIP:DMG: }, [1677116172.265956][2434:2441] CHIP:DMG: [1677116172.266015][2434:2441] CHIP:DMG: }, [1677116172.266086][2434:2441] CHIP:DMG: [1677116172.266141][2434:2441] CHIP:DMG: ], [1677116172.266208][2434:2441] CHIP:DMG: [1677116172.266259][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116172.266309][2434:2441] CHIP:DMG: }, [1677116172.266442][2434:2441] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001 [1677116172.266622][2434:2441] CHIP:CTL: Received ArmFailSafe response errorCode=0 [1677116172.266686][2434:2441] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe' [1677116172.266736][2434:2441] CHIP:CTL: No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks [1677116172.266779][2434:2441] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory' [1677116172.266835][2434:2441] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory' [1677116172.266880][2434:2441] CHIP:CTL: Setting Regulatory Config [1677116172.266922][2434:2441] CHIP:CTL: Device does not support configurable regulatory location [1677116172.267036][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116172.267104][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116172.267259][2434:2441] CHIP:EM: <<< [E:45464i M:258977204] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116172.267342][2434:2441] CHIP:IN: (S) Sending msg 258977204 on secure session with LSID: 45493 [1677116172.267520][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116172.267635][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116172.396868][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116172.398600][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116172.398808][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116172.399077][2434:2441] CHIP:EM: >>> [E:45464i M:121797162] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116172.399155][2434:2441] CHIP:EM: Found matching exchange: 45464i, Delegate: 0xffff68020f18 [1677116172.399232][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116172.399328][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116172.399381][2434:2441] CHIP:DMG: { [1677116172.399431][2434:2441] CHIP:DMG: suppressResponse = false, [1677116172.399484][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116172.399551][2434:2441] CHIP:DMG: [ [1677116172.399602][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116172.399683][2434:2441] CHIP:DMG: { [1677116172.399739][2434:2441] CHIP:DMG: CommandDataIB = [1677116172.399806][2434:2441] CHIP:DMG: { [1677116172.399877][2434:2441] CHIP:DMG: CommandPathIB = [1677116172.399946][2434:2441] CHIP:DMG: { [1677116172.400019][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116172.400103][2434:2441] CHIP:DMG: ClusterId = 0x30, [1677116172.400239][2434:2441] CHIP:DMG: CommandId = 0x3, [1677116172.400320][2434:2441] CHIP:DMG: }, [1677116172.400401][2434:2441] CHIP:DMG: [1677116172.400468][2434:2441] CHIP:DMG: CommandFields = [1677116172.400550][2434:2441] CHIP:DMG: { [1677116172.400623][2434:2441] CHIP:DMG: 0x0 = 0, [1677116172.400712][2434:2441] CHIP:DMG: 0x1 = "" (0 chars), [1677116172.400794][2434:2441] CHIP:DMG: }, [1677116172.400867][2434:2441] CHIP:DMG: }, [1677116172.400939][2434:2441] CHIP:DMG: [1677116172.400997][2434:2441] CHIP:DMG: }, [1677116172.401070][2434:2441] CHIP:DMG: [1677116172.401121][2434:2441] CHIP:DMG: ], [1677116172.401186][2434:2441] CHIP:DMG: [1677116172.401236][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116172.401285][2434:2441] CHIP:DMG: }, [1677116172.401419][2434:2441] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003 [1677116172.401552][2434:2441] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0 [1677116172.401615][2434:2441] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory' [1677116172.401661][2434:2441] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest' [1677116172.401717][2434:2441] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest' [1677116172.401762][2434:2441] CHIP:CTL: Sending request for PAI certificate [1677116172.401804][2434:2441] CHIP:CTL: Sending Certificate Chain request to 0xffff680242d0 device [1677116172.401972][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116172.402059][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116172.402219][2434:2441] CHIP:EM: <<< [E:45465i M:258977205] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116172.402306][2434:2441] CHIP:IN: (S) Sending msg 258977205 on secure session with LSID: 45493 [1677116172.402488][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116172.402608][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116172.487683][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116172.670129][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116172.670336][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116172.805200][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116172.805421][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116173.028246][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116173.028472][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116173.028747][2434:2441] CHIP:EM: >>> [E:45465i M:121797163] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116173.028824][2434:2441] CHIP:EM: Found matching exchange: 45465i, Delegate: 0xffff74058278 [1677116173.028905][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116173.029004][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116173.029061][2434:2441] CHIP:DMG: { [1677116173.029113][2434:2441] CHIP:DMG: suppressResponse = false, [1677116173.029167][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116173.029235][2434:2441] CHIP:DMG: [ [1677116173.029287][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116173.029371][2434:2441] CHIP:DMG: { [1677116173.029436][2434:2441] CHIP:DMG: CommandDataIB = [1677116173.029492][2434:2441] CHIP:DMG: { [1677116173.029555][2434:2441] CHIP:DMG: CommandPathIB = [1677116173.029635][2434:2441] CHIP:DMG: { [1677116173.029719][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116173.029802][2434:2441] CHIP:DMG: ClusterId = 0x3e, [1677116173.029886][2434:2441] CHIP:DMG: CommandId = 0x3, [1677116173.029967][2434:2441] CHIP:DMG: }, [1677116173.030049][2434:2441] CHIP:DMG: [1677116173.030123][2434:2441] CHIP:DMG: CommandFields = [1677116173.030202][2434:2441] CHIP:DMG: { [1677116173.030274][2434:2441] CHIP:DMG: 0x0 = [ [1677116173.030598][2434:2441] CHIP:DMG: 0x30, 0x82, 0x01, 0xcb, 0x30, 0x82, 0x01, 0x71, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x56, 0xad, 0x82, 0x22, 0xad, 0x94, 0x5b, 0x64, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x30, 0x31, 0x18, 0x30, 0x16, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x0f, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x54, 0x65, 0x73, 0x74, 0x20, 0x50, 0x41, 0x41, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x41, 0x9a, 0x93, 0x15, 0xc2, 0x17, 0x3e, 0x0c, 0x8c, 0x87, 0x6d, 0x03, 0xcc, 0xfc, 0x94, 0x48, 0x52, 0x64, 0x7f, 0x7f, 0xec, 0x5e, 0x50, 0x82, 0xf4, 0x05, 0x99, 0x28, 0xec, 0xa8, 0x94, 0xc5, 0x94, 0x15, 0x13, 0x09, 0xac, 0x63, 0x1e, 0x4c, 0xb0, 0x33, 0x92, 0xaf, 0x68, 0x4b, 0x0b, 0xaf, 0xb7, 0xe6, 0x5b, 0x3b, 0x81, 0x62, 0xc2, 0xf5, 0x2b, 0xf9, 0x31, 0xb8, 0xe7, 0x7a, 0xaa, 0x82, 0xa3, 0x66, 0x30, 0x64, 0x30, 0x12, 0x06, 0x03, 0x55, 0x1d, 0x [1677116173.030778][2434:2441] CHIP:DMG: ] (463 bytes) [1677116173.030864][2434:2441] CHIP:DMG: }, [1677116173.030940][2434:2441] CHIP:DMG: }, [1677116173.031024][2434:2441] CHIP:DMG: [1677116173.031083][2434:2441] CHIP:DMG: }, [1677116173.031152][2434:2441] CHIP:DMG: [1677116173.031217][2434:2441] CHIP:DMG: ], [1677116173.031285][2434:2441] CHIP:DMG: [1677116173.031338][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116173.031388][2434:2441] CHIP:DMG: }, [1677116173.031521][2434:2441] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1677116173.031590][2434:2441] CHIP:CTL: Received certificate chain from the device [1677116173.031650][2434:2441] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest' [1677116173.031704][2434:2441] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest' [1677116173.031763][2434:2441] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest' [1677116173.031808][2434:2441] CHIP:CTL: Sending request for DAC certificate [1677116173.031850][2434:2441] CHIP:CTL: Sending Certificate Chain request to 0xffff680242d0 device [1677116173.031963][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116173.032025][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116173.032243][2434:2441] CHIP:EM: <<< [E:45466i M:258977206] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116173.032331][2434:2441] CHIP:IN: (S) Sending msg 258977206 on secure session with LSID: 45493 [1677116173.032518][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116173.032635][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116173.207784][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116173.345219][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116173.345432][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116173.435119][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116173.435323][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116173.523561][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116173.523753][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116173.523996][2434:2441] CHIP:EM: >>> [E:45466i M:121797164] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116173.524063][2434:2441] CHIP:EM: Found matching exchange: 45466i, Delegate: 0xffff740586c8 [1677116173.524175][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116173.524263][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116173.524310][2434:2441] CHIP:DMG: { [1677116173.524354][2434:2441] CHIP:DMG: suppressResponse = false, [1677116173.524399][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116173.524457][2434:2441] CHIP:DMG: [ [1677116173.524501][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116173.524571][2434:2441] CHIP:DMG: { [1677116173.524619][2434:2441] CHIP:DMG: CommandDataIB = [1677116173.524672][2434:2441] CHIP:DMG: { [1677116173.524733][2434:2441] CHIP:DMG: CommandPathIB = [1677116173.524790][2434:2441] CHIP:DMG: { [1677116173.524853][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116173.524925][2434:2441] CHIP:DMG: ClusterId = 0x3e, [1677116173.524991][2434:2441] CHIP:DMG: CommandId = 0x3, [1677116173.525045][2434:2441] CHIP:DMG: }, [1677116173.525109][2434:2441] CHIP:DMG: [1677116173.525173][2434:2441] CHIP:DMG: CommandFields = [1677116173.525223][2434:2441] CHIP:DMG: { [1677116173.525291][2434:2441] CHIP:DMG: 0x0 = [ [1677116173.525551][2434:2441] CHIP:DMG: 0x30, 0x82, 0x01, 0xe7, 0x30, 0x82, 0x01, 0x8e, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x46, 0x7f, 0x57, 0x62, 0xc8, 0xdc, 0x90, 0xd5, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x33, 0x33, 0x31, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x53, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x44, 0x41, 0x43, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x2f, 0x30, 0x78, 0x38, 0x30, 0x31, 0x30, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x02, 0x0c, 0x04, 0x38, 0x30, 0x31, 0x30, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x39, 0xef, 0x6c, 0x9d, 0x9c, 0x99, 0x7b, 0xa2, 0xc7, 0x31, 0x9a, 0x4c, 0x73, 0xc9, 0xbf, 0x47, 0xdb, 0xcd, 0xbc, 0x42, 0xc5, 0x41, 0x3e, 0xec, 0x14, 0x52, 0x75, 0xb8, 0x8f, 0xc1, 0x1a, 0xb1, 0xad, 0x0b, 0xc3, 0x3e, 0xf1, 0x4c, 0x27, 0x [1677116173.525695][2434:2441] CHIP:DMG: ] (491 bytes) [1677116173.525766][2434:2441] CHIP:DMG: }, [1677116173.525825][2434:2441] CHIP:DMG: }, [1677116173.525896][2434:2441] CHIP:DMG: [1677116173.525943][2434:2441] CHIP:DMG: }, [1677116173.526005][2434:2441] CHIP:DMG: [1677116173.526049][2434:2441] CHIP:DMG: ], [1677116173.526106][2434:2441] CHIP:DMG: [1677116173.526151][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116173.526193][2434:2441] CHIP:DMG: }, [1677116173.526309][2434:2441] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1677116173.526370][2434:2441] CHIP:CTL: Received certificate chain from the device [1677116173.526422][2434:2441] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest' [1677116173.526473][2434:2441] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest' [1677116173.526525][2434:2441] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest' [1677116173.526563][2434:2441] CHIP:CTL: Sending Attestation Request to the device. [1677116173.526600][2434:2441] CHIP:CTL: Sending Attestation request to 0xffff680242d0 device [1677116173.526700][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116173.526755][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116173.526903][2434:2441] CHIP:EM: <<< [E:45467i M:258977207] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116173.526977][2434:2441] CHIP:IN: (S) Sending msg 258977207 on secure session with LSID: 45493 [1677116173.527135][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116173.527191][2434:2441] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information [1677116173.527270][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116173.656918][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116173.705155][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116173.705362][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116173.840248][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116173.840459][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116173.929725][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116173.929891][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116173.930110][2434:2441] CHIP:EM: >>> [E:45467i M:121797165] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116173.930164][2434:2441] CHIP:EM: Found matching exchange: 45467i, Delegate: 0xffff74058988 [1677116173.930221][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116173.930291][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116173.930328][2434:2441] CHIP:DMG: { [1677116173.930363][2434:2441] CHIP:DMG: suppressResponse = false, [1677116173.930398][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116173.930445][2434:2441] CHIP:DMG: [ [1677116173.930479][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116173.930536][2434:2441] CHIP:DMG: { [1677116173.930574][2434:2441] CHIP:DMG: CommandDataIB = [1677116173.930632][2434:2441] CHIP:DMG: { [1677116173.930672][2434:2441] CHIP:DMG: CommandPathIB = [1677116173.930743][2434:2441] CHIP:DMG: { [1677116173.930789][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116173.930845][2434:2441] CHIP:DMG: ClusterId = 0x3e, [1677116173.930900][2434:2441] CHIP:DMG: CommandId = 0x1, [1677116173.930950][2434:2441] CHIP:DMG: }, [1677116173.931004][2434:2441] CHIP:DMG: [1677116173.931053][2434:2441] CHIP:DMG: CommandFields = [1677116173.931097][2434:2441] CHIP:DMG: { [1677116173.931152][2434:2441] CHIP:DMG: 0x0 = [ [1677116173.931367][2434:2441] CHIP:DMG: 0x15, 0x31, 0x01, 0x1b, 0x02, 0x30, 0x82, 0x02, 0x17, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x02, 0xa0, 0x82, 0x02, 0x08, 0x30, 0x82, 0x02, 0x04, 0x02, 0x01, 0x03, 0x31, 0x0d, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x82, 0x01, 0x70, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x01, 0xa0, 0x82, 0x01, 0x61, 0x04, 0x82, 0x01, 0x5d, 0x15, 0x24, 0x00, 0x01, 0x25, 0x01, 0xf1, 0xff, 0x36, 0x02, 0x05, 0x00, 0x80, 0x05, 0x01, 0x80, 0x05, 0x02, 0x80, 0x05, 0x03, 0x80, 0x05, 0x04, 0x80, 0x05, 0x05, 0x80, 0x05, 0x06, 0x80, 0x05, 0x07, 0x80, 0x05, 0x08, 0x80, 0x05, 0x09, 0x80, 0x05, 0x0a, 0x80, 0x05, 0x0b, 0x80, 0x05, 0x0c, 0x80, 0x05, 0x0d, 0x80, 0x05, 0x0e, 0x80, 0x05, 0x0f, 0x80, 0x05, 0x10, 0x80, 0x05, 0x11, 0x80, 0x05, 0x12, 0x80, 0x05, 0x13, 0x80, 0x05, 0x14, 0x80, 0x05, 0x15, 0x80, 0x05, 0x16, 0x80, 0x05, 0x17, 0x80, 0x05, 0x18, 0x80, 0x05, 0x19, 0x80, 0x05, 0x1a, 0x80, 0x05, 0x1b, 0x80, 0x05, 0x1c, 0x80, 0x05, 0x1d, 0x80, 0x05, 0x1e, 0x80, 0x05, 0x1f, 0x80, 0x05, 0x20, 0x80, 0x05, 0x21, 0x80, 0x05, 0x22, 0x80, 0x05, 0x23, 0x80, 0x05, 0x24, 0x80, 0x05, 0x25, 0x80, 0x05, 0x26, 0x80, 0x05, 0x27, 0x80, 0x05, 0x28, 0x80, 0x05, 0x29, 0x80, 0x05, 0x2a, 0x80, 0x05, 0x2b, 0x80, 0x05, 0x2c, 0x80, 0x05, 0x2d, 0x80, 0x05, 0x2e, 0x80, 0x05, 0x2f, 0x80, 0x05, 0x30, 0x80, 0x05, 0x31, 0x80, 0x05, 0x32, 0x80, 0x05, 0x33, 0x80, 0x05, 0x34, 0x80, 0x05, 0x35, 0x80, 0x05, 0x36, 0x80, 0x05, 0x37, 0x80, 0x05, 0x38, 0x80, 0x05, 0x39, 0x80, 0x05, 0x3a, 0x80, 0x05, 0x3b, 0x80, 0x05, 0x3c, 0x80, 0x05, 0x3d, 0x80, 0x05, 0x3e, 0x80, 0x05, 0x3f, 0x80, 0x05, 0x40, 0x80, 0x05, 0x41, 0x80, 0x05, 0x42, 0x80, 0x05, 0x43, 0x80, 0x [1677116173.931476][2434:2441] CHIP:DMG: ] (583 bytes) [1677116173.931532][2434:2441] CHIP:DMG: 0x1 = [ [1677116173.931616][2434:2441] CHIP:DMG: 0xd0, 0x1d, 0xb3, 0xd9, 0x70, 0xe3, 0x6a, 0xa2, 0x6b, 0xc0, 0x1f, 0xa5, 0xfd, 0x75, 0x2e, 0x30, 0x25, 0x91, 0x2e, 0xf9, 0x85, 0x96, 0xda, 0x4b, 0x17, 0xc5, 0x97, 0x0b, 0xc1, 0x7d, 0xcb, 0x3d, 0xb4, 0x6d, 0x6c, 0x03, 0x3b, 0x89, 0x81, 0xb4, 0x88, 0x7b, 0xfb, 0xf4, 0xe1, 0x95, 0x69, 0x88, 0xae, 0x21, 0x03, 0xda, 0x23, 0x29, 0x0b, 0xac, 0x15, 0x30, 0xb3, 0xcd, 0x26, 0x42, 0x58, 0x05, [1677116173.931687][2434:2441] CHIP:DMG: ] (64 bytes) [1677116173.931744][2434:2441] CHIP:DMG: }, [1677116173.931793][2434:2441] CHIP:DMG: }, [1677116173.931848][2434:2441] CHIP:DMG: [1677116173.931883][2434:2441] CHIP:DMG: }, [1677116173.931932][2434:2441] CHIP:DMG: [1677116173.931965][2434:2441] CHIP:DMG: ], [1677116173.932011][2434:2441] CHIP:DMG: [1677116173.932045][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116173.932078][2434:2441] CHIP:DMG: }, [1677116173.932211][2434:2441] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001 [1677116173.932266][2434:2441] CHIP:CTL: Received Attestation Information from the device [1677116173.932309][2434:2441] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest' [1677116173.932344][2434:2441] CHIP:CTL: AutoCommissioner setting attestationElements buffer size 583/583 [1677116173.932433][2434:2441] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification' [1677116173.932478][2434:2441] CHIP:CTL: Performing next commissioning step 'AttestationVerification' [1677116173.932509][2434:2441] CHIP:CTL: Verifying attestation [1677116173.941048][2434:2441] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device. [1677116173.941120][2434:2441] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification' [1677116173.941153][2434:2441] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest' [1677116173.941195][2434:2441] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest' [1677116173.941228][2434:2441] CHIP:CTL: Sending CSR request to 0xffff680242d0 device [1677116173.941326][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116173.943378][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116173.943499][2434:2441] CHIP:EM: <<< [E:45468i M:258977208] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116173.943539][2434:2441] CHIP:IN: (S) Sending msg 258977208 on secure session with LSID: 45493 [1677116173.943640][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116173.943670][2434:2441] CHIP:CTL: Sent CSR request, waiting for the CSR [1677116173.943723][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116174.062074][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116174.290221][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116174.290440][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116174.379016][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116174.379234][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116174.379517][2434:2441] CHIP:EM: >>> [E:45468i M:121797166] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116174.379593][2434:2441] CHIP:EM: Found matching exchange: 45468i, Delegate: 0xffff74058ae8 [1677116174.379692][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116174.379791][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116174.379864][2434:2441] CHIP:DMG: { [1677116174.379916][2434:2441] CHIP:DMG: suppressResponse = false, [1677116174.380084][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116174.380243][2434:2441] CHIP:DMG: [ [1677116174.380357][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116174.380466][2434:2441] CHIP:DMG: { [1677116174.380546][2434:2441] CHIP:DMG: CommandDataIB = [1677116174.380621][2434:2441] CHIP:DMG: { [1677116174.380756][2434:2441] CHIP:DMG: CommandPathIB = [1677116174.380858][2434:2441] CHIP:DMG: { [1677116174.380940][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116174.381099][2434:2441] CHIP:DMG: ClusterId = 0x3e, [1677116174.381211][2434:2441] CHIP:DMG: CommandId = 0x5, [1677116174.381362][2434:2441] CHIP:DMG: }, [1677116174.381472][2434:2441] CHIP:DMG: [1677116174.381545][2434:2441] CHIP:DMG: CommandFields = [1677116174.381697][2434:2441] CHIP:DMG: { [1677116174.381847][2434:2441] CHIP:DMG: 0x0 = [ [1677116174.382227][2434:2441] CHIP:DMG: 0x15, 0x30, 0x01, 0xce, 0x30, 0x81, 0xcb, 0x30, 0x70, 0x02, 0x01, 0x00, 0x30, 0x0e, 0x31, 0x0c, 0x30, 0x0a, 0x06, 0x03, 0x55, 0x04, 0x0a, 0x0c, 0x03, 0x43, 0x53, 0x52, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x4a, 0x99, 0x79, 0xa0, 0x83, 0xd1, 0x49, 0x10, 0x5c, 0x9b, 0xfe, 0xb7, 0x89, 0x83, 0xff, 0x59, 0x21, 0x8a, 0x40, 0xc0, 0xe2, 0x09, 0xfe, 0x44, 0xf0, 0x72, 0xc6, 0x22, 0x50, 0xa9, 0x18, 0x16, 0x1c, 0x22, 0xc0, 0x84, 0xcd, 0x57, 0x3e, 0x3d, 0xea, 0x96, 0xe4, 0x18, 0xcd, 0x8d, 0xc9, 0xf8, 0x86, 0xfc, 0xd6, 0x46, 0xb2, 0xa2, 0x66, 0x64, 0x08, 0x4c, 0xe5, 0x09, 0x52, 0xf3, 0x8e, 0x02, 0xa0, 0x00, 0x30, 0x0c, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x05, 0x00, 0x03, 0x49, 0x00, 0x30, 0x46, 0x02, 0x21, 0x00, 0xef, 0x69, 0x3d, 0xd0, 0xa3, 0x4f, 0xcf, 0x49, 0x92, 0xcd, 0x30, 0xbe, 0x68, 0xf7, 0x34, 0x56, 0x1c, 0xae, 0x4d, 0x95, 0x09, 0x11, 0x5d, 0xaf, 0x7c, 0x2c, 0x7a, 0x73, 0x0d, 0x62, 0xb1, 0x25, 0x02, 0x21, 0x00, 0x9a, 0xd9, 0x7f, 0x87, 0xaf, 0xef, 0x4f, 0x2c, 0x9b, 0x1a, 0x76, 0x80, 0x8a, 0xf9, 0xb9, 0xe9, 0x4a, 0x58, 0x30, 0xc4, 0x9f, 0x19, 0x3b, 0xd0, 0x07, 0xe4, 0x88, 0x55, 0x85, 0xf4, 0x03, 0x72, 0x30, 0x02, 0x20, 0xc0, 0xa9, 0xef, 0x2c, 0xac, 0x42, 0xf1, 0x40, 0x59, 0xad, 0xda, 0x7e, 0xb9, 0xad, 0x0e, 0x0d, 0xbe, 0x5c, 0xbf, 0x23, 0x21, 0x25, 0x9c, 0xe4, 0xe2, 0x02, 0x45, 0x32, 0xaf, 0xea, 0xf5, 0x0e, 0x18, [1677116174.382445][2434:2441] CHIP:DMG: ] (246 bytes) [1677116174.382550][2434:2441] CHIP:DMG: 0x1 = [ [1677116174.382676][2434:2441] CHIP:DMG: 0x48, 0x80, 0xe7, 0x63, 0x44, 0xe0, 0x0c, 0x76, 0xd4, 0x8a, 0x59, 0x6e, 0x9d, 0xe8, 0x46, 0xb6, 0xed, 0xf5, 0xf1, 0x8e, 0xd9, 0x19, 0xb1, 0xd3, 0x2a, 0x7e, 0x03, 0xbf, 0x4b, 0x42, 0x06, 0x1f, 0xa0, 0xca, 0xf8, 0xe0, 0x7f, 0xf2, 0x85, 0xf3, 0x92, 0xbc, 0xf2, 0x63, 0xc9, 0x6a, 0x5d, 0x83, 0xb6, 0x87, 0x4c, 0x6b, 0xaa, 0xdd, 0xad, 0x6f, 0x94, 0xc9, 0x0b, 0xcd, 0x7e, 0xb2, 0xf1, 0x75, [1677116174.382779][2434:2441] CHIP:DMG: ] (64 bytes) [1677116174.382887][2434:2441] CHIP:DMG: }, [1677116174.383036][2434:2441] CHIP:DMG: }, [1677116174.383124][2434:2441] CHIP:DMG: [1677116174.383243][2434:2441] CHIP:DMG: }, [1677116174.383317][2434:2441] CHIP:DMG: [1677116174.383384][2434:2441] CHIP:DMG: ], [1677116174.383453][2434:2441] CHIP:DMG: [1677116174.383504][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116174.383628][2434:2441] CHIP:DMG: }, [1677116174.383877][2434:2441] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005 [1677116174.383972][2434:2441] CHIP:CTL: Received certificate signing request from the device [1677116174.384087][2434:2441] CHIP:CTL: Successfully finished commissioning step 'SendOpCertSigningRequest' [1677116174.384169][2434:2441] CHIP:CTL: Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR' [1677116174.384248][2434:2441] CHIP:CTL: Performing next commissioning step 'ValidateCSR' [1677116174.386837][2434:2441] CHIP:CTL: Successfully finished commissioning step 'ValidateCSR' [1677116174.387063][2434:2441] CHIP:CTL: Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain' [1677116174.387122][2434:2441] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain' [1677116174.387169][2434:2441] CHIP:CTL: Getting certificate chain for the device from the issuer [1677116174.387935][2434:2441] CHIP:CTL: Verifying Certificate Signing Request [1677116174.389688][2434:2441] CHIP:CTL: Generating NOC [1677116174.389986][2434:2441] CHIP:CTL: Providing certificate chain to the commissioner [1677116174.390014][2434:2441] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/ExampleOperationalCredentialsIssuer.cpp:396: Success [1677116174.390041][2434:2441] CHIP:CTL: Successfully finished commissioning step 'GenerateNOCChain' [1677116174.390263][2434:2441] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert' [1677116174.390287][2434:2441] CHIP:CTL: Sending root certificate to the device [1677116174.390354][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116174.390410][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116174.390523][2434:2441] CHIP:EM: <<< [E:45469i M:258977209] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116174.390559][2434:2441] CHIP:IN: (S) Sending msg 258977209 on secure session with LSID: 45493 [1677116174.390707][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116174.390737][2434:2441] CHIP:CTL: Sent root certificate to the device [1677116174.391094][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116174.647113][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116174.736920][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116174.783091][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116174.783289][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116174.783570][2434:2441] CHIP:EM: >>> [E:45469i M:121797167] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116174.783646][2434:2441] CHIP:EM: Found matching exchange: 45469i, Delegate: 0xffff74058988 [1677116174.783743][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116174.783959][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116174.784013][2434:2441] CHIP:DMG: { [1677116174.784063][2434:2441] CHIP:DMG: suppressResponse = false, [1677116174.784276][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116174.784369][2434:2441] CHIP:DMG: [ [1677116174.784422][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116174.784566][2434:2441] CHIP:DMG: { [1677116174.784623][2434:2441] CHIP:DMG: CommandStatusIB = [1677116174.784713][2434:2441] CHIP:DMG: { [1677116174.784785][2434:2441] CHIP:DMG: CommandPathIB = [1677116174.784873][2434:2441] CHIP:DMG: { [1677116174.784954][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116174.785125][2434:2441] CHIP:DMG: ClusterId = 0x3e, [1677116174.785230][2434:2441] CHIP:DMG: CommandId = 0xb, [1677116174.785374][2434:2441] CHIP:DMG: }, [1677116174.785527][2434:2441] CHIP:DMG: [1677116174.785625][2434:2441] CHIP:DMG: StatusIB = [1677116174.785703][2434:2441] CHIP:DMG: { [1677116174.785869][2434:2441] CHIP:DMG: status = 0x00 (SUCCESS), [1677116174.785952][2434:2441] CHIP:DMG: }, [1677116174.786039][2434:2441] CHIP:DMG: [1677116174.786109][2434:2441] CHIP:DMG: }, [1677116174.786258][2434:2441] CHIP:DMG: [1677116174.786338][2434:2441] CHIP:DMG: }, [1677116174.786464][2434:2441] CHIP:DMG: [1677116174.786520][2434:2441] CHIP:DMG: ], [1677116174.786655][2434:2441] CHIP:DMG: [1677116174.786713][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116174.786783][2434:2441] CHIP:DMG: }, [1677116174.786966][2434:2441] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0 [1677116174.787045][2434:2441] CHIP:CTL: Device confirmed that it has received the root certificate [1677116174.787100][2434:2441] CHIP:CTL: Successfully finished commissioning step 'SendTrustedRootCert' [1677116174.787146][2434:2441] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC' [1677116174.787222][2434:2441] CHIP:CTL: Performing next commissioning step 'SendNOC' [1677116174.787428][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116174.787562][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116174.787828][2434:2441] CHIP:EM: <<< [E:45470i M:258977210] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116174.787976][2434:2441] CHIP:IN: (S) Sending msg 258977210 on secure session with LSID: 45493 [1677116174.788297][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116174.788391][2434:2441] CHIP:CTL: Sent operational certificate to the device [1677116174.788488][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116175.007110][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116175.096930][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116175.231733][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116175.323157][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116175.323359][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116175.323650][2434:2441] CHIP:EM: >>> [E:45470i M:121797168] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116175.323746][2434:2441] CHIP:EM: Found matching exchange: 45470i, Delegate: 0xffff74058ae8 [1677116175.323824][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116175.323918][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116175.323972][2434:2441] CHIP:DMG: { [1677116175.324044][2434:2441] CHIP:DMG: suppressResponse = false, [1677116175.324095][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116175.324325][2434:2441] CHIP:DMG: [ [1677116175.324402][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116175.324570][2434:2441] CHIP:DMG: { [1677116175.324638][2434:2441] CHIP:DMG: CommandDataIB = [1677116175.324729][2434:2441] CHIP:DMG: { [1677116175.324800][2434:2441] CHIP:DMG: CommandPathIB = [1677116175.324946][2434:2441] CHIP:DMG: { [1677116175.325049][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116175.325200][2434:2441] CHIP:DMG: ClusterId = 0x3e, [1677116175.325285][2434:2441] CHIP:DMG: CommandId = 0x8, [1677116175.325384][2434:2441] CHIP:DMG: }, [1677116175.325523][2434:2441] CHIP:DMG: [1677116175.325602][2434:2441] CHIP:DMG: CommandFields = [1677116175.325691][2434:2441] CHIP:DMG: { [1677116175.325775][2434:2441] CHIP:DMG: 0x0 = 0, [1677116175.325956][2434:2441] CHIP:DMG: 0x1 = 1, [1677116175.326041][2434:2441] CHIP:DMG: }, [1677116175.326191][2434:2441] CHIP:DMG: }, [1677116175.326347][2434:2441] CHIP:DMG: [1677116175.326427][2434:2441] CHIP:DMG: }, [1677116175.326500][2434:2441] CHIP:DMG: [1677116175.326623][2434:2441] CHIP:DMG: ], [1677116175.326711][2434:2441] CHIP:DMG: [1677116175.326762][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116175.326891][2434:2441] CHIP:DMG: }, [1677116175.327119][2434:2441] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008 [1677116175.327197][2434:2441] CHIP:CTL: Device returned status 0 on receiving the NOC [1677116175.327265][2434:2441] CHIP:CTL: Operational credentials provisioned on device 0xffff680242d0 [1677116175.327311][2434:2441] CHIP:TOO: Secure Pairing Success [1677116175.327349][2434:2441] CHIP:TOO: CASE establishment successful [1677116175.327399][2434:2441] CHIP:CTL: Successfully finished commissioning step 'SendNOC' [1677116175.327510][2434:2441] CHIP:CTL: Commissioning stage next step: 'SendNOC' -> 'ThreadNetworkSetup' [1677116175.327566][2434:2441] CHIP:CTL: Performing next commissioning step 'ThreadNetworkSetup' [1677116175.327704][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116175.327771][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116175.328049][2434:2441] CHIP:EM: <<< [E:45471i M:258977211] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116175.328288][2434:2441] CHIP:IN: (S) Sending msg 258977211 on secure session with LSID: 45493 [1677116175.328470][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116175.328678][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116175.411775][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116175.503106][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116175.503299][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116175.503562][2434:2441] CHIP:EM: >>> [E:45471i M:121797169] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116175.503625][2434:2441] CHIP:EM: Found matching exchange: 45471i, Delegate: 0xffff74058988 [1677116175.503707][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116175.503788][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116175.503833][2434:2441] CHIP:DMG: { [1677116175.503898][2434:2441] CHIP:DMG: suppressResponse = false, [1677116175.503943][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116175.504017][2434:2441] CHIP:DMG: [ [1677116175.504062][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116175.504304][2434:2441] CHIP:DMG: { [1677116175.504373][2434:2441] CHIP:DMG: CommandDataIB = [1677116175.504438][2434:2441] CHIP:DMG: { [1677116175.504516][2434:2441] CHIP:DMG: CommandPathIB = [1677116175.504646][2434:2441] CHIP:DMG: { [1677116175.504733][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116175.504866][2434:2441] CHIP:DMG: ClusterId = 0x31, [1677116175.504940][2434:2441] CHIP:DMG: CommandId = 0x5, [1677116175.505027][2434:2441] CHIP:DMG: }, [1677116175.505113][2434:2441] CHIP:DMG: [1677116175.505262][2434:2441] CHIP:DMG: CommandFields = [1677116175.505337][2434:2441] CHIP:DMG: { [1677116175.505424][2434:2441] CHIP:DMG: 0x0 = 0, [1677116175.505494][2434:2441] CHIP:DMG: 0x2 = 0, [1677116175.505616][2434:2441] CHIP:DMG: }, [1677116175.505681][2434:2441] CHIP:DMG: }, [1677116175.505766][2434:2441] CHIP:DMG: [1677116175.505851][2434:2441] CHIP:DMG: }, [1677116175.505936][2434:2441] CHIP:DMG: [1677116175.505979][2434:2441] CHIP:DMG: ], [1677116175.506053][2434:2441] CHIP:DMG: [1677116175.506098][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116175.506209][2434:2441] CHIP:DMG: }, [1677116175.506342][2434:2441] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005 [1677116175.508807][2434:2441] CHIP:CTL: Received NetworkConfig response, networkingStatus=0 [1677116175.508874][2434:2441] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkSetup' [1677116175.508918][2434:2441] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkSetup' -> 'ThreadNetworkEnable' [1677116175.508970][2434:2441] CHIP:CTL: Performing next commissioning step 'ThreadNetworkEnable' [1677116175.509088][2434:2441] CHIP:DMG: ICR moving to [AddingComm] [1677116175.509149][2434:2441] CHIP:DMG: ICR moving to [AddedComma] [1677116175.509305][2434:2441] CHIP:EM: <<< [E:45472i M:258977212] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1677116175.509381][2434:2441] CHIP:IN: (S) Sending msg 258977212 on secure session with LSID: 45493 [1677116175.509552][2434:2441] CHIP:DMG: ICR moving to [CommandSen] [1677116175.509661][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116175.638165][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116178.112678][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116178.112909][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116180.722069][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116183.197837][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116183.198071][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116185.224082][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116185.224356][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116185.224586][2434:2441] CHIP:EM: >>> [E:45472i M:121797170] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1677116185.224666][2434:2441] CHIP:EM: Found matching exchange: 45472i, Delegate: 0xffff74058ae8 [1677116185.224750][2434:2441] CHIP:DMG: ICR moving to [ResponseRe] [1677116185.224849][2434:2441] CHIP:DMG: InvokeResponseMessage = [1677116185.224904][2434:2441] CHIP:DMG: { [1677116185.224955][2434:2441] CHIP:DMG: suppressResponse = false, [1677116185.225009][2434:2441] CHIP:DMG: InvokeResponseIBs = [1677116185.225090][2434:2441] CHIP:DMG: [ [1677116185.225143][2434:2441] CHIP:DMG: InvokeResponseIB = [1677116185.225222][2434:2441] CHIP:DMG: { [1677116185.225279][2434:2441] CHIP:DMG: CommandDataIB = [1677116185.225342][2434:2441] CHIP:DMG: { [1677116185.225406][2434:2441] CHIP:DMG: CommandPathIB = [1677116185.225485][2434:2441] CHIP:DMG: { [1677116185.225566][2434:2441] CHIP:DMG: EndpointId = 0x0, [1677116185.225651][2434:2441] CHIP:DMG: ClusterId = 0x31, [1677116185.225737][2434:2441] CHIP:DMG: CommandId = 0x7, [1677116185.225801][2434:2441] CHIP:DMG: }, [1677116185.225869][2434:2441] CHIP:DMG: [1677116185.225943][2434:2441] CHIP:DMG: CommandFields = [1677116185.226022][2434:2441] CHIP:DMG: { [1677116185.226104][2434:2441] CHIP:DMG: 0x0 = 0, [1677116185.226179][2434:2441] CHIP:DMG: 0x2 = NULL [1677116185.226262][2434:2441] CHIP:DMG: }, [1677116185.226322][2434:2441] CHIP:DMG: }, [1677116185.226403][2434:2441] CHIP:DMG: [1677116185.226457][2434:2441] CHIP:DMG: }, [1677116185.226541][2434:2441] CHIP:DMG: [1677116185.226591][2434:2441] CHIP:DMG: ], [1677116185.226658][2434:2441] CHIP:DMG: [1677116185.226710][2434:2441] CHIP:DMG: InteractionModelRevision = 1 [1677116185.226759][2434:2441] CHIP:DMG: }, [1677116185.226894][2434:2441] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007 [1677116185.227027][2434:2441] CHIP:CTL: Received ConnectNetwork response, networkingStatus=0 [1677116185.227092][2434:2441] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkEnable' [1677116185.227141][2434:2441] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkEnable' -> 'FindOperational' [1677116185.227199][2434:2441] CHIP:CTL: Performing next commissioning step 'FindOperational' [1677116185.227245][2434:2441] CHIP:CSM: FindOrEstablishSession: PeerId = [1:00000000000004D2] [1677116185.227293][2434:2441] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found [1677116185.227363][2434:2441] CHIP:CTL: OperationalSessionSetup[1:00000000000004D2]: State change 1 --> 2 [1677116185.227423][2434:2441] CHIP:DIS: Resolving 76A23B1FF96B9178:00000000000004D2 ... [1677116185.229565][2434:2441] CHIP:DMG: ICR moving to [AwaitingDe] [1677116185.428109][2434:2441] CHIP:DIS: Checking node lookup status after 200 ms [1677116185.807306][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116188.237929][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116188.238163][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116189.631195][2434:2441] CHIP:DL: Avahi resolve found [1677116189.631343][2434:2441] CHIP:DIS: Node ID resolved for 76A23B1FF96B9178:00000000000004D2 [1677116189.631399][2434:2441] CHIP:DIS: Hostname: 4AD34CC5911ED5C3 [1677116189.631461][2434:2441] CHIP:DIS: IP Address #1: fd11:22::715f:e6d6:da3:b64 [1677116189.631512][2434:2441] CHIP:DIS: Port: 5540 [1677116189.631559][2434:2441] CHIP:DIS: Mrp Interval idle: 5500 ms [1677116189.631606][2434:2441] CHIP:DIS: Mrp Interval active: 800 ms [1677116189.631652][2434:2441] CHIP:DIS: TCP Supported: 0 [1677116189.633050][2434:2441] CHIP:DIS: Lookup clearing interface for non LL address [1677116189.633116][2434:2441] CHIP:DIS: UDP:[fd11:22::715f:e6d6:da3:b64%otbr0]:5540: new best score: 4 [1677116189.633166][2434:2441] CHIP:DIS: Checking node lookup status after 4406 ms [1677116189.633229][2434:2441] CHIP:DIS: OperationalSessionSetup[1:00000000000004D2]: Updating device address to UDP:[fd11:22::715f:e6d6:da3:b64]:5540 while in state 2 [1677116189.633281][2434:2441] CHIP:CTL: OperationalSessionSetup[1:00000000000004D2]: State change 2 --> 3 [1677116189.633548][2434:2441] CHIP:IN: SecureSession[0xffff74010800]: Allocated Type:2 LSID:45494 [1677116189.633732][2434:2441] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x00000000000004D2 [1677116189.635158][2434:2441] CHIP:SC: Including MRP parameters [1677116189.635410][2434:2441] CHIP:EM: <<< [E:45473i M:30975918] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1677116189.635540][2434:2441] CHIP:IN: (U) Sending msg 30975918 to IP address 'UDP:[fd11:22::715f:e6d6:da3:b64]:5540' [1677116189.636404][2434:2441] CHIP:SC: Sent Sigma1 msg [1677116189.636560][2434:2441] CHIP:CTL: OperationalSessionSetup[1:00000000000004D2]: State change 3 --> 4 [1677116190.272443][2434:2441] CHIP:EM: >>> [E:45473i M:260332607 (Ack:30975918)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1677116190.272530][2434:2441] CHIP:EM: Found matching exchange: 45473i, Delegate: 0xffff68039eb8 [1677116190.272601][2434:2441] CHIP:EM: Rxd Ack; Removing MessageCounter:30975918 from Retrans Table on exchange 45473i [1677116190.633623][2434:2441] CHIP:EM: >>> [E:45473i M:260332608 (Ack:30975918)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1677116190.633710][2434:2441] CHIP:EM: Found matching exchange: 45473i, Delegate: 0xffff68039eb8 [1677116190.633761][2434:2441] CHIP:EM: CHIP MessageCounter:30975918 not in RetransTable on exchange 45473i [1677116190.633837][2434:2441] CHIP:SC: Received Sigma2 msg [1677116190.633900][2434:2441] CHIP:SC: Peer assigned session session ID 28498 [1677116190.640686][2434:2441] CHIP:SC: Found MRP parameters in the message [1677116190.640771][2434:2441] CHIP:SC: Sending Sigma3 [1677116190.641617][2434:2441] CHIP:EM: <<< [E:45473i M:30975919 (Ack:260332608)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1677116190.641829][2434:2441] CHIP:IN: (U) Sending msg 30975919 to IP address 'UDP:[fd11:22::715f:e6d6:da3:b64%otbr0]:5540' [1677116190.642208][2434:2441] CHIP:SC: Sent Sigma3 msg [1677116190.847415][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116191.530396][2434:2441] CHIP:EM: Retransmitting MessageCounter:30975919 on exchange 45473i Send Cnt 1 [1677116191.530708][2434:2441] CHIP:IN: (U) Sending msg 30975919 to IP address 'UDP:[fd11:22::715f:e6d6:da3:b64%otbr0]:5540' [1677116191.891686][2434:2441] CHIP:IN: Received a duplicate message with MessageCounter:260332608 on exchange 45473i [1677116191.891764][2434:2441] CHIP:EM: >>> [E:45473i M:260332608 (Ack:30975918)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1677116191.891804][2434:2441] CHIP:EM: Found matching exchange: 45473i, Delegate: 0xffff68039eb8 [1677116191.891839][2434:2441] CHIP:EM: Forcing tx of solitary ack for duplicate MessageCounter:260332608 on exchange 45473i [1677116191.891895][2434:2441] CHIP:EM: <<< [E:45473i M:30975920 (Ack:260332608)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1677116191.892044][2434:2441] CHIP:IN: (U) Sending msg 30975920 to IP address 'UDP:[fd11:22::715f:e6d6:da3:b64%otbr0]:5540' [1677116192.516100][2434:2441] CHIP:EM: Retransmitting MessageCounter:30975919 on exchange 45473i Send Cnt 2 [1677116192.516477][2434:2441] CHIP:IN: (U) Sending msg 30975919 to IP address 'UDP:[fd11:22::715f:e6d6:da3:b64%otbr0]:5540' [1677116192.551722][2434:2441] CHIP:IN: Received a duplicate message with MessageCounter:260332608 on exchange 45473i [1677116192.551819][2434:2441] CHIP:EM: >>> [E:45473i M:260332608 (Ack:30975918)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1677116192.551877][2434:2441] CHIP:EM: Found matching exchange: 45473i, Delegate: 0xffff68039eb8 [1677116192.551924][2434:2441] CHIP:EM: Forcing tx of solitary ack for duplicate MessageCounter:260332608 on exchange 45473i [1677116192.551999][2434:2441] CHIP:EM: <<< [E:45473i M:30975921 (Ack:260332608)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1677116192.552223][2434:2441] CHIP:IN: (U) Sending msg 30975921 to IP address 'UDP:[fd11:22::715f:e6d6:da3:b64%otbr0]:5540' [1677116193.278632][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116193.278863][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116193.945271][2434:2441] CHIP:IN: Received a duplicate message with MessageCounter:260332608 on exchange 45473i [1677116193.945355][2434:2441] CHIP:EM: >>> [E:45473i M:260332608 (Ack:30975918)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1677116193.945399][2434:2441] CHIP:EM: Found matching exchange: 45473i, Delegate: 0xffff68039eb8 [1677116193.945437][2434:2441] CHIP:EM: Forcing tx of solitary ack for duplicate MessageCounter:260332608 on exchange 45473i [1677116193.945497][2434:2441] CHIP:EM: <<< [E:45473i M:30975922 (Ack:260332608)] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1677116193.945679][2434:2441] CHIP:IN: (U) Sending msg 30975922 to IP address 'UDP:[fd11:22::715f:e6d6:da3:b64%otbr0]:5540' [1677116193.964174][2434:2441] CHIP:EM: Retransmitting MessageCounter:30975919 on exchange 45473i Send Cnt 3 [1677116193.964421][2434:2441] CHIP:IN: (U) Sending msg 30975919 to IP address 'UDP:[fd11:22::715f:e6d6:da3:b64%otbr0]:5540' [1677116195.842450][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116196.445307][2434:2441] CHIP:EM: Retransmitting MessageCounter:30975919 on exchange 45473i Send Cnt 4 [1677116196.445647][2434:2441] CHIP:IN: (U) Sending msg 30975919 to IP address 'UDP:[fd11:22::715f:e6d6:da3:b64%otbr0]:5540' [1677116198.318204][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116198.318428][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116200.487921][2434:2441] CHIP:EM: Failed to Send CHIP MessageCounter:30975919 on exchange 45473i sendCount: 4 max retries: 4 [1677116200.972031][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116203.492374][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116203.492639][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116206.057769][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116208.533791][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116208.534008][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116211.097707][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116213.573649][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116213.573884][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116216.138522][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116218.613756][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116218.613988][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116221.178073][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116223.653793][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116223.654021][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116226.308187][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116228.693871][2434:2439] CHIP:DL: Indication received, conn = 0xffff740572f0 [1677116228.694096][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1677116231.303214][2434:2441] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1677116232.520061][2434:2439] CHIP:DL: Bluez disconnected [1677116232.520221][2434:2439] CHIP:DL: Bluez notify CHIPoBluez connection disconnected [1677116232.520420][2434:2441] CHIP:IN: Clearing BLE pending packets. [1677116248.157359][2434:2441] CHIP:SC: CASESession timed out while waiting for a response from the peer. Current state was 3 [1677116248.157462][2434:2441] CHIP:IN: SecureSession[0xffff74010800]: Released - Type:2 LSID:45494 [1677116248.157577][2434:2441] CHIP:CTL: Device connection failed. Error ../../src/protocols/secure_channel/CASESession.cpp:290: CHIP Error 0x00000032: Timeout [1677116248.157652][2434:2441] CHIP:CTL: Error on commissioning step 'FindOperational': '../../src/protocols/secure_channel/CASESession.cpp:290: CHIP Error 0x00000032: Timeout' [1677116248.157702][2434:2441] CHIP:CTL: Failed to perform commissioning step 18 [1677116248.157755][2434:2441] CHIP:CTL: Going from commissioning step 'FindOperational' with lastErr = '../../src/protocols/secure_channel/CASESession.cpp:290: CHIP Error 0x00000032: Timeout' -> 'Cleanup' [1677116248.157826][2434:2441] CHIP:CTL: Performing next commissioning step 'Cleanup' with completion status = '../../src/protocols/secure_channel/CASESession.cpp:290: CHIP Error 0x00000032: Timeout' [1677116248.157881][2434:2441] CHIP:CTL: Successfully finished commissioning step 'Cleanup' [1677116248.157946][2434:2441] CHIP:TOO: Device commissioning Failure: ../../src/protocols/secure_channel/CASESession.cpp:290: CHIP Error 0x00000032: Timeout [1677116248.158583][2434:2434] CHIP:CTL: Shutting down the commissioner [1677116248.158659][2434:2434] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1677116248.158716][2434:2434] CHIP:DIS: Closing all BLE connections [1677116248.158766][2434:2434] CHIP:IN: SecureSession[0xffff6801d9f0]: MarkForEviction Type:1 LSID:45493 [1677116248.158812][2434:2434] CHIP:SC: SecureSession[0xffff6801d9f0]: Moving from state 'kActive' --> 'kPendingEviction' [1677116248.159029][2434:2434] CHIP:IN: SecureSession[0xffff6801d9f0]: Released - Type:1 LSID:45493 [1677116248.159101][2434:2434] CHIP:CTL: Shutting down the controller [1677116248.159174][2434:2434] CHIP:IN: Expiring all sessions for fabric 0x1!! [1677116248.159219][2434:2434] CHIP:FP: Forgetting fabric 0x1 [1677116248.159279][2434:2434] CHIP:TS: Pending Last Known Good Time: 2022-11-30T10:20:26 [1677116248.159625][2434:2434] CHIP:TS: Previous Last Known Good Time: 2022-11-30T10:20:26 [1677116248.159698][2434:2434] CHIP:TS: Reverted Last Known Good Time to previous value [1677116248.159771][2434:2434] CHIP:CTL: Shutting down the commissioner [1677116248.159818][2434:2434] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1677116248.159864][2434:2434] CHIP:CTL: Shutting down the controller [1677116248.159906][2434:2434] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1677116248.161748][2434:2434] CHIP:DMG: IM WH moving to [Uninitialized] [1677116248.161813][2434:2434] CHIP:DMG: IM WH moving to [Uninitialized] [1677116248.161858][2434:2434] CHIP:DMG: IM WH moving to [Uninitialized] [1677116248.161894][2434:2434] CHIP:DMG: IM WH moving to [Uninitialized] [1677116248.161934][2434:2434] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1677116248.162086][2434:2434] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1677116248.162207][2434:2434] CHIP:FP: Shutting down FabricTable [1677116248.162264][2434:2434] CHIP:TS: Pending Last Known Good Time: 2022-11-30T10:20:26 [1677116248.162489][2434:2434] CHIP:TS: Previous Last Known Good Time: 2022-11-30T10:20:26 [1677116248.162539][2434:2434] CHIP:TS: Reverted Last Known Good Time to previous value [1677116248.163040][2434:2434] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-fhlf0f) [1677116248.164002][2434:2434] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1677116248.164092][2434:2434] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1677116248.164182][2434:2434] CHIP:DL: Inet Layer shutdown [1677116248.164221][2434:2434] CHIP:DL: BLE shutdown [1677116248.168642][2434:2434] CHIP:DL: System Layer shutdown [1677116248.168828][2434:2434] CHIP:TOO: Run command failure: ../../src/protocols/secure_channel/CASESession.cpp:290: CHIP Error 0x00000032: Timeout ubuntu@ubuntu:~/chip-tool$
Hi,
What is the android CHIP tool version? Is it v2.2.0 prebuilt apk?
What is the ubuntu version of the raspberry pi?
Are you using DK or a custom board?
Hi,
1、CHIP Tool：v2.2.0 (https://github.com/nrfconnect/sdk-connectedhomeip/releases/tag/v2.2.0).
2、Ubuntu version of th raspberry pi:20.04
3、A custom board
Regards,
Danny zhang
Hi,
1、CHIP Tool：v2.2.0 (https://github.com/nrfconnect/sdk-connectedhomeip/releases/tag/v2.2.0).
2、Ubuntu version of th raspberry pi:20.04
3、A custom board
Regards,
Danny zhang
Hi,
The Lock sample has a different Thread device type than the Window Covering one. Window Covering example is an SSED Thread device type (https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/nrf/protocols/matter/getting_started/low_power_configuration.html#synchronized-sleepy-end-device-ssed-configuration-in-matter and from Thread: https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/nrf/protocols/thread/overview/supported_features.html#coordinated-sampled-listening-csl) and it uses CSL to synchronize with OTBR.
We noticed some problems with CSL on NCS 2.2.0 revision; that case looks like the same issue we know. Unfortunately, there is no workaround or fix for that on NCS 2.2.0. This behavior is not always reproducible, it is a kind of instability, so you can try to commission the Window Covering sample several times to ensure that the issue always exists. Currently, the team is working together with the Radio Driver and OpenThread teams to repair CSL and improve its stability.
Regards,
Amanda H
Hi,
Which version is stable for window covering?I can choose a lower version of our product.And what is the difference in power consumption between SSED and SED? Is this data available?
Regards,
Danny zhang
Hi,
It would be more stable in the NCS 2.3.0 which would be released soon in March.
You can disable CSL by building the Window Covering sample with the flag CONFIG_CHIP_THREAD_SSED=n . After that, the window covering sample will work as a SED Thread device so in the same way as the DoorLock sample.
Regarding power consumption of SED vs SSED please look at the recent measurements here: https://developer.nordicsemi.com/nRF_Connect_SDK/doc/latest/nrf/protocols/thread/overview/power_consumption.html#power-consumption-data
Regards,
Amanda H.
Hi,
Thank you for your support.
Regards,
Danny zhang