irenesiu@Irenes-MacBook-Pro connectedhomeip % out/apps/ota-provider/chip-ota-provider-app -f ~/Downloads/test2.ota --passcode 20202021 --discriminator 3840 --KVS /tmp/chip_kvs_provider [1651080075858] [2857:76310] CHIP: [DL] KVS will be written to: file:///tmp/chip_kvs_provider [1651080075887] [2857:76310] CHIP: [SPT] PASE PBKDF iterations set to 1000 [1651080075887] [2857:76310] CHIP: [SPT] LinuxCommissionableDataProvider didn't get a PASE salt, generating one. [1651080075894] [2857:76310] CHIP: [DL] Device Configuration: [1651080075894] [2857:76310] CHIP: [DL] Serial Number: TEST_SN [1651080075894] [2857:76310] CHIP: [DL] Vendor Id: 65521 (0xFFF1) [1651080075894] [2857:76310] CHIP: [DL] Product Id: 32769 (0x8001) [1651080075895] [2857:76310] CHIP: [DL] Hardware Version: 0 [1651080075895] [2857:76310] CHIP: [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 [1651080075895] [2857:76310] CHIP: [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) [1651080075895] [2857:76310] CHIP: [DL] Manufacturing Date: (not set) [1651080075895] [2857:76310] CHIP: [DL] Device Type: 65535 (0xFFFF) [1651080075895] [2857:76310] CHIP: [SVR] SetupQRCode: [MT:-24J0AFN00KA0648G00] [1651080075895] [2857:76310] CHIP: [SVR] Copy/paste the below URL in a browser to see the QR Code: [1651080075895] [2857:76310] CHIP: [SVR] https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J0AFN00KA0648G00 [1651080075895] [2857:76310] CHIP: [SVR] Manual pairing code: [34970112332] [1651080075895] [2857:76310] CHIP: [SVR] SetupQRCode: [MT:-24J029Q00KA0648G00] [1651080075895] [2857:76310] CHIP: [SVR] Copy/paste the below URL in a browser to see the QR Code: [1651080075895] [2857:76310] CHIP: [SVR] https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J029Q00KA0648G00 [1651080075895] [2857:76310] CHIP: [SVR] Manual pairing code: [749701123365521327694] [1651080075895] [2857:76310] CHIP: [ZCL] Using ZAP configuration... [1651080075895] [2857:76310] CHIP: [DMG] Failed to read stored attribute (0, 0x0000_0028, 0x0000_0005: ../../../examples/ota-provider-app/linux/third_party/connectedhomeip/src/platform/Darwin/KeyValueStoreManagerImpl.mm:222: CHIP Error 0x000000A0: Value n [1651080075895] [2857:76310] CHIP: [DMG] Failed to read stored attribute (0, 0x0000_0028, 0x0000_0010: ../../../examples/ota-provider-app/linux/third_party/connectedhomeip/src/platform/Darwin/KeyValueStoreManagerImpl.mm:222: CHIP Error 0x000000A0: Value n [1651080075895] [2857:76310] CHIP: [DMG] Failed to read stored attribute (0, 0x0000_002B, 0x0000_0001: ../../../examples/ota-provider-app/linux/third_party/connectedhomeip/src/platform/Darwin/KeyValueStoreManagerImpl.mm:222: CHIP Error 0x000000A0: Value n [1651080075895] [2857:76310] CHIP: [DMG] Failed to read stored attribute (0, 0x0000_002C, 0x0000_0000: ../../../examples/ota-provider-app/linux/third_party/connectedhomeip/src/platform/Darwin/KeyValueStoreManagerImpl.mm:222: CHIP Error 0x000000A0: Value n [1651080075896] [2857:76310] CHIP: [DMG] Failed to read stored attribute (0, 0x0000_002C, 0x0000_0001: ../../../examples/ota-provider-app/linux/third_party/connectedhomeip/src/platform/Darwin/KeyValueStoreManagerImpl.mm:222: CHIP Error 0x000000A0: Value n [1651080075896] [2857:76310] CHIP: [DMG] AccessControlCluster: initializing [1651080075896] [2857:76310] CHIP: [DIS] Add fabric pairing table delegate [1651080075896] [2857:76310] CHIP: [ZCL] OpCreds: Initiating OpCreds cluster by writing fabrics list from fabric table. [1651080075896] [2857:76310] CHIP: [DIS] Add fabric pairing table delegate [1651080075896] [2857:76310] CHIP: [DMG] Endpoint 0, Cluster 0x0000_002B update version to 8f368f2e [1651080075896] [2857:76310] CHIP: [DIS] Init fabric pairing table with server storage [1651080075897] [2857:76310] CHIP: [DMG] AccessControl: initializing [1651080075897] [2857:76310] CHIP: [DMG] Examples::AccessControlDelegate::Init [1651080075897] [2857:76310] CHIP: [DMG] AccessControl: unable to load stored ACL entries; using empty list instead [1651080075897] [2857:76310] CHIP: [DMG] AccessControl: setting [1651080075897] [2857:76310] CHIP: [IN] UDP::Init bind&listen port=5540 [1651080075897] [2857:76310] CHIP: [IN] UDP::Init bound to port=5540 [1651080075897] [2857:76310] CHIP: [IN] UDP::Init bind&listen port=5540 [1651080075897] [2857:76310] CHIP: [IN] UDP::Init bound to port=5540 [1651080075897] [2857:76310] CHIP: [IN] TransportMgr initialized [1651080075898] [2857:76310] CHIP: [DIS] Add fabric pairing table delegate [1651080075898] [2857:76310] CHIP: [SC] Assigned local session key ID 57613 [1651080075898] [2857:76310] CHIP: [SC] Waiting for PBKDF param request [1651080075898] [2857:76310] CHIP: [DIS] Updating services using commissioning mode 1 [1651080075898] [2857:76310] CHIP: [DL] Using wifi MAC for hostname [1651080075899] [2857:76310] CHIP: [DIS] Advertise commission parameter vendorID=65521 productID=32769 discriminator=3840/15 [1651080075899] [2857:76310] CHIP: [DL] Publishing service 63B1FEBBD9121BEA on port 5540 with type: _matterc._udp,_V65521,_S15,_L3840,_CM on interface id: 0 [1651080075899] [2857:76310] CHIP: [DIS] Scheduling discovery timeout in 900s [1651080075899] [2857:76310] CHIP: [DIS] Updating services using commissioning mode 1 [1651080075899] [2857:76310] CHIP: [DL] Using wifi MAC for hostname [1651080075899] [2857:76310] CHIP: [DIS] Advertise commission parameter vendorID=65521 productID=32769 discriminator=3840/15 [1651080075899] [2857:76310] CHIP: [DL] Publishing service 63B1FEBBD9121BEA on port 5540 with type: _matterc._udp,_V65521,_S15,_L3840,_CM on interface id: 0 [1651080075900] [2857:76310] CHIP: [DIS] Scheduling discovery timeout in 900s [1651080075900] [2857:76310] CHIP: [IN] CASE Server enabling CASE session setups [1651080075900] [2857:76310] CHIP: [SVR] Joining Multicast groups [1651080075900] [2857:76310] CHIP: [ZCL] Emitting StartUp event [1651080075900] [2857:76310] CHIP: [EVL] LogEvent event number: 0x0000000000000000 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x0 Sys timestamp: 0x0000000000424678 [1651080075900] [2857:76310] CHIP: [SVR] Server Listening... [1651080075900] [2857:76310] CHIP: [DL] Device Configuration: [1651080075900] [2857:76310] CHIP: [DL] Serial Number: TEST_SN [1651080075900] [2857:76310] CHIP: [DL] Vendor Id: 65521 (0xFFF1) [1651080075900] [2857:76310] CHIP: [DL] Product Id: 32769 (0x8001) [1651080075900] [2857:76310] CHIP: [DL] Hardware Version: 0 [1651080075900] [2857:76310] CHIP: [DL] Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 [1651080075900] [2857:76310] CHIP: [DL] Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) [1651080075900] [2857:76310] CHIP: [DL] Manufacturing Date: (not set) [1651080075900] [2857:76310] CHIP: [DL] Device Type: 65535 (0xFFFF) [1651080075900] [2857:76310] CHIP: [SVR] SetupQRCode: [MT:-24J029Q00KA0648G00] [1651080075900] [2857:76310] CHIP: [SVR] Copy/paste the below URL in a browser to see the QR Code: [1651080075900] [2857:76310] CHIP: [SVR] https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J029Q00KA0648G00 [1651080075900] [2857:76310] CHIP: [SVR] Manual pairing code: [749701123365521327694] [1651080075900] [2857:76310] CHIP: [SWU] Using OTA file: /Users/irenesiu/Downloads/test2.ota [1651080075900] [2857:76310] CHIP: [SWU] Using ImageList file: (none) [1651080075900] [2857:76324] CHIP: [DIS] Updating services using commissioning mode 1 [1651080075901] [2857:76324] CHIP: [DL] Using wifi MAC for hostname [1651080075901] [2857:76324] CHIP: [DIS] Advertise commission parameter vendorID=65521 productID=32769 discriminator=3840/15 [1651080075901] [2857:76324] CHIP: [DL] Publishing service 63B1FEBBD9121BEA on port 5540 with type: _matterc._udp,_V65521,_S15,_L3840,_CM on interface id: 0 [1651080075901] [2857:76324] CHIP: [DIS] Scheduling discovery timeout in 900s [1651080076534] [2857:76324] CHIP: [DL] Mdns: OnRegister name: 63B1FEBBD9121BEA, type: _matterc._udp., domain: local., flags: 2 [1651080076534] [2857:76324] CHIP: [DIS] mDNS service published: _matterc [1651080101812] [2857:76478] CHIP: [EM] Received message of type 0x20 with protocolId (0, 0) and MessageCounter:3035076623 on exchange 107r [1651080101812] [2857:76478] CHIP: [EM] Handling via exchange: 107r, Delegate: 0x10f391228 [1651080101812] [2857:76478] CHIP: [SC] Received PBKDF param request [1651080101812] [2857:76478] CHIP: [SC] Peer assigned session ID 15674 [1651080101812] [2857:76478] CHIP: [SC] Found MRP parameters in the message [1651080101812] [2857:76478] CHIP: [SC] Including MRP parameters in PBKDF param response [1651080101813] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:3035076623 on exchange: 107r [1651080101813] [2857:76478] CHIP: [IN] Prepared unauthenticated message 0x10f389de8 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 107r with MessageCounter:2279333804. [1651080101813] [2857:76478] CHIP: [IN] Sending unauthenticated msg 0x10f389de8 with MessageCounter:2279333804 to 0x0000000000000000 at monotonic time: 000000000042ABB1 msec [1651080101813] [2857:76478] CHIP: [SC] Sent PBKDF param response [1651080101816] [2857:76478] CHIP: [EM] Received message of type 0x22 with protocolId (0, 0) and MessageCounter:3035076624 on exchange 107r [1651080101816] [2857:76478] CHIP: [EM] Found matching exchange: 107r, Delegate: 0x10f391228 [1651080101816] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:2279333804 from Retrans Table on exchange 107r [1651080101816] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:2279333804 from RetransTable on exchange 107r [1651080101816] [2857:76478] CHIP: [SC] Received spake2p msg1 [1651080101816] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:3035076624 on exchange: 107r [1651080101816] [2857:76478] CHIP: [IN] Prepared unauthenticated message 0x10f389de8 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 107r with MessageCounter:2279333805. [1651080101816] [2857:76478] CHIP: [IN] Sending unauthenticated msg 0x10f389de8 with MessageCounter:2279333805 to 0x0000000000000000 at monotonic time: 000000000042ABB4 msec [1651080101816] [2857:76478] CHIP: [SC] Sent spake2p msg2 [1651080101817] [2857:76478] CHIP: [EM] Received message of type 0x24 with protocolId (0, 0) and MessageCounter:3035076625 on exchange 107r [1651080101817] [2857:76478] CHIP: [EM] Found matching exchange: 107r, Delegate: 0x10f391228 [1651080101817] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:2279333805 from Retrans Table on exchange 107r [1651080101817] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:2279333805 from RetransTable on exchange 107r [1651080101817] [2857:76478] CHIP: [SC] Received spake2p msg3 [1651080101817] [2857:76478] CHIP: [SC] Sending status report. Protocol code 0, exchange 107 [1651080101817] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:3035076625 on exchange: 107r [1651080101817] [2857:76478] CHIP: [IN] Prepared unauthenticated message 0x10f389de8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 107r with MessageCounter:2279333806. [1651080101817] [2857:76478] CHIP: [IN] Sending unauthenticated msg 0x10f389de8 with MessageCounter:2279333806 to 0x0000000000000000 at monotonic time: 000000000042ABB5 msec [1651080101817] [2857:76478] CHIP: [IN] New secure session created for device , LSID:57613 PSID:15674! [1651080101817] [2857:76478] CHIP: [SVR] Commissioning completed session establishment step [1651080101817] [2857:76478] CHIP: [DIS] Updating services using commissioning mode 0 [1651080101819] [2857:76478] CHIP: [SVR] Device completed Rendezvous process [1651080101819] [2857:76478] CHIP: [EM] Received message of type 0x2 with protocolId (0, 1) and MessageCounter:14615239 on exchange 108r [1651080101819] [2857:76478] CHIP: [EM] Handling via exchange: 108r, Delegate: 0x10f391a60 [1651080101819] [2857:76478] CHIP: [IM] Received Read request [1651080101819] [2857:76478] CHIP: [DMG] ReadRequestMessage = [1651080101819] [2857:76478] CHIP: [DMG] { [1651080101819] [2857:76478] CHIP: [DMG] AttributePathIBs = [1651080101819] [2857:76478] CHIP: [DMG] [ [1651080101819] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080101819] [2857:76478] CHIP: [DMG] { [1651080101819] [2857:76478] CHIP: [DMG] Cluster = 0x31, [1651080101819] [2857:76478] CHIP: [DMG] Attribute = 0x0000_FFFC, [1651080101819] [2857:76478] CHIP: [DMG] } [1651080101819] [2857:76478] CHIP: [DMG] [1651080101819] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080101819] [2857:76478] CHIP: [DMG] { [1651080101819] [2857:76478] CHIP: [DMG] Endpoint = 0x0, [1651080101819] [2857:76478] CHIP: [DMG] Cluster = 0x30, [1651080101819] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0000, [1651080101819] [2857:76478] CHIP: [DMG] } [1651080101819] [2857:76478] CHIP: [DMG] [1651080101819] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080101819] [2857:76478] CHIP: [DMG] { [1651080101819] [2857:76478] CHIP: [DMG] Endpoint = 0x0, [1651080101819] [2857:76478] CHIP: [DMG] Cluster = 0x30, [1651080101819] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0001, [1651080101819] [2857:76478] CHIP: [DMG] } [1651080101819] [2857:76478] CHIP: [DMG] [1651080101819] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080101819] [2857:76478] CHIP: [DMG] { [1651080101819] [2857:76478] CHIP: [DMG] Endpoint = 0x0, [1651080101819] [2857:76478] CHIP: [DMG] Cluster = 0x30, [1651080101819] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0002, [1651080101819] [2857:76478] CHIP: [DMG] } [1651080101819] [2857:76478] CHIP: [DMG] [1651080101819] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080101819] [2857:76478] CHIP: [DMG] { [1651080101819] [2857:76478] CHIP: [DMG] Endpoint = 0x0, [1651080101819] [2857:76478] CHIP: [DMG] Cluster = 0x30, [1651080101819] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0003, [1651080101819] [2857:76478] CHIP: [DMG] } [1651080101819] [2857:76478] CHIP: [DMG] [1651080101819] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080101819] [2857:76478] CHIP: [DMG] { [1651080101819] [2857:76478] CHIP: [DMG] Endpoint = 0x0, [1651080101819] [2857:76478] CHIP: [DMG] Cluster = 0x28, [1651080101819] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0002, [1651080101819] [2857:76478] CHIP: [DMG] } [1651080101819] [2857:76478] CHIP: [DMG] [1651080101819] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080101819] [2857:76478] CHIP: [DMG] { [1651080101819] [2857:76478] CHIP: [DMG] Endpoint = 0x0, [1651080101819] [2857:76478] CHIP: [DMG] Cluster = 0x28, [1651080101819] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0004, [1651080101819] [2857:76478] CHIP: [DMG] } [1651080101819] [2857:76478] CHIP: [DMG] [1651080101819] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080101819] [2857:76478] CHIP: [DMG] { [1651080101819] [2857:76478] CHIP: [DMG] Cluster = 0x31, [1651080101819] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0003, [1651080101819] [2857:76478] CHIP: [DMG] } [1651080101819] [2857:76478] CHIP: [DMG] [1651080101819] [2857:76478] CHIP: [DMG] ], [1651080101819] [2857:76478] CHIP: [DMG] [1651080101819] [2857:76478] CHIP: [DMG] isFabricFiltered = true, [1651080101819] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080101819] [2857:76478] CHIP: [DMG] }, [1651080101819] [2857:76478] CHIP: [DMG] IM RH moving to [GeneratingReports] [1651080101819] [2857:76478] CHIP: [DMG] Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 [1651080101819] [2857:76478] CHIP: [DMG] Cluster 31, Attribute 3 is dirty [1651080101819] [2857:76478] CHIP: [DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) [1651080101819] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=v [1651080101819] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101819] [2857:76478] CHIP: [DMG] Cluster 28, Attribute 4 is dirty [1651080101819] [2857:76478] CHIP: [DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) [1651080101819] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0028 e=0 p=v [1651080101819] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101819] [2857:76478] CHIP: [DMG] Cluster 28, Attribute 2 is dirty [1651080101819] [2857:76478] CHIP: [DMG] Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) [1651080101819] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0028 e=0 p=v [1651080101819] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101820] [2857:76478] CHIP: [DMG] Cluster 30, Attribute 3 is dirty [1651080101820] [2857:76478] CHIP: [DMG] Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101820] [2857:76478] CHIP: [DMG] Cluster 30, Attribute 2 is dirty [1651080101820] [2857:76478] CHIP: [DMG] Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101820] [2857:76478] CHIP: [DMG] Cluster 30, Attribute 1 is dirty [1651080101820] [2857:76478] CHIP: [DMG] Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101820] [2857:76478] CHIP: [DMG] Cluster 30, Attribute 0 is dirty [1651080101820] [2857:76478] CHIP: [DMG] Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0) [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101820] [2857:76478] CHIP: [DMG] Cluster 31, Attribute fffc is dirty [1651080101820] [2857:76478] CHIP: [DMG] Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=v [1651080101820] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101820] [2857:76478] CHIP: [DMG] Sending report (payload has 224 bytes)... [1651080101820] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:14615239 on exchange: 108r [1651080101820] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389e08 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 108r with MessageCounter:12016041. [1651080101820] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389e08 with MessageCounter:12016041 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000042ABB8 msec [1651080101820] [2857:76478] CHIP: [DMG] OnReportConfirm: NumReports = 0 [1651080101820] [2857:76478] CHIP: [DMG] ReportsInFlight = 0 with readHandler 0, RE has no more messages [1651080101820] [2857:76478] CHIP: [DMG] IM RH moving to [AwaitingDestruction] [1651080101820] [2857:76478] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1651080101820] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:3035076626 on exchange 107r [1651080101820] [2857:76478] CHIP: [EM] Found matching exchange: 107r, Delegate: 0x0 [1651080101820] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:2279333806 from Retrans Table on exchange 107r [1651080101820] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:2279333806 from RetransTable on exchange 107r [1651080101822] [2857:76478] CHIP: [EM] Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14615240 on exchange 109r [1651080101822] [2857:76478] CHIP: [EM] Handling via exchange: 109r, Delegate: 0x10f391a60 [1651080101822] [2857:76478] CHIP: [DMG] InvokeRequestMessage = [1651080101822] [2857:76478] CHIP: [DMG] { [1651080101822] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080101822] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080101822] [2857:76478] CHIP: [DMG] InvokeRequests = [1651080101822] [2857:76478] CHIP: [DMG] [ [1651080101822] [2857:76478] CHIP: [DMG] CommandDataIB = [1651080101822] [2857:76478] CHIP: [DMG] { [1651080101822] [2857:76478] CHIP: [DMG] CommandPathIB = [1651080101822] [2857:76478] CHIP: [DMG] { [1651080101822] [2857:76478] CHIP: [DMG] EndpointId = 0x0, [1651080101822] [2857:76478] CHIP: [DMG] ClusterId = 0x30, [1651080101822] [2857:76478] CHIP: [DMG] CommandId = 0x0, [1651080101822] [2857:76478] CHIP: [DMG] }, [1651080101822] [2857:76478] CHIP: [DMG] [1651080101822] [2857:76478] CHIP: [DMG] CommandData = [1651080101822] [2857:76478] CHIP: [DMG] { [1651080101822] [2857:76478] CHIP: [DMG] 0x0 = 60, [1651080101822] [2857:76478] CHIP: [DMG] 0x1 = 3, [1651080101822] [2857:76478] CHIP: [DMG] }, [1651080101822] [2857:76478] CHIP: [DMG] }, [1651080101822] [2857:76478] CHIP: [DMG] [1651080101822] [2857:76478] CHIP: [DMG] ], [1651080101822] [2857:76478] CHIP: [DMG] [1651080101822] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080101822] [2857:76478] CHIP: [DMG] }, [1651080101822] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1651080101822] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101822] [2857:76478] CHIP: [DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 [1651080101822] [2857:76478] CHIP: [DMG] ICR moving to [ Preparing] [1651080101822] [2857:76478] CHIP: [DMG] ICR moving to [AddingComm] [1651080101822] [2857:76478] CHIP: [DMG] ICR moving to [AddedComma] [1651080101823] [2857:76478] CHIP: [DMG] Decreasing reference count for CommandHandler, remaining 0 [1651080101823] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:14615240 on exchange: 109r [1651080101823] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389de8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 109r with MessageCounter:12016042. [1651080101823] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389de8 with MessageCounter:12016042 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000042ABBB msec [1651080101823] [2857:76478] CHIP: [DMG] ICR moving to [CommandSen] [1651080101823] [2857:76478] CHIP: [DMG] ICR moving to [AwaitingDe] [1651080101823] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14615241 on exchange 108r [1651080101823] [2857:76478] CHIP: [EM] Found matching exchange: 108r, Delegate: 0x0 [1651080101823] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:12016041 from Retrans Table on exchange 108r [1651080101823] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:12016041 from RetransTable on exchange 108r [1651080101823] [2857:76478] CHIP: [EM] Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14615242 on exchange 110r [1651080101823] [2857:76478] CHIP: [EM] Handling via exchange: 110r, Delegate: 0x10f391a60 [1651080101823] [2857:76478] CHIP: [DMG] InvokeRequestMessage = [1651080101823] [2857:76478] CHIP: [DMG] { [1651080101823] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080101823] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080101823] [2857:76478] CHIP: [DMG] InvokeRequests = [1651080101823] [2857:76478] CHIP: [DMG] [ [1651080101823] [2857:76478] CHIP: [DMG] CommandDataIB = [1651080101823] [2857:76478] CHIP: [DMG] { [1651080101823] [2857:76478] CHIP: [DMG] CommandPathIB = [1651080101823] [2857:76478] CHIP: [DMG] { [1651080101823] [2857:76478] CHIP: [DMG] EndpointId = 0x0, [1651080101823] [2857:76478] CHIP: [DMG] ClusterId = 0x30, [1651080101823] [2857:76478] CHIP: [DMG] CommandId = 0x2, [1651080101823] [2857:76478] CHIP: [DMG] }, [1651080101823] [2857:76478] CHIP: [DMG] [1651080101823] [2857:76478] CHIP: [DMG] CommandData = [1651080101823] [2857:76478] CHIP: [DMG] { [1651080101823] [2857:76478] CHIP: [DMG] 0x0 = 0, [1651080101823] [2857:76478] CHIP: [DMG] 0x1 = "XX", [1651080101823] [2857:76478] CHIP: [DMG] 0x2 = 4, [1651080101823] [2857:76478] CHIP: [DMG] }, [1651080101823] [2857:76478] CHIP: [DMG] }, [1651080101823] [2857:76478] CHIP: [DMG] [1651080101823] [2857:76478] CHIP: [DMG] ], [1651080101823] [2857:76478] CHIP: [DMG] [1651080101823] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080101823] [2857:76478] CHIP: [DMG] }, [1651080101823] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1651080101823] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101823] [2857:76478] CHIP: [DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 [1651080101824] [2857:76478] CHIP: [DMG] ICR moving to [ Preparing] [1651080101824] [2857:76478] CHIP: [DMG] ICR moving to [AddingComm] [1651080101824] [2857:76478] CHIP: [DMG] ICR moving to [AddedComma] [1651080101824] [2857:76478] CHIP: [DMG] Decreasing reference count for CommandHandler, remaining 0 [1651080101824] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:14615242 on exchange: 110r [1651080101824] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389e08 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 110r with MessageCounter:12016043. [1651080101824] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389e08 with MessageCounter:12016043 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000042ABBC msec [1651080101825] [2857:76478] CHIP: [DMG] ICR moving to [CommandSen] [1651080101825] [2857:76478] CHIP: [DMG] ICR moving to [AwaitingDe] [1651080101825] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14615243 on exchange 109r [1651080101825] [2857:76478] CHIP: [EM] Found matching exchange: 109r, Delegate: 0x0 [1651080101825] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:12016042 from Retrans Table on exchange 109r [1651080101825] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:12016042 from RetransTable on exchange 109r [1651080101825] [2857:76478] CHIP: [EM] Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14615244 on exchange 111r [1651080101825] [2857:76478] CHIP: [EM] Handling via exchange: 111r, Delegate: 0x10f391a60 [1651080101825] [2857:76478] CHIP: [DMG] InvokeRequestMessage = [1651080101825] [2857:76478] CHIP: [DMG] { [1651080101825] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080101825] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080101825] [2857:76478] CHIP: [DMG] InvokeRequests = [1651080101825] [2857:76478] CHIP: [DMG] [ [1651080101825] [2857:76478] CHIP: [DMG] CommandDataIB = [1651080101825] [2857:76478] CHIP: [DMG] { [1651080101825] [2857:76478] CHIP: [DMG] CommandPathIB = [1651080101825] [2857:76478] CHIP: [DMG] { [1651080101825] [2857:76478] CHIP: [DMG] EndpointId = 0x0, [1651080101825] [2857:76478] CHIP: [DMG] ClusterId = 0x3e, [1651080101825] [2857:76478] CHIP: [DMG] CommandId = 0x2, [1651080101825] [2857:76478] CHIP: [DMG] }, [1651080101825] [2857:76478] CHIP: [DMG] [1651080101825] [2857:76478] CHIP: [DMG] CommandData = [1651080101825] [2857:76478] CHIP: [DMG] { [1651080101825] [2857:76478] CHIP: [DMG] 0x0 = 2, [1651080101825] [2857:76478] CHIP: [DMG] }, [1651080101825] [2857:76478] CHIP: [DMG] }, [1651080101825] [2857:76478] CHIP: [DMG] [1651080101825] [2857:76478] CHIP: [DMG] ], [1651080101825] [2857:76478] CHIP: [DMG] [1651080101825] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080101825] [2857:76478] CHIP: [DMG] }, [1651080101825] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1651080101825] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101825] [2857:76478] CHIP: [DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 [1651080101825] [2857:76478] CHIP: [ZCL] OpCreds: Certificate Chain request received for PAI [1651080101825] [2857:76478] CHIP: [DMG] ICR moving to [ Preparing] [1651080101825] [2857:76478] CHIP: [DMG] ICR moving to [AddingComm] [1651080101825] [2857:76478] CHIP: [DMG] ICR moving to [AddedComma] [1651080101825] [2857:76478] CHIP: [DMG] Decreasing reference count for CommandHandler, remaining 0 [1651080101825] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:14615244 on exchange: 111r [1651080101825] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389de8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 111r with MessageCounter:12016044. [1651080101825] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389de8 with MessageCounter:12016044 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000042ABBD msec [1651080101825] [2857:76478] CHIP: [DMG] ICR moving to [CommandSen] [1651080101825] [2857:76478] CHIP: [DMG] ICR moving to [AwaitingDe] [1651080101825] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14615245 on exchange 110r [1651080101825] [2857:76478] CHIP: [EM] Found matching exchange: 110r, Delegate: 0x0 [1651080101825] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:12016043 from Retrans Table on exchange 110r [1651080101825] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:12016043 from RetransTable on exchange 110r [1651080101826] [2857:76478] CHIP: [EM] Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14615246 on exchange 112r [1651080101826] [2857:76478] CHIP: [EM] Handling via exchange: 112r, Delegate: 0x10f391a60 [1651080101826] [2857:76478] CHIP: [DMG] InvokeRequestMessage = [1651080101826] [2857:76478] CHIP: [DMG] { [1651080101826] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080101826] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080101826] [2857:76478] CHIP: [DMG] InvokeRequests = [1651080101826] [2857:76478] CHIP: [DMG] [ [1651080101826] [2857:76478] CHIP: [DMG] CommandDataIB = [1651080101826] [2857:76478] CHIP: [DMG] { [1651080101826] [2857:76478] CHIP: [DMG] CommandPathIB = [1651080101826] [2857:76478] CHIP: [DMG] { [1651080101826] [2857:76478] CHIP: [DMG] EndpointId = 0x0, [1651080101826] [2857:76478] CHIP: [DMG] ClusterId = 0x3e, [1651080101826] [2857:76478] CHIP: [DMG] CommandId = 0x2, [1651080101826] [2857:76478] CHIP: [DMG] }, [1651080101826] [2857:76478] CHIP: [DMG] [1651080101826] [2857:76478] CHIP: [DMG] CommandData = [1651080101826] [2857:76478] CHIP: [DMG] { [1651080101826] [2857:76478] CHIP: [DMG] 0x0 = 1, [1651080101826] [2857:76478] CHIP: [DMG] }, [1651080101826] [2857:76478] CHIP: [DMG] }, [1651080101826] [2857:76478] CHIP: [DMG] [1651080101826] [2857:76478] CHIP: [DMG] ], [1651080101826] [2857:76478] CHIP: [DMG] [1651080101826] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080101826] [2857:76478] CHIP: [DMG] }, [1651080101826] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1651080101826] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101826] [2857:76478] CHIP: [DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 [1651080101826] [2857:76478] CHIP: [ZCL] OpCreds: Certificate Chain request received for DAC [1651080101826] [2857:76478] CHIP: [DMG] ICR moving to [ Preparing] [1651080101826] [2857:76478] CHIP: [DMG] ICR moving to [AddingComm] [1651080101826] [2857:76478] CHIP: [DMG] ICR moving to [AddedComma] [1651080101826] [2857:76478] CHIP: [DMG] Decreasing reference count for CommandHandler, remaining 0 [1651080101826] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:14615246 on exchange: 112r [1651080101826] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389e08 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 112r with MessageCounter:12016045. [1651080101826] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389e08 with MessageCounter:12016045 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000042ABBE msec [1651080101826] [2857:76478] CHIP: [DMG] ICR moving to [CommandSen] [1651080101826] [2857:76478] CHIP: [DMG] ICR moving to [AwaitingDe] [1651080101826] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14615247 on exchange 111r [1651080101826] [2857:76478] CHIP: [EM] Found matching exchange: 111r, Delegate: 0x0 [1651080101826] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:12016044 from Retrans Table on exchange 111r [1651080101826] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:12016044 from RetransTable on exchange 111r [1651080101826] [2857:76478] CHIP: [EM] Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14615248 on exchange 113r [1651080101826] [2857:76478] CHIP: [EM] Handling via exchange: 113r, Delegate: 0x10f391a60 [1651080101826] [2857:76478] CHIP: [DMG] InvokeRequestMessage = [1651080101826] [2857:76478] CHIP: [DMG] { [1651080101826] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080101826] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080101826] [2857:76478] CHIP: [DMG] InvokeRequests = [1651080101826] [2857:76478] CHIP: [DMG] [ [1651080101826] [2857:76478] CHIP: [DMG] CommandDataIB = [1651080101826] [2857:76478] CHIP: [DMG] { [1651080101826] [2857:76478] CHIP: [DMG] CommandPathIB = [1651080101826] [2857:76478] CHIP: [DMG] { [1651080101826] [2857:76478] CHIP: [DMG] EndpointId = 0x0, [1651080101826] [2857:76478] CHIP: [DMG] ClusterId = 0x3e, [1651080101826] [2857:76478] CHIP: [DMG] CommandId = 0x0, [1651080101826] [2857:76478] CHIP: [DMG] }, [1651080101826] [2857:76478] CHIP: [DMG] [1651080101826] [2857:76478] CHIP: [DMG] CommandData = [1651080101826] [2857:76478] CHIP: [DMG] { [1651080101826] [2857:76478] CHIP: [DMG] 0x0 = [ [1651080101826] [2857:76478] CHIP: [DMG] 0x85, 0xed, 0xa5, 0x69, 0x14, 0x96, 0x13, 0x8b, 0xba, 0x32, 0x46, 0x6e, 0x6c, 0x6d, 0x39, 0x44, 0x29, 0x9f, 0x8c, 0xe1, 0x97, 0x90, 0xd6, 0x1b, 0xb4, 0xe5, 0xfb, 0xc7, 0xf3, 0xe6, 0x9, 0x97, [1651080101826] [2857:76478] CHIP: [DMG] ] [1651080101826] [2857:76478] CHIP: [DMG] }, [1651080101826] [2857:76478] CHIP: [DMG] }, [1651080101826] [2857:76478] CHIP: [DMG] [1651080101826] [2857:76478] CHIP: [DMG] ], [1651080101826] [2857:76478] CHIP: [DMG] [1651080101826] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080101826] [2857:76478] CHIP: [DMG] }, [1651080101826] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1651080101826] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101826] [2857:76478] CHIP: [DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 [1651080101827] [2857:76478] CHIP: [ZCL] OpCreds: received an AttestationRequest [1651080101827] [2857:76478] CHIP: [DMG] ICR moving to [ Preparing] [1651080101827] [2857:76478] CHIP: [DMG] ICR moving to [AddingComm] [1651080101827] [2857:76478] CHIP: [DMG] ICR moving to [AddedComma] [1651080101827] [2857:76478] CHIP: [DMG] Decreasing reference count for CommandHandler, remaining 0 [1651080101827] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:14615248 on exchange: 113r [1651080101827] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389de8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 113r with MessageCounter:12016046. [1651080101827] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389de8 with MessageCounter:12016046 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000042ABBF msec [1651080101827] [2857:76478] CHIP: [DMG] ICR moving to [CommandSen] [1651080101827] [2857:76478] CHIP: [DMG] ICR moving to [AwaitingDe] [1651080101827] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14615249 on exchange 112r [1651080101827] [2857:76478] CHIP: [EM] Found matching exchange: 112r, Delegate: 0x0 [1651080101827] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:12016045 from Retrans Table on exchange 112r [1651080101827] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:12016045 from RetransTable on exchange 112r [1651080101841] [2857:76478] CHIP: [EM] Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14615250 on exchange 114r [1651080101841] [2857:76478] CHIP: [EM] Handling via exchange: 114r, Delegate: 0x10f391a60 [1651080101841] [2857:76478] CHIP: [DMG] InvokeRequestMessage = [1651080101841] [2857:76478] CHIP: [DMG] { [1651080101841] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080101841] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080101841] [2857:76478] CHIP: [DMG] InvokeRequests = [1651080101841] [2857:76478] CHIP: [DMG] [ [1651080101841] [2857:76478] CHIP: [DMG] CommandDataIB = [1651080101841] [2857:76478] CHIP: [DMG] { [1651080101841] [2857:76478] CHIP: [DMG] CommandPathIB = [1651080101841] [2857:76478] CHIP: [DMG] { [1651080101841] [2857:76478] CHIP: [DMG] EndpointId = 0x0, [1651080101841] [2857:76478] CHIP: [DMG] ClusterId = 0x3e, [1651080101841] [2857:76478] CHIP: [DMG] CommandId = 0x4, [1651080101841] [2857:76478] CHIP: [DMG] }, [1651080101841] [2857:76478] CHIP: [DMG] [1651080101841] [2857:76478] CHIP: [DMG] CommandData = [1651080101841] [2857:76478] CHIP: [DMG] { [1651080101841] [2857:76478] CHIP: [DMG] 0x0 = [ [1651080101841] [2857:76478] CHIP: [DMG] 0xdd, 0x1c, 0x82, 0x2d, 0xb1, 0xf4, 0x85, 0x48, 0x6f, 0x17, 0x48, 0xca, 0x61, 0x77, 0xae, 0x4c, 0xf4, 0xfe, 0x7a, 0xac, 0xe, 0x4c, 0x39, 0x1e, 0x4a, 0xce, 0x31, 0x60, 0x60, 0xca, 0x4e, 0x93, [1651080101841] [2857:76478] CHIP: [DMG] ] [1651080101841] [2857:76478] CHIP: [DMG] }, [1651080101841] [2857:76478] CHIP: [DMG] }, [1651080101841] [2857:76478] CHIP: [DMG] [1651080101841] [2857:76478] CHIP: [DMG] ], [1651080101841] [2857:76478] CHIP: [DMG] [1651080101841] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080101841] [2857:76478] CHIP: [DMG] }, [1651080101841] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1651080101841] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101841] [2857:76478] CHIP: [DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 [1651080101841] [2857:76478] CHIP: [ZCL] OpCreds: commissioner has requested a CSR [1651080101842] [2857:76478] CHIP: [ZCL] OpCreds: NewCertificateSigningRequest returned ../../../examples/ota-provider-app/linux/third_party/connectedhomeip/src/crypto/CHIPCryptoPALOpenSSL.cpp:1114: Success [1651080101842] [2857:76478] CHIP: [DMG] ICR moving to [ Preparing] [1651080101842] [2857:76478] CHIP: [DMG] ICR moving to [AddingComm] [1651080101842] [2857:76478] CHIP: [DMG] ICR moving to [AddedComma] [1651080101842] [2857:76478] CHIP: [DMG] Decreasing reference count for CommandHandler, remaining 0 [1651080101842] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:14615250 on exchange: 114r [1651080101842] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389e08 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 114r with MessageCounter:12016047. [1651080101842] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389e08 with MessageCounter:12016047 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000042ABCE msec [1651080101842] [2857:76478] CHIP: [DMG] ICR moving to [CommandSen] [1651080101842] [2857:76478] CHIP: [DMG] ICR moving to [AwaitingDe] [1651080101843] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14615251 on exchange 113r [1651080101843] [2857:76478] CHIP: [EM] Found matching exchange: 113r, Delegate: 0x0 [1651080101843] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:12016046 from Retrans Table on exchange 113r [1651080101843] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:12016046 from RetransTable on exchange 113r [1651080101846] [2857:76478] CHIP: [EM] Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14615252 on exchange 115r [1651080101846] [2857:76478] CHIP: [EM] Handling via exchange: 115r, Delegate: 0x10f391a60 [1651080101846] [2857:76478] CHIP: [DMG] InvokeRequestMessage = [1651080101846] [2857:76478] CHIP: [DMG] { [1651080101846] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080101846] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080101846] [2857:76478] CHIP: [DMG] InvokeRequests = [1651080101846] [2857:76478] CHIP: [DMG] [ [1651080101846] [2857:76478] CHIP: [DMG] CommandDataIB = [1651080101846] [2857:76478] CHIP: [DMG] { [1651080101846] [2857:76478] CHIP: [DMG] CommandPathIB = [1651080101846] [2857:76478] CHIP: [DMG] { [1651080101846] [2857:76478] CHIP: [DMG] EndpointId = 0x0, [1651080101846] [2857:76478] CHIP: [DMG] ClusterId = 0x3e, [1651080101846] [2857:76478] CHIP: [DMG] CommandId = 0xb, [1651080101846] [2857:76478] CHIP: [DMG] }, [1651080101846] [2857:76478] CHIP: [DMG] [1651080101846] [2857:76478] CHIP: [DMG] CommandData = [1651080101846] [2857:76478] CHIP: [DMG] { [1651080101846] [2857:76478] CHIP: [DMG] 0x0 = [ [1651080101846] [2857:76478] CHIP: [DMG] 0x15, 0x30, 0x1, 0x1, 0x0, 0x24, 0x2, 0x1, 0x37, 0x3, 0x24, 0x14, 0x0, 0x18, 0x26, 0x4, 0x80, 0x22, 0x81, 0x27, 0x26, 0x5, 0x80, 0x25, 0x4d, 0x3a, 0x37, 0x6, 0x24, 0x14, 0x0, 0x18, 0x24, 0x7, 0x1, 0x24, 0x8, 0 [1651080101846] [2857:76478] CHIP: [DMG] ] [1651080101846] [2857:76478] CHIP: [DMG] }, [1651080101847] [2857:76478] CHIP: [DMG] }, [1651080101847] [2857:76478] CHIP: [DMG] [1651080101847] [2857:76478] CHIP: [DMG] ], [1651080101847] [2857:76478] CHIP: [DMG] [1651080101847] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080101847] [2857:76478] CHIP: [DMG] }, [1651080101847] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1651080101847] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101847] [2857:76478] CHIP: [DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B [1651080101847] [2857:76478] CHIP: [ZCL] OpCreds: commissioner has added a trusted root Cert [1651080101847] [2857:76478] CHIP: [DMG] ICR moving to [ Preparing] [1651080101847] [2857:76478] CHIP: [DMG] ICR moving to [AddingComm] [1651080101847] [2857:76478] CHIP: [DMG] ICR moving to [AddedComma] [1651080101847] [2857:76478] CHIP: [DMG] Endpoint 0, Cluster 0x0000_003E update version to 4afbe424 [1651080101847] [2857:76478] CHIP: [DMG] Decreasing reference count for CommandHandler, remaining 0 [1651080101847] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:14615252 on exchange: 115r [1651080101847] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389de8 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 115r with MessageCounter:12016048. [1651080101847] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389de8 with MessageCounter:12016048 to 0xFFFFFFFB00000000 (0) at monotonic time: 000000000042ABD3 msec [1651080101847] [2857:76478] CHIP: [DMG] ICR moving to [CommandSen] [1651080101847] [2857:76478] CHIP: [DMG] ICR moving to [AwaitingDe] [1651080101847] [2857:76478] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1651080101847] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14615253 on exchange 114r [1651080101847] [2857:76478] CHIP: [EM] Found matching exchange: 114r, Delegate: 0x0 [1651080101847] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:12016047 from Retrans Table on exchange 114r [1651080101847] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:12016047 from RetransTable on exchange 114r [1651080101848] [2857:76478] CHIP: [EM] Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14615254 on exchange 116r [1651080101848] [2857:76478] CHIP: [EM] Handling via exchange: 116r, Delegate: 0x10f391a60 [1651080101848] [2857:76478] CHIP: [DMG] InvokeRequestMessage = [1651080101848] [2857:76478] CHIP: [DMG] { [1651080101848] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080101848] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080101848] [2857:76478] CHIP: [DMG] InvokeRequests = [1651080101848] [2857:76478] CHIP: [DMG] [ [1651080101848] [2857:76478] CHIP: [DMG] CommandDataIB = [1651080101848] [2857:76478] CHIP: [DMG] { [1651080101848] [2857:76478] CHIP: [DMG] CommandPathIB = [1651080101848] [2857:76478] CHIP: [DMG] { [1651080101848] [2857:76478] CHIP: [DMG] EndpointId = 0x0, [1651080101848] [2857:76478] CHIP: [DMG] ClusterId = 0x3e, [1651080101848] [2857:76478] CHIP: [DMG] CommandId = 0x6, [1651080101848] [2857:76478] CHIP: [DMG] }, [1651080101848] [2857:76478] CHIP: [DMG] [1651080101848] [2857:76478] CHIP: [DMG] CommandData = [1651080101848] [2857:76478] CHIP: [DMG] { [1651080101848] [2857:76478] CHIP: [DMG] 0x0 = [ [1651080101848] [2857:76478] CHIP: [DMG] 0x15, 0x30, 0x1, 0x1, 0x1, 0x24, 0x2, 0x1, 0x37, 0x3, 0x24, 0x13, 0x1, 0x18, 0x26, 0x4, 0x80, 0x22, 0x81, 0x27, 0x26, 0x5, 0x80, 0x25, 0x4d, 0x3a, 0x37, 0x6, 0x24, 0x15, 0x1, 0x25, 0x11, 0xcd, 0xab, 0x18, 0x24 [1651080101848] [2857:76478] CHIP: [DMG] ] [1651080101848] [2857:76478] CHIP: [DMG] 0x1 = [ [1651080101848] [2857:76478] CHIP: [DMG] 0x15, 0x30, 0x1, 0x1, 0x0, 0x24, 0x2, 0x1, 0x37, 0x3, 0x24, 0x14, 0x0, 0x18, 0x26, 0x4, 0x80, 0x22, 0x81, 0x27, 0x26, 0x5, 0x80, 0x25, 0x4d, 0x3a, 0x37, 0x6, 0x24, 0x13, 0x1, 0x18, 0x24, 0x7, 0x1, 0x24, 0x8, 0 [1651080101848] [2857:76478] CHIP: [DMG] ] [1651080101848] [2857:76478] CHIP: [DMG] 0x2 = [ [1651080101848] [2857:76478] CHIP: [DMG] 0x74, 0x65, 0x6d, 0x70, 0x6f, 0x72, 0x61, 0x72, 0x79, 0x20, 0x69, 0x70, 0x6b, 0x20, 0x30, 0x31, [1651080101848] [2857:76478] CHIP: [DMG] ] [1651080101848] [2857:76478] CHIP: [DMG] 0x3 = 112233, [1651080101848] [2857:76478] CHIP: [DMG] 0x4 = 65521, [1651080101848] [2857:76478] CHIP: [DMG] }, [1651080101848] [2857:76478] CHIP: [DMG] }, [1651080101848] [2857:76478] CHIP: [DMG] [1651080101848] [2857:76478] CHIP: [DMG] ], [1651080101848] [2857:76478] CHIP: [DMG] [1651080101848] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080101848] [2857:76478] CHIP: [DMG] }, [1651080101848] [2857:76478] CHIP: [DMG] AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1651080101848] [2857:76478] CHIP: [DMG] AccessControl: implicit admin (PASE) [1651080101848] [2857:76478] CHIP: [DMG] Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 [1651080101848] [2857:76478] CHIP: [ZCL] OpCreds: Received AddNOC command [1651080101848] [2857:76478] CHIP: [DIS] Verifying the received credentials [1651080101849] [2857:76478] CHIP: [DIS] Added new fabric at index: 0x1, Initialized: 1 [1651080101849] [2857:76478] CHIP: [DIS] Assigned compressed fabric ID: 0x6BB45AAF83E2B276, node ID: 0x000000000000ABCD [1651080101850] [2857:76478] CHIP: [DIS] Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage [1651080101850] [2857:76478] CHIP: [ZCL] OpCreds: Fabric index 0x1 was persisted to storage. FabricId 0000000000000001, NodeId 000000000000ABCD, VendorId 0xFFF1 [1651080101850] [2857:76478] CHIP: [ZCL] OpCreds: Call to fabricListChanged [1651080101850] [2857:76478] CHIP: [DMG] Endpoint 0, Cluster 0x0000_003E update version to 4afbe425 [1651080101850] [2857:76478] CHIP: [DMG] Endpoint 0, Cluster 0x0000_003E update version to 4afbe426 [1651080101851] [2857:76478] CHIP: [DMG] AccessControl: validating f=1 p=a a=c s=1 t=0 [1651080101851] [2857:76478] CHIP: [DMG] validating subject 0x000000000001B669 [1651080101869] [2857:76478] CHIP: [ZCL] OpCreds: ACL entry created for Fabric 1 CASE Admin NodeId 0x000000000001B669 [1651080101871] [2857:76478] CHIP: [DL] Using wifi MAC for hostname [1651080101871] [2857:76478] CHIP: [DIS] Advertise operational node 6BB45AAF83E2B276-000000000000ABCD [1651080101871] [2857:76478] CHIP: [DL] Publishing service 6BB45AAF83E2B276-000000000000ABCD on port 5540 with type: _matter._tcp,_I6BB45AAF83E2B276 on interface id: 0 [1651080101871] [2857:76478] CHIP: [DMG] ICR moving to [ Preparing] [1651080101871] [2857:76478] CHIP: [DMG] ICR moving to [AddingComm] [1651080101871] [2857:76478] CHIP: [DMG] ICR moving to [AddedComma] [1651080101871] [2857:76478] CHIP: [ZCL] OpCreds: successfully created fabric index 1 via AddNOC [1651080101871] [2857:76478] CHIP: [DMG] Decreasing reference count for CommandHandler, remaining 0 [1651080101871] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:14615254 on exchange: 116r [1651080101871] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389e08 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 116r with MessageCounter:12016049. [1651080101871] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389e08 with MessageCounter:12016049 to 0xFFFFFFFB00000000 (1) at monotonic time: 000000000042ABEB msec [1651080101871] [2857:76478] CHIP: [DMG] ICR moving to [CommandSen] [1651080101871] [2857:76478] CHIP: [DMG] ICR moving to [AwaitingDe] [1651080101871] [2857:76478] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1651080101871] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14615255 on exchange 115r [1651080101871] [2857:76478] CHIP: [EM] Found matching exchange: 115r, Delegate: 0x0 [1651080101871] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:12016048 from Retrans Table on exchange 115r [1651080101871] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:12016048 from RetransTable on exchange 115r [1651080101872] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14615256 on exchange 116r [1651080101872] [2857:76478] CHIP: [EM] Found matching exchange: 116r, Delegate: 0x0 [1651080101872] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:12016049 from Retrans Table on exchange 116r [1651080101872] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:12016049 from RetransTable on exchange 116r [1651080102578] [2857:76478] CHIP: [DL] Mdns: OnRegister name: 6BB45AAF83E2B276-000000000000ABCD, type: _matter._tcp., domain: local., flags: 2 [1651080102578] [2857:76478] CHIP: [DIS] mDNS service published: _matter. [1651080102832] [2857:76478] CHIP: [EM] Received message of type 0x30 with protocolId (0, 0) and MessageCounter:3035076627 on exchange 117r [1651080102832] [2857:76478] CHIP: [EM] Handling via exchange: 117r, Delegate: 0x10f389808 [1651080102832] [2857:76478] CHIP: [IN] CASE Server received Sigma1 message. Starting handshake. EC 0x10f38b0f0 [1651080102832] [2857:76478] CHIP: [SC] Waiting for Sigma1 msg [1651080102832] [2857:76478] CHIP: [IN] CASE Server disabling CASE session setups [1651080102833] [2857:76478] CHIP: [SC] Received Sigma1 msg [1651080102833] [2857:76478] CHIP: [SC] Found MRP parameters in the message [1651080102833] [2857:76478] CHIP: [SC] Peer assigned session key ID 15675 [1651080102833] [2857:76478] CHIP: [SC] CASE matched destination ID: fabricIndex 1, NodeID 0x000000000000ABCD [1651080102834] [2857:76478] CHIP: [SC] Including MRP parameters [1651080102834] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:3035076627 on exchange: 117r [1651080102834] [2857:76478] CHIP: [IN] Prepared unauthenticated message 0x10f389de8 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 117r with MessageCounter:2279333807. [1651080102834] [2857:76478] CHIP: [IN] Sending unauthenticated msg 0x10f389de8 with MessageCounter:2279333807 to 0x0000000000000000 at monotonic time: 000000000042AFAE msec [1651080102834] [2857:76478] CHIP: [SC] Sent Sigma2 msg [1651080102836] [2857:76478] CHIP: [EM] Received message of type 0x32 with protocolId (0, 0) and MessageCounter:3035076628 on exchange 117r [1651080102836] [2857:76478] CHIP: [EM] Found matching exchange: 117r, Delegate: 0x10f389828 [1651080102836] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:2279333807 from Retrans Table on exchange 117r [1651080102836] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:2279333807 from RetransTable on exchange 117r [1651080102836] [2857:76478] CHIP: [SC] Received Sigma3 msg [1651080102838] [2857:76478] CHIP: [SC] Sending status report. Protocol code 0, exchange 117 [1651080102838] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:3035076628 on exchange: 117r [1651080102838] [2857:76478] CHIP: [IN] Prepared unauthenticated message 0x10f389de8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 117r with MessageCounter:2279333808. [1651080102838] [2857:76478] CHIP: [IN] Sending unauthenticated msg 0x10f389de8 with MessageCounter:2279333808 to 0x0000000000000000 at monotonic time: 000000000042AFB2 msec [1651080102838] [2857:76478] CHIP: [IN] New secure session created for device <000000000001B669, 1>, LSID:57614 PSID:15675! [1651080102838] [2857:76478] CHIP: [IN] CASE Session established to peer: <000000000001B669, 1> [1651080102838] [2857:76478] CHIP: [IN] CASE Server enabling CASE session setups [1651080102838] [2857:76478] CHIP: [EM] Received message of type 0x8 with protocolId (0, 1) and MessageCounter:4737134 on exchange 118r [1651080102839] [2857:76478] CHIP: [EM] Handling via exchange: 118r, Delegate: 0x10f391a60 [1651080102839] [2857:76478] CHIP: [DMG] InvokeRequestMessage = [1651080102839] [2857:76478] CHIP: [DMG] { [1651080102839] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080102839] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080102839] [2857:76478] CHIP: [DMG] InvokeRequests = [1651080102839] [2857:76478] CHIP: [DMG] [ [1651080102839] [2857:76478] CHIP: [DMG] CommandDataIB = [1651080102839] [2857:76478] CHIP: [DMG] { [1651080102839] [2857:76478] CHIP: [DMG] CommandPathIB = [1651080102839] [2857:76478] CHIP: [DMG] { [1651080102839] [2857:76478] CHIP: [DMG] EndpointId = 0x0, [1651080102839] [2857:76478] CHIP: [DMG] ClusterId = 0x30, [1651080102839] [2857:76478] CHIP: [DMG] CommandId = 0x4, [1651080102839] [2857:76478] CHIP: [DMG] }, [1651080102839] [2857:76478] CHIP: [DMG] [1651080102839] [2857:76478] CHIP: [DMG] CommandData = [1651080102839] [2857:76478] CHIP: [DMG] { [1651080102839] [2857:76478] CHIP: [DMG] }, [1651080102839] [2857:76478] CHIP: [DMG] }, [1651080102839] [2857:76478] CHIP: [DMG] [1651080102839] [2857:76478] CHIP: [DMG] ], [1651080102839] [2857:76478] CHIP: [DMG] [1651080102839] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080102839] [2857:76478] CHIP: [DMG] }, [1651080102839] [2857:76478] CHIP: [DMG] AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0030 e=0 p=a [1651080102839] [2857:76478] CHIP: [DMG] AccessControl: allowed [1651080102839] [2857:76478] CHIP: [DMG] Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 [1651080102840] [2857:76478] CHIP: [DMG] ICR moving to [ Preparing] [1651080102840] [2857:76478] CHIP: [DMG] ICR moving to [AddingComm] [1651080102840] [2857:76478] CHIP: [DMG] ICR moving to [AddedComma] [1651080102840] [2857:76478] CHIP: [DMG] Decreasing reference count for CommandHandler, remaining 0 [1651080102840] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:4737134 on exchange: 118r [1651080102840] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389e08 to 0x000000000001B669 (1) of type 0x9 and protocolId (0, 1) on exchange 118r with MessageCounter:6439054. [1651080102840] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389e08 with MessageCounter:6439054 to 0x000000000001B669 (1) at monotonic time: 000000000042AFB4 msec [1651080102840] [2857:76478] CHIP: [DMG] ICR moving to [CommandSen] [1651080102840] [2857:76478] CHIP: [DMG] ICR moving to [AwaitingDe] [1651080102840] [2857:76478] CHIP: [SVR] Commissioning completed successfully [1651080102840] [2857:76478] CHIP: [DIS] Updating services using commissioning mode 0 [1651080102840] [2857:76478] CHIP: [DL] Using wifi MAC for hostname [1651080102840] [2857:76478] CHIP: [DIS] Advertise operational node 6BB45AAF83E2B276-000000000000ABCD [1651080102840] [2857:76478] CHIP: [DL] Publishing service 6BB45AAF83E2B276-000000000000ABCD on port 5540 with type: _matter._tcp,_I6BB45AAF83E2B276 on interface id: 0 [1651080102840] [2857:76478] CHIP: [IN] Expiring all PASE pairings [1651080102841] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:3035076629 on exchange 117r [1651080102841] [2857:76478] CHIP: [EM] Found matching exchange: 117r, Delegate: 0x0 [1651080102841] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:2279333808 from Retrans Table on exchange 117r [1651080102841] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:2279333808 from RetransTable on exchange 117r [1651080102841] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:4737135 on exchange 118r [1651080102841] [2857:76478] CHIP: [EM] Found matching exchange: 118r, Delegate: 0x0 [1651080102841] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:6439054 from Retrans Table on exchange 118r [1651080102841] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:6439054 from RetransTable on exchange 118r [1651080103481] [2857:76478] CHIP: [DL] Mdns: OnRegister name: 6BB45AAF83E2B276-000000000000ABCD, type: _matter._tcp., domain: local., flags: 2 [1651080103481] [2857:76478] CHIP: [DIS] mDNS service published: _matter. [1651080132017] [2857:76478] CHIP: [EM] Received message of type 0x30 with protocolId (0, 0) and MessageCounter:2210334992 on exchange 15862r [1651080132017] [2857:76478] CHIP: [EM] Handling via exchange: 15862r, Delegate: 0x10f389808 [1651080132017] [2857:76478] CHIP: [IN] CASE Server received Sigma1 message. Starting handshake. EC 0x10f38b0f0 [1651080132017] [2857:76478] CHIP: [SC] Waiting for Sigma1 msg [1651080132017] [2857:76478] CHIP: [IN] CASE Server disabling CASE session setups [1651080132017] [2857:76478] CHIP: [SC] Received Sigma1 msg [1651080132017] [2857:76478] CHIP: [SC] Found MRP parameters in the message [1651080132017] [2857:76478] CHIP: [SC] Peer assigned session key ID 20105 [1651080132018] [2857:76478] CHIP: [SC] CASE matched destination ID: fabricIndex 1, NodeID 0x000000000000ABCD [1651080132018] [2857:76478] CHIP: [SC] Including MRP parameters [1651080132018] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:2210334992 on exchange: 15862r [1651080132019] [2857:76478] CHIP: [IN] Prepared unauthenticated message 0x10f389de8 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 15862r with MessageCounter:2279333809. [1651080132019] [2857:76478] CHIP: [IN] Sending unauthenticated msg 0x10f389de8 with MessageCounter:2279333809 to 0x0000000000000000 at monotonic time: 00000000004321AE msec [1651080132019] [2857:76478] CHIP: [SC] Sent Sigma2 msg [1651080132020] [2857:76478] CHIP: [EM] Received message of type 0x32 with protocolId (0, 0) and MessageCounter:2210334993 on exchange 15862r [1651080132020] [2857:76478] CHIP: [EM] Found matching exchange: 15862r, Delegate: 0x10f389828 [1651080132020] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:2279333809 from Retrans Table on exchange 15862r [1651080132020] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:2279333809 from RetransTable on exchange 15862r [1651080132021] [2857:76478] CHIP: [SC] Received Sigma3 msg [1651080132023] [2857:76478] CHIP: [SC] Sending status report. Protocol code 0, exchange 15862 [1651080132023] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:2210334993 on exchange: 15862r [1651080132023] [2857:76478] CHIP: [IN] Prepared unauthenticated message 0x10f389de8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 15862r with MessageCounter:2279333810. [1651080132023] [2857:76478] CHIP: [IN] Sending unauthenticated msg 0x10f389de8 with MessageCounter:2279333810 to 0x0000000000000000 at monotonic time: 00000000004321B3 msec [1651080132023] [2857:76478] CHIP: [IN] New secure session created for device <000000000001B669, 1>, LSID:57615 PSID:20105! [1651080132023] [2857:76478] CHIP: [IN] CASE Session established to peer: <000000000001B669, 1> [1651080132023] [2857:76478] CHIP: [IN] CASE Server enabling CASE session setups [1651080132024] [2857:76478] CHIP: [EM] Received message of type 0x6 with protocolId (0, 1) and MessageCounter:7260433 on exchange 15863r [1651080132024] [2857:76478] CHIP: [EM] Handling via exchange: 15863r, Delegate: 0x10f391a60 [1651080132024] [2857:76478] CHIP: [IM] Received Write request [1651080132024] [2857:76478] CHIP: [DMG] IM WH moving to [Initialized] [1651080132024] [2857:76478] CHIP: [DMG] WriteRequestMessage = [1651080132024] [2857:76478] CHIP: [DMG] { [1651080132024] [2857:76478] CHIP: [DMG] suppressResponse = false, [1651080132024] [2857:76478] CHIP: [DMG] timedRequest = false, [1651080132024] [2857:76478] CHIP: [DMG] AttributeDataIBs = [1651080132024] [2857:76478] CHIP: [DMG] [ [1651080132024] [2857:76478] CHIP: [DMG] AttributeDataIB = [1651080132024] [2857:76478] CHIP: [DMG] { [1651080132024] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080132024] [2857:76478] CHIP: [DMG] { [1651080132024] [2857:76478] CHIP: [DMG] Endpoint = 0x0, [1651080132024] [2857:76478] CHIP: [DMG] Cluster = 0x1f, [1651080132024] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0000, [1651080132024] [2857:76478] CHIP: [DMG] } [1651080132024] [2857:76478] CHIP: [DMG] [1651080132024] [2857:76478] CHIP: [DMG] Data = [ [1651080132024] [2857:76478] CHIP: [DMG] [1651080132024] [2857:76478] CHIP: [DMG] ], [1651080132024] [2857:76478] CHIP: [DMG] }, [1651080132024] [2857:76478] CHIP: [DMG] [1651080132024] [2857:76478] CHIP: [DMG] AttributeDataIB = [1651080132024] [2857:76478] CHIP: [DMG] { [1651080132024] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080132024] [2857:76478] CHIP: [DMG] { [1651080132024] [2857:76478] CHIP: [DMG] Endpoint = 0x0, [1651080132024] [2857:76478] CHIP: [DMG] Cluster = 0x1f, [1651080132024] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0000, [1651080132024] [2857:76478] CHIP: [DMG] ListIndex = Null, [1651080132024] [2857:76478] CHIP: [DMG] } [1651080132024] [2857:76478] CHIP: [DMG] [1651080132024] [2857:76478] CHIP: [DMG] Data = [1651080132024] [2857:76478] CHIP: [DMG] { [1651080132024] [2857:76478] CHIP: [DMG] 0x1 = 5, [1651080132024] [2857:76478] CHIP: [DMG] 0x2 = 2, [1651080132024] [2857:76478] CHIP: [DMG] 0x3 = [ [1651080132024] [2857:76478] CHIP: [DMG] 112233, [1651080132024] [2857:76478] CHIP: [DMG] ], [1651080132024] [2857:76478] CHIP: [DMG] 0x4 = NULL [1651080132024] [2857:76478] CHIP: [DMG] }, [1651080132024] [2857:76478] CHIP: [DMG] }, [1651080132024] [2857:76478] CHIP: [DMG] [1651080132024] [2857:76478] CHIP: [DMG] AttributeDataIB = [1651080132024] [2857:76478] CHIP: [DMG] { [1651080132024] [2857:76478] CHIP: [DMG] AttributePathIB = [1651080132024] [2857:76478] CHIP: [DMG] { [1651080132024] [2857:76478] CHIP: [DMG] Endpoint = 0x0, [1651080132024] [2857:76478] CHIP: [DMG] Cluster = 0x1f, [1651080132024] [2857:76478] CHIP: [DMG] Attribute = 0x0000_0000, [1651080132024] [2857:76478] CHIP: [DMG] ListIndex = Null, [1651080132024] [2857:76478] CHIP: [DMG] } [1651080132024] [2857:76478] CHIP: [DMG] [1651080132024] [2857:76478] CHIP: [DMG] Data = [1651080132024] [2857:76478] CHIP: [DMG] { [1651080132024] [2857:76478] CHIP: [DMG] 0x1 = 3, [1651080132024] [2857:76478] CHIP: [DMG] 0x2 = 2, [1651080132024] [2857:76478] CHIP: [DMG] 0x3 = NULL [1651080132024] [2857:76478] CHIP: [DMG] 0x4 = NULL [1651080132024] [2857:76478] CHIP: [DMG] }, [1651080132024] [2857:76478] CHIP: [DMG] }, [1651080132024] [2857:76478] CHIP: [DMG] [1651080132024] [2857:76478] CHIP: [DMG] ], [1651080132024] [2857:76478] CHIP: [DMG] [1651080132025] [2857:76478] CHIP: [DMG] moreChunkedMessages = false, [1651080132025] [2857:76478] CHIP: [DMG] InteractionModelRevision = 1 [1651080132025] [2857:76478] CHIP: [DMG] }, [1651080132025] [2857:76478] CHIP: [DMG] AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_001F e=0 p=a [1651080132025] [2857:76478] CHIP: [DMG] AccessControl: allowed [1651080132025] [2857:76478] CHIP: [EVL] LogEvent event number: 0x0000000000000001 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x00000000004321B4 [1651080132043] [2857:76478] CHIP: [DMG] Endpoint 0, Cluster 0x0000_001F update version to 4ca64ec7 [1651080132043] [2857:76478] CHIP: [DMG] IM WH moving to [AddStatus] [1651080132043] [2857:76478] CHIP: [DMG] AccessControl: validating f=1 p=a a=c s=1 t=0 [1651080132043] [2857:76478] CHIP: [DMG] validating subject 0x000000000001B669 [1651080132059] [2857:76478] CHIP: [EVL] LogEvent event number: 0x0000000000000002 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x00000000004321D6 [1651080132059] [2857:76478] CHIP: [DMG] Endpoint 0, Cluster 0x0000_001F update version to 4ca64ec8 [1651080132059] [2857:76478] CHIP: [DMG] IM WH moving to [AddStatus] [1651080132059] [2857:76478] CHIP: [DMG] AccessControl: validating f=1 p=o a=c s=0 t=0 [1651080132075] [2857:76478] CHIP: [EVL] LogEvent event number: 0x0000000000000003 priority: 1, endpoint id: 0x0 cluster id: 0x0000_001F event id: 0x0 Sys timestamp: 0x00000000004321E6 [1651080132075] [2857:76478] CHIP: [DMG] Endpoint 0, Cluster 0x0000_001F update version to 4ca64ec9 [1651080132075] [2857:76478] CHIP: [DMG] IM WH moving to [AddStatus] [1651080132075] [2857:76478] CHIP: [EM] Piggybacking Ack for MessageCounter:7260433 on exchange: 15863r [1651080132075] [2857:76478] CHIP: [IN] Prepared secure message 0x10f389e08 to 0x000000000001B669 (1) of type 0x7 and protocolId (0, 1) on exchange 15863r with MessageCounter:11246651. [1651080132075] [2857:76478] CHIP: [IN] Sending encrypted msg 0x10f389e08 with MessageCounter:11246651 to 0x000000000001B669 (1) at monotonic time: 00000000004321E7 msec [1651080132075] [2857:76478] CHIP: [DMG] IM WH moving to [Sending] [1651080132075] [2857:76478] CHIP: [DMG] IM WH moving to [Uninitialized] [1651080132075] [2857:76478] CHIP: [DMG] All ReadHandler-s are clean, clear GlobalDirtySet [1651080132075] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:2210334994 on exchange 15862r [1651080132075] [2857:76478] CHIP: [EM] Found matching exchange: 15862r, Delegate: 0x0 [1651080132075] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:2279333810 from Retrans Table on exchange 15862r [1651080132075] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:2279333810 from RetransTable on exchange 15862r [1651080132076] [2857:76478] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:7260434 on exchange 15863r [1651080132076] [2857:76478] CHIP: [EM] Found matching exchange: 15863r, Delegate: 0x0 [1651080132076] [2857:76478] CHIP: [EM] Rxd Ack; Removing MessageCounter:11246651 from Retrans Table on exchange 15863r [1651080132076] [2857:76478] CHIP: [EM] Removed CHIP MessageCounter:11246651 from RetransTable on exchange 15863r [1651080975903] [2857:87720] CHIP: [DIS] OnExpiration callback for cleared session [1651080975903] [2857:87720] CHIP: [DIS] OnDiscoveryExpiration callback for cleared session