wiced_platform_bt_management_callback: event(21). wiced_platform_application_thread_handler ChipLighting App starting Initializing CHIP PrgA CHIP:DL: BLEManagerImpl::Init() complete Initializing OpenThread stack PrgA CHIP:DL: OpenThread started: OK PrgA CHIP:DL: Setting OpenThread device type to MINIMAL END DEVICE Starting event loop task Starting thread task DtlT CHIP:DL: Thread task running DtlM CHIP:DL: CHIP task running DtlM CHIP:DL: Free RAM sizes: 175284 PrgM CHIP:DL: CHIPoBLE advertising started PrgM CHIP:DL: SetAdvertisingData: device name set: MATTER-3840 PrgM CHIP:DL: SetAdvertisingData: RPA: 466FA71E0A95 PrgM CHIP:DL: BLEManagerImpl::SetAdvertisingData err:0 Advertisement State Change: 3 PrgM CHIP:DL: Device Configuration: PrgM CHIP:DL: Serial Number: (not set) PrgM CHIP:DL: Vendor Id: 65521 (0xFFF1) PrgM CHIP:DL: Product Id: 32773 (0x8005) PrgM CHIP:DL: Hardware Version: 30739 PrgM CHIP:DL: Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 PrgM CHIP:DL: Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) PrgM CHIP:DL: Manufacturing Date: (not set) PrgM CHIP:DL: Device Type: 65535 (0xFFFF) PrgM CHIP:SVR: Server initializing... DtlM CHIP:FP: Initializing FabricTable from persistent storage PrgM CHIP:TS: Last Known Good Time: [unknown] PrgM CHIP:TS: Setting Last Known Good Time to firmware build time 2022-07-07T15:59:16 PrgM CHIP:DMG: AccessControl: initializing PrgM CHIP:DMG: Examples::AccessControlDelegate::Init PrgM CHIP:DMG: AccessControl: setting PrgM CHIP:DMG: DefaultAclStorage: initializing PrgM CHIP:DMG: DefaultAclStorage: 0 entries loaded PrgM CHIP:ZCL: Using ZAP configuration... DtlM CHIP:DMG: Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: a0 DtlM CHIP:DMG: Failed to read stored attribute (0, 0x0000_0028, 0x0000_0010: a0 DtlM CHIP:DMG: Failed to read stored attribute (0, 0x0000_002B, 0x0000_0000: a0 DtlM CHIP:DMG: Failed to read stored attribute (0, 0x0000_002C, 0x0000_0000: a0 DtlM CHIP:DMG: Failed to read stored attribute (0, 0x0000_002C, 0x0000_0001: a0 DtlM CHIP:DMG: Failed to read stored attribute (1, 0x0000_0006, 0x0000_0000: a0 DtlM CHIP:DMG: Failed to read stored attribute (1, 0x0000_0006, 0x0000_4003: a0 DtlM CHIP:DMG: Failed to read stored attribute (1, 0x0000_0008, 0x0000_0000: a0 DtlM CHIP:DMG: Failed to read stored attribute (1, 0x0000_0008, 0x0000_4000: a0 PrgM CHIP:DMG: AccessControlCluster: initializing DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 38b78231 Unhandled cluster ID: 0x0030 DtlM CHIP:ZCL: GeneralDiagnostics: OnDeviceReboot DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_0033 update version to 1c529b72 ErrM CHIP:ZCL: GeneralDiagnostics: Failed to record BootReason event: 3 PrgM CHIP:ZCL: Initiating Admin Commissioning cluster. DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_0004 update version to 4c63e30a Unhandled cluster ID: 0x0004 ErrM CHIP:ZCL: DeviceInfoProvider is not registered ErrM CHIP:ZCL: Trying to write invalid Calendar Type ErrM CHIP:ZCL: Failed to write calendar type with error: 0x87 DtlM CHIP:DMG: Endpoint 1, Cluster 0x0000_0003 update version to a0ed9893 ERROR clusterId: 0x0003, unknown attribute ID: 0x0001 DtlM CHIP:DMG: Endpoint 1, Cluster 0x0000_0004 update version to 28ba42d5 Unhandled cluster ID: 0x0004 PrgM CHIP:ZCL: On/Off set value: 1 0 PrgM CHIP:ZCL: On/off already set to new value DtlM CHIP:DMG: Endpoint 1, Cluster 0x0000_0008 update version to 4430c8f4 ZCL CurrentLevel -> 1 DtlM CHIP:DMG: Endpoint 1, Cluster 0x0000_0300 update version to a6243224 Unhandled cluster ID: 0x0300 DtlM CHIP:DMG: Endpoint 1, Cluster 0x0000_0300 update version to a6243225 Unhandled cluster ID: 0x0300 DtlM CHIP:DMG: Endpoint 1, Cluster 0x0000_0300 update version to a6243226 Unhandled cluster ID: 0x0300 DtlM CHIP:DMG: Endpoint 1, Cluster 0x0000_0406 update version to 20909a Unhandled cluster ID: 0x0406 DtlM CHIP:DMG: Endpoint 1, Cluster 0x0000_0406 update version to 20909b Unhandled cluster ID: 0x0406 DtlM CHIP:IN: UDP::Init bind&listen port=5540 DtlM CHIP:IN: UDP::Init bound to port=5540 DtlM CHIP:IN: BLEBase::Init - setting/overriding transport DtlM CHIP:IN: TransportMgr initialized DtlM CHIP:DL: Using Thread extended MAC for hostname. DtlM CHIP:IN: SecureSession[00226ed8]: Allocated Type:1 LSID:30627 DtlM CHIP:SC: Assigned local session key ID 30627 DtlM CHIP:SC: Waiting for PBKDF param request PrgM CHIP:DIS: Updating services using commissioning mode 1 DtlM CHIP:DL: Using Thread extended MAC for hostname. DtlM CHIP:DL: Using Thread extended MAC for hostname. PrgM CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 ErrM CHIP:DIS: Failed to advertise commissionable node: 3 ErrM CHIP:DIS: Failed to finalize service update: 1c PrgM CHIP:DIS: Updating services using commissioning mode 1 DtlM CHIP:DL: Using Thread extended MAC for hostname. DtlM CHIP:DL: Using Thread extended MAC for hostname. PrgM CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 ErrM CHIP:DIS: Failed to advertise commissionable node: 3 ErrM CHIP:DIS: Failed to finalize service update: 1c PrgM CHIP:DIS: Delaying proxy of operational discovery: missing delegate PrgM CHIP:IN: CASE Server enabling CASE session setups DtlM CHIP:IN: SecureSession[00226f90]: Allocated Type:2 LSID:30628 DtlM CHIP:SC: Allocated SecureSession (00226f90) - waiting for Sigma1 msg DtlM CHIP:ZCL: Emitting StartUp event DtlM CHIP:EVL: LogEvent event number: 0x0000000000000000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x0000000000418B21 PrgM CHIP:SVR: Server Listening... DtlM CHIP:DMG: Endpoint 1, Cluster 0x0000_0008 update version to 4430c8f5 ZCL CurrentLevel -> 254 Set light level = 254 ErrM CHIP:DL: Long dispatch time: 306 ms, for event type 2 DtlM CHIP:DL: OpenThread State Changed (Flags: 0x00038200) DtlM CHIP:DL: Network Name: OpenThread DtlM CHIP:DL: PAN Id: 0xFFFF DtlM CHIP:DL: Extended PAN Id: 0xDEAD00BEEF00CAFE DtlM CHIP:DL: Channel: 11 DtlM CHIP:DL: Mesh Prefix: fdde:ad00:beef:0:0:0:0:0/64 ErrA CHIP:DL: Failed to find CHIPoBLEConState PrgA CHIP:DL: BLE GATT connection up (con 1) Advertisement State Change: 0 Advertisement State BTM_BLE_ADVERT_OFF PrgA CHIP:DL: GATT Read handler: conn_id:0001 handle:0003 len:11 PrgA CHIP:DL: GATT Read handler: conn_id:0001 handle:0005 len:2 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 9 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:BLE: local and remote recv window sizes = 6 PrgM CHIP:BLE: selected BTP version 4 PrgM CHIP:BLE: using BTP fragment sizes rx 244 / tx 244. DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con:0001 handle:000c len:2 PrgA CHIP:DL: CHIPoBLE subscribe received DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 6) DtlM CHIP:IN: BLE EndPoint 0022a120 Connection Complete DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 84 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x20 with protocolId (0, 0) and MessageCounter:220996869 on exchange 20330r DtlM CHIP:EM: Handling via exchange: 20330r, Delegate: 002293c4 DtlM CHIP:SC: Received PBKDF param request DtlM CHIP:SC: Peer assigned session ID 20324 DtlM CHIP:SC: Found MRP parameters in the message DtlM CHIP:SC: Including MRP parameters in PBKDF param response PrgM CHIP:IN: Prepared unauthenticated message 0023d000 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 20330r with MessageCounter:227768852. PrgM CHIP:IN: Sending unauthenticated msg 0023d000 with MessageCounter:227768852 to 0x0000000000000000 at monotonic time: 000000000041DDEC msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 140) DtlM CHIP:SC: Sent PBKDF param response DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 97 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x22 with protocolId (0, 0) and MessageCounter:220996870 on exchange 20330r DtlM CHIP:EM: Found matching exchange: 20330r, Delegate: 002293c4 DtlM CHIP:SC: Received spake2p msg1 PrgM CHIP:IN: Prepared unauthenticated message 0023cf90 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 20330r with MessageCounter:227768853. PrgM CHIP:IN: Sending unauthenticated msg 0023cf90 with MessageCounter:227768853 to 0x0000000000000000 at monotonic time: 000000000041E5A8 msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 132) DtlM CHIP:SC: Sent spake2p msg2 ErrM CHIP:DL: Long dispatch time: 1792 ms, for event type 7 DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 64 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x24 with protocolId (0, 0) and MessageCounter:220996871 on exchange 20330r DtlM CHIP:EM: Found matching exchange: 20330r, Delegate: 002293c4 DtlM CHIP:SC: Received spake2p msg3 DtlM CHIP:SC: Sending status report. Protocol code 0, exchange 20330 PrgM CHIP:IN: Prepared unauthenticated message 0023d018 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 20330r with MessageCounter:227768854. PrgM CHIP:IN: Sending unauthenticated msg 0023d018 with MessageCounter:227768854 to 0x0000000000000000 at monotonic time: 000000000041E64B msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 35) PrgM CHIP:SC: SecureSession[00226ed8]: Moving from state 'kEstablishing' --> 'kActive' DtlM CHIP:IN: SecureSession[00226ed8]: Activated - Type:1 LSID:30627 DtlM CHIP:IN: New secure session activated for device , LSID:30627 PSID:20324! PrgM CHIP:SVR: Commissioning completed session establishment step PrgM CHIP:DIS: Updating services using commissioning mode 0 DtlM CHIP:DL: Using Thread extended MAC for hostname. DtlM CHIP:DL: Using Thread extended MAC for hostname. PrgM CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 ErrM CHIP:DIS: Failed to advertise extended commissionable node: 3 DtlM CHIP:DIS: Scheduling extended discovery timeout in 900s ErrM CHIP:DIS: Failed to finalize service update: 1c PrgM CHIP:SVR: Device completed Rendezvous process PrgM CHIP:DL: CHIPoBLE stop advertising Advertisement State Change: 0 Advertisement State BTM_BLE_ADVERT_OFF DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 128 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:81080689 on exchange 20331r DtlM CHIP:EM: Handling via exchange: 20331r, Delegate: 0021f43c DtlM CHIP:IM: Received Read request DtlM CHIP:DMG: IM RH moving to [GeneratingReports] DtlM CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 DtlM CHIP:DMG: Cluster 31, Attribute 3 is dirty DtlM CHIP:DMG: Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) DtlM CHIP:DMG: Cluster 28, Attribute 4 is dirty DtlM CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) DtlM CHIP:DMG: Cluster 28, Attribute 2 is dirty DtlM CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) DtlM CHIP:DMG: Cluster 30, Attribute 3 is dirty DtlM CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) DtlM CHIP:DMG: Cluster 30, Attribute 2 is dirty DtlM CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) DtlM CHIP:DMG: Cluster 30, Attribute 1 is dirty DtlM CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) DtlM CHIP:DMG: Cluster 30, Attribute 0 is dirty DtlM CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0) DtlM CHIP:DMG: Cluster 31, Attribute fffc is dirty DtlM CHIP:DMG: Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) DtlM CHIP:DMG: Sending report (payload has 228 bytes)... PrgM CHIP:IN: Prepared secure message 0023d188 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 20331r with MessageCounter:104862476. PrgM CHIP:IN: Sending encrypted msg 0023d188 with MessageCounter:104862476 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000041E6BE msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 244) DtlM CHIP:DMG: OnReportConfirm: NumReports = 0 DtlM CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages DtlM CHIP:DMG: IM RH moving to [AwaitingDestruction] DtlM CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 21) DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 70 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080690 on exchange 20332r DtlM CHIP:EM: Handling via exchange: 20332r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 PrgM CHIP:FS: GeneralCommissioning: Received ArmFailSafe (60s) DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 38b78232 Unhandled cluster ID: 0x0030 DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d070 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 20332r with MessageCounter:104862477. PrgM CHIP:IN: Sending encrypted msg 0023d070 with MessageCounter:104862477 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000041E836 msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 71) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 75 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080691 on exchange 20333r DtlM CHIP:EM: Handling via exchange: 20333r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 38b78233 Unhandled cluster ID: 0x0030 DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d070 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 20333r with MessageCounter:104862478. PrgM CHIP:IN: Sending encrypted msg 0023d070 with MessageCounter:104862478 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000041E89A msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 71) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 67 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080692 on exchange 20334r DtlM CHIP:EM: Handling via exchange: 20334r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 PrgM CHIP:ZCL: OpCreds: Certificate Chain request received for PAI DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d070 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 20334r with MessageCounter:104862479. PrgM CHIP:IN: Sending encrypted msg 0023d070 with MessageCounter:104862479 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000041E8F9 msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 244) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 244) DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 48) DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 67 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080693 on exchange 20335r DtlM CHIP:EM: Handling via exchange: 20335r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 PrgM CHIP:ZCL: OpCreds: Certificate Chain request received for DAC DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d070 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 20335r with MessageCounter:104862480. PrgM CHIP:IN: Sending encrypted msg 0023d070 with MessageCounter:104862480 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000041EA7F msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 244) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 244) DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 77) DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 99 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080694 on exchange 20336r DtlM CHIP:EM: Handling via exchange: 20336r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 PrgM CHIP:ZCL: OpCreds: Received an AttestationRequest command PrgM CHIP:ZCL: OpCreds: AttestationRequest successful. DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d070 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 20336r with MessageCounter:104862481. PrgM CHIP:IN: Sending encrypted msg 0023d070 with MessageCounter:104862481 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000041EDD0 msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 244) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] ErrM CHIP:DL: Long dispatch time: 370 ms, for event type 7 DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 244) DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 237) DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 99 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080695 on exchange 20337r DtlM CHIP:EM: Handling via exchange: 20337r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 PrgM CHIP:ZCL: OpCreds: Received a CSRRequest command DtlM CHIP:ZCL: OpCreds: Finding fabric with fabricIndex 0x0 PrgM CHIP:ZCL: OpCreds: AllocatePendingOperationalKey succeeded PrgM CHIP:ZCL: OpCreds: CSRRequest successful. DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d070 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 20337r with MessageCounter:104862482. PrgM CHIP:IN: Sending encrypted msg 0023d070 with MessageCounter:104862482 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000041F3AD msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 244) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] ErrM CHIP:DL: Long dispatch time: 1091 ms, for event type 7 DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 139) DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 244 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 56 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080696 on exchange 20338r DtlM CHIP:EM: Handling via exchange: 20338r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B PrgM CHIP:ZCL: OpCreds: Received an AddTrustedRootCertificate command PrgM CHIP:ZCL: OpCreds: AddTrustedRootCertificate successful. DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d070 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 20338r with MessageCounter:104862483. PrgM CHIP:IN: Sending encrypted msg 0023d070 with MessageCounter:104862483 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000041F58A msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 68) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 244 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 244 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 87 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080697 on exchange 20339r DtlM CHIP:EM: Handling via exchange: 20339r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 PrgM CHIP:ZCL: OpCreds: Received an AddNOC command PrgM CHIP:FP: Validating NOC chain PrgM CHIP:FP: NOC chain validation successful PrgM CHIP:FP: Added new fabric at index: 0x1 PrgM CHIP:FP: Assigned compressed fabric ID: 0xA4A2E578C9A5C677, node ID: 0x0000000000000014 PrgM CHIP:TS: Last Known Good Time: 2022-07-07T15:59:16 PrgM CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 PrgM CHIP:TS: Retaining current Last Known Good Time DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 1bd8a691 DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 1bd8a692 DtlM CHIP:EVL: LogEvent event number: 0x0000000000000001 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x000000000041FD2A PrgM CHIP:ZCL: OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669 DtlM CHIP:DL: Using Thread extended MAC for hostname. PrgM CHIP:DIS: Advertise operational node A4A2E578C9A5C677-0000000000000014 DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 1bd8a693 DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 1bd8a694 DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] PrgM CHIP:ZCL: OpCreds: successfully created fabric index 0x1 via AddNOC DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d070 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 20339r with MessageCounter:104862484. PrgM CHIP:IN: Sending encrypted msg 0023d070 with MessageCounter:104862484 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000041FD31 msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 71) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] ErrM CHIP:DL: Long dispatch time: 1530 ms, for event type 7 DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 175 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080698 on exchange 20340r DtlM CHIP:EM: Handling via exchange: 20340r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0003 DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 38b78234 Unhandled cluster ID: 0x0030 DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d070 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 20340r with MessageCounter:104862485. PrgM CHIP:IN: Sending encrypted msg 0023d070 with MessageCounter:104862485 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000041FD8E msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 71) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 78 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:81080699 on exchange 20341r DtlM CHIP:EM: Handling via exchange: 20341r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 ErrM CHIP:DL: _Get ReadConfigValueBin Error Device Layer:0x000002 DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 1 ErrM CHIP:DL: Long dispatch time: 150 ms, for event type 7 DtlM CHIP:DL: OpenThread State Changed (Flags: 0x1017c100) DtlM CHIP:DL: Network Name: OpenThreadDemo DtlM CHIP:DL: PAN Id: 0x1234 DtlM CHIP:DL: Extended PAN Id: 0x1111111122222222 DtlM CHIP:DL: Channel: 15 DtlM CHIP:DL: Mesh Prefix: fd2e:2f57:f702:e16e:0:0:0:0/64 ErrM CHIP:DL: Long dispatch time: 153 ms, for event type 3 DtlM CHIP:DL: OpenThread State Changed (Flags: 0x1100101d) DtlM CHIP:DL: Device Role: DETACHED DtlM CHIP:DL: Thread Unicast Addresses: DtlM CHIP:DL: fd2e:2f57:f702:e16e:5fdd:e7f2:722e:ea3e/64 valid DtlM CHIP:DL: fe80:0:0:0:4412:fab3:b85d:e883/64 valid preferred ErrM CHIP:DL: Long dispatch time: 153 ms, for event type 3 PrgT CHIP:DL: SRP Client was started, detected server: fd2e:2f57:f702:e16e:eaa2:6ac0:3dda:9334 DtlM CHIP:DL: OpenThread State Changed (Flags: 0x200002a4) DtlM CHIP:DL: Device Role: CHILD DtlM CHIP:DL: Partition Id: 0x7F045A43 ErrM CHIP:DL: Long dispatch time: 751 ms, for event type 32777 ErrM CHIP:DL: Long dispatch time: 101 ms, for event type 3 DtlM CHIP:DL: Thread Attached updating Multicast address PrgM CHIP:SVR: Joining Multicast groups DtlM CHIP:DL: OpenThread State Changed (Flags: 0x00000001) DtlM CHIP:DL: Thread Unicast Addresses: DtlM CHIP:DL: fd11:22:0:0:d8d5:666c:2d87:2fd1/64 valid preferred DtlM CHIP:DL: fd2e:2f57:f702:e16e:0:ff:fe00:740e/64 valid rloc DtlM CHIP:DL: fd2e:2f57:f702:e16e:5fdd:e7f2:722e:ea3e/64 valid DtlM CHIP:DL: fe80:0:0:0:4412:fab3:b85d:e883/64 valid preferred DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 38b78235 Unhandled cluster ID: 0x0030 DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 PrgM CHIP:IN: Prepared secure message 0023d270 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 20341r with MessageCounter:104862486. PrgM CHIP:IN: Sending encrypted msg 0023d270 with MessageCounter:104862486 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000042064D msec DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 70) DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] DtlM CHIP:DL: Using Thread extended MAC for hostname. PrgM CHIP:DIS: Advertise operational node A4A2E578C9A5C677-0000000000000014 PrgM CHIP:SVR: Operational advertising enabled DtlT CHIP:DL: SRP update succeeded PrgT CHIP:DIS: Setting operational delegate post init PrgM CHIP:DIS: Updating services using commissioning mode 0 DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Using Thread extended MAC for hostname. PrgM CHIP:DIS: Advertise operational node A4A2E578C9A5C677-0000000000000014 PrgM CHIP:DL: advertising srp service: A4A2E578C9A5C677-0000000000000014._matter._tcp DtlM CHIP:DL: Using Thread extended MAC for hostname. PrgM CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 PrgM CHIP:DL: advertising srp service: E30BEF95DFD2EFD8._matterc._udp ErrM CHIP:DL: Long dispatch time: 977 ms, for event type 32784 DtlT CHIP:IN: UDP Message Received packet nb : 1 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[44406] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 177 PrgM CHIP:EM: Received message of type 0x30 with protocolId (0, 0) and MessageCounter:220996872 on exchange 20342r DtlM CHIP:EM: Handling via exchange: 20342r, Delegate: 00227b48 PrgM CHIP:IN: CASE Server received Sigma1 message. Starting handshake. EC 00228748 PrgM CHIP:IN: CASE Server disabling CASE session setups DtlM CHIP:EM: Sending Standalone Ack for MessageCounter:220996872 on exchange 20342r PrgM CHIP:IN: Prepared unauthenticated message 0023d078 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 20342r with MessageCounter:227768855. PrgM CHIP:IN: Sending unauthenticated msg 0023d078 with MessageCounter:227768855 to 0x0000000000000000 at monotonic time: 0000000000420F2A msec DtlM CHIP:EM: Flushed pending ack for MessageCounter:220996872 on exchange 20342r PrgM CHIP:SC: Received Sigma1 msg DtlM CHIP:SC: Found MRP parameters in the message DtlM CHIP:SC: Peer assigned session key ID 20325 PrgM CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000014 DtlT CHIP:DL: SRP update succeeded DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con 0001 len 3 DtlM CHIP:SC: Including MRP parameters DtlM CHIP:EM: Piggybacking Ack for MessageCounter:220996872 on exchange: 20342r PrgM CHIP:IN: Prepared unauthenticated message 00228c7c to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 20342r with MessageCounter:227768856. PrgM CHIP:IN: Sending unauthenticated msg 00228c7c with MessageCounter:227768856 to 0x0000000000000000 at monotonic time: 00000000004213B1 msec PrgM CHIP:SC: Sent Sigma2 msg ErrM CHIP:DL: Long dispatch time: 1184 ms, for event type 3 PrgM CHIP:DL: _OnPlatformEvent kCHIPoBLEWriteReceived DtlM CHIP:EM: Retransmitting MessageCounter:227768856 on exchange 20342r Send Cnt 1 PrgM CHIP:IN: Sending unauthenticated msg 00228c7c with MessageCounter:227768856 to 0x0000000000000000 at monotonic time: 00000000004214F8 msec DtlT CHIP:IN: UDP Message Received packet nb : 2 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[44406] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 598 PrgM CHIP:EM: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:220996873 on exchange 20342r DtlM CHIP:EM: Found matching exchange: 20342r, Delegate: 00227b64 DtlM CHIP:EM: Rxd Ack; Removing MessageCounter:227768856 from Retrans Table on exchange 20342r DtlM CHIP:EM: Removed CHIP MessageCounter:227768856 from RetransTable on exchange 20342r DtlM CHIP:EM: Sending Standalone Ack for MessageCounter:220996873 on exchange 20342r PrgM CHIP:IN: Prepared unauthenticated message 0023d060 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 20342r with MessageCounter:227768857. PrgM CHIP:IN: Sending unauthenticated msg 0023d060 with MessageCounter:227768857 to 0x0000000000000000 at monotonic time: 000000000042162E msec DtlM CHIP:EM: Flushed pending ack for MessageCounter:220996873 on exchange 20342r PrgM CHIP:SC: Received Sigma3 msg ErrM CHIP:SC: The device does not support GetClock_RealTimeMS() API: 6c. Falling back to Last Known Good UTC Time DtlT CHIP:IN: UDP Message Received packet nb : 3 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[44406] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 598 DtlT CHIP:IN: UDP Message Received packet nb : 4 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[44406] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 26 ErrM CHIP:SC: Unable to save session resumption state: 2f DtlM CHIP:SC: Sending status report. Protocol code 0, exchange 20342 DtlM CHIP:EM: Piggybacking Ack for MessageCounter:220996873 on exchange: 20342r PrgM CHIP:IN: Prepared unauthenticated message 00228c7c to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 20342r with MessageCounter:227768858. PrgM CHIP:IN: Sending unauthenticated msg 00228c7c with MessageCounter:227768858 to 0x0000000000000000 at monotonic time: 0000000000421F2F msec PrgM CHIP:SC: SecureSession[00226f90]: Moving from state 'kEstablishing' --> 'kActive' DtlM CHIP:IN: SecureSession[00226f90]: Activated - Type:2 LSID:30628 DtlM CHIP:IN: New secure session activated for device <000000000001B669, 1>, LSID:30628 PSID:20325! PrgM CHIP:IN: CASE Session established to peer: <000000000001B669, 1> PrgM CHIP:IN: CASE Server enabling CASE session setups DtlM CHIP:IN: SecureSession[00227048]: Allocated Type:2 LSID:30629 DtlM CHIP:SC: Allocated SecureSession (00227048) - waiting for Sigma1 msg ErrM CHIP:DL: Long dispatch time: 2319 ms, for event type 3 DtlM CHIP:DL: Sending indication for CHIPoBLE TX characteristic (con 1, len 3) DtlM CHIP:IN: Received a duplicate message with MessageCounter:220996873 on exchange 20342r PrgM CHIP:EM: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:220996873 on exchange 20342r DtlM CHIP:EM: Found matching exchange: 20342r, Delegate: 00000000 DtlM CHIP:EM: Forcing tx of solitary ack for duplicate MessageCounter:220996873 on exchange 20342r DtlM CHIP:EM: Sending Standalone Ack for MessageCounter:220996873 on exchange 20342r PrgM CHIP:IN: Prepared unauthenticated message 0023d060 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 20342r with MessageCounter:227768859. PrgM CHIP:IN: Sending unauthenticated msg 0023d060 with MessageCounter:227768859 to 0x0000000000000000 at monotonic time: 0000000000421F3E msec PrgM CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:220996874 on exchange 20342r DtlM CHIP:EM: Found matching exchange: 20342r, Delegate: 00000000 DtlM CHIP:EM: CHIP MessageCounter:227768856 not in RetransTable on exchange 20342r DtlT CHIP:IN: UDP Message Received packet nb : 5 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[44406] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 59 PrgM CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:75635293 on exchange 20343r DtlM CHIP:EM: Handling via exchange: 20343r, Delegate: 0021f43c DtlM CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 PrgM CHIP:FS: GeneralCommissioning: Received CommissioningComplete PrgM CHIP:FP: Metadata for Fabric 0x1 persisted to storage. DtlT CHIP:IN: UDP Message Received packet nb : 6 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[44406] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 26 PrgM CHIP:TS: Committing Last Known Good Time to storage: 2022-07-07T15:59:16 PrgM CHIP:ZCL: OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0xA4A2E578C9A5C677, FabricId 0000000000000001, NodeId 0000000000000014, VendorId 0xFFF1 PrgM CHIP:FS: GeneralCommissioning: Successfully commited pending fabric data PrgM CHIP:FS: Fail-safe cleanly disarmed DtlM CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 38b78236 Unhandled cluster ID: 0x0030 DtlM CHIP:DMG: ICR moving to [ Preparing] DtlM CHIP:DMG: ICR moving to [AddingComm] DtlM CHIP:DMG: ICR moving to [AddedComma] DtlM CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 DtlM CHIP:EM: Piggybacking Ack for MessageCounter:75635293 on exchange: 20343r PrgM CHIP:IN: Prepared secure message 00228c94 to 0x000000000001B669 (1) of type 0x9 and protocolId (0, 1) on exchange 20343r with MessageCounter:166448080. PrgM CHIP:IN: Sending encrypted msg 00228c94 with MessageCounter:166448080 to 0x000000000001B669 (1) at monotonic time: 0000000000421FF2 msec DtlM CHIP:DMG: ICR moving to [CommandSen] DtlM CHIP:DMG: ICR moving to [AwaitingDe] PrgM CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:220996875 on exchange 20342r DtlM CHIP:EM: Found matching exchange: 20342r, Delegate: 00000000 DtlM CHIP:EM: Rxd Ack; Removing MessageCounter:227768858 from Retrans Table on exchange 20342r DtlM CHIP:EM: Removed CHIP MessageCounter:227768858 from RetransTable on exchange 20342r PrgM CHIP:SVR: Commissioning completed successfully PrgM CHIP:DIS: Updating services using commissioning mode 0 DtlM CHIP:DL: Using Thread extended MAC for hostname. PrgM CHIP:DIS: Advertise operational node A4A2E578C9A5C677-0000000000000014 DtlA CHIP:DL: GATT Ind Cfm received con:0001 handle:11 DtlM CHIP:DL: Using Thread extended MAC for hostname. PrgM CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32773 discriminator=3840/15 DtlT CHIP:IN: UDP Message Received packet nb : 7 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[44406] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 34 DtlA CHIP:DL: Write received for CHIPoBLE RX characteristic con:0001 handle:000c len:2 PrgA CHIP:DL: CHIPoBLE unsubscribe received DtlM CHIP:IN: Expiring all PASE pairings DtlM CHIP:IN: SecureSession[00226ed8]: MarkForEviction Type:1 LSID:30627 PrgM CHIP:SC: SecureSession[00226ed8]: Moving from state 'kActive' --> 'kPendingEviction' DtlM CHIP:IN: SecureSession[00226ed8]: Released - Type:1 LSID:30627 DtlM CHIP:IN: Clearing BLE pending packets. PrgM CHIP:BLE: Releasing end point's BLE connection back to application. DtlM CHIP:ZCL: Commissioning complete, notify platform driver to persist network credentials. ErrM CHIP:DL: Long dispatch time: 225 ms, for event type 32781 ErrM CHIP:BLE: no endpoint for BLE sent data ack PrgM CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:75635294 on exchange 20343r DtlM CHIP:EM: Found matching exchange: 20343r, Delegate: 00000000 DtlM CHIP:EM: Rxd Ack; Removing MessageCounter:166448080 from Retrans Table on exchange 20343r DtlM CHIP:EM: Removed CHIP MessageCounter:166448080 from RetransTable on exchange 20343r ErrM CHIP:BLE: no endpoint for unsub recvd PrgA CHIP:DL: BLE GATT connection closed (con 1, reason 19) DtlT CHIP:IN: UDP Message Received packet nb : 8 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[53214] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 177 PrgM CHIP:EM: Received message of type 0x30 with protocolId (0, 0) and MessageCounter:241426311 on exchange 58773r DtlM CHIP:EM: Handling via exchange: 58773r, Delegate: 00227b48 PrgM CHIP:IN: CASE Server received Sigma1 message. Starting handshake. EC 00228748 PrgM CHIP:IN: CASE Server disabling CASE session setups DtlM CHIP:EM: Sending Standalone Ack for MessageCounter:241426311 on exchange 58773r PrgM CHIP:IN: Prepared unauthenticated message 0023d078 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 58773r with MessageCounter:227768860. PrgM CHIP:IN: Sending unauthenticated msg 0023d078 with MessageCounter:227768860 to 0x0000000000000000 at monotonic time: 0000000000423829 msec DtlM CHIP:EM: Flushed pending ack for MessageCounter:241426311 on exchange 58773r PrgM CHIP:SC: Received Sigma1 msg DtlM CHIP:SC: Found MRP parameters in the message DtlM CHIP:SC: Peer assigned session key ID 32306 PrgM CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000014 DtlM CHIP:SC: Including MRP parameters DtlM CHIP:EM: Piggybacking Ack for MessageCounter:241426311 on exchange: 58773r PrgM CHIP:IN: Prepared unauthenticated message 00228c7c to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 58773r with MessageCounter:227768861. PrgM CHIP:IN: Sending unauthenticated msg 00228c7c with MessageCounter:227768861 to 0x0000000000000000 at monotonic time: 0000000000423C92 msec PrgM CHIP:SC: Sent Sigma2 msg ErrM CHIP:DL: Long dispatch time: 1168 ms, for event type 3 DtlM CHIP:EM: Retransmitting MessageCounter:227768861 on exchange 58773r Send Cnt 1 PrgM CHIP:IN: Sending unauthenticated msg 00228c7c with MessageCounter:227768861 to 0x0000000000000000 at monotonic time: 0000000000423DEB msec DtlT CHIP:IN: UDP Message Received packet nb : 9 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[53214] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 598 PrgM CHIP:EM: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:241426312 on exchange 58773r DtlM CHIP:EM: Found matching exchange: 58773r, Delegate: 00227b64 DtlM CHIP:EM: Rxd Ack; Removing MessageCounter:227768861 from Retrans Table on exchange 58773r DtlM CHIP:EM: Removed CHIP MessageCounter:227768861 from RetransTable on exchange 58773r DtlM CHIP:EM: Sending Standalone Ack for MessageCounter:241426312 on exchange 58773r PrgM CHIP:IN: Prepared unauthenticated message 0023d060 to 0x0000000000000000 (0) of type 0x10 and protocolId (0, 0) on exchange 58773r with MessageCounter:227768862. PrgM CHIP:IN: Sending unauthenticated msg 0023d060 with MessageCounter:227768862 to 0x0000000000000000 at monotonic time: 0000000000423F21 msec DtlM CHIP:EM: Flushed pending ack for MessageCounter:241426312 on exchange 58773r PrgM CHIP:SC: Received Sigma3 msg ErrM CHIP:SC: The device does not support GetClock_RealTimeMS() API: 6c. Falling back to Last Known Good UTC Time DtlT CHIP:IN: UDP Message Received packet nb : 10 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[53214] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 26 ErrM CHIP:SC: Unable to save session resumption state: 2f DtlM CHIP:SC: Sending status report. Protocol code 0, exchange 58773 DtlM CHIP:EM: Piggybacking Ack for MessageCounter:241426312 on exchange: 58773r PrgM CHIP:IN: Prepared unauthenticated message 00228c7c to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 58773r with MessageCounter:227768863. PrgM CHIP:IN: Sending unauthenticated msg 00228c7c with MessageCounter:227768863 to 0x0000000000000000 at monotonic time: 00000000004247EB msec PrgM CHIP:SC: SecureSession[00227048]: Moving from state 'kEstablishing' --> 'kActive' DtlM CHIP:IN: SecureSession[00227048]: Activated - Type:2 LSID:30629 DtlM CHIP:IN: New secure session activated for device <000000000001B669, 1>, LSID:30629 PSID:32306! PrgM CHIP:IN: CASE Session established to peer: <000000000001B669, 1> PrgM CHIP:IN: CASE Server enabling CASE session setups DtlM CHIP:IN: SecureSession[00226ed8]: Allocated Type:2 LSID:30630 DtlM CHIP:SC: Allocated SecureSession (00226ed8) - waiting for Sigma1 msg ErrM CHIP:DL: Long dispatch time: 2300 ms, for event type 3 PrgM CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:241426313 on exchange 58773r DtlM CHIP:EM: Found matching exchange: 58773r, Delegate: 00000000 DtlM CHIP:EM: CHIP MessageCounter:227768861 not in RetransTable on exchange 58773r DtlT CHIP:IN: UDP Message Received packet nb : 11 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[53214] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 51 PrgM CHIP:EM: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:65544630 on exchange 58774r DtlM CHIP:EM: Handling via exchange: 58774r, Delegate: 0021f43c DtlM CHIP:IM: Received Read request DtlM CHIP:DMG: IM RH moving to [GeneratingReports] DtlM CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 DtlT CHIP:IN: UDP Message Received packet nb : 12 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[53214] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 26 DtlM CHIP:DMG: Fetched 0 events DtlM CHIP:DMG: Sending report (payload has 7 bytes)... DtlM CHIP:EM: Piggybacking Ack for MessageCounter:65544630 on exchange: 58774r PrgM CHIP:IN: Prepared secure message 00228c94 to 0x000000000001B669 (1) of type 0x5 and protocolId (0, 1) on exchange 58774r with MessageCounter:212214313. PrgM CHIP:IN: Sending encrypted msg 00228c94 with MessageCounter:212214313 to 0x000000000001B669 (1) at monotonic time: 00000000004248B2 msec DtlM CHIP:DMG: OnReportConfirm: NumReports = 0 DtlM CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages DtlM CHIP:DMG: IM RH moving to [AwaitingDestruction] DtlM CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet PrgM CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:241426314 on exchange 58773r DtlM CHIP:EM: Found matching exchange: 58773r, Delegate: 00000000 DtlM CHIP:EM: Rxd Ack; Removing MessageCounter:227768863 from Retrans Table on exchange 58773r DtlM CHIP:EM: Removed CHIP MessageCounter:227768863 from RetransTable on exchange 58773r DtlT CHIP:IN: UDP Message Received packet nb : 13 SrcAddr : fda5:92c:e0d4:0:42:51ff:fef3:b80c[53214] DestAddr : fd11:22:0:0:d8d5:666c:2d87:2fd1[5540] Payload Length 34 PrgM CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:65544631 on exchange 58774r DtlM CHIP:EM: Found matching exchange: 58774r, Delegate: 00000000 DtlM CHIP:EM: Rxd Ack; Removing MessageCounter:212214313 from Retrans Table on exchange 58774r DtlM CHIP:EM: Removed CHIP MessageCounter:212214313 from RetransTable on exchange 58774r