[1699002701.914978][1141:1141] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1699002701.942288][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-9WfJR7) [1699002701.944545][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002701.958907][1141:1141] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1699002701.958969][1141:1141] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1699002701.987919][1141:1141] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1699002701.988254][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-IcD2n6) [1699002701.988460][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1699002701.988657][1141:1141] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1699002701.988833][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_config.ini-p4eAko) [1699002701.988966][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1699002701.989142][1141:1141] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1699002701.989258][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-V9u2El) [1699002701.989390][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1699002701.990094][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-kgiqHJ) [1699002701.991498][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1699002701.991591][1141:1141] CHIP:DL: NVS set: chip-factory/unique-id = "A4AAF5D3585BF250" [1699002701.991859][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-qzatcn) [1699002701.992977][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1699002701.993060][1141:1141] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1699002701.993278][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-GARhdr) [1699002701.993768][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1699002701.993873][1141:1141] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1699002701.994061][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-EOOerG) [1699002701.994507][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1699002701.994588][1141:1141] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1699002701.994809][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-CPVlSn) [1699002701.995277][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1699002701.995344][1141:1141] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1699002701.995570][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-D2jiEQ) [1699002701.996031][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1699002701.996096][1141:1141] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1699002701.996286][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_config.ini-BxcJnK) [1699002701.996622][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1699002701.996789][1141:1141] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1699002701.997084][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_config.ini-IH05mk) [1699002701.997556][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1699002701.997661][1141:1141] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1699002702.002886][1141:1141] CHIP:DL: Got Ethernet interface: eth0 [1699002702.006867][1141:1141] CHIP:DL: Found the primary Ethernet interface:eth0 [1699002702.007425][1141:1141] CHIP:DL: Got WiFi interface: wlan0 [1699002702.007522][1141:1141] CHIP:DL: Failed to reset WiFi statistic counts [1699002702.007592][1141:1141] CHIP:SPT: *** WARNING: Using temporary passcode 20202021 due to no neither --passcode or --spake2p-verifier-base64 given on command line. This is temporary and will disappear. Please update your scripts to explicitly configure onboarding credentials. *** [1699002702.007659][1141:1141] CHIP:SPT: PASE PBKDF iterations set to 1000 [1699002702.007723][1141:1141] CHIP:SPT: LinuxCommissionableDataProvider didn't get a PASE salt, generating one. [1699002702.050611][1141:1141] CHIP:DL: Device Configuration: [1699002702.050805][1141:1141] CHIP:DL: Serial Number: TEST_SN [1699002702.050894][1141:1141] CHIP:DL: Vendor Id: 65521 (0xFFF1) [1699002702.050995][1141:1141] CHIP:DL: Product Id: 32769 (0x8001) [1699002702.051014][1141:1141] CHIP:DL: Product Name: TEST_PRODUCT [1699002702.051097][1141:1141] CHIP:DL: Hardware Version: 0 [1699002702.051116][1141:1141] CHIP:DL: Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 [1699002702.051132][1141:1141] CHIP:DL: Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 18 (0x12) [1699002702.051189][1141:1141] CHIP:DL: Manufacturing Date: (not set) [1699002702.051206][1141:1141] CHIP:DL: Device Type: 257 (0x101) [1699002702.051217][1141:1141] CHIP:-: ==== Onboarding payload for Standard Commissioning Flow ==== [1699002702.055554][1141:1141] CHIP:SVR: SetupQRCode: [MT:-24J0KQS02-Z.548G00] [1699002702.059185][1141:1141] CHIP:SVR: Copy/paste the below URL in a browser to see the QR Code: [1699002702.059206][1141:1141] CHIP:SVR: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J0KQS02-Z.548G00 [1699002702.059274][1141:1141] CHIP:SVR: Manual pairing code: [00054912336] [1699002702.061728][1141:1141] CHIP:SVR: Initializing subscription resumption storage... [1699002702.062249][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-6OPXIb) [1699002702.063050][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002702.063221][1141:1141] CHIP:SVR: Server initializing... [1699002702.063311][1141:1141] CHIP:FP: Initializing FabricTable from persistent storage [1699002702.067903][1141:1141] CHIP:TS: Last Known Good Time: [unknown] [1699002702.067943][1141:1141] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1699002702.068245][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-wpb6HT) [1699002702.068989][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002702.069248][1141:1141] CHIP:DMG: AccessControl: initializing [1699002702.073784][1141:1141] CHIP:DMG: Examples::AccessControlDelegate::Init [1699002702.073831][1141:1141] CHIP:DMG: AccessControl: setting [1699002702.073856][1141:1141] CHIP:DMG: DefaultAclStorage: initializing [1699002702.077128][1141:1141] CHIP:DMG: DefaultAclStorage: 0 entries loaded [1699002702.077193][1141:1141] CHIP:IN: UDP::Init bind&listen port=5540 [1699002702.077429][1141:1141] CHIP:IN: UDP::Init bound to port=5540 [1699002702.077456][1141:1141] CHIP:IN: UDP::Init bind&listen port=5540 [1699002702.077549][1141:1141] CHIP:IN: UDP::Init bound to port=5540 [1699002702.077567][1141:1141] CHIP:IN: BLEBase::Init - setting/overriding transport [1699002702.077912][1141:1141] CHIP:IN: TransportMgr initialized [1699002702.078539][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-vkt9nL) [1699002702.079273][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002702.079724][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-uWBpjL) [1699002702.081109][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002702.088013][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-2lo7Ms) [1699002702.088838][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002702.088941][1141:1141] CHIP:ZCL: Using ZAP configuration... [1699002702.097485][1141:1141] CHIP:DMG: Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101230][1141:1141] CHIP:DMG: Failed to read stored attribute (0, 0x0000_0028, 0x0000_0010: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101301][1141:1141] CHIP:DMG: Failed to read stored attribute (0, 0x0000_002B, 0x0000_0000: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101386][1141:1141] CHIP:DMG: Failed to read stored attribute (0, 0x0000_002C, 0x0000_0000: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101434][1141:1141] CHIP:DMG: Failed to read stored attribute (0, 0x0000_002C, 0x0000_0001: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101551][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0006, 0x0000_0000: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101623][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0006, 0x0000_4003: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101674][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0008, 0x0000_0000: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101755][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0008, 0x0000_4000: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101807][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_0000: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101854][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_0001: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101901][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_0003: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101947][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_0004: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.101992][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_0007: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.102037][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_0008: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.102102][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_4000: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.102149][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_4001: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.102196][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_4002: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.102241][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_4003: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.102292][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_4004: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.102361][1141:1141] CHIP:DMG: Failed to read stored attribute (1, 0x0000_0300, 0x0000_4010: src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1699002702.102390][1141:1141] CHIP:DMG: AccessControlCluster: initializing [1699002702.105945][1141:1141] CHIP:ZCL: Initiating Admin Commissioning cluster. [1699002702.109444][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to d0fd56f7 [1699002702.113315][1141:1141] CHIP:ZCL: GeneralDiagnostics: OnDeviceReboot [1699002702.116959][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_0033 update version to 398fe166 [1699002702.124222][1141:1141] CHIP:EVL: LogEvent event number: 0x0000000000000000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0033 event id: 0x3 Epoch timestamp: 0x0000018B9473D925 [1699002702.126077][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0005 update version to 3b6e89d5 [1699002702.126117][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0005 update version to 3b6e89d6 [1699002702.126138][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0005 update version to 3b6e89d7 [1699002702.129830][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0004 update version to 4827fb58 [1699002702.129889][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0004 update version to 4827fb59 [1699002702.129932][1141:1141] CHIP:ZCL: Endpoint 1 On/off already set to new value [1699002702.134009][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-BvlFYu) [1699002702.134790][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002702.134927][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0008 update version to cdef3a07 [1699002702.135210][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-iYDPVe) [1699002702.136329][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002702.136432][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0300 update version to fe4833fb [1699002702.136754][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-RZuPQC) [1699002702.137517][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002702.137659][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0300 update version to fe4833fc [1699002702.137908][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-bS71Sk) [1699002702.138766][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002702.138863][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0300 update version to fe4833fd [1699002702.138914][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0406 update version to c6dee584 [1699002702.138937][1141:1141] CHIP:DMG: Endpoint 1, Cluster 0x0000_0406 update version to c6dee585 [1699002702.139313][1141:1141] CHIP:IN: SecureSession[0xffff7fa0fb80]: Allocated Type:1 LSID:27946 [1699002702.139359][1141:1141] CHIP:SC: Assigned local session key ID 27946 [1699002702.139397][1141:1141] CHIP:SC: Waiting for PBKDF param request [1699002702.139439][1141:1141] CHIP:DIS: Updating services using commissioning mode 1 [1699002702.145630][1141:1141] CHIP:DIS: CHIP minimal mDNS started advertising. [1699002702.153094][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002702.153427][1141:1141] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=1 [1699002702.153562][1141:1141] CHIP:DIS: Responding with _matterc._udp.local [1699002702.153626][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002702.153645][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002702.153663][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002702.153694][1141:1141] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1699002702.153737][1141:1141] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1699002702.153763][1141:1141] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1699002702.153801][1141:1141] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1699002702.153842][1141:1141] CHIP:DIS: Responding with _CM._sub._matterc._udp.local [1699002702.153928][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002702.153943][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: CB8C096D0BF02F51. [1699002702.155686][1141:1141] CHIP:DIS: mDNS service published: _matterc._udp [1699002702.155734][1141:1141] CHIP:DIS: Updating services using commissioning mode 1 [1699002702.157244][1141:1141] CHIP:DIS: CHIP minimal mDNS started advertising. [1699002702.160600][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002702.160914][1141:1141] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=1 [1699002702.161022][1141:1141] CHIP:DIS: Responding with _matterc._udp.local [1699002702.161066][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002702.161084][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002702.161113][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002702.161161][1141:1141] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1699002702.161201][1141:1141] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1699002702.161226][1141:1141] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1699002702.161257][1141:1141] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1699002702.161281][1141:1141] CHIP:DIS: Responding with _CM._sub._matterc._udp.local [1699002702.161337][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002702.161351][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: CB8C096D0BF02F51. [1699002702.162952][1141:1141] CHIP:DIS: mDNS service published: _matterc._udp/ [1699002702.163040][1141:1141] CHIP:IN: CASE Server enabling CASE session setups [1699002702.163220][1141:1141] CHIP:IN: SecureSession[0xffff7fa0fa40]: Allocated Type:2 LSID:27947 [1699002702.163272][1141:1141] CHIP:SC: Allocated SecureSession (0xffff7fa0fa40) - waiting for Sigma1 msg [1699002702.163303][1141:1141] CHIP:SVR: Joining Multicast groups [1699002702.163346][1141:1141] CHIP:ZCL: Emitting StartUp event [1699002702.167383][1141:1141] CHIP:EVL: LogEvent event number: 0x0000000000000001 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Epoch timestamp: 0x0000018B9473D957 [1699002702.167443][1141:1141] CHIP:SVR: Server Listening... [1699002702.167464][1141:1141] CHIP:DL: Device Configuration: [1699002702.167642][1141:1141] CHIP:DL: Serial Number: TEST_SN [1699002702.167786][1141:1141] CHIP:DL: Vendor Id: 65521 (0xFFF1) [1699002702.167882][1141:1141] CHIP:DL: Product Id: 32769 (0x8001) [1699002702.167899][1141:1141] CHIP:DL: Product Name: TEST_PRODUCT [1699002702.167975][1141:1141] CHIP:DL: Hardware Version: 0 [1699002702.167996][1141:1141] CHIP:DL: Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 [1699002702.168011][1141:1141] CHIP:DL: Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 18 (0x12) [1699002702.168098][1141:1141] CHIP:DL: Manufacturing Date: (not set) [1699002702.168117][1141:1141] CHIP:DL: Device Type: 257 (0x101) [1699002702.168175][1141:1141] CHIP:SVR: SetupQRCode: [MT:-24J0KQS02-Z.548G00] [1699002702.168205][1141:1141] CHIP:SVR: Copy/paste the below URL in a browser to see the QR Code: [1699002702.168217][1141:1141] CHIP:SVR: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J0KQS02-Z.548G00 [1699002702.168257][1141:1141] CHIP:SVR: Manual pairing code: [00054912336] [1699002702.220612][1141:1142] CHIP:DL: TRACE: Bus acquired for name MATTER-0018 [1699002702.221643][1141:1142] CHIP:DL: CREATE service object at /chipoble/0475/service [1699002702.231181][1141:1142] CHIP:DL: Create characteristic object at /chipoble/0475/service/c1 [1699002702.233259][1141:1142] CHIP:DL: Create characteristic object at /chipoble/0475/service/c2 [1699002702.234679][1141:1142] CHIP:DL: CHIP BTP C1 /chipoble/0475/service [1699002702.234740][1141:1142] CHIP:DL: CHIP BTP C2 /chipoble/0475/service [1699002702.234752][1141:1142] CHIP:DL: CHIP_ENABLE_ADDITIONAL_DATA_ADVERTISING is FALSE [1699002702.250375][1141:1141] CHIP:DL: PlatformBlueZInit init success [1699002702.259133][1141:1142] CHIP:DL: BluezPeripheralRegisterAppDone done [1699002702.259252][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 16392 [1699002702.259487][1141:1142] CHIP:DL: Create adv object at /chipoble/0475/advertising [1699002702.268404][1141:1142] CHIP:DL: SET service data to {'0xFFF6': <[byte 0x00, 0x12, 0x00, 0xf1, 0xff, 0x01, 0x80, 0x00]>} [1699002702.270130][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 16393 [1699002702.270172][1141:1141] CHIP:DL: CHIPoBLE advertising config complete [1699002702.280720][1141:1142] CHIP:DL: RegisterAdvertisement complete [1699002702.280880][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 16394 [1699002713.839256][1141:1142] CHIP:DL: BLE device connected: conn 0xffff80c06ed0, device E4:5F:01:0A:DA:38, path /org/bluez/hci0/dev_E4_5F_01_0A_DA_38 [1699002715.688265][1141:1142] CHIP:DL: BluezCharacteristicAcquireWrite is called, conn: 0xffff80c06ed0 [1699002715.690761][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002715.691072][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002715.691448][1141:1141] CHIP:BLE: local and remote recv window sizes = 6 [1699002715.691492][1141:1141] CHIP:BLE: selected BTP version 4 [1699002715.691517][1141:1141] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244. [1699002715.773982][1141:1142] CHIP:DL: CHIPoBLE subscribe received [1699002715.774908][1141:1141] CHIP:IN: BLE EndPoint 0xaaaab7878b00 Connection Complete [1699002715.775002][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 32775 [1699002715.776243][1141:1141] CHIP:DL: Receive kCHIPoBLEConnectionEstablished [1699002715.871133][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002715.871509][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002715.872993][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002715.880585][1141:1141] CHIP:EM: >>> [E:26208r S:0 M:82986291] (U) Msg RX from 0:23E3962F98959B55 [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) [1699002715.880720][1141:1141] CHIP:EM: Handling via exchange: 26208r, Delegate: 0xaaaab7877390 [1699002715.883773][1141:1141] CHIP:SC: Received PBKDF param request [1699002715.884355][1141:1141] CHIP:SC: Peer assigned session ID 3193 [1699002715.885901][1141:1141] CHIP:EM: <<< [E:26208r S:0 M:211636709] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) [1699002715.886504][1141:1141] CHIP:SC: Sent PBKDF param response [1699002715.886556][1141:1141] CHIP:SVR: Commissioning session establishment step started [1699002715.968752][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002715.969007][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002715.971841][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002715.975492][1141:1141] CHIP:EM: >>> [E:26208r S:0 M:82986292] (U) Msg RX from 0:23E3962F98959B55 [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1) [1699002715.975610][1141:1141] CHIP:EM: Found matching exchange: 26208r, Delegate: 0xaaaab7877390 [1699002715.975814][1141:1141] CHIP:SC: Received spake2p msg1 [1699002715.982361][1141:1141] CHIP:EM: <<< [E:26208r S:0 M:211636710] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) [1699002715.982924][1141:1141] CHIP:SC: Sent spake2p msg2 [1699002716.066268][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.066503][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002716.068995][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002716.069622][1141:1141] CHIP:EM: >>> [E:26208r S:0 M:82986293] (U) Msg RX from 0:23E3962F98959B55 [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3) [1699002716.069718][1141:1141] CHIP:EM: Found matching exchange: 26208r, Delegate: 0xaaaab7877390 [1699002716.069846][1141:1141] CHIP:SC: Received spake2p msg3 [1699002716.070267][1141:1141] CHIP:SC: Sending status report. Protocol code 0, exchange 26208 [1699002716.070447][1141:1141] CHIP:EM: <<< [E:26208r S:0 M:211636711] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) [1699002716.074013][1141:1141] CHIP:SC: SecureSession[0xffff7fa0fb80, LSID:27946]: State change 'kEstablishing' --> 'kActive' [1699002716.074182][1141:1141] CHIP:IN: SecureSession[0xffff7fa0fb80]: Activated - Type:1 LSID:27946 [1699002716.074205][1141:1141] CHIP:IN: New secure session activated for device , LSID:27946 PSID:3193! [1699002716.074267][1141:1141] CHIP:SVR: Commissioning completed session establishment step [1699002716.074571][1141:1141] CHIP:DIS: Updating services using commissioning mode 0 [1699002716.076764][1141:1141] CHIP:DIS: CHIP minimal mDNS started advertising. [1699002716.081047][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002716.081327][1141:1141] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=0 [1699002716.081441][1141:1141] CHIP:DIS: Responding with _matterc._udp.local [1699002716.081480][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002716.081505][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002716.081526][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002716.081606][1141:1141] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1699002716.081645][1141:1141] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1699002716.081678][1141:1141] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1699002716.081709][1141:1141] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1699002716.081776][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002716.081796][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: CB8C096D0BF02F51. [1699002716.083787][1141:1141] CHIP:DIS: mDNS service published: _matterc._udp [1699002716.083825][1141:1141] CHIP:DIS: Scheduling extended discovery timeout in 900s [1699002716.083951][1141:1141] CHIP:SVR: Device completed Rendezvous process [1699002716.087643][1141:1142] CHIP:DL: UnregisterAdvertisement complete [1699002716.087851][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 16395 [1699002716.087871][1141:1141] CHIP:DL: CHIPoBLE advertising stopped [1699002716.162960][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.164373][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002716.166314][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002716.167405][1141:1141] CHIP:EM: >>> [E:26209r S:27946 M:120084037] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) [1699002716.167519][1141:1141] CHIP:EM: Handling via exchange: 26209r, Delegate: 0xaaaab786c308 [1699002716.171471][1141:1141] CHIP:IM: Received Read request [1699002716.175375][1141:1141] CHIP:DMG: ReadRequestMessage = [1699002716.175476][1141:1141] CHIP:DMG: { [1699002716.175496][1141:1141] CHIP:DMG: AttributePathIBs = [1699002716.175519][1141:1141] CHIP:DMG: [ [1699002716.177744][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.177808][1141:1141] CHIP:DMG: { [1699002716.177832][1141:1141] CHIP:DMG: Cluster = 0x31, [1699002716.177853][1141:1141] CHIP:DMG: Attribute = 0x0000_FFFC, [1699002716.177867][1141:1141] CHIP:DMG: } [1699002716.177901][1141:1141] CHIP:DMG: [1699002716.177916][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.177937][1141:1141] CHIP:DMG: { [1699002716.177955][1141:1141] CHIP:DMG: Endpoint = 0x0, [1699002716.177973][1141:1141] CHIP:DMG: Cluster = 0x30, [1699002716.177991][1141:1141] CHIP:DMG: Attribute = 0x0000_0000, [1699002716.178005][1141:1141] CHIP:DMG: } [1699002716.178026][1141:1141] CHIP:DMG: [1699002716.178041][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.178057][1141:1141] CHIP:DMG: { [1699002716.178075][1141:1141] CHIP:DMG: Endpoint = 0x0, [1699002716.178093][1141:1141] CHIP:DMG: Cluster = 0x30, [1699002716.178111][1141:1141] CHIP:DMG: Attribute = 0x0000_0001, [1699002716.178125][1141:1141] CHIP:DMG: } [1699002716.178146][1141:1141] CHIP:DMG: [1699002716.178161][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.178177][1141:1141] CHIP:DMG: { [1699002716.178194][1141:1141] CHIP:DMG: Endpoint = 0x0, [1699002716.178212][1141:1141] CHIP:DMG: Cluster = 0x30, [1699002716.178230][1141:1141] CHIP:DMG: Attribute = 0x0000_0002, [1699002716.178243][1141:1141] CHIP:DMG: } [1699002716.178264][1141:1141] CHIP:DMG: [1699002716.178279][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.178295][1141:1141] CHIP:DMG: { [1699002716.178313][1141:1141] CHIP:DMG: Endpoint = 0x0, [1699002716.178331][1141:1141] CHIP:DMG: Cluster = 0x30, [1699002716.178348][1141:1141] CHIP:DMG: Attribute = 0x0000_0003, [1699002716.178362][1141:1141] CHIP:DMG: } [1699002716.178383][1141:1141] CHIP:DMG: [1699002716.178397][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.178413][1141:1141] CHIP:DMG: { [1699002716.178431][1141:1141] CHIP:DMG: Endpoint = 0x0, [1699002716.178449][1141:1141] CHIP:DMG: Cluster = 0x28, [1699002716.178467][1141:1141] CHIP:DMG: Attribute = 0x0000_0002, [1699002716.178481][1141:1141] CHIP:DMG: } [1699002716.178501][1141:1141] CHIP:DMG: [1699002716.178516][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.178532][1141:1141] CHIP:DMG: { [1699002716.178550][1141:1141] CHIP:DMG: Endpoint = 0x0, [1699002716.178567][1141:1141] CHIP:DMG: Cluster = 0x28, [1699002716.178585][1141:1141] CHIP:DMG: Attribute = 0x0000_0004, [1699002716.178598][1141:1141] CHIP:DMG: } [1699002716.178621][1141:1141] CHIP:DMG: [1699002716.178638][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.178656][1141:1141] CHIP:DMG: { [1699002716.178676][1141:1141] CHIP:DMG: Cluster = 0x31, [1699002716.178694][1141:1141] CHIP:DMG: Attribute = 0x0000_0003, [1699002716.178708][1141:1141] CHIP:DMG: } [1699002716.178730][1141:1141] CHIP:DMG: [1699002716.178746][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.178764][1141:1141] CHIP:DMG: { [1699002716.178784][1141:1141] CHIP:DMG: Endpoint = 0x0, [1699002716.178801][1141:1141] CHIP:DMG: Cluster = 0x38, [1699002716.178814][1141:1141] CHIP:DMG: } [1699002716.178835][1141:1141] CHIP:DMG: [1699002716.178850][1141:1141] CHIP:DMG: ], [1699002716.178909][1141:1141] CHIP:DMG: [1699002716.178932][1141:1141] CHIP:DMG: isFabricFiltered = false, [1699002716.178949][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002716.178962][1141:1141] CHIP:DMG: }, [1699002716.179769][1141:1141] CHIP:DMG: IM RH moving to [CanStartReporting] [1699002716.180078][1141:1141] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 [1699002716.180123][1141:1141] CHIP:DMG: Cluster 31, Attribute 3 is dirty [1699002716.180145][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) [1699002716.187083][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=v [1699002716.187157][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.187369][1141:1141] CHIP:DMG: Cluster 28, Attribute 4 is dirty [1699002716.187392][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) [1699002716.187423][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0028 e=0 p=v [1699002716.187438][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.187672][1141:1141] CHIP:DMG: Cluster 28, Attribute 2 is dirty [1699002716.187690][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) [1699002716.187709][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0028 e=0 p=v [1699002716.187724][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.187810][1141:1141] CHIP:DMG: Cluster 30, Attribute 3 is dirty [1699002716.187827][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) [1699002716.187844][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1699002716.187859][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.187969][1141:1141] CHIP:DMG: Cluster 30, Attribute 2 is dirty [1699002716.187985][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) [1699002716.188002][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1699002716.188016][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.188095][1141:1141] CHIP:DMG: Cluster 30, Attribute 1 is dirty [1699002716.188111][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) [1699002716.188127][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1699002716.188142][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.188185][1141:1141] CHIP:DMG: Cluster 30, Attribute 0 is dirty [1699002716.188199][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0) [1699002716.188214][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1699002716.188228][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.188290][1141:1141] CHIP:DMG: Cluster 31, Attribute fffc is dirty [1699002716.188305][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) [1699002716.188321][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=v [1699002716.188336][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.188417][1141:1141] CHIP:DMG: Sending report (payload has 228 bytes)... [1699002716.188733][1141:1141] CHIP:EM: <<< [E:26209r S:27946 M:186828885] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) [1699002716.189303][1141:1141] CHIP:DMG: OnReportConfirm: NumReports = 0 [1699002716.189347][1141:1141] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1699002716.189367][1141:1141] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1699002716.192075][1141:1141] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1699002716.260181][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.358569][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002716.361553][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002716.361816][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.362443][1141:1141] CHIP:EM: >>> [E:26210r S:27946 M:120084038] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) [1699002716.362573][1141:1141] CHIP:EM: Handling via exchange: 26210r, Delegate: 0xaaaab786c308 [1699002716.362646][1141:1141] CHIP:IM: Received Read request [1699002716.362794][1141:1141] CHIP:DMG: ReadRequestMessage = [1699002716.362854][1141:1141] CHIP:DMG: { [1699002716.362896][1141:1141] CHIP:DMG: AttributePathIBs = [1699002716.362945][1141:1141] CHIP:DMG: [ [1699002716.362984][1141:1141] CHIP:DMG: AttributePathIB = [1699002716.363032][1141:1141] CHIP:DMG: { [1699002716.363084][1141:1141] CHIP:DMG: Endpoint = 0x0, [1699002716.363134][1141:1141] CHIP:DMG: Cluster = 0x30, [1699002716.363182][1141:1141] CHIP:DMG: Attribute = 0x0000_0004, [1699002716.363219][1141:1141] CHIP:DMG: } [1699002716.363276][1141:1141] CHIP:DMG: [1699002716.363314][1141:1141] CHIP:DMG: ], [1699002716.363376][1141:1141] CHIP:DMG: [1699002716.363430][1141:1141] CHIP:DMG: isFabricFiltered = false, [1699002716.363475][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002716.363509][1141:1141] CHIP:DMG: }, [1699002716.363984][1141:1141] CHIP:DMG: IM RH moving to [CanStartReporting] [1699002716.364395][1141:1141] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 [1699002716.364464][1141:1141] CHIP:DMG: Cluster 30, Attribute 4 is dirty [1699002716.364506][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) [1699002716.364572][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1699002716.364620][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.364809][1141:1141] CHIP:DMG: Sending report (payload has 35 bytes)... [1699002716.365142][1141:1141] CHIP:EM: <<< [E:26210r S:27946 M:186828886] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) [1699002716.367441][1141:1141] CHIP:DMG: OnReportConfirm: NumReports = 0 [1699002716.367530][1141:1141] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1699002716.367574][1141:1141] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1699002716.372557][1141:1141] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1699002716.455025][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.455905][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002716.456821][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002716.457378][1141:1141] CHIP:EM: >>> [E:26211r S:27946 M:120084039] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002716.457500][1141:1141] CHIP:EM: Handling via exchange: 26211r, Delegate: 0xaaaab786c308 [1699002716.457758][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002716.457811][1141:1141] CHIP:DMG: { [1699002716.457852][1141:1141] CHIP:DMG: suppressResponse = false, [1699002716.457895][1141:1141] CHIP:DMG: timedRequest = false, [1699002716.457930][1141:1141] CHIP:DMG: InvokeRequests = [1699002716.457997][1141:1141] CHIP:DMG: [ [1699002716.458032][1141:1141] CHIP:DMG: CommandDataIB = [1699002716.458073][1141:1141] CHIP:DMG: { [1699002716.458107][1141:1141] CHIP:DMG: CommandPathIB = [1699002716.458150][1141:1141] CHIP:DMG: { [1699002716.458196][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002716.458239][1141:1141] CHIP:DMG: ClusterId = 0x30, [1699002716.458279][1141:1141] CHIP:DMG: CommandId = 0x0, [1699002716.458311][1141:1141] CHIP:DMG: }, [1699002716.458361][1141:1141] CHIP:DMG: [1699002716.458400][1141:1141] CHIP:DMG: CommandFields = [1699002716.458440][1141:1141] CHIP:DMG: { [1699002716.458489][1141:1141] CHIP:DMG: 0x0 = 60, [1699002716.458533][1141:1141] CHIP:DMG: 0x1 = 4, [1699002716.458575][1141:1141] CHIP:DMG: }, [1699002716.458608][1141:1141] CHIP:DMG: }, [1699002716.458666][1141:1141] CHIP:DMG: [1699002716.458699][1141:1141] CHIP:DMG: ], [1699002716.458767][1141:1141] CHIP:DMG: [1699002716.458806][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002716.458837][1141:1141] CHIP:DMG: }, [1699002716.459078][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1699002716.459136][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.459205][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 [1699002716.459516][1141:1141] CHIP:FS: GeneralCommissioning: Received ArmFailSafe (60s) [1699002716.463742][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to d0fd56f8 [1699002716.463874][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002716.463954][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002716.464032][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002716.464191][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002716.464567][1141:1141] CHIP:EM: <<< [E:26211r S:27946 M:186828887] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002716.465223][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002716.465266][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002716.552446][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.553317][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002716.554339][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002716.554924][1141:1141] CHIP:EM: >>> [E:26212r S:27946 M:120084040] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002716.555011][1141:1141] CHIP:EM: Handling via exchange: 26212r, Delegate: 0xaaaab786c308 [1699002716.555160][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002716.555182][1141:1141] CHIP:DMG: { [1699002716.555200][1141:1141] CHIP:DMG: suppressResponse = false, [1699002716.555219][1141:1141] CHIP:DMG: timedRequest = false, [1699002716.555233][1141:1141] CHIP:DMG: InvokeRequests = [1699002716.555263][1141:1141] CHIP:DMG: [ [1699002716.555277][1141:1141] CHIP:DMG: CommandDataIB = [1699002716.555297][1141:1141] CHIP:DMG: { [1699002716.555310][1141:1141] CHIP:DMG: CommandPathIB = [1699002716.555329][1141:1141] CHIP:DMG: { [1699002716.555349][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002716.555367][1141:1141] CHIP:DMG: ClusterId = 0x30, [1699002716.555382][1141:1141] CHIP:DMG: CommandId = 0x2, [1699002716.555395][1141:1141] CHIP:DMG: }, [1699002716.555417][1141:1141] CHIP:DMG: [1699002716.555434][1141:1141] CHIP:DMG: CommandFields = [1699002716.555455][1141:1141] CHIP:DMG: { [1699002716.555480][1141:1141] CHIP:DMG: 0x0 = 0, [1699002716.555508][1141:1141] CHIP:DMG: 0x1 = "XX" (2 chars), [1699002716.555526][1141:1141] CHIP:DMG: 0x2 = 5, [1699002716.555544][1141:1141] CHIP:DMG: }, [1699002716.555557][1141:1141] CHIP:DMG: }, [1699002716.555583][1141:1141] CHIP:DMG: [1699002716.555596][1141:1141] CHIP:DMG: ], [1699002716.555631][1141:1141] CHIP:DMG: [1699002716.555648][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002716.555660][1141:1141] CHIP:DMG: }, [1699002716.555838][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1699002716.555867][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.555900][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 [1699002716.556562][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_config.ini-aHvWUa) [1699002716.557429][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1699002716.557549][1141:1141] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1699002716.557841][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_config.ini-gunc6H) [1699002716.558964][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1699002716.559066][1141:1141] CHIP:DL: NVS set: chip-config/country-code = "XX" [1699002716.559141][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to d0fd56f9 [1699002716.559240][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002716.559300][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002716.559346][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002716.559449][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002716.559737][1141:1141] CHIP:EM: <<< [E:26212r S:27946 M:186828888] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002716.560254][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002716.560286][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002716.649998][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.650801][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002716.651748][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002716.652292][1141:1141] CHIP:EM: >>> [E:26213r S:27946 M:120084041] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002716.652376][1141:1141] CHIP:EM: Handling via exchange: 26213r, Delegate: 0xaaaab786c308 [1699002716.652496][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002716.652520][1141:1141] CHIP:DMG: { [1699002716.652536][1141:1141] CHIP:DMG: suppressResponse = false, [1699002716.652555][1141:1141] CHIP:DMG: timedRequest = false, [1699002716.652570][1141:1141] CHIP:DMG: InvokeRequests = [1699002716.652600][1141:1141] CHIP:DMG: [ [1699002716.652614][1141:1141] CHIP:DMG: CommandDataIB = [1699002716.652639][1141:1141] CHIP:DMG: { [1699002716.652653][1141:1141] CHIP:DMG: CommandPathIB = [1699002716.652675][1141:1141] CHIP:DMG: { [1699002716.652696][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002716.652713][1141:1141] CHIP:DMG: ClusterId = 0x3e, [1699002716.652730][1141:1141] CHIP:DMG: CommandId = 0x2, [1699002716.652744][1141:1141] CHIP:DMG: }, [1699002716.652770][1141:1141] CHIP:DMG: [1699002716.652787][1141:1141] CHIP:DMG: CommandFields = [1699002716.652808][1141:1141] CHIP:DMG: { [1699002716.652830][1141:1141] CHIP:DMG: 0x0 = 2, [1699002716.652848][1141:1141] CHIP:DMG: }, [1699002716.652861][1141:1141] CHIP:DMG: }, [1699002716.652890][1141:1141] CHIP:DMG: [1699002716.652903][1141:1141] CHIP:DMG: ], [1699002716.652936][1141:1141] CHIP:DMG: [1699002716.652953][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002716.652966][1141:1141] CHIP:DMG: }, [1699002716.653137][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1699002716.653164][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.653199][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 [1699002716.653352][1141:1141] CHIP:ZCL: OpCreds: Certificate Chain request received for PAI [1699002716.653491][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002716.653555][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002716.653657][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002716.653756][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002716.654026][1141:1141] CHIP:EM: <<< [E:26213r S:27946 M:186828889] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002716.654532][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002716.654558][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002716.747420][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.846071][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.943569][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002716.943798][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002716.945978][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002716.946703][1141:1141] CHIP:EM: >>> [E:26214r S:27946 M:120084042] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002716.946841][1141:1141] CHIP:EM: Handling via exchange: 26214r, Delegate: 0xaaaab786c308 [1699002716.947100][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002716.947156][1141:1141] CHIP:DMG: { [1699002716.947204][1141:1141] CHIP:DMG: suppressResponse = false, [1699002716.947254][1141:1141] CHIP:DMG: timedRequest = false, [1699002716.947294][1141:1141] CHIP:DMG: InvokeRequests = [1699002716.947371][1141:1141] CHIP:DMG: [ [1699002716.947412][1141:1141] CHIP:DMG: CommandDataIB = [1699002716.947459][1141:1141] CHIP:DMG: { [1699002716.947499][1141:1141] CHIP:DMG: CommandPathIB = [1699002716.947551][1141:1141] CHIP:DMG: { [1699002716.947608][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002716.947663][1141:1141] CHIP:DMG: ClusterId = 0x3e, [1699002716.947709][1141:1141] CHIP:DMG: CommandId = 0x2, [1699002716.947748][1141:1141] CHIP:DMG: }, [1699002716.947810][1141:1141] CHIP:DMG: [1699002716.947855][1141:1141] CHIP:DMG: CommandFields = [1699002716.947902][1141:1141] CHIP:DMG: { [1699002716.947961][1141:1141] CHIP:DMG: 0x0 = 1, [1699002716.948014][1141:1141] CHIP:DMG: }, [1699002716.948054][1141:1141] CHIP:DMG: }, [1699002716.948124][1141:1141] CHIP:DMG: [1699002716.948163][1141:1141] CHIP:DMG: ], [1699002716.948242][1141:1141] CHIP:DMG: [1699002716.948290][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002716.948326][1141:1141] CHIP:DMG: }, [1699002716.948587][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1699002716.948648][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002716.948723][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 [1699002716.948847][1141:1141] CHIP:ZCL: OpCreds: Certificate Chain request received for DAC [1699002716.948969][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002716.949064][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002716.949156][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002716.949319][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002716.949767][1141:1141] CHIP:EM: <<< [E:26214r S:27946 M:186828890] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002716.950465][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002716.950518][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002717.039903][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002717.187298][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002717.284531][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002717.285237][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002717.287561][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002717.288410][1141:1141] CHIP:EM: >>> [E:26215r S:27946 M:120084043] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002717.288527][1141:1141] CHIP:EM: Handling via exchange: 26215r, Delegate: 0xaaaab786c308 [1699002717.288727][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002717.288774][1141:1141] CHIP:DMG: { [1699002717.288816][1141:1141] CHIP:DMG: suppressResponse = false, [1699002717.288860][1141:1141] CHIP:DMG: timedRequest = false, [1699002717.288897][1141:1141] CHIP:DMG: InvokeRequests = [1699002717.288964][1141:1141] CHIP:DMG: [ [1699002717.289004][1141:1141] CHIP:DMG: CommandDataIB = [1699002717.289045][1141:1141] CHIP:DMG: { [1699002717.289079][1141:1141] CHIP:DMG: CommandPathIB = [1699002717.289122][1141:1141] CHIP:DMG: { [1699002717.289167][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002717.289204][1141:1141] CHIP:DMG: ClusterId = 0x3e, [1699002717.289231][1141:1141] CHIP:DMG: CommandId = 0x0, [1699002717.289254][1141:1141] CHIP:DMG: }, [1699002717.289293][1141:1141] CHIP:DMG: [1699002717.289438][1141:1141] CHIP:DMG: CommandFields = [1699002717.289479][1141:1141] CHIP:DMG: { [1699002717.289514][1141:1141] CHIP:DMG: 0x0 = [ [1699002717.289604][1141:1141] CHIP:DMG: 0xf1, 0x04, 0xa3, 0x39, 0xa7, 0xbb, 0xcc, 0x01, 0x70, 0xa8, 0x5b, 0xf6, 0x48, 0x19, 0xe6, 0x33, 0x3c, 0xd5, 0x6d, 0xf5, 0x36, 0x61, 0x97, 0xdb, 0x06, 0xe1, 0xe6, 0xe0, 0xf5, 0xfd, 0xe1, 0x3e, [1699002717.289646][1141:1141] CHIP:DMG: ] (32 bytes) [1699002717.289678][1141:1141] CHIP:DMG: }, [1699002717.289701][1141:1141] CHIP:DMG: }, [1699002717.289744][1141:1141] CHIP:DMG: [1699002717.289768][1141:1141] CHIP:DMG: ], [1699002717.289823][1141:1141] CHIP:DMG: [1699002717.289853][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002717.289875][1141:1141] CHIP:DMG: }, [1699002717.290076][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1699002717.290116][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002717.290170][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 [1699002717.290839][1141:1141] CHIP:ZCL: OpCreds: Received an AttestationRequest command [1699002717.294077][1141:1141] CHIP:ZCL: OpCreds: AttestationRequest successful. [1699002717.294224][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002717.294289][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002717.294490][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002717.294646][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002717.294979][1141:1141] CHIP:EM: <<< [E:26215r S:27946 M:186828891] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002717.295597][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002717.295637][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002717.381140][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002717.479956][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002717.577061][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002717.674382][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002717.677560][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002717.678444][1141:1141] CHIP:EM: >>> [E:26216r S:27946 M:120084044] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002717.678583][1141:1141] CHIP:EM: Handling via exchange: 26216r, Delegate: 0xaaaab786c308 [1699002717.678809][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002717.678870][1141:1141] CHIP:DMG: { [1699002717.678921][1141:1141] CHIP:DMG: suppressResponse = false, [1699002717.678971][1141:1141] CHIP:DMG: timedRequest = false, [1699002717.679015][1141:1141] CHIP:DMG: InvokeRequests = [1699002717.679096][1141:1141] CHIP:DMG: [ [1699002717.679138][1141:1141] CHIP:DMG: CommandDataIB = [1699002717.679187][1141:1141] CHIP:DMG: { [1699002717.679227][1141:1141] CHIP:DMG: CommandPathIB = [1699002717.679277][1141:1141] CHIP:DMG: { [1699002717.679330][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002717.679380][1141:1141] CHIP:DMG: ClusterId = 0x3e, [1699002717.679426][1141:1141] CHIP:DMG: CommandId = 0x4, [1699002717.679464][1141:1141] CHIP:DMG: }, [1699002717.679528][1141:1141] CHIP:DMG: [1699002717.679572][1141:1141] CHIP:DMG: CommandFields = [1699002717.679624][1141:1141] CHIP:DMG: { [1699002717.679677][1141:1141] CHIP:DMG: 0x0 = [ [1699002717.679790][1141:1141] CHIP:DMG: 0x83, 0x0c, 0xd9, 0xa6, 0x36, 0x18, 0xb8, 0x62, 0x42, 0x3f, 0xbc, 0x4d, 0x18, 0xc4, 0x31, 0x62, 0xfb, 0x7b, 0x97, 0x6a, 0x2c, 0x11, 0xba, 0xa9, 0x9f, 0x6c, 0x93, 0x5a, 0x3c, 0xda, 0xb4, 0xd4, [1699002717.679845][1141:1141] CHIP:DMG: ] (32 bytes) [1699002717.679898][1141:1141] CHIP:DMG: }, [1699002717.679938][1141:1141] CHIP:DMG: }, [1699002717.680009][1141:1141] CHIP:DMG: [1699002717.680049][1141:1141] CHIP:DMG: ], [1699002717.680128][1141:1141] CHIP:DMG: [1699002717.680177][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002717.680213][1141:1141] CHIP:DMG: }, [1699002717.680468][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1699002717.680531][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002717.680602][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 [1699002717.680727][1141:1141] CHIP:ZCL: OpCreds: Received a CSRRequest command [1699002717.680782][1141:1141] CHIP:ZCL: OpCreds: Finding fabric with fabricIndex 0x0 [1699002717.689198][1141:1141] CHIP:ZCL: OpCreds: AllocatePendingOperationalKey succeeded [1699002717.690826][1141:1141] CHIP:ZCL: OpCreds: CSRRequest successful. [1699002717.690957][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002717.691015][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002717.691149][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002717.691268][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002717.691519][1141:1141] CHIP:EM: <<< [E:26216r S:27946 M:186828892] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002717.692133][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002717.692159][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002717.771931][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002717.869569][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002717.919775][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002717.924333][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002718.015028][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002718.019481][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002718.020196][1141:1141] CHIP:EM: >>> [E:26217r S:27946 M:120084045] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002718.020343][1141:1141] CHIP:EM: Handling via exchange: 26217r, Delegate: 0xaaaab786c308 [1699002718.020567][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002718.020623][1141:1141] CHIP:DMG: { [1699002718.020675][1141:1141] CHIP:DMG: suppressResponse = false, [1699002718.020727][1141:1141] CHIP:DMG: timedRequest = false, [1699002718.020770][1141:1141] CHIP:DMG: InvokeRequests = [1699002718.020850][1141:1141] CHIP:DMG: [ [1699002718.020893][1141:1141] CHIP:DMG: CommandDataIB = [1699002718.020941][1141:1141] CHIP:DMG: { [1699002718.020981][1141:1141] CHIP:DMG: CommandPathIB = [1699002718.021029][1141:1141] CHIP:DMG: { [1699002718.021082][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002718.021132][1141:1141] CHIP:DMG: ClusterId = 0x3e, [1699002718.021178][1141:1141] CHIP:DMG: CommandId = 0xb, [1699002718.021216][1141:1141] CHIP:DMG: }, [1699002718.021274][1141:1141] CHIP:DMG: [1699002718.021317][1141:1141] CHIP:DMG: CommandFields = [1699002718.021365][1141:1141] CHIP:DMG: { [1699002718.021419][1141:1141] CHIP:DMG: 0x0 = [ [1699002718.022011][1141:1141] CHIP:DMG: 0x15, 0x30, 0x01, 0x01, 0x01, 0x24, 0x02, 0x01, 0x37, 0x03, 0x24, 0x14, 0x01, 0x18, 0x26, 0x04, 0x80, 0x22, 0x81, 0x27, 0x26, 0x05, 0x80, 0x25, 0x4d, 0x3a, 0x37, 0x06, 0x24, 0x14, 0x01, 0x18, 0x24, 0x07, 0x01, 0x24, 0x08, 0x01, 0x30, 0x09, 0x41, 0x04, 0xb4, 0xe9, 0x16, 0x75, 0x1d, 0x80, 0x4a, 0xf8, 0x1f, 0x41, 0xd3, 0xdf, 0x30, 0xc8, 0xfb, 0x29, 0xbb, 0x44, 0x8c, 0x34, 0x84, 0xbd, 0x9f, 0x75, 0x2a, 0xf4, 0x01, 0xfb, 0xb3, 0xee, 0xa9, 0x26, 0xeb, 0x0c, 0x11, 0xf8, 0xf9, 0xe3, 0xa2, 0xa0, 0xe2, 0xdb, 0x72, 0xa6, 0x0f, 0x4c, 0xdf, 0xaa, 0x98, 0x3c, 0x6c, 0x7f, 0xe4, 0x7b, 0x49, 0xfc, 0x57, 0xc2, 0x50, 0x22, 0x4f, 0x86, 0x77, 0x42, 0x37, 0x0a, 0x35, 0x01, 0x29, 0x01, 0x18, 0x24, 0x02, 0x60, 0x30, 0x04, 0x14, 0x5f, 0xe5, 0x83, 0x90, 0x92, 0x25, 0x7d, 0x58, 0x72, 0x93, 0xa6, 0x3f, 0x4d, 0x1c, 0x8f, 0xe1, 0xad, 0xd2, 0x3f, 0x93, 0x30, 0x05, 0x14, 0x5f, 0xe5, 0x83, 0x90, 0x92, 0x25, 0x7d, 0x58, 0x72, 0x93, 0xa6, 0x3f, 0x4d, 0x1c, 0x8f, 0xe1, 0xad, 0xd2, 0x3f, 0x93, 0x18, 0x30, 0x0b, 0x40, 0x65, 0xc5, 0xf9, 0x2e, 0x21, 0xa1, 0xd9, 0x55, 0x09, 0x45, 0x07, 0x22, 0xf0, 0x97, 0xc1, 0x74, 0x7c, 0xac, 0x70, 0x06, 0xdb, 0x5c, 0xc5, 0x30, 0xde, 0x3a, 0x86, 0x0d, 0x33, 0x61, 0xd0, 0xbb, 0xd1, 0x90, 0x5b, 0xe9, 0x12, 0x1d, 0xb7, 0x5b, 0x55, 0x24, 0x03, 0xad, 0x88, 0x9a, 0x55, 0x82, 0xba, 0xb5, 0x98, 0x42, 0xbd, 0x0e, 0x50, 0x9f, 0xad, 0xa2, 0x32, 0x63, 0x6f, 0x9b, 0xc4, 0x32, 0x18, [1699002718.022078][1141:1141] CHIP:DMG: ] (231 bytes) [1699002718.022128][1141:1141] CHIP:DMG: }, [1699002718.022167][1141:1141] CHIP:DMG: }, [1699002718.022235][1141:1141] CHIP:DMG: [1699002718.022273][1141:1141] CHIP:DMG: ], [1699002718.022350][1141:1141] CHIP:DMG: [1699002718.022398][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002718.022435][1141:1141] CHIP:DMG: }, [1699002718.022692][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1699002718.022753][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002718.022819][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B [1699002718.023032][1141:1141] CHIP:ZCL: OpCreds: Received an AddTrustedRootCertificate command [1699002718.026596][1141:1141] CHIP:ZCL: OpCreds: AddTrustedRootCertificate successful. [1699002718.026716][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002718.026783][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002718.026821][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002718.026949][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002718.027214][1141:1141] CHIP:EM: <<< [E:26217r S:27946 M:186828893] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002718.027805][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002718.027834][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002718.112479][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002718.115266][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002718.116952][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002718.212266][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002718.219277][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002718.307718][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002718.310430][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002718.311222][1141:1141] CHIP:EM: >>> [E:26218r S:27946 M:120084046] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002718.311358][1141:1141] CHIP:EM: Handling via exchange: 26218r, Delegate: 0xaaaab786c308 [1699002718.311595][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002718.311651][1141:1141] CHIP:DMG: { [1699002718.311699][1141:1141] CHIP:DMG: suppressResponse = false, [1699002718.311749][1141:1141] CHIP:DMG: timedRequest = false, [1699002718.311792][1141:1141] CHIP:DMG: InvokeRequests = [1699002718.311888][1141:1141] CHIP:DMG: [ [1699002718.311933][1141:1141] CHIP:DMG: CommandDataIB = [1699002718.311982][1141:1141] CHIP:DMG: { [1699002718.312022][1141:1141] CHIP:DMG: CommandPathIB = [1699002718.312071][1141:1141] CHIP:DMG: { [1699002718.312124][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002718.312174][1141:1141] CHIP:DMG: ClusterId = 0x3e, [1699002718.312220][1141:1141] CHIP:DMG: CommandId = 0x6, [1699002718.312258][1141:1141] CHIP:DMG: }, [1699002718.312317][1141:1141] CHIP:DMG: [1699002718.312361][1141:1141] CHIP:DMG: CommandFields = [1699002718.312410][1141:1141] CHIP:DMG: { [1699002718.312464][1141:1141] CHIP:DMG: 0x0 = [ [1699002718.313050][1141:1141] CHIP:DMG: 0x15, 0x30, 0x01, 0x01, 0x01, 0x24, 0x02, 0x01, 0x37, 0x03, 0x24, 0x13, 0x02, 0x18, 0x26, 0x04, 0x80, 0x22, 0x81, 0x27, 0x26, 0x05, 0x80, 0x25, 0x4d, 0x3a, 0x37, 0x06, 0x24, 0x15, 0x01, 0x25, 0x11, 0xce, 0x07, 0x18, 0x24, 0x07, 0x01, 0x24, 0x08, 0x01, 0x30, 0x09, 0x41, 0x04, 0x0f, 0xe3, 0xfa, 0xac, 0xdf, 0x75, 0xb4, 0xe5, 0x94, 0x81, 0xe1, 0xcd, 0x8b, 0x3a, 0xe4, 0xec, 0xc9, 0x01, 0x86, 0xe1, 0x51, 0x74, 0x13, 0x51, 0xad, 0x0e, 0x7f, 0x13, 0x36, 0xfb, 0x93, 0x1a, 0x2a, 0x54, 0xa4, 0x40, 0x3c, 0x28, 0xc0, 0xd2, 0x08, 0x30, 0x72, 0x8d, 0x14, 0x09, 0x7e, 0xcd, 0xe0, 0x43, 0xe1, 0xa3, 0x10, 0x0e, 0xef, 0xd7, 0xa9, 0xc4, 0x9c, 0xb1, 0x02, 0x8f, 0x72, 0x0e, 0x37, 0x0a, 0x35, 0x01, 0x28, 0x01, 0x18, 0x24, 0x02, 0x01, 0x36, 0x03, 0x04, 0x02, 0x04, 0x01, 0x18, 0x30, 0x04, 0x14, 0x1a, 0x71, 0x87, 0xad, 0x07, 0xbd, 0xcc, 0x24, 0x15, 0xa1, 0x6f, 0x8a, 0x83, 0xb6, 0xcd, 0x2e, 0x86, 0x83, 0x5e, 0x06, 0x30, 0x05, 0x14, 0x71, 0x7d, 0xab, 0x41, 0x37, 0x07, 0x0d, 0x8a, 0x0b, 0x43, 0xae, 0xde, 0x91, 0x80, 0x9e, 0x2b, 0xbb, 0xb5, 0xd6, 0xf7, 0x18, 0x30, 0x0b, 0x40, 0xf7, 0xf7, 0x2a, 0xa9, 0x78, 0x49, 0xf6, 0xbc, 0x82, 0x51, 0x25, 0xc2, 0xf7, 0x34, 0xc9, 0xf5, 0xf0, 0x48, 0xa3, 0x3d, 0x35, 0x7b, 0x2c, 0x7a, 0xf6, 0x46, 0xcc, 0xc6, 0xde, 0x3a, 0x2c, 0x09, 0xc3, 0xa2, 0x88, 0xc3, 0x83, 0xce, 0x7b, 0xc4, 0x5e, 0xfa, 0x94, 0x7b, 0xdd, 0x25, 0x96, 0xc9, 0x77, 0x57, 0xbb, 0xc9, 0x69, 0x5f, 0x35, 0x54, 0xf4, 0x42, 0x9e, 0x69, 0xd8, 0x14, 0x71, 0x6e, 0x18, [1699002718.313110][1141:1141] CHIP:DMG: ] (242 bytes) [1699002718.313159][1141:1141] CHIP:DMG: 0x1 = [ [1699002718.313767][1141:1141] CHIP:DMG: 0x15, 0x30, 0x01, 0x01, 0x01, 0x24, 0x02, 0x01, 0x37, 0x03, 0x24, 0x14, 0x01, 0x18, 0x26, 0x04, 0x80, 0x22, 0x81, 0x27, 0x26, 0x05, 0x80, 0x25, 0x4d, 0x3a, 0x37, 0x06, 0x24, 0x13, 0x02, 0x18, 0x24, 0x07, 0x01, 0x24, 0x08, 0x01, 0x30, 0x09, 0x41, 0x04, 0x44, 0xfa, 0x2c, 0xe6, 0x1f, 0x0d, 0xda, 0x77, 0x18, 0x30, 0xef, 0x92, 0xb3, 0x55, 0x2c, 0xd0, 0x62, 0x63, 0x88, 0x07, 0xfa, 0x88, 0xe4, 0xc1, 0x18, 0xf5, 0x82, 0x47, 0x9a, 0x1f, 0xf9, 0xad, 0xd5, 0x1c, 0xc2, 0xbc, 0xd0, 0x91, 0x0e, 0xba, 0x47, 0xeb, 0x5a, 0xce, 0x6f, 0x8e, 0x09, 0xf2, 0x22, 0x49, 0x17, 0xa9, 0x0d, 0x80, 0xf1, 0xc3, 0xda, 0xad, 0x7c, 0x4c, 0x92, 0x54, 0xa7, 0xb1, 0x37, 0x0a, 0x35, 0x01, 0x29, 0x01, 0x18, 0x24, 0x02, 0x60, 0x30, 0x04, 0x14, 0x71, 0x7d, 0xab, 0x41, 0x37, 0x07, 0x0d, 0x8a, 0x0b, 0x43, 0xae, 0xde, 0x91, 0x80, 0x9e, 0x2b, 0xbb, 0xb5, 0xd6, 0xf7, 0x30, 0x05, 0x14, 0x5f, 0xe5, 0x83, 0x90, 0x92, 0x25, 0x7d, 0x58, 0x72, 0x93, 0xa6, 0x3f, 0x4d, 0x1c, 0x8f, 0xe1, 0xad, 0xd2, 0x3f, 0x93, 0x18, 0x30, 0x0b, 0x40, 0x45, 0xe7, 0xc1, 0x7a, 0x08, 0x8b, 0xa1, 0xc6, 0xc7, 0xbe, 0x57, 0x02, 0xc3, 0xf5, 0x83, 0x9a, 0x30, 0x97, 0x29, 0xf7, 0xe3, 0x7b, 0x01, 0x8a, 0x55, 0xa0, 0xc0, 0x6d, 0xc6, 0x7e, 0xc0, 0x1d, 0x33, 0x79, 0x34, 0x66, 0xe3, 0x90, 0xa9, 0x88, 0x3a, 0xfe, 0x98, 0x57, 0x14, 0xb4, 0xf2, 0xbe, 0x09, 0x12, 0xe1, 0x4a, 0x2d, 0xd1, 0x19, 0x60, 0xeb, 0xec, 0x27, 0x62, 0x08, 0x0e, 0x67, 0x1e, 0x18, [1699002718.313852][1141:1141] CHIP:DMG: ] (231 bytes) [1699002718.313914][1141:1141] CHIP:DMG: 0x2 = [ [1699002718.313991][1141:1141] CHIP:DMG: 0x74, 0x65, 0x6d, 0x70, 0x6f, 0x72, 0x61, 0x72, 0x79, 0x20, 0x69, 0x70, 0x6b, 0x20, 0x30, 0x31, [1699002718.314046][1141:1141] CHIP:DMG: ] (16 bytes) [1699002718.314107][1141:1141] CHIP:DMG: 0x3 = 112233, [1699002718.314158][1141:1141] CHIP:DMG: 0x4 = 65521, [1699002718.314208][1141:1141] CHIP:DMG: }, [1699002718.314246][1141:1141] CHIP:DMG: }, [1699002718.314326][1141:1141] CHIP:DMG: [1699002718.314365][1141:1141] CHIP:DMG: ], [1699002718.314452][1141:1141] CHIP:DMG: [1699002718.314498][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002718.314534][1141:1141] CHIP:DMG: }, [1699002718.314814][1141:1141] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1699002718.314873][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002718.314940][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 [1699002718.315191][1141:1141] CHIP:ZCL: OpCreds: Received an AddNOC command [1699002718.320932][1141:1141] CHIP:FP: Validating NOC chain [1699002718.326166][1141:1141] CHIP:FP: NOC chain validation successful [1699002718.326267][1141:1141] CHIP:FP: Added new fabric at index: 0x1 [1699002718.326282][1141:1141] CHIP:FP: Assigned compressed fabric ID: 0x027FBA21A63140CE, node ID: 0x00000000000007CE [1699002718.326325][1141:1141] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1699002718.326343][1141:1141] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1699002718.326358][1141:1141] CHIP:TS: Retaining current Last Known Good Time [1699002718.326398][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to f19c1dbb [1699002718.326424][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to f19c1dbc [1699002718.328128][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-xaM5D0) [1699002718.329137][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002718.329626][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-8oUrlX) [1699002718.330393][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002718.330741][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-5DUTOV) [1699002718.331409][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002718.331583][1141:1141] CHIP:DMG: AccessControl: validating f=1 p=a a=c s=1 t=0 [1699002718.331612][1141:1141] CHIP:DMG: validating subject 0x000000000001B669 [1699002718.331973][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-Xx05f8) [1699002718.332712][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002718.333148][1141:1141] CHIP:EVL: LogEvent event number: 0x0000000000000002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Epoch timestamp: 0x0000018B9474187C [1699002718.333181][1141:1141] CHIP:ZCL: OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669 [1699002718.333729][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002718.333802][1141:1141] CHIP:DIS: Advertise operational node 027FBA21A63140CE-00000000000007CE [1699002718.333958][1141:1141] CHIP:DIS: Responding with _matter._tcp.local [1699002718.333991][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002718.334029][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002718.334047][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002718.334063][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002718.334100][1141:1141] CHIP:DIS: Responding with _I027FBA21A63140CE._sub._matter._tcp.local [1699002718.334114][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 027FBA21A63140CE-00000000000007CE. [1699002718.335686][1141:1141] CHIP:DIS: mDNS service published: _matter._tcp [1699002718.335740][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to f19c1dbd [1699002718.335769][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to f19c1dbe [1699002718.335837][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002718.335889][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002718.335932][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002718.335948][1141:1141] CHIP:ZCL: OpCreds: successfully created fabric index 0x1 via AddNOC [1699002718.336085][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002718.336322][1141:1141] CHIP:EM: <<< [E:26218r S:27946 M:186828894] (S) Msg TX to 1:FFFFFFFB00000000 [40CE] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002718.336858][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002718.336883][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002718.405363][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002718.406099][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002718.407208][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002718.407804][1141:1141] CHIP:EM: >>> [E:26219r S:27946 M:120084047] (S) Msg RX from 1:FFFFFFFB00000000 [40CE] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002718.407889][1141:1141] CHIP:EM: Handling via exchange: 26219r, Delegate: 0xaaaab786c308 [1699002718.408024][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002718.408047][1141:1141] CHIP:DMG: { [1699002718.408066][1141:1141] CHIP:DMG: suppressResponse = false, [1699002718.408086][1141:1141] CHIP:DMG: timedRequest = false, [1699002718.408101][1141:1141] CHIP:DMG: InvokeRequests = [1699002718.408134][1141:1141] CHIP:DMG: [ [1699002718.408149][1141:1141] CHIP:DMG: CommandDataIB = [1699002718.408169][1141:1141] CHIP:DMG: { [1699002718.408182][1141:1141] CHIP:DMG: CommandPathIB = [1699002718.408201][1141:1141] CHIP:DMG: { [1699002718.408221][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002718.408238][1141:1141] CHIP:DMG: ClusterId = 0x31, [1699002718.408253][1141:1141] CHIP:DMG: CommandId = 0x2, [1699002718.408266][1141:1141] CHIP:DMG: }, [1699002718.408290][1141:1141] CHIP:DMG: [1699002718.408306][1141:1141] CHIP:DMG: CommandFields = [1699002718.408328][1141:1141] CHIP:DMG: { [1699002718.408350][1141:1141] CHIP:DMG: 0x0 = [ [1699002718.408369][1141:1141] CHIP:DMG: 0x4d, 0x4d, 0x2d, 0x4c, 0x41, 0x42, [1699002718.408389][1141:1141] CHIP:DMG: ] (6 bytes) [1699002718.408404][1141:1141] CHIP:DMG: 0x1 = [ [1699002718.408426][1141:1141] CHIP:DMG: 0x4c, 0x61, 0x62, 0x43, 0x6f, 0x61, 0x74, 0x43, 0x6f, 0x64, 0x65, [1699002718.408442][1141:1141] CHIP:DMG: ] (11 bytes) [1699002718.408461][1141:1141] CHIP:DMG: 0x2 = 20, [1699002718.408477][1141:1141] CHIP:DMG: }, [1699002718.408490][1141:1141] CHIP:DMG: }, [1699002718.408517][1141:1141] CHIP:DMG: [1699002718.408530][1141:1141] CHIP:DMG: ], [1699002718.408564][1141:1141] CHIP:DMG: [1699002718.408580][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002718.408592][1141:1141] CHIP:DMG: }, [1699002718.413114][1141:1141] CHIP:DMG: AccessControl: checking f=1 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=a [1699002718.413200][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002718.413274][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0002 [1699002718.413550][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002718.413631][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002718.413681][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002718.413748][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to d0fd56fa [1699002718.413833][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002718.414094][1141:1141] CHIP:EM: <<< [E:26219r S:27946 M:186828895] (S) Msg TX to 1:FFFFFFFB00000000 [40CE] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002718.414588][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002718.414611][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002718.502817][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002718.503349][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002718.504392][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002718.504936][1141:1141] CHIP:EM: >>> [E:26220r S:27946 M:120084048] (S) Msg RX from 1:FFFFFFFB00000000 [40CE] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002718.505013][1141:1141] CHIP:EM: Handling via exchange: 26220r, Delegate: 0xaaaab786c308 [1699002718.505158][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002718.505177][1141:1141] CHIP:DMG: { [1699002718.505196][1141:1141] CHIP:DMG: suppressResponse = false, [1699002718.505216][1141:1141] CHIP:DMG: timedRequest = false, [1699002718.505232][1141:1141] CHIP:DMG: InvokeRequests = [1699002718.505261][1141:1141] CHIP:DMG: [ [1699002718.505276][1141:1141] CHIP:DMG: CommandDataIB = [1699002718.505294][1141:1141] CHIP:DMG: { [1699002718.505308][1141:1141] CHIP:DMG: CommandPathIB = [1699002718.505328][1141:1141] CHIP:DMG: { [1699002718.505350][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002718.505369][1141:1141] CHIP:DMG: ClusterId = 0x30, [1699002718.505384][1141:1141] CHIP:DMG: CommandId = 0x0, [1699002718.505397][1141:1141] CHIP:DMG: }, [1699002718.505421][1141:1141] CHIP:DMG: [1699002718.505437][1141:1141] CHIP:DMG: CommandFields = [1699002718.505454][1141:1141] CHIP:DMG: { [1699002718.505474][1141:1141] CHIP:DMG: 0x0 = 66, [1699002718.505491][1141:1141] CHIP:DMG: 0x1 = 22, [1699002718.505508][1141:1141] CHIP:DMG: }, [1699002718.505521][1141:1141] CHIP:DMG: }, [1699002718.505548][1141:1141] CHIP:DMG: [1699002718.505561][1141:1141] CHIP:DMG: ], [1699002718.505663][1141:1141] CHIP:DMG: [1699002718.505683][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002718.505695][1141:1141] CHIP:DMG: }, [1699002718.505868][1141:1141] CHIP:DMG: AccessControl: checking f=1 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1699002718.505896][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002718.505929][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 [1699002718.506010][1141:1141] CHIP:FS: GeneralCommissioning: Received ArmFailSafe (66s) [1699002718.506156][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to d0fd56fb [1699002718.506277][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002718.506328][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002718.506382][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002718.506473][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002718.506738][1141:1141] CHIP:EM: <<< [E:26220r S:27946 M:186828896] (S) Msg TX to 1:FFFFFFFB00000000 [40CE] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002718.507207][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002718.507230][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002718.600379][1141:1142] CHIP:BLE: Indication confirmation, 0xffff80c06ed0 [1699002718.601351][1141:1142] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1699002718.603741][1141:1142] CHIP:BLE: Write request received debug 0xffff80c06ed0 [1699002718.604505][1141:1141] CHIP:EM: >>> [E:26221r S:27946 M:120084049] (S) Msg RX from 1:FFFFFFFB00000000 [40CE] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002718.604641][1141:1141] CHIP:EM: Handling via exchange: 26221r, Delegate: 0xaaaab786c308 [1699002718.604868][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002718.604923][1141:1141] CHIP:DMG: { [1699002718.604971][1141:1141] CHIP:DMG: suppressResponse = false, [1699002718.605026][1141:1141] CHIP:DMG: timedRequest = false, [1699002718.605068][1141:1141] CHIP:DMG: InvokeRequests = [1699002718.605151][1141:1141] CHIP:DMG: [ [1699002718.605195][1141:1141] CHIP:DMG: CommandDataIB = [1699002718.605247][1141:1141] CHIP:DMG: { [1699002718.605287][1141:1141] CHIP:DMG: CommandPathIB = [1699002718.605336][1141:1141] CHIP:DMG: { [1699002718.605390][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002718.605440][1141:1141] CHIP:DMG: ClusterId = 0x31, [1699002718.605486][1141:1141] CHIP:DMG: CommandId = 0x6, [1699002718.605524][1141:1141] CHIP:DMG: }, [1699002718.605645][1141:1141] CHIP:DMG: [1699002718.605697][1141:1141] CHIP:DMG: CommandFields = [1699002718.605749][1141:1141] CHIP:DMG: { [1699002718.605802][1141:1141] CHIP:DMG: 0x0 = [ [1699002718.605857][1141:1141] CHIP:DMG: 0x4d, 0x4d, 0x2d, 0x4c, 0x41, 0x42, [1699002718.605911][1141:1141] CHIP:DMG: ] (6 bytes) [1699002718.605968][1141:1141] CHIP:DMG: 0x1 = 24, [1699002718.606019][1141:1141] CHIP:DMG: }, [1699002718.606057][1141:1141] CHIP:DMG: }, [1699002718.606132][1141:1141] CHIP:DMG: [1699002718.606172][1141:1141] CHIP:DMG: ], [1699002718.606254][1141:1141] CHIP:DMG: [1699002718.606303][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002718.606339][1141:1141] CHIP:DMG: }, [1699002718.606616][1141:1141] CHIP:DMG: AccessControl: checking f=1 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=a [1699002718.606676][1141:1141] CHIP:DMG: AccessControl: implicit admin (PASE) [1699002718.606747][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 [1699002718.606811][1141:1141] CHIP:NP: Commands::ConnectNetwork::Id PostCloseAllBLEConnectionsToOperationalNetworkEvent [1699002718.607096][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 1 [1699002718.607225][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 32777 [1699002718.607275][1141:1141] CHIP:SVR: CommissioningWindowManager::OnPlatformEvent::kCloseAllBleConnections [1699002718.607333][1141:1141] CHIP:IN: Clearing BLE pending packets. [1699002718.607371][1141:1141] CHIP:BLE: Releasing end point's BLE connection back to application. [1699002718.607405][1141:1141] CHIP:BLE: Got notification regarding chip connection closure [1699002718.607612][1141:1142] CHIP:DL: wpa_supplicant: Start WiFi management [1699002718.623203][1141:1142] CHIP:DL: wpa_supplicant: connected to wpa_supplicant proxy [1699002718.625140][1141:1142] CHIP:DL: wpa_supplicant: WiFi interface: /fi/w1/wpa_supplicant1/Interfaces/0 [1699002718.642804][1141:1142] CHIP:DL: wpa_supplicant: connected to wpa_supplicant interface proxy [1699002718.643472][1141:1142] CHIP:DL: wpa_supplicant: connected to wpa_supplicant bss proxy [1699002718.713978][1141:1141] CHIP:DL: Non-concurrent mode Wi-Fi Management Started. [1699002718.714059][1141:1141] CHIP:DL: Long dispatch time: 107 ms, for event type 32777 [1699002718.714089][1141:1141] CHIP:DL: wpa_supplicant: disabling auto scan [1699002718.717282][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 32778 [1699002718.717376][1141:1141] CHIP:NP: HandleNonConcurrentConnectNetwork() SSID=MM-LAB [1699002718.717422][1141:1141] CHIP:NP: LinuxWiFiDriver: SSID: MM-LAB [1699002718.739056][1141:1141] CHIP:DL: wpa_supplicant: added network: /fi/w1/wpa_supplicant1/Interfaces/0/Networks/0 [1699002718.768011][1141:1142] CHIP:DL: wpa_supplicant:PropertiesChanged:key:State -> 'scanning' [1699002718.768142][1141:1142] CHIP:DL: wpa_supplicant:PropertiesChanged:key:Scanning -> true [1699002721.593933][1141:1142] CHIP:DL: wpa_supplicant: network scan done [1699002721.594900][1141:1142] CHIP:DL: wpa_supplicant:PropertiesChanged:key:Scanning -> false [1699002721.595135][1141:1142] CHIP:DL: wpa_supplicant:PropertiesChanged:key:BSSs -> [objectpath '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/0', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/1', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/2', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/3', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/4', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/5', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/6', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/7', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/8', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/9', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/10', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/11', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/12', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/13', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/14', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/15', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/16', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/17', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/18', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/19', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/20', '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/21'] [1699002721.609765][1141:1142] CHIP:DL: wpa_supplicant:PropertiesChanged:key:State -> 'associating' [1699002724.510697][1141:1142] CHIP:DL: wpa_supplicant:PropertiesChanged:key:State -> 'completed' [1699002724.510809][1141:1142] CHIP:DL: wpa_supplicant:PropertiesChanged:key:CurrentBSS -> objectpath '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/0' [1699002724.510842][1141:1142] CHIP:DL: wpa_supplicant:PropertiesChanged:key:CurrentAuthMode -> 'WPA2-PSK+WPA-PSK' [1699002724.510934][1141:1141] CHIP:NP: Instance::OnResult Non-Concurrent Mode, ConnectNetworkResponse will NOT be sent [1699002724.510993][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to d0fd56fc [1699002724.511034][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002724.511092][1141:1141] CHIP:DMG: Failed to send command response: src/app/CommandHandler.cpp:221: CHIP Error 0x00000003: Incorrect state [1699002724.511108][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002724.705617][1141:1141] CHIP:DL: dhclient is running on the wlan0 interface. [1699002724.705731][1141:1141] CHIP:DL: Long dispatch time: 195 ms, for event type 3 [1699002724.705818][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 32785 [1699002724.706713][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002724.706812][1141:1141] CHIP:DIS: Advertise operational node 027FBA21A63140CE-00000000000007CE [1699002724.707018][1141:1141] CHIP:DIS: Responding with _matter._tcp.local [1699002724.707086][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002724.707165][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002724.707254][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.707302][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.707378][1141:1141] CHIP:DIS: Responding with _I027FBA21A63140CE._sub._matter._tcp.local [1699002724.707419][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 027FBA21A63140CE-00000000000007CE. [1699002724.715634][1141:1141] CHIP:DIS: Failed to advertise records: src/lib/dnssd/minimal_mdns/Server.cpp:344: CHIP Error 0x00000046: No endpoint was available to send the message [1699002724.715747][1141:1141] CHIP:DIS: mDNS service published: _matter._tcp [1699002724.715801][1141:1141] CHIP:SVR: Operational advertising enabled [1699002724.761069][1141:1142] CHIP:DL: Got IP address on interface: wlan0 IP: 172.16.62.162 [1699002724.763605][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 32770 [1699002724.763667][1141:1141] CHIP:DL: EventHandler: DeviceEventType::kInternetConnectivityChange [1699002724.763700][1141:1141] CHIP:DL: EventHandler: posted kDnssdRestartNeeded [1699002724.763726][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 32787 [1699002724.763747][1141:1141] CHIP:DIS: Updating services using commissioning mode 0 [1699002724.772294][1141:1141] CHIP:DIS: CHIP minimal mDNS started advertising. [1699002724.781283][1141:1141] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.781331][1141:1141] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1699002724.781362][1141:1141] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.788995][1141:1141] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.789044][1141:1141] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1699002724.789071][1141:1141] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.789548][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002724.789955][1141:1141] CHIP:DIS: Advertise operational node 027FBA21A63140CE-00000000000007CE [1699002724.790138][1141:1141] CHIP:DIS: Responding with _matter._tcp.local [1699002724.790177][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002724.790216][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002724.790234][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.790251][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.790286][1141:1141] CHIP:DIS: Responding with _I027FBA21A63140CE._sub._matter._tcp.local [1699002724.790300][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 027FBA21A63140CE-00000000000007CE. [1699002724.796459][1141:1141] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.796529][1141:1141] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1699002724.796560][1141:1141] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.796611][1141:1141] CHIP:DIS: mDNS service published: _matter._tcp [1699002724.797126][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002724.797429][1141:1141] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=0 [1699002724.797559][1141:1141] CHIP:DIS: Responding with _matterc._udp.local [1699002724.798041][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002724.798071][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.798123][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.798180][1141:1141] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1699002724.798214][1141:1141] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1699002724.798242][1141:1141] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1699002724.798284][1141:1141] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1699002724.798359][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002724.798375][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: CB8C096D0BF02F51. [1699002724.806258][1141:1141] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.806320][1141:1141] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1699002724.806352][1141:1141] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.806400][1141:1141] CHIP:DIS: mDNS service published: _matterc._udp [1699002724.806472][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1699002724.806501][1141:1141] CHIP:SVR: Server initialization complete [1699002724.806550][1141:1141] CHIP:DIS: Updating services using commissioning mode 0 [1699002724.811052][1141:1141] CHIP:DIS: CHIP minimal mDNS started advertising. [1699002724.819318][1141:1141] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.819372][1141:1141] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1699002724.819399][1141:1141] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.827195][1141:1141] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.827253][1141:1141] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1699002724.827280][1141:1141] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.827838][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002724.827933][1141:1141] CHIP:DIS: Advertise operational node 027FBA21A63140CE-00000000000007CE [1699002724.828078][1141:1141] CHIP:DIS: Responding with _matter._tcp.local [1699002724.828113][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002724.828148][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002724.828165][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.828180][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.828212][1141:1141] CHIP:DIS: Responding with _I027FBA21A63140CE._sub._matter._tcp.local [1699002724.828225][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 027FBA21A63140CE-00000000000007CE. [1699002724.834696][1141:1141] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.834754][1141:1141] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1699002724.834781][1141:1141] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.834833][1141:1141] CHIP:DIS: mDNS service published: _matter._tcp [1699002724.835261][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002724.835540][1141:1141] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=0 [1699002724.835637][1141:1141] CHIP:DIS: Responding with _matterc._udp.local [1699002724.835666][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002724.835683][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.835700][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002724.835737][1141:1141] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1699002724.835765][1141:1141] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1699002724.835792][1141:1141] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1699002724.835815][1141:1141] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1699002724.835879][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002724.835895][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: CB8C096D0BF02F51. [1699002724.843510][1141:1141] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.843571][1141:1141] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1699002724.843604][1141:1141] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1699002724.843652][1141:1141] CHIP:DIS: mDNS service published: _matterc._udp [1699002724.843728][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 32790 [1699002724.847391][1141:1141] CHIP:IM: No subscriptions to resume [1699002727.071222][1141:1141] CHIP:EM: >>> [E:26222r S:0 M:82986294] (U) Msg RX from 0:60F75BDCA4C9D94B [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1699002727.071392][1141:1141] CHIP:EM: Handling via exchange: 26222r, Delegate: 0xaaaab7875160 [1699002727.071530][1141:1141] CHIP:IN: CASE Server received Sigma1 message . Starting handshake. EC 0xffff8001d140 [1699002727.071702][1141:1141] CHIP:SC: Received Sigma1 msg [1699002727.071939][1141:1141] CHIP:SC: Peer assigned session key ID 3194 [1699002727.075171][1141:1141] CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x00000000000007CE [1699002727.087067][1141:1141] CHIP:EM: <<< [E:26222r S:0 M:211636712 (Ack:82986294)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:45113] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1699002727.087623][1141:1141] CHIP:SC: Sent Sigma2 msg [1699002727.108992][1141:1141] CHIP:EM: >>> [E:26222r S:0 M:82986295 (Ack:211636712)] (U) Msg RX from 0:60F75BDCA4C9D94B [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1699002727.109073][1141:1141] CHIP:EM: Found matching exchange: 26222r, Delegate: 0xaaaab7875198 [1699002727.109172][1141:1141] CHIP:EM: Rxd Ack; Removing MessageCounter:211636712 from Retrans Table on exchange 26222r [1699002727.111092][1141:1141] CHIP:SC: Received Sigma3 msg [1699002727.126380][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-8rPCbm) [1699002727.127416][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.127852][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-4tvtb7) [1699002727.128670][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.129000][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-lTBNcM) [1699002727.129773][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.129900][1141:1141] CHIP:SC: Sending status report. Protocol code 0, exchange 26222 [1699002727.130222][1141:1141] CHIP:EM: <<< [E:26222r S:0 M:211636713 (Ack:82986295)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:45113] --- Type 0000:40 (SecureChannel:StatusReport) [1699002727.131308][1141:1141] CHIP:SC: SecureSession[0xffff7fa0fa40, LSID:27947]: State change 'kEstablishing' --> 'kActive' [1699002727.131365][1141:1141] CHIP:IN: SecureSession[0xffff7fa0fa40]: Activated - Type:2 LSID:27947 [1699002727.131383][1141:1141] CHIP:IN: New secure session activated for device <000000000001B669, 1>, LSID:27947 PSID:3194! [1699002727.131407][1141:1141] CHIP:IN: CASE Session established to peer: <000000000001B669, 1> [1699002727.131642][1141:1141] CHIP:IN: SecureSession[0xffff7fa2cf00]: Allocated Type:2 LSID:27948 [1699002727.131688][1141:1141] CHIP:SC: Allocated SecureSession (0xffff7fa2cf00) - waiting for Sigma1 msg [1699002727.147448][1141:1141] CHIP:EM: >>> [E:26223r S:27947 M:21517655] (S) Msg RX from 1:000000000001B669 [40CE] --- Type 0001:08 (IM:InvokeCommandRequest) [1699002727.147571][1141:1141] CHIP:EM: Handling via exchange: 26223r, Delegate: 0xaaaab786c308 [1699002727.147772][1141:1141] CHIP:DMG: InvokeRequestMessage = [1699002727.147795][1141:1141] CHIP:DMG: { [1699002727.147813][1141:1141] CHIP:DMG: suppressResponse = false, [1699002727.147833][1141:1141] CHIP:DMG: timedRequest = false, [1699002727.147849][1141:1141] CHIP:DMG: InvokeRequests = [1699002727.147876][1141:1141] CHIP:DMG: [ [1699002727.147891][1141:1141] CHIP:DMG: CommandDataIB = [1699002727.147908][1141:1141] CHIP:DMG: { [1699002727.147922][1141:1141] CHIP:DMG: CommandPathIB = [1699002727.147944][1141:1141] CHIP:DMG: { [1699002727.147967][1141:1141] CHIP:DMG: EndpointId = 0x0, [1699002727.147986][1141:1141] CHIP:DMG: ClusterId = 0x30, [1699002727.148002][1141:1141] CHIP:DMG: CommandId = 0x4, [1699002727.148016][1141:1141] CHIP:DMG: }, [1699002727.148042][1141:1141] CHIP:DMG: [1699002727.148059][1141:1141] CHIP:DMG: CommandFields = [1699002727.148077][1141:1141] CHIP:DMG: { [1699002727.148095][1141:1141] CHIP:DMG: }, [1699002727.148108][1141:1141] CHIP:DMG: }, [1699002727.148133][1141:1141] CHIP:DMG: [1699002727.148146][1141:1141] CHIP:DMG: ], [1699002727.148176][1141:1141] CHIP:DMG: [1699002727.148193][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002727.148205][1141:1141] CHIP:DMG: }, [1699002727.148353][1141:1141] CHIP:DMG: AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0030 e=0 p=a [1699002727.148407][1141:1141] CHIP:DMG: AccessControl: allowed [1699002727.148439][1141:1141] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 [1699002727.148493][1141:1141] CHIP:FS: GeneralCommissioning: Received CommissioningComplete [1699002727.148920][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-lrBtRU) [1699002727.149943][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.150344][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-1zpgu6) [1699002727.151137][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.151254][1141:1141] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1699002727.151571][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-e2cHNs) [1699002727.152346][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.152846][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-qVYwEF) [1699002727.153672][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.153982][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-MSj9tT) [1699002727.154833][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.155136][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-IR2w5h) [1699002727.156154][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.156318][1141:1141] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1699002727.156557][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-Dd7dmr) [1699002727.157347][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.157658][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-Xiwtg1) [1699002727.158567][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.158659][1141:1141] CHIP:ZCL: OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0x027FBA21A63140CE, FabricId 0000000000000001, NodeId 00000000000007CE, VendorId 0xFFF1 [1699002727.158842][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-JCyiSu) [1699002727.160090][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.160188][1141:1141] CHIP:FS: GeneralCommissioning: Successfully commited pending fabric data [1699002727.160243][1141:1141] CHIP:FS: Fail-safe cleanly disarmed [1699002727.160319][1141:1141] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to d0fd56fd [1699002727.160439][1141:1141] CHIP:DMG: Command handler moving to [ Preparing] [1699002727.160496][1141:1141] CHIP:DMG: Command handler moving to [AddingComm] [1699002727.160549][1141:1141] CHIP:DMG: Command handler moving to [AddedComma] [1699002727.160664][1141:1141] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1699002727.161109][1141:1141] CHIP:EM: <<< [E:26223r S:27947 M:202569746 (Ack:21517655)] (S) Msg TX to 1:000000000001B669 [40CE] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:45113] --- Type 0001:09 (IM:InvokeCommandResponse) [1699002727.161551][1141:1141] CHIP:DMG: Command handler moving to [CommandSen] [1699002727.161624][1141:1141] CHIP:DMG: Command handler moving to [AwaitingDe] [1699002727.161715][1141:1141] CHIP:DL: HandlePlatformSpecificBLEEvent 32783 [1699002727.161742][1141:1141] CHIP:SVR: Commissioning completed successfully [1699002727.161797][1141:1141] CHIP:DIS: Updating services using commissioning mode 0 [1699002727.165735][1141:1141] CHIP:DIS: CHIP minimal mDNS started advertising. [1699002727.177902][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002727.178008][1141:1141] CHIP:DIS: Advertise operational node 027FBA21A63140CE-00000000000007CE [1699002727.178176][1141:1141] CHIP:DIS: Responding with _matter._tcp.local [1699002727.178208][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002727.178245][1141:1141] CHIP:DIS: Responding with 027FBA21A63140CE-00000000000007CE._matter._tcp.local [1699002727.178264][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002727.178282][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002727.178324][1141:1141] CHIP:DIS: Responding with _I027FBA21A63140CE._sub._matter._tcp.local [1699002727.178338][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 027FBA21A63140CE-00000000000007CE. [1699002727.183295][1141:1141] CHIP:DIS: mDNS service published: _matter._tcp [1699002727.183726][1141:1141] CHIP:DL: Using wifi MAC for hostname [1699002727.184013][1141:1141] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=0 [1699002727.184108][1141:1141] CHIP:DIS: Responding with _matterc._udp.local [1699002727.184144][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002727.184162][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002727.184179][1141:1141] CHIP:DIS: Responding with E45F01C247AF0000.local [1699002727.184210][1141:1141] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1699002727.184237][1141:1141] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1699002727.184264][1141:1141] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1699002727.184302][1141:1141] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1699002727.184369][1141:1141] CHIP:DIS: Responding with CB8C096D0BF02F51._matterc._udp.local [1699002727.184385][1141:1141] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: CB8C096D0BF02F51. [1699002727.190806][1141:1141] CHIP:DIS: mDNS service published: _matterc._udp [1699002727.190948][1141:1141] CHIP:IN: Expiring all PASE sessions [1699002727.190969][1141:1141] CHIP:IN: SecureSession[0xffff7fa0fb80]: MarkForEviction Type:1 LSID:27946 [1699002727.190994][1141:1141] CHIP:SC: SecureSession[0xffff7fa0fb80, LSID:27946]: State change 'kActive' --> 'kPendingEviction' [1699002727.191035][1141:1141] CHIP:IN: SecureSession[0xffff7fa0fb80]: Released - Type:1 LSID:27946 [1699002727.191065][1141:1141] CHIP:ZCL: Commissioning complete, notify platform driver to persist network credentials. [1699002727.191425][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-DiEpse) [1699002727.192556][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.192845][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-C7hmze) [1699002727.194203][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002727.194339][1141:1141] CHIP:DL: wpa_supplicant: save config [1699002727.240669][1141:1141] CHIP:DL: wpa_supplicant: save config succeeded! [1699002727.241203][1141:1141] CHIP:EM: >>> [E:26222r S:0 M:82986296 (Ack:211636713)] (U) Msg RX from 0:60F75BDCA4C9D94B [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1699002727.241242][1141:1141] CHIP:EM: Found matching exchange: 26222r, Delegate: (nil) [1699002727.241421][1141:1141] CHIP:EM: Rxd Ack; Removing MessageCounter:211636713 from Retrans Table on exchange 26222r [1699002727.244240][1141:1141] CHIP:DIS: SRV record already actively processed. [1699002727.247468][1141:1141] CHIP:DIS: SRV record already actively processed. [1699002727.248173][1141:1141] CHIP:DIS: SRV record already actively processed. [1699002727.250886][1141:1141] CHIP:DIS: SRV record already actively processed. [1699002727.500072][1141:1141] CHIP:EM: Retransmitting MessageCounter:202569746 on exchange 26223r Send Cnt 1 [1699002727.834159][1141:1141] CHIP:EM: Retransmitting MessageCounter:202569746 on exchange 26223r Send Cnt 2 [1699002728.362662][1141:1141] CHIP:EM: Retransmitting MessageCounter:202569746 on exchange 26223r Send Cnt 3 [1699002729.369623][1141:1141] CHIP:EM: Retransmitting MessageCounter:202569746 on exchange 26223r Send Cnt 4 [1699002729.381510][1141:1141] CHIP:EM: >>> [E:26223r S:27947 M:21517656 (Ack:202569746)] (S) Msg RX from 1:000000000001B669 [40CE] --- Type 0000:10 (SecureChannel:StandaloneAck) [1699002729.381651][1141:1141] CHIP:EM: Found matching exchange: 26223r, Delegate: (nil) [1699002729.381777][1141:1141] CHIP:EM: Rxd Ack; Removing MessageCounter:202569746 from Retrans Table on exchange 26223r [1699002729.621337][1141:1142] CHIP:DL: Bluez disconnected [1699002729.621425][1141:1142] CHIP:DL: Bluez notify CHIPoBluez connection disconnected [1699002736.772841][1141:1141] CHIP:EM: >>> [E:61730r S:0 M:156899182] (U) Msg RX from 0:A50896979672C69B [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1699002736.772941][1141:1141] CHIP:EM: Handling via exchange: 61730r, Delegate: 0xaaaab7875160 [1699002736.773018][1141:1141] CHIP:IN: CASE Server received Sigma1 message . Starting handshake. EC 0xffff800262c0 [1699002736.773091][1141:1141] CHIP:SC: Received Sigma1 msg [1699002736.773223][1141:1141] CHIP:SC: Peer assigned session key ID 8525 [1699002736.776748][1141:1141] CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x00000000000007CE [1699002736.790330][1141:1141] CHIP:EM: <<< [E:61730r S:0 M:211636714 (Ack:156899182)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:36036] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1699002736.790737][1141:1141] CHIP:SC: Sent Sigma2 msg [1699002736.815930][1141:1141] CHIP:EM: >>> [E:61730r S:0 M:156899183 (Ack:211636714)] (U) Msg RX from 0:A50896979672C69B [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1699002736.815983][1141:1141] CHIP:EM: Found matching exchange: 61730r, Delegate: 0xaaaab7875198 [1699002736.816048][1141:1141] CHIP:EM: Rxd Ack; Removing MessageCounter:211636714 from Retrans Table on exchange 61730r [1699002736.816156][1141:1141] CHIP:SC: Received Sigma3 msg [1699002736.830227][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-3dZqwg) [1699002736.831299][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002736.831660][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-TlPOC1) [1699002736.832946][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002736.833309][1141:1141] CHIP:DL: writing settings to file (/tmp/chip_kvs-6cdSpL) [1699002736.834491][1141:1141] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1699002736.834590][1141:1141] CHIP:SC: Sending status report. Protocol code 0, exchange 61730 [1699002736.834916][1141:1141] CHIP:EM: <<< [E:61730r S:0 M:211636715 (Ack:156899183)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:36036] --- Type 0000:40 (SecureChannel:StatusReport) [1699002736.835877][1141:1141] CHIP:SC: SecureSession[0xffff7fa2cf00, LSID:27948]: State change 'kEstablishing' --> 'kActive' [1699002736.835922][1141:1141] CHIP:IN: SecureSession[0xffff7fa2cf00]: Activated - Type:2 LSID:27948 [1699002736.835939][1141:1141] CHIP:IN: New secure session activated for device <000000000001B669, 1>, LSID:27948 PSID:8525! [1699002736.835959][1141:1141] CHIP:IN: CASE Session established to peer: <000000000001B669, 1> [1699002736.836159][1141:1141] CHIP:IN: SecureSession[0xffff7fa39c00]: Allocated Type:2 LSID:27949 [1699002736.836208][1141:1141] CHIP:SC: Allocated SecureSession (0xffff7fa39c00) - waiting for Sigma1 msg [1699002736.855535][1141:1141] CHIP:EM: >>> [E:61731r S:27948 M:227096689] (S) Msg RX from 1:000000000001B669 [40CE] --- Type 0001:02 (IM:ReadRequest) [1699002736.855609][1141:1141] CHIP:EM: Handling via exchange: 61731r, Delegate: 0xaaaab786c308 [1699002736.855691][1141:1141] CHIP:IM: Received Read request [1699002736.855805][1141:1141] CHIP:DMG: ReadRequestMessage = [1699002736.855834][1141:1141] CHIP:DMG: { [1699002736.855851][1141:1141] CHIP:DMG: AttributePathIBs = [1699002736.855869][1141:1141] CHIP:DMG: [ [1699002736.855883][1141:1141] CHIP:DMG: AttributePathIB = [1699002736.855901][1141:1141] CHIP:DMG: { [1699002736.855924][1141:1141] CHIP:DMG: Endpoint = 0x0, [1699002736.855941][1141:1141] CHIP:DMG: Cluster = 0x28, [1699002736.855957][1141:1141] CHIP:DMG: Attribute = 0x0000_0009, [1699002736.855970][1141:1141] CHIP:DMG: } [1699002736.855992][1141:1141] CHIP:DMG: [1699002736.856004][1141:1141] CHIP:DMG: ], [1699002736.856030][1141:1141] CHIP:DMG: [1699002736.856050][1141:1141] CHIP:DMG: isFabricFiltered = true, [1699002736.856066][1141:1141] CHIP:DMG: InteractionModelRevision = 11 [1699002736.856078][1141:1141] CHIP:DMG: }, [1699002736.856334][1141:1141] CHIP:DMG: IM RH moving to [CanStartReporting] [1699002736.856545][1141:1141] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 [1699002736.856583][1141:1141] CHIP:DMG: Cluster 28, Attribute 9 is dirty [1699002736.856601][1141:1141] CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0009 (expanded=0) [1699002736.856639][1141:1141] CHIP:DMG: AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0028 e=0 p=v [1699002736.856691][1141:1141] CHIP:DMG: AccessControl: allowed [1699002736.856914][1141:1141] CHIP:DMG: Sending report (payload has 36 bytes)... [1699002736.857387][1141:1141] CHIP:EM: <<< [E:61731r S:27948 M:187089172 (Ack:227096689)] (S) Msg TX to 1:000000000001B669 [40CE] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:36036] --- Type 0001:05 (IM:ReportData) [1699002736.857744][1141:1141] CHIP:DMG: OnReportConfirm: NumReports = 0 [1699002736.857784][1141:1141] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1699002736.857806][1141:1141] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1699002736.864999][1141:1141] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1699002736.865389][1141:1141] CHIP:EM: >>> [E:61730r S:0 M:156899184 (Ack:211636715)] (U) Msg RX from 0:A50896979672C69B [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1699002736.865428][1141:1141] CHIP:EM: Found matching exchange: 61730r, Delegate: (nil) [1699002736.865521][1141:1141] CHIP:EM: Rxd Ack; Removing MessageCounter:211636715 from Retrans Table on exchange 61730r [1699002736.881367][1141:1141] CHIP:EM: >>> [E:61731r S:27948 M:227096690 (Ack:187089172)] (S) Msg RX from 1:000000000001B669 [40CE] --- Type 0000:10 (SecureChannel:StandaloneAck) [1699002736.881415][1141:1141] CHIP:EM: Found matching exchange: 61731r, Delegate: (nil) [1699002736.881469][1141:1141] CHIP:EM: Rxd Ack; Removing MessageCounter:187089172 from Retrans Table on exchange 61731r