[1679500380.003093][6291:6291] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1679500380.003574][6291:6291] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1679500380.003711][6291:6291] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1679500380.003820][6291:6291] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1679500380.004105][6291:6291] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-yWcALU) [1679500380.004501][6291:6291] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1679500380.004546][6291:6291] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2) [1679500380.004969][6291:6291] CHIP:DL: Got Ethernet interface: enp4s0 [1679500380.005241][6291:6291] CHIP:DL: Found the primary Ethernet interface:enp4s0 [1679500380.005506][6291:6291] CHIP:DL: Got WiFi interface: wlx18a6f712c1ee [1679500380.005793][6291:6291] CHIP:DL: Found the primary WiFi interface:wlx18a6f712c1ee [1679500380.005840][6291:6291] CHIP:IN: UDP::Init bind&listen port=0 [1679500380.005916][6291:6291] CHIP:IN: UDP::Init bound to port=34647 [1679500380.005942][6291:6291] CHIP:IN: UDP::Init bind&listen port=0 [1679500380.006006][6291:6291] CHIP:IN: UDP::Init bound to port=49743 [1679500380.006031][6291:6291] CHIP:IN: BLEBase::Init - setting/overriding transport [1679500380.006052][6291:6291] CHIP:IN: TransportMgr initialized [1679500380.006088][6291:6291] CHIP:FP: Initializing FabricTable from persistent storage [1679500380.006213][6291:6291] CHIP:TS: Last Known Good Time: 2023-03-02T09:25:05 [1679500380.006588][6291:6291] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xEB2BB6B80AC66AB2, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1 [1679500380.008224][6291:6291] CHIP:ZCL: Using ZAP configuration... [1679500380.014097][6291:6291] CHIP:DL: Avahi client registered [1679500380.015799][6291:6291] CHIP:CTL: System State Initialized... [1679500380.015893][6291:6291] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1679500380.015939][6291:6291] CHIP:CTL: Setting attestation nonce to random value [1679500380.015968][6291:6291] CHIP:CTL: Setting CSR nonce to random value [1679500380.016581][6291:6295] CHIP:DL: CHIP task running [1679500380.016831][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 32784 [1679500380.017209][6291:6295] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1679500380.017278][6291:6295] CHIP:CTL: Setting attestation nonce to random value [1679500380.017330][6291:6295] CHIP:CTL: Setting CSR nonce to random value [1679500380.029754][6291:6295] CHIP:CTL: Generating NOC [1679500380.042871][6291:6295] CHIP:FP: Validating NOC chain [1679500380.092839][6291:6295] CHIP:FP: NOC chain validation successful [1679500380.092922][6291:6295] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669 [1679500380.092950][6291:6295] CHIP:TS: Last Known Good Time: 2023-03-02T09:25:05 [1679500380.092973][6291:6295] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1679500380.092992][6291:6295] CHIP:TS: Retaining current Last Known Good Time [1679500380.094686][6291:6295] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1679500380.096210][6291:6295] CHIP:TS: Committing Last Known Good Time to storage: 2023-03-02T09:25:05 [1679500380.097544][6291:6295] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: EB2BB6B80AC66AB2) [1679500380.104772][6291:6295] CHIP:CTL: Setting thread operational dataset from parameters [1679500380.104818][6291:6295] CHIP:CTL: Setting attempt thread scan from parameters [1679500380.104842][6291:6295] CHIP:CTL: Setting attestation nonce to random value [1679500380.104875][6291:6295] CHIP:CTL: Setting CSR nonce to random value [1679500380.104905][6291:6295] CHIP:CTL: Setting PASE-only commissioning from parameters [1679500380.104928][6291:6295] CHIP:CTL: Commission called for node ID 0x0000000000000001 [1679500380.112837][6291:6294] CHIP:DL: TRACE: Bus acquired for name C-1893 [1679500380.124283][6291:6295] CHIP:DL: PlatformBlueZInit init success [1679500380.132974][6291:6294] CHIP:BLE: BLE removing known devices. [1679500380.136080][6291:6294] CHIP:BLE: BLE initiating scan. [1679500380.706924][6291:6294] CHIP:BLE: New device scanned: C4:59:9B:B5:0D:6F [1679500380.707041][6291:6294] CHIP:BLE: Device discriminator match. Attempting to connect. [1679500380.710981][6291:6294] CHIP:BLE: Scan complete notification without an active scan. [1679500382.606003][6291:6294] CHIP:DL: ConnectDevice complete [1679500383.720410][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.720524][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.720581][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0001 [1679500383.720617][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.720662][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0001 [1679500383.720697][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.720738][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0001 [1679500383.720776][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.720827][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0001 [1679500383.720865][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.720910][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0001 [1679500383.720946][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.720987][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0001 [1679500383.721023][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.721074][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.721141][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.721190][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.721228][6291:6294] CHIP:DL: Char1 /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F/service0010 [1679500383.721277][6291:6294] CHIP:DL: New BLE connection 0x7f46b00471e0, device C4:59:9B:B5:0D:6F, path /org/bluez/hci0/dev_C4_59_9B_B5_0D_6F [1679500383.721392][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16385 [1679500383.721460][6291:6295] CHIP:DIS: Closing all BLE connections [1679500383.721511][6291:6295] CHIP:IN: BleConnectionComplete: endPoint 0x55963efd8420 [1679500383.721636][6291:6295] CHIP:IN: SecureSession[0x7f46a800e800]: Allocated Type:1 LSID:55740 [1679500383.721669][6291:6295] CHIP:SC: Assigned local session key ID 55740 [1679500383.721746][6291:6295] CHIP:EM: <<< [E:5139i M:223393267] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) [1679500383.721784][6291:6295] CHIP:IN: (U) Sending msg 223393267 to IP address 'BLE' [1679500383.721812][6291:6295] CHIP:IN: Message appended to BLE send queue [1679500383.721836][6291:6295] CHIP:SC: Sent PBKDF param request [1679500384.134829][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500384.225741][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16388 [1679500384.225817][6291:6295] CHIP:BLE: subscribe complete, ep = 0x55963efd8420 [1679500384.226277][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500384.226381][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500384.226413][6291:6295] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4 [1679500384.226438][6291:6295] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244. [1679500384.226461][6291:6295] CHIP:BLE: local and remote recv window size = 5 [1679500384.226538][6291:6295] CHIP:IN: BLE EndPoint 0x55963efd8420 Connection Complete [1679500384.313631][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500384.316852][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500384.317019][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500384.317158][6291:6295] CHIP:EM: >>> [E:5139i M:49097240] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) [1679500384.317199][6291:6295] CHIP:EM: Found matching exchange: 5139i, Delegate: 0x7f46a800ba50 [1679500384.317237][6291:6295] CHIP:SC: Received PBKDF param response [1679500384.317284][6291:6295] CHIP:SC: Peer assigned session ID 26314 [1679500384.317316][6291:6295] CHIP:SC: Found MRP parameters in the message [1679500384.388944][6291:6295] CHIP:EM: <<< [E:5139i M:223393268] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1) [1679500384.389082][6291:6295] CHIP:IN: (U) Sending msg 223393268 to IP address 'BLE' [1679500384.389544][6291:6295] CHIP:SC: Sent spake2p msg1 [1679500384.449017][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500386.341318][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500386.341829][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500386.342004][6291:6295] CHIP:EM: >>> [E:5139i M:49097241] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2) [1679500386.342047][6291:6295] CHIP:EM: Found matching exchange: 5139i, Delegate: 0x7f46a800ba50 [1679500386.342090][6291:6295] CHIP:SC: Received spake2p msg2 [1679500386.393748][6291:6295] CHIP:EM: <<< [E:5139i M:223393269] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3) [1679500386.393944][6291:6295] CHIP:IN: (U) Sending msg 223393269 to IP address 'BLE' [1679500386.394177][6291:6295] CHIP:SC: Sent spake2p msg3 [1679500386.475558][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500386.475954][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500386.476841][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500386.476973][6291:6295] CHIP:EM: >>> [E:5139i M:49097242] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) [1679500386.477003][6291:6295] CHIP:EM: Found matching exchange: 5139i, Delegate: 0x7f46a800ba50 [1679500386.477126][6291:6295] CHIP:SC: SecureSession[0x7f46a800e800]: Moving from state 'kEstablishing' --> 'kActive' [1679500386.477152][6291:6295] CHIP:IN: SecureSession[0x7f46a800e800]: Activated - Type:1 LSID:55740 [1679500386.477174][6291:6295] CHIP:IN: New secure session activated for device , LSID:55740 PSID:26314! [1679500386.477201][6291:6295] CHIP:CTL: Remote device completed SPAKE2+ handshake [1679500386.477222][6291:6295] CHIP:TOO: Pairing Success [1679500386.477242][6291:6295] CHIP:TOO: PASE establishment successful [1679500386.477266][6291:6295] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo' [1679500386.477290][6291:6295] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo' [1679500386.477311][6291:6295] CHIP:CTL: Sending request for commissioning information [1679500386.477346][6291:6295] CHIP:DMG: SendReadRequest ReadClient[0x7f46a801a500]: Sending Read Request [1679500386.477467][6291:6295] CHIP:EM: <<< [E:5140i M:155586262] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) [1679500386.477497][6291:6295] CHIP:IN: (S) Sending msg 155586262 on secure session with LSID: 55740 [1679500386.477567][6291:6295] CHIP:DMG: MoveToState ReadClient[0x7f46a801a500]: Moving to [AwaitingIn] [1679500386.563727][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500386.567642][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500386.568010][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500386.655946][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500386.656176][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500386.656444][6291:6295] CHIP:EM: >>> [E:5140i M:227813834] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData) [1679500386.656485][6291:6295] CHIP:EM: Found matching exchange: 5140i, Delegate: 0x7f46a801a510 [1679500386.656634][6291:6295] CHIP:DMG: ReportDataMessage = [1679500386.656667][6291:6295] CHIP:DMG: { [1679500386.656691][6291:6295] CHIP:DMG: AttributeReportIBs = [1679500386.656724][6291:6295] CHIP:DMG: [ [1679500386.656749][6291:6295] CHIP:DMG: AttributeReportIB = [1679500386.656778][6291:6295] CHIP:DMG: { [1679500386.656806][6291:6295] CHIP:DMG: AttributeDataIB = [1679500386.656831][6291:6295] CHIP:DMG: { [1679500386.656859][6291:6295] CHIP:DMG: DataVersion = 0xa32d96c5, [1679500386.656881][6291:6295] CHIP:DMG: AttributePathIB = [1679500386.656906][6291:6295] CHIP:DMG: { [1679500386.656935][6291:6295] CHIP:DMG: Endpoint = 0x0, [1679500386.656960][6291:6295] CHIP:DMG: Cluster = 0x31, [1679500386.656990][6291:6295] CHIP:DMG: Attribute = 0x0000_0003, [1679500386.657012][6291:6295] CHIP:DMG: } [1679500386.657043][6291:6295] CHIP:DMG: [1679500386.657074][6291:6295] CHIP:DMG: Data = 20, [1679500386.657149][6291:6295] CHIP:DMG: }, [1679500386.657176][6291:6295] CHIP:DMG: [1679500386.657202][6291:6295] CHIP:DMG: }, [1679500386.657235][6291:6295] CHIP:DMG: [1679500386.657258][6291:6295] CHIP:DMG: AttributeReportIB = [1679500386.657288][6291:6295] CHIP:DMG: { [1679500386.657310][6291:6295] CHIP:DMG: AttributeDataIB = [1679500386.657335][6291:6295] CHIP:DMG: { [1679500386.657364][6291:6295] CHIP:DMG: DataVersion = 0xeff832dd, [1679500386.657386][6291:6295] CHIP:DMG: AttributePathIB = [1679500386.657411][6291:6295] CHIP:DMG: { [1679500386.657437][6291:6295] CHIP:DMG: Endpoint = 0x0, [1679500386.657463][6291:6295] CHIP:DMG: Cluster = 0x28, [1679500386.657488][6291:6295] CHIP:DMG: Attribute = 0x0000_0004, [1679500386.657512][6291:6295] CHIP:DMG: } [1679500386.657539][6291:6295] CHIP:DMG: [1679500386.657566][6291:6295] CHIP:DMG: Data = 32768, [1679500386.657589][6291:6295] CHIP:DMG: }, [1679500386.657619][6291:6295] CHIP:DMG: [1679500386.657642][6291:6295] CHIP:DMG: }, [1679500386.657676][6291:6295] CHIP:DMG: [1679500386.657699][6291:6295] CHIP:DMG: AttributeReportIB = [1679500386.657730][6291:6295] CHIP:DMG: { [1679500386.657753][6291:6295] CHIP:DMG: AttributeDataIB = [1679500386.657778][6291:6295] CHIP:DMG: { [1679500386.657804][6291:6295] CHIP:DMG: DataVersion = 0xeff832dd, [1679500386.657829][6291:6295] CHIP:DMG: AttributePathIB = [1679500386.657853][6291:6295] CHIP:DMG: { [1679500386.657881][6291:6295] CHIP:DMG: Endpoint = 0x0, [1679500386.657906][6291:6295] CHIP:DMG: Cluster = 0x28, [1679500386.657931][6291:6295] CHIP:DMG: Attribute = 0x0000_0002, [1679500386.657955][6291:6295] CHIP:DMG: } [1679500386.657981][6291:6295] CHIP:DMG: [1679500386.658009][6291:6295] CHIP:DMG: Data = 65521, [1679500386.658031][6291:6295] CHIP:DMG: }, [1679500386.658059][6291:6295] CHIP:DMG: [1679500386.658081][6291:6295] CHIP:DMG: }, [1679500386.658114][6291:6295] CHIP:DMG: [1679500386.658136][6291:6295] CHIP:DMG: AttributeReportIB = [1679500386.658213][6291:6295] CHIP:DMG: { [1679500386.658236][6291:6295] CHIP:DMG: AttributeDataIB = [1679500386.658261][6291:6295] CHIP:DMG: { [1679500386.658287][6291:6295] CHIP:DMG: DataVersion = 0xd7be04d1, [1679500386.658311][6291:6295] CHIP:DMG: AttributePathIB = [1679500386.658335][6291:6295] CHIP:DMG: { [1679500386.658361][6291:6295] CHIP:DMG: Endpoint = 0x0, [1679500386.658387][6291:6295] CHIP:DMG: Cluster = 0x30, [1679500386.658411][6291:6295] CHIP:DMG: Attribute = 0x0000_0003, [1679500386.658437][6291:6295] CHIP:DMG: } [1679500386.658462][6291:6295] CHIP:DMG: [1679500386.658490][6291:6295] CHIP:DMG: Data = 0, [1679500386.658514][6291:6295] CHIP:DMG: }, [1679500386.658542][6291:6295] CHIP:DMG: [1679500386.658565][6291:6295] CHIP:DMG: }, [1679500386.658598][6291:6295] CHIP:DMG: [1679500386.658620][6291:6295] CHIP:DMG: AttributeReportIB = [1679500386.658650][6291:6295] CHIP:DMG: { [1679500386.658674][6291:6295] CHIP:DMG: AttributeDataIB = [1679500386.658757][6291:6295] CHIP:DMG: { [1679500386.658784][6291:6295] CHIP:DMG: DataVersion = 0xd7be04d1, [1679500386.658810][6291:6295] CHIP:DMG: AttributePathIB = [1679500386.658834][6291:6295] CHIP:DMG: { [1679500386.658860][6291:6295] CHIP:DMG: Endpoint = 0x0, [1679500386.658885][6291:6295] CHIP:DMG: Cluster = 0x30, [1679500386.658910][6291:6295] CHIP:DMG: Attribute = 0x0000_0002, [1679500386.658933][6291:6295] CHIP:DMG: } [1679500386.658962][6291:6295] CHIP:DMG: [1679500386.658988][6291:6295] CHIP:DMG: Data = 0, [1679500386.659014][6291:6295] CHIP:DMG: }, [1679500386.659041][6291:6295] CHIP:DMG: [1679500386.659065][6291:6295] CHIP:DMG: }, [1679500386.659101][6291:6295] CHIP:DMG: [1679500386.659123][6291:6295] CHIP:DMG: AttributeReportIB = [1679500386.659154][6291:6295] CHIP:DMG: { [1679500386.659177][6291:6295] CHIP:DMG: AttributeDataIB = [1679500386.659201][6291:6295] CHIP:DMG: { [1679500386.659229][6291:6295] CHIP:DMG: DataVersion = 0xd7be04d1, [1679500386.659251][6291:6295] CHIP:DMG: AttributePathIB = [1679500386.659276][6291:6295] CHIP:DMG: { [1679500386.659301][6291:6295] CHIP:DMG: Endpoint = 0x0, [1679500386.659326][6291:6295] CHIP:DMG: Cluster = 0x30, [1679500386.659351][6291:6295] CHIP:DMG: Attribute = 0x0000_0001, [1679500386.659373][6291:6295] CHIP:DMG: } [1679500386.659400][6291:6295] CHIP:DMG: [1679500386.659442][6291:6295] CHIP:DMG: Data = [1679500386.659466][6291:6295] CHIP:DMG: { [1679500386.659492][6291:6295] CHIP:DMG: 0x0 = 60, [1679500386.659518][6291:6295] CHIP:DMG: 0x1 = 900, [1679500386.659542][6291:6295] CHIP:DMG: }, [1679500386.659564][6291:6295] CHIP:DMG: }, [1679500386.659592][6291:6295] CHIP:DMG: [1679500386.659615][6291:6295] CHIP:DMG: }, [1679500386.659649][6291:6295] CHIP:DMG: [1679500386.659671][6291:6295] CHIP:DMG: AttributeReportIB = [1679500386.659701][6291:6295] CHIP:DMG: { [1679500386.659723][6291:6295] CHIP:DMG: AttributeDataIB = [1679500386.659748][6291:6295] CHIP:DMG: { [1679500386.659773][6291:6295] CHIP:DMG: DataVersion = 0xd7be04d1, [1679500386.659796][6291:6295] CHIP:DMG: AttributePathIB = [1679500386.659820][6291:6295] CHIP:DMG: { [1679500386.659845][6291:6295] CHIP:DMG: Endpoint = 0x0, [1679500386.659871][6291:6295] CHIP:DMG: Cluster = 0x30, [1679500386.659895][6291:6295] CHIP:DMG: Attribute = 0x0000_0000, [1679500386.659921][6291:6295] CHIP:DMG: } [1679500386.659946][6291:6295] CHIP:DMG: [1679500386.659974][6291:6295] CHIP:DMG: Data = 0, [1679500386.659996][6291:6295] CHIP:DMG: }, [1679500386.660024][6291:6295] CHIP:DMG: [1679500386.660047][6291:6295] CHIP:DMG: }, [1679500386.660080][6291:6295] CHIP:DMG: [1679500386.660102][6291:6295] CHIP:DMG: AttributeReportIB = [1679500386.660131][6291:6295] CHIP:DMG: { [1679500386.660154][6291:6295] CHIP:DMG: AttributeDataIB = [1679500386.660179][6291:6295] CHIP:DMG: { [1679500386.660204][6291:6295] CHIP:DMG: DataVersion = 0xa32d96c5, [1679500386.660226][6291:6295] CHIP:DMG: AttributePathIB = [1679500386.660251][6291:6295] CHIP:DMG: { [1679500386.660278][6291:6295] CHIP:DMG: Endpoint = 0x0, [1679500386.660304][6291:6295] CHIP:DMG: Cluster = 0x31, [1679500386.660334][6291:6295] CHIP:DMG: Attribute = 0x0000_FFFC, [1679500386.660356][6291:6295] CHIP:DMG: } [1679500386.660382][6291:6295] CHIP:DMG: [1679500386.660408][6291:6295] CHIP:DMG: Data = 2, [1679500386.660431][6291:6295] CHIP:DMG: }, [1679500386.660459][6291:6295] CHIP:DMG: [1679500386.660482][6291:6295] CHIP:DMG: }, [1679500386.660510][6291:6295] CHIP:DMG: [1679500386.660533][6291:6295] CHIP:DMG: ], [1679500386.660591][6291:6295] CHIP:DMG: [1679500386.660619][6291:6295] CHIP:DMG: SuppressResponse = true, [1679500386.660644][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500386.660666][6291:6295] CHIP:DMG: } [1679500386.661516][6291:6295] CHIP:CTL: ----- NetworkCommissioning Features: has Thread. endpointid = 0 [1679500386.661723][6291:6295] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo' [1679500386.661758][6291:6295] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe' [1679500386.661795][6291:6295] CHIP:CTL: Performing next commissioning step 'ArmFailSafe' [1679500386.661820][6291:6295] CHIP:CTL: Arming failsafe (60 seconds) [1679500386.661903][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500386.661932][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500386.662033][6291:6295] CHIP:EM: <<< [E:5141i M:155586263] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500386.662074][6291:6295] CHIP:IN: (S) Sending msg 155586263 on secure session with LSID: 55740 [1679500386.662171][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500386.788834][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500386.791151][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500386.791375][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500386.791580][6291:6295] CHIP:EM: >>> [E:5141i M:227813835] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500386.791631][6291:6295] CHIP:EM: Found matching exchange: 5141i, Delegate: 0x7f46b0048f78 [1679500386.791666][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500386.791709][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500386.791734][6291:6295] CHIP:DMG: { [1679500386.791761][6291:6295] CHIP:DMG: suppressResponse = false, [1679500386.791783][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500386.791817][6291:6295] CHIP:DMG: [ [1679500386.791839][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500386.791870][6291:6295] CHIP:DMG: { [1679500386.791904][6291:6295] CHIP:DMG: CommandDataIB = [1679500386.791930][6291:6295] CHIP:DMG: { [1679500386.791953][6291:6295] CHIP:DMG: CommandPathIB = [1679500386.791979][6291:6295] CHIP:DMG: { [1679500386.792005][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500386.792029][6291:6295] CHIP:DMG: ClusterId = 0x30, [1679500386.792054][6291:6295] CHIP:DMG: CommandId = 0x1, [1679500386.792075][6291:6295] CHIP:DMG: }, [1679500386.792101][6291:6295] CHIP:DMG: [1679500386.792125][6291:6295] CHIP:DMG: CommandFields = [1679500386.792149][6291:6295] CHIP:DMG: { [1679500386.792178][6291:6295] CHIP:DMG: 0x0 = 0, [1679500386.792204][6291:6295] CHIP:DMG: 0x1 = "" (0 chars), [1679500386.792229][6291:6295] CHIP:DMG: }, [1679500386.792250][6291:6295] CHIP:DMG: }, [1679500386.792279][6291:6295] CHIP:DMG: [1679500386.792302][6291:6295] CHIP:DMG: }, [1679500386.792332][6291:6295] CHIP:DMG: [1679500386.792355][6291:6295] CHIP:DMG: ], [1679500386.792384][6291:6295] CHIP:DMG: [1679500386.792408][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500386.792430][6291:6295] CHIP:DMG: }, [1679500386.792487][6291:6295] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001 [1679500386.792522][6291:6295] CHIP:CTL: Received ArmFailSafe response errorCode=0 [1679500386.792551][6291:6295] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe' [1679500386.792575][6291:6295] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory' [1679500386.792602][6291:6295] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory' [1679500386.792624][6291:6295] CHIP:CTL: Setting Regulatory Config [1679500386.792646][6291:6295] CHIP:CTL: Device does not support configurable regulatory location [1679500386.792706][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500386.792755][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500386.792848][6291:6295] CHIP:EM: <<< [E:5142i M:155586264] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500386.792885][6291:6295] CHIP:IN: (S) Sending msg 155586264 on secure session with LSID: 55740 [1679500386.792975][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500386.793068][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500386.878876][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500386.881542][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500386.881829][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500386.881981][6291:6295] CHIP:EM: >>> [E:5142i M:227813836] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500386.882022][6291:6295] CHIP:EM: Found matching exchange: 5142i, Delegate: 0x7f46a8008d78 [1679500386.882085][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500386.882135][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500386.882162][6291:6295] CHIP:DMG: { [1679500386.882187][6291:6295] CHIP:DMG: suppressResponse = false, [1679500386.882209][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500386.882241][6291:6295] CHIP:DMG: [ [1679500386.882263][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500386.882293][6291:6295] CHIP:DMG: { [1679500386.882316][6291:6295] CHIP:DMG: CommandDataIB = [1679500386.882344][6291:6295] CHIP:DMG: { [1679500386.882366][6291:6295] CHIP:DMG: CommandPathIB = [1679500386.882391][6291:6295] CHIP:DMG: { [1679500386.882416][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500386.882441][6291:6295] CHIP:DMG: ClusterId = 0x30, [1679500386.882465][6291:6295] CHIP:DMG: CommandId = 0x3, [1679500386.882487][6291:6295] CHIP:DMG: }, [1679500386.882513][6291:6295] CHIP:DMG: [1679500386.882537][6291:6295] CHIP:DMG: CommandFields = [1679500386.882562][6291:6295] CHIP:DMG: { [1679500386.882588][6291:6295] CHIP:DMG: 0x0 = 0, [1679500386.882617][6291:6295] CHIP:DMG: 0x1 = "" (0 chars), [1679500386.882641][6291:6295] CHIP:DMG: }, [1679500386.882664][6291:6295] CHIP:DMG: }, [1679500386.882692][6291:6295] CHIP:DMG: [1679500386.882717][6291:6295] CHIP:DMG: }, [1679500386.882745][6291:6295] CHIP:DMG: [1679500386.882769][6291:6295] CHIP:DMG: ], [1679500386.882798][6291:6295] CHIP:DMG: [1679500386.882823][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500386.882846][6291:6295] CHIP:DMG: }, [1679500386.882903][6291:6295] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003 [1679500386.882966][6291:6295] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0 [1679500386.882998][6291:6295] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory' [1679500386.883021][6291:6295] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest' [1679500386.883049][6291:6295] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest' [1679500386.883071][6291:6295] CHIP:CTL: Sending request for PAI certificate [1679500386.883091][6291:6295] CHIP:CTL: Sending Certificate Chain request to 0x7f46a800ba00 device [1679500386.883153][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500386.883184][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500386.883281][6291:6295] CHIP:EM: <<< [E:5143i M:155586265] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500386.883318][6291:6295] CHIP:IN: (S) Sending msg 155586265 on secure session with LSID: 55740 [1679500386.883783][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500386.883878][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500386.968754][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500386.973019][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500386.973295][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500387.062624][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500387.062931][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500387.150883][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500387.151170][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500387.151373][6291:6295] CHIP:EM: >>> [E:5143i M:227813837] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500387.151469][6291:6295] CHIP:EM: Found matching exchange: 5143i, Delegate: 0x7f46b0048f78 [1679500387.151509][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500387.151555][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500387.151580][6291:6295] CHIP:DMG: { [1679500387.151605][6291:6295] CHIP:DMG: suppressResponse = false, [1679500387.151627][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500387.151657][6291:6295] CHIP:DMG: [ [1679500387.151681][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500387.151711][6291:6295] CHIP:DMG: { [1679500387.151735][6291:6295] CHIP:DMG: CommandDataIB = [1679500387.151759][6291:6295] CHIP:DMG: { [1679500387.151782][6291:6295] CHIP:DMG: CommandPathIB = [1679500387.151807][6291:6295] CHIP:DMG: { [1679500387.151832][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500387.151857][6291:6295] CHIP:DMG: ClusterId = 0x3e, [1679500387.151883][6291:6295] CHIP:DMG: CommandId = 0x3, [1679500387.151905][6291:6295] CHIP:DMG: }, [1679500387.151931][6291:6295] CHIP:DMG: [1679500387.151958][6291:6295] CHIP:DMG: CommandFields = [1679500387.151982][6291:6295] CHIP:DMG: { [1679500387.152011][6291:6295] CHIP:DMG: 0x0 = [ [1679500387.152123][6291:6295] 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 [1679500387.152151][6291:6295] CHIP:DMG: ] (463 bytes) [1679500387.152177][6291:6295] CHIP:DMG: }, [1679500387.152200][6291:6295] CHIP:DMG: }, [1679500387.152228][6291:6295] CHIP:DMG: [1679500387.152252][6291:6295] CHIP:DMG: }, [1679500387.152280][6291:6295] CHIP:DMG: [1679500387.152302][6291:6295] CHIP:DMG: ], [1679500387.152333][6291:6295] CHIP:DMG: [1679500387.152358][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500387.152379][6291:6295] CHIP:DMG: }, [1679500387.152439][6291:6295] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1679500387.152474][6291:6295] CHIP:CTL: Received certificate chain from the device [1679500387.152504][6291:6295] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest' [1679500387.152533][6291:6295] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest' [1679500387.152562][6291:6295] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest' [1679500387.152614][6291:6295] CHIP:CTL: Sending request for DAC certificate [1679500387.152671][6291:6295] CHIP:CTL: Sending Certificate Chain request to 0x7f46a800ba00 device [1679500387.152734][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500387.152762][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500387.152875][6291:6295] CHIP:EM: <<< [E:5144i M:155586266] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500387.152914][6291:6295] CHIP:IN: (S) Sending msg 155586266 on secure session with LSID: 55740 [1679500387.153523][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500387.153637][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500387.238821][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500387.242796][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500387.243036][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500387.332495][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500387.332794][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500387.420598][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500387.420823][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500387.420993][6291:6295] CHIP:EM: >>> [E:5144i M:227813838] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500387.421026][6291:6295] CHIP:EM: Found matching exchange: 5144i, Delegate: 0x7f46b0049238 [1679500387.421062][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500387.421127][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500387.421155][6291:6295] CHIP:DMG: { [1679500387.421180][6291:6295] CHIP:DMG: suppressResponse = false, [1679500387.421202][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500387.421232][6291:6295] CHIP:DMG: [ [1679500387.421254][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500387.421283][6291:6295] CHIP:DMG: { [1679500387.421306][6291:6295] CHIP:DMG: CommandDataIB = [1679500387.421330][6291:6295] CHIP:DMG: { [1679500387.421353][6291:6295] CHIP:DMG: CommandPathIB = [1679500387.421377][6291:6295] CHIP:DMG: { [1679500387.421402][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500387.421426][6291:6295] CHIP:DMG: ClusterId = 0x3e, [1679500387.421450][6291:6295] CHIP:DMG: CommandId = 0x3, [1679500387.421473][6291:6295] CHIP:DMG: }, [1679500387.421499][6291:6295] CHIP:DMG: [1679500387.421523][6291:6295] CHIP:DMG: CommandFields = [1679500387.421547][6291:6295] CHIP:DMG: { [1679500387.421572][6291:6295] CHIP:DMG: 0x0 = [ [1679500387.421686][6291:6295] CHIP:DMG: 0x30, 0x82, 0x01, 0xe9, 0x30, 0x82, 0x01, 0x8e, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x23, 0x8a, 0x64, 0x7b, 0xbc, 0x4c, 0x30, 0xdd, 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, 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, 0x30, 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, 0x62, 0xdb, 0x16, 0xba, 0xde, 0xa3, 0x26, 0xa6, 0xdb, 0x84, 0x81, 0x4a, 0x06, 0x3f, 0xc6, 0xc7, 0xe9, 0xe2, 0xb1, 0x01, 0xb7, 0x21, 0x64, 0x8e, 0xba, 0x4e, 0x5a, 0xc8, 0x40, 0xf5, 0xda, 0x30, 0x1e, 0xe6, 0x18, 0x12, 0x4e, 0xb4, 0x18, 0x [1679500387.421752][6291:6295] CHIP:DMG: ] (493 bytes) [1679500387.421778][6291:6295] CHIP:DMG: }, [1679500387.421800][6291:6295] CHIP:DMG: }, [1679500387.421827][6291:6295] CHIP:DMG: [1679500387.421849][6291:6295] CHIP:DMG: }, [1679500387.421878][6291:6295] CHIP:DMG: [1679500387.421900][6291:6295] CHIP:DMG: ], [1679500387.421930][6291:6295] CHIP:DMG: [1679500387.421954][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500387.421975][6291:6295] CHIP:DMG: }, [1679500387.422034][6291:6295] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003 [1679500387.422066][6291:6295] CHIP:CTL: Received certificate chain from the device [1679500387.422095][6291:6295] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest' [1679500387.422122][6291:6295] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest' [1679500387.422150][6291:6295] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest' [1679500387.422172][6291:6295] CHIP:CTL: Sending Attestation Request to the device. [1679500387.422193][6291:6295] CHIP:CTL: Sending Attestation request to 0x7f46a800ba00 device [1679500387.422249][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500387.422277][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500387.422369][6291:6295] CHIP:EM: <<< [E:5145i M:155586267] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500387.422405][6291:6295] CHIP:IN: (S) Sending msg 155586267 on secure session with LSID: 55740 [1679500387.422856][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500387.422915][6291:6295] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information [1679500387.422961][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500387.508892][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500387.557268][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500387.557498][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500387.647583][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500387.647843][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500387.737403][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500387.737675][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500387.737884][6291:6295] CHIP:EM: >>> [E:5145i M:227813839] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500387.737923][6291:6295] CHIP:EM: Found matching exchange: 5145i, Delegate: 0x7f46b0049628 [1679500387.737960][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500387.738006][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500387.738031][6291:6295] CHIP:DMG: { [1679500387.738056][6291:6295] CHIP:DMG: suppressResponse = false, [1679500387.738080][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500387.738111][6291:6295] CHIP:DMG: [ [1679500387.738135][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500387.738165][6291:6295] CHIP:DMG: { [1679500387.738188][6291:6295] CHIP:DMG: CommandDataIB = [1679500387.738212][6291:6295] CHIP:DMG: { [1679500387.738235][6291:6295] CHIP:DMG: CommandPathIB = [1679500387.738261][6291:6295] CHIP:DMG: { [1679500387.738287][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500387.738313][6291:6295] CHIP:DMG: ClusterId = 0x3e, [1679500387.738336][6291:6295] CHIP:DMG: CommandId = 0x1, [1679500387.738358][6291:6295] CHIP:DMG: }, [1679500387.738384][6291:6295] CHIP:DMG: [1679500387.738408][6291:6295] CHIP:DMG: CommandFields = [1679500387.738431][6291:6295] CHIP:DMG: { [1679500387.738458][6291:6295] CHIP:DMG: 0x0 = [ [1679500387.738576][6291:6295] 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 [1679500387.738642][6291:6295] CHIP:DMG: ] (583 bytes) [1679500387.738668][6291:6295] CHIP:DMG: 0x1 = [ [1679500387.738709][6291:6295] CHIP:DMG: 0xa7, 0x1d, 0x36, 0xdd, 0x3f, 0x30, 0x83, 0x12, 0x17, 0xa1, 0x6f, 0xe2, 0x41, 0x98, 0x6a, 0x0a, 0xe8, 0x16, 0xa1, 0x38, 0xe7, 0xfb, 0xb1, 0xab, 0x17, 0x45, 0xb6, 0x16, 0x25, 0xab, 0xbc, 0xe8, 0x8b, 0xb3, 0xec, 0x0b, 0x1d, 0x3b, 0xdd, 0xc6, 0xf9, 0x5b, 0xdc, 0x73, 0x7b, 0x65, 0xf1, 0x5e, 0xf2, 0xa5, 0x92, 0x89, 0x4c, 0xe8, 0x49, 0x6c, 0xe2, 0xc1, 0xce, 0x7f, 0xde, 0x2c, 0x6b, 0x5e, [1679500387.738734][6291:6295] CHIP:DMG: ] (64 bytes) [1679500387.738758][6291:6295] CHIP:DMG: }, [1679500387.738780][6291:6295] CHIP:DMG: }, [1679500387.738808][6291:6295] CHIP:DMG: [1679500387.738830][6291:6295] CHIP:DMG: }, [1679500387.738858][6291:6295] CHIP:DMG: [1679500387.738881][6291:6295] CHIP:DMG: ], [1679500387.738912][6291:6295] CHIP:DMG: [1679500387.738936][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500387.738958][6291:6295] CHIP:DMG: }, [1679500387.739018][6291:6295] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001 [1679500387.739051][6291:6295] CHIP:CTL: Received Attestation Information from the device [1679500387.739088][6291:6295] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest' [1679500387.739116][6291:6295] CHIP:CTL: AutoCommissioner setting attestationElements buffer size 583/583 [1679500387.739160][6291:6295] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification' [1679500387.739196][6291:6295] CHIP:CTL: Performing next commissioning step 'AttestationVerification' [1679500387.739217][6291:6295] CHIP:CTL: Verifying attestation [1679500387.766323][6291:6295] CHIP:CR: mbedTLS error: ERROR - Generic error [1679500387.850552][6291:6295] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device. [1679500387.850643][6291:6295] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification' [1679500387.850669][6291:6295] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest' [1679500387.850699][6291:6295] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest' [1679500387.850724][6291:6295] CHIP:CTL: Sending CSR request to 0x7f46a800ba00 device [1679500387.850803][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500387.850873][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500387.850984][6291:6295] CHIP:EM: <<< [E:5146i M:155586268] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500387.851020][6291:6295] CHIP:IN: (S) Sending msg 155586268 on secure session with LSID: 55740 [1679500387.851872][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500387.851942][6291:6295] CHIP:CTL: Sent CSR request, waiting for the CSR [1679500387.852001][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500387.852044][6291:6295] CHIP:DL: Long dispatch time: 114 ms, for event type 16389 [1679500387.914277][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500388.142368][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500388.142598][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500388.231801][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500388.232119][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500388.232296][6291:6295] CHIP:EM: >>> [E:5146i M:227813840] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500388.232330][6291:6295] CHIP:EM: Found matching exchange: 5146i, Delegate: 0x7f46b00498b8 [1679500388.232370][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500388.232422][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500388.232447][6291:6295] CHIP:DMG: { [1679500388.232472][6291:6295] CHIP:DMG: suppressResponse = false, [1679500388.232495][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500388.232526][6291:6295] CHIP:DMG: [ [1679500388.232549][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500388.232578][6291:6295] CHIP:DMG: { [1679500388.232601][6291:6295] CHIP:DMG: CommandDataIB = [1679500388.232627][6291:6295] CHIP:DMG: { [1679500388.232650][6291:6295] CHIP:DMG: CommandPathIB = [1679500388.232677][6291:6295] CHIP:DMG: { [1679500388.232703][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500388.232730][6291:6295] CHIP:DMG: ClusterId = 0x3e, [1679500388.232754][6291:6295] CHIP:DMG: CommandId = 0x5, [1679500388.232776][6291:6295] CHIP:DMG: }, [1679500388.232802][6291:6295] CHIP:DMG: [1679500388.232827][6291:6295] CHIP:DMG: CommandFields = [1679500388.232853][6291:6295] CHIP:DMG: { [1679500388.232881][6291:6295] CHIP:DMG: 0x0 = [ [1679500388.232981][6291:6295] CHIP:DMG: 0x15, 0x30, 0x01, 0xcd, 0x30, 0x81, 0xca, 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, 0x07, 0xc7, 0x62, 0xdf, 0xe8, 0xff, 0x9f, 0x14, 0x31, 0x92, 0x06, 0x09, 0x38, 0xb9, 0xe1, 0x40, 0x4d, 0x6a, 0x22, 0x2d, 0xdc, 0x39, 0x86, 0xb9, 0xf3, 0x47, 0x68, 0xe3, 0xf9, 0x35, 0x9e, 0x66, 0x82, 0xec, 0x00, 0x45, 0xfa, 0x30, 0x3e, 0x78, 0x13, 0xa3, 0xed, 0x68, 0x12, 0xf8, 0x32, 0x65, 0x24, 0x72, 0xd6, 0xbf, 0xd4, 0xa8, 0x82, 0x1c, 0xdd, 0x8c, 0xf9, 0x9b, 0x87, 0x53, 0xbd, 0x83, 0xa0, 0x00, 0x30, 0x0c, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x05, 0x00, 0x03, 0x48, 0x00, 0x30, 0x45, 0x02, 0x21, 0x00, 0xcd, 0xc7, 0x04, 0x49, 0xf3, 0xb4, 0x87, 0x63, 0x60, 0x7c, 0xc1, 0x65, 0x34, 0xbb, 0x53, 0x97, 0x53, 0x0e, 0x5f, 0x23, 0x1c, 0x08, 0x88, 0x07, 0x07, 0x91, 0x75, 0xbf, 0x49, 0x2b, 0xed, 0x3e, 0x02, 0x20, 0x73, 0x1a, 0xcd, 0x79, 0x22, 0x76, 0x2e, 0xb5, 0xf0, 0xd0, 0xfc, 0x95, 0xf0, 0xac, 0x10, 0xdb, 0xf0, 0x8d, 0x2f, 0x40, 0x06, 0x6c, 0xe3, 0x9a, 0x00, 0x11, 0x16, 0x27, 0xf1, 0xfd, 0xd4, 0x10, 0x30, 0x02, 0x20, 0x18, 0x8b, 0xbf, 0x96, 0x56, 0xb6, 0xae, 0x00, 0x31, 0xb9, 0x0e, 0x83, 0xa6, 0xe6, 0x5f, 0x64, 0x85, 0x4a, 0x7d, 0x3f, 0x63, 0x4a, 0xc8, 0x91, 0xa3, 0x9c, 0x43, 0x7b, 0xeb, 0xf5, 0xbe, 0x79, 0x18, [1679500388.233115][6291:6295] CHIP:DMG: ] (245 bytes) [1679500388.233149][6291:6295] CHIP:DMG: 0x1 = [ [1679500388.233192][6291:6295] CHIP:DMG: 0xfb, 0x0c, 0xc3, 0x2e, 0x53, 0x4a, 0xbf, 0x1a, 0x91, 0x59, 0xa7, 0x76, 0x2a, 0xcc, 0x06, 0x55, 0x13, 0x31, 0x46, 0x3a, 0xb3, 0xfb, 0x13, 0x2a, 0x4a, 0x09, 0x3f, 0x5e, 0x23, 0x5d, 0x28, 0x9e, 0xc0, 0x2d, 0xe5, 0xa4, 0xc6, 0xb7, 0x09, 0x10, 0xce, 0x37, 0xfb, 0x1c, 0xb3, 0xc9, 0x20, 0x43, 0x24, 0xcc, 0x47, 0xb9, 0x37, 0x17, 0x44, 0x26, 0xa1, 0x22, 0xf8, 0x29, 0x41, 0x0b, 0xbb, 0xc3, [1679500388.233252][6291:6295] CHIP:DMG: ] (64 bytes) [1679500388.233278][6291:6295] CHIP:DMG: }, [1679500388.233300][6291:6295] CHIP:DMG: }, [1679500388.233330][6291:6295] CHIP:DMG: [1679500388.233352][6291:6295] CHIP:DMG: }, [1679500388.233380][6291:6295] CHIP:DMG: [1679500388.233402][6291:6295] CHIP:DMG: ], [1679500388.233432][6291:6295] CHIP:DMG: [1679500388.233459][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500388.233481][6291:6295] CHIP:DMG: }, [1679500388.233542][6291:6295] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005 [1679500388.233576][6291:6295] CHIP:CTL: Received certificate signing request from the device [1679500388.233606][6291:6295] CHIP:CTL: Successfully finished commissioning step 'SendOpCertSigningRequest' [1679500388.233630][6291:6295] CHIP:CTL: Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR' [1679500388.233658][6291:6295] CHIP:CTL: Performing next commissioning step 'ValidateCSR' [1679500388.260062][6291:6295] CHIP:CTL: Successfully finished commissioning step 'ValidateCSR' [1679500388.260129][6291:6295] CHIP:CTL: Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain' [1679500388.260160][6291:6295] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain' [1679500388.260185][6291:6295] CHIP:CTL: Getting certificate chain for the device from the issuer [1679500388.260258][6291:6295] CHIP:CTL: Verifying Certificate Signing Request [1679500388.287243][6291:6295] CHIP:CTL: Generating NOC [1679500388.300322][6291:6295] CHIP:CTL: Providing certificate chain to the commissioner [1679500388.300403][6291:6295] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status ../../src/controller/ExampleOperationalCredentialsIssuer.cpp:396: Success [1679500388.300435][6291:6295] CHIP:CTL: Successfully finished commissioning step 'GenerateNOCChain' [1679500388.300578][6291:6295] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert' [1679500388.300609][6291:6295] CHIP:CTL: Sending root certificate to the device [1679500388.300684][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500388.300716][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500388.300868][6291:6295] CHIP:EM: <<< [E:5147i M:155586269] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500388.300912][6291:6295] CHIP:IN: (S) Sending msg 155586269 on secure session with LSID: 55740 [1679500388.302133][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500388.302247][6291:6295] CHIP:CTL: Sent root certificate to the device [1679500388.302579][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500388.409703][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500388.498926][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500388.591464][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500388.591743][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500388.591906][6291:6295] CHIP:EM: >>> [E:5147i M:227813841] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500388.591948][6291:6295] CHIP:EM: Found matching exchange: 5147i, Delegate: 0x7f46b0049628 [1679500388.591985][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500388.592033][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500388.592058][6291:6295] CHIP:DMG: { [1679500388.592083][6291:6295] CHIP:DMG: suppressResponse = false, [1679500388.592108][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500388.592139][6291:6295] CHIP:DMG: [ [1679500388.592164][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500388.592193][6291:6295] CHIP:DMG: { [1679500388.592272][6291:6295] CHIP:DMG: CommandStatusIB = [1679500388.592302][6291:6295] CHIP:DMG: { [1679500388.592325][6291:6295] CHIP:DMG: CommandPathIB = [1679500388.592351][6291:6295] CHIP:DMG: { [1679500388.592380][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500388.592404][6291:6295] CHIP:DMG: ClusterId = 0x3e, [1679500388.592433][6291:6295] CHIP:DMG: CommandId = 0xb, [1679500388.592457][6291:6295] CHIP:DMG: }, [1679500388.592489][6291:6295] CHIP:DMG: [1679500388.592512][6291:6295] CHIP:DMG: StatusIB = [1679500388.592539][6291:6295] CHIP:DMG: { [1679500388.592564][6291:6295] CHIP:DMG: status = 0x00 (SUCCESS), [1679500388.592589][6291:6295] CHIP:DMG: }, [1679500388.592615][6291:6295] CHIP:DMG: [1679500388.592637][6291:6295] CHIP:DMG: }, [1679500388.592664][6291:6295] CHIP:DMG: [1679500388.592686][6291:6295] CHIP:DMG: }, [1679500388.592734][6291:6295] CHIP:DMG: [1679500388.592757][6291:6295] CHIP:DMG: ], [1679500388.592787][6291:6295] CHIP:DMG: [1679500388.592812][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500388.592834][6291:6295] CHIP:DMG: }, [1679500388.592892][6291:6295] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0 [1679500388.592921][6291:6295] CHIP:CTL: Device confirmed that it has received the root certificate [1679500388.592958][6291:6295] CHIP:CTL: Successfully finished commissioning step 'SendTrustedRootCert' [1679500388.592981][6291:6295] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC' [1679500388.593012][6291:6295] CHIP:CTL: Performing next commissioning step 'SendNOC' [1679500388.593136][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500388.593184][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500388.593374][6291:6295] CHIP:EM: <<< [E:5148i M:155586270] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500388.593416][6291:6295] CHIP:IN: (S) Sending msg 155586270 on secure session with LSID: 55740 [1679500388.594044][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500388.594124][6291:6295] CHIP:CTL: Sent operational certificate to the device [1679500388.594179][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500388.724431][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500388.859620][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500388.886440][6291:6294] CHIP:DL: Got IP address on interface: wlx18a6f712c1ee IP: 192.168.1.64 [1679500388.886682][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 32770 [1679500388.949262][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500389.076362][6291:6294] CHIP:DL: Got IP address on interface: wlx18a6f712c1ee IP: 192.168.100.170 [1679500389.076540][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 32770 [1679500389.176460][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500389.176713][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500389.176886][6291:6295] CHIP:EM: >>> [E:5148i M:227813842] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500389.176924][6291:6295] CHIP:EM: Found matching exchange: 5148i, Delegate: 0x7f46b00498b8 [1679500389.176962][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500389.177010][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500389.177035][6291:6295] CHIP:DMG: { [1679500389.177061][6291:6295] CHIP:DMG: suppressResponse = false, [1679500389.177151][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500389.177191][6291:6295] CHIP:DMG: [ [1679500389.177218][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500389.177251][6291:6295] CHIP:DMG: { [1679500389.177277][6291:6295] CHIP:DMG: CommandDataIB = [1679500389.177305][6291:6295] CHIP:DMG: { [1679500389.177328][6291:6295] CHIP:DMG: CommandPathIB = [1679500389.177355][6291:6295] CHIP:DMG: { [1679500389.177383][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500389.177408][6291:6295] CHIP:DMG: ClusterId = 0x3e, [1679500389.177493][6291:6295] CHIP:DMG: CommandId = 0x8, [1679500389.177516][6291:6295] CHIP:DMG: }, [1679500389.177544][6291:6295] CHIP:DMG: [1679500389.177569][6291:6295] CHIP:DMG: CommandFields = [1679500389.177594][6291:6295] CHIP:DMG: { [1679500389.177621][6291:6295] CHIP:DMG: 0x0 = 0, [1679500389.177646][6291:6295] CHIP:DMG: 0x1 = 1, [1679500389.177670][6291:6295] CHIP:DMG: }, [1679500389.177692][6291:6295] CHIP:DMG: }, [1679500389.177720][6291:6295] CHIP:DMG: [1679500389.177743][6291:6295] CHIP:DMG: }, [1679500389.177772][6291:6295] CHIP:DMG: [1679500389.177794][6291:6295] CHIP:DMG: ], [1679500389.177825][6291:6295] CHIP:DMG: [1679500389.177850][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500389.177873][6291:6295] CHIP:DMG: }, [1679500389.177935][6291:6295] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008 [1679500389.177975][6291:6295] CHIP:CTL: Device returned status 0 on receiving the NOC [1679500389.177998][6291:6295] CHIP:CTL: Operational credentials provisioned on device 0x7f46a800ba00 [1679500389.178023][6291:6295] CHIP:TOO: Secure Pairing Success [1679500389.178043][6291:6295] CHIP:TOO: CASE establishment successful [1679500389.178075][6291:6295] CHIP:CTL: Successfully finished commissioning step 'SendNOC' [1679500389.178100][6291:6295] CHIP:CTL: No NetworkScan enabled or WiFi/Thread endpoint not specified, skipping ScanNetworks [1679500389.178123][6291:6295] CHIP:CTL: Commissioning stage next step: 'SendNOC' -> 'ThreadNetworkSetup' [1679500389.178154][6291:6295] CHIP:CTL: Performing next commissioning step 'ThreadNetworkSetup' [1679500389.178227][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500389.178259][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500389.178380][6291:6295] CHIP:EM: <<< [E:5149i M:155586271] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500389.178414][6291:6295] CHIP:IN: (S) Sending msg 155586271 on secure session with LSID: 55740 [1679500389.178965][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500389.179058][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500389.264239][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500389.267493][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500389.267763][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500389.267936][6291:6295] CHIP:EM: >>> [E:5149i M:227813843] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500389.267972][6291:6295] CHIP:EM: Found matching exchange: 5149i, Delegate: 0x7f46b0049628 [1679500389.268008][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500389.268057][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500389.268084][6291:6295] CHIP:DMG: { [1679500389.268109][6291:6295] CHIP:DMG: suppressResponse = false, [1679500389.268132][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500389.268162][6291:6295] CHIP:DMG: [ [1679500389.268185][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500389.268214][6291:6295] CHIP:DMG: { [1679500389.268238][6291:6295] CHIP:DMG: CommandDataIB = [1679500389.268265][6291:6295] CHIP:DMG: { [1679500389.268287][6291:6295] CHIP:DMG: CommandPathIB = [1679500389.268312][6291:6295] CHIP:DMG: { [1679500389.268338][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500389.268366][6291:6295] CHIP:DMG: ClusterId = 0x31, [1679500389.268390][6291:6295] CHIP:DMG: CommandId = 0x5, [1679500389.268412][6291:6295] CHIP:DMG: }, [1679500389.268438][6291:6295] CHIP:DMG: [1679500389.268464][6291:6295] CHIP:DMG: CommandFields = [1679500389.268488][6291:6295] CHIP:DMG: { [1679500389.268515][6291:6295] CHIP:DMG: 0x0 = 0, [1679500389.268540][6291:6295] CHIP:DMG: 0x2 = 0, [1679500389.268564][6291:6295] CHIP:DMG: }, [1679500389.268586][6291:6295] CHIP:DMG: }, [1679500389.268615][6291:6295] CHIP:DMG: [1679500389.268637][6291:6295] CHIP:DMG: }, [1679500389.268668][6291:6295] CHIP:DMG: [1679500389.268733][6291:6295] CHIP:DMG: ], [1679500389.268767][6291:6295] CHIP:DMG: [1679500389.268792][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500389.268813][6291:6295] CHIP:DMG: }, [1679500389.268873][6291:6295] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0005 [1679500389.268935][6291:6295] CHIP:CTL: Received NetworkConfig response, networkingStatus=0 [1679500389.268969][6291:6295] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkSetup' [1679500389.268996][6291:6295] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkSetup' -> 'ThreadNetworkEnable' [1679500389.269027][6291:6295] CHIP:CTL: Performing next commissioning step 'ThreadNetworkEnable' [1679500389.269156][6291:6295] CHIP:DMG: ICR moving to [AddingComm] [1679500389.269197][6291:6295] CHIP:DMG: ICR moving to [AddedComma] [1679500389.269318][6291:6295] CHIP:EM: <<< [E:5150i M:155586272] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1679500389.269357][6291:6295] CHIP:IN: (S) Sending msg 155586272 on secure session with LSID: 55740 [1679500389.270015][6291:6295] CHIP:DMG: ICR moving to [CommandSen] [1679500389.270117][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500389.354673][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500391.831622][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500391.831817][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500392.687115][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500392.687434][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500392.687588][6291:6295] CHIP:EM: >>> [E:5150i M:227813844] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse) [1679500392.687637][6291:6295] CHIP:EM: Found matching exchange: 5150i, Delegate: 0x7f46b00498b8 [1679500392.687691][6291:6295] CHIP:DMG: ICR moving to [ResponseRe] [1679500392.687757][6291:6295] CHIP:DMG: InvokeResponseMessage = [1679500392.687799][6291:6295] CHIP:DMG: { [1679500392.687842][6291:6295] CHIP:DMG: suppressResponse = false, [1679500392.687879][6291:6295] CHIP:DMG: InvokeResponseIBs = [1679500392.687929][6291:6295] CHIP:DMG: [ [1679500392.687966][6291:6295] CHIP:DMG: InvokeResponseIB = [1679500392.688018][6291:6295] CHIP:DMG: { [1679500392.688058][6291:6295] CHIP:DMG: CommandDataIB = [1679500392.688100][6291:6295] CHIP:DMG: { [1679500392.688137][6291:6295] CHIP:DMG: CommandPathIB = [1679500392.688177][6291:6295] CHIP:DMG: { [1679500392.688218][6291:6295] CHIP:DMG: EndpointId = 0x0, [1679500392.688260][6291:6295] CHIP:DMG: ClusterId = 0x31, [1679500392.688301][6291:6295] CHIP:DMG: CommandId = 0x7, [1679500392.688337][6291:6295] CHIP:DMG: }, [1679500392.688381][6291:6295] CHIP:DMG: [1679500392.688419][6291:6295] CHIP:DMG: CommandFields = [1679500392.688459][6291:6295] CHIP:DMG: { [1679500392.688502][6291:6295] CHIP:DMG: 0x0 = 0, [1679500392.688545][6291:6295] CHIP:DMG: 0x2 = NULL [1679500392.688586][6291:6295] CHIP:DMG: }, [1679500392.688622][6291:6295] CHIP:DMG: }, [1679500392.688670][6291:6295] CHIP:DMG: [1679500392.688706][6291:6295] CHIP:DMG: }, [1679500392.688753][6291:6295] CHIP:DMG: [1679500392.688790][6291:6295] CHIP:DMG: ], [1679500392.688841][6291:6295] CHIP:DMG: [1679500392.688880][6291:6295] CHIP:DMG: InteractionModelRevision = 1 [1679500392.688916][6291:6295] CHIP:DMG: }, [1679500392.689010][6291:6295] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007 [1679500392.689064][6291:6295] CHIP:CTL: Received ConnectNetwork response, networkingStatus=0 [1679500392.689139][6291:6295] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkEnable' [1679500392.689185][6291:6295] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkEnable' -> 'FindOperational' [1679500392.689229][6291:6295] CHIP:CTL: Performing next commissioning step 'FindOperational' [1679500392.689264][6291:6295] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001] [1679500392.689352][6291:6295] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found [1679500392.689408][6291:6295] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2 [1679500392.689451][6291:6295] CHIP:DIS: Resolving EB2BB6B80AC66AB2:0000000000000001 ... [1679500392.691176][6291:6295] CHIP:DMG: ICR moving to [AwaitingDe] [1679500392.890927][6291:6295] CHIP:DIS: Checking node lookup status after 201 ms [1679500393.046224][6291:6295] CHIP:DL: Avahi resolve found [1679500393.046356][6291:6295] CHIP:DIS: Node ID resolved for EB2BB6B80AC66AB2:0000000000000001 [1679500393.046398][6291:6295] CHIP:DIS: Hostname: 4A647D838796B426 [1679500393.046441][6291:6295] CHIP:DIS: IP Address #1: fd6a:8c75:12d3:1:b723:d43f:a760:33ad [1679500393.046474][6291:6295] CHIP:DIS: Port: 5540 [1679500393.046507][6291:6295] CHIP:DIS: Mrp Interval idle: 1000 ms [1679500393.046539][6291:6295] CHIP:DIS: Mrp Interval active: 1000 ms [1679500393.046571][6291:6295] CHIP:DIS: TCP Supported: 0 [1679500393.046951][6291:6295] CHIP:DIS: Lookup clearing interface for non LL address [1679500393.047071][6291:6295] CHIP:DIS: UDP:[fd6a:8c75:12d3:1:b723:d43f:a760:33ad%wlx18a6f712c1ee]:5540: new best score: 4 [1679500393.047116][6291:6295] CHIP:DIS: Checking node lookup status after 357 ms [1679500393.047167][6291:6295] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fd6a:8c75:12d3:1:b723:d43f:a760:33ad]:5540 while in state 2 [1679500393.047205][6291:6295] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3 [1679500393.047311][6291:6295] CHIP:IN: SecureSession[0x7f46a80191f0]: Allocated Type:2 LSID:55741 [1679500393.047368][6291:6295] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1679500393.069245][6291:6295] CHIP:EM: <<< [E:5151i M:223393270] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1679500393.069355][6291:6295] CHIP:IN: (U) Sending msg 223393270 to IP address 'UDP:[fd6a:8c75:12d3:1:b723:d43f:a760:33ad]:5540' [1679500393.069660][6291:6295] CHIP:SC: Sent Sigma1 msg [1679500393.069726][6291:6295] CHIP:CTL: OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4 [1679500394.371848][6291:6295] CHIP:EM: Retransmitting MessageCounter:223393270 on exchange 5151i Send Cnt 1 [1679500394.371994][6291:6295] CHIP:IN: (U) Sending msg 223393270 to IP address 'UDP:[fd6a:8c75:12d3:1:b723:d43f:a760:33ad]:5540' [1679500394.394588][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500395.596329][6291:6295] CHIP:EM: Retransmitting MessageCounter:223393270 on exchange 5151i Send Cnt 2 [1679500395.596472][6291:6295] CHIP:IN: (U) Sending msg 223393270 to IP address 'UDP:[fd6a:8c75:12d3:1:b723:d43f:a760:33ad]:5540' [1679500396.872828][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500396.873022][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500397.469257][6291:6295] CHIP:EM: Retransmitting MessageCounter:223393270 on exchange 5151i Send Cnt 3 [1679500397.469413][6291:6295] CHIP:IN: (U) Sending msg 223393270 to IP address 'UDP:[fd6a:8c75:12d3:1:b723:d43f:a760:33ad]:5540' [1679500399.436693][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500400.504291][6291:6295] CHIP:EM: Retransmitting MessageCounter:223393270 on exchange 5151i Send Cnt 4 [1679500400.504439][6291:6295] CHIP:IN: (U) Sending msg 223393270 to IP address 'UDP:[fd6a:8c75:12d3:1:b723:d43f:a760:33ad]:5540' [1679500401.912132][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500401.912329][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500403.801399][6291:6294] CHIP:DL: Got IP address on interface: wlx18a6f712c1ee IP: 192.168.100.170 [1679500403.801876][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 32770 [1679500404.476755][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16387 [1679500405.141519][6291:6295] CHIP:EM: Failed to Send CHIP MessageCounter:223393270 on exchange 5151i sendCount: 4 max retries: 4 [1679500406.951749][6291:6294] CHIP:DL: Indication received, conn = 0x7f46b00471e0 [1679500406.952078][6291:6295] CHIP:DL: HandlePlatformSpecificBLEEvent 16389 [1679500409.157982][6291:6295] CHIP:SC: CASESession timed out while waiting for a response from the peer. Current state was 1 [1679500409.158108][6291:6295] CHIP:IN: SecureSession[0x7f46a80191f0]: Released - Type:2 LSID:55741 [1679500409.158179][6291:6295] CHIP:CTL: Device connection failed. Error ../../src/protocols/secure_channel/CASESession.cpp:295: CHIP Error 0x00000032: Timeout [1679500409.158231][6291:6295] CHIP:CTL: Error on commissioning step 'FindOperational': '../../src/protocols/secure_channel/CASESession.cpp:295: CHIP Error 0x00000032: Timeout' [1679500409.158266][6291:6295] CHIP:CTL: Failed to perform commissioning step 18 [1679500409.158307][6291:6295] CHIP:CTL: Going from commissioning step 'FindOperational' with lastErr = '../../src/protocols/secure_channel/CASESession.cpp:295: CHIP Error 0x00000032: Timeout' -> 'Cleanup' [1679500409.158356][6291:6295] CHIP:CTL: Performing next commissioning step 'Cleanup' with completion status = '../../src/protocols/secure_channel/CASESession.cpp:295: CHIP Error 0x00000032: Timeout' [1679500409.158395][6291:6295] CHIP:CTL: Successfully finished commissioning step 'Cleanup' [1679500409.158445][6291:6295] CHIP:TOO: Device commissioning Failure: ../../src/protocols/secure_channel/CASESession.cpp:295: CHIP Error 0x00000032: Timeout [1679500409.158811][6291:6291] CHIP:CTL: Shutting down the commissioner [1679500409.158863][6291:6291] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1679500409.158886][6291:6291] CHIP:DIS: Closing all BLE connections [1679500409.158908][6291:6291] CHIP:IN: Clearing BLE pending packets. [1679500409.158977][6291:6291] CHIP:BLE: Auto-closing end point's BLE connection. [1679500409.159000][6291:6291] CHIP:DL: Closing BLE GATT connection (con 0x7f46b00471e0) [1679500409.159038][6291:6291] CHIP:IN: SecureSession[0x7f46a800e800]: MarkForEviction Type:1 LSID:55740 [1679500409.159060][6291:6291] CHIP:SC: SecureSession[0x7f46a800e800]: Moving from state 'kActive' --> 'kPendingEviction' [1679500409.159095][6291:6291] CHIP:IN: SecureSession[0x7f46a800e800]: Released - Type:1 LSID:55740 [1679500409.159124][6291:6291] CHIP:CTL: Shutting down the controller [1679500409.159147][6291:6291] CHIP:IN: Expiring all sessions for fabric 0x1!! [1679500409.159168][6291:6291] CHIP:FP: Forgetting fabric 0x1 [1679500409.159196][6291:6291] CHIP:TS: Pending Last Known Good Time: 2023-03-02T09:25:05 [1679500409.159293][6291:6291] CHIP:TS: Previous Last Known Good Time: 2023-03-02T09:25:05 [1679500409.159317][6291:6291] CHIP:TS: Reverted Last Known Good Time to previous value [1679500409.159347][6291:6291] CHIP:CTL: Shutting down the commissioner [1679500409.159368][6291:6291] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1679500409.159389][6291:6291] CHIP:CTL: Shutting down the controller [1679500409.159409][6291:6291] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1679500409.159768][6291:6294] CHIP:DL: BluezDisconnect peer=C4:59:9B:B5:0D:6F [1679500409.160961][6291:6291] CHIP:DMG: IM WH moving to [Uninitialized] [1679500409.161020][6291:6291] CHIP:DMG: IM WH moving to [Uninitialized] [1679500409.161044][6291:6291] CHIP:DMG: IM WH moving to [Uninitialized] [1679500409.161069][6291:6291] CHIP:DMG: IM WH moving to [Uninitialized] [1679500409.161128][6291:6291] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1679500409.161217][6291:6291] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1679500409.161259][6291:6291] CHIP:FP: Shutting down FabricTable [1679500409.161290][6291:6291] CHIP:TS: Pending Last Known Good Time: 2023-03-02T09:25:05 [1679500409.161393][6291:6291] CHIP:TS: Previous Last Known Good Time: 2023-03-02T09:25:05 [1679500409.161416][6291:6291] CHIP:TS: Reverted Last Known Good Time to previous value [1679500409.161599][6291:6291] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-rRevmN) [1679500409.162045][6291:6291] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1679500409.162088][6291:6291] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1679500409.162113][6291:6291] CHIP:DL: Inet Layer shutdown [1679500409.162135][6291:6291] CHIP:DL: BLE shutdown [1679500409.162952][6291:6291] CHIP:DL: System Layer shutdown [1679500409.338308][6291:6291] CHIP:TOO: Run command failure: ../../src/protocols/secure_channel/CASESession.cpp:295: CHIP Error 0x00000032: Timeout