I am evaluating the Light bulb example for Matter. I programmed it on nRF7002 DK. Then on UBUNTU on Raspberry Pi I run the following command
chip-tool pairing ble-wifi 0 tank 012345678 20202021 3840
But chip-tool had this error:
Run command failure: examples/chip-tool/commands/common/CHIPCommand.cpp:537: CHIP Error 0x00000032: Timeout
The whole chip-tool log:
itmaster@itmaster-desktop:~/Downloads$ ./chip-tool-debug pairing ble-wifi 1 tm 012345678 20202021 3840
[1697121343.057978][5383:5383] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1697121343.058325][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_kvs-CgekUL)
[1697121343.058558][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs)
[1697121343.059026][5383:5383] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1697121343.059210][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-k8ROAf)
[1697121343.059381][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1697121343.059475][5383:5383] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1697121343.059698][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_config.ini-fSRz5o)
[1697121343.059860][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1697121343.059951][5383:5383] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1697121343.060088][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-a13ONI)
[1697121343.060251][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1697121343.060482][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-eUz1IN)
[1697121343.061131][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1697121343.061197][5383:5383] CHIP:DL: NVS set: chip-factory/unique-id = "C1B730673A077643"
[1697121343.061369][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-xv3eZh)
[1697121343.061880][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1697121343.061942][5383:5383] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1)
[1697121343.062094][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-yJK7kx)
[1697121343.062663][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini)
[1697121343.062730][5383:5383] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001)
[1697121343.062894][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ZYofCb)
[1697121343.063379][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1697121343.063438][5383:5383] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1)
[1697121343.063597][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-PbOPmP)
[1697121343.064052][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1697121343.064163][5383:5383] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1697121343.064333][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-TgZMGU)
[1697121343.064817][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1697121343.064878][5383:5383] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0)
[1697121343.065028][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_config.ini-uIuUih)
[1697121343.065499][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1697121343.065554][5383:5383] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0)
[1697121343.065730][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_config.ini-aIXkP3)
[1697121343.066268][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini)
[1697121343.066333][5383:5383] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2)
[1697121343.066964][5383:5383] CHIP:DL: Got Ethernet interface: eth0
[1697121343.067402][5383:5383] CHIP:DL: Found the primary Ethernet interface:eth0
[1697121343.067826][5383:5383] CHIP:DL: Got WiFi interface: wlan0
[1697121343.067898][5383:5383] CHIP:DL: Failed to reset WiFi statistic counts
[1697121343.067989][5383:5383] CHIP:IN: UDP::Init bind&listen port=0
[1697121343.068175][5383:5383] CHIP:IN: UDP::Init bound to port=39326
[1697121343.068200][5383:5383] CHIP:IN: UDP::Init bind&listen port=0
[1697121343.068302][5383:5383] CHIP:IN: UDP::Init bound to port=60231
[1697121343.068333][5383:5383] CHIP:IN: BLEBase::Init - setting/overriding transport
[1697121343.068353][5383:5383] CHIP:IN: TransportMgr initialized
[1697121343.068387][5383:5383] CHIP:FP: Initializing FabricTable from persistent storage
[1697121343.068432][5383:5383] CHIP:TS: Last Known Good Time: [unknown]
[1697121343.068466][5383:5383] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-07-11T08:00:09
[1697121343.070273][5383:5383] CHIP:ZCL: Using ZAP configuration...
[1697121343.074886][5383:5383] CHIP:DL: Avahi client registered
[1697121343.076146][5383:5383] CHIP:CTL: System State Initialized...
[1697121343.076308][5383:5383] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1697121343.076356][5383:5383] CHIP:CTL: Setting attestation nonce to random value
[1697121343.076385][5383:5383] CHIP:CTL: Setting CSR nonce to random value
[1697121343.076738][5383:5385] CHIP:DL: CHIP task running
[1697121343.076998][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1697121343.077521][5383:5385] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1697121343.077576][5383:5385] CHIP:CTL: Setting attestation nonce to random value
[1697121343.077615][5383:5385] CHIP:CTL: Setting CSR nonce to random value
[1697121343.077729][5383:5385] CHIP:CTL: Couldn't get ExampleOpCredsCAKey from storage: src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1697121343.092434][5383:5385] CHIP:CTL: Couldn't get ExampleOpCredsICAKey from storage: src/controller/ExamplePersistentStorage.cpp:93: CHIP Error 0x000000A0: Value not found in the persisted storage
[1697121343.113963][5383:5385] CHIP:CTL: Generating RCAC
[1697121343.125528][5383:5385] CHIP:CTL: Generating ICAC
[1697121343.136963][5383:5385] CHIP:CTL: Generating NOC
[1697121343.148155][5383:5385] CHIP:FP: Validating NOC chain
[1697121343.191241][5383:5385] CHIP:FP: NOC chain validation successful
[1697121343.191308][5383:5385] CHIP:FP: Added new fabric at index: 0x1
[1697121343.191332][5383:5385] CHIP:FP: Assigned compressed fabric ID: 0x1534A8A76FBAF98B, node ID: 0x000000000001B669
[1697121343.191357][5383:5385] CHIP:TS: Last Known Good Time: 2023-07-11T08:00:09
[1697121343.191377][5383:5385] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1697121343.191395][5383:5385] CHIP:TS: Retaining current Last Known Good Time
[1697121343.192675][5383:5385] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1697121343.194242][5383:5385] CHIP:TS: Committing Last Known Good Time to storage: 2023-07-11T08:00:09
[1697121343.195981][5383:5385] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 1534A8A76FBAF98B)
[1697121343.220464][5383:5385] CHIP:CTL: Setting wifi credentials from parameters
[1697121343.220512][5383:5385] CHIP:CTL: Setting attestation nonce to random value
[1697121343.220548][5383:5385] CHIP:CTL: Setting CSR nonce to random value
[1697121343.220576][5383:5385] CHIP:CTL: Commission called for node ID 0x0000000000000001
[1697121343.220603][5383:5385] CHIP:DL: Long dispatch time: 143 ms, for event type 2
[1697121343.225711][5383:5384] CHIP:DL: TRACE: Bus acquired for name C-1507
[1697121343.234473][5383:5385] CHIP:DL: PlatformBlueZInit init success
[1697121343.242400][5383:5384] CHIP:BLE: BLE removing known devices.
[1697121343.245063][5383:5384] CHIP:BLE: BLE initiating scan.
[1697121343.259753][5383:5384] CHIP:BLE: New device scanned: D6:A9:C0:D9:16:F3
[1697121343.259836][5383:5384] CHIP:BLE: Device discriminator match. Attempting to connect.
[1697121343.896789][5383:5384] CHIP:DL: ConnectDevice complete
[1697121345.180559][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0001
[1697121345.180615][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180642][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0001
[1697121345.180664][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180688][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0001
[1697121345.180709][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180734][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180754][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180778][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180798][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180825][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0001
[1697121345.180845][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180867][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0001
[1697121345.180886][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180909][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0001
[1697121345.180952][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.180986][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0001
[1697121345.181006][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.181038][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0001
[1697121345.181059][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.181081][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0001
[1697121345.181101][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.181137][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.181158][5383:5384] CHIP:DL: Char1 /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3/service0010
[1697121345.181185][5383:5384] CHIP:DL: New BLE connection 0xffff94036750, device D6:A9:C0:D9:16:F3, path /org/bluez/hci0/dev_D6_A9_C0_D9_16_F3
[1697121345.181316][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16385
[1697121345.181357][5383:5385] CHIP:DIS: Closing all BLE connections
[1697121345.181419][5383:5385] CHIP:IN: BleConnectionComplete: endPoint 0xaaaabd366aa0
[1697121345.181892][5383:5385] CHIP:IN: SecureSession[0xffff8c007c60]: Allocated Type:1 LSID:28183
[1697121345.181938][5383:5385] CHIP:SC: Assigned local session key ID 28183
[1697121345.182045][5383:5385] CHIP:EM: <<< [E:52037i S:0 M:240474498] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
[1697121345.182104][5383:5385] CHIP:IN: (U) Sending msg 240474498 to IP address 'BLE'
[1697121345.182140][5383:5385] CHIP:IN: Message appended to BLE send queue
[1697121345.182164][5383:5385] CHIP:SC: Sent PBKDF param request
[1697121345.593781][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121345.686767][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1697121345.686892][5383:5385] CHIP:BLE: subscribe complete, ep = 0xaaaabd366aa0
[1697121345.688218][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121345.688779][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121345.688873][5383:5385] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4
[1697121345.688944][5383:5385] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244.
[1697121345.689000][5383:5385] CHIP:BLE: local and remote recv window size = 5
[1697121345.690197][5383:5385] CHIP:IN: BLE EndPoint 0xaaaabd366aa0 Connection Complete
[1697121345.773680][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121345.820824][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121345.821241][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121345.821487][5383:5385] CHIP:EM: >>> [E:52037i S:0 M:103645598] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
[1697121345.821572][5383:5385] CHIP:EM: Found matching exchange: 52037i, Delegate: 0xffff8c00ce10
[1697121345.821668][5383:5385] CHIP:SC: Received PBKDF param response
[1697121345.821775][5383:5385] CHIP:SC: Peer assigned session ID 52969
[1697121345.821843][5383:5385] CHIP:SC: Found MRP parameters in the message
[1697121345.881323][5383:5385] CHIP:EM: <<< [E:52037i S:0 M:240474499] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
[1697121345.881388][5383:5385] CHIP:IN: (U) Sending msg 240474499 to IP address 'BLE'
[1697121345.881769][5383:5385] CHIP:SC: Sent spake2p msg1
[1697121345.954314][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121347.351380][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121347.351794][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121347.352121][5383:5385] CHIP:EM: >>> [E:52037i S:0 M:103645599] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
[1697121347.352227][5383:5385] CHIP:EM: Found matching exchange: 52037i, Delegate: 0xffff8c00ce10
[1697121347.352336][5383:5385] CHIP:SC: Received spake2p msg2
[1697121347.402710][5383:5385] CHIP:EM: <<< [E:52037i S:0 M:240474500] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
[1697121347.402781][5383:5385] CHIP:IN: (U) Sending msg 240474500 to IP address 'BLE'
[1697121347.403234][5383:5385] CHIP:SC: Sent spake2p msg3
[1697121347.482374][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121347.530232][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121347.530578][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121347.530960][5383:5385] CHIP:EM: >>> [E:52037i S:0 M:103645600] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1697121347.531053][5383:5385] CHIP:EM: Found matching exchange: 52037i, Delegate: 0xffff8c00ce10
[1697121347.531346][5383:5385] CHIP:SC: SecureSession[0xffff8c007c60]: Moving from state 'kEstablishing' --> 'kActive'
[1697121347.531437][5383:5385] CHIP:IN: SecureSession[0xffff8c007c60]: Activated - Type:1 LSID:28183
[1697121347.531507][5383:5385] CHIP:IN: New secure session activated for device <FFFFFFFB00000000, 0>, LSID:28183 PSID:52969!
[1697121347.531586][5383:5385] CHIP:CTL: Remote device completed SPAKE2+ handshake
[1697121347.531651][5383:5385] CHIP:TOO: Pairing Success
[1697121347.531709][5383:5385] CHIP:TOO: PASE establishment successful
[1697121347.531780][5383:5385] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1697121347.531855][5383:5385] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo'
[1697121347.531918][5383:5385] CHIP:CTL: Sending request for commissioning information
[1697121347.532025][5383:5385] CHIP:DMG: SendReadRequest ReadClient[0xffff8c014670]: Sending Read Request
[1697121347.532389][5383:5385] CHIP:EM: <<< [E:52038i S:28183 M:154142813] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
[1697121347.532509][5383:5385] CHIP:IN: (S) Sending msg 154142813 on secure session with LSID: 28183
[1697121347.533374][5383:5385] CHIP:DMG: MoveToState ReadClient[0xffff8c014670]: Moving to [AwaitingIn]
[1697121347.618815][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121347.712504][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121347.713118][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121347.799485][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121347.800036][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121347.800366][5383:5385] CHIP:EM: >>> [E:52038i S:28183 M:200847291] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
[1697121347.800448][5383:5385] CHIP:EM: Found matching exchange: 52038i, Delegate: 0xffff8c014680
[1697121347.800660][5383:5385] CHIP:DMG: ReportDataMessage =
[1697121347.800712][5383:5385] CHIP:DMG: {
[1697121347.800756][5383:5385] CHIP:DMG: AttributeReportIBs =
[1697121347.800837][5383:5385] CHIP:DMG: [
[1697121347.800886][5383:5385] CHIP:DMG: AttributeReportIB =
[1697121347.800952][5383:5385] CHIP:DMG: {
[1697121347.801003][5383:5385] CHIP:DMG: AttributeDataIB =
[1697121347.801086][5383:5385] CHIP:DMG: {
[1697121347.801148][5383:5385] CHIP:DMG: DataVersion = 0x6a70eb69,
[1697121347.801227][5383:5385] CHIP:DMG: AttributePathIB =
[1697121347.801298][5383:5385] CHIP:DMG: {
[1697121347.801495][5383:5385] CHIP:DMG: Endpoint = 0x0,
[1697121347.801584][5383:5385] CHIP:DMG: Cluster = 0x31,
[1697121347.801657][5383:5385] CHIP:DMG: Attribute = 0x0000_0003,
[1697121347.801725][5383:5385] CHIP:DMG: }
[1697121347.801810][5383:5385] CHIP:DMG:
[1697121347.801878][5383:5385] CHIP:DMG: Data = 35,
[1697121347.801953][5383:5385] CHIP:DMG: },
[1697121347.802019][5383:5385] CHIP:DMG:
[1697121347.802070][5383:5385] CHIP:DMG: },
[1697121347.802163][5383:5385] CHIP:DMG:
[1697121347.802291][5383:5385] CHIP:DMG: AttributeReportIB =
[1697121347.802357][5383:5385] CHIP:DMG: {
[1697121347.802425][5383:5385] CHIP:DMG: AttributeDataIB =
[1697121347.802485][5383:5385] CHIP:DMG: {
[1697121347.802547][5383:5385] CHIP:DMG: DataVersion = 0xe9e4b422,
[1697121347.802659][5383:5385] CHIP:DMG: AttributePathIB =
[1697121347.802731][5383:5385] CHIP:DMG: {
[1697121347.802812][5383:5385] CHIP:DMG: Endpoint = 0x0,
[1697121347.802880][5383:5385] CHIP:DMG: Cluster = 0x28,
[1697121347.802966][5383:5385] CHIP:DMG: Attribute = 0x0000_0004,
[1697121347.803093][5383:5385] CHIP:DMG: }
[1697121347.803183][5383:5385] CHIP:DMG:
[1697121347.803253][5383:5385] CHIP:DMG: Data = 32773,
[1697121347.803335][5383:5385] CHIP:DMG: },
[1697121347.803399][5383:5385] CHIP:DMG:
[1697121347.803474][5383:5385] CHIP:DMG: },
[1697121347.803546][5383:5385] CHIP:DMG:
[1697121347.803609][5383:5385] CHIP:DMG: AttributeReportIB =
[1697121347.803675][5383:5385] CHIP:DMG: {
[1697121347.803726][5383:5385] CHIP:DMG: AttributeDataIB =
[1697121347.803812][5383:5385] CHIP:DMG: {
[1697121347.803876][5383:5385] CHIP:DMG: DataVersion = 0xe9e4b422,
[1697121347.804032][5383:5385] CHIP:DMG: AttributePathIB =
[1697121347.804127][5383:5385] CHIP:DMG: {
[1697121347.804240][5383:5385] CHIP:DMG: Endpoint = 0x0,
[1697121347.804342][5383:5385] CHIP:DMG: Cluster = 0x28,
[1697121347.804439][5383:5385] CHIP:DMG: Attribute = 0x0000_0002,
[1697121347.804608][5383:5385] CHIP:DMG: }
[1697121347.804689][5383:5385] CHIP:DMG:
[1697121347.804769][5383:5385] CHIP:DMG: Data = 65521,
[1697121347.804829][5383:5385] CHIP:DMG: },
[1697121347.804912][5383:5385] CHIP:DMG:
[1697121347.804967][5383:5385] CHIP:DMG: },
[1697121347.805037][5383:5385] CHIP:DMG:
[1697121347.805103][5383:5385] CHIP:DMG: AttributeReportIB =
[1697121347.805165][5383:5385] CHIP:DMG: {
[1697121347.805232][5383:5385] CHIP:DMG: AttributeDataIB =
[1697121347.805291][5383:5385] CHIP:DMG: {
[1697121347.805352][5383:5385] CHIP:DMG: DataVersion = 0x56ea9a70,
[1697121347.805429][5383:5385] CHIP:DMG: AttributePathIB =
[1697121347.805493][5383:5385] CHIP:DMG: {
[1697121347.805571][5383:5385] CHIP:DMG: Endpoint = 0x0,
[1697121347.805642][5383:5385] CHIP:DMG: Cluster = 0x30,
[1697121347.805783][5383:5385] CHIP:DMG: Attribute = 0x0000_0003,
[1697121347.805855][5383:5385] CHIP:DMG: }
[1697121347.805942][5383:5385] CHIP:DMG:
[1697121347.806007][5383:5385] CHIP:DMG: Data = 0,
[1697121347.806084][5383:5385] CHIP:DMG: },
[1697121347.806149][5383:5385] CHIP:DMG:
[1697121347.806217][5383:5385] CHIP:DMG: },
[1697121347.806288][5383:5385] CHIP:DMG:
[1697121347.806335][5383:5385] CHIP:DMG: AttributeReportIB =
[1697121347.806413][5383:5385] CHIP:DMG: {
[1697121347.806465][5383:5385] CHIP:DMG: AttributeDataIB =
[1697121347.806536][5383:5385] CHIP:DMG: {
[1697121347.806596][5383:5385] CHIP:DMG: DataVersion = 0x56ea9a70,
[1697121347.806856][5383:5385] CHIP:DMG: AttributePathIB =
[1697121347.806939][5383:5385] CHIP:DMG: {
[1697121347.807003][5383:5385] CHIP:DMG: Endpoint = 0x0,
[1697121347.807073][5383:5385] CHIP:DMG: Cluster = 0x30,
[1697121347.807161][5383:5385] CHIP:DMG: Attribute = 0x0000_0002,
[1697121347.807228][5383:5385] CHIP:DMG: }
[1697121347.807310][5383:5385] CHIP:DMG:
[1697121347.807377][5383:5385] CHIP:DMG: Data = 0,
[1697121347.807437][5383:5385] CHIP:DMG: },
[1697121347.807571][5383:5385] CHIP:DMG:
[1697121347.807644][5383:5385] CHIP:DMG: },
[1697121347.807720][5383:5385] CHIP:DMG:
[1697121347.807784][5383:5385] CHIP:DMG: AttributeReportIB =
[1697121347.807852][5383:5385] CHIP:DMG: {
[1697121347.807902][5383:5385] CHIP:DMG: AttributeDataIB =
[1697121347.807978][5383:5385] CHIP:DMG: {
[1697121347.808038][5383:5385] CHIP:DMG: DataVersion = 0x56ea9a70,
[1697121347.808114][5383:5385] CHIP:DMG: AttributePathIB =
[1697121347.808183][5383:5385] CHIP:DMG: {
[1697121347.808263][5383:5385] CHIP:DMG: Endpoint = 0x0,
[1697121347.808332][5383:5385] CHIP:DMG: Cluster = 0x30,
[1697121347.808446][5383:5385] CHIP:DMG: Attribute = 0x0000_0001,
[1697121347.808512][5383:5385] CHIP:DMG: }
[1697121347.808578][5383:5385] CHIP:DMG:
[1697121347.808657][5383:5385] CHIP:DMG: Data =
[1697121347.808720][5383:5385] CHIP:DMG: {
[1697121347.808803][5383:5385] CHIP:DMG: 0x0 = 60,
[1697121347.808875][5383:5385] CHIP:DMG: 0x1 = 900,
[1697121347.808959][5383:5385] CHIP:DMG: },
[1697121347.809019][5383:5385] CHIP:DMG: },
[1697121347.809102][5383:5385] CHIP:DMG:
[1697121347.809154][5383:5385] CHIP:DMG: },
[1697121347.809243][5383:5385] CHIP:DMG:
[1697121347.809293][5383:5385] CHIP:DMG: AttributeReportIB =
[1697121347.809355][5383:5385] CHIP:DMG: {
[1697121347.809422][5383:5385] CHIP:DMG: AttributeDataIB =
[1697121347.809479][5383:5385] CHIP:DMG: {
[1697121347.809554][5383:5385] CHIP:DMG: DataVersion = 0x56ea9a70,
[1697121347.809615][5383:5385] CHIP:DMG: AttributePathIB =
[1697121347.809736][5383:5385] CHIP:DMG: {
[1697121347.809803][5383:5385] CHIP:DMG: Endpoint = 0x0,
[1697121347.809870][5383:5385] CHIP:DMG: Cluster = 0x30,
[1697121347.809957][5383:5385] CHIP:DMG: Attribute = 0x0000_0000,
[1697121347.810021][5383:5385] CHIP:DMG: }
[1697121347.810093][5383:5385] CHIP:DMG:
[1697121347.810129][5383:5385] CHIP:DMG: Data = 0,
[1697121347.810165][5383:5385] CHIP:DMG: },
[1697121347.810196][5383:5385] CHIP:DMG:
[1697121347.810227][5383:5385] CHIP:DMG: },
[1697121347.810260][5383:5385] CHIP:DMG:
[1697121347.810344][5383:5385] CHIP:DMG: AttributeReportIB =
[1697121347.810383][5383:5385] CHIP:DMG: {
[1697121347.810407][5383:5385] CHIP:DMG: AttributeDataIB =
[1697121347.810435][5383:5385] CHIP:DMG: {
[1697121347.810464][5383:5385] CHIP:DMG: DataVersion = 0x6a70eb69,
[1697121347.810501][5383:5385] CHIP:DMG: AttributePathIB =
[1697121347.810569][5383:5385] CHIP:DMG: {
[1697121347.810600][5383:5385] CHIP:DMG: Endpoint = 0x0,
[1697121347.810647][5383:5385] CHIP:DMG: Cluster = 0x31,
[1697121347.810688][5383:5385] CHIP:DMG: Attribute = 0x0000_FFFC,
[1697121347.810719][5383:5385] CHIP:DMG: }
[1697121347.810759][5383:5385] CHIP:DMG:
[1697121347.810791][5383:5385] CHIP:DMG: Data = 1,
[1697121347.810828][5383:5385] CHIP:DMG: },
[1697121347.810858][5383:5385] CHIP:DMG:
[1697121347.810891][5383:5385] CHIP:DMG: },
[1697121347.810921][5383:5385] CHIP:DMG:
[1697121347.810943][5383:5385] CHIP:DMG: ],
[1697121347.811004][5383:5385] CHIP:DMG:
[1697121347.811036][5383:5385] CHIP:DMG: SuppressResponse = true,
[1697121347.811060][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121347.811082][5383:5385] CHIP:DMG: }
[1697121347.811875][5383:5385] CHIP:CTL: ----- NetworkCommissioning Features: has WiFi. endpointid = 0
[1697121347.811945][5383:5385] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo'
[1697121347.811978][5383:5385] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe'
[1697121347.812009][5383:5385] CHIP:CTL: Performing next commissioning step 'ArmFailSafe'
[1697121347.812034][5383:5385] CHIP:CTL: Arming failsafe (60 seconds)
[1697121347.812110][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121347.812150][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121347.812296][5383:5385] CHIP:EM: <<< [E:52039i S:28183 M:154142814] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121347.812336][5383:5385] CHIP:IN: (S) Sending msg 154142814 on secure session with LSID: 28183
[1697121347.812726][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121347.888689][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121347.936089][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121347.936954][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121347.937366][5383:5385] CHIP:EM: >>> [E:52039i S:28183 M:200847292] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121347.937462][5383:5385] CHIP:EM: Found matching exchange: 52039i, Delegate: 0xffff940383e8
[1697121347.937577][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121347.937698][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121347.937760][5383:5385] CHIP:DMG: {
[1697121347.937821][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121347.937886][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121347.937972][5383:5385] CHIP:DMG: [
[1697121347.938036][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121347.938123][5383:5385] CHIP:DMG: {
[1697121347.938191][5383:5385] CHIP:DMG: CommandDataIB =
[1697121347.938280][5383:5385] CHIP:DMG: {
[1697121347.938355][5383:5385] CHIP:DMG: CommandPathIB =
[1697121347.938442][5383:5385] CHIP:DMG: {
[1697121347.938529][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121347.938688][5383:5385] CHIP:DMG: ClusterId = 0x30,
[1697121347.938783][5383:5385] CHIP:DMG: CommandId = 0x1,
[1697121347.938869][5383:5385] CHIP:DMG: },
[1697121347.938957][5383:5385] CHIP:DMG:
[1697121347.939034][5383:5385] CHIP:DMG: CommandFields =
[1697121347.939120][5383:5385] CHIP:DMG: {
[1697121347.939209][5383:5385] CHIP:DMG: 0x0 = 0,
[1697121347.939305][5383:5385] CHIP:DMG: 0x1 = "" (0 chars),
[1697121347.939396][5383:5385] CHIP:DMG: },
[1697121347.939477][5383:5385] CHIP:DMG: },
[1697121347.939565][5383:5385] CHIP:DMG:
[1697121347.939632][5383:5385] CHIP:DMG: },
[1697121347.939712][5383:5385] CHIP:DMG:
[1697121347.939775][5383:5385] CHIP:DMG: ],
[1697121347.939858][5383:5385] CHIP:DMG:
[1697121347.939919][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121347.939980][5383:5385] CHIP:DMG: },
[1697121347.940140][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1697121347.940343][5383:5385] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1697121347.940420][5383:5385] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe'
[1697121347.940479][5383:5385] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1697121347.940550][5383:5385] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory'
[1697121347.940608][5383:5385] CHIP:CTL: Setting Regulatory Config
[1697121347.940662][5383:5385] CHIP:CTL: Device does not support configurable regulatory location
[1697121347.940855][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121347.941036][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121347.941254][5383:5385] CHIP:EM: <<< [E:52040i S:28183 M:154142815] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121347.941353][5383:5385] CHIP:IN: (S) Sending msg 154142815 on secure session with LSID: 28183
[1697121347.942234][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121347.942391][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121348.023571][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121348.071337][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121348.071658][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121348.072016][5383:5385] CHIP:EM: >>> [E:52040i S:28183 M:200847293] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121348.072110][5383:5385] CHIP:EM: Found matching exchange: 52040i, Delegate: 0xffff8c008b28
[1697121348.072197][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121348.072295][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121348.072347][5383:5385] CHIP:DMG: {
[1697121348.072393][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121348.072445][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121348.072512][5383:5385] CHIP:DMG: [
[1697121348.072563][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121348.072632][5383:5385] CHIP:DMG: {
[1697121348.072708][5383:5385] CHIP:DMG: CommandDataIB =
[1697121348.072781][5383:5385] CHIP:DMG: {
[1697121348.072846][5383:5385] CHIP:DMG: CommandPathIB =
[1697121348.072919][5383:5385] CHIP:DMG: {
[1697121348.073000][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121348.073082][5383:5385] CHIP:DMG: ClusterId = 0x30,
[1697121348.073159][5383:5385] CHIP:DMG: CommandId = 0x3,
[1697121348.073233][5383:5385] CHIP:DMG: },
[1697121348.073310][5383:5385] CHIP:DMG:
[1697121348.073376][5383:5385] CHIP:DMG: CommandFields =
[1697121348.073448][5383:5385] CHIP:DMG: {
[1697121348.073530][5383:5385] CHIP:DMG: 0x0 = 0,
[1697121348.073618][5383:5385] CHIP:DMG: 0x1 = "" (0 chars),
[1697121348.073696][5383:5385] CHIP:DMG: },
[1697121348.073766][5383:5385] CHIP:DMG: },
[1697121348.073842][5383:5385] CHIP:DMG:
[1697121348.073900][5383:5385] CHIP:DMG: },
[1697121348.073968][5383:5385] CHIP:DMG:
[1697121348.074022][5383:5385] CHIP:DMG: ],
[1697121348.074092][5383:5385] CHIP:DMG:
[1697121348.074145][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121348.074199][5383:5385] CHIP:DMG: },
[1697121348.074334][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1697121348.074517][5383:5385] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0
[1697121348.074593][5383:5385] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory'
[1697121348.074696][5383:5385] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest'
[1697121348.074761][5383:5385] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest'
[1697121348.074810][5383:5385] CHIP:CTL: Sending request for PAI certificate
[1697121348.074855][5383:5385] CHIP:CTL: Sending Certificate Chain request to 0xffff8c00cdc0 device
[1697121348.074987][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121348.075133][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121348.075340][5383:5385] CHIP:EM: <<< [E:52041i S:28183 M:154142816] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121348.075431][5383:5385] CHIP:IN: (S) Sending msg 154142816 on secure session with LSID: 28183
[1697121348.076359][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121348.076509][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121348.158501][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121348.207374][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121348.207847][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121348.297081][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121348.298245][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121348.384974][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121348.385599][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121348.386039][5383:5385] CHIP:EM: >>> [E:52041i S:28183 M:200847294] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121348.386158][5383:5385] CHIP:EM: Found matching exchange: 52041i, Delegate: 0xffff940383e8
[1697121348.386258][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121348.386366][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121348.386419][5383:5385] CHIP:DMG: {
[1697121348.386472][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121348.386553][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121348.386678][5383:5385] CHIP:DMG: [
[1697121348.386740][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121348.386836][5383:5385] CHIP:DMG: {
[1697121348.386894][5383:5385] CHIP:DMG: CommandDataIB =
[1697121348.386984][5383:5385] CHIP:DMG: {
[1697121348.387051][5383:5385] CHIP:DMG: CommandPathIB =
[1697121348.387143][5383:5385] CHIP:DMG: {
[1697121348.387362][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121348.387449][5383:5385] CHIP:DMG: ClusterId = 0x3e,
[1697121348.387545][5383:5385] CHIP:DMG: CommandId = 0x3,
[1697121348.387619][5383:5385] CHIP:DMG: },
[1697121348.387717][5383:5385] CHIP:DMG:
[1697121348.387785][5383:5385] CHIP:DMG: CommandFields =
[1697121348.387859][5383:5385] CHIP:DMG: {
[1697121348.387951][5383:5385] CHIP:DMG: 0x0 = [
[1697121348.388270][5383:5385] 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
[1697121348.388432][5383:5385] CHIP:DMG: ] (463 bytes)
[1697121348.388514][5383:5385] CHIP:DMG: },
[1697121348.388584][5383:5385] CHIP:DMG: },
[1697121348.388662][5383:5385] CHIP:DMG:
[1697121348.388719][5383:5385] CHIP:DMG: },
[1697121348.388788][5383:5385] CHIP:DMG:
[1697121348.388842][5383:5385] CHIP:DMG: ],
[1697121348.388936][5383:5385] CHIP:DMG:
[1697121348.388992][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121348.389045][5383:5385] CHIP:DMG: },
[1697121348.389279][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1697121348.389359][5383:5385] CHIP:CTL: Received certificate chain from the device
[1697121348.389422][5383:5385] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest'
[1697121348.389482][5383:5385] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1697121348.389547][5383:5385] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest'
[1697121348.389597][5383:5385] CHIP:CTL: Sending request for DAC certificate
[1697121348.389642][5383:5385] CHIP:CTL: Sending Certificate Chain request to 0xffff8c00cdc0 device
[1697121348.389797][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121348.389884][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121348.390113][5383:5385] CHIP:EM: <<< [E:52042i S:28183 M:154142817] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121348.390271][5383:5385] CHIP:IN: (S) Sending msg 154142817 on secure session with LSID: 28183
[1697121348.391226][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121348.391385][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121348.472518][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121348.522284][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121348.523021][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121348.612580][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121348.613295][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121348.701276][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121348.701982][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121348.702477][5383:5385] CHIP:EM: >>> [E:52042i S:28183 M:200847295] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121348.702585][5383:5385] CHIP:EM: Found matching exchange: 52042i, Delegate: 0xffff94038b08
[1697121348.702806][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121348.702929][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121348.702992][5383:5385] CHIP:DMG: {
[1697121348.703055][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121348.703122][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121348.703205][5383:5385] CHIP:DMG: [
[1697121348.703298][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121348.703384][5383:5385] CHIP:DMG: {
[1697121348.703452][5383:5385] CHIP:DMG: CommandDataIB =
[1697121348.703559][5383:5385] CHIP:DMG: {
[1697121348.703753][5383:5385] CHIP:DMG: CommandPathIB =
[1697121348.703850][5383:5385] CHIP:DMG: {
[1697121348.703939][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121348.704053][5383:5385] CHIP:DMG: ClusterId = 0x3e,
[1697121348.704142][5383:5385] CHIP:DMG: CommandId = 0x3,
[1697121348.704262][5383:5385] CHIP:DMG: },
[1697121348.704354][5383:5385] CHIP:DMG:
[1697121348.704461][5383:5385] CHIP:DMG: CommandFields =
[1697121348.704549][5383:5385] CHIP:DMG: {
[1697121348.704699][5383:5385] CHIP:DMG: 0x0 = [
[1697121348.704991][5383:5385] CHIP:DMG: 0x30, 0x82, 0x01, 0xe8, 0x30, 0x82, 0x01, 0x8e, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x6f, 0xdc, 0xb6, 0xed, 0x06, 0xf3, 0x58, 0xf9, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x53, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x44, 0x41, 0x43, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x2f, 0x30, 0x78, 0x38, 0x30, 0x30, 0x35, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x02, 0x0c, 0x04, 0x38, 0x30, 0x30, 0x35, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x7e, 0xf2, 0xf1, 0x08, 0x2b, 0x2a, 0x56, 0x4a, 0x05, 0x44, 0xc0, 0xa6, 0x13, 0xd2, 0x1b, 0x15, 0x75, 0x00, 0x55, 0x2d, 0x03, 0x5f, 0x23, 0x02, 0x25, 0x2f, 0xce, 0xe8, 0x1d, 0x6e, 0xc6, 0x74, 0x17, 0x34, 0x18, 0xa9, 0x4a, 0x88, 0xdb, 0x
[1697121348.705192][5383:5385] CHIP:DMG: ] (492 bytes)
[1697121348.705288][5383:5385] CHIP:DMG: },
[1697121348.705368][5383:5385] CHIP:DMG: },
[1697121348.705456][5383:5385] CHIP:DMG:
[1697121348.705522][5383:5385] CHIP:DMG: },
[1697121348.705709][5383:5385] CHIP:DMG:
[1697121348.705774][5383:5385] CHIP:DMG: ],
[1697121348.705856][5383:5385] CHIP:DMG:
[1697121348.705944][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121348.706006][5383:5385] CHIP:DMG: },
[1697121348.706186][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1697121348.706277][5383:5385] CHIP:CTL: Received certificate chain from the device
[1697121348.706381][5383:5385] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest'
[1697121348.706456][5383:5385] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1697121348.706596][5383:5385] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest'
[1697121348.706702][5383:5385] CHIP:CTL: Sending Attestation Request to the device.
[1697121348.706760][5383:5385] CHIP:CTL: Sending Attestation request to 0xffff8c00cdc0 device
[1697121348.706932][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121348.707013][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121348.707278][5383:5385] CHIP:EM: <<< [E:52043i S:28183 M:154142818] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121348.707400][5383:5385] CHIP:IN: (S) Sending msg 154142818 on secure session with LSID: 28183
[1697121348.708358][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121348.708473][5383:5385] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information
[1697121348.708606][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121348.788685][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121348.882318][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121348.882885][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121348.972603][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121348.973105][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121349.062734][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121349.063228][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121349.063734][5383:5385] CHIP:EM: >>> [E:52043i S:28183 M:200847296] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121349.063852][5383:5385] CHIP:EM: Found matching exchange: 52043i, Delegate: 0xffff940392c8
[1697121349.063963][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121349.064099][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121349.064176][5383:5385] CHIP:DMG: {
[1697121349.064245][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121349.064319][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121349.064405][5383:5385] CHIP:DMG: [
[1697121349.064469][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121349.064558][5383:5385] CHIP:DMG: {
[1697121349.064627][5383:5385] CHIP:DMG: CommandDataIB =
[1697121349.064713][5383:5385] CHIP:DMG: {
[1697121349.064791][5383:5385] CHIP:DMG: CommandPathIB =
[1697121349.064878][5383:5385] CHIP:DMG: {
[1697121349.064971][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121349.065066][5383:5385] CHIP:DMG: ClusterId = 0x3e,
[1697121349.065160][5383:5385] CHIP:DMG: CommandId = 0x1,
[1697121349.065250][5383:5385] CHIP:DMG: },
[1697121349.065341][5383:5385] CHIP:DMG:
[1697121349.065419][5383:5385] CHIP:DMG: CommandFields =
[1697121349.065505][5383:5385] CHIP:DMG: {
[1697121349.065592][5383:5385] CHIP:DMG: 0x0 = [
[1697121349.065862][5383:5385] 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
[1697121349.066037][5383:5385] CHIP:DMG: ] (583 bytes)
[1697121349.066130][5383:5385] CHIP:DMG: 0x1 = [
[1697121349.066251][5383:5385] CHIP:DMG: 0x0b, 0x5e, 0x6d, 0x14, 0xfb, 0x5a, 0xee, 0x34, 0xe9, 0xf5, 0xf9, 0xdd, 0x7c, 0x4d, 0x6f, 0xa4, 0xac, 0x97, 0x92, 0x55, 0x88, 0x3c, 0x7d, 0xc8, 0x36, 0x25, 0x0f, 0xc6, 0x31, 0x60, 0x62, 0xaa, 0xa1, 0xe0, 0xaf, 0x17, 0x8c, 0x16, 0x9a, 0x9c, 0xbf, 0xdc, 0x5d, 0x3a, 0xf0, 0x43, 0xa5, 0x7a, 0xd5, 0x7f, 0x26, 0xe4, 0xc6, 0x17, 0xd4, 0xc3, 0x48, 0x66, 0xd9, 0x41, 0x3b, 0x96, 0x44, 0xd9,
[1697121349.066373][5383:5385] CHIP:DMG: ] (64 bytes)
[1697121349.066468][5383:5385] CHIP:DMG: },
[1697121349.066549][5383:5385] CHIP:DMG: },
[1697121349.066689][5383:5385] CHIP:DMG:
[1697121349.066766][5383:5385] CHIP:DMG: },
[1697121349.066851][5383:5385] CHIP:DMG:
[1697121349.066914][5383:5385] CHIP:DMG: ],
[1697121349.066994][5383:5385] CHIP:DMG:
[1697121349.067055][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121349.067118][5383:5385] CHIP:DMG: },
[1697121349.067277][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1697121349.067350][5383:5385] CHIP:CTL: Received Attestation Information from the device
[1697121349.067392][5383:5385] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest'
[1697121349.067426][5383:5385] CHIP:CTL: AutoCommissioner setting attestationElements buffer size 583/583
[1697121349.067479][5383:5385] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1697121349.067522][5383:5385] CHIP:CTL: Performing next commissioning step 'AttestationVerification'
[1697121349.067550][5383:5385] CHIP:CTL: Verifying attestation
[1697121349.093079][5383:5385] CHIP:CR: mbedTLS error: ERROR - Generic error
[1697121349.157701][5383:5385] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device.
[1697121349.157742][5383:5385] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification'
[1697121349.157762][5383:5385] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest'
[1697121349.157789][5383:5385] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest'
[1697121349.157809][5383:5385] CHIP:CTL: Sending CSR request to 0xffff8c00cdc0 device
[1697121349.157879][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121349.157909][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121349.158025][5383:5385] CHIP:EM: <<< [E:52044i S:28183 M:154142819] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121349.158063][5383:5385] CHIP:IN: (S) Sending msg 154142819 on secure session with LSID: 28183
[1697121349.158427][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121349.158463][5383:5385] CHIP:CTL: Sent CSR request, waiting for the CSR
[1697121349.158516][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121349.238537][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121349.466513][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121349.467320][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121349.556471][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121349.556831][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121349.557239][5383:5385] CHIP:EM: >>> [E:52044i S:28183 M:200847297] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121349.557346][5383:5385] CHIP:EM: Found matching exchange: 52044i, Delegate: 0xffff940395a8
[1697121349.557450][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121349.557556][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121349.557613][5383:5385] CHIP:DMG: {
[1697121349.557666][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121349.557724][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121349.557799][5383:5385] CHIP:DMG: [
[1697121349.557855][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121349.557934][5383:5385] CHIP:DMG: {
[1697121349.557994][5383:5385] CHIP:DMG: CommandDataIB =
[1697121349.558076][5383:5385] CHIP:DMG: {
[1697121349.558148][5383:5385] CHIP:DMG: CommandPathIB =
[1697121349.558226][5383:5385] CHIP:DMG: {
[1697121349.558315][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121349.558413][5383:5385] CHIP:DMG: ClusterId = 0x3e,
[1697121349.558509][5383:5385] CHIP:DMG: CommandId = 0x5,
[1697121349.558598][5383:5385] CHIP:DMG: },
[1697121349.558766][5383:5385] CHIP:DMG:
[1697121349.558840][5383:5385] CHIP:DMG: CommandFields =
[1697121349.558920][5383:5385] CHIP:DMG: {
[1697121349.558991][5383:5385] CHIP:DMG: 0x0 = [
[1697121349.559196][5383:5385] 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, 0x1e, 0xc6, 0x33, 0x7d, 0x96, 0xbe, 0x25, 0x4c, 0xd9, 0x23, 0x0d, 0xe1, 0xa5, 0xfb, 0x13, 0xd5, 0x52, 0xd4, 0x4f, 0x52, 0xa9, 0xe9, 0x94, 0x2f, 0x13, 0x4f, 0xa0, 0xd3, 0x3c, 0xd0, 0x2a, 0x2f, 0x1b, 0xf7, 0xd6, 0x37, 0x12, 0x0c, 0xbd, 0xc0, 0x56, 0x92, 0xd5, 0xa3, 0x00, 0x6f, 0xb7, 0xbf, 0xdb, 0xf2, 0xa6, 0xb4, 0x8a, 0xae, 0x84, 0xfa, 0x53, 0x1b, 0xac, 0x38, 0x58, 0xd9, 0x38, 0x09, 0xa0, 0x00, 0x30, 0x0c, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x05, 0x00, 0x03, 0x49, 0x00, 0x30, 0x46, 0x02, 0x21, 0x00, 0xca, 0x9e, 0x27, 0x3e, 0x19, 0x53, 0xb1, 0x34, 0x1c, 0x68, 0x8d, 0xc3, 0xe0, 0xec, 0xf1, 0x50, 0x67, 0xc4, 0x86, 0xe1, 0x31, 0x80, 0x79, 0xfe, 0xbb, 0xd5, 0x5e, 0x66, 0x9a, 0xe3, 0x30, 0xd7, 0x02, 0x21, 0x00, 0x8b, 0x19, 0xe0, 0xb4, 0x83, 0xb2, 0x3d, 0x7c, 0xa1, 0x9d, 0x72, 0x27, 0x35, 0x0e, 0x13, 0x34, 0xfb, 0x7f, 0x69, 0xb2, 0xa6, 0x76, 0x69, 0x30, 0x78, 0x65, 0x2b, 0xc7, 0x01, 0x65, 0xdd, 0x6b, 0x30, 0x02, 0x20, 0xa3, 0x29, 0x32, 0x14, 0x66, 0x67, 0xda, 0x6e, 0x76, 0xea, 0xfa, 0xd0, 0x4d, 0x67, 0xdc, 0xb8, 0xea, 0xa5, 0x58, 0x63, 0xe5, 0x53, 0x57, 0x2e, 0xf1, 0xb8, 0xcc, 0x19, 0x91, 0x39, 0x87, 0x6c, 0x18,
[1697121349.559378][5383:5385] CHIP:DMG: ] (246 bytes)
[1697121349.559458][5383:5385] CHIP:DMG: 0x1 = [
[1697121349.559560][5383:5385] CHIP:DMG: 0xc7, 0xe8, 0xc2, 0x0f, 0x42, 0x5b, 0x79, 0x89, 0x34, 0x73, 0xc9, 0x18, 0x48, 0x82, 0xff, 0x90, 0x8c, 0xc8, 0xff, 0x2d, 0xc4, 0x78, 0xa8, 0x94, 0x23, 0x79, 0xba, 0x13, 0x50, 0xff, 0x1e, 0xde, 0xca, 0x63, 0xbe, 0x7a, 0xb7, 0x94, 0x6d, 0xfd, 0xca, 0x0e, 0xcf, 0x47, 0x55, 0xe8, 0x53, 0x40, 0xd8, 0x7b, 0xde, 0xf6, 0xa8, 0xe9, 0x54, 0x48, 0x49, 0x3a, 0x21, 0x77, 0xd3, 0x1f, 0xc6, 0xcf,
[1697121349.559662][5383:5385] CHIP:DMG: ] (64 bytes)
[1697121349.559740][5383:5385] CHIP:DMG: },
[1697121349.559811][5383:5385] CHIP:DMG: },
[1697121349.559886][5383:5385] CHIP:DMG:
[1697121349.559943][5383:5385] CHIP:DMG: },
[1697121349.560014][5383:5385] CHIP:DMG:
[1697121349.560067][5383:5385] CHIP:DMG: ],
[1697121349.560139][5383:5385] CHIP:DMG:
[1697121349.560194][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121349.560247][5383:5385] CHIP:DMG: },
[1697121349.560393][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1697121349.560470][5383:5385] CHIP:CTL: Received certificate signing request from the device
[1697121349.560538][5383:5385] CHIP:CTL: Successfully finished commissioning step 'SendOpCertSigningRequest'
[1697121349.560590][5383:5385] CHIP:CTL: Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR'
[1697121349.560650][5383:5385] CHIP:CTL: Performing next commissioning step 'ValidateCSR'
[1697121349.586563][5383:5385] CHIP:CTL: Successfully finished commissioning step 'ValidateCSR'
[1697121349.586598][5383:5385] CHIP:CTL: Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain'
[1697121349.586628][5383:5385] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain'
[1697121349.586651][5383:5385] CHIP:CTL: Getting certificate chain for the device from the issuer
[1697121349.586708][5383:5385] CHIP:CTL: Verifying Certificate Signing Request
[1697121349.608334][5383:5385] CHIP:CTL: Generating NOC
[1697121349.619135][5383:5385] CHIP:CTL: Providing certificate chain to the commissioner
[1697121349.619164][5383:5385] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status src/controller/ExampleOperationalCredentialsIssuer.cpp:396: Success
[1697121349.619193][5383:5385] CHIP:CTL: Successfully finished commissioning step 'GenerateNOCChain'
[1697121349.619344][5383:5385] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert'
[1697121349.619369][5383:5385] CHIP:CTL: Sending root certificate to the device
[1697121349.619469][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121349.619552][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121349.619677][5383:5385] CHIP:EM: <<< [E:52045i S:28183 M:154142820] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121349.619717][5383:5385] CHIP:IN: (S) Sending msg 154142820 on secure session with LSID: 28183
[1697121349.620244][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121349.620291][5383:5385] CHIP:CTL: Sent root certificate to the device
[1697121349.620642][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121349.688756][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121349.778226][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121349.871041][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121349.871377][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121349.871740][5383:5385] CHIP:EM: >>> [E:52045i S:28183 M:200847298] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121349.871882][5383:5385] CHIP:EM: Found matching exchange: 52045i, Delegate: 0xffff940392c8
[1697121349.871980][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121349.872108][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121349.872170][5383:5385] CHIP:DMG: {
[1697121349.872222][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121349.872279][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121349.872369][5383:5385] CHIP:DMG: [
[1697121349.872425][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121349.872518][5383:5385] CHIP:DMG: {
[1697121349.872579][5383:5385] CHIP:DMG: CommandStatusIB =
[1697121349.872650][5383:5385] CHIP:DMG: {
[1697121349.872734][5383:5385] CHIP:DMG: CommandPathIB =
[1697121349.872815][5383:5385] CHIP:DMG: {
[1697121349.873064][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121349.873153][5383:5385] CHIP:DMG: ClusterId = 0x3e,
[1697121349.873254][5383:5385] CHIP:DMG: CommandId = 0xb,
[1697121349.873327][5383:5385] CHIP:DMG: },
[1697121349.873427][5383:5385] CHIP:DMG:
[1697121349.873494][5383:5385] CHIP:DMG: StatusIB =
[1697121349.873573][5383:5385] CHIP:DMG: {
[1697121349.873671][5383:5385] CHIP:DMG: status = 0x00 (SUCCESS),
[1697121349.873751][5383:5385] CHIP:DMG: },
[1697121349.873848][5383:5385] CHIP:DMG:
[1697121349.873912][5383:5385] CHIP:DMG: },
[1697121349.874004][5383:5385] CHIP:DMG:
[1697121349.874063][5383:5385] CHIP:DMG: },
[1697121349.874212][5383:5385] CHIP:DMG:
[1697121349.874273][5383:5385] CHIP:DMG: ],
[1697121349.874362][5383:5385] CHIP:DMG:
[1697121349.874417][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121349.874470][5383:5385] CHIP:DMG: },
[1697121349.874693][5383:5385] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1697121349.874775][5383:5385] CHIP:CTL: Device confirmed that it has received the root certificate
[1697121349.874836][5383:5385] CHIP:CTL: Successfully finished commissioning step 'SendTrustedRootCert'
[1697121349.874887][5383:5385] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
[1697121349.874949][5383:5385] CHIP:CTL: Performing next commissioning step 'SendNOC'
[1697121349.875201][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121349.875287][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121349.875606][5383:5385] CHIP:EM: <<< [E:52046i S:28183 M:154142821] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121349.875704][5383:5385] CHIP:IN: (S) Sending msg 154142821 on secure session with LSID: 28183
[1697121349.876433][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121349.876517][5383:5385] CHIP:CTL: Sent operational certificate to the device
[1697121349.876619][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121349.957388][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121350.048527][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121350.138366][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121350.411502][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121350.412111][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121350.412517][5383:5385] CHIP:EM: >>> [E:52046i S:28183 M:200847299] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121350.412623][5383:5385] CHIP:EM: Found matching exchange: 52046i, Delegate: 0xffff940395a8
[1697121350.412728][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121350.412849][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121350.412916][5383:5385] CHIP:DMG: {
[1697121350.412979][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121350.413045][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121350.413128][5383:5385] CHIP:DMG: [
[1697121350.413192][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121350.413279][5383:5385] CHIP:DMG: {
[1697121350.413348][5383:5385] CHIP:DMG: CommandDataIB =
[1697121350.413433][5383:5385] CHIP:DMG: {
[1697121350.413509][5383:5385] CHIP:DMG: CommandPathIB =
[1697121350.413591][5383:5385] CHIP:DMG: {
[1697121350.413680][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121350.413776][5383:5385] CHIP:DMG: ClusterId = 0x3e,
[1697121350.413871][5383:5385] CHIP:DMG: CommandId = 0x8,
[1697121350.413961][5383:5385] CHIP:DMG: },
[1697121350.414049][5383:5385] CHIP:DMG:
[1697121350.414125][5383:5385] CHIP:DMG: CommandFields =
[1697121350.414210][5383:5385] CHIP:DMG: {
[1697121350.414298][5383:5385] CHIP:DMG: 0x0 = 0,
[1697121350.414394][5383:5385] CHIP:DMG: 0x1 = 1,
[1697121350.414487][5383:5385] CHIP:DMG: },
[1697121350.414568][5383:5385] CHIP:DMG: },
[1697121350.414734][5383:5385] CHIP:DMG:
[1697121350.414806][5383:5385] CHIP:DMG: },
[1697121350.414889][5383:5385] CHIP:DMG:
[1697121350.414953][5383:5385] CHIP:DMG: ],
[1697121350.415036][5383:5385] CHIP:DMG:
[1697121350.415098][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121350.415160][5383:5385] CHIP:DMG: },
[1697121350.415317][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1697121350.415408][5383:5385] CHIP:CTL: Device returned status 0 on receiving the NOC
[1697121350.415468][5383:5385] CHIP:CTL: Operational credentials provisioned on device 0xffff8c00cdc0
[1697121350.415525][5383:5385] CHIP:TOO: Secure Pairing Success
[1697121350.415577][5383:5385] CHIP:TOO: CASE establishment successful
[1697121350.415643][5383:5385] CHIP:CTL: Successfully finished commissioning step 'SendNOC'
[1697121350.415707][5383:5385] CHIP:CTL: No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks
[1697121350.415764][5383:5385] CHIP:CTL: Commissioning stage next step: 'SendNOC' -> 'WiFiNetworkSetup'
[1697121350.415834][5383:5385] CHIP:CTL: Performing next commissioning step 'WiFiNetworkSetup'
[1697121350.415986][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121350.416198][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121350.416431][5383:5385] CHIP:EM: <<< [E:52047i S:28183 M:154142822] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121350.416535][5383:5385] CHIP:IN: (S) Sending msg 154142822 on secure session with LSID: 28183
[1697121350.417532][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121350.417709][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121350.498718][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121350.546213][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121350.546868][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121350.547372][5383:5385] CHIP:EM: >>> [E:52047i S:28183 M:200847300] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121350.547480][5383:5385] CHIP:EM: Found matching exchange: 52047i, Delegate: 0xffff940392c8
[1697121350.547581][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121350.547694][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121350.547759][5383:5385] CHIP:DMG: {
[1697121350.547821][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121350.547888][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121350.548001][5383:5385] CHIP:DMG: [
[1697121350.548066][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121350.548179][5383:5385] CHIP:DMG: {
[1697121350.548250][5383:5385] CHIP:DMG: CommandDataIB =
[1697121350.548495][5383:5385] CHIP:DMG: {
[1697121350.548603][5383:5385] CHIP:DMG: CommandPathIB =
[1697121350.548692][5383:5385] CHIP:DMG: {
[1697121350.548779][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121350.548874][5383:5385] CHIP:DMG: ClusterId = 0x31,
[1697121350.548986][5383:5385] CHIP:DMG: CommandId = 0x5,
[1697121350.549077][5383:5385] CHIP:DMG: },
[1697121350.549187][5383:5385] CHIP:DMG:
[1697121350.549265][5383:5385] CHIP:DMG: CommandFields =
[1697121350.549452][5383:5385] CHIP:DMG: {
[1697121350.549543][5383:5385] CHIP:DMG: 0x0 = 0,
[1697121350.549662][5383:5385] CHIP:DMG: 0x2 = 0,
[1697121350.549752][5383:5385] CHIP:DMG: },
[1697121350.549851][5383:5385] CHIP:DMG: },
[1697121350.549939][5383:5385] CHIP:DMG:
[1697121350.550025][5383:5385] CHIP:DMG: },
[1697121350.550109][5383:5385] CHIP:DMG:
[1697121350.550172][5383:5385] CHIP:DMG: ],
[1697121350.550341][5383:5385] CHIP:DMG:
[1697121350.550409][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121350.550494][5383:5385] CHIP:DMG: },
[1697121350.550696][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005
[1697121350.551042][5383:5385] CHIP:CTL: Received NetworkConfig response, networkingStatus=0
[1697121350.551127][5383:5385] CHIP:CTL: Successfully finished commissioning step 'WiFiNetworkSetup'
[1697121350.551214][5383:5385] CHIP:CTL: Commissioning stage next step: 'WiFiNetworkSetup' -> 'FailsafeBeforeWiFiEnable'
[1697121350.551290][5383:5385] CHIP:CTL: Performing next commissioning step 'FailsafeBeforeWiFiEnable'
[1697121350.551374][5383:5385] CHIP:CTL: Arming failsafe (76 seconds)
[1697121350.551640][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121350.551746][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121350.551970][5383:5385] CHIP:EM: <<< [E:52048i S:28183 M:154142823] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121350.552092][5383:5385] CHIP:IN: (S) Sending msg 154142823 on secure session with LSID: 28183
[1697121350.552961][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121350.553137][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121350.633474][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121350.680993][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121350.681570][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121350.682022][5383:5385] CHIP:EM: >>> [E:52048i S:28183 M:200847301] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121350.682165][5383:5385] CHIP:EM: Found matching exchange: 52048i, Delegate: 0xffff940395a8
[1697121350.682267][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121350.682386][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121350.682448][5383:5385] CHIP:DMG: {
[1697121350.682507][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121350.682575][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121350.682742][5383:5385] CHIP:DMG: [
[1697121350.682844][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121350.683069][5383:5385] CHIP:DMG: {
[1697121350.683164][5383:5385] CHIP:DMG: CommandDataIB =
[1697121350.683252][5383:5385] CHIP:DMG: {
[1697121350.683348][5383:5385] CHIP:DMG: CommandPathIB =
[1697121350.683445][5383:5385] CHIP:DMG: {
[1697121350.683553][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121350.683646][5383:5385] CHIP:DMG: ClusterId = 0x30,
[1697121350.683735][5383:5385] CHIP:DMG: CommandId = 0x1,
[1697121350.683913][5383:5385] CHIP:DMG: },
[1697121350.684039][5383:5385] CHIP:DMG:
[1697121350.684118][5383:5385] CHIP:DMG: CommandFields =
[1697121350.684221][5383:5385] CHIP:DMG: {
[1697121350.684308][5383:5385] CHIP:DMG: 0x0 = 0,
[1697121350.684430][5383:5385] CHIP:DMG: 0x1 = "" (0 chars),
[1697121350.684522][5383:5385] CHIP:DMG: },
[1697121350.684623][5383:5385] CHIP:DMG: },
[1697121350.684774][5383:5385] CHIP:DMG:
[1697121350.684870][5383:5385] CHIP:DMG: },
[1697121350.684954][5383:5385] CHIP:DMG:
[1697121350.685038][5383:5385] CHIP:DMG: ],
[1697121350.685122][5383:5385] CHIP:DMG:
[1697121350.685185][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121350.685278][5383:5385] CHIP:DMG: },
[1697121350.685459][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1697121350.685550][5383:5385] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1697121350.685625][5383:5385] CHIP:CTL: Successfully finished commissioning step 'FailsafeBeforeWiFiEnable'
[1697121350.685684][5383:5385] CHIP:CTL: Commissioning stage next step: 'FailsafeBeforeWiFiEnable' -> 'WiFiNetworkEnable'
[1697121350.685766][5383:5385] CHIP:CTL: Setting wifi connection time min = 35
[1697121350.685833][5383:5385] CHIP:CTL: Performing next commissioning step 'WiFiNetworkEnable'
[1697121350.686006][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121350.686092][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121350.686335][5383:5385] CHIP:EM: <<< [E:52049i S:28183 M:154142824] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121350.686569][5383:5385] CHIP:IN: (S) Sending msg 154142824 on secure session with LSID: 28183
[1697121350.687582][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121350.687754][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121350.767387][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121353.253174][5383:5385] CHIP:BLE: BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:154: CHIP Error 0x00000032: Timeout
[1697121353.290538][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121353.291183][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121355.853608][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121358.330332][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121358.330770][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121360.893462][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121364.765340][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121364.765700][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121367.285428][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121367.285946][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121367.286262][5383:5385] CHIP:EM: >>> [E:52049i S:28183 M:200847302] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121367.286366][5383:5385] CHIP:EM: Found matching exchange: 52049i, Delegate: 0xffff940392c8
[1697121367.286524][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121367.286732][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121367.286790][5383:5385] CHIP:DMG: {
[1697121367.286839][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121367.286890][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121367.286954][5383:5385] CHIP:DMG: [
[1697121367.287003][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121367.287071][5383:5385] CHIP:DMG: {
[1697121367.287123][5383:5385] CHIP:DMG: CommandDataIB =
[1697121367.287240][5383:5385] CHIP:DMG: {
[1697121367.287303][5383:5385] CHIP:DMG: CommandPathIB =
[1697121367.287366][5383:5385] CHIP:DMG: {
[1697121367.287433][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121367.287502][5383:5385] CHIP:DMG: ClusterId = 0x31,
[1697121367.287569][5383:5385] CHIP:DMG: CommandId = 0x7,
[1697121367.287632][5383:5385] CHIP:DMG: },
[1697121367.287698][5383:5385] CHIP:DMG:
[1697121367.287756][5383:5385] CHIP:DMG: CommandFields =
[1697121367.287822][5383:5385] CHIP:DMG: {
[1697121367.287889][5383:5385] CHIP:DMG: 0x0 = 0,
[1697121367.287958][5383:5385] CHIP:DMG: 0x2 = NULL
[1697121367.288023][5383:5385] CHIP:DMG: },
[1697121367.288082][5383:5385] CHIP:DMG: },
[1697121367.288149][5383:5385] CHIP:DMG:
[1697121367.288200][5383:5385] CHIP:DMG: },
[1697121367.288261][5383:5385] CHIP:DMG:
[1697121367.288308][5383:5385] CHIP:DMG: ],
[1697121367.288370][5383:5385] CHIP:DMG:
[1697121367.288416][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121367.288463][5383:5385] CHIP:DMG: },
[1697121367.288583][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1697121367.288657][5383:5385] CHIP:CTL: Received ConnectNetwork response, networkingStatus=0
[1697121367.288715][5383:5385] CHIP:CTL: Successfully finished commissioning step 'WiFiNetworkEnable'
[1697121367.288769][5383:5385] CHIP:CTL: Commissioning stage next step: 'WiFiNetworkEnable' -> 'FindOperational'
[1697121367.288825][5383:5385] CHIP:CTL: Performing next commissioning step 'FindOperational'
[1697121367.288871][5383:5385] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001]
[1697121367.288917][5383:5385] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1697121367.288982][5383:5385] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1697121367.289041][5383:5385] CHIP:DIS: Resolving 1534A8A76FBAF98B:0000000000000001 ...
[1697121367.291344][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121367.328794][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121367.489244][5383:5385] CHIP:DIS: Checking node lookup status after 200 ms
[1697121369.847991][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121370.120751][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121370.121287][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121372.294572][5383:5385] CHIP:DL: Re-trying resolve
[1697121372.683630][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121375.160350][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121375.161034][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121377.302527][5383:5385] CHIP:DL: Re-trying resolve
[1697121377.723218][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121380.200336][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121380.200723][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121382.308091][5383:5385] CHIP:DL: Re-trying resolve
[1697121382.763456][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121385.239917][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121385.240303][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121387.315126][5383:5385] CHIP:DL: Avahi resolve failed
[1697121387.803200][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121390.280336][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121390.280726][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121392.843691][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121395.320272][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121395.320704][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121397.883505][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121400.359790][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121400.360196][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121402.922831][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121405.399263][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121405.399748][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121407.963171][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121410.440319][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121410.440696][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121412.291002][5383:5385] CHIP:DIS: Checking node lookup status after 45002 ms
[1697121412.291155][5383:5385] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: operational discovery failed: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:114: CHIP Error 0x00000032: Timeout
[1697121412.291221][5383:5385] CHIP:DIS: Retrying operational DNS-SD discovery. Attempts remaining: 2
[1697121412.291292][5383:5385] CHIP:DIS: Resolving 1534A8A76FBAF98B:0000000000000001 ...
[1697121412.294056][5383:5385] CHIP:CTL: Session establishment failed for <0000000000000001, 1>, error: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:114: CHIP Error 0x00000032: Timeout. Next retry expected to get a response to Sigma1 or fail within 60 seconds
[1697121412.294182][5383:5385] CHIP:CTL: Arming failsafe (120 seconds)
[1697121412.294353][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121412.294434][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121412.294801][5383:5385] CHIP:EM: <<< [E:52050i S:28183 M:154142825] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121412.294911][5383:5385] CHIP:IN: (S) Sending msg 154142825 on secure session with LSID: 28183
[1697121412.295798][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121412.372949][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121412.420525][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121412.421142][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121412.421517][5383:5385] CHIP:EM: >>> [E:52050i S:28183 M:200847303] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121412.421611][5383:5385] CHIP:EM: Found matching exchange: 52050i, Delegate: 0xffff940395a8
[1697121412.421705][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121412.421816][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121412.421875][5383:5385] CHIP:DMG: {
[1697121412.421930][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121412.421990][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121412.422086][5383:5385] CHIP:DMG: [
[1697121412.422154][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121412.422245][5383:5385] CHIP:DMG: {
[1697121412.422316][5383:5385] CHIP:DMG: CommandDataIB =
[1697121412.422401][5383:5385] CHIP:DMG: {
[1697121412.422479][5383:5385] CHIP:DMG: CommandPathIB =
[1697121412.422573][5383:5385] CHIP:DMG: {
[1697121412.422729][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121412.422820][5383:5385] CHIP:DMG: ClusterId = 0x30,
[1697121412.422935][5383:5385] CHIP:DMG: CommandId = 0x1,
[1697121412.423022][5383:5385] CHIP:DMG: },
[1697121412.423113][5383:5385] CHIP:DMG:
[1697121412.423191][5383:5385] CHIP:DMG: CommandFields =
[1697121412.423283][5383:5385] CHIP:DMG: {
[1697121412.423374][5383:5385] CHIP:DMG: 0x0 = 0,
[1697121412.423478][5383:5385] CHIP:DMG: 0x1 = "" (0 chars),
[1697121412.423575][5383:5385] CHIP:DMG: },
[1697121412.423655][5383:5385] CHIP:DMG: },
[1697121412.423744][5383:5385] CHIP:DMG:
[1697121412.423813][5383:5385] CHIP:DMG: },
[1697121412.423897][5383:5385] CHIP:DMG:
[1697121412.423960][5383:5385] CHIP:DMG: ],
[1697121412.424045][5383:5385] CHIP:DMG:
[1697121412.424109][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121412.424172][5383:5385] CHIP:DMG: },
[1697121412.424332][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1697121412.424425][5383:5385] CHIP:CTL: Status of extending fail-safe for CASE retry: 0
[1697121412.424531][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121412.490998][5383:5385] CHIP:DIS: Checking node lookup status after 200 ms
[1697121414.982966][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121417.297000][5383:5385] CHIP:DL: Re-trying resolve
[1697121417.460270][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121417.460915][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121420.022848][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121422.305507][5383:5385] CHIP:DL: Re-trying resolve
[1697121422.499906][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121422.500528][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121425.063263][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121427.310675][5383:5385] CHIP:DL: Re-trying resolve
[1697121427.539202][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121427.539833][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121430.103275][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121432.318390][5383:5385] CHIP:DL: Avahi resolve failed
[1697121432.579707][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121432.580469][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121435.143420][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121437.620569][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121437.620918][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121440.183173][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121442.660316][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121442.660771][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121445.223146][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121447.700238][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121447.700613][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121450.263388][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121452.740291][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121452.740671][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121455.303391][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121457.293729][5383:5385] CHIP:DIS: Checking node lookup status after 45003 ms
[1697121457.293873][5383:5385] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: operational discovery failed: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:114: CHIP Error 0x00000032: Timeout
[1697121457.293943][5383:5385] CHIP:DIS: Retrying operational DNS-SD discovery. Attempts remaining: 1
[1697121457.294013][5383:5385] CHIP:DIS: Resolving 1534A8A76FBAF98B:0000000000000001 ...
[1697121457.296780][5383:5385] CHIP:CTL: Session establishment failed for <0000000000000001, 1>, error: src/lib/address_resolve/AddressResolve_DefaultImpl.cpp:114: CHIP Error 0x00000032: Timeout. Next retry expected to get a response to Sigma1 or fail within 60 seconds
[1697121457.296899][5383:5385] CHIP:CTL: Arming failsafe (120 seconds)
[1697121457.297061][5383:5385] CHIP:DMG: ICR moving to [AddingComm]
[1697121457.297145][5383:5385] CHIP:DMG: ICR moving to [AddedComma]
[1697121457.297390][5383:5385] CHIP:EM: <<< [E:52051i S:28183 M:154142826] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697121457.297500][5383:5385] CHIP:IN: (S) Sending msg 154142826 on secure session with LSID: 28183
[1697121457.298347][5383:5385] CHIP:DMG: ICR moving to [CommandSen]
[1697121457.373546][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121457.420073][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121457.420365][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121457.420664][5383:5385] CHIP:EM: >>> [E:52051i S:28183 M:200847304] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697121457.420780][5383:5385] CHIP:EM: Found matching exchange: 52051i, Delegate: 0xffff940395a8
[1697121457.420862][5383:5385] CHIP:DMG: ICR moving to [ResponseRe]
[1697121457.420952][5383:5385] CHIP:DMG: InvokeResponseMessage =
[1697121457.420994][5383:5385] CHIP:DMG: {
[1697121457.421037][5383:5385] CHIP:DMG: suppressResponse = false,
[1697121457.421155][5383:5385] CHIP:DMG: InvokeResponseIBs =
[1697121457.421232][5383:5385] CHIP:DMG: [
[1697121457.421282][5383:5385] CHIP:DMG: InvokeResponseIB =
[1697121457.421356][5383:5385] CHIP:DMG: {
[1697121457.421408][5383:5385] CHIP:DMG: CommandDataIB =
[1697121457.421519][5383:5385] CHIP:DMG: {
[1697121457.421581][5383:5385] CHIP:DMG: CommandPathIB =
[1697121457.421653][5383:5385] CHIP:DMG: {
[1697121457.421723][5383:5385] CHIP:DMG: EndpointId = 0x0,
[1697121457.421790][5383:5385] CHIP:DMG: ClusterId = 0x30,
[1697121457.421858][5383:5385] CHIP:DMG: CommandId = 0x1,
[1697121457.421923][5383:5385] CHIP:DMG: },
[1697121457.421990][5383:5385] CHIP:DMG:
[1697121457.422049][5383:5385] CHIP:DMG: CommandFields =
[1697121457.422113][5383:5385] CHIP:DMG: {
[1697121457.422179][5383:5385] CHIP:DMG: 0x0 = 0,
[1697121457.422254][5383:5385] CHIP:DMG: 0x1 = "" (0 chars),
[1697121457.422321][5383:5385] CHIP:DMG: },
[1697121457.422381][5383:5385] CHIP:DMG: },
[1697121457.422447][5383:5385] CHIP:DMG:
[1697121457.422498][5383:5385] CHIP:DMG: },
[1697121457.422560][5383:5385] CHIP:DMG:
[1697121457.422656][5383:5385] CHIP:DMG: ],
[1697121457.422725][5383:5385] CHIP:DMG:
[1697121457.422773][5383:5385] CHIP:DMG: InteractionModelRevision = 1
[1697121457.422820][5383:5385] CHIP:DMG: },
[1697121457.422940][5383:5385] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1697121457.423008][5383:5385] CHIP:CTL: Status of extending fail-safe for CASE retry: 0
[1697121457.423087][5383:5385] CHIP:DMG: ICR moving to [AwaitingDe]
[1697121457.494504][5383:5385] CHIP:DIS: Checking node lookup status after 200 ms
[1697121459.983144][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697121462.299468][5383:5385] CHIP:DL: Re-trying resolve
[1697121462.459520][5383:5384] CHIP:DL: Indication received, conn = 0xffff94036750
[1697121462.460045][5383:5385] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697121463.077545][5383:5383] CHIP:CTL: Shutting down the commissioner
[1697121463.077665][5383:5383] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1697121463.077730][5383:5383] CHIP:DIS: Closing all BLE connections
[1697121463.077797][5383:5383] CHIP:IN: Clearing BLE pending packets.
[1697121463.078662][5383:5383] CHIP:BLE: Auto-closing end point's BLE connection.
[1697121463.078744][5383:5383] CHIP:DL: Closing BLE GATT connection (con 0xffff94036750)
[1697121463.079222][5383:5384] CHIP:DL: BluezDisconnect peer=D6:A9:C0:D9:16:F3
[1697121463.409720][5383:5383] CHIP:IN: SecureSession[0xffff8c007c60]: MarkForEviction Type:1 LSID:28183
[1697121463.409850][5383:5383] CHIP:SC: SecureSession[0xffff8c007c60]: Moving from state 'kActive' --> 'kPendingEviction'
[1697121463.410004][5383:5383] CHIP:IN: SecureSession[0xffff8c007c60]: Released - Type:1 LSID:28183
[1697121463.410105][5383:5383] CHIP:CTL: Shutting down the controller
[1697121463.410182][5383:5383] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: Cancelling incomplete address resolution as device is being deleted.
[1697121463.410323][5383:5383] CHIP:CTL: Device connection failed. Error src/app/OperationalSessionSetup.cpp:438: CHIP Error 0x00000074: The operation has been cancelled
[1697121463.410404][5383:5383] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1697121463.410473][5383:5383] CHIP:FP: Forgetting fabric 0x1
[1697121463.410697][5383:5383] CHIP:TS: Pending Last Known Good Time: 2023-07-11T08:00:09
[1697121463.411117][5383:5383] CHIP:TS: Previous Last Known Good Time: 2023-07-11T08:00:09
[1697121463.411233][5383:5383] CHIP:TS: Reverted Last Known Good Time to previous value
[1697121463.411329][5383:5383] CHIP:CTL: Shutting down the commissioner
[1697121463.411395][5383:5383] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1697121463.411468][5383:5383] CHIP:CTL: Shutting down the controller
[1697121463.411530][5383:5383] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1697121463.413725][5383:5384] CHIP:DL: Bluez disconnected
[1697121463.413864][5383:5384] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1697121463.416810][5383:5383] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1697121463.417013][5383:5383] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1697121463.417092][5383:5383] CHIP:FP: Shutting down FabricTable
[1697121463.417133][5383:5383] CHIP:TS: Pending Last Known Good Time: 2023-07-11T08:00:09
[1697121463.417294][5383:5383] CHIP:TS: Previous Last Known Good Time: 2023-07-11T08:00:09
[1697121463.417332][5383:5383] CHIP:TS: Reverted Last Known Good Time to previous value
[1697121463.417691][5383:5383] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-4eBOiC)
[1697121463.418719][5383:5383] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1697121463.418846][5383:5383] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1697121463.418875][5383:5383] CHIP:DL: Inet Layer shutdown
[1697121463.418898][5383:5383] CHIP:DL: BLE shutdown
[1697121463.419940][5383:5383] CHIP:DL: System Layer shutdown
[1697121463.420303][5383:5383] CHIP:TOO: Run command failure: examples/chip-tool/commands/common/CHIPCommand.cpp:537: CHIP Error 0x00000032: Timeout
itmaster@itmaster-desktop:~/Downloads$
