[1706278620.419370][1102:1102] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1706278620.453247][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-gBdO2H) [1706278620.455631][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.469523][1102:1102] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1706278620.469577][1102:1102] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1706278620.498848][1102:1102] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1706278620.499226][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-oAgVJM) [1706278620.499447][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1706278620.499637][1102:1102] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1706278620.499812][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_config.ini-CKrAmI) [1706278620.499956][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1706278620.500140][1102:1102] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1706278620.500276][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-q4YXSr) [1706278620.500428][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1706278620.500995][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-5mEqm5) [1706278620.504218][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1706278620.504299][1102:1102] CHIP:DL: NVS set: chip-factory/unique-id = "9C82A59D0EAEA7C1" [1706278620.504646][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-kNhIG4) [1706278620.506241][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1706278620.506355][1102:1102] CHIP:DL: NVS set: chip-factory/vendor-id = 65521 (0xFFF1) [1706278620.506628][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_factory.ini-ot9UrL) [1706278620.509799][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_factory.ini) [1706278620.509936][1102:1102] CHIP:DL: NVS set: chip-factory/product-id = 32769 (0x8001) [1706278620.510205][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-XO3vDk) [1706278620.510721][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1706278620.510812][1102:1102] CHIP:DL: NVS set: chip-counters/reboot-count = 1 (0x1) [1706278620.511110][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-LHWVJR) [1706278620.511735][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1706278620.511830][1102:1102] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1706278620.512160][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-iXy56i) [1706278620.512784][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1706278620.512892][1102:1102] CHIP:DL: NVS set: chip-counters/boot-reason = 0 (0x0) [1706278620.513135][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_config.ini-deHxK4) [1706278620.513620][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1706278620.513720][1102:1102] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1706278620.513986][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_config.ini-hGgd2K) [1706278620.514609][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1706278620.514734][1102:1102] CHIP:DL: NVS set: chip-config/location-capability = 2 (0x2) [1706278620.520729][1102:1102] CHIP:DL: Got Ethernet interface: eth0 [1706278620.525004][1102:1102] CHIP:DL: Found the primary Ethernet interface:eth0 [1706278620.525451][1102:1102] CHIP:DL: Got WiFi interface: wlan0 [1706278620.525520][1102:1102] CHIP:DL: Failed to reset WiFi statistic counts [1706278620.525577][1102:1102] 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. *** [1706278620.525604][1102:1102] CHIP:SPT: PASE PBKDF iterations set to 1000 [1706278620.525674][1102:1102] CHIP:SPT: LinuxCommissionableDataProvider didn't get a PASE salt, generating one. [1706278620.577144][1102:1102] CHIP:DL: Device Configuration: [1706278620.577308][1102:1102] CHIP:DL: Serial Number: TEST_SN [1706278620.577376][1102:1102] CHIP:DL: Vendor Id: 65521 (0xFFF1) [1706278620.577443][1102:1102] CHIP:DL: Product Id: 32769 (0x8001) [1706278620.577460][1102:1102] CHIP:DL: Product Name: TEST_PRODUCT [1706278620.577531][1102:1102] CHIP:DL: Hardware Version: 0 [1706278620.577549][1102:1102] CHIP:DL: Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 [1706278620.577564][1102:1102] CHIP:DL: Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 18 (0x12) [1706278620.577639][1102:1102] CHIP:DL: Manufacturing Date: (not set) [1706278620.577654][1102:1102] CHIP:DL: Device Type: 257 (0x101) [1706278620.577665][1102:1102] CHIP:-: ==== Onboarding payload for Standard Commissioning Flow ==== [1706278620.588085][1102:1102] CHIP:SVR: SetupQRCode: [MT:-24J0KQS02-Z.548G00] [1706278620.591628][1102:1102] CHIP:SVR: Copy/paste the below URL in a browser to see the QR Code: [1706278620.591646][1102:1102] CHIP:SVR: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J0KQS02-Z.548G00 [1706278620.591736][1102:1102] CHIP:SVR: Manual pairing code: [00054912336] [1706278620.592015][1102:1105] CHIP:DL: wpa_supplicant: Start WiFi management [1706278620.823053][1102:1105] CHIP:DL: wpa_supplicant: connected to wpa_supplicant proxy [1706278620.825717][1102:1105] CHIP:DL: wpa_supplicant: WiFi interface: /fi/w1/wpa_supplicant1/Interfaces/0 [1706278620.848343][1102:1105] CHIP:DL: wpa_supplicant: connected to wpa_supplicant interface proxy [1706278620.849092][1102:1105] CHIP:DL: wpa_supplicant: connected to wpa_supplicant bss proxy [1706278620.859713][1102:1102] CHIP:SVR: Initializing subscription resumption storage... [1706278620.860237][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-niQHgS) [1706278620.861002][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.861178][1102:1102] CHIP:SVR: Server initializing... [1706278620.865025][1102:1102] CHIP:FP: Initializing FabricTable from persistent storage [1706278620.867494][1102:1102] CHIP:TS: Last Known Good Time: [unknown] [1706278620.867550][1102:1102] CHIP:TS: Setting Last Known Good Time to firmware build time 2023-10-14T01:16:48 [1706278620.867927][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-KqTjkw) [1706278620.868853][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.869163][1102:1102] CHIP:DMG: AccessControl: initializing [1706278620.873287][1102:1102] CHIP:DMG: Examples::AccessControlDelegate::Init [1706278620.873332][1102:1102] CHIP:DMG: AccessControl: setting [1706278620.873355][1102:1102] CHIP:DMG: DefaultAclStorage: initializing [1706278620.876905][1102:1102] CHIP:DMG: DefaultAclStorage: 0 entries loaded [1706278620.877010][1102:1102] CHIP:IN: UDP::Init bind&listen port=5540 [1706278620.877204][1102:1102] CHIP:IN: UDP::Init bound to port=5540 [1706278620.877231][1102:1102] CHIP:IN: UDP::Init bind&listen port=5540 [1706278620.877327][1102:1102] CHIP:IN: UDP::Init bound to port=5540 [1706278620.877345][1102:1102] CHIP:IN: BLEBase::Init - setting/overriding transport [1706278620.877526][1102:1102] CHIP:IN: TransportMgr initialized [1706278620.878072][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-Cq0LM9) [1706278620.878781][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.879049][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-Xer6xH) [1706278620.880224][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.888467][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-YzwSA3) [1706278620.889288][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.889434][1102:1102] CHIP:ZCL: Using ZAP configuration... [1706278620.897881][1102:1102] 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 [1706278620.901617][1102:1102] 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 [1706278620.901689][1102:1102] 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 [1706278620.901770][1102:1102] 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 [1706278620.901820][1102:1102] 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 [1706278620.901925][1102:1102] 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 [1706278620.901987][1102:1102] 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 [1706278620.902035][1102:1102] 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 [1706278620.902091][1102:1102] 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 [1706278620.902144][1102:1102] 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 [1706278620.902189][1102:1102] 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 [1706278620.902234][1102:1102] 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 [1706278620.902279][1102:1102] 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 [1706278620.902325][1102:1102] 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 [1706278620.902371][1102:1102] 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 [1706278620.902434][1102:1102] 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 [1706278620.902480][1102:1102] 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 [1706278620.902525][1102:1102] 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 [1706278620.902587][1102:1102] 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 [1706278620.902632][1102:1102] 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 [1706278620.902687][1102:1102] 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 [1706278620.902714][1102:1102] CHIP:DMG: AccessControlCluster: initializing [1706278620.906237][1102:1102] CHIP:ZCL: Initiating Admin Commissioning cluster. [1706278620.910207][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 3d182cd5 [1706278620.913960][1102:1102] CHIP:ZCL: GeneralDiagnostics: OnDeviceReboot [1706278620.917572][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_0033 update version to 71c7a260 [1706278620.923717][1102:1102] CHIP:EVL: LogEvent event number: 0x0000000000000000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0033 event id: 0x3 Epoch timestamp: 0x0000018D46218EF5 [1706278620.927598][1102:1102] CHIP:DMG: Endpoint 1, Cluster 0x0000_0004 update version to 6d86c621 [1706278620.927663][1102:1102] CHIP:DMG: Endpoint 1, Cluster 0x0000_0004 update version to 6d86c622 [1706278620.927707][1102:1102] CHIP:ZCL: Endpoint 1 On/off already set to new value [1706278620.932409][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-Hsqc4g) [1706278620.933200][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.933330][1102:1102] CHIP:DMG: Endpoint 1, Cluster 0x0000_0008 update version to 66dc33a6 [1706278620.933427][1102:1102] CHIP:DMG: Endpoint 1, Cluster 0x0000_0062 update version to b0a9428a [1706278620.933682][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-7SFoTX) [1706278620.934672][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.934768][1102:1102] CHIP:DMG: Endpoint 1, Cluster 0x0000_0300 update version to 47aacc2d [1706278620.934979][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-mY78Dx) [1706278620.935852][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.935991][1102:1102] CHIP:DMG: Endpoint 1, Cluster 0x0000_0300 update version to 47aacc2e [1706278620.936197][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-USqgUf) [1706278620.937085][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278620.937169][1102:1102] CHIP:DMG: Endpoint 1, Cluster 0x0000_0300 update version to 47aacc2f [1706278620.937221][1102:1102] CHIP:DMG: Endpoint 1, Cluster 0x0000_0406 update version to c64c62e4 [1706278620.937246][1102:1102] CHIP:DMG: Endpoint 1, Cluster 0x0000_0406 update version to c64c62e5 [1706278620.937600][1102:1102] CHIP:IN: SecureSession[0xffffa0903ac0]: Allocated Type:1 LSID:39053 [1706278620.940428][1102:1102] CHIP:SC: Assigned local session key ID 39053 [1706278620.940491][1102:1102] CHIP:SC: Waiting for PBKDF param request [1706278620.940534][1102:1102] CHIP:DIS: Updating services using commissioning mode 1 [1706278620.942382][1102:1102] CHIP:DIS: CHIP minimal mDNS started advertising. [1706278620.949747][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278620.950088][1102:1102] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=1 cp=0 [1706278620.950216][1102:1102] CHIP:DIS: Responding with _matterc._udp.local [1706278620.950246][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278620.950266][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278620.950281][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278620.950332][1102:1102] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1706278620.950360][1102:1102] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1706278620.950386][1102:1102] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1706278620.950411][1102:1102] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1706278620.950442][1102:1102] CHIP:DIS: Responding with _CM._sub._matterc._udp.local [1706278620.950525][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278620.950541][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 586331307FC43F37. [1706278620.952110][1102:1102] CHIP:DIS: mDNS service published: _matterc._udp [1706278620.952160][1102:1102] CHIP:DIS: Updating services using commissioning mode 1 [1706278620.953587][1102:1102] CHIP:DIS: CHIP minimal mDNS started advertising. [1706278620.956841][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278620.957108][1102:1102] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=1 cp=0 [1706278620.957202][1102:1102] CHIP:DIS: Responding with _matterc._udp.local [1706278620.957234][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278620.957252][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278620.957267][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278620.957318][1102:1102] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1706278620.957348][1102:1102] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1706278620.957374][1102:1102] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1706278620.957397][1102:1102] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1706278620.957421][1102:1102] CHIP:DIS: Responding with _CM._sub._matterc._udp.local [1706278620.957480][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278620.957496][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 586331307FC43F37. [1706278620.958987][1102:1102] CHIP:DIS: mDNS service published: _matterc._udp [1706278620.959053][1102:1102] CHIP:IN: CASE Server enabling CASE session setups [1706278620.961517][1102:1102] CHIP:IN: SecureSession[0xffffa0903940]: Allocated Type:2 LSID:39054 [1706278620.961632][1102:1102] CHIP:SC: Allocated SecureSession (0xffffa0903940) - waiting for Sigma1 msg [1706278620.964220][1102:1102] CHIP:SVR: Joining Multicast groups [1706278620.964327][1102:1102] CHIP:IN: UDP::Init bind&listen port=5560 [1706278620.964510][1102:1102] CHIP:IN: UDP::Init bound to port=5560 [1706278620.964551][1102:1102] CHIP:IN: UDP::Init bind&listen port=5560 [1706278620.964660][1102:1102] CHIP:IN: UDP::Init bound to port=5560 [1706278620.964676][1102:1102] CHIP:IN: TransportMgr initialized [1706278620.964716][1102:1102] CHIP:ZCL: Emitting StartUp event [1706278620.968596][1102:1102] CHIP:EVL: LogEvent event number: 0x0000000000000001 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Epoch timestamp: 0x0000018D46218F28 [1706278620.968673][1102:1102] CHIP:SVR: Server Listening... [1706278620.968700][1102:1102] CHIP:DL: Device Configuration: [1706278620.968836][1102:1102] CHIP:DL: Serial Number: TEST_SN [1706278620.968952][1102:1102] CHIP:DL: Vendor Id: 65521 (0xFFF1) [1706278620.969009][1102:1102] CHIP:DL: Product Id: 32769 (0x8001) [1706278620.969025][1102:1102] CHIP:DL: Product Name: TEST_PRODUCT [1706278620.969076][1102:1102] CHIP:DL: Hardware Version: 0 [1706278620.969094][1102:1102] CHIP:DL: Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 [1706278620.969109][1102:1102] CHIP:DL: Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 18 (0x12) [1706278620.969199][1102:1102] CHIP:DL: Manufacturing Date: (not set) [1706278620.969216][1102:1102] CHIP:DL: Device Type: 257 (0x101) [1706278620.969292][1102:1102] CHIP:SVR: SetupQRCode: [MT:-24J0KQS02-Z.548G00] [1706278620.969322][1102:1102] CHIP:SVR: Copy/paste the below URL in a browser to see the QR Code: [1706278620.969334][1102:1102] CHIP:SVR: https://project-chip.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J0KQS02-Z.548G00 [1706278620.969369][1102:1102] CHIP:SVR: Manual pairing code: [00054912336] [1706278620.977224][1102:1105] CHIP:DL: TRACE: Bus acquired for name MATTER-0018 [1706278620.977891][1102:1105] CHIP:DL: CREATE service object at /chipoble/044e/service [1706278620.987235][1102:1105] CHIP:DL: Create characteristic object at /chipoble/044e/service/c1 [1706278620.988480][1102:1105] CHIP:DL: Create characteristic object at /chipoble/044e/service/c2 [1706278620.988932][1102:1105] CHIP:DL: CHIP BTP C1 /chipoble/044e/service [1706278620.988952][1102:1105] CHIP:DL: CHIP BTP C2 /chipoble/044e/service [1706278620.988964][1102:1105] CHIP:DL: CHIP_ENABLE_ADDITIONAL_DATA_ADVERTISING is FALSE [1706278621.005677][1102:1102] CHIP:DL: BlueZ integration init success [1706278621.006537][1102:1102] CHIP:DL: wpa_supplicant: disabling auto scan [1706278621.014709][1102:1105] CHIP:DL: BluezPeripheralRegisterAppDone done [1706278621.014882][1102:1102] CHIP:DL: HandlePlatformSpecificBLEEvent 16392 [1706278621.015290][1102:1105] CHIP:DL: Create BLE adv object at /chipoble/044e/advertising [1706278621.027996][1102:1105] CHIP:DL: SET service data to {'0xFFF6': <[byte 0x00, 0x12, 0x00, 0xf1, 0xff, 0x01, 0x80, 0x00]>} [1706278621.118576][1102:1105] CHIP:DL: RegisterAdvertisement complete [1706278621.118859][1102:1102] CHIP:DL: HandlePlatformSpecificBLEEvent 16393 [1706278639.405869][1102:1105] CHIP:DL: BLE device connected: conn 0xffffa4708de0, device E4:5F:01:0A:DA:38, path /org/bluez/hci0/dev_E4_5F_01_0A_DA_38 [1706278664.482721][1102:1105] CHIP:DL: Bluez disconnected [1706278664.482811][1102:1105] CHIP:DL: Bluez notify CHIPoBluez connection disconnected [1706278665.817597][1102:1105] CHIP:DL: New BLE connection: conn 0xffffa4705ff0, device E4:5F:01:0A:DA:38, path /org/bluez/hci0/dev_E4_5F_01_0A_DA_38 [1706278667.447670][1102:1105] CHIP:DL: BluezCharacteristicAcquireWrite is called, conn: 0xffffa4705ff0 [1706278667.450843][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278667.451458][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278667.451913][1102:1102] CHIP:BLE: local and remote recv window sizes = 6 [1706278667.451972][1102:1102] CHIP:BLE: selected BTP version 4 [1706278667.452010][1102:1102] CHIP:BLE: using BTP fragment sizes rx 244 / tx 244. [1706278667.545645][1102:1105] CHIP:DL: CHIPoBLE subscribe received [1706278667.546945][1102:1102] CHIP:IN: BLE EndPoint 0xaaaabf0b24c0 Connection Complete [1706278667.547070][1102:1102] CHIP:DL: HandlePlatformSpecificBLEEvent 32775 [1706278667.547168][1102:1102] CHIP:DL: Receive kCHIPoBLEConnectionEstablished [1706278667.640379][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278667.689581][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278667.691515][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278667.702309][1102:1102] CHIP:EM: >>> [E:17675r S:0 M:221639108] (U) Msg RX from 0:FDC74CD551A1866F [0000] --- Type 0000:20 (SecureChannel:PBKDFParamRequest) [1706278667.702468][1102:1102] CHIP:EM: Handling via exchange: 17675r, Delegate: 0xaaaabf0b0d58 [1706278667.702557][1102:1102] CHIP:SC: Received PBKDF param request [1706278667.703259][1102:1102] CHIP:SC: Peer assigned session ID 6381 [1706278667.703347][1102:1102] CHIP:SC: Found MRP parameters in the message [1706278667.704479][1102:1102] CHIP:EM: <<< [E:17675r S:0 M:190944763] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:21 (SecureChannel:PBKDFParamResponse) [1706278667.705058][1102:1102] CHIP:SC: Sent PBKDF param response [1706278667.705150][1102:1102] CHIP:SVR: Commissioning session establishment step started [1706278667.835297][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278667.883942][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278667.886648][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278667.887323][1102:1102] CHIP:EM: >>> [E:17675r S:0 M:221639109] (U) Msg RX from 0:FDC74CD551A1866F [0000] --- Type 0000:22 (SecureChannel:PASE_Pake1) [1706278667.887407][1102:1102] CHIP:EM: Found matching exchange: 17675r, Delegate: 0xaaaabf0b0d58 [1706278667.887525][1102:1102] CHIP:SC: Received spake2p msg1 [1706278667.894027][1102:1102] CHIP:EM: <<< [E:17675r S:0 M:190944764] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:23 (SecureChannel:PASE_Pake2) [1706278667.894620][1102:1102] CHIP:SC: Sent spake2p msg2 [1706278668.030299][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278668.077426][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278668.079817][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278668.080432][1102:1102] CHIP:EM: >>> [E:17675r S:0 M:221639110] (U) Msg RX from 0:FDC74CD551A1866F [0000] --- Type 0000:24 (SecureChannel:PASE_Pake3) [1706278668.080518][1102:1102] CHIP:EM: Found matching exchange: 17675r, Delegate: 0xaaaabf0b0d58 [1706278668.080639][1102:1102] CHIP:SC: Received spake2p msg3 [1706278668.081055][1102:1102] CHIP:SC: Sending status report. Protocol code 0, exchange 17675 [1706278668.081229][1102:1102] CHIP:EM: <<< [E:17675r S:0 M:190944765] (U) Msg TX to 0:0000000000000000 [0000] [BLE] --- Type 0000:40 (SecureChannel:StatusReport) [1706278668.084714][1102:1102] CHIP:SC: SecureSession[0xffffa0903ac0, LSID:39053]: State change 'kEstablishing' --> 'kActive' [1706278668.084810][1102:1102] CHIP:IN: SecureSession[0xffffa0903ac0]: Activated - Type:1 LSID:39053 [1706278668.084850][1102:1102] CHIP:IN: New secure session activated for device , LSID:39053 PSID:6381! [1706278668.084941][1102:1102] CHIP:SVR: Commissioning completed session establishment step [1706278668.085501][1102:1102] CHIP:DIS: Updating services using commissioning mode 0 [1706278668.089828][1102:1102] CHIP:DIS: CHIP minimal mDNS started advertising. [1706278668.093197][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278668.093479][1102:1102] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=0 cp=0 [1706278668.093583][1102:1102] CHIP:DIS: Responding with _matterc._udp.local [1706278668.093618][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278668.093638][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278668.093664][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278668.093694][1102:1102] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1706278668.093723][1102:1102] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1706278668.093748][1102:1102] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1706278668.093772][1102:1102] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1706278668.093846][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278668.093862][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 586331307FC43F37. [1706278668.095457][1102:1102] CHIP:DIS: mDNS service published: _matterc._udp [1706278668.095498][1102:1102] CHIP:DIS: Scheduling extended discovery timeout in 900s [1706278668.095642][1102:1102] CHIP:SVR: Device completed Rendezvous process [1706278668.098687][1102:1105] CHIP:DL: UnregisterAdvertisement complete [1706278668.098891][1102:1102] CHIP:DL: HandlePlatformSpecificBLEEvent 16394 [1706278668.098913][1102:1102] CHIP:DL: CHIPoBLE advertising stopped [1706278668.177010][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278668.273005][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278668.276207][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278668.277156][1102:1102] CHIP:EM: >>> [E:17676r S:39053 M:68287843] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) [1706278668.277300][1102:1102] CHIP:EM: Handling via exchange: 17676r, Delegate: 0xaaaabf0a5b08 [1706278668.277369][1102:1102] CHIP:IM: Received Read request [1706278668.281932][1102:1102] CHIP:DMG: ReadRequestMessage = [1706278668.282064][1102:1102] CHIP:DMG: { [1706278668.284443][1102:1102] CHIP:DMG: AttributePathIBs = [1706278668.284505][1102:1102] CHIP:DMG: [ [1706278668.286930][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.286971][1102:1102] CHIP:DMG: { [1706278668.286993][1102:1102] CHIP:DMG: Cluster = 0x31, [1706278668.287013][1102:1102] CHIP:DMG: Attribute = 0x0000_FFFC, [1706278668.287029][1102:1102] CHIP:DMG: } [1706278668.287065][1102:1102] CHIP:DMG: [1706278668.287080][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.287099][1102:1102] CHIP:DMG: { [1706278668.287140][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.287162][1102:1102] CHIP:DMG: Cluster = 0x30, [1706278668.287180][1102:1102] CHIP:DMG: Attribute = 0x0000_0000, [1706278668.287195][1102:1102] CHIP:DMG: } [1706278668.287218][1102:1102] CHIP:DMG: [1706278668.287234][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.287250][1102:1102] CHIP:DMG: { [1706278668.287269][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.287286][1102:1102] CHIP:DMG: Cluster = 0x30, [1706278668.287304][1102:1102] CHIP:DMG: Attribute = 0x0000_0001, [1706278668.287318][1102:1102] CHIP:DMG: } [1706278668.287340][1102:1102] CHIP:DMG: [1706278668.287355][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.287371][1102:1102] CHIP:DMG: { [1706278668.287390][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.287408][1102:1102] CHIP:DMG: Cluster = 0x30, [1706278668.287425][1102:1102] CHIP:DMG: Attribute = 0x0000_0002, [1706278668.287439][1102:1102] CHIP:DMG: } [1706278668.287460][1102:1102] CHIP:DMG: [1706278668.287476][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.287492][1102:1102] CHIP:DMG: { [1706278668.287510][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.287528][1102:1102] CHIP:DMG: Cluster = 0x30, [1706278668.287546][1102:1102] CHIP:DMG: Attribute = 0x0000_0003, [1706278668.287560][1102:1102] CHIP:DMG: } [1706278668.287581][1102:1102] CHIP:DMG: [1706278668.287596][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.287612][1102:1102] CHIP:DMG: { [1706278668.287630][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.287648][1102:1102] CHIP:DMG: Cluster = 0x28, [1706278668.287665][1102:1102] CHIP:DMG: Attribute = 0x0000_0002, [1706278668.287679][1102:1102] CHIP:DMG: } [1706278668.287699][1102:1102] CHIP:DMG: [1706278668.287715][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.287731][1102:1102] CHIP:DMG: { [1706278668.287749][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.287767][1102:1102] CHIP:DMG: Cluster = 0x28, [1706278668.287784][1102:1102] CHIP:DMG: Attribute = 0x0000_0004, [1706278668.287798][1102:1102] CHIP:DMG: } [1706278668.287819][1102:1102] CHIP:DMG: [1706278668.287834][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.287850][1102:1102] CHIP:DMG: { [1706278668.287868][1102:1102] CHIP:DMG: Cluster = 0x31, [1706278668.287885][1102:1102] CHIP:DMG: Attribute = 0x0000_0003, [1706278668.287899][1102:1102] CHIP:DMG: } [1706278668.287919][1102:1102] CHIP:DMG: [1706278668.287934][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.287950][1102:1102] CHIP:DMG: { [1706278668.287968][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.287985][1102:1102] CHIP:DMG: Cluster = 0x38, [1706278668.287998][1102:1102] CHIP:DMG: } [1706278668.288017][1102:1102] CHIP:DMG: [1706278668.288031][1102:1102] CHIP:DMG: ], [1706278668.288089][1102:1102] CHIP:DMG: [1706278668.288114][1102:1102] CHIP:DMG: isFabricFiltered = false, [1706278668.288132][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278668.288146][1102:1102] CHIP:DMG: }, [1706278668.288920][1102:1102] CHIP:DMG: IM RH moving to [CanStartReporting] [1706278668.289340][1102:1102] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0x0000000000000000 DirtyGeneration = 0x0000000000000000 [1706278668.289391][1102:1102] CHIP:DMG: Cluster 31, Attribute 3 is dirty [1706278668.289411][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) [1706278668.296440][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=v [1706278668.296518][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.296677][1102:1102] CHIP:DMG: Cluster 28, Attribute 4 is dirty [1706278668.296697][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) [1706278668.296725][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0028 e=0 p=v [1706278668.296740][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.296975][1102:1102] CHIP:DMG: Cluster 28, Attribute 2 is dirty [1706278668.296997][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) [1706278668.297014][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0028 e=0 p=v [1706278668.297030][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.297101][1102:1102] CHIP:DMG: Cluster 30, Attribute 3 is dirty [1706278668.297117][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) [1706278668.297135][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1706278668.297150][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.297269][1102:1102] CHIP:DMG: Cluster 30, Attribute 2 is dirty [1706278668.297285][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) [1706278668.297302][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1706278668.297317][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.297402][1102:1102] CHIP:DMG: Cluster 30, Attribute 1 is dirty [1706278668.297418][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) [1706278668.297434][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1706278668.297448][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.297513][1102:1102] CHIP:DMG: Cluster 30, Attribute 0 is dirty [1706278668.297527][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0) [1706278668.297544][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1706278668.297559][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.297617][1102:1102] CHIP:DMG: Cluster 31, Attribute fffc is dirty [1706278668.297632][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) [1706278668.297648][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=v [1706278668.297663][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.297753][1102:1102] CHIP:DMG: Sending report (payload has 228 bytes)... [1706278668.298776][1102:1102] CHIP:EM: <<< [E:17676r S:39053 M:362498] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) [1706278668.299343][1102:1102] CHIP:DMG: OnReportConfirm: NumReports = 0 [1706278668.299385][1102:1102] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1706278668.299403][1102:1102] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1706278668.302119][1102:1102] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1706278668.468143][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278668.566535][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278668.615070][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278668.618170][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278668.618904][1102:1102] CHIP:EM: >>> [E:17677r S:39053 M:68287844] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:02 (IM:ReadRequest) [1706278668.619028][1102:1102] CHIP:EM: Handling via exchange: 17677r, Delegate: 0xaaaabf0a5b08 [1706278668.619091][1102:1102] CHIP:IM: Received Read request [1706278668.619294][1102:1102] CHIP:DMG: ReadRequestMessage = [1706278668.619351][1102:1102] CHIP:DMG: { [1706278668.619390][1102:1102] CHIP:DMG: AttributePathIBs = [1706278668.619436][1102:1102] CHIP:DMG: [ [1706278668.619471][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.619514][1102:1102] CHIP:DMG: { [1706278668.619559][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.619603][1102:1102] CHIP:DMG: Cluster = 0x30, [1706278668.619644][1102:1102] CHIP:DMG: Attribute = 0x0000_0004, [1706278668.619676][1102:1102] CHIP:DMG: } [1706278668.619732][1102:1102] CHIP:DMG: [1706278668.619768][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.619806][1102:1102] CHIP:DMG: { [1706278668.619848][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.619890][1102:1102] CHIP:DMG: Cluster = 0x46, [1706278668.619931][1102:1102] CHIP:DMG: Attribute = 0x0000_FFFC, [1706278668.619964][1102:1102] CHIP:DMG: } [1706278668.620012][1102:1102] CHIP:DMG: [1706278668.620048][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.620085][1102:1102] CHIP:DMG: { [1706278668.620127][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.620168][1102:1102] CHIP:DMG: Cluster = 0x46, [1706278668.620209][1102:1102] CHIP:DMG: Attribute = 0x0000_0006, [1706278668.620241][1102:1102] CHIP:DMG: } [1706278668.620289][1102:1102] CHIP:DMG: [1706278668.620324][1102:1102] CHIP:DMG: AttributePathIB = [1706278668.620360][1102:1102] CHIP:DMG: { [1706278668.620402][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278668.620443][1102:1102] CHIP:DMG: Cluster = 0x46, [1706278668.620483][1102:1102] CHIP:DMG: Attribute = 0x0000_0007, [1706278668.620514][1102:1102] CHIP:DMG: } [1706278668.620559][1102:1102] CHIP:DMG: [1706278668.620592][1102:1102] CHIP:DMG: ], [1706278668.620673][1102:1102] CHIP:DMG: [1706278668.620719][1102:1102] CHIP:DMG: isFabricFiltered = false, [1706278668.620757][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278668.620788][1102:1102] CHIP:DMG: }, [1706278668.621666][1102:1102] CHIP:DMG: IM RH moving to [CanStartReporting] [1706278668.622047][1102:1102] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0x0000000000000000 DirtyGeneration = 0x0000000000000000 [1706278668.622133][1102:1102] CHIP:DMG: Cluster 46, Attribute 7 is dirty [1706278668.622171][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0046 Endpoint=0 AttributeId=0x0000_0007 (expanded=0) [1706278668.622309][1102:1102] CHIP:DMG: Cluster 46, Attribute 6 is dirty [1706278668.622347][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0046 Endpoint=0 AttributeId=0x0000_0006 (expanded=0) [1706278668.622430][1102:1102] CHIP:DMG: Cluster 46, Attribute fffc is dirty [1706278668.622467][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0046 Endpoint=0 AttributeId=0x0000_FFFC (expanded=0) [1706278668.622552][1102:1102] CHIP:DMG: Cluster 30, Attribute 4 is dirty [1706278668.622588][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) [1706278668.622637][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1706278668.622680][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.622844][1102:1102] CHIP:DMG: Sending report (payload has 105 bytes)... [1706278668.623407][1102:1102] CHIP:EM: <<< [E:17677r S:39053 M:362499] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:05 (IM:ReportData) [1706278668.624029][1102:1102] CHIP:DMG: OnReportConfirm: NumReports = 0 [1706278668.624083][1102:1102] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1706278668.624118][1102:1102] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1706278668.628876][1102:1102] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1706278668.760616][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278668.809273][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278668.811959][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278668.812747][1102:1102] CHIP:EM: >>> [E:17678r S:39053 M:68287845] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278668.812884][1102:1102] CHIP:EM: Handling via exchange: 17678r, Delegate: 0xaaaabf0a5b08 [1706278668.813193][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278668.813249][1102:1102] CHIP:DMG: { [1706278668.813298][1102:1102] CHIP:DMG: suppressResponse = false, [1706278668.813348][1102:1102] CHIP:DMG: timedRequest = false, [1706278668.813390][1102:1102] CHIP:DMG: InvokeRequests = [1706278668.813468][1102:1102] CHIP:DMG: [ [1706278668.813510][1102:1102] CHIP:DMG: CommandDataIB = [1706278668.813558][1102:1102] CHIP:DMG: { [1706278668.813597][1102:1102] CHIP:DMG: CommandPathIB = [1706278668.813645][1102:1102] CHIP:DMG: { [1706278668.813698][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278668.813750][1102:1102] CHIP:DMG: ClusterId = 0x30, [1706278668.813797][1102:1102] CHIP:DMG: CommandId = 0x0, [1706278668.813835][1102:1102] CHIP:DMG: }, [1706278668.813946][1102:1102] CHIP:DMG: [1706278668.813991][1102:1102] CHIP:DMG: CommandFields = [1706278668.814041][1102:1102] CHIP:DMG: { [1706278668.814096][1102:1102] CHIP:DMG: 0x0 = 60, [1706278668.814147][1102:1102] CHIP:DMG: 0x1 = 4, [1706278668.814196][1102:1102] CHIP:DMG: }, [1706278668.814234][1102:1102] CHIP:DMG: }, [1706278668.814303][1102:1102] CHIP:DMG: [1706278668.814342][1102:1102] CHIP:DMG: ], [1706278668.814419][1102:1102] CHIP:DMG: [1706278668.814466][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278668.814501][1102:1102] CHIP:DMG: }, [1706278668.814996][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1706278668.815059][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.817763][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 [1706278668.821793][1102:1102] CHIP:FS: GeneralCommissioning: Received ArmFailSafe (60s) [1706278668.825545][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 3d182cd6 [1706278668.825682][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278668.825713][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278668.825763][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278668.825815][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278668.825910][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278668.826262][1102:1102] CHIP:EM: <<< [E:17678r S:39053 M:362500] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278668.826753][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278668.826783][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278668.907141][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278668.956515][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278668.958840][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278668.959715][1102:1102] CHIP:EM: >>> [E:17679r S:39053 M:68287846] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278668.959857][1102:1102] CHIP:EM: Handling via exchange: 17679r, Delegate: 0xaaaabf0a5b08 [1706278668.960095][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278668.960151][1102:1102] CHIP:DMG: { [1706278668.960198][1102:1102] CHIP:DMG: suppressResponse = false, [1706278668.960249][1102:1102] CHIP:DMG: timedRequest = false, [1706278668.960292][1102:1102] CHIP:DMG: InvokeRequests = [1706278668.960376][1102:1102] CHIP:DMG: [ [1706278668.960419][1102:1102] CHIP:DMG: CommandDataIB = [1706278668.960468][1102:1102] CHIP:DMG: { [1706278668.960508][1102:1102] CHIP:DMG: CommandPathIB = [1706278668.960558][1102:1102] CHIP:DMG: { [1706278668.960610][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278668.960659][1102:1102] CHIP:DMG: ClusterId = 0x30, [1706278668.960705][1102:1102] CHIP:DMG: CommandId = 0x2, [1706278668.960744][1102:1102] CHIP:DMG: }, [1706278668.960807][1102:1102] CHIP:DMG: [1706278668.960853][1102:1102] CHIP:DMG: CommandFields = [1706278668.960900][1102:1102] CHIP:DMG: { [1706278668.960957][1102:1102] CHIP:DMG: 0x0 = 0, [1706278668.961023][1102:1102] CHIP:DMG: 0x1 = "XX" (2 chars), [1706278668.961075][1102:1102] CHIP:DMG: 0x2 = 5, [1706278668.961123][1102:1102] CHIP:DMG: }, [1706278668.961161][1102:1102] CHIP:DMG: }, [1706278668.961233][1102:1102] CHIP:DMG: [1706278668.961272][1102:1102] CHIP:DMG: ], [1706278668.961354][1102:1102] CHIP:DMG: [1706278668.961401][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278668.961436][1102:1102] CHIP:DMG: }, [1706278668.961957][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1706278668.962025][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278668.962104][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 [1706278668.962995][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_config.ini-ktoawa) [1706278668.964345][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1706278668.964538][1102:1102] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1706278668.964907][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_config.ini-yf9nZW) [1706278668.966006][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1706278668.966178][1102:1102] CHIP:DL: NVS set: chip-config/country-code = "XX" [1706278668.966279][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 3d182cd7 [1706278668.966473][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278668.966529][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278668.966608][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278668.966689][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278668.966893][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278668.967336][1102:1102] CHIP:EM: <<< [E:17679r S:39053 M:362501] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278668.967899][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278668.967929][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278669.053368][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278669.102792][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278669.105233][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278669.106004][1102:1102] CHIP:EM: >>> [E:17680r S:39053 M:68287847] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278669.106142][1102:1102] CHIP:EM: Handling via exchange: 17680r, Delegate: 0xaaaabf0a5b08 [1706278669.106372][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278669.106430][1102:1102] CHIP:DMG: { [1706278669.106478][1102:1102] CHIP:DMG: suppressResponse = false, [1706278669.106528][1102:1102] CHIP:DMG: timedRequest = false, [1706278669.106569][1102:1102] CHIP:DMG: InvokeRequests = [1706278669.106647][1102:1102] CHIP:DMG: [ [1706278669.106689][1102:1102] CHIP:DMG: CommandDataIB = [1706278669.106738][1102:1102] CHIP:DMG: { [1706278669.106779][1102:1102] CHIP:DMG: CommandPathIB = [1706278669.106829][1102:1102] CHIP:DMG: { [1706278669.106883][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278669.106932][1102:1102] CHIP:DMG: ClusterId = 0x3e, [1706278669.106978][1102:1102] CHIP:DMG: CommandId = 0x2, [1706278669.107016][1102:1102] CHIP:DMG: }, [1706278669.107076][1102:1102] CHIP:DMG: [1706278669.107176][1102:1102] CHIP:DMG: CommandFields = [1706278669.107233][1102:1102] CHIP:DMG: { [1706278669.107287][1102:1102] CHIP:DMG: 0x0 = 2, [1706278669.107337][1102:1102] CHIP:DMG: }, [1706278669.107375][1102:1102] CHIP:DMG: }, [1706278669.107441][1102:1102] CHIP:DMG: [1706278669.107479][1102:1102] CHIP:DMG: ], [1706278669.107556][1102:1102] CHIP:DMG: [1706278669.107603][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278669.107639][1102:1102] CHIP:DMG: }, [1706278669.108123][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1706278669.108184][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278669.108254][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 [1706278669.108460][1102:1102] CHIP:ZCL: OpCreds: Certificate Chain request received for PAI [1706278669.108676][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278669.108734][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278669.108817][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278669.108900][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278669.109063][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278669.109494][1102:1102] CHIP:EM: <<< [E:17680r S:39053 M:362502] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278669.110195][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278669.110250][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278669.297974][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278669.444337][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278669.541462][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278669.589468][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278669.591191][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278669.591823][1102:1102] CHIP:EM: >>> [E:17681r S:39053 M:68287848] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278669.591934][1102:1102] CHIP:EM: Handling via exchange: 17681r, Delegate: 0xaaaabf0a5b08 [1706278669.592170][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278669.592213][1102:1102] CHIP:DMG: { [1706278669.592249][1102:1102] CHIP:DMG: suppressResponse = false, [1706278669.592287][1102:1102] CHIP:DMG: timedRequest = false, [1706278669.592317][1102:1102] CHIP:DMG: InvokeRequests = [1706278669.592374][1102:1102] CHIP:DMG: [ [1706278669.592406][1102:1102] CHIP:DMG: CommandDataIB = [1706278669.592443][1102:1102] CHIP:DMG: { [1706278669.592473][1102:1102] CHIP:DMG: CommandPathIB = [1706278669.592511][1102:1102] CHIP:DMG: { [1706278669.592550][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278669.592591][1102:1102] CHIP:DMG: ClusterId = 0x3e, [1706278669.592625][1102:1102] CHIP:DMG: CommandId = 0x2, [1706278669.592653][1102:1102] CHIP:DMG: }, [1706278669.592699][1102:1102] CHIP:DMG: [1706278669.592733][1102:1102] CHIP:DMG: CommandFields = [1706278669.592770][1102:1102] CHIP:DMG: { [1706278669.592812][1102:1102] CHIP:DMG: 0x0 = 1, [1706278669.592851][1102:1102] CHIP:DMG: }, [1706278669.592880][1102:1102] CHIP:DMG: }, [1706278669.592931][1102:1102] CHIP:DMG: [1706278669.592960][1102:1102] CHIP:DMG: ], [1706278669.593020][1102:1102] CHIP:DMG: [1706278669.593056][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278669.593083][1102:1102] CHIP:DMG: }, [1706278669.593498][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1706278669.593561][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278669.593625][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 [1706278669.593738][1102:1102] CHIP:ZCL: OpCreds: Certificate Chain request received for DAC [1706278669.593947][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278669.593998][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278669.594079][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278669.594174][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278669.594355][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278669.594873][1102:1102] CHIP:EM: <<< [E:17681r S:39053 M:362503] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278669.595765][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278669.595838][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278669.785551][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278669.931784][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278670.028910][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278670.077733][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278670.080082][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278670.080842][1102:1102] CHIP:EM: >>> [E:17682r S:39053 M:68287849] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278670.080967][1102:1102] CHIP:EM: Handling via exchange: 17682r, Delegate: 0xaaaabf0a5b08 [1706278670.081182][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278670.081230][1102:1102] CHIP:DMG: { [1706278670.081273][1102:1102] CHIP:DMG: suppressResponse = false, [1706278670.081316][1102:1102] CHIP:DMG: timedRequest = false, [1706278670.081352][1102:1102] CHIP:DMG: InvokeRequests = [1706278670.081419][1102:1102] CHIP:DMG: [ [1706278670.081455][1102:1102] CHIP:DMG: CommandDataIB = [1706278670.081496][1102:1102] CHIP:DMG: { [1706278670.081530][1102:1102] CHIP:DMG: CommandPathIB = [1706278670.081571][1102:1102] CHIP:DMG: { [1706278670.081616][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278670.081658][1102:1102] CHIP:DMG: ClusterId = 0x3e, [1706278670.081697][1102:1102] CHIP:DMG: CommandId = 0x0, [1706278670.081728][1102:1102] CHIP:DMG: }, [1706278670.081778][1102:1102] CHIP:DMG: [1706278670.081816][1102:1102] CHIP:DMG: CommandFields = [1706278670.081857][1102:1102] CHIP:DMG: { [1706278670.081901][1102:1102] CHIP:DMG: 0x0 = [ [1706278670.081995][1102:1102] CHIP:DMG: 0x81, 0x05, 0x59, 0xa9, 0x27, 0xd2, 0x32, 0xf4, 0xe3, 0x49, 0x37, 0x6a, 0x96, 0xc3, 0xe0, 0x83, 0x1c, 0x0e, 0xab, 0x75, 0xfe, 0x8a, 0x0f, 0x77, 0x48, 0x29, 0xb8, 0xd3, 0xfd, 0x25, 0xb9, 0x81, [1706278670.082038][1102:1102] CHIP:DMG: ] (32 bytes) [1706278670.082079][1102:1102] CHIP:DMG: }, [1706278670.082111][1102:1102] CHIP:DMG: }, [1706278670.082168][1102:1102] CHIP:DMG: [1706278670.082200][1102:1102] CHIP:DMG: ], [1706278670.082265][1102:1102] CHIP:DMG: [1706278670.082305][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278670.082335][1102:1102] CHIP:DMG: }, [1706278670.082767][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1706278670.082824][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278670.082884][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 [1706278670.083609][1102:1102] CHIP:ZCL: OpCreds: Received an AttestationRequest command [1706278670.086938][1102:1102] CHIP:ZCL: OpCreds: AttestationRequest successful. [1706278670.087110][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278670.087204][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278670.087276][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278670.087354][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278670.087537][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278670.087939][1102:1102] CHIP:EM: <<< [E:17682r S:39053 M:362504] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278670.088627][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278670.088675][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278670.273180][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278670.419000][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278670.565554][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278670.709989][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278670.713090][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278670.713903][1102:1102] CHIP:EM: >>> [E:17683r S:39053 M:68287850] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278670.714039][1102:1102] CHIP:EM: Handling via exchange: 17683r, Delegate: 0xaaaabf0a5b08 [1706278670.714274][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278670.714329][1102:1102] CHIP:DMG: { [1706278670.714375][1102:1102] CHIP:DMG: suppressResponse = false, [1706278670.714424][1102:1102] CHIP:DMG: timedRequest = false, [1706278670.714465][1102:1102] CHIP:DMG: InvokeRequests = [1706278670.714541][1102:1102] CHIP:DMG: [ [1706278670.714582][1102:1102] CHIP:DMG: CommandDataIB = [1706278670.714630][1102:1102] CHIP:DMG: { [1706278670.714669][1102:1102] CHIP:DMG: CommandPathIB = [1706278670.714716][1102:1102] CHIP:DMG: { [1706278670.714767][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278670.714815][1102:1102] CHIP:DMG: ClusterId = 0x3e, [1706278670.714860][1102:1102] CHIP:DMG: CommandId = 0x4, [1706278670.714896][1102:1102] CHIP:DMG: }, [1706278670.714953][1102:1102] CHIP:DMG: [1706278670.714995][1102:1102] CHIP:DMG: CommandFields = [1706278670.715041][1102:1102] CHIP:DMG: { [1706278670.715091][1102:1102] CHIP:DMG: 0x0 = [ [1706278670.715259][1102:1102] CHIP:DMG: 0x9a, 0x06, 0x54, 0x11, 0x69, 0x27, 0xac, 0x7e, 0xf4, 0x76, 0x97, 0x86, 0x33, 0x33, 0x35, 0xf6, 0x91, 0x99, 0x71, 0xf6, 0xde, 0x09, 0x2f, 0xb7, 0x41, 0xab, 0xd6, 0x03, 0x77, 0x95, 0xee, 0x84, [1706278670.715317][1102:1102] CHIP:DMG: ] (32 bytes) [1706278670.715365][1102:1102] CHIP:DMG: }, [1706278670.715402][1102:1102] CHIP:DMG: }, [1706278670.715467][1102:1102] CHIP:DMG: [1706278670.715504][1102:1102] CHIP:DMG: ], [1706278670.715580][1102:1102] CHIP:DMG: [1706278670.715625][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278670.715658][1102:1102] CHIP:DMG: }, [1706278670.716144][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1706278670.716208][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278670.716275][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 [1706278670.716391][1102:1102] CHIP:ZCL: OpCreds: Received a CSRRequest command [1706278670.716445][1102:1102] CHIP:ZCL: OpCreds: Finding fabric with fabricIndex 0x0 [1706278670.723934][1102:1102] CHIP:ZCL: OpCreds: AllocatePendingOperationalKey succeeded [1706278670.725437][1102:1102] CHIP:ZCL: OpCreds: CSRRequest successful. [1706278670.725572][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278670.725599][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278670.725644][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278670.725786][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278670.725896][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278670.726202][1102:1102] CHIP:EM: <<< [E:17683r S:39053 M:362505] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278670.726763][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278670.726787][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278670.906811][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278671.004223][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278671.150154][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278671.155206][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278671.248103][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278671.252567][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278671.253267][1102:1102] CHIP:EM: >>> [E:17684r S:39053 M:68287851] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278671.253407][1102:1102] CHIP:EM: Handling via exchange: 17684r, Delegate: 0xaaaabf0a5b08 [1706278671.253688][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278671.253750][1102:1102] CHIP:DMG: { [1706278671.253799][1102:1102] CHIP:DMG: suppressResponse = false, [1706278671.253849][1102:1102] CHIP:DMG: timedRequest = false, [1706278671.253891][1102:1102] CHIP:DMG: InvokeRequests = [1706278671.253972][1102:1102] CHIP:DMG: [ [1706278671.254014][1102:1102] CHIP:DMG: CommandDataIB = [1706278671.254062][1102:1102] CHIP:DMG: { [1706278671.254103][1102:1102] CHIP:DMG: CommandPathIB = [1706278671.254151][1102:1102] CHIP:DMG: { [1706278671.254203][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278671.254257][1102:1102] CHIP:DMG: ClusterId = 0x3e, [1706278671.254304][1102:1102] CHIP:DMG: CommandId = 0xb, [1706278671.254342][1102:1102] CHIP:DMG: }, [1706278671.254402][1102:1102] CHIP:DMG: [1706278671.254447][1102:1102] CHIP:DMG: CommandFields = [1706278671.254496][1102:1102] CHIP:DMG: { [1706278671.254550][1102:1102] CHIP:DMG: 0x0 = [ [1706278671.255110][1102:1102] 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, 0xe9, 0xb3, 0x51, 0x09, 0xc4, 0x5a, 0xa6, 0xeb, 0x0b, 0xc0, 0xb3, 0x8b, 0x10, 0x75, 0x19, 0x94, 0x32, 0x65, 0x3c, 0xba, 0x39, 0x6e, 0x04, 0x1e, 0x50, 0x1b, 0x5a, 0x89, 0x87, 0xad, 0x65, 0xa1, 0x17, 0xff, 0xd6, 0x44, 0x04, 0x6f, 0x9e, 0xa6, 0x76, 0x83, 0x6c, 0x62, 0xfb, 0xaf, 0xc6, 0xdc, 0xcc, 0x70, 0x14, 0xee, 0xd0, 0x44, 0xe9, 0xb2, 0xe7, 0x1d, 0x8f, 0x29, 0xbe, 0x0e, 0x7b, 0x60, 0x37, 0x0a, 0x35, 0x01, 0x29, 0x01, 0x18, 0x24, 0x02, 0x60, 0x30, 0x04, 0x14, 0x36, 0x51, 0x4c, 0x1e, 0xd3, 0x88, 0xa6, 0x2c, 0xa3, 0xd4, 0xe1, 0x4a, 0xf1, 0x0a, 0xdc, 0x22, 0xaa, 0x10, 0x31, 0xf7, 0x30, 0x05, 0x14, 0x36, 0x51, 0x4c, 0x1e, 0xd3, 0x88, 0xa6, 0x2c, 0xa3, 0xd4, 0xe1, 0x4a, 0xf1, 0x0a, 0xdc, 0x22, 0xaa, 0x10, 0x31, 0xf7, 0x18, 0x30, 0x0b, 0x40, 0x54, 0x76, 0xe3, 0x16, 0xfb, 0x84, 0xa5, 0xda, 0xd5, 0x13, 0x96, 0x16, 0xce, 0xba, 0xcd, 0x35, 0xcb, 0x0a, 0x32, 0xb9, 0xb5, 0x3e, 0xdc, 0xe0, 0x4b, 0x11, 0xbe, 0x9f, 0xd4, 0x26, 0x2f, 0x21, 0x70, 0x10, 0x65, 0x6d, 0x48, 0xfc, 0x14, 0xd5, 0x7b, 0xa4, 0xc2, 0x1c, 0x34, 0x78, 0x82, 0xa3, 0x47, 0x7b, 0x46, 0xf8, 0xca, 0xaf, 0x3f, 0x9b, 0x17, 0x7b, 0xf3, 0x74, 0xe7, 0xe1, 0xee, 0xc5, 0x18, [1706278671.255240][1102:1102] CHIP:DMG: ] (231 bytes) [1706278671.255293][1102:1102] CHIP:DMG: }, [1706278671.255332][1102:1102] CHIP:DMG: }, [1706278671.255404][1102:1102] CHIP:DMG: [1706278671.255443][1102:1102] CHIP:DMG: ], [1706278671.255525][1102:1102] CHIP:DMG: [1706278671.255572][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278671.255607][1102:1102] CHIP:DMG: }, [1706278671.256109][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1706278671.256175][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278671.256245][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B [1706278671.256364][1102:1102] CHIP:ZCL: OpCreds: Received an AddTrustedRootCertificate command [1706278671.260208][1102:1102] CHIP:ZCL: OpCreds: AddTrustedRootCertificate successful. [1706278671.260354][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278671.260392][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278671.260442][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278671.260477][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278671.260612][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278671.260917][1102:1102] CHIP:EM: <<< [E:17684r S:39053 M:362506] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278671.261462][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278671.261491][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278671.344597][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278671.490737][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278671.496004][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278671.686987][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278671.692971][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278671.831862][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278671.836699][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278671.837499][1102:1102] CHIP:EM: >>> [E:17685r S:39053 M:68287852] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278671.837637][1102:1102] CHIP:EM: Handling via exchange: 17685r, Delegate: 0xaaaabf0a5b08 [1706278671.837896][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278671.837951][1102:1102] CHIP:DMG: { [1706278671.837999][1102:1102] CHIP:DMG: suppressResponse = false, [1706278671.838049][1102:1102] CHIP:DMG: timedRequest = false, [1706278671.838090][1102:1102] CHIP:DMG: InvokeRequests = [1706278671.838181][1102:1102] CHIP:DMG: [ [1706278671.838224][1102:1102] CHIP:DMG: CommandDataIB = [1706278671.838273][1102:1102] CHIP:DMG: { [1706278671.838314][1102:1102] CHIP:DMG: CommandPathIB = [1706278671.838365][1102:1102] CHIP:DMG: { [1706278671.838417][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278671.838467][1102:1102] CHIP:DMG: ClusterId = 0x3e, [1706278671.838512][1102:1102] CHIP:DMG: CommandId = 0x6, [1706278671.838550][1102:1102] CHIP:DMG: }, [1706278671.838609][1102:1102] CHIP:DMG: [1706278671.838653][1102:1102] CHIP:DMG: CommandFields = [1706278671.838702][1102:1102] CHIP:DMG: { [1706278671.838754][1102:1102] CHIP:DMG: 0x0 = [ [1706278671.839386][1102:1102] 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, 0xff, 0x90, 0x35, 0x54, 0x08, 0xac, 0x9b, 0x33, 0x92, 0x46, 0x2e, 0x75, 0x0b, 0xef, 0x9f, 0xd1, 0x29, 0x0f, 0xcb, 0x4c, 0xc0, 0xf2, 0x43, 0x69, 0xba, 0x43, 0x23, 0x63, 0x95, 0xb5, 0x90, 0x62, 0xa9, 0x43, 0x73, 0xd2, 0x29, 0xb4, 0x45, 0xb4, 0x39, 0x9b, 0x62, 0x3e, 0x95, 0xdc, 0xb6, 0xf7, 0x10, 0x86, 0x44, 0xab, 0x4c, 0x7f, 0x34, 0x67, 0x03, 0x1a, 0x0a, 0xef, 0x6b, 0x80, 0x1b, 0x21, 0x37, 0x0a, 0x35, 0x01, 0x28, 0x01, 0x18, 0x24, 0x02, 0x01, 0x36, 0x03, 0x04, 0x02, 0x04, 0x01, 0x18, 0x30, 0x04, 0x14, 0xb5, 0xfd, 0xea, 0xd2, 0x8b, 0x97, 0x50, 0x5f, 0x88, 0x7d, 0xa3, 0xcb, 0x03, 0x78, 0x5a, 0x30, 0xe3, 0x8c, 0x6a, 0x51, 0x30, 0x05, 0x14, 0x15, 0x8f, 0x5f, 0xf2, 0x38, 0xed, 0xcf, 0x5e, 0xa2, 0xea, 0xe2, 0x4c, 0x55, 0x14, 0x31, 0x5a, 0x27, 0x42, 0x49, 0x0c, 0x18, 0x30, 0x0b, 0x40, 0xc7, 0xe7, 0xe3, 0x02, 0x76, 0xbf, 0x96, 0x8d, 0x66, 0x20, 0x1c, 0xaa, 0x40, 0x52, 0x11, 0x08, 0x7c, 0xa1, 0xb8, 0xa0, 0x69, 0x5a, 0x51, 0xdc, 0x63, 0xed, 0x0f, 0x2f, 0xde, 0x58, 0x0b, 0x01, 0x07, 0x79, 0x47, 0xb4, 0x09, 0x82, 0xb0, 0xae, 0x08, 0x06, 0xaf, 0xdd, 0x56, 0x98, 0xc0, 0xf8, 0x49, 0x90, 0x85, 0xce, 0x0d, 0xec, 0xda, 0xc4, 0x38, 0x96, 0x43, 0x68, 0xdd, 0xa2, 0x1f, 0x7f, 0x18, [1706278671.839458][1102:1102] CHIP:DMG: ] (242 bytes) [1706278671.839507][1102:1102] CHIP:DMG: 0x1 = [ [1706278671.840058][1102:1102] 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, 0x7c, 0xfc, 0xe3, 0xed, 0x05, 0xd8, 0x12, 0x64, 0xd9, 0xae, 0x3d, 0xb5, 0x31, 0x50, 0xbb, 0x5f, 0xa0, 0x32, 0xa8, 0xfe, 0xc5, 0xde, 0x21, 0xdf, 0x96, 0x8e, 0xb0, 0x04, 0x77, 0x4d, 0xdf, 0x23, 0x05, 0x95, 0x44, 0x7d, 0x29, 0xfd, 0x38, 0x84, 0xcf, 0xfb, 0x21, 0x05, 0x3d, 0x9d, 0x91, 0x33, 0x59, 0x55, 0xa7, 0xd8, 0x1f, 0x65, 0x3e, 0x70, 0x0b, 0x52, 0x37, 0x4b, 0x50, 0x32, 0x9b, 0x3d, 0x37, 0x0a, 0x35, 0x01, 0x29, 0x01, 0x18, 0x24, 0x02, 0x60, 0x30, 0x04, 0x14, 0x15, 0x8f, 0x5f, 0xf2, 0x38, 0xed, 0xcf, 0x5e, 0xa2, 0xea, 0xe2, 0x4c, 0x55, 0x14, 0x31, 0x5a, 0x27, 0x42, 0x49, 0x0c, 0x30, 0x05, 0x14, 0x36, 0x51, 0x4c, 0x1e, 0xd3, 0x88, 0xa6, 0x2c, 0xa3, 0xd4, 0xe1, 0x4a, 0xf1, 0x0a, 0xdc, 0x22, 0xaa, 0x10, 0x31, 0xf7, 0x18, 0x30, 0x0b, 0x40, 0x28, 0x57, 0x39, 0xe5, 0xb1, 0xf4, 0x63, 0xb5, 0x06, 0x06, 0x5e, 0xe0, 0x94, 0x0b, 0x08, 0x6e, 0xdf, 0x08, 0x45, 0x67, 0x8e, 0xaa, 0x90, 0xa5, 0x0a, 0x06, 0x67, 0x6c, 0x20, 0x20, 0x77, 0x6b, 0x3b, 0x85, 0x75, 0x9b, 0x3c, 0xf7, 0x07, 0x77, 0xf0, 0xa3, 0x5d, 0x7f, 0x54, 0xe3, 0x87, 0x8d, 0xe4, 0x6f, 0x31, 0x4b, 0xcb, 0x15, 0x2d, 0x04, 0x8b, 0xca, 0x5f, 0x1a, 0x87, 0xa2, 0xe1, 0x79, 0x18, [1706278671.840128][1102:1102] CHIP:DMG: ] (231 bytes) [1706278671.840188][1102:1102] CHIP:DMG: 0x2 = [ [1706278671.840262][1102:1102] CHIP:DMG: 0x74, 0x65, 0x6d, 0x70, 0x6f, 0x72, 0x61, 0x72, 0x79, 0x20, 0x69, 0x70, 0x6b, 0x20, 0x30, 0x31, [1706278671.840312][1102:1102] CHIP:DMG: ] (16 bytes) [1706278671.840368][1102:1102] CHIP:DMG: 0x3 = 112233, [1706278671.840419][1102:1102] CHIP:DMG: 0x4 = 65521, [1706278671.840467][1102:1102] CHIP:DMG: }, [1706278671.840505][1102:1102] CHIP:DMG: }, [1706278671.840586][1102:1102] CHIP:DMG: [1706278671.840625][1102:1102] CHIP:DMG: ], [1706278671.840714][1102:1102] CHIP:DMG: [1706278671.840762][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278671.840797][1102:1102] CHIP:DMG: }, [1706278671.841375][1102:1102] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1706278671.841437][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278671.841510][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 [1706278671.841760][1102:1102] CHIP:ZCL: OpCreds: Received an AddNOC command [1706278671.847213][1102:1102] CHIP:FP: Validating NOC chain [1706278671.852074][1102:1102] CHIP:FP: NOC chain validation successful [1706278671.852239][1102:1102] CHIP:FP: Added new fabric at index: 0x1 [1706278671.852256][1102:1102] CHIP:FP: Assigned compressed fabric ID: 0x7EEEC0CBDA802E76, node ID: 0x00000000000007CE [1706278671.852290][1102:1102] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1706278671.852308][1102:1102] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1706278671.852324][1102:1102] CHIP:TS: Retaining current Last Known Good Time [1706278671.852382][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 10dc9d8b [1706278671.852411][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 10dc9d8c [1706278671.854149][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-jquCzc) [1706278671.855294][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278671.855793][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-CrqX6c) [1706278671.857117][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278671.857553][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-S2B6HS) [1706278671.858715][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278671.858902][1102:1102] CHIP:DMG: AccessControl: validating f=1 p=a a=c s=1 t=0 [1706278671.858932][1102:1102] CHIP:DMG: validating subject 0x000000000001B669 [1706278671.862116][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-0eQPR5) [1706278671.862909][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278671.863333][1102:1102] CHIP:EVL: LogEvent event number: 0x0000000000000002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Epoch timestamp: 0x0000018D462255F7 [1706278671.863372][1102:1102] CHIP:ZCL: OpCreds: ACL entry created for Fabric index 0x1 CASE Admin Subject 0x000000000001B669 [1706278671.863886][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278671.863957][1102:1102] CHIP:DIS: Advertise operational node 7EEEC0CBDA802E76-00000000000007CE [1706278671.864098][1102:1102] CHIP:DIS: Responding with _matter._tcp.local [1706278671.864129][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278671.864182][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278671.864201][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278671.864218][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278671.864252][1102:1102] CHIP:DIS: Responding with _I7EEEC0CBDA802E76._sub._matter._tcp.local [1706278671.864265][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 7EEEC0CBDA802E76-00000000000007CE. [1706278671.865754][1102:1102] CHIP:DIS: mDNS service published: _matter._tcp [1706278671.865796][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 10dc9d8d [1706278671.865825][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 10dc9d8e [1706278671.865941][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278671.865965][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278671.866006][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278671.866044][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278671.866061][1102:1102] CHIP:ZCL: OpCreds: successfully created fabric index 0x1 via AddNOC [1706278671.866179][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278671.866489][1102:1102] CHIP:EM: <<< [E:17685r S:39053 M:362507] (S) Msg TX to 1:FFFFFFFB00000000 [2E76] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278671.867064][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278671.867093][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278671.930046][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278671.979130][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278671.980335][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278671.980890][1102:1102] CHIP:EM: >>> [E:17686r S:39053 M:68287853] (S) Msg RX from 1:FFFFFFFB00000000 [2E76] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278671.980982][1102:1102] CHIP:EM: Handling via exchange: 17686r, Delegate: 0xaaaabf0a5b08 [1706278671.981170][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278671.981193][1102:1102] CHIP:DMG: { [1706278671.981211][1102:1102] CHIP:DMG: suppressResponse = false, [1706278671.981231][1102:1102] CHIP:DMG: timedRequest = false, [1706278671.981247][1102:1102] CHIP:DMG: InvokeRequests = [1706278671.981278][1102:1102] CHIP:DMG: [ [1706278671.981293][1102:1102] CHIP:DMG: CommandDataIB = [1706278671.981313][1102:1102] CHIP:DMG: { [1706278671.981327][1102:1102] CHIP:DMG: CommandPathIB = [1706278671.981350][1102:1102] CHIP:DMG: { [1706278671.981372][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278671.981389][1102:1102] CHIP:DMG: ClusterId = 0x31, [1706278671.981404][1102:1102] CHIP:DMG: CommandId = 0x2, [1706278671.981417][1102:1102] CHIP:DMG: }, [1706278671.981442][1102:1102] CHIP:DMG: [1706278671.981459][1102:1102] CHIP:DMG: CommandFields = [1706278671.981480][1102:1102] CHIP:DMG: { [1706278671.981501][1102:1102] CHIP:DMG: 0x0 = [ [1706278671.981520][1102:1102] CHIP:DMG: 0x4d, 0x4d, 0x2d, 0x4c, 0x41, 0x42, [1706278671.981539][1102:1102] CHIP:DMG: ] (6 bytes) [1706278671.981554][1102:1102] CHIP:DMG: 0x1 = [ [1706278671.981575][1102:1102] CHIP:DMG: 0x4c, 0x61, 0x62, 0x43, 0x6f, 0x61, 0x74, 0x43, 0x6f, 0x64, 0x65, [1706278671.981591][1102:1102] CHIP:DMG: ] (11 bytes) [1706278671.981609][1102:1102] CHIP:DMG: 0x2 = 23, [1706278671.981626][1102:1102] CHIP:DMG: }, [1706278671.981639][1102:1102] CHIP:DMG: }, [1706278671.981665][1102:1102] CHIP:DMG: [1706278671.981679][1102:1102] CHIP:DMG: ], [1706278671.981714][1102:1102] CHIP:DMG: [1706278671.981730][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278671.981742][1102:1102] CHIP:DMG: }, [1706278671.986241][1102:1102] CHIP:DMG: AccessControl: checking f=1 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=a [1706278671.986324][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278671.986400][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0002 [1706278671.986653][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278671.986683][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278671.986734][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278671.986776][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278671.986842][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 3d182cd8 [1706278671.986927][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278671.987274][1102:1102] CHIP:EM: <<< [E:17686r S:39053 M:362508] (S) Msg TX to 1:FFFFFFFB00000000 [2E76] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278671.987788][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278671.987815][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278672.076578][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278672.125212][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278672.127508][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278672.128212][1102:1102] CHIP:EM: >>> [E:17687r S:39053 M:68287854] (S) Msg RX from 1:FFFFFFFB00000000 [2E76] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278672.128341][1102:1102] CHIP:EM: Handling via exchange: 17687r, Delegate: 0xaaaabf0a5b08 [1706278672.128564][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278672.128612][1102:1102] CHIP:DMG: { [1706278672.128653][1102:1102] CHIP:DMG: suppressResponse = false, [1706278672.128697][1102:1102] CHIP:DMG: timedRequest = false, [1706278672.128733][1102:1102] CHIP:DMG: InvokeRequests = [1706278672.128802][1102:1102] CHIP:DMG: [ [1706278672.128839][1102:1102] CHIP:DMG: CommandDataIB = [1706278672.128880][1102:1102] CHIP:DMG: { [1706278672.128915][1102:1102] CHIP:DMG: CommandPathIB = [1706278672.128958][1102:1102] CHIP:DMG: { [1706278672.129002][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278672.129046][1102:1102] CHIP:DMG: ClusterId = 0x30, [1706278672.129086][1102:1102] CHIP:DMG: CommandId = 0x0, [1706278672.129118][1102:1102] CHIP:DMG: }, [1706278672.129168][1102:1102] CHIP:DMG: [1706278672.129207][1102:1102] CHIP:DMG: CommandFields = [1706278672.129247][1102:1102] CHIP:DMG: { [1706278672.129296][1102:1102] CHIP:DMG: 0x0 = 66, [1706278672.129341][1102:1102] CHIP:DMG: 0x1 = 25, [1706278672.129383][1102:1102] CHIP:DMG: }, [1706278672.129415][1102:1102] CHIP:DMG: }, [1706278672.129474][1102:1102] CHIP:DMG: [1706278672.129507][1102:1102] CHIP:DMG: ], [1706278672.129574][1102:1102] CHIP:DMG: [1706278672.129615][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278672.129645][1102:1102] CHIP:DMG: }, [1706278672.130085][1102:1102] CHIP:DMG: AccessControl: checking f=1 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1706278672.130138][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278672.130201][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 [1706278672.130308][1102:1102] CHIP:FS: GeneralCommissioning: Received ArmFailSafe (66s) [1706278672.130471][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 3d182cd9 [1706278672.130661][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278672.130717][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278672.130794][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278672.130870][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278672.131032][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278672.131436][1102:1102] CHIP:EM: <<< [E:17687r S:39053 M:362509] (S) Msg TX to 1:FFFFFFFB00000000 [2E76] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278672.132080][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278672.132130][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278672.222304][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278672.271668][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278672.273709][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278672.274405][1102:1102] CHIP:EM: >>> [E:17688r S:39053 M:68287855] (S) Msg RX from 1:FFFFFFFB00000000 [2E76] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278672.274524][1102:1102] CHIP:EM: Handling via exchange: 17688r, Delegate: 0xaaaabf0a5b08 [1706278672.274737][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278672.274784][1102:1102] CHIP:DMG: { [1706278672.274826][1102:1102] CHIP:DMG: suppressResponse = false, [1706278672.274870][1102:1102] CHIP:DMG: timedRequest = false, [1706278672.274906][1102:1102] CHIP:DMG: InvokeRequests = [1706278672.274975][1102:1102] CHIP:DMG: [ [1706278672.275012][1102:1102] CHIP:DMG: CommandDataIB = [1706278672.275053][1102:1102] CHIP:DMG: { [1706278672.275088][1102:1102] CHIP:DMG: CommandPathIB = [1706278672.275188][1102:1102] CHIP:DMG: { [1706278672.275241][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278672.275283][1102:1102] CHIP:DMG: ClusterId = 0x31, [1706278672.275323][1102:1102] CHIP:DMG: CommandId = 0x6, [1706278672.275356][1102:1102] CHIP:DMG: }, [1706278672.275407][1102:1102] CHIP:DMG: [1706278672.275445][1102:1102] CHIP:DMG: CommandFields = [1706278672.275488][1102:1102] CHIP:DMG: { [1706278672.275531][1102:1102] CHIP:DMG: 0x0 = [ [1706278672.275577][1102:1102] CHIP:DMG: 0x4d, 0x4d, 0x2d, 0x4c, 0x41, 0x42, [1706278672.275621][1102:1102] CHIP:DMG: ] (6 bytes) [1706278672.275666][1102:1102] CHIP:DMG: 0x1 = 27, [1706278672.275708][1102:1102] CHIP:DMG: }, [1706278672.275740][1102:1102] CHIP:DMG: }, [1706278672.275800][1102:1102] CHIP:DMG: [1706278672.275833][1102:1102] CHIP:DMG: ], [1706278672.275902][1102:1102] CHIP:DMG: [1706278672.275942][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278672.275972][1102:1102] CHIP:DMG: }, [1706278672.276429][1102:1102] CHIP:DMG: AccessControl: checking f=1 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=a [1706278672.276492][1102:1102] CHIP:DMG: AccessControl: implicit admin (PASE) [1706278672.276557][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0006 [1706278672.276707][1102:1102] CHIP:NP: LinuxWiFiDriver: SSID: MM-LAB [1706278672.296776][1102:1102] CHIP:DL: wpa_supplicant: added network: /fi/w1/wpa_supplicant1/Interfaces/0/Networks/0 [1706278672.297396][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 1 [1706278672.324492][1102:1105] CHIP:DL: wpa_supplicant:PropertiesChanged:key:State -> 'scanning' [1706278672.324551][1102:1105] CHIP:DL: wpa_supplicant:PropertiesChanged:key:Scanning -> true [1706278674.855881][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278675.149503][1102:1105] CHIP:DL: wpa_supplicant: network scan done [1706278675.150487][1102:1105] CHIP:DL: wpa_supplicant:PropertiesChanged:key:Scanning -> false [1706278675.150692][1102:1105] 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'] [1706278675.167644][1102:1105] CHIP:DL: wpa_supplicant:PropertiesChanged:key:State -> 'associating' [1706278677.537740][1102:1105] CHIP:DL: C1 WriteHandlerCallback MTU: 517 [1706278677.539367][1102:1105] CHIP:BLE: Write request received debug 0xffffa4705ff0 [1706278678.123184][1102:1105] CHIP:DL: wpa_supplicant:PropertiesChanged:key:State -> 'completed' [1706278678.123563][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278678.123615][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278678.123662][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278678.123713][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278678.123766][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 3d182cda [1706278678.123803][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278678.124136][1102:1102] CHIP:EM: <<< [E:17688r S:39053 M:362510] (S) Msg TX to 1:FFFFFFFB00000000 [2E76] [BLE] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278678.124471][1102:1105] CHIP:DL: wpa_supplicant:PropertiesChanged:key:CurrentBSS -> objectpath '/fi/w1/wpa_supplicant1/Interfaces/0/BSSs/1' [1706278678.124512][1102:1105] CHIP:DL: wpa_supplicant:PropertiesChanged:key:CurrentAuthMode -> 'WPA2-PSK+WPA-PSK' [1706278678.124936][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278678.124967][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278678.125580][1102:1102] CHIP:DL: HandlePlatformSpecificBLEEvent 32785 [1706278678.126065][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278678.126144][1102:1102] CHIP:DIS: Advertise operational node 7EEEC0CBDA802E76-00000000000007CE [1706278678.126291][1102:1102] CHIP:DIS: Responding with _matter._tcp.local [1706278678.126331][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278678.126371][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278678.126394][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278678.126415][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278678.126453][1102:1102] CHIP:DIS: Responding with _I7EEEC0CBDA802E76._sub._matter._tcp.local [1706278678.126469][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 7EEEC0CBDA802E76-00000000000007CE. [1706278678.130583][1102:1102] 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 [1706278678.130655][1102:1102] CHIP:DIS: mDNS service published: _matter._tcp [1706278678.130686][1102:1102] CHIP:SVR: Operational advertising enabled [1706278678.218814][1102:1105] CHIP:BLE: Indication confirmation, 0xffffa4705ff0 [1706278679.172460][1102:1105] CHIP:DL: Got IP address on interface: wlan0 IP: 172.16.62.113 [1706278679.172903][1102:1102] CHIP:DL: HandlePlatformSpecificBLEEvent 32770 [1706278679.172981][1102:1102] CHIP:DIS: Updating services using commissioning mode 0 [1706278679.182755][1102:1102] CHIP:DIS: CHIP minimal mDNS started advertising. [1706278679.190820][1102:1102] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.190864][1102:1102] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1706278679.190892][1102:1102] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.196159][1102:1102] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.196199][1102:1102] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1706278679.196226][1102:1102] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.196655][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278679.196714][1102:1102] CHIP:DIS: Advertise operational node 7EEEC0CBDA802E76-00000000000007CE [1706278679.196797][1102:1102] CHIP:DIS: Responding with _matter._tcp.local [1706278679.196823][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278679.196861][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278679.196881][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.196898][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.196940][1102:1102] CHIP:DIS: Responding with _I7EEEC0CBDA802E76._sub._matter._tcp.local [1706278679.196954][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 7EEEC0CBDA802E76-00000000000007CE. [1706278679.201233][1102:1102] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.201276][1102:1102] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1706278679.201302][1102:1102] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.201338][1102:1102] CHIP:DIS: mDNS service published: _matter._tcp [1706278679.201680][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278679.201921][1102:1102] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=0 cp=0 [1706278679.202015][1102:1102] CHIP:DIS: Responding with _matterc._udp.local [1706278679.202039][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278679.202058][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.202074][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.202101][1102:1102] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1706278679.202129][1102:1102] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1706278679.202154][1102:1102] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1706278679.202201][1102:1102] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1706278679.202266][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278679.202281][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 586331307FC43F37. [1706278679.207524][1102:1102] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.207588][1102:1102] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1706278679.207616][1102:1102] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.207667][1102:1102] CHIP:DIS: mDNS service published: _matterc._udp [1706278679.207730][1102:1102] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1706278679.207757][1102:1102] CHIP:SVR: Server initialization complete [1706278679.207800][1102:1102] CHIP:DIS: Updating services using commissioning mode 0 [1706278679.212185][1102:1102] CHIP:DIS: CHIP minimal mDNS started advertising. [1706278679.217715][1102:1102] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.217753][1102:1102] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1706278679.217778][1102:1102] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.222722][1102:1102] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.222770][1102:1102] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1706278679.222793][1102:1102] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.223644][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278679.223719][1102:1102] CHIP:DIS: Advertise operational node 7EEEC0CBDA802E76-00000000000007CE [1706278679.223827][1102:1102] CHIP:DIS: Responding with _matter._tcp.local [1706278679.223861][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278679.223898][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278679.223915][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.223931][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.223971][1102:1102] CHIP:DIS: Responding with _I7EEEC0CBDA802E76._sub._matter._tcp.local [1706278679.223984][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 7EEEC0CBDA802E76-00000000000007CE. [1706278679.228255][1102:1102] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.228301][1102:1102] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1706278679.228327][1102:1102] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.228363][1102:1102] CHIP:DIS: mDNS service published: _matter._tcp [1706278679.228675][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278679.228924][1102:1102] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=0 cp=0 [1706278679.229014][1102:1102] CHIP:DIS: Responding with _matterc._udp.local [1706278679.229045][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278679.229063][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.229081][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.229115][1102:1102] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1706278679.229143][1102:1102] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1706278679.229196][1102:1102] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1706278679.229222][1102:1102] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1706278679.229285][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278679.229300][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 586331307FC43F37. [1706278679.234349][1102:1102] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.234388][1102:1102] CHIP:DIS: mDNS broadcast full failed in 1 separate send attempts. [1706278679.234410][1102:1102] CHIP:DIS: Failed to advertise records: src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000063: Cannot assign requested address [1706278679.234442][1102:1102] CHIP:DIS: mDNS service published: _matterc._udp [1706278679.234497][1102:1102] CHIP:DL: HandlePlatformSpecificBLEEvent 32790 [1706278679.237950][1102:1102] CHIP:IM: No subscriptions to resume [1706278679.617458][1102:1102] CHIP:EM: >>> [E:17689r S:0 M:221639111] (U) Msg RX from 0:9F453237A972DC05 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1706278679.617625][1102:1102] CHIP:EM: Handling via exchange: 17689r, Delegate: 0xaaaabf0aeb00 [1706278679.617771][1102:1102] CHIP:IN: CASE Server received Sigma1 message . Starting handshake. EC 0xffffa3b1d2c0 [1706278679.618029][1102:1102] CHIP:SC: Received Sigma1 msg [1706278679.618196][1102:1102] CHIP:SC: Found MRP parameters in the message [1706278679.618332][1102:1102] CHIP:SC: Peer assigned session key ID 6382 [1706278679.621624][1102:1102] CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x00000000000007CE [1706278679.633118][1102:1102] CHIP:EM: <<< [E:17689r S:0 M:190944766 (Ack:221639111)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:46247] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1706278679.633750][1102:1102] CHIP:SC: Sent Sigma2 msg [1706278679.668594][1102:1102] CHIP:EM: >>> [E:17689r S:0 M:221639112 (Ack:190944766)] (U) Msg RX from 0:9F453237A972DC05 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1706278679.668662][1102:1102] CHIP:EM: Found matching exchange: 17689r, Delegate: 0xaaaabf0aeb38 [1706278679.668792][1102:1102] CHIP:EM: Rxd Ack; Removing MessageCounter:190944766 from Retrans Table on exchange 17689r [1706278679.668974][1102:1102] CHIP:SC: Received Sigma3 msg [1706278679.685754][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-TuiCRZ) [1706278679.686824][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.687282][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-cIuGHR) [1706278679.690895][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.691300][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-Bpv7uc) [1706278679.692129][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.692218][1102:1102] CHIP:SC: Sending status report. Protocol code 0, exchange 17689 [1706278679.692572][1102:1102] CHIP:EM: <<< [E:17689r S:0 M:190944767 (Ack:221639112)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:46247] --- Type 0000:40 (SecureChannel:StatusReport) [1706278679.693732][1102:1102] CHIP:SC: SecureSession[0xffffa0903940, LSID:39054]: State change 'kEstablishing' --> 'kActive' [1706278679.693789][1102:1102] CHIP:IN: SecureSession[0xffffa0903940]: Activated - Type:2 LSID:39054 [1706278679.693804][1102:1102] CHIP:IN: New secure session activated for device <000000000001B669, 1>, LSID:39054 PSID:6382! [1706278679.693832][1102:1102] CHIP:IN: CASE Session established to peer: <000000000001B669, 1> [1706278679.694072][1102:1102] CHIP:IN: SecureSession[0xffffa0903340]: Allocated Type:2 LSID:39055 [1706278679.694119][1102:1102] CHIP:SC: Allocated SecureSession (0xffffa0903340) - waiting for Sigma1 msg [1706278679.709357][1102:1102] CHIP:EM: >>> [E:17690r S:39054 M:50331511] (S) Msg RX from 1:000000000001B669 [2E76] --- Type 0001:08 (IM:InvokeCommandRequest) [1706278679.709436][1102:1102] CHIP:EM: Handling via exchange: 17690r, Delegate: 0xaaaabf0a5b08 [1706278679.709673][1102:1102] CHIP:DMG: InvokeRequestMessage = [1706278679.709699][1102:1102] CHIP:DMG: { [1706278679.709717][1102:1102] CHIP:DMG: suppressResponse = false, [1706278679.709739][1102:1102] CHIP:DMG: timedRequest = false, [1706278679.709756][1102:1102] CHIP:DMG: InvokeRequests = [1706278679.709786][1102:1102] CHIP:DMG: [ [1706278679.709801][1102:1102] CHIP:DMG: CommandDataIB = [1706278679.709820][1102:1102] CHIP:DMG: { [1706278679.709833][1102:1102] CHIP:DMG: CommandPathIB = [1706278679.709855][1102:1102] CHIP:DMG: { [1706278679.709876][1102:1102] CHIP:DMG: EndpointId = 0x0, [1706278679.709895][1102:1102] CHIP:DMG: ClusterId = 0x30, [1706278679.709911][1102:1102] CHIP:DMG: CommandId = 0x4, [1706278679.709924][1102:1102] CHIP:DMG: }, [1706278679.709948][1102:1102] CHIP:DMG: [1706278679.709966][1102:1102] CHIP:DMG: CommandFields = [1706278679.709982][1102:1102] CHIP:DMG: { [1706278679.709999][1102:1102] CHIP:DMG: }, [1706278679.710012][1102:1102] CHIP:DMG: }, [1706278679.710037][1102:1102] CHIP:DMG: [1706278679.710050][1102:1102] CHIP:DMG: ], [1706278679.710083][1102:1102] CHIP:DMG: [1706278679.710098][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278679.710110][1102:1102] CHIP:DMG: }, [1706278679.710352][1102:1102] CHIP:DMG: AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0030 e=0 p=a [1706278679.710412][1102:1102] CHIP:DMG: AccessControl: allowed [1706278679.710448][1102:1102] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 [1706278679.710502][1102:1102] CHIP:FS: GeneralCommissioning: Received CommissioningComplete [1706278679.711604][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-u9Xtz8) [1706278679.712482][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.712806][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-HOEhz3) [1706278679.718961][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.719192][1102:1102] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1706278679.719651][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-cuz88V) [1706278679.720505][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.721311][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-CNjV5z) [1706278679.722491][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.722879][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-G57dgc) [1706278679.746932][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.747401][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-HRUCiU) [1706278679.748744][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.748935][1102:1102] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1706278679.749202][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-RR7iNn) [1706278679.761842][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.762259][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-0Lltrb) [1706278679.763097][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.763256][1102:1102] CHIP:ZCL: OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0x7EEEC0CBDA802E76, FabricId 0000000000000001, NodeId 00000000000007CE, VendorId 0xFFF1 [1706278679.763460][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-X4W0CF) [1706278679.764330][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.764436][1102:1102] CHIP:FS: GeneralCommissioning: Successfully commited pending fabric data [1706278679.764489][1102:1102] CHIP:FS: Fail-safe cleanly disarmed [1706278679.764557][1102:1102] CHIP:DMG: Endpoint 0, Cluster 0x0000_0030 update version to 3d182cdb [1706278679.764682][1102:1102] CHIP:DMG: Command handler moving to [NewRespons] [1706278679.764706][1102:1102] CHIP:DMG: Command handler moving to [ Preparing] [1706278679.764757][1102:1102] CHIP:DMG: Command handler moving to [AddingComm] [1706278679.764805][1102:1102] CHIP:DMG: Command handler moving to [AddedComma] [1706278679.765047][1102:1102] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1706278679.765554][1102:1102] CHIP:EM: <<< [E:17690r S:39054 M:184245974 (Ack:50331511)] (S) Msg TX to 1:000000000001B669 [2E76] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:46247] --- Type 0001:09 (IM:InvokeCommandResponse) [1706278679.765998][1102:1102] CHIP:DMG: Command response sender moving to [AllInvokeR] [1706278679.766025][1102:1102] CHIP:DMG: Command handler moving to [AwaitingDe] [1706278679.766128][1102:1102] CHIP:DL: HandlePlatformSpecificBLEEvent 32783 [1706278679.766152][1102:1102] CHIP:SVR: Commissioning completed successfully [1706278679.766219][1102:1102] CHIP:DIS: Updating services using commissioning mode 0 [1706278679.769250][1102:1102] CHIP:DIS: CHIP minimal mDNS started advertising. [1706278679.781216][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278679.781326][1102:1102] CHIP:DIS: Advertise operational node 7EEEC0CBDA802E76-00000000000007CE [1706278679.781430][1102:1102] CHIP:DIS: Responding with _matter._tcp.local [1706278679.781457][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278679.781498][1102:1102] CHIP:DIS: Responding with 7EEEC0CBDA802E76-00000000000007CE._matter._tcp.local [1706278679.781517][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.781533][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.781570][1102:1102] CHIP:DIS: Responding with _I7EEEC0CBDA802E76._sub._matter._tcp.local [1706278679.781583][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'; instance name: 7EEEC0CBDA802E76-00000000000007CE. [1706278679.786238][1102:1102] CHIP:DIS: mDNS service published: _matter._tcp [1706278679.786699][1102:1102] CHIP:DL: Using wifi MAC for hostname [1706278679.786963][1102:1102] CHIP:DIS: Advertise commission parameter vendorID=65521 productID=32769 discriminator=0018/00 cm=0 cp=0 [1706278679.787040][1102:1102] CHIP:DIS: Responding with _matterc._udp.local [1706278679.787068][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278679.787085][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.787234][1102:1102] CHIP:DIS: Responding with E45F01C247AF0000.local [1706278679.787283][1102:1102] CHIP:DIS: Responding with _V65521._sub._matterc._udp.local [1706278679.787310][1102:1102] CHIP:DIS: Responding with _T257._sub._matterc._udp.local [1706278679.787335][1102:1102] CHIP:DIS: Responding with _S0._sub._matterc._udp.local [1706278679.787379][1102:1102] CHIP:DIS: Responding with _L18._sub._matterc._udp.local [1706278679.787444][1102:1102] CHIP:DIS: Responding with 586331307FC43F37._matterc._udp.local [1706278679.787459][1102:1102] CHIP:DIS: CHIP minimal mDNS configured as 'Commissionable node device'; instance name: 586331307FC43F37. [1706278679.792799][1102:1102] CHIP:DIS: mDNS service published: _matterc._udp [1706278679.792973][1102:1102] CHIP:IN: Expiring all PASE sessions [1706278679.792994][1102:1102] CHIP:IN: SecureSession[0xffffa0903ac0]: MarkForEviction Type:1 LSID:39053 [1706278679.793017][1102:1102] CHIP:SC: SecureSession[0xffffa0903ac0, LSID:39053]: State change 'kActive' --> 'kPendingEviction' [1706278679.793046][1102:1102] CHIP:IN: SecureSession[0xffffa0903ac0]: Released - Type:1 LSID:39053 [1706278679.793087][1102:1102] CHIP:IN: Clearing BLE pending packets. [1706278679.793103][1102:1102] CHIP:BLE: Releasing end point's BLE connection back to application. [1706278679.793116][1102:1102] CHIP:BLE: Got notification regarding chip connection closure [1706278679.793161][1102:1102] CHIP:ZCL: Commissioning complete, notify platform driver to persist network credentials. [1706278679.793519][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-DHadG1) [1706278679.794627][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.794895][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-IbHqn5) [1706278679.795825][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278679.795927][1102:1102] CHIP:DL: wpa_supplicant: save config [1706278679.808760][1102:1102] CHIP:DL: wpa_supplicant: save config succeeded! [1706278679.809293][1102:1102] CHIP:EM: >>> [E:17689r S:0 M:221639113 (Ack:190944767)] (U) Msg RX from 0:9F453237A972DC05 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1706278679.809338][1102:1102] CHIP:EM: Found matching exchange: 17689r, Delegate: (nil) [1706278679.809435][1102:1102] CHIP:EM: Rxd Ack; Removing MessageCounter:190944767 from Retrans Table on exchange 17689r [1706278680.122018][1102:1102] CHIP:EM: Retransmitting MessageCounter:184245974 on exchange 17690r Send Cnt 1 [1706278680.494798][1102:1102] CHIP:EM: Retransmitting MessageCounter:184245974 on exchange 17690r Send Cnt 2 [1706278681.066991][1102:1102] CHIP:EM: Retransmitting MessageCounter:184245974 on exchange 17690r Send Cnt 3 [1706278682.028510][1102:1102] CHIP:EM: Retransmitting MessageCounter:184245974 on exchange 17690r Send Cnt 4 [1706278682.271735][1102:1102] CHIP:EM: >>> [E:17690r S:39054 M:50331512 (Ack:184245974)] (S) Msg RX from 1:000000000001B669 [2E76] --- Type 0000:10 (SecureChannel:StandaloneAck) [1706278682.271849][1102:1102] CHIP:EM: Found matching exchange: 17690r, Delegate: (nil) [1706278682.271977][1102:1102] CHIP:EM: Rxd Ack; Removing MessageCounter:184245974 from Retrans Table on exchange 17690r [1706278682.406617][1102:1105] CHIP:DL: Bluez disconnected [1706278682.406706][1102:1105] CHIP:DL: Bluez notify CHIPoBluez connection disconnected [1706278690.688692][1102:1102] CHIP:EM: >>> [E:18942r S:0 M:237614114] (U) Msg RX from 0:B00729AF0CE27A9B [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1706278690.688858][1102:1102] CHIP:EM: Handling via exchange: 18942r, Delegate: 0xaaaabf0aeb00 [1706278690.688998][1102:1102] CHIP:IN: CASE Server received Sigma1 message . Starting handshake. EC 0xffffa3b26680 [1706278690.689116][1102:1102] CHIP:SC: Received Sigma1 msg [1706278690.689287][1102:1102] CHIP:SC: Found MRP parameters in the message [1706278690.689428][1102:1102] CHIP:SC: Peer assigned session key ID 47306 [1706278690.693029][1102:1102] CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x00000000000007CE [1706278690.705444][1102:1102] CHIP:EM: <<< [E:18942r S:0 M:190944768 (Ack:237614114)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:39153] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1706278690.705949][1102:1102] CHIP:SC: Sent Sigma2 msg [1706278690.731620][1102:1102] CHIP:EM: >>> [E:18942r S:0 M:237614115 (Ack:190944768)] (U) Msg RX from 0:B00729AF0CE27A9B [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1706278690.731660][1102:1102] CHIP:EM: Found matching exchange: 18942r, Delegate: 0xaaaabf0aeb38 [1706278690.731713][1102:1102] CHIP:EM: Rxd Ack; Removing MessageCounter:190944768 from Retrans Table on exchange 18942r [1706278690.731823][1102:1102] CHIP:SC: Received Sigma3 msg [1706278690.746827][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-aFr6bk) [1706278690.747894][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278690.748279][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-P4uTUS) [1706278690.749168][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278690.749534][1102:1102] CHIP:DL: writing settings to file (/tmp/chip_kvs-rewDDq) [1706278690.750381][1102:1102] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1706278690.750480][1102:1102] CHIP:SC: Sending status report. Protocol code 0, exchange 18942 [1706278690.750779][1102:1102] CHIP:EM: <<< [E:18942r S:0 M:190944769 (Ack:237614115)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:39153] --- Type 0000:40 (SecureChannel:StatusReport) [1706278690.751969][1102:1102] CHIP:SC: SecureSession[0xffffa0903340, LSID:39055]: State change 'kEstablishing' --> 'kActive' [1706278690.752041][1102:1102] CHIP:IN: SecureSession[0xffffa0903340]: Activated - Type:2 LSID:39055 [1706278690.752059][1102:1102] CHIP:IN: New secure session activated for device <000000000001B669, 1>, LSID:39055 PSID:47306! [1706278690.752086][1102:1102] CHIP:IN: CASE Session established to peer: <000000000001B669, 1> [1706278690.752310][1102:1102] CHIP:IN: SecureSession[0xffffa0909c40]: Allocated Type:2 LSID:39056 [1706278690.752365][1102:1102] CHIP:SC: Allocated SecureSession (0xffffa0909c40) - waiting for Sigma1 msg [1706278690.768187][1102:1102] CHIP:EM: >>> [E:18943r S:39055 M:164381868] (S) Msg RX from 1:000000000001B669 [2E76] --- Type 0001:02 (IM:ReadRequest) [1706278690.768293][1102:1102] CHIP:EM: Handling via exchange: 18943r, Delegate: 0xaaaabf0a5b08 [1706278690.768395][1102:1102] CHIP:IM: Received Read request [1706278690.768510][1102:1102] CHIP:DMG: ReadRequestMessage = [1706278690.768535][1102:1102] CHIP:DMG: { [1706278690.768550][1102:1102] CHIP:DMG: AttributePathIBs = [1706278690.768572][1102:1102] CHIP:DMG: [ [1706278690.768586][1102:1102] CHIP:DMG: AttributePathIB = [1706278690.768610][1102:1102] CHIP:DMG: { [1706278690.768631][1102:1102] CHIP:DMG: Endpoint = 0x0, [1706278690.768650][1102:1102] CHIP:DMG: Cluster = 0x28, [1706278690.768667][1102:1102] CHIP:DMG: Attribute = 0x0000_0009, [1706278690.768679][1102:1102] CHIP:DMG: } [1706278690.768699][1102:1102] CHIP:DMG: [1706278690.768712][1102:1102] CHIP:DMG: ], [1706278690.768736][1102:1102] CHIP:DMG: [1706278690.768755][1102:1102] CHIP:DMG: isFabricFiltered = true, [1706278690.768770][1102:1102] CHIP:DMG: InteractionModelRevision = 11 [1706278690.768782][1102:1102] CHIP:DMG: }, [1706278690.769099][1102:1102] CHIP:DMG: IM RH moving to [CanStartReporting] [1706278690.769298][1102:1102] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0x0000000000000000 DirtyGeneration = 0x0000000000000000 [1706278690.769334][1102:1102] CHIP:DMG: Cluster 28, Attribute 9 is dirty [1706278690.769349][1102:1102] CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0009 (expanded=0) [1706278690.769394][1102:1102] CHIP:DMG: AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0028 e=0 p=v [1706278690.769449][1102:1102] CHIP:DMG: AccessControl: allowed [1706278690.769605][1102:1102] CHIP:DMG: Sending report (payload has 36 bytes)... [1706278690.770035][1102:1102] CHIP:EM: <<< [E:18943r S:39055 M:64904145 (Ack:164381868)] (S) Msg TX to 1:000000000001B669 [2E76] [UDP:[fe80::e65f:1ff:fe0a:da36%wlan0]:39153] --- Type 0001:05 (IM:ReportData) [1706278690.770685][1102:1102] CHIP:DMG: OnReportConfirm: NumReports = 0 [1706278690.770720][1102:1102] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1706278690.770739][1102:1102] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1706278690.777943][1102:1102] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1706278690.778456][1102:1102] CHIP:EM: >>> [E:18942r S:0 M:237614116 (Ack:190944769)] (U) Msg RX from 0:B00729AF0CE27A9B [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) [1706278690.778500][1102:1102] CHIP:EM: Found matching exchange: 18942r, Delegate: (nil) [1706278690.778609][1102:1102] CHIP:EM: Rxd Ack; Removing MessageCounter:190944769 from Retrans Table on exchange 18942r [1706278690.793675][1102:1102] CHIP:EM: >>> [E:18943r S:39055 M:164381869 (Ack:64904145)] (S) Msg RX from 1:000000000001B669 [2E76] --- Type 0000:10 (SecureChannel:StandaloneAck) [1706278690.793723][1102:1102] CHIP:EM: Found matching exchange: 18943r, Delegate: (nil) [1706278690.793776][1102:1102] CHIP:EM: Rxd Ack; Removing MessageCounter:64904145 from Retrans Table on exchange 18943r