I use the Matter Light bulb example on nRF7002 DK. I have built it on sdk-nrf-v2.4.99-dev2. I use chip-tool v2.4.1 on UBUNTU 23.10 (on Raspberry Pi)
I try commissioning over ble-wifi. I use this command: sudo ./chip-tool pairing ble-wifi 1 tm 012345678 20202021 3840
After the WiFiNetworkEnable step I have the error:
BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:154: CHIP Error 0x00000032: Timeout
The chip-tool output:
[1697294747.035202][32395:32395] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1697294747.035721][32395:32395] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1697294747.035898][32395:32395] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1697294747.036016][32395:32395] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1697294747.036387][32395:32395] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-8oYcc3)
[1697294747.037066][32395:32395] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1697294747.037144][32395:32395] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2)
[1697294747.037782][32395:32395] CHIP:DL: Got Ethernet interface: eth0
[1697294747.038146][32395:32395] CHIP:DL: Found the primary Ethernet interface:eth0
[1697294747.038552][32395:32395] CHIP:DL: Got WiFi interface: wlan0
[1697294747.038628][32395:32395] CHIP:DL: Failed to reset WiFi statistic counts
[1697294747.038678][32395:32395] CHIP:IN: UDP::Init bind&listen port=0
[1697294747.038810][32395:32395] CHIP:IN: UDP::Init bound to port=39055
[1697294747.038833][32395:32395] CHIP:IN: UDP::Init bind&listen port=0
[1697294747.038929][32395:32395] CHIP:IN: UDP::Init bound to port=52554
[1697294747.038951][32395:32395] CHIP:IN: BLEBase::Init - setting/overriding transport
[1697294747.038969][32395:32395] CHIP:IN: TransportMgr initialized
[1697294747.039005][32395:32395] CHIP:FP: Initializing FabricTable from persistent storage
[1697294747.039144][32395:32395] CHIP:TS: Last Known Good Time: 2023-07-11T08:00:09
[1697294747.039590][32395:32395] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x99A797A4F8C34467, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1697294747.041597][32395:32395] CHIP:ZCL: Using ZAP configuration...
[1697294747.046270][32395:32395] CHIP:DL: Avahi client registered
[1697294747.047688][32395:32395] CHIP:CTL: System State Initialized...
[1697294747.047840][32395:32395] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1697294747.047882][32395:32395] CHIP:CTL: Setting attestation nonce to random value
[1697294747.047910][32395:32395] CHIP:CTL: Setting CSR nonce to random value
[1697294747.048297][32395:32397] CHIP:DL: CHIP task running
[1697294747.048569][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 32784
[1697294747.048854][32395:32397] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1697294747.048904][32395:32397] CHIP:CTL: Setting attestation nonce to random value
[1697294747.048939][32395:32397] CHIP:CTL: Setting CSR nonce to random value
[1697294747.062410][32395:32397] CHIP:CTL: Generating NOC
[1697294747.074484][32395:32397] CHIP:FP: Validating NOC chain
[1697294747.117598][32395:32397] CHIP:FP: NOC chain validation successful
[1697294747.117640][32395:32397] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1697294747.117664][32395:32397] CHIP:TS: Last Known Good Time: 2023-07-11T08:00:09
[1697294747.117682][32395:32397] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1697294747.117698][32395:32397] CHIP:TS: Retaining current Last Known Good Time
[1697294747.119793][32395:32397] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1697294747.121520][32395:32397] CHIP:TS: Committing Last Known Good Time to storage: 2023-07-11T08:00:09
[1697294747.123183][32395:32397] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 99A797A4F8C34467)
[1697294747.134875][32395:32397] CHIP:CTL: Setting wifi credentials from parameters
[1697294747.134917][32395:32397] CHIP:CTL: Setting attestation nonce to random value
[1697294747.134952][32395:32397] CHIP:CTL: Setting CSR nonce to random value
[1697294747.134977][32395:32397] CHIP:CTL: Commission called for node ID 0x0000000000000001
[1697294747.140106][32395:32396] CHIP:DL: TRACE: Bus acquired for name C-7e8b
[1697294747.147339][32395:32397] CHIP:DL: PlatformBlueZInit init success
[1697294747.153708][32395:32396] CHIP:BLE: BLE removing known devices.
[1697294747.156302][32395:32396] CHIP:BLE: BLE initiating scan.
[1697294747.197506][32395:32396] CHIP:BLE: New device scanned: DD:FD:F2:53:5E:88
[1697294747.197641][32395:32396] CHIP:BLE: Device discriminator match. Attempting to connect.
[1697294747.684375][32395:32396] CHIP:DL: ConnectDevice complete
[1697294748.780809][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service000c
[1697294748.780868][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service000c
[1697294748.780966][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service0001
[1697294748.780994][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service000c
[1697294748.781019][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service0001
[1697294748.781040][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service000c
[1697294748.781063][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service0001
[1697294748.781144][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service000c
[1697294748.781209][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service000c
[1697294748.781235][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service000c
[1697294748.781257][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service000c
[1697294748.781281][32395:32396] CHIP:DL: Char1 /org/bluez/hci0/dev_DD_FD_F2_53_5E_88/service000c
[1697294748.781311][32395:32396] CHIP:DL: New BLE connection 0xffff80032890, device DD:FD:F2:53:5E:88, path /org/bluez/hci0/dev_DD_FD_F2_53_5E_88
[1697294748.781439][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16385
[1697294748.781475][32395:32397] CHIP:DIS: Closing all BLE connections
[1697294748.781533][32395:32397] CHIP:IN: BleConnectionComplete: endPoint 0xaaaae4fd6aa0
[1697294748.782037][32395:32397] CHIP:IN: SecureSession[0xffff780095a0]: Allocated Type:1 LSID:1189
[1697294748.782090][32395:32397] CHIP:SC: Assigned local session key ID 1189
[1697294748.782200][32395:32397] CHIP:EM: <<< [E:8633i S:0 M:131244374] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
[1697294748.782270][32395:32397] CHIP:IN: (U) Sending msg 131244374 to IP address 'BLE'
[1697294748.782311][32395:32397] CHIP:IN: Message appended to BLE send queue
[1697294748.782340][32395:32397] CHIP:SC: Sent PBKDF param request
[1697294749.186604][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294749.278805][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1697294749.278922][32395:32397] CHIP:BLE: subscribe complete, ep = 0xaaaae4fd6aa0
[1697294749.280933][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294749.281493][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294749.281569][32395:32397] CHIP:BLE: peripheral chose BTP version 4; central expected between 4 and 4
[1697294749.281624][32395:32397] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244.
[1697294749.281672][32395:32397] CHIP:BLE: local and remote recv window size = 5
[1697294749.282265][32395:32397] CHIP:IN: BLE EndPoint 0xaaaae4fd6aa0 Connection Complete
[1697294749.410673][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294749.503595][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294749.503925][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294749.504201][32395:32397] CHIP:EM: >>> [E:8633i S:0 M:36006713] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
[1697294749.504285][32395:32397] CHIP:EM: Found matching exchange: 8633i, Delegate: 0xffff7800c2a0
[1697294749.504388][32395:32397] CHIP:SC: Received PBKDF param response
[1697294749.504612][32395:32397] CHIP:SC: Peer assigned session ID 33323
[1697294749.504790][32395:32397] CHIP:SC: Found MRP parameters in the message
[1697294749.564747][32395:32397] CHIP:EM: <<< [E:8633i S:0 M:131244375] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1)
[1697294749.564807][32395:32397] CHIP:IN: (U) Sending msg 131244375 to IP address 'BLE'
[1697294749.565174][32395:32397] CHIP:SC: Sent spake2p msg1
[1697294749.635834][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294751.078232][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294751.078921][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294751.079232][32395:32397] CHIP:EM: >>> [E:8633i S:0 M:36006714] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
[1697294751.079310][32395:32397] CHIP:EM: Found matching exchange: 8633i, Delegate: 0xffff7800c2a0
[1697294751.079516][32395:32397] CHIP:SC: Received spake2p msg2
[1697294751.130857][32395:32397] CHIP:EM: <<< [E:8633i S:0 M:131244376] (U) Msg TX to 0:0000000000000000 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3)
[1697294751.130907][32395:32397] CHIP:IN: (U) Sending msg 131244376 to IP address 'BLE'
[1697294751.131345][32395:32397] CHIP:SC: Sent spake2p msg3
[1697294751.255785][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294751.257694][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294751.258165][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294751.258588][32395:32397] CHIP:EM: >>> [E:8633i S:0 M:36006715] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1697294751.259121][32395:32397] CHIP:EM: Found matching exchange: 8633i, Delegate: 0xffff7800c2a0
[1697294751.259544][32395:32397] CHIP:SC: SecureSession[0xffff780095a0]: Moving from state 'kEstablishing' --> 'kActive'[1697294751.259782][32395:32397] CHIP:IN: SecureSession[0xffff780095a0]: Activated - Type:1 LSID:1189
[1697294751.259837][32395:32397] CHIP:IN: New secure session activated for device <FFFFFFFB00000000, 0>, LSID:1189 PSID:33323!
[1697294751.259928][32395:32397] CHIP:CTL: Remote device completed SPAKE2+ handshake
[1697294751.259983][32395:32397] CHIP:TOO: Pairing Success
[1697294751.260032][32395:32397] CHIP:TOO: PASE establishment successful
[1697294751.260090][32395:32397] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1697294751.260152][32395:32397] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo'
[1697294751.260204][32395:32397] CHIP:CTL: Sending request for commissioning information
[1697294751.260300][32395:32397] CHIP:DMG: SendReadRequest ReadClient[0xffff780137e0]: Sending Read Request
[1697294751.260730][32395:32397] CHIP:EM: <<< [E:8634i S:1189 M:161582293] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
[1697294751.260831][32395:32397] CHIP:IN: (S) Sending msg 161582293 on secure session with LSID: 1189
[1697294751.261722][32395:32397] CHIP:DMG: MoveToState ReadClient[0xffff780137e0]: Moving to [AwaitingIn]
[1697294751.390795][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294751.484339][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294751.485093][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294751.573097][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294751.573738][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294751.574060][32395:32397] CHIP:EM: >>> [E:8634i S:1189 M:169693654] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
[1697294751.574141][32395:32397] CHIP:EM: Found matching exchange: 8634i, Delegate: 0xffff780137f0
[1697294751.574373][32395:32397] CHIP:DMG: ReportDataMessage =
[1697294751.574436][32395:32397] CHIP:DMG: {
[1697294751.574491][32395:32397] CHIP:DMG: AttributeReportIBs =
[1697294751.574565][32395:32397] CHIP:DMG: [
[1697294751.574623][32395:32397] CHIP:DMG: AttributeReportIB =
[1697294751.574700][32395:32397] CHIP:DMG: {
[1697294751.574759][32395:32397] CHIP:DMG: AttributeDataIB =
[1697294751.574840][32395:32397] CHIP:DMG: {
[1697294751.574913][32395:32397] CHIP:DMG: DataVersion = 0xdc16d884,
[1697294751.574983][32395:32397] CHIP:DMG: AttributePathIB =
[1697294751.575054][32395:32397] CHIP:DMG: {
[1697294751.575127][32395:32397] CHIP:DMG: Endpoint = 0x0,
[1697294751.575204][32395:32397] CHIP:DMG: Cluster = 0x31,
[1697294751.575281][32395:32397] CHIP:DMG: Attribute = 0x0000_0003,
[1697294751.575363][32395:32397] CHIP:DMG: }
[1697294751.575530][32395:32397] CHIP:DMG:
[1697294751.575618][32395:32397] CHIP:DMG: Data = 35,
[1697294751.575689][32395:32397] CHIP:DMG: },
[1697294751.575779][32395:32397] CHIP:DMG:
[1697294751.575841][32395:32397] CHIP:DMG: },
[1697294751.575930][32395:32397] CHIP:DMG:
[1697294751.575989][32395:32397] CHIP:DMG: AttributeReportIB =
[1697294751.576065][32395:32397] CHIP:DMG: {
[1697294751.576131][32395:32397] CHIP:DMG: AttributeDataIB =
[1697294751.576197][32395:32397] CHIP:DMG: {
[1697294751.576267][32395:32397] CHIP:DMG: DataVersion = 0xb42131a8,
[1697294751.576343][32395:32397] CHIP:DMG: AttributePathIB =
[1697294751.576421][32395:32397] CHIP:DMG: {
[1697294751.576490][32395:32397] CHIP:DMG: Endpoint = 0x0,
[1697294751.576583][32395:32397] CHIP:DMG: Cluster = 0x28,
[1697294751.576677][32395:32397] CHIP:DMG: Attribute = 0x0000_0004,
[1697294751.576750][32395:32397] CHIP:DMG: }
[1697294751.576832][32395:32397] CHIP:DMG:
[1697294751.576912][32395:32397] CHIP:DMG: Data = 32773,
[1697294751.576989][32395:32397] CHIP:DMG: },
[1697294751.577065][32395:32397] CHIP:DMG:
[1697294751.577124][32395:32397] CHIP:DMG: },
[1697294751.577210][32395:32397] CHIP:DMG:
[1697294751.577269][32395:32397] CHIP:DMG: AttributeReportIB =
[1697294751.577343][32395:32397] CHIP:DMG: {
[1697294751.577402][32395:32397] CHIP:DMG: AttributeDataIB =
[1697294751.577468][32395:32397] CHIP:DMG: {
[1697294751.577537][32395:32397] CHIP:DMG: DataVersion = 0xb42131a8,
[1697294751.577613][32395:32397] CHIP:DMG: AttributePathIB =
[1697294751.577692][32395:32397] CHIP:DMG: {
[1697294751.577764][32395:32397] CHIP:DMG: Endpoint = 0x0,
[1697294751.577858][32395:32397] CHIP:DMG: Cluster = 0x28,
[1697294751.577952][32395:32397] CHIP:DMG: Attribute = 0x0000_0002,
[1697294751.578041][32395:32397] CHIP:DMG: }
[1697294751.578123][32395:32397] CHIP:DMG:
[1697294751.578205][32395:32397] CHIP:DMG: Data = 65521,
[1697294751.578280][32395:32397] CHIP:DMG: },
[1697294751.578355][32395:32397] CHIP:DMG:
[1697294751.578415][32395:32397] CHIP:DMG: },
[1697294751.578498][32395:32397] CHIP:DMG:
[1697294751.578555][32395:32397] CHIP:DMG: AttributeReportIB =
[1697294751.578627][32395:32397] CHIP:DMG: {
[1697294751.578687][32395:32397] CHIP:DMG: AttributeDataIB =
[1697294751.578755][32395:32397] CHIP:DMG: {
[1697294751.578826][32395:32397] CHIP:DMG: DataVersion = 0xf47beac4,
[1697294751.578902][32395:32397] CHIP:DMG: AttributePathIB =
[1697294751.578982][32395:32397] CHIP:DMG: {
[1697294751.579062][32395:32397] CHIP:DMG: Endpoint = 0x0,
[1697294751.579135][32395:32397] CHIP:DMG: Cluster = 0x30,
[1697294751.579228][32395:32397] CHIP:DMG: Attribute = 0x0000_0003,
[1697294751.579316][32395:32397] CHIP:DMG: }
[1697294751.579433][32395:32397] CHIP:DMG:
[1697294751.579521][32395:32397] CHIP:DMG: Data = 0,
[1697294751.579599][32395:32397] CHIP:DMG: },
[1697294751.579673][32395:32397] CHIP:DMG:
[1697294751.579732][32395:32397] CHIP:DMG: },
[1697294751.579816][32395:32397] CHIP:DMG:
[1697294751.579873][32395:32397] CHIP:DMG: AttributeReportIB =
[1697294751.579947][32395:32397] CHIP:DMG: {
[1697294751.580007][32395:32397] CHIP:DMG: AttributeDataIB =
[1697294751.580071][32395:32397] CHIP:DMG: {
[1697294751.580149][32395:32397] CHIP:DMG: DataVersion = 0xf47beac4,
[1697294751.580225][32395:32397] CHIP:DMG: AttributePathIB =
[1697294751.580303][32395:32397] CHIP:DMG: {
[1697294751.580382][32395:32397] CHIP:DMG: Endpoint = 0x0,
[1697294751.580476][32395:32397] CHIP:DMG: Cluster = 0x30,
[1697294751.580570][32395:32397] CHIP:DMG: Attribute = 0x0000_0002,
[1697294751.580659][32395:32397] CHIP:DMG: }
[1697294751.580741][32395:32397] CHIP:DMG:
[1697294751.580822][32395:32397] CHIP:DMG: Data = 0,
[1697294751.580897][32395:32397] CHIP:DMG: },
[1697294751.580971][32395:32397] CHIP:DMG:
[1697294751.581030][32395:32397] CHIP:DMG: },
[1697294751.581117][32395:32397] CHIP:DMG:
[1697294751.581173][32395:32397] CHIP:DMG: AttributeReportIB =
[1697294751.581250][32395:32397] CHIP:DMG: {
[1697294751.581310][32395:32397] CHIP:DMG: AttributeDataIB =
[1697294751.581375][32395:32397] CHIP:DMG: {
[1697294751.581440][32395:32397] CHIP:DMG: DataVersion = 0xf47beac4,
[1697294751.581516][32395:32397] CHIP:DMG: AttributePathIB =
[1697294751.581596][32395:32397] CHIP:DMG: {
[1697294751.581675][32395:32397] CHIP:DMG: Endpoint = 0x0,
[1697294751.581770][32395:32397] CHIP:DMG: Cluster = 0x30,
[1697294751.581847][32395:32397] CHIP:DMG: Attribute = 0x0000_0001,
[1697294751.581938][32395:32397] CHIP:DMG: }
[1697294751.582020][32395:32397] CHIP:DMG:
[1697294751.582097][32395:32397] CHIP:DMG: Data =
[1697294751.582169][32395:32397] CHIP:DMG: {
[1697294751.582251][32395:32397] CHIP:DMG: 0x0 = 60,
[1697294751.582346][32395:32397] CHIP:DMG: 0x1 = 900,
[1697294751.582440][32395:32397] CHIP:DMG: },
[1697294751.582505][32395:32397] CHIP:DMG: },
[1697294751.582581][32395:32397] CHIP:DMG:
[1697294751.582640][32395:32397] CHIP:DMG: },
[1697294751.582726][32395:32397] CHIP:DMG:
[1697294751.582789][32395:32397] CHIP:DMG: AttributeReportIB =
[1697294751.582865][32395:32397] CHIP:DMG: {
[1697294751.582925][32395:32397] CHIP:DMG: AttributeDataIB =
[1697294751.582990][32395:32397] CHIP:DMG: {
[1697294751.583058][32395:32397] CHIP:DMG: DataVersion = 0xf47beac4,
[1697294751.583133][32395:32397] CHIP:DMG: AttributePathIB =
[1697294751.583211][32395:32397] CHIP:DMG: {
[1697294751.583291][32395:32397] CHIP:DMG: Endpoint = 0x0,
[1697294751.583368][32395:32397] CHIP:DMG: Cluster = 0x30,
[1697294751.583532][32395:32397] CHIP:DMG: Attribute = 0x0000_0000,
[1697294751.583622][32395:32397] CHIP:DMG: }
[1697294751.583706][32395:32397] CHIP:DMG:
[1697294751.583786][32395:32397] CHIP:DMG: Data = 0,
[1697294751.583850][32395:32397] CHIP:DMG: },
[1697294751.583925][32395:32397] CHIP:DMG:
[1697294751.583984][32395:32397] CHIP:DMG: },
[1697294751.584063][32395:32397] CHIP:DMG:
[1697294751.584100][32395:32397] CHIP:DMG: AttributeReportIB =
[1697294751.584138][32395:32397] CHIP:DMG: {
[1697294751.584159][32395:32397] CHIP:DMG: AttributeDataIB =
[1697294751.584182][32395:32397] CHIP:DMG: {
[1697294751.584206][32395:32397] CHIP:DMG: DataVersion = 0xdc16d884,
[1697294751.584233][32395:32397] CHIP:DMG: AttributePathIB =
[1697294751.584256][32395:32397] CHIP:DMG: {
[1697294751.584288][32395:32397] CHIP:DMG: Endpoint = 0x0,
[1697294751.584322][32395:32397] CHIP:DMG: Cluster = 0x31,
[1697294751.584347][32395:32397] CHIP:DMG: Attribute = 0x0000_FFFC,
[1697294751.584379][32395:32397] CHIP:DMG: }
[1697294751.584408][32395:32397] CHIP:DMG:
[1697294751.584436][32395:32397] CHIP:DMG: Data = 1,
[1697294751.584463][32395:32397] CHIP:DMG: },
[1697294751.584489][32395:32397] CHIP:DMG:
[1697294751.584510][32395:32397] CHIP:DMG: },
[1697294751.584535][32395:32397] CHIP:DMG:
[1697294751.584554][32395:32397] CHIP:DMG: ],
[1697294751.584603][32395:32397] CHIP:DMG:
[1697294751.584623][32395:32397] CHIP:DMG: SuppressResponse = true,
[1697294751.584644][32395:32397] CHIP:DMG: InteractionModelRevision = 1
[1697294751.584664][32395:32397] CHIP:DMG: }
[1697294751.585401][32395:32397] CHIP:CTL: ----- NetworkCommissioning Features: has WiFi. endpointid = 0
[1697294751.585467][32395:32397] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo'
[1697294751.585497][32395:32397] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ArmFailSafe'
[1697294751.585524][32395:32397] CHIP:CTL: Performing next commissioning step 'ArmFailSafe'
[1697294751.585546][32395:32397] CHIP:CTL: Arming failsafe (60 seconds)
[1697294751.585611][32395:32397] CHIP:DMG: ICR moving to [AddingComm]
[1697294751.585639][32395:32397] CHIP:DMG: ICR moving to [AddedComma]
[1697294751.585744][32395:32397] CHIP:EM: <<< [E:8635i S:1189 M:161582294] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697294751.585784][32395:32397] CHIP:IN: (S) Sending msg 161582294 on secure session with LSID: 1189
[1697294751.586159][32395:32397] CHIP:DMG: ICR moving to [CommandSen]
[1697294751.796634][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294751.888361][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294751.888794][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294751.889236][32395:32397] CHIP:EM: >>> [E:8635i S:1189 M:169693655] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697294751.889320][32395:32397] CHIP:EM: Found matching exchange: 8635i, Delegate: 0xffff80034758
[1697294751.889408][32395:32397] CHIP:DMG: ICR moving to [ResponseRe]
[1697294751.889516][32395:32397] CHIP:DMG: InvokeResponseMessage =
[1697294751.889572][32395:32397] CHIP:DMG: {
[1697294751.889629][32395:32397] CHIP:DMG: suppressResponse = false,
[1697294751.889688][32395:32397] CHIP:DMG: InvokeResponseIBs =
[1697294751.889785][32395:32397] CHIP:DMG: [
[1697294751.889852][32395:32397] CHIP:DMG: InvokeResponseIB =
[1697294751.889933][32395:32397] CHIP:DMG: {
[1697294751.889995][32395:32397] CHIP:DMG: CommandDataIB =
[1697294751.890065][32395:32397] CHIP:DMG: {
[1697294751.890128][32395:32397] CHIP:DMG: CommandPathIB =
[1697294751.890294][32395:32397] CHIP:DMG: {
[1697294751.890399][32395:32397] CHIP:DMG: EndpointId = 0x0,
[1697294751.890546][32395:32397] CHIP:DMG: ClusterId = 0x30,
[1697294751.890623][32395:32397] CHIP:DMG: CommandId = 0x1,
[1697294751.890690][32395:32397] CHIP:DMG: },
[1697294751.890759][32395:32397] CHIP:DMG:
[1697294751.890829][32395:32397] CHIP:DMG: CommandFields =
[1697294751.890899][32395:32397] CHIP:DMG: {
[1697294751.890979][32395:32397] CHIP:DMG: 0x0 = 0,
[1697294751.891057][32395:32397] CHIP:DMG: 0x1 = "" (0 chars),
[1697294751.891137][32395:32397] CHIP:DMG: },
[1697294751.891271][32395:32397] CHIP:DMG: },
[1697294751.891350][32395:32397] CHIP:DMG:
[1697294751.891453][32395:32397] CHIP:DMG: },
[1697294751.891598][32395:32397] CHIP:DMG:
[1697294751.891658][32395:32397] CHIP:DMG: ],
[1697294751.891734][32395:32397] CHIP:DMG:
[1697294751.891794][32395:32397] CHIP:DMG: InteractionModelRevision = 1
[1697294751.891853][32395:32397] CHIP:DMG: },
[1697294751.892005][32395:32397] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1697294751.892230][32395:32397] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1697294751.892303][32395:32397] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe'
[1697294751.892357][32395:32397] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1697294751.892426][32395:32397] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory'
[1697294751.892477][32395:32397] CHIP:CTL: Setting Regulatory Config
[1697294751.892528][32395:32397] CHIP:CTL: Device does not support configurable regulatory location
[1697294751.892676][32395:32397] CHIP:DMG: ICR moving to [AddingComm]
[1697294751.892869][32395:32397] CHIP:DMG: ICR moving to [AddedComma]
[1697294751.893097][32395:32397] CHIP:EM: <<< [E:8636i S:1189 M:161582295] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697294751.893203][32395:32397] CHIP:IN: (S) Sending msg 161582295 on secure session with LSID: 1189
[1697294751.894126][32395:32397] CHIP:DMG: ICR moving to [CommandSen]
[1697294751.894298][32395:32397] CHIP:DMG: ICR moving to [AwaitingDe]
[1697294751.976410][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294752.293425][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294752.293827][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294752.294202][32395:32397] CHIP:EM: >>> [E:8636i S:1189 M:169693656] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697294752.294289][32395:32397] CHIP:EM: Found matching exchange: 8636i, Delegate: 0xffff78008898
[1697294752.294381][32395:32397] CHIP:DMG: ICR moving to [ResponseRe]
[1697294752.294491][32395:32397] CHIP:DMG: InvokeResponseMessage =
[1697294752.294548][32395:32397] CHIP:DMG: {
[1697294752.294604][32395:32397] CHIP:DMG: suppressResponse = false,
[1697294752.294757][32395:32397] CHIP:DMG: InvokeResponseIBs =
[1697294752.294835][32395:32397] CHIP:DMG: [
[1697294752.294893][32395:32397] CHIP:DMG: InvokeResponseIB =
[1697294752.294971][32395:32397] CHIP:DMG: {
[1697294752.295032][32395:32397] CHIP:DMG: CommandDataIB =
[1697294752.295165][32395:32397] CHIP:DMG: {
[1697294752.295233][32395:32397] CHIP:DMG: CommandPathIB =
[1697294752.295371][32395:32397] CHIP:DMG: {
[1697294752.295559][32395:32397] CHIP:DMG: EndpointId = 0x0,
[1697294752.295703][32395:32397] CHIP:DMG: ClusterId = 0x30,
[1697294752.295780][32395:32397] CHIP:DMG: CommandId = 0x3,
[1697294752.295860][32395:32397] CHIP:DMG: },
[1697294752.295936][32395:32397] CHIP:DMG:
[1697294752.296002][32395:32397] CHIP:DMG: CommandFields =
[1697294752.296069][32395:32397] CHIP:DMG: {
[1697294752.296139][32395:32397] CHIP:DMG: 0x0 = 0,
[1697294752.296284][32395:32397] CHIP:DMG: 0x1 = "" (0 chars),
[1697294752.296369][32395:32397] CHIP:DMG: },
[1697294752.296439][32395:32397] CHIP:DMG: },
[1697294752.296515][32395:32397] CHIP:DMG:
[1697294752.296577][32395:32397] CHIP:DMG: },
[1697294752.296650][32395:32397] CHIP:DMG:
[1697294752.296706][32395:32397] CHIP:DMG: ],
[1697294752.296787][32395:32397] CHIP:DMG:
[1697294752.296845][32395:32397] CHIP:DMG: InteractionModelRevision = 1
[1697294752.296902][32395:32397] CHIP:DMG: },
[1697294752.297053][32395:32397] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1697294752.297280][32395:32397] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0
[1697294752.297352][32395:32397] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory'
[1697294752.297406][32395:32397] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest'
[1697294752.297474][32395:32397] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest'
[1697294752.297525][32395:32397] CHIP:CTL: Sending request for PAI certificate
[1697294752.297576][32395:32397] CHIP:CTL: Sending Certificate Chain request to 0xffff7800c250 device
[1697294752.297719][32395:32397] CHIP:DMG: ICR moving to [AddingComm]
[1697294752.297903][32395:32397] CHIP:DMG: ICR moving to [AddedComma]
[1697294752.298122][32395:32397] CHIP:EM: <<< [E:8637i S:1189 M:161582296] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697294752.298222][32395:32397] CHIP:IN: (S) Sending msg 161582296 on secure session with LSID: 1189
[1697294752.299052][32395:32397] CHIP:DMG: ICR moving to [CommandSen]
[1697294752.299216][32395:32397] CHIP:DMG: ICR moving to [AwaitingDe]
[1697294752.515744][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294752.655058][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294752.655476][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294752.743313][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294752.743797][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294752.967463][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294752.968039][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294752.968476][32395:32397] CHIP:EM: >>> [E:8637i S:1189 M:169693657] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697294752.968561][32395:32397] CHIP:EM: Found matching exchange: 8637i, Delegate: 0xffff80034758
[1697294752.968663][32395:32397] CHIP:DMG: ICR moving to [ResponseRe]
[1697294752.968775][32395:32397] CHIP:DMG: InvokeResponseMessage =
[1697294752.968832][32395:32397] CHIP:DMG: {
[1697294752.968890][32395:32397] CHIP:DMG: suppressResponse = false,
[1697294752.968945][32395:32397] CHIP:DMG: InvokeResponseIBs =
[1697294752.969020][32395:32397] CHIP:DMG: [
[1697294752.969081][32395:32397] CHIP:DMG: InvokeResponseIB =
[1697294752.969160][32395:32397] CHIP:DMG: {
[1697294752.969221][32395:32397] CHIP:DMG: CommandDataIB =
[1697294752.969289][32395:32397] CHIP:DMG: {
[1697294752.969356][32395:32397] CHIP:DMG: CommandPathIB =
[1697294752.969441][32395:32397] CHIP:DMG: {
[1697294752.969523][32395:32397] CHIP:DMG: EndpointId = 0x0,
[1697294752.969619][32395:32397] CHIP:DMG: ClusterId = 0x3e,
[1697294752.969709][32395:32397] CHIP:DMG: CommandId = 0x3,
[1697294752.969784][32395:32397] CHIP:DMG: },
[1697294752.969859][32395:32397] CHIP:DMG:
[1697294752.969927][32395:32397] CHIP:DMG: CommandFields =
[1697294752.970006][32395:32397] CHIP:DMG: {
[1697294752.970089][32395:32397] CHIP:DMG: 0x0 = [
[1697294752.970358][32395:32397] 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
[1697294752.970535][32395:32397] CHIP:DMG: ] (463 bytes)
[1697294752.970631][32395:32397] CHIP:DMG: },
[1697294752.970707][32395:32397] CHIP:DMG: },
[1697294752.970784][32395:32397] CHIP:DMG:
[1697294752.970845][32395:32397] CHIP:DMG: },
[1697294752.970917][32395:32397] CHIP:DMG:
[1697294752.970973][32395:32397] CHIP:DMG: ],
[1697294752.971049][32395:32397] CHIP:DMG:
[1697294752.971106][32395:32397] CHIP:DMG: InteractionModelRevision = 1
[1697294752.971163][32395:32397] CHIP:DMG: },
[1697294752.971316][32395:32397] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1697294752.971453][32395:32397] CHIP:CTL: Received certificate chain from the device
[1697294752.971527][32395:32397] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest'
[1697294752.971592][32395:32397] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1697294752.971661][32395:32397] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest'
[1697294752.971710][32395:32397] CHIP:CTL: Sending request for DAC certificate
[1697294752.971768][32395:32397] CHIP:CTL: Sending Certificate Chain request to 0xffff7800c250 device
[1697294752.971912][32395:32397] CHIP:DMG: ICR moving to [AddingComm]
[1697294752.971985][32395:32397] CHIP:DMG: ICR moving to [AddedComma]
[1697294752.972206][32395:32397] CHIP:EM: <<< [E:8638i S:1189 M:161582297] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697294752.972301][32395:32397] CHIP:IN: (S) Sending msg 161582297 on secure session with LSID: 1189
[1697294752.973330][32395:32397] CHIP:DMG: ICR moving to [CommandSen]
[1697294752.973510][32395:32397] CHIP:DMG: ICR moving to [AwaitingDe]
[1697294753.190746][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294753.419504][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294753.420058][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294753.554623][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294753.555209][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294753.868649][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294753.868989][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294753.869399][32395:32397] CHIP:EM: >>> [E:8638i S:1189 M:169693658] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697294753.869486][32395:32397] CHIP:EM: Found matching exchange: 8638i, Delegate: 0xffff80034b38
[1697294753.869587][32395:32397] CHIP:DMG: ICR moving to [ResponseRe]
[1697294753.869704][32395:32397] CHIP:DMG: InvokeResponseMessage =
[1697294753.869765][32395:32397] CHIP:DMG: {
[1697294753.869820][32395:32397] CHIP:DMG: suppressResponse = false,
[1697294753.869876][32395:32397] CHIP:DMG: InvokeResponseIBs =
[1697294753.869983][32395:32397] CHIP:DMG: [
[1697294753.870041][32395:32397] CHIP:DMG: InvokeResponseIB =
[1697294753.870120][32395:32397] CHIP:DMG: {
[1697294753.870178][32395:32397] CHIP:DMG: CommandDataIB =
[1697294753.870251][32395:32397] CHIP:DMG: {
[1697294753.870314][32395:32397] CHIP:DMG: CommandPathIB =
[1697294753.870397][32395:32397] CHIP:DMG: {
[1697294753.870470][32395:32397] CHIP:DMG: EndpointId = 0x0,
[1697294753.870555][32395:32397] CHIP:DMG: ClusterId = 0x3e,
[1697294753.870649][32395:32397] CHIP:DMG: CommandId = 0x3,
[1697294753.870739][32395:32397] CHIP:DMG: },
[1697294753.870832][32395:32397] CHIP:DMG:
[1697294753.870901][32395:32397] CHIP:DMG: CommandFields =
[1697294753.870980][32395:32397] CHIP:DMG: {
[1697294753.871061][32395:32397] CHIP:DMG: 0x0 = [
[1697294753.871334][32395:32397] 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
[1697294753.871569][32395:32397] CHIP:DMG: ] (492 bytes)
[1697294753.871667][32395:32397] CHIP:DMG: },
[1697294753.871743][32395:32397] CHIP:DMG: },
[1697294753.871822][32395:32397] CHIP:DMG:
[1697294753.871882][32395:32397] CHIP:DMG: },
[1697294753.871978][32395:32397] CHIP:DMG:
[1697294753.872036][32395:32397] CHIP:DMG: ],
[1697294753.872111][32395:32397] CHIP:DMG:
[1697294753.872170][32395:32397] CHIP:DMG: InteractionModelRevision = 1
[1697294753.872227][32395:32397] CHIP:DMG: },
[1697294753.872391][32395:32397] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1697294753.872472][32395:32397] CHIP:CTL: Received certificate chain from the device
[1697294753.872538][32395:32397] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest'
[1697294753.872606][32395:32397] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1697294753.872675][32395:32397] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest'
[1697294753.872724][32395:32397] CHIP:CTL: Sending Attestation Request to the device.
[1697294753.872777][32395:32397] CHIP:CTL: Sending Attestation request to 0xffff7800c250 device
[1697294753.872916][32395:32397] CHIP:DMG: ICR moving to [AddingComm]
[1697294753.872993][32395:32397] CHIP:DMG: ICR moving to [AddedComma]
[1697294753.873219][32395:32397] CHIP:EM: <<< [E:8639i S:1189 M:161582298] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697294753.873314][32395:32397] CHIP:IN: (S) Sending msg 161582298 on secure session with LSID: 1189
[1697294753.874174][32395:32397] CHIP:DMG: ICR moving to [CommandSen]
[1697294753.874285][32395:32397] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information
[1697294753.874424][32395:32397] CHIP:DMG: ICR moving to [AwaitingDe]
[1697294754.000907][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294754.318536][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294754.318819][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294755.848285][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294755.848672][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294755.984711][32395:32396] CHIP:DL: Indication received, conn = 0xffff80032890
[1697294755.985066][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1697294755.985762][32395:32397] CHIP:EM: >>> [E:8639i S:1189 M:169693659] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1697294755.985847][32395:32397] CHIP:EM: Found matching exchange: 8639i, Delegate: 0xffff80035588
[1697294755.985974][32395:32397] CHIP:DMG: ICR moving to [ResponseRe]
[1697294755.986078][32395:32397] CHIP:DMG: InvokeResponseMessage =
[1697294755.986129][32395:32397] CHIP:DMG: {
[1697294755.986176][32395:32397] CHIP:DMG: suppressResponse = false,
[1697294755.986236][32395:32397] CHIP:DMG: InvokeResponseIBs =
[1697294755.986302][32395:32397] CHIP:DMG: [
[1697294755.986351][32395:32397] CHIP:DMG: InvokeResponseIB =
[1697294755.986421][32395:32397] CHIP:DMG: {
[1697294755.986495][32395:32397] CHIP:DMG: CommandDataIB =
[1697294755.986556][32395:32397] CHIP:DMG: {
[1697294755.986611][32395:32397] CHIP:DMG: CommandPathIB =
[1697294755.986751][32395:32397] CHIP:DMG: {
[1697294755.986868][32395:32397] CHIP:DMG: EndpointId = 0x0,
[1697294755.987122][32395:32397] CHIP:DMG: ClusterId = 0x3e,
[1697294755.987252][32395:32397] CHIP:DMG: CommandId = 0x1,
[1697294755.987422][32395:32397] CHIP:DMG: },
[1697294755.987568][32395:32397] CHIP:DMG:
[1697294755.987630][32395:32397] CHIP:DMG: CommandFields =
[1697294755.987749][32395:32397] CHIP:DMG: {
[1697294755.987886][32395:32397] CHIP:DMG: 0x0 = [
[1697294755.988190][32395:32397] 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
[1697294755.988352][32395:32397] CHIP:DMG: ] (583 bytes)
[1697294755.988489][32395:32397] CHIP:DMG: 0x1 = [
[1697294755.988660][32395:32397] CHIP:DMG: 0xea, 0x4a, 0xec, 0xe0, 0xfe, 0x17, 0xcd, 0xec, 0xf2, 0xd7, 0x7c, 0x36, 0x7f, 0xd3, 0x12, 0xda, 0x7d, 0x41, 0xbe, 0x6f, 0x50, 0x9f, 0x2f, 0x69, 0x22, 0xda, 0x38, 0xd7, 0x3c, 0x34, 0xfe, 0xbd, 0x18, 0x4a, 0x97, 0x43, 0xc6, 0xfa, 0x38, 0xcf, 0x08, 0x80, 0x42, 0xea, 0x6f, 0x26, 0x2f, 0xdd, 0x1e, 0x27, 0x86, 0x22, 0x43, 0x4c, 0x56, 0x1f, 0x36, 0x16, 0x50, 0x18, 0x3b, 0x5c, 0xe3, 0xf2,
[1697294755.988800][32395:32397] CHIP:DMG: ] (64 bytes)
[1697294755.988951][32395:32397] CHIP:DMG: },
[1697294755.989064][32395:32397] CHIP:DMG: },
[1697294755.989212][32395:32397] CHIP:DMG:
[1697294755.989286][32395:32397] CHIP:DMG: },
[1697294755.989405][32395:32397] CHIP:DMG:
[1697294755.989478][32395:32397] CHIP:DMG: ],
[1697294755.989548][32395:32397] CHIP:DMG:
[1697294755.989600][32395:32397] CHIP:DMG: InteractionModelRevision = 1
[1697294755.989649][32395:32397] CHIP:DMG: },
[1697294755.989801][32395:32397] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1697294755.989872][32395:32397] CHIP:CTL: Received Attestation Information from the device
[1697294755.989932][32395:32397] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest'
[1697294755.989982][32395:32397] CHIP:CTL: AutoCommissioner setting attestationElements buffer size 583/583
[1697294755.990083][32395:32397] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1697294755.990148][32395:32397] CHIP:CTL: Performing next commissioning step 'AttestationVerification'
[1697294755.990191][32395:32397] CHIP:CTL: Verifying attestation
[1697294756.017850][32395:32397] CHIP:CR: mbedTLS error: ERROR - Generic error
[1697294756.082581][32395:32397] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device.
[1697294756.082628][32395:32397] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification'
[1697294756.082648][32395:32397] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest'
[1697294756.082674][32395:32397] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest'
[1697294756.082694][32395:32397] CHIP:CTL: Sending CSR request to 0xffff7800c250 device
[1697294756.082769][32395:32397] CHIP:DMG: ICR moving to [AddingComm]
[1697294756.082798][32395:32397] CHIP:DMG: ICR moving to [AddedComma]
[1697294756.082911][32395:32397] CHIP:EM: <<< [E:8640i S:1189 M:161582299] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697294756.082950][32395:32397] CHIP:IN: (S) Sending msg 161582299 on secure session with LSID: 1189
[1697294756.083437][32395:32397] CHIP:DMG: ICR moving to [CommandSen]
[1697294756.083911][32395:32397] CHIP:CTL: Sent CSR request, waiting for the CSR
[1697294756.083988][32395:32397] CHIP:DMG: ICR moving to [AwaitingDe]
[1697294756.205891][32395:32397] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1697294757.163125][32395:32397] CHIP:BLE: BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:154: CHIP Error 0x00000032: Timeout
[1697294761.473903][32395:32396] CHIP:DL: Bluez disconnected
[1697294761.474171][32395:32396] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1697294761.474822][32395:32397] CHIP:IN: Clearing BLE pending packets.
[1697294786.107882][32395:32397] CHIP:DMG: Time out! failed to receive invoke command response from Exchange: 8640i
[1697294786.108021][32395:32397] CHIP:CTL: Device failed to receive the CSR request Response: src/app/CommandSender.cpp:248: CHIP Error 0x00000032: Timeout
[1697294786.108102][32395:32397] CHIP:CTL: Error on commissioning step 'SendOpCertSigningRequest': 'src/app/CommandSender.cpp:248: CHIP Error 0x00000032: Timeout'
[1697294786.108160][32395:32397] CHIP:CTL: Failed to perform commissioning step 9
[1697294786.108222][32395:32397] CHIP:CTL: Going from commissioning step 'SendOpCertSigningRequest' with lastErr = 'src/app/CommandSender.cpp:248: CHIP Error 0x00000032: Timeout' -> 'Cleanup'
[1697294786.108304][32395:32397] CHIP:CTL: Performing next commissioning step 'Cleanup' with completion status = 'src/app/CommandSender.cpp:248: CHIP Error 0x00000032: Timeout'
[1697294786.108362][32395:32397] CHIP:CTL: Expiring failsafe on proxy 0xffff7800c250
[1697294786.108524][32395:32397] CHIP:DMG: ICR moving to [AddingComm]
[1697294786.108600][32395:32397] CHIP:DMG: ICR moving to [AddedComma]
[1697294786.108848][32395:32397] CHIP:EM: <<< [E:8641i S:1189 M:161582300] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
[1697294786.108952][32395:32397] CHIP:IN: (S) Sending msg 161582300 on secure session with LSID: 1189
[1697294786.109024][32395:32397] CHIP:IN: Message appended to BLE send queue
[1697294786.109084][32395:32397] CHIP:DMG: ICR moving to [CommandSen]
[1697294786.109157][32395:32397] CHIP:DMG: ICR moving to [AwaitingDe]
[1697294803.126501][32395:32397] CHIP:DMG: Time out! failed to receive invoke command response from Exchange: 8641i
[1697294803.126627][32395:32397] CHIP:CTL: Received failure response when disarming failsafesrc/app/CommandSender.cpp:248: CHIP Error 0x00000032: Timeout
[1697294803.126720][32395:32397] CHIP:CTL: Successfully finished commissioning step 'Cleanup'
[1697294803.126794][32395:32397] CHIP:TOO: Device commissioning Failure: src/app/CommandSender.cpp:248: CHIP Error 0x00000032: Timeout
[1697294803.126888][32395:32397] CHIP:DIS: Closing all BLE connections
[1697294803.126937][32395:32397] CHIP:IN: SecureSession[0xffff780095a0]: MarkForEviction Type:1 LSID:1189
[1697294803.126988][32395:32397] CHIP:SC: SecureSession[0xffff780095a0]: Moving from state 'kActive' --> 'kPendingEviction'
[1697294803.127084][32395:32397] CHIP:IN: SecureSession[0xffff780095a0]: Released - Type:1 LSID:1189
[1697294803.127152][32395:32397] CHIP:DMG: ICR moving to [AwaitingDe]
[1697294803.127686][32395:32395] CHIP:CTL: Shutting down the commissioner
[1697294803.127755][32395:32395] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1697294803.127806][32395:32395] CHIP:CTL: Shutting down the controller
[1697294803.127880][32395:32395] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1697294803.127929][32395:32395] CHIP:FP: Forgetting fabric 0x1
[1697294803.127992][32395:32395] CHIP:TS: Pending Last Known Good Time: 2023-07-11T08:00:09
[1697294803.128246][32395:32395] CHIP:TS: Previous Last Known Good Time: 2023-07-11T08:00:09
[1697294803.128385][32395:32395] CHIP:TS: Reverted Last Known Good Time to previous value
[1697294803.128477][32395:32395] CHIP:CTL: Shutting down the commissioner
[1697294803.128523][32395:32395] CHIP:CTL: Stopping commissioning discovery over DNS-SD
[1697294803.128591][32395:32395] CHIP:CTL: Shutting down the controller
[1697294803.128633][32395:32395] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1697294803.131255][32395:32395] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1697294803.131674][32395:32395] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented.
[1697294803.131809][32395:32395] CHIP:FP: Shutting down FabricTable
[1697294803.131886][32395:32395] CHIP:TS: Pending Last Known Good Time: 2023-07-11T08:00:09
[1697294803.132173][32395:32395] CHIP:TS: Previous Last Known Good Time: 2023-07-11T08:00:09
[1697294803.132252][32395:32395] CHIP:TS: Reverted Last Known Good Time to previous value
[1697294803.133031][32395:32395] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-u1eVY2)
[1697294803.135209][32395:32395] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1697294803.135497][32395:32395] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1697294803.135569][32395:32395] CHIP:DL: Inet Layer shutdown
[1697294803.135619][32395:32395] CHIP:DL: BLE shutdown
[1697294803.136932][32395:32395] CHIP:DL: System Layer shutdown
[1697294803.137641][32395:32395] CHIP:TOO: Run command failure: src/app/CommandSender.cpp:248: CHIP Error 0x00000032: Timeout
The terminal output (last commands):
D: 147125 [DIS]Responding with EFDF42FFEF35D1D6._matterc._udp.local
I: 147131 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: EFDF42FFEF35D1D6.
I: 147141 [DIS]mDNS service published: _matterc._udp
D: 147146 [DIS]Scheduling extended discovery timeout in 900s
D: 147151 [DL]CHIPoBLE advertising set to off
I: 147155 [SVR]Device completed Rendezvous process
E: 147160 [DL]Long dispatch time: 170 ms, for event type 16388
D: 147165 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 147174 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 147182 [EM]>>> [E:8634r S:33323 M:161582293] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest)
D: 147193 [IM]Received Read request
I: 147201 [EM]<<< [E:8634r S:33323 M:169693654] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
I: 147212 [IN](S) Sending msg 169693654 on secure session with LSID: 33323
D: 147218 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 147350 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 147358 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 21)
D: 147530 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 147576 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 147584 [EM]>>> [E:8635r S:33323 M:161582294] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 147596 [FS]GeneralCommissioning: Received ArmFailSafe (60s)
I: 147602 [EM]<<< [E:8635r S:33323 M:169693655] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 147614 [IN](S) Sending msg 169693655 on secure session with LSID: 33323
D: 147621 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 147755 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 147763 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 147771 [EM]>>> [E:8636r S:33323 M:161582295] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 147785 [EM]<<< [E:8636r S:33323 M:169693656] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 147796 [IN](S) Sending msg 169693656 on secure session with LSID: 33323
D: 147803 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 71)
D: 148160 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 148168 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 148176 [EM]>>> [E:8637r S:33323 M:161582296] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 148188 [ZCL]OpCreds: Certificate Chain request received for PAI
I: 148198 [EM]<<< [E:8637r S:33323 M:169693657] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 148209 [IN](S) Sending msg 169693657 on secure session with LSID: 33323
D: 148216 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 148520 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 148528 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 148610 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 148618 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 48)
D: 148835 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 148843 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 148851 [EM]>>> [E:8638r S:33323 M:161582297] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 148863 [ZCL]OpCreds: Certificate Chain request received for DAC
I: 148873 [EM]<<< [E:8638r S:33323 M:169693658] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 148884 [IN](S) Sending msg 169693658 on secure session with LSID: 33323
D: 148891 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 149285 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 149293 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 149420 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 149428 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 77)
D: 149735 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 149781 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 149789 [EM]>>> [E:8639r S:33323 M:161582298] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 149801 [ZCL]OpCreds: Received an AttestationRequest command
I: 149836 [ZCL]OpCreds: AttestationRequest successful.
I: 149845 [EM]<<< [E:8639r S:33323 M:169693659] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 149856 [IN](S) Sending msg 169693659 on secure session with LSID: 33323
D: 149863 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 150185 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 150193 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
D: 151715 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 151722 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 235)
D: 151850 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x00)
D: 151940 [DL]Write request received for CHIPoBLE RX characteristic (ConnId 0x00)
I: 151949 [EM]>>> [E:8640r S:33323 M:161582299] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest)
I: 151961 [ZCL]OpCreds: Received a CSRRequest command
I: 152108 [ZCL]OpCreds: AllocatePendingOperationalKey succeeded
I: 152142 [ZCL]OpCreds: CSRRequest successful.
I: 152149 [EM]<<< [E:8640r S:33323 M:169693660] (S) Msg TX to 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
I: 152160 [IN](S) Sending msg 169693660 on secure session with LSID: 33323
D: 152167 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 244)
E: 152175 [DL]Long dispatch time: 235 ms, for event type 16388
D: 162336 [DL]Indication for CHIPoBLE TX characteristic done (ConnId 0x00, result 0x0e)
D: 162344 [DL]Sending indication for CHIPoBLE TX characteristic (ConnId 00, len 138)
E: 162352 [DL]BLEManagerImpl::SendIndication() failed: 2000080
D: 162357 [IN]Clearing BLE pending packets.
I: 162361 [BLE]Releasing end point's BLE connection back to application.
I: 162368 [DL]Closing BLE GATT connection (ConnId 00)
E: 162372 [BLE]endpoint conf recvd failed, err = 408
I: 162377 [DL]BLE GAP connection terminated (reason 0x08)
I: 162382 [DL]Current number of connections: 0/1
I: 207601 [FS]Fail-safe timer expired
E: 207604 [SVR]Failsafe timer expired
D: 207608 [IN]SecureSession[0x200041c8]: MarkForEviction Type:1 LSID:33323
I: 207614 [SC]SecureSession[0x200041c8]: Moving from state 'kActive' --> 'kPendingEviction'
D: 207623 [IN]SecureSession[0x200041c8]: Released - Type:1 LSID:33323
E: 207629 [SVR]Commissioning failed (attempt 1): 32
D: 207635 [IN]SecureSession[0x200041c8]: Allocated Type:1 LSID:33325
D: 207641 [DL]CHIPoBLE advertising set to on
I: 207645 [DIS]Updating services using commissioning mode 1
I: 207651 [DIS]CHIP minimal mDNS started advertising.
D: 207656 [DL]Using wifi MAC for hostname
I: 207660 [DIS]Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 cm=1
D: 207669 [DIS]Responding with _matterc._udp.local
D: 207674 [DIS]Responding with EFDF42FFEF35D1D6._matterc._udp.local
D: 207680 [DIS]Responding with F4CE36001F4A.local
D: 207684 [DIS]Responding with F4CE36001F4A.local
D: 207689 [DIS]Responding with _V65521._sub._matterc._udp.local
D: 207694 [DIS]Responding with _S15._sub._matterc._udp.local
D: 207700 [DIS]Responding with _L3840._sub._matterc._udp.local
D: 207706 [DIS]Responding with _CM._sub._matterc._udp.local
D: 207711 [DIS]Responding with EFDF42FFEF35D1D6._matterc._udp.local
I: 207717 [DIS]CHIP minimal mDNS configured as 'Commissionable node device'; instance name: EFDF42FFEF35D1D6.
I: 207727 [DIS]mDNS service published: _matterc._udp
E: 207731 [ZCL]OpCreds: Got FailSafeTimerExpired
E: 207736 [ZCL]OpCreds: Proceeding to FailSafeCleanup on fail-safe expiry!
I: 207743 [TS]Pending Last Known Good Time: 2023-10-14T13:14:12
I: 207749 [TS]Previous Last Known Good Time: 2023-10-14T13:14:12
I: 207754 [TS]Reverted Last Known Good Time to previous value
E: 207760 [DL]Long dispatch time: 156 ms, for event type 32782
I: 207766 [FS]Fail-safe cleanly disarmed
I: 207773 [DL]CHIPoBLE advertising started
I: 207777 [DL]NFC Tag emulation started
I: 237776 [DL]CHIPoBLE advertising mode changed to slow
I: 237785 [DL]CHIPoBLE advertising started
