`door-lock-app` built with commit SHA: `fa5561c23d8c1f9464da8669931affbae0660f51` Lines of Interest: ubuntu@accessory:~/TE/stableBuild/connectedhomeip$ ./out/debug/standalone/chip-door-lock-app ... [1650578348.945350][20235:20235] CHIP:SVR: Commissioning completed successfully ... [1650579166.689257][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0101 Endpoint=1 AttributeId=0x0000_FFFD (expanded=0) ubuntu@accessory:~/TE/stableBuild/connectedhomeip$ ./out/debug/standalone/chip-door-lock-app [1650578334.629426][20235:20235] CHIP:ZCL: GeneralDiagnosticsDelegate: OnDeviceRebooted [1650578334.629459][20235:20235] CHIP:DMG: Endpoint 0, Cluster 0x0000_0033 update version to 251dca12 [1650578334.629514][20235:20235] CHIP:EVL: LogEvent event number: 0x0000000000000001 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0033 event id: 0x3 Sys timestamp: 0x00000000014BD06C [1650578334.629544][20235:20235] CHIP:SVR: Server Listening... [1650578334.629562][20235:20235] CHIP:DL: Device Configuration: [1650578334.629596][20235:20235] CHIP:DL: Serial Number: TEST_SN [1650578334.629636][20235:20235] CHIP:DL: Vendor Id: 65521 (0xFFF1) [1650578334.629665][20235:20235] CHIP:DL: Product Id: 32769 (0x8001) [1650578334.629694][20235:20235] CHIP:DL: Hardware Version: 0 [1650578334.629714][20235:20235] CHIP:DL: Setup Pin Code (0 for UNKNOWN/ERROR): 20202021 [1650578334.629736][20235:20235] CHIP:DL: Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00) [1650578334.629763][20235:20235] CHIP:DL: Manufacturing Date: (not set) [1650578334.629782][20235:20235] CHIP:DL: Device Type: 65535 (0xFFFF) [1650578334.629838][20235:20235] CHIP:SVR: SetupQRCode: [MT:-24J029Q00KA0648G00] [1650578334.629869][20235:20235] CHIP:SVR: Copy/paste the below URL in a browser to see the QR Code: [1650578334.629891][20235:20235] CHIP:SVR: https://dhrishi.github.io/connectedhomeip/qrcode.html?data=MT%3A-24J029Q00KA0648G00 [1650578334.629929][20235:20235] CHIP:SVR: Manual pairing code: [749701123365521327694] [1650578334.630084][20235:20235] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1650578348.332249][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.335867][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.338968][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.341958][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.344848][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.347828][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.350970][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.353988][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.356928][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.359788][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.363488][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.366290][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.369044][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.372051][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.375741][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.378869][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.382313][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.385638][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.386071][20235:20235] CHIP:EM: Received message of type 0x20 with protocolId (0, 0) and MessageCounter:1492815440 on exchange 12503r [1650578348.386130][20235:20235] CHIP:EM: Handling via exchange: 12503r, Delegate: 0xaaaaca4c7f90 [1650578348.386181][20235:20235] CHIP:SC: Received PBKDF param request [1650578348.386224][20235:20235] CHIP:SC: Peer assigned session ID 63759 [1650578348.386253][20235:20235] CHIP:SC: Found MRP parameters in the message [1650578348.386338][20235:20235] CHIP:SC: Including MRP parameters in PBKDF param response [1650578348.386503][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:1492815440 on exchange: 12503r [1650578348.386551][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x21 and protocolId (0, 0) on exchange 12503r with MessageCounter:4016367935. [1650578348.386588][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016367935 to 0x0000000000000000 at monotonic time: 00000000014C0629 msec [1650578348.386769][20235:20235] CHIP:SC: Sent PBKDF param response [1650578348.394603][20235:20235] CHIP:EM: Received message of type 0x22 with protocolId (0, 0) and MessageCounter:1492815441 on exchange 12503r [1650578348.394667][20235:20235] CHIP:EM: Found matching exchange: 12503r, Delegate: 0xaaaaca4c7f90 [1650578348.394711][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016367935 from Retrans Table on exchange 12503r [1650578348.394732][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016367935 from RetransTable on exchange 12503r [1650578348.394764][20235:20235] CHIP:SC: Received spake2p msg1 [1650578348.396871][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:1492815441 on exchange: 12503r [1650578348.397017][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x23 and protocolId (0, 0) on exchange 12503r with MessageCounter:4016367936. [1650578348.397059][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016367936 to 0x0000000000000000 at monotonic time: 00000000014C0633 msec [1650578348.397306][20235:20235] CHIP:SC: Sent spake2p msg2 [1650578348.399738][20235:20235] CHIP:EM: Received message of type 0x24 with protocolId (0, 0) and MessageCounter:1492815442 on exchange 12503r [1650578348.399805][20235:20235] CHIP:EM: Found matching exchange: 12503r, Delegate: 0xaaaaca4c7f90 [1650578348.399859][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016367936 from Retrans Table on exchange 12503r [1650578348.399885][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016367936 from RetransTable on exchange 12503r [1650578348.399921][20235:20235] CHIP:SC: Received spake2p msg3 [1650578348.400017][20235:20235] CHIP:SC: Sending status report. Protocol code 0, exchange 12503 [1650578348.400058][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:1492815442 on exchange: 12503r [1650578348.400099][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 12503r with MessageCounter:4016367937. [1650578348.400139][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016367937 to 0x0000000000000000 at monotonic time: 00000000014C0637 msec [1650578348.400348][20235:20235] CHIP:IN: New secure session created for device 0xFFFFFFFB00000000, LSID:20516 PSID:63759! [1650578348.400435][20235:20235] CHIP:SVR: Commissioning completed session establishment step [1650578348.400492][20235:20235] CHIP:DIS: Updating services using commissioning mode 0 [1650578348.405954][20235:20235] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1650578348.416123][20235:20235] CHIP:DL: MDNS failed to join multicast group on vethe3891d4 for address type IPv4: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1650578348.418441][20235:20235] CHIP:DL: MDNS failed to join multicast group on veth6796ea6 for address type IPv4: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1650578348.420582][20235:20235] CHIP:DL: MDNS failed to join multicast group on vethc106652 for address type IPv4: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1650578348.420976][20235:20235] CHIP:DIS: CHIP minimal mDNS started advertising. [1650578348.425805][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 17.44.37.53 [1650578348.429571][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 192.168.255.1 [1650578348.433305][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.18.0.1 [1650578348.438158][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.19.0.1 [1650578348.441951][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.20.0.1 [1650578348.445700][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.17.0.1 [1650578348.449072][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.21.0.1 [1650578348.452938][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 2620:149:af:2820:dea6:32ff:fe8d:6e32 [1650578348.457296][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::dea6:32ff:fe8d:6e32 [1650578348.460682][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fdaa:bb:1::2 [1650578348.464078][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::6b67:1037:f650:9fbe [1650578348.467542][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fd11:db8:1::1 [1650578348.467744][20235:20235] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on otbr0: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578348.467788][20235:20235] CHIP:DIS: Failed to advertise records: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578348.471004][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::1 [1650578348.471243][20235:20235] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on otbr0: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578348.471291][20235:20235] CHIP:DIS: Failed to advertise records: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578348.474616][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fd00:6d61:7474:6572::1 [1650578348.478134][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::42:cfff:fe8a:be03 [1650578348.481675][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::1 [1650578348.484813][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::c99:d4ff:fe23:140 [1650578348.488314][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::6c0a:46ff:fe70:fce8 [1650578348.492389][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::345f:96ff:feaa:d421 [1650578348.492887][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-hrikdo) [1650578348.493554][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.493764][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_config.ini-wjR6WQ) [1650578348.494315][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1650578348.494384][20235:20235] CHIP:DL: NVS set: chip-config/fail-safe-armed = true [1650578348.494411][20235:20235] CHIP:SVR: Device completed Rendezvous process [1650578348.494694][20235:20235] CHIP:EM: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:14103664 on exchange 12504r [1650578348.494859][20235:20235] CHIP:EM: Handling via exchange: 12504r, Delegate: 0xaaaaca4c08b8 [1650578348.494911][20235:20235] CHIP:IM: Received Read request [1650578348.494982][20235:20235] CHIP:DMG: ReadRequestMessage = [1650578348.495010][20235:20235] CHIP:DMG: { [1650578348.495034][20235:20235] CHIP:DMG: AttributePathIBs = [1650578348.495062][20235:20235] CHIP:DMG: [ [1650578348.495087][20235:20235] CHIP:DMG: AttributePathIB = [1650578348.495119][20235:20235] CHIP:DMG: { [1650578348.495148][20235:20235] CHIP:DMG: Cluster = 0x31, [1650578348.495182][20235:20235] CHIP:DMG: Attribute = 0x0000_FFFC, [1650578348.495213][20235:20235] CHIP:DMG: } [1650578348.495246][20235:20235] CHIP:DMG: [1650578348.495275][20235:20235] CHIP:DMG: AttributePathIB = [1650578348.495305][20235:20235] CHIP:DMG: { [1650578348.495334][20235:20235] CHIP:DMG: Endpoint = 0x0, [1650578348.495369][20235:20235] CHIP:DMG: Cluster = 0x30, [1650578348.495405][20235:20235] CHIP:DMG: Attribute = 0x0000_0000, [1650578348.495439][20235:20235] CHIP:DMG: } [1650578348.495471][20235:20235] CHIP:DMG: [1650578348.495499][20235:20235] CHIP:DMG: AttributePathIB = [1650578348.495528][20235:20235] CHIP:DMG: { [1650578348.495559][20235:20235] CHIP:DMG: Endpoint = 0x0, [1650578348.495595][20235:20235] CHIP:DMG: Cluster = 0x30, [1650578348.495631][20235:20235] CHIP:DMG: Attribute = 0x0000_0001, [1650578348.495664][20235:20235] CHIP:DMG: } [1650578348.495696][20235:20235] CHIP:DMG: [1650578348.495725][20235:20235] CHIP:DMG: AttributePathIB = [1650578348.495753][20235:20235] CHIP:DMG: { [1650578348.495781][20235:20235] CHIP:DMG: Endpoint = 0x0, [1650578348.495814][20235:20235] CHIP:DMG: Cluster = 0x30, [1650578348.495849][20235:20235] CHIP:DMG: Attribute = 0x0000_0002, [1650578348.495880][20235:20235] CHIP:DMG: } [1650578348.495912][20235:20235] CHIP:DMG: [1650578348.495941][20235:20235] CHIP:DMG: AttributePathIB = [1650578348.495971][20235:20235] CHIP:DMG: { [1650578348.495999][20235:20235] CHIP:DMG: Endpoint = 0x0, [1650578348.496033][20235:20235] CHIP:DMG: Cluster = 0x30, [1650578348.496066][20235:20235] CHIP:DMG: Attribute = 0x0000_0003, [1650578348.496096][20235:20235] CHIP:DMG: } [1650578348.496123][20235:20235] CHIP:DMG: [1650578348.496145][20235:20235] CHIP:DMG: AttributePathIB = [1650578348.496167][20235:20235] CHIP:DMG: { [1650578348.496193][20235:20235] CHIP:DMG: Endpoint = 0x0, [1650578348.496225][20235:20235] CHIP:DMG: Cluster = 0x28, [1650578348.496258][20235:20235] CHIP:DMG: Attribute = 0x0000_0002, [1650578348.496291][20235:20235] CHIP:DMG: } [1650578348.496321][20235:20235] CHIP:DMG: [1650578348.496349][20235:20235] CHIP:DMG: AttributePathIB = [1650578348.496378][20235:20235] CHIP:DMG: { [1650578348.496409][20235:20235] CHIP:DMG: Endpoint = 0x0, [1650578348.496442][20235:20235] CHIP:DMG: Cluster = 0x28, [1650578348.496477][20235:20235] CHIP:DMG: Attribute = 0x0000_0004, [1650578348.496508][20235:20235] CHIP:DMG: } [1650578348.496540][20235:20235] CHIP:DMG: [1650578348.496568][20235:20235] CHIP:DMG: AttributePathIB = [1650578348.496598][20235:20235] CHIP:DMG: { [1650578348.496628][20235:20235] CHIP:DMG: Cluster = 0x31, [1650578348.496664][20235:20235] CHIP:DMG: Attribute = 0x0000_0003, [1650578348.496694][20235:20235] CHIP:DMG: } [1650578348.496722][20235:20235] CHIP:DMG: [1650578348.496750][20235:20235] CHIP:DMG: ], [1650578348.496793][20235:20235] CHIP:DMG: [1650578348.496823][20235:20235] CHIP:DMG: isFabricFiltered = true, [1650578348.496853][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.496878][20235:20235] CHIP:DMG: }, [1650578348.497077][20235:20235] CHIP:DMG: IM RH moving to [GeneratingReports] [1650578348.498050][20235:20235] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 [1650578348.498099][20235:20235] CHIP:DMG: Cluster 31, Attribute 3 is dirty [1650578348.498122][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_0003 (expanded=1) [1650578348.498151][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=v [1650578348.498175][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.498220][20235:20235] CHIP:DMG: Cluster 28, Attribute 4 is dirty [1650578348.498243][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0004 (expanded=0) [1650578348.498267][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0028 e=0 p=v [1650578348.498289][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.498375][20235:20235] CHIP:DMG: Cluster 28, Attribute 2 is dirty [1650578348.498400][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0028 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) [1650578348.498424][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0028 e=0 p=v [1650578348.498446][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.498486][20235:20235] CHIP:DMG: Cluster 30, Attribute 3 is dirty [1650578348.498510][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0003 (expanded=0) [1650578348.498532][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1650578348.498553][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.498602][20235:20235] CHIP:DMG: Cluster 30, Attribute 2 is dirty [1650578348.498626][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0002 (expanded=0) [1650578348.498649][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1650578348.498670][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.498709][20235:20235] CHIP:DMG: Cluster 30, Attribute 1 is dirty [1650578348.498733][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0001 (expanded=0) [1650578348.498756][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1650578348.498778][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.498806][20235:20235] CHIP:DMG: Cluster 30, Attribute 0 is dirty [1650578348.498828][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0030 Endpoint=0 AttributeId=0x0000_0000 (expanded=0) [1650578348.498850][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=v [1650578348.498872][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.498903][20235:20235] CHIP:DMG: Cluster 31, Attribute fffc is dirty [1650578348.498925][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0031 Endpoint=0 AttributeId=0x0000_FFFC (expanded=1) [1650578348.498948][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0031 e=0 p=v [1650578348.498970][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.499008][20235:20235] CHIP:DMG: Sending report (payload has 224 bytes)... [1650578348.499045][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:14103664 on exchange: 12504r [1650578348.499131][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6620 to 0xFFFFFFFB00000000 (0) of type 0x5 and protocolId (0, 1) on exchange 12504r with MessageCounter:14364827. [1650578348.499174][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6620 with MessageCounter:14364827 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000014C069A msec [1650578348.499385][20235:20235] CHIP:DMG: OnReportConfirm: NumReports = 0 [1650578348.499416][20235:20235] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1650578348.499441][20235:20235] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1650578348.499475][20235:20235] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1650578348.499570][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:1492815443 on exchange 12503r [1650578348.499599][20235:20235] CHIP:EM: Found matching exchange: 12503r, Delegate: (nil) [1650578348.499636][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016367937 from Retrans Table on exchange 12503r [1650578348.499660][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016367937 from RetransTable on exchange 12503r [1650578348.506547][20235:20235] CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14103665 on exchange 12505r [1650578348.506615][20235:20235] CHIP:EM: Handling via exchange: 12505r, Delegate: 0xaaaaca4c08b8 [1650578348.506695][20235:20235] CHIP:DMG: InvokeRequestMessage = [1650578348.506722][20235:20235] CHIP:DMG: { [1650578348.506746][20235:20235] CHIP:DMG: suppressResponse = false, [1650578348.506773][20235:20235] CHIP:DMG: timedRequest = false, [1650578348.506798][20235:20235] CHIP:DMG: InvokeRequests = [1650578348.506829][20235:20235] CHIP:DMG: [ [1650578348.506853][20235:20235] CHIP:DMG: CommandDataIB = [1650578348.506887][20235:20235] CHIP:DMG: { [1650578348.506919][20235:20235] CHIP:DMG: CommandPathIB = [1650578348.506956][20235:20235] CHIP:DMG: { [1650578348.506993][20235:20235] CHIP:DMG: EndpointId = 0x0, [1650578348.507031][20235:20235] CHIP:DMG: ClusterId = 0x30, [1650578348.507064][20235:20235] CHIP:DMG: CommandId = 0x0, [1650578348.507093][20235:20235] CHIP:DMG: }, [1650578348.507120][20235:20235] CHIP:DMG: [1650578348.507143][20235:20235] CHIP:DMG: CommandData = [1650578348.507167][20235:20235] CHIP:DMG: { [1650578348.507193][20235:20235] CHIP:DMG: 0x0 = 60, [1650578348.507219][20235:20235] CHIP:DMG: 0x1 = 3, [1650578348.507245][20235:20235] CHIP:DMG: }, [1650578348.507267][20235:20235] CHIP:DMG: }, [1650578348.507294][20235:20235] CHIP:DMG: [1650578348.507320][20235:20235] CHIP:DMG: ], [1650578348.507352][20235:20235] CHIP:DMG: [1650578348.507377][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.507400][20235:20235] CHIP:DMG: }, [1650578348.507466][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1650578348.507494][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.507520][20235:20235] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0000 [1650578348.507732][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-V1EeRN) [1650578348.508311][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.508462][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_config.ini-Jpuh28) [1650578348.508871][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1650578348.508919][20235:20235] CHIP:DL: NVS set: chip-config/fail-safe-armed = true [1650578348.508959][20235:20235] CHIP:DMG: ICR moving to [ Preparing] [1650578348.508990][20235:20235] CHIP:DMG: ICR moving to [AddingComm] [1650578348.509021][20235:20235] CHIP:DMG: ICR moving to [AddedComma] [1650578348.509067][20235:20235] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1650578348.509102][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:14103665 on exchange: 12505r [1650578348.510058][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6600 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 12505r with MessageCounter:14364828. [1650578348.510110][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6600 with MessageCounter:14364828 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000014C06A4 msec [1650578348.510315][20235:20235] CHIP:DMG: ICR moving to [CommandSen] [1650578348.510344][20235:20235] CHIP:DMG: ICR moving to [AwaitingDe] [1650578348.511311][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14103666 on exchange 12504r [1650578348.511353][20235:20235] CHIP:EM: Found matching exchange: 12504r, Delegate: (nil) [1650578348.511394][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:14364827 from Retrans Table on exchange 12504r [1650578348.511418][20235:20235] CHIP:EM: Removed CHIP MessageCounter:14364827 from RetransTable on exchange 12504r [1650578348.512930][20235:20235] CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14103667 on exchange 12506r [1650578348.512976][20235:20235] CHIP:EM: Handling via exchange: 12506r, Delegate: 0xaaaaca4c08b8 [1650578348.513046][20235:20235] CHIP:DMG: InvokeRequestMessage = [1650578348.513072][20235:20235] CHIP:DMG: { [1650578348.513096][20235:20235] CHIP:DMG: suppressResponse = false, [1650578348.513141][20235:20235] CHIP:DMG: timedRequest = false, [1650578348.513173][20235:20235] CHIP:DMG: InvokeRequests = [1650578348.513206][20235:20235] CHIP:DMG: [ [1650578348.513231][20235:20235] CHIP:DMG: CommandDataIB = [1650578348.513257][20235:20235] CHIP:DMG: { [1650578348.513283][20235:20235] CHIP:DMG: CommandPathIB = [1650578348.513313][20235:20235] CHIP:DMG: { [1650578348.513343][20235:20235] CHIP:DMG: EndpointId = 0x0, [1650578348.513374][20235:20235] CHIP:DMG: ClusterId = 0x30, [1650578348.513404][20235:20235] CHIP:DMG: CommandId = 0x2, [1650578348.513432][20235:20235] CHIP:DMG: }, [1650578348.513463][20235:20235] CHIP:DMG: [1650578348.513490][20235:20235] CHIP:DMG: CommandData = [1650578348.513519][20235:20235] CHIP:DMG: { [1650578348.513548][20235:20235] CHIP:DMG: 0x0 = 0, [1650578348.513582][20235:20235] CHIP:DMG: 0x1 = "XX", [1650578348.513614][20235:20235] CHIP:DMG: 0x2 = 4, [1650578348.513644][20235:20235] CHIP:DMG: }, [1650578348.513670][20235:20235] CHIP:DMG: }, [1650578348.513701][20235:20235] CHIP:DMG: [1650578348.513725][20235:20235] CHIP:DMG: ], [1650578348.513757][20235:20235] CHIP:DMG: [1650578348.513781][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.513804][20235:20235] CHIP:DMG: }, [1650578348.513869][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_0030 e=0 p=a [1650578348.513897][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.513923][20235:20235] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0002 [1650578348.514148][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_config.ini-mpnFA7) [1650578348.514716][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1650578348.514773][20235:20235] CHIP:DL: NVS set: chip-config/regulatory-location = 0 (0x0) [1650578348.514895][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_config.ini-eFbX3B) [1650578348.516284][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1650578348.516341][20235:20235] CHIP:DL: NVS set: chip-config/country-code = "XX" [1650578348.516468][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_config.ini-TmzygF) [1650578348.517910][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1650578348.517966][20235:20235] CHIP:DL: NVS set: chip-config/breadcrumb = 4 (0x4) [1650578348.518008][20235:20235] CHIP:DMG: ICR moving to [ Preparing] [1650578348.518040][20235:20235] CHIP:DMG: ICR moving to [AddingComm] [1650578348.518070][20235:20235] CHIP:DMG: ICR moving to [AddedComma] [1650578348.518118][20235:20235] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1650578348.518155][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:14103667 on exchange: 12506r [1650578348.518234][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6620 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 12506r with MessageCounter:14364829. [1650578348.518275][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6620 with MessageCounter:14364829 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000014C06AD msec [1650578348.518466][20235:20235] CHIP:DMG: ICR moving to [CommandSen] [1650578348.518493][20235:20235] CHIP:DMG: ICR moving to [AwaitingDe] [1650578348.519364][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14103668 on exchange 12505r [1650578348.519428][20235:20235] CHIP:EM: Found matching exchange: 12505r, Delegate: (nil) [1650578348.519484][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:14364828 from Retrans Table on exchange 12505r [1650578348.519507][20235:20235] CHIP:EM: Removed CHIP MessageCounter:14364828 from RetransTable on exchange 12505r [1650578348.521955][20235:20235] CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14103669 on exchange 12507r [1650578348.522040][20235:20235] CHIP:EM: Handling via exchange: 12507r, Delegate: 0xaaaaca4c08b8 [1650578348.522127][20235:20235] CHIP:DMG: InvokeRequestMessage = [1650578348.522158][20235:20235] CHIP:DMG: { [1650578348.522182][20235:20235] CHIP:DMG: suppressResponse = false, [1650578348.522211][20235:20235] CHIP:DMG: timedRequest = false, [1650578348.522237][20235:20235] CHIP:DMG: InvokeRequests = [1650578348.522269][20235:20235] CHIP:DMG: [ [1650578348.522295][20235:20235] CHIP:DMG: CommandDataIB = [1650578348.522328][20235:20235] CHIP:DMG: { [1650578348.522354][20235:20235] CHIP:DMG: CommandPathIB = [1650578348.522392][20235:20235] CHIP:DMG: { [1650578348.522429][20235:20235] CHIP:DMG: EndpointId = 0x0, [1650578348.522467][20235:20235] CHIP:DMG: ClusterId = 0x3e, [1650578348.522504][20235:20235] CHIP:DMG: CommandId = 0x2, [1650578348.522539][20235:20235] CHIP:DMG: }, [1650578348.522577][20235:20235] CHIP:DMG: [1650578348.522604][20235:20235] CHIP:DMG: CommandData = [1650578348.522633][20235:20235] CHIP:DMG: { [1650578348.522667][20235:20235] CHIP:DMG: 0x0 = 2, [1650578348.522704][20235:20235] CHIP:DMG: }, [1650578348.522735][20235:20235] CHIP:DMG: }, [1650578348.522769][20235:20235] CHIP:DMG: [1650578348.522793][20235:20235] CHIP:DMG: ], [1650578348.522825][20235:20235] CHIP:DMG: [1650578348.522851][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.522875][20235:20235] CHIP:DMG: }, [1650578348.522944][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1650578348.522974][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.523001][20235:20235] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 [1650578348.523033][20235:20235] CHIP:ZCL: OpCreds: Certificate Chain request received for PAI [1650578348.523074][20235:20235] CHIP:DMG: ICR moving to [ Preparing] [1650578348.523107][20235:20235] CHIP:DMG: ICR moving to [AddingComm] [1650578348.523137][20235:20235] CHIP:DMG: ICR moving to [AddedComma] [1650578348.523177][20235:20235] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1650578348.523212][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:14103669 on exchange: 12507r [1650578348.523312][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6600 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 12507r with MessageCounter:14364830. [1650578348.523358][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6600 with MessageCounter:14364830 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000014C06B2 msec [1650578348.523556][20235:20235] CHIP:DMG: ICR moving to [CommandSen] [1650578348.523592][20235:20235] CHIP:DMG: ICR moving to [AwaitingDe] [1650578348.524526][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14103670 on exchange 12506r [1650578348.524589][20235:20235] CHIP:EM: Found matching exchange: 12506r, Delegate: (nil) [1650578348.524640][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:14364829 from Retrans Table on exchange 12506r [1650578348.524666][20235:20235] CHIP:EM: Removed CHIP MessageCounter:14364829 from RetransTable on exchange 12506r [1650578348.526814][20235:20235] CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14103671 on exchange 12508r [1650578348.526878][20235:20235] CHIP:EM: Handling via exchange: 12508r, Delegate: 0xaaaaca4c08b8 [1650578348.526955][20235:20235] CHIP:DMG: InvokeRequestMessage = [1650578348.526982][20235:20235] CHIP:DMG: { [1650578348.527005][20235:20235] CHIP:DMG: suppressResponse = false, [1650578348.527034][20235:20235] CHIP:DMG: timedRequest = false, [1650578348.527065][20235:20235] CHIP:DMG: InvokeRequests = [1650578348.527096][20235:20235] CHIP:DMG: [ [1650578348.527121][20235:20235] CHIP:DMG: CommandDataIB = [1650578348.527151][20235:20235] CHIP:DMG: { [1650578348.527179][20235:20235] CHIP:DMG: CommandPathIB = [1650578348.527216][20235:20235] CHIP:DMG: { [1650578348.527251][20235:20235] CHIP:DMG: EndpointId = 0x0, [1650578348.527289][20235:20235] CHIP:DMG: ClusterId = 0x3e, [1650578348.527325][20235:20235] CHIP:DMG: CommandId = 0x2, [1650578348.527359][20235:20235] CHIP:DMG: }, [1650578348.527397][20235:20235] CHIP:DMG: [1650578348.527425][20235:20235] CHIP:DMG: CommandData = [1650578348.527460][20235:20235] CHIP:DMG: { [1650578348.527496][20235:20235] CHIP:DMG: 0x0 = 1, [1650578348.527533][20235:20235] CHIP:DMG: }, [1650578348.527565][20235:20235] CHIP:DMG: }, [1650578348.527597][20235:20235] CHIP:DMG: [1650578348.527621][20235:20235] CHIP:DMG: ], [1650578348.527651][20235:20235] CHIP:DMG: [1650578348.527675][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.527700][20235:20235] CHIP:DMG: }, [1650578348.527762][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1650578348.527789][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.527815][20235:20235] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0002 [1650578348.527845][20235:20235] CHIP:ZCL: OpCreds: Certificate Chain request received for DAC [1650578348.527880][20235:20235] CHIP:DMG: ICR moving to [ Preparing] [1650578348.527909][20235:20235] CHIP:DMG: ICR moving to [AddingComm] [1650578348.527938][20235:20235] CHIP:DMG: ICR moving to [AddedComma] [1650578348.527973][20235:20235] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1650578348.528003][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:14103671 on exchange: 12508r [1650578348.528083][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6620 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 12508r with MessageCounter:14364831. [1650578348.528119][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6620 with MessageCounter:14364831 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000014C06B7 msec [1650578348.528299][20235:20235] CHIP:DMG: ICR moving to [CommandSen] [1650578348.528326][20235:20235] CHIP:DMG: ICR moving to [AwaitingDe] [1650578348.528901][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14103672 on exchange 12507r [1650578348.528934][20235:20235] CHIP:EM: Found matching exchange: 12507r, Delegate: (nil) [1650578348.528970][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:14364830 from Retrans Table on exchange 12507r [1650578348.528994][20235:20235] CHIP:EM: Removed CHIP MessageCounter:14364830 from RetransTable on exchange 12507r [1650578348.531217][20235:20235] CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14103673 on exchange 12509r [1650578348.531265][20235:20235] CHIP:EM: Handling via exchange: 12509r, Delegate: 0xaaaaca4c08b8 [1650578348.531327][20235:20235] CHIP:DMG: InvokeRequestMessage = [1650578348.531353][20235:20235] CHIP:DMG: { [1650578348.531376][20235:20235] CHIP:DMG: suppressResponse = false, [1650578348.531403][20235:20235] CHIP:DMG: timedRequest = false, [1650578348.531427][20235:20235] CHIP:DMG: InvokeRequests = [1650578348.531458][20235:20235] CHIP:DMG: [ [1650578348.531482][20235:20235] CHIP:DMG: CommandDataIB = [1650578348.531516][20235:20235] CHIP:DMG: { [1650578348.531547][20235:20235] CHIP:DMG: CommandPathIB = [1650578348.531583][20235:20235] CHIP:DMG: { [1650578348.531619][20235:20235] CHIP:DMG: EndpointId = 0x0, [1650578348.531656][20235:20235] CHIP:DMG: ClusterId = 0x3e, [1650578348.531692][20235:20235] CHIP:DMG: CommandId = 0x0, [1650578348.531726][20235:20235] CHIP:DMG: }, [1650578348.531763][20235:20235] CHIP:DMG: [1650578348.531792][20235:20235] CHIP:DMG: CommandData = [1650578348.531827][20235:20235] CHIP:DMG: { [1650578348.531862][20235:20235] CHIP:DMG: 0x0 = [ [1650578348.531907][20235:20235] CHIP:DMG: 0x4e, 0xd7, 0x7e, 0x88, 0xbd, 0xe9, 0xcd, 0xc3, 0x24, 0xa4, 0x2e, 0xd4, 0x48, 0xa8, 0x99, 0xc5, 0xf1, 0xe2, 0xb1, 0xb0, 0x88, 0xfc, 0xd1, 0x47, 0xdf, 0x74, 0x9f, 0x58, 0xe9, 0x86, 0x57, 0x5b, [1650578348.531949][20235:20235] CHIP:DMG: ] [1650578348.531984][20235:20235] CHIP:DMG: }, [1650578348.532016][20235:20235] CHIP:DMG: }, [1650578348.532049][20235:20235] CHIP:DMG: [1650578348.532073][20235:20235] CHIP:DMG: ], [1650578348.532103][20235:20235] CHIP:DMG: [1650578348.532127][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.532150][20235:20235] CHIP:DMG: }, [1650578348.532210][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1650578348.532237][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.532262][20235:20235] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0000 [1650578348.532294][20235:20235] CHIP:ZCL: OpCreds: received an AttestationRequest [1650578348.538090][20235:20235] CHIP:DMG: ICR moving to [ Preparing] [1650578348.538173][20235:20235] CHIP:DMG: ICR moving to [AddingComm] [1650578348.538205][20235:20235] CHIP:DMG: ICR moving to [AddedComma] [1650578348.538258][20235:20235] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1650578348.538297][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:14103673 on exchange: 12509r [1650578348.538411][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6600 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 12509r with MessageCounter:14364832. [1650578348.538457][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6600 with MessageCounter:14364832 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000014C06C1 msec [1650578348.538670][20235:20235] CHIP:DMG: ICR moving to [CommandSen] [1650578348.538706][20235:20235] CHIP:DMG: ICR moving to [AwaitingDe] [1650578348.538944][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14103674 on exchange 12508r [1650578348.538985][20235:20235] CHIP:EM: Found matching exchange: 12508r, Delegate: (nil) [1650578348.539030][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:14364831 from Retrans Table on exchange 12508r [1650578348.539055][20235:20235] CHIP:EM: Removed CHIP MessageCounter:14364831 from RetransTable on exchange 12508r [1650578348.551728][20235:20235] CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14103675 on exchange 12510r [1650578348.551804][20235:20235] CHIP:EM: Handling via exchange: 12510r, Delegate: 0xaaaaca4c08b8 [1650578348.551888][20235:20235] CHIP:DMG: InvokeRequestMessage = [1650578348.551916][20235:20235] CHIP:DMG: { [1650578348.551940][20235:20235] CHIP:DMG: suppressResponse = false, [1650578348.551976][20235:20235] CHIP:DMG: timedRequest = false, [1650578348.552000][20235:20235] CHIP:DMG: InvokeRequests = [1650578348.552031][20235:20235] CHIP:DMG: [ [1650578348.552057][20235:20235] CHIP:DMG: CommandDataIB = [1650578348.552092][20235:20235] CHIP:DMG: { [1650578348.552120][20235:20235] CHIP:DMG: CommandPathIB = [1650578348.552157][20235:20235] CHIP:DMG: { [1650578348.552195][20235:20235] CHIP:DMG: EndpointId = 0x0, [1650578348.552233][20235:20235] CHIP:DMG: ClusterId = 0x3e, [1650578348.552271][20235:20235] CHIP:DMG: CommandId = 0x4, [1650578348.552300][20235:20235] CHIP:DMG: }, [1650578348.552334][20235:20235] CHIP:DMG: [1650578348.552364][20235:20235] CHIP:DMG: CommandData = [1650578348.552400][20235:20235] CHIP:DMG: { [1650578348.552432][20235:20235] CHIP:DMG: 0x0 = [ [1650578348.552472][20235:20235] CHIP:DMG: 0x79, 0x36, 0x65, 0x4d, 0x1c, 0x72, 0xc1, 0xd3, 0x12, 0x56, 0x48, 0x83, 0xf, 0xaa, 0x8, 0xe2, 0x48, 0x98, 0x10, 0xb, 0x7a, 0xc5, 0xe8, 0x71, 0x33, 0xc7, 0x85, 0xc4, 0xab, 0x16, 0x85, 0x42, [1650578348.552512][20235:20235] CHIP:DMG: ] [1650578348.552548][20235:20235] CHIP:DMG: }, [1650578348.552575][20235:20235] CHIP:DMG: }, [1650578348.552608][20235:20235] CHIP:DMG: [1650578348.552636][20235:20235] CHIP:DMG: ], [1650578348.552667][20235:20235] CHIP:DMG: [1650578348.552692][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.552717][20235:20235] CHIP:DMG: }, [1650578348.552784][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1650578348.552813][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.552840][20235:20235] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0004 [1650578348.552873][20235:20235] CHIP:ZCL: OpCreds: commissioner has requested a CSR [1650578348.554966][20235:20235] CHIP:ZCL: OpCreds: NewCertificateSigningRequest returned ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/crypto/CHIPCryptoPALOpenSSL.cpp:1114: Success [1650578348.555393][20235:20235] CHIP:DMG: ICR moving to [ Preparing] [1650578348.555449][20235:20235] CHIP:DMG: ICR moving to [AddingComm] [1650578348.555483][20235:20235] CHIP:DMG: ICR moving to [AddedComma] [1650578348.555534][20235:20235] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1650578348.555572][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:14103675 on exchange: 12510r [1650578348.555665][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6620 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 12510r with MessageCounter:14364833. [1650578348.555712][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6620 with MessageCounter:14364833 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000014C06D2 msec [1650578348.555922][20235:20235] CHIP:DMG: ICR moving to [CommandSen] [1650578348.555958][20235:20235] CHIP:DMG: ICR moving to [AwaitingDe] [1650578348.556175][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14103676 on exchange 12509r [1650578348.556213][20235:20235] CHIP:EM: Found matching exchange: 12509r, Delegate: (nil) [1650578348.556255][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:14364832 from Retrans Table on exchange 12509r [1650578348.556280][20235:20235] CHIP:EM: Removed CHIP MessageCounter:14364832 from RetransTable on exchange 12509r [1650578348.561504][20235:20235] CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14103677 on exchange 12511r [1650578348.561576][20235:20235] CHIP:EM: Handling via exchange: 12511r, Delegate: 0xaaaaca4c08b8 [1650578348.561659][20235:20235] CHIP:DMG: InvokeRequestMessage = [1650578348.561688][20235:20235] CHIP:DMG: { [1650578348.561712][20235:20235] CHIP:DMG: suppressResponse = false, [1650578348.561747][20235:20235] CHIP:DMG: timedRequest = false, [1650578348.561773][20235:20235] CHIP:DMG: InvokeRequests = [1650578348.561807][20235:20235] CHIP:DMG: [ [1650578348.561833][20235:20235] CHIP:DMG: CommandDataIB = [1650578348.561861][20235:20235] CHIP:DMG: { [1650578348.561887][20235:20235] CHIP:DMG: CommandPathIB = [1650578348.561923][20235:20235] CHIP:DMG: { [1650578348.561954][20235:20235] CHIP:DMG: EndpointId = 0x0, [1650578348.561981][20235:20235] CHIP:DMG: ClusterId = 0x3e, [1650578348.562018][20235:20235] CHIP:DMG: CommandId = 0xb, [1650578348.562054][20235:20235] CHIP:DMG: }, [1650578348.562089][20235:20235] CHIP:DMG: [1650578348.562119][20235:20235] CHIP:DMG: CommandData = [1650578348.562155][20235:20235] CHIP:DMG: { [1650578348.562192][20235:20235] CHIP:DMG: 0x0 = [ [1650578348.562250][20235:20235] 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, 0x1, 0x30, 0x9, 0x41, 0x4, 0x2f, 0xdd, 0xc [1650578348.562288][20235:20235] CHIP:DMG: ] [1650578348.562320][20235:20235] CHIP:DMG: }, [1650578348.562354][20235:20235] CHIP:DMG: }, [1650578348.562388][20235:20235] CHIP:DMG: [1650578348.562415][20235:20235] CHIP:DMG: ], [1650578348.562447][20235:20235] CHIP:DMG: [1650578348.562472][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.562499][20235:20235] CHIP:DMG: }, [1650578348.562565][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1650578348.562594][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.562621][20235:20235] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B [1650578348.562653][20235:20235] CHIP:ZCL: OpCreds: commissioner has added a trusted root Cert [1650578348.562694][20235:20235] CHIP:DMG: ICR moving to [ Preparing] [1650578348.562726][20235:20235] CHIP:DMG: ICR moving to [AddingComm] [1650578348.562754][20235:20235] CHIP:DMG: ICR moving to [AddedComma] [1650578348.562779][20235:20235] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 4b5efd13 [1650578348.562830][20235:20235] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1650578348.562864][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:14103677 on exchange: 12511r [1650578348.562937][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6600 to 0xFFFFFFFB00000000 (0) of type 0x9 and protocolId (0, 1) on exchange 12511r with MessageCounter:14364834. [1650578348.562979][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6600 with MessageCounter:14364834 to 0xFFFFFFFB00000000 (0) at monotonic time: 00000000014C06D9 msec [1650578348.563183][20235:20235] CHIP:DMG: ICR moving to [CommandSen] [1650578348.563216][20235:20235] CHIP:DMG: ICR moving to [AwaitingDe] [1650578348.563328][20235:20235] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1650578348.563454][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14103678 on exchange 12510r [1650578348.563492][20235:20235] CHIP:EM: Found matching exchange: 12510r, Delegate: (nil) [1650578348.563536][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:14364833 from Retrans Table on exchange 12510r [1650578348.563561][20235:20235] CHIP:EM: Removed CHIP MessageCounter:14364833 from RetransTable on exchange 12510r [1650578348.565486][20235:20235] CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:14103679 on exchange 12512r [1650578348.565559][20235:20235] CHIP:EM: Handling via exchange: 12512r, Delegate: 0xaaaaca4c08b8 [1650578348.565652][20235:20235] CHIP:DMG: InvokeRequestMessage = [1650578348.565683][20235:20235] CHIP:DMG: { [1650578348.565707][20235:20235] CHIP:DMG: suppressResponse = false, [1650578348.565738][20235:20235] CHIP:DMG: timedRequest = false, [1650578348.565764][20235:20235] CHIP:DMG: InvokeRequests = [1650578348.565799][20235:20235] CHIP:DMG: [ [1650578348.565825][20235:20235] CHIP:DMG: CommandDataIB = [1650578348.565856][20235:20235] CHIP:DMG: { [1650578348.565884][20235:20235] CHIP:DMG: CommandPathIB = [1650578348.565919][20235:20235] CHIP:DMG: { [1650578348.565953][20235:20235] CHIP:DMG: EndpointId = 0x0, [1650578348.565991][20235:20235] CHIP:DMG: ClusterId = 0x3e, [1650578348.566027][20235:20235] CHIP:DMG: CommandId = 0x6, [1650578348.566063][20235:20235] CHIP:DMG: }, [1650578348.566098][20235:20235] CHIP:DMG: [1650578348.566126][20235:20235] CHIP:DMG: CommandData = [1650578348.566161][20235:20235] CHIP:DMG: { [1650578348.566197][20235:20235] CHIP:DMG: 0x0 = [ [1650578348.566253][20235:20235] 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, 0x24, 0x11, 0x11, 0x18, 0x24, 0x7, 0x1, 0x24, 0x8, 0x1, 0x30, 0x9, 0x41, 0x [1650578348.566292][20235:20235] CHIP:DMG: ] [1650578348.566327][20235:20235] CHIP:DMG: 0x1 = [ [1650578348.566382][20235:20235] 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, 0x1, 0x30, 0x9, 0x41, 0x4, 0xec, 0xec, 0x9 [1650578348.566420][20235:20235] CHIP:DMG: ] [1650578348.566455][20235:20235] CHIP:DMG: 0x2 = [ [1650578348.566495][20235:20235] CHIP:DMG: 0x74, 0x65, 0x6d, 0x70, 0x6f, 0x72, 0x61, 0x72, 0x79, 0x20, 0x69, 0x70, 0x6b, 0x20, 0x30, 0x31, [1650578348.566531][20235:20235] CHIP:DMG: ] [1650578348.566568][20235:20235] CHIP:DMG: 0x3 = 112233, [1650578348.566605][20235:20235] CHIP:DMG: 0x4 = 65521, [1650578348.566642][20235:20235] CHIP:DMG: }, [1650578348.566672][20235:20235] CHIP:DMG: }, [1650578348.566708][20235:20235] CHIP:DMG: [1650578348.566733][20235:20235] CHIP:DMG: ], [1650578348.566763][20235:20235] CHIP:DMG: [1650578348.566784][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.566804][20235:20235] CHIP:DMG: }, [1650578348.566874][20235:20235] CHIP:DMG: AccessControl: checking f=0 a=p s=0xFFFFFFFB00000000 t= c=0x0000_003E e=0 p=a [1650578348.566900][20235:20235] CHIP:DMG: AccessControl: implicit admin (PASE) [1650578348.566923][20235:20235] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_003E Command=0x0000_0006 [1650578348.566967][20235:20235] CHIP:ZCL: OpCreds: commissioner has added a NOC [1650578348.567275][20235:20235] CHIP:DIS: Verifying the received credentials [1650578348.569231][20235:20235] CHIP:DIS: Added new fabric at index: 1, Initialized: 1 [1650578348.569288][20235:20235] CHIP:DIS: Assigned compressed fabric ID: 0x1CA619EC425B4FB0, node ID: 0x0000000000000011 [1650578348.569523][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-CXd5ug) [1650578348.570190][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.570425][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-J9z0g1) [1650578348.572285][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.572533][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-CFFtKn) [1650578348.573886][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.574102][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-wfiKsa) [1650578348.575527][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.575702][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-JCZNZc) [1650578348.577257][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.577328][20235:20235] CHIP:DIS: Fabric (1) persisted to storage. Calling OnFabricPersistedToStorage [1650578348.577354][20235:20235] CHIP:ZCL: OpCreds: Fabric 1 was persisted to storage. FabricId 0000000000000001, NodeId 0000000000000011, VendorId 0xFFF1 [1650578348.577375][20235:20235] CHIP:ZCL: OpCreds: Call to fabricListChanged [1650578348.577398][20235:20235] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 4b5efd14 [1650578348.577438][20235:20235] CHIP:DMG: Endpoint 0, Cluster 0x0000_003E update version to 4b5efd15 [1650578348.577602][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-6ZRI1S) [1650578348.581361][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.581565][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-T2JhQT) [1650578348.582154][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.582260][20235:20235] CHIP:DMG: AccessControl: validating f=1 p=a a=c s=1 t=0 [1650578348.582284][20235:20235] CHIP:DMG: validating subject 0x000000000001B669 [1650578348.582448][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-aRS2u2) [1650578348.583006][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.583194][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-CX1vSC) [1650578348.583847][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.584024][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-SDI6OB) [1650578348.584732][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.584984][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-3YE0cm) [1650578348.585723][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.585959][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-YlkAhM) [1650578348.586681][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.586940][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-oTVrbU) [1650578348.587949][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.588188][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-rbGPGu) [1650578348.588882][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.589099][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-lJw43A) [1650578348.590117][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.590363][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-74idfW) [1650578348.591376][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.591607][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-WlzrzN) [1650578348.592651][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.592887][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-TvhfmK) [1650578348.593934][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.594142][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-jJHOI3) [1650578348.595215][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.595446][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-gfmQTk) [1650578348.596556][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.596832][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-TTl65N) [1650578348.598089][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.598355][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-uMJ38O) [1650578348.599209][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.599432][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-OUVZlt) [1650578348.600788][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.601024][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-uFLMno) [1650578348.602419][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.602652][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-qbWEFO) [1650578348.604058][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.604273][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-W5V0UQ) [1650578348.605865][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.606137][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-oWILMJ) [1650578348.607397][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.607678][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-yaeswu) [1650578348.609081][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.609359][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-AoFBk5) [1650578348.610785][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.611017][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-SZyX4g) [1650578348.614916][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.615163][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-tUPQA4) [1650578348.616030][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.616192][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-ivJJGo) [1650578348.616973][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.617142][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-agCjo2) [1650578348.617944][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.618091][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-8HGNGl) [1650578348.618890][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.619032][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-fsaLUT) [1650578348.619828][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.619966][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-6KjooY) [1650578348.620756][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.620904][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-y50UsY) [1650578348.621880][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.622118][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-XU1wSM) [1650578348.623141][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.623405][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-YfHwHd) [1650578348.624461][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.624681][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-G8854f) [1650578348.625792][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.626028][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-i4Mf2l) [1650578348.627064][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.627252][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-pXH9wk) [1650578348.628377][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.628604][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-yfrjEZ) [1650578348.629740][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.629928][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-k6ouRy) [1650578348.631604][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.631762][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-zbjJvt) [1650578348.633322][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.633502][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-knQ0Vp) [1650578348.635025][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.635179][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-rbLRrh) [1650578348.636764][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.636921][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-vxOEbY) [1650578348.641431][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.641622][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-MseTpf) [1650578348.642691][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.642854][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-es5rqG) [1650578348.643871][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.644018][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-BL36qo) [1650578348.645064][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.645248][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-YZQFXP) [1650578348.646547][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.646721][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-oKbST3) [1650578348.647813][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.647966][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-1yIMCM) [1650578348.649057][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.649228][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-3fNqn8) [1650578348.650343][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.650491][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-EixeAc) [1650578348.652218][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.652270][20235:20235] CHIP:ZCL: OpCreds: ACL entry created for Fabric 1 CASE Admin NodeId 0x000000000001B669 [1650578348.652570][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-arVeAB) [1650578348.653975][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.654224][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-8uiOte) [1650578348.655657][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.655817][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-Umwn1Q) [1650578348.657411][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.658144][20235:20235] CHIP:DL: Using wifi MAC for hostname [1650578348.658189][20235:20235] CHIP:DIS: Advertise operational node 1CA619EC425B4FB0-0000000000000011 [1650578348.658265][20235:20235] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'. [1650578348.661518][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 17.44.37.53 [1650578348.664702][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 192.168.255.1 [1650578348.667808][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.18.0.1 [1650578348.671045][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.19.0.1 [1650578348.674330][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.20.0.1 [1650578348.677570][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.17.0.1 [1650578348.680777][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.21.0.1 [1650578348.684117][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 2620:149:af:2820:dea6:32ff:fe8d:6e32 [1650578348.687498][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::dea6:32ff:fe8d:6e32 [1650578348.690644][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fdaa:bb:1::2 [1650578348.693670][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::6b67:1037:f650:9fbe [1650578348.696737][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fd11:db8:1::1 [1650578348.696896][20235:20235] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on otbr0: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578348.696931][20235:20235] CHIP:DIS: Failed to advertise records: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578348.699727][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::1 [1650578348.699925][20235:20235] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on otbr0: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578348.699961][20235:20235] CHIP:DIS: Failed to advertise records: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578348.704949][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fd00:6d61:7474:6572::1 [1650578348.708106][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::42:cfff:fe8a:be03 [1650578348.711238][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::1 [1650578348.715068][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::c99:d4ff:fe23:140 [1650578348.718008][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::6c0a:46ff:fe70:fce8 [1650578348.720879][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::345f:96ff:feaa:d421 [1650578348.721065][20235:20235] CHIP:DIS: mDNS service published: _matter._tcp [1650578348.721163][20235:20235] CHIP:DMG: ICR moving to [ Preparing] [1650578348.721200][20235:20235] CHIP:DMG: ICR moving to [AddingComm] [1650578348.721231][20235:20235] CHIP:DMG: ICR moving to [AddedComma] [1650578348.721255][20235:20235] CHIP:ZCL: OpCreds: successfully added a NOC [1650578348.721312][20235:20235] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1650578348.721351][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:14103679 on exchange: 12512r [1650578348.721437][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6620 to 0xFFFFFFFB00000000 (1) of type 0x9 and protocolId (0, 1) on exchange 12512r with MessageCounter:14364835. [1650578348.721483][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6620 with MessageCounter:14364835 to 0xFFFFFFFB00000000 (1) at monotonic time: 00000000014C0778 msec [1650578348.721659][20235:20235] CHIP:DMG: ICR moving to [CommandSen] [1650578348.721688][20235:20235] CHIP:DMG: ICR moving to [AwaitingDe] [1650578348.721814][20235:20235] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1650578348.721928][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14103680 on exchange 12511r [1650578348.721959][20235:20235] CHIP:EM: Found matching exchange: 12511r, Delegate: (nil) [1650578348.721998][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:14364834 from Retrans Table on exchange 12511r [1650578348.722022][20235:20235] CHIP:EM: Removed CHIP MessageCounter:14364834 from RetransTable on exchange 12511r [1650578348.728974][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:14103681 on exchange 12512r [1650578348.729048][20235:20235] CHIP:EM: Found matching exchange: 12512r, Delegate: (nil) [1650578348.729098][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:14364835 from Retrans Table on exchange 12512r [1650578348.729153][20235:20235] CHIP:EM: Removed CHIP MessageCounter:14364835 from RetransTable on exchange 12512r [1650578348.739056][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.742830][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.746019][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.749208][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.752106][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.754944][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.757756][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 59401 [1650578348.761966][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.764769][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.767577][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.770816][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.774840][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.777988][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.782105][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.807865][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.810932][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.813965][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.816912][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 40996 [1650578348.926330][20235:20235] CHIP:EM: Received message of type 0x30 with protocolId (0, 0) and MessageCounter:1492815444 on exchange 12513r [1650578348.926586][20235:20235] CHIP:EM: Handling via exchange: 12513r, Delegate: 0xaaaaca4c6018 [1650578348.926663][20235:20235] CHIP:IN: CASE Server received Sigma1 message. Starting handshake. EC 0xaaaaca4c6938 [1650578348.926783][20235:20235] CHIP:SC: Waiting for Sigma1 msg [1650578348.926813][20235:20235] CHIP:IN: CASE Server disabling CASE session setups [1650578348.926839][20235:20235] CHIP:SC: Received Sigma1 msg [1650578348.926889][20235:20235] CHIP:SC: Found MRP parameters in the message [1650578348.926918][20235:20235] CHIP:SC: Peer assigned session key ID 63760 [1650578348.927328][20235:20235] CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000011 [1650578348.928779][20235:20235] CHIP:SC: Including MRP parameters [1650578348.928885][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:1492815444 on exchange: 12513r [1650578348.928935][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 12513r with MessageCounter:4016367938. [1650578348.928980][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016367938 to 0x0000000000000000 at monotonic time: 00000000014C0847 msec [1650578348.929233][20235:20235] CHIP:SC: Sent Sigma2 msg [1650578348.936723][20235:20235] CHIP:EM: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:1492815445 on exchange 12513r [1650578348.936783][20235:20235] CHIP:EM: Found matching exchange: 12513r, Delegate: 0xaaaaca4c6030 [1650578348.936860][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016367938 from Retrans Table on exchange 12513r [1650578348.936887][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016367938 from RetransTable on exchange 12513r [1650578348.936925][20235:20235] CHIP:SC: Received Sigma3 msg [1650578348.937064][20235:20235] CHIP:SC: The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures. [1650578348.939859][20235:20235] CHIP:SC: Unable to save session resumption state: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1650578348.939917][20235:20235] CHIP:SC: Sending status report. Protocol code 0, exchange 12513 [1650578348.939957][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:1492815445 on exchange: 12513r [1650578348.940000][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 12513r with MessageCounter:4016367939. [1650578348.940041][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016367939 to 0x0000000000000000 at monotonic time: 00000000014C0852 msec [1650578348.940249][20235:20235] CHIP:IN: CASE Session established. Setting up the secure channel. [1650578348.940284][20235:20235] CHIP:IN: New secure session created for device 0x000000000001B669, LSID:20517 PSID:63760! [1650578348.940358][20235:20235] CHIP:IN: CASE secure channel is available now. [1650578348.940382][20235:20235] CHIP:IN: CASE Server enabling CASE session setups [1650578348.941370][20235:20235] CHIP:EM: Received message of type 0x8 with protocolId (0, 1) and MessageCounter:4626768 on exchange 12514r [1650578348.941441][20235:20235] CHIP:EM: Handling via exchange: 12514r, Delegate: 0xaaaaca4c08b8 [1650578348.941518][20235:20235] CHIP:DMG: InvokeRequestMessage = [1650578348.941546][20235:20235] CHIP:DMG: { [1650578348.941570][20235:20235] CHIP:DMG: suppressResponse = false, [1650578348.941595][20235:20235] CHIP:DMG: timedRequest = false, [1650578348.941628][20235:20235] CHIP:DMG: InvokeRequests = [1650578348.941658][20235:20235] CHIP:DMG: [ [1650578348.941683][20235:20235] CHIP:DMG: CommandDataIB = [1650578348.941714][20235:20235] CHIP:DMG: { [1650578348.941742][20235:20235] CHIP:DMG: CommandPathIB = [1650578348.941777][20235:20235] CHIP:DMG: { [1650578348.941813][20235:20235] CHIP:DMG: EndpointId = 0x0, [1650578348.941854][20235:20235] CHIP:DMG: ClusterId = 0x30, [1650578348.941891][20235:20235] CHIP:DMG: CommandId = 0x4, [1650578348.941926][20235:20235] CHIP:DMG: }, [1650578348.941960][20235:20235] CHIP:DMG: [1650578348.941989][20235:20235] CHIP:DMG: CommandData = [1650578348.942024][20235:20235] CHIP:DMG: { [1650578348.942061][20235:20235] CHIP:DMG: }, [1650578348.942094][20235:20235] CHIP:DMG: }, [1650578348.942127][20235:20235] CHIP:DMG: [1650578348.942151][20235:20235] CHIP:DMG: ], [1650578348.942183][20235:20235] CHIP:DMG: [1650578348.942245][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650578348.942273][20235:20235] CHIP:DMG: }, [1650578348.942336][20235:20235] CHIP:DMG: AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0030 e=0 p=a [1650578348.942375][20235:20235] CHIP:DMG: AccessControl: allowed [1650578348.942403][20235:20235] CHIP:DMG: Received command for Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0004 [1650578348.942630][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_config.ini-od6hs8) [1650578348.943266][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_config.ini) [1650578348.943326][20235:20235] CHIP:DL: NVS set: chip-config/fail-safe-armed = false [1650578348.943463][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_kvs-L29lGY) [1650578348.944677][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_kvs) [1650578348.944761][20235:20235] CHIP:DMG: ICR moving to [ Preparing] [1650578348.944795][20235:20235] CHIP:DMG: ICR moving to [AddingComm] [1650578348.944826][20235:20235] CHIP:DMG: ICR moving to [AddedComma] [1650578348.944874][20235:20235] CHIP:DMG: Decreasing reference count for CommandHandler, remaining 0 [1650578348.944915][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:4626768 on exchange: 12514r [1650578348.944997][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6620 to 0x000000000001B669 (1) of type 0x9 and protocolId (0, 1) on exchange 12514r with MessageCounter:6683892. [1650578348.945042][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6620 with MessageCounter:6683892 to 0x000000000001B669 (1) at monotonic time: 00000000014C0857 msec [1650578348.945276][20235:20235] CHIP:DMG: ICR moving to [CommandSen] [1650578348.945306][20235:20235] CHIP:DMG: ICR moving to [AwaitingDe] [1650578348.945350][20235:20235] CHIP:SVR: Commissioning completed successfully [1650578348.945398][20235:20235] CHIP:DIS: Updating services using commissioning mode 0 [1650578348.949979][20235:20235] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1650578348.958871][20235:20235] CHIP:DL: MDNS failed to join multicast group on vethe3891d4 for address type IPv4: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1650578348.960581][20235:20235] CHIP:DL: MDNS failed to join multicast group on veth6796ea6 for address type IPv4: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1650578348.962450][20235:20235] CHIP:DL: MDNS failed to join multicast group on vethc106652 for address type IPv4: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1650578348.962835][20235:20235] CHIP:DIS: CHIP minimal mDNS started advertising. [1650578348.966303][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 17.44.37.53 [1650578348.969427][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 192.168.255.1 [1650578348.972571][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.18.0.1 [1650578348.975837][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.19.0.1 [1650578348.978970][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.20.0.1 [1650578348.982228][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.17.0.1 [1650578348.985951][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.21.0.1 [1650578348.989357][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 2620:149:af:2820:dea6:32ff:fe8d:6e32 [1650578348.992437][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::dea6:32ff:fe8d:6e32 [1650578348.995659][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fdaa:bb:1::2 [1650578348.999285][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::6b67:1037:f650:9fbe [1650578349.002982][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fd11:db8:1::1 [1650578349.003225][20235:20235] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on otbr0: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578349.003268][20235:20235] CHIP:DIS: Failed to advertise records: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578349.007708][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::1 [1650578349.007965][20235:20235] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on otbr0: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578349.008009][20235:20235] CHIP:DIS: Failed to advertise records: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578349.011065][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fd00:6d61:7474:6572::1 [1650578349.014273][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::42:cfff:fe8a:be03 [1650578349.017530][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::1 [1650578349.020531][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::c99:d4ff:fe23:140 [1650578349.023626][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::6c0a:46ff:fe70:fce8 [1650578349.029288][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::345f:96ff:feaa:d421 [1650578349.030126][20235:20235] CHIP:DL: Using wifi MAC for hostname [1650578349.030178][20235:20235] CHIP:DIS: Advertise operational node 1CA619EC425B4FB0-0000000000000011 [1650578349.030248][20235:20235] CHIP:DIS: CHIP minimal mDNS configured as 'Operational device'. [1650578349.033569][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 17.44.37.53 [1650578349.036970][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 192.168.255.1 [1650578349.040323][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.18.0.1 [1650578349.043839][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.19.0.1 [1650578349.047215][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.20.0.1 [1650578349.050480][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.17.0.1 [1650578349.055481][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 172.21.0.1 [1650578349.058907][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from 2620:149:af:2820:dea6:32ff:fe8d:6e32 [1650578349.062329][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::dea6:32ff:fe8d:6e32 [1650578349.065584][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fdaa:bb:1::2 [1650578349.068881][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::6b67:1037:f650:9fbe [1650578349.072042][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fd11:db8:1::1 [1650578349.072227][20235:20235] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on otbr0: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578349.072265][20235:20235] CHIP:DIS: Failed to advertise records: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578349.075077][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::1 [1650578349.075231][20235:20235] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on otbr0: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578349.075267][20235:20235] CHIP:DIS: Failed to advertise records: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1650578349.078102][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fd00:6d61:7474:6572::1 [1650578349.081218][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::42:cfff:fe8a:be03 [1650578349.084307][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::1 [1650578349.087420][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::c99:d4ff:fe23:140 [1650578349.090389][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::6c0a:46ff:fe70:fce8 [1650578349.093377][20235:20235] CHIP:DIS: Broadcasting mDns reply for query from fe80::345f:96ff:feaa:d421 [1650578349.093585][20235:20235] CHIP:DIS: mDNS service published: _matter._tcp [1650578349.093624][20235:20235] CHIP:IN: Expiring all PASE pairings [1650578349.093661][20235:20235] CHIP:DL: Long dispatch time: 148 ms, for event type 32784 [1650578349.093879][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:1492815446 on exchange 12513r [1650578349.093913][20235:20235] CHIP:EM: Found matching exchange: 12513r, Delegate: (nil) [1650578349.093964][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016367939 from Retrans Table on exchange 12513r [1650578349.093988][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016367939 from RetransTable on exchange 12513r [1650578349.094779][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:4626769 on exchange 12514r [1650578349.094819][20235:20235] CHIP:EM: Found matching exchange: 12514r, Delegate: (nil) [1650578349.094855][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:6683892 from Retrans Table on exchange 12514r [1650578349.094878][20235:20235] CHIP:EM: Removed CHIP MessageCounter:6683892 from RetransTable on exchange 12514r [1650578467.767156][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.767663][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.767733][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.767794][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.767865][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.767927][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.768079][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773194][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773289][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773351][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773412][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773471][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773545][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773616][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773685][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773745][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773804][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578467.773863][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.339705][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.339815][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.339878][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.339933][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.339993][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.340125][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.340258][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.345655][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.345752][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.345814][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.345868][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.345929][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.345983][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.346037][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.346099][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.346153][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.346213][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650578625.346273][20235:20235] CHIP:DIS: Failed to parse received mDNS packet [1650579163.699371][20235:20235] CHIP:EM: Received message of type 0x30 with protocolId (0, 0) and MessageCounter:1338931402 on exchange 10615r [1650579163.699520][20235:20235] CHIP:EM: Handling via exchange: 10615r, Delegate: 0xaaaaca4c6018 [1650579163.699583][20235:20235] CHIP:IN: CASE Server received Sigma1 message. Starting handshake. EC 0xaaaaca4c6938 [1650579163.699687][20235:20235] CHIP:SC: Waiting for Sigma1 msg [1650579163.699718][20235:20235] CHIP:IN: CASE Server disabling CASE session setups [1650579163.699750][20235:20235] CHIP:SC: Received Sigma1 msg [1650579163.699810][20235:20235] CHIP:SC: Found MRP parameters in the message [1650579163.699843][20235:20235] CHIP:SC: Peer assigned session key ID 54425 [1650579163.700332][20235:20235] CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000011 [1650579163.701693][20235:20235] CHIP:SC: Including MRP parameters [1650579163.701786][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:1338931402 on exchange: 10615r [1650579163.701839][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 10615r with MessageCounter:4016368034. [1650579163.701884][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016368034 to 0x0000000000000000 at monotonic time: 00000000015876FC msec [1650579163.702114][20235:20235] CHIP:SC: Sent Sigma2 msg [1650579163.706911][20235:20235] CHIP:EM: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:1338931403 on exchange 10615r [1650579163.706970][20235:20235] CHIP:EM: Found matching exchange: 10615r, Delegate: 0xaaaaca4c6030 [1650579163.707050][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016368034 from Retrans Table on exchange 10615r [1650579163.707076][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016368034 from RetransTable on exchange 10615r [1650579163.707122][20235:20235] CHIP:SC: Received Sigma3 msg [1650579163.707264][20235:20235] CHIP:SC: The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures. [1650579163.710212][20235:20235] CHIP:SC: Unable to save session resumption state: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1650579163.710312][20235:20235] CHIP:SC: Sending status report. Protocol code 0, exchange 10615 [1650579163.710356][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:1338931403 on exchange: 10615r [1650579163.710400][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 10615r with MessageCounter:4016368035. [1650579163.710444][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016368035 to 0x0000000000000000 at monotonic time: 0000000001587705 msec [1650579163.710674][20235:20235] CHIP:IN: CASE Session established. Setting up the secure channel. [1650579163.710718][20235:20235] CHIP:IN: New secure session created for device 0x000000000001B669, LSID:20565 PSID:54425! [1650579163.710804][20235:20235] CHIP:IN: CASE secure channel is available now. [1650579163.710829][20235:20235] CHIP:IN: CASE Server enabling CASE session setups [1650579163.711669][20235:20235] CHIP:EM: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:15735763 on exchange 10616r [1650579163.711721][20235:20235] CHIP:EM: Handling via exchange: 10616r, Delegate: 0xaaaaca4c08b8 [1650579163.711793][20235:20235] CHIP:IM: Received Read request [1650579163.711846][20235:20235] CHIP:DMG: ReadRequestMessage = [1650579163.711873][20235:20235] CHIP:DMG: { [1650579163.711894][20235:20235] CHIP:DMG: AttributePathIBs = [1650579163.711928][20235:20235] CHIP:DMG: [ [1650579163.711953][20235:20235] CHIP:DMG: AttributePathIB = [1650579163.711982][20235:20235] CHIP:DMG: { [1650579163.712011][20235:20235] CHIP:DMG: Endpoint = 0x1, [1650579163.712045][20235:20235] CHIP:DMG: Cluster = 0x101, [1650579163.712077][20235:20235] CHIP:DMG: Attribute = 0x0000_FFFD, [1650579163.712107][20235:20235] CHIP:DMG: } [1650579163.712138][20235:20235] CHIP:DMG: [1650579163.712165][20235:20235] CHIP:DMG: ], [1650579163.712194][20235:20235] CHIP:DMG: [1650579163.712220][20235:20235] CHIP:DMG: isFabricFiltered = true, [1650579163.712248][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650579163.712273][20235:20235] CHIP:DMG: }, [1650579163.712341][20235:20235] CHIP:DMG: IM RH moving to [GeneratingReports] [1650579163.713110][20235:20235] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 [1650579163.713171][20235:20235] CHIP:DMG: Cluster 101, Attribute fffd is dirty [1650579163.713193][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0101 Endpoint=1 AttributeId=0x0000_FFFD (expanded=0) [1650579163.713222][20235:20235] CHIP:DMG: AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0101 e=1 p=v [1650579163.713255][20235:20235] CHIP:DMG: AccessControl: allowed [1650579163.713309][20235:20235] CHIP:DMG: Sending report (payload has 38 bytes)... [1650579163.713343][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:15735763 on exchange: 10616r [1650579163.713410][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6620 to 0x000000000001B669 (1) of type 0x5 and protocolId (0, 1) on exchange 10616r with MessageCounter:6119598. [1650579163.713447][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6620 with MessageCounter:6119598 to 0x000000000001B669 (1) at monotonic time: 0000000001587708 msec [1650579163.713631][20235:20235] CHIP:DMG: OnReportConfirm: NumReports = 0 [1650579163.713659][20235:20235] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1650579163.713681][20235:20235] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1650579163.713709][20235:20235] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1650579163.713794][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:1338931404 on exchange 10615r [1650579163.713823][20235:20235] CHIP:EM: Found matching exchange: 10615r, Delegate: (nil) [1650579163.713868][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016368035 from Retrans Table on exchange 10615r [1650579163.713892][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016368035 from RetransTable on exchange 10615r [1650579163.715437][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:15735764 on exchange 10616r [1650579163.715468][20235:20235] CHIP:EM: Found matching exchange: 10616r, Delegate: (nil) [1650579163.715510][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:6119598 from Retrans Table on exchange 10616r [1650579163.715534][20235:20235] CHIP:EM: Removed CHIP MessageCounter:6119598 from RetransTable on exchange 10616r [1650579164.869632][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 42955 [1650579164.872701][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 42955 [1650579164.875676][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 42955 [1650579164.878579][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 42955 [1650579164.881505][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 42955 [1650579164.884374][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 42955 [1650579164.887581][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 42955 [1650579164.890406][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.893153][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.895882][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.898672][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.901678][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.904514][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.908160][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.910915][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.913695][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.916543][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579164.920142][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 37507 [1650579165.068089][20235:20235] CHIP:EM: Received message of type 0x30 with protocolId (0, 0) and MessageCounter:652977138 on exchange 50802r [1650579165.068167][20235:20235] CHIP:EM: Handling via exchange: 50802r, Delegate: 0xaaaaca4c6018 [1650579165.068213][20235:20235] CHIP:IN: CASE Server received Sigma1 message. Starting handshake. EC 0xaaaaca4c6938 [1650579165.068298][20235:20235] CHIP:SC: Waiting for Sigma1 msg [1650579165.068323][20235:20235] CHIP:IN: CASE Server disabling CASE session setups [1650579165.068349][20235:20235] CHIP:SC: Received Sigma1 msg [1650579165.068400][20235:20235] CHIP:SC: Found MRP parameters in the message [1650579165.068430][20235:20235] CHIP:SC: Peer assigned session key ID 21155 [1650579165.068844][20235:20235] CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000011 [1650579165.070031][20235:20235] CHIP:SC: Including MRP parameters [1650579165.070133][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:652977138 on exchange: 50802r [1650579165.070183][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 50802r with MessageCounter:4016368036. [1650579165.070226][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016368036 to 0x0000000000000000 at monotonic time: 0000000001587C55 msec [1650579165.070470][20235:20235] CHIP:SC: Sent Sigma2 msg [1650579165.075278][20235:20235] CHIP:EM: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:652977139 on exchange 50802r [1650579165.075325][20235:20235] CHIP:EM: Found matching exchange: 50802r, Delegate: 0xaaaaca4c6030 [1650579165.075391][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016368036 from Retrans Table on exchange 50802r [1650579165.075417][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016368036 from RetransTable on exchange 50802r [1650579165.075462][20235:20235] CHIP:SC: Received Sigma3 msg [1650579165.075597][20235:20235] CHIP:SC: The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures. [1650579165.078678][20235:20235] CHIP:SC: Unable to save session resumption state: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1650579165.078741][20235:20235] CHIP:SC: Sending status report. Protocol code 0, exchange 50802 [1650579165.078812][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:652977139 on exchange: 50802r [1650579165.078858][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 50802r with MessageCounter:4016368037. [1650579165.078903][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016368037 to 0x0000000000000000 at monotonic time: 0000000001587C5D msec [1650579165.079147][20235:20235] CHIP:IN: CASE Session established. Setting up the secure channel. [1650579165.079195][20235:20235] CHIP:IN: New secure session created for device 0x000000000001B669, LSID:20566 PSID:21155! [1650579165.079279][20235:20235] CHIP:IN: CASE secure channel is available now. [1650579165.079305][20235:20235] CHIP:IN: CASE Server enabling CASE session setups [1650579165.081184][20235:20235] CHIP:EM: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:4106407 on exchange 50803r [1650579165.081237][20235:20235] CHIP:EM: Handling via exchange: 50803r, Delegate: 0xaaaaca4c08b8 [1650579165.081314][20235:20235] CHIP:IM: Received Read request [1650579165.081371][20235:20235] CHIP:DMG: ReadRequestMessage = [1650579165.081397][20235:20235] CHIP:DMG: { [1650579165.081420][20235:20235] CHIP:DMG: AttributePathIBs = [1650579165.081447][20235:20235] CHIP:DMG: [ [1650579165.081471][20235:20235] CHIP:DMG: AttributePathIB = [1650579165.081506][20235:20235] CHIP:DMG: { [1650579165.081539][20235:20235] CHIP:DMG: Endpoint = 0x1, [1650579165.081577][20235:20235] CHIP:DMG: Cluster = 0x101, [1650579165.081610][20235:20235] CHIP:DMG: Attribute = 0x0000_FFFD, [1650579165.081640][20235:20235] CHIP:DMG: } [1650579165.081672][20235:20235] CHIP:DMG: [1650579165.081700][20235:20235] CHIP:DMG: ], [1650579165.081730][20235:20235] CHIP:DMG: [1650579165.081756][20235:20235] CHIP:DMG: isFabricFiltered = true, [1650579165.081782][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650579165.081805][20235:20235] CHIP:DMG: }, [1650579165.081874][20235:20235] CHIP:DMG: IM RH moving to [GeneratingReports] [1650579165.082000][20235:20235] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 [1650579165.082033][20235:20235] CHIP:DMG: Cluster 101, Attribute fffd is dirty [1650579165.082055][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0101 Endpoint=1 AttributeId=0x0000_FFFD (expanded=0) [1650579165.082084][20235:20235] CHIP:DMG: AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0101 e=1 p=v [1650579165.082120][20235:20235] CHIP:DMG: AccessControl: allowed [1650579165.082176][20235:20235] CHIP:DMG: Sending report (payload has 38 bytes)... [1650579165.082211][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:4106407 on exchange: 50803r [1650579165.082279][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6620 to 0x000000000001B669 (1) of type 0x5 and protocolId (0, 1) on exchange 50803r with MessageCounter:8925379. [1650579165.082318][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6620 with MessageCounter:8925379 to 0x000000000001B669 (1) at monotonic time: 0000000001587C61 msec [1650579165.082528][20235:20235] CHIP:DMG: OnReportConfirm: NumReports = 0 [1650579165.082563][20235:20235] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1650579165.082586][20235:20235] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1650579165.082616][20235:20235] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1650579165.082722][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:652977140 on exchange 50802r [1650579165.082754][20235:20235] CHIP:EM: Found matching exchange: 50802r, Delegate: (nil) [1650579165.082814][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016368037 from Retrans Table on exchange 50802r [1650579165.082841][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016368037 from RetransTable on exchange 50802r [1650579165.084465][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:4106408 on exchange 50803r [1650579165.084507][20235:20235] CHIP:EM: Found matching exchange: 50803r, Delegate: (nil) [1650579165.084567][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:8925379 from Retrans Table on exchange 50803r [1650579165.084592][20235:20235] CHIP:EM: Removed CHIP MessageCounter:8925379 from RetransTable on exchange 50803r [1650579166.477111][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 57686 [1650579166.480171][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 57686 [1650579166.483146][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 57686 [1650579166.486214][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 57686 [1650579166.489164][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 57686 [1650579166.492232][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 57686 [1650579166.495969][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.499159][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.502288][20235:20235] CHIP:DIS: Directly sending mDns reply to peer 17.44.37.67 on port 57686 [1650579166.506127][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.509285][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.512405][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.515519][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.518962][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.521817][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.524534][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.528078][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.530786][20235:20235] CHIP:DIS: Directly sending mDns reply to peer fe80::dea6:32ff:feb6:ef2a on port 32783 [1650579166.675408][20235:20235] CHIP:EM: Received message of type 0x30 with protocolId (0, 0) and MessageCounter:1816963361 on exchange 23654r [1650579166.675497][20235:20235] CHIP:EM: Handling via exchange: 23654r, Delegate: 0xaaaaca4c6018 [1650579166.675555][20235:20235] CHIP:IN: CASE Server received Sigma1 message. Starting handshake. EC 0xaaaaca4c6938 [1650579166.675643][20235:20235] CHIP:SC: Waiting for Sigma1 msg [1650579166.675666][20235:20235] CHIP:IN: CASE Server disabling CASE session setups [1650579166.675696][20235:20235] CHIP:SC: Received Sigma1 msg [1650579166.675748][20235:20235] CHIP:SC: Found MRP parameters in the message [1650579166.675774][20235:20235] CHIP:SC: Peer assigned session key ID 50279 [1650579166.676209][20235:20235] CHIP:SC: CASE matched destination ID: fabricIndex 1, NodeID 0x0000000000000011 [1650579166.677480][20235:20235] CHIP:SC: Including MRP parameters [1650579166.677561][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:1816963361 on exchange: 23654r [1650579166.677605][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x31 and protocolId (0, 0) on exchange 23654r with MessageCounter:4016368038. [1650579166.677645][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016368038 to 0x0000000000000000 at monotonic time: 000000000158829C msec [1650579166.677869][20235:20235] CHIP:SC: Sent Sigma2 msg [1650579166.683111][20235:20235] CHIP:EM: Received message of type 0x32 with protocolId (0, 0) and MessageCounter:1816963362 on exchange 23654r [1650579166.683180][20235:20235] CHIP:EM: Found matching exchange: 23654r, Delegate: 0xaaaaca4c6030 [1650579166.683273][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016368038 from Retrans Table on exchange 23654r [1650579166.683302][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016368038 from RetransTable on exchange 23654r [1650579166.683348][20235:20235] CHIP:SC: Received Sigma3 msg [1650579166.683523][20235:20235] CHIP:SC: The device does not support GetClock_RealTimeMS() API. This will eventually result in CASE session setup failures. [1650579166.686499][20235:20235] CHIP:SC: Unable to save session resumption state: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/platform/Linux/KeyValueStoreManagerImpl.cpp:53: CHIP Error 0x000000A0: Value not found in the persisted storage [1650579166.686561][20235:20235] CHIP:SC: Sending status report. Protocol code 0, exchange 23654 [1650579166.686609][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:1816963362 on exchange: 23654r [1650579166.686654][20235:20235] CHIP:IN: Prepared unauthenticated message 0xaaaaca4c6600 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 23654r with MessageCounter:4016368039. [1650579166.686696][20235:20235] CHIP:IN: Sending unauthenticated msg 0xaaaaca4c6600 with MessageCounter:4016368039 to 0x0000000000000000 at monotonic time: 00000000015882A5 msec [1650579166.687006][20235:20235] CHIP:IN: CASE Session established. Setting up the secure channel. [1650579166.687066][20235:20235] CHIP:IN: New secure session created for device 0x000000000001B669, LSID:20567 PSID:50279! [1650579166.687163][20235:20235] CHIP:IN: CASE secure channel is available now. [1650579166.687191][20235:20235] CHIP:IN: CASE Server enabling CASE session setups [1650579166.688241][20235:20235] CHIP:EM: Received message of type 0x2 with protocolId (0, 1) and MessageCounter:10081879 on exchange 23655r [1650579166.688305][20235:20235] CHIP:EM: Handling via exchange: 23655r, Delegate: 0xaaaaca4c08b8 [1650579166.688398][20235:20235] CHIP:IM: Received Read request [1650579166.688453][20235:20235] CHIP:DMG: ReadRequestMessage = [1650579166.688492][20235:20235] CHIP:DMG: { [1650579166.688515][20235:20235] CHIP:DMG: AttributePathIBs = [1650579166.688542][20235:20235] CHIP:DMG: [ [1650579166.688567][20235:20235] CHIP:DMG: AttributePathIB = [1650579166.688606][20235:20235] CHIP:DMG: { [1650579166.688635][20235:20235] CHIP:DMG: Endpoint = 0x1, [1650579166.688685][20235:20235] CHIP:DMG: Cluster = 0x101, [1650579166.688729][20235:20235] CHIP:DMG: Attribute = 0x0000_FFFD, [1650579166.688763][20235:20235] CHIP:DMG: } [1650579166.688804][20235:20235] CHIP:DMG: [1650579166.688840][20235:20235] CHIP:DMG: ], [1650579166.688869][20235:20235] CHIP:DMG: [1650579166.688895][20235:20235] CHIP:DMG: isFabricFiltered = true, [1650579166.688931][20235:20235] CHIP:DMG: InteractionModelRevision = 1 [1650579166.688954][20235:20235] CHIP:DMG: }, [1650579166.689041][20235:20235] CHIP:DMG: IM RH moving to [GeneratingReports] [1650579166.689202][20235:20235] CHIP:DMG: Building Reports for ReadHandler with LastReportGeneration = 0 DirtyGeneration = 0 [1650579166.689234][20235:20235] CHIP:DMG: Cluster 101, Attribute fffd is dirty [1650579166.689257][20235:20235] CHIP:DMG: Reading attribute: Cluster=0x0000_0101 Endpoint=1 AttributeId=0x0000_FFFD (expanded=0) [1650579166.689287][20235:20235] CHIP:DMG: AccessControl: checking f=1 a=c s=0x000000000001B669 t= c=0x0000_0101 e=1 p=v [1650579166.689321][20235:20235] CHIP:DMG: AccessControl: allowed [1650579166.689377][20235:20235] CHIP:DMG: Sending report (payload has 38 bytes)... [1650579166.689411][20235:20235] CHIP:EM: Piggybacking Ack for MessageCounter:10081879 on exchange: 23655r [1650579166.689478][20235:20235] CHIP:IN: Prepared secure message 0xaaaaca4c6620 to 0x000000000001B669 (1) of type 0x5 and protocolId (0, 1) on exchange 23655r with MessageCounter:926543. [1650579166.689516][20235:20235] CHIP:IN: Sending encrypted msg 0xaaaaca4c6620 with MessageCounter:926543 to 0x000000000001B669 (1) at monotonic time: 00000000015882A8 msec [1650579166.689727][20235:20235] CHIP:DMG: OnReportConfirm: NumReports = 0 [1650579166.689757][20235:20235] CHIP:DMG: ReportsInFlight = 0 with readHandler 0, RE has no more messages [1650579166.689780][20235:20235] CHIP:DMG: IM RH moving to [AwaitingDestruction] [1650579166.689811][20235:20235] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1650579166.689901][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:1816963363 on exchange 23654r [1650579166.689931][20235:20235] CHIP:EM: Found matching exchange: 23654r, Delegate: (nil) [1650579166.689975][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:4016368039 from Retrans Table on exchange 23654r [1650579166.690000][20235:20235] CHIP:EM: Removed CHIP MessageCounter:4016368039 from RetransTable on exchange 23654r [1650579166.691684][20235:20235] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:10081880 on exchange 23655r [1650579166.691721][20235:20235] CHIP:EM: Found matching exchange: 23655r, Delegate: (nil) [1650579166.691774][20235:20235] CHIP:EM: Rxd Ack; Removing MessageCounter:926543 from Retrans Table on exchange 23655r [1650579166.691799][20235:20235] CHIP:EM: Removed CHIP MessageCounter:926543 from RetransTable on exchange 23655r [1650579234.629496][20235:20235] CHIP:DIS: OnExpiration callback for cleared session [1650579234.629556][20235:20235] CHIP:DIS: OnDiscoveryExpiration callback for cleared session ^C[1650579340.063136][20235:20235] CHIP:DL: Caught signal 2 [1650579340.063353][20235:20235] CHIP:DL: select failed: ../../../examples/door-lock-app/linux/third_party/connectedhomeip/src/system/SystemLayerImplSelect.cpp:377: OS Error 0x02000004: Interrupted system call [1650579340.063409][20235:20235] CHIP:ZCL: Emitting ShutDown event [1650579340.063515][20235:20235] CHIP:EVL: LogEvent event number: 0x0000000000000002 priority: 2, endpoint id: 0x0 cluster id: 0x0000_0028 event id: 0x1 Sys timestamp: 0x00000000015B27E6 [1650579340.063585][20235:20235] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1650579340.065149][20235:20235] CHIP:DMG: IM WH moving to [Uninitialized] [1650579340.065213][20235:20235] CHIP:DMG: IM WH moving to [Uninitialized] [1650579340.065236][20235:20235] CHIP:DMG: IM WH moving to [Uninitialized] [1650579340.065258][20235:20235] CHIP:DMG: IM WH moving to [Uninitialized] [1650579340.065282][20235:20235] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1650579340.065771][20235:20235] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-y1TI3p) [1650579340.066522][20235:20235] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1650579340.066596][20235:20235] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1650579340.066626][20235:20235] CHIP:DL: Inet Layer shutdown [1650579340.066650][20235:20235] CHIP:DL: System Layer shutdown