pi@ubuntu:~$ ./chip-tool doorlock read number-of-total-users-supported 1 1 [1655326079.550230][2326:2326] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655326079.550804][2326:2326] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655326079.550993][2326:2326] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655326079.551125][2326:2326] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655326079.551508][2326:2326] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-V9Doqo) [1655326079.552130][2326:2326] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655326079.552187][2326:2326] CHIP:DL: NVS set: chip-counters/reboot-count = 3 (0x3) [1655326079.552877][2326:2326] CHIP:DL: Got Ethernet interface: eth0 [1655326079.553303][2326:2326] CHIP:DL: Found the primary Ethernet interface:eth0 [1655326079.553760][2326:2326] CHIP:DL: Got WiFi interface: wlan0 [1655326079.553836][2326:2326] CHIP:DL: Failed to reset WiFi statistic counts [1655326079.553913][2326:2326] CHIP:IN: UDP::Init bind&listen port=0 [1655326079.554062][2326:2326] CHIP:IN: UDP::Init bound to port=45934 [1655326079.554089][2326:2326] CHIP:IN: UDP::Init bind&listen port=0 [1655326079.554202][2326:2326] CHIP:IN: UDP::Init bound to port=60257 [1655326079.554226][2326:2326] CHIP:IN: BLEBase::Init - setting/overriding transport [1655326079.554258][2326:2326] CHIP:IN: TransportMgr initialized [1655326079.554307][2326:2326] CHIP:FP: Initializing FabricTable from persistent storage [1655326079.554489][2326:2326] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326079.554584][2326:2326] CHIP:FP: Loading from storage for fabric index 0x1 [1655326079.555084][2326:2326] CHIP:FP: Loading from storage for fabric index 0x2 [1655326079.555440][2326:2326] CHIP:FP: Loading from storage for fabric index 0x3 [1655326079.558561][2326:2326] CHIP:ZCL: Using ZAP configuration... [1655326079.560878][2326:2326] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1655326079.563418][2326:2326] CHIP:DL: MDNS failed to join multicast group on wpan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1655326079.563814][2326:2326] CHIP:CTL: System State Initialized... [1655326079.563880][2326:2326] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326079.563945][2326:2326] CHIP:CTL: Setting attestation nonce to random value [1655326079.564022][2326:2326] CHIP:CTL: Setting CSR nonce to random value [1655326079.564101][2326:2326] CHIP:IN: UDP::Init bind&listen port=5550 [1655326079.564225][2326:2326] CHIP:IN: UDP::Init bound to port=5550 [1655326079.564254][2326:2326] CHIP:IN: UDP::Init bind&listen port=5550 [1655326079.564351][2326:2326] CHIP:IN: UDP::Init bound to port=5550 [1655326079.564375][2326:2326] CHIP:IN: TransportMgr initialized [1655326079.564430][2326:2326] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326079.564461][2326:2326] CHIP:CTL: Setting attestation nonce to random value [1655326079.564548][2326:2326] CHIP:CTL: Setting CSR nonce to random value [1655326079.567315][2326:2326] CHIP:CTL: Generating NOC [1655326079.568181][2326:2326] CHIP:FP: Validating NOC chain [1655326079.569981][2326:2326] CHIP:FP: NOC chain validation successful [1655326079.570144][2326:2326] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655326079.570186][2326:2326] CHIP:FP: Assigned compressed fabric ID: 0x3507FA7A67620D99, node ID: 0x000000000001B669 [1655326079.575842][2326:2326] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655326079.575898][2326:2326] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326079.575923][2326:2326] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326079.575945][2326:2326] CHIP:TS: Retaining current Last Known Good Time [1655326079.577367][2326:2326] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x3507FA7A67620D99 [1655326079.577445][2326:2326] CHIP:IN: UDP::Init bind&listen port=5550 [1655326079.577588][2326:2326] CHIP:IN: UDP::Init bound to port=5550 [1655326079.577617][2326:2326] CHIP:IN: UDP::Init bind&listen port=5550 [1655326079.577729][2326:2326] CHIP:IN: UDP::Init bound to port=5550 [1655326079.577764][2326:2326] CHIP:IN: TransportMgr initialized [1655326079.577880][2326:2326] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326079.577932][2326:2326] CHIP:CTL: Setting attestation nonce to random value [1655326079.577994][2326:2326] CHIP:CTL: Setting CSR nonce to random value [1655326079.578891][2326:2326] CHIP:CTL: Generating NOC [1655326079.579716][2326:2326] CHIP:FP: Validating NOC chain [1655326079.581479][2326:2326] CHIP:FP: NOC chain validation successful [1655326079.581691][2326:2326] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655326079.581721][2326:2326] CHIP:FP: Assigned compressed fabric ID: 0xD4B726C925D03E8C, node ID: 0x000000000001B669 [1655326079.586453][2326:2326] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655326079.586502][2326:2326] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326079.586526][2326:2326] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326079.586548][2326:2326] CHIP:TS: Retaining current Last Known Good Time [1655326079.587800][2326:2326] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0xD4B726C925D03E8C [1655326079.587873][2326:2326] CHIP:IN: UDP::Init bind&listen port=5550 [1655326079.588012][2326:2326] CHIP:IN: UDP::Init bound to port=5550 [1655326079.588055][2326:2326] CHIP:IN: UDP::Init bind&listen port=5550 [1655326079.588158][2326:2326] CHIP:IN: UDP::Init bound to port=5550 [1655326079.588193][2326:2326] CHIP:IN: TransportMgr initialized [1655326079.588313][2326:2326] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326079.588355][2326:2326] CHIP:CTL: Setting attestation nonce to random value [1655326079.588451][2326:2326] CHIP:CTL: Setting CSR nonce to random value [1655326079.589364][2326:2326] CHIP:CTL: Generating NOC [1655326079.590215][2326:2326] CHIP:FP: Validating NOC chain [1655326079.591965][2326:2326] CHIP:FP: NOC chain validation successful [1655326079.592179][2326:2326] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655326079.592208][2326:2326] CHIP:FP: Assigned compressed fabric ID: 0xF2495982D9C810C1, node ID: 0x000000000001B669 [1655326079.597366][2326:2326] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655326079.597419][2326:2326] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326079.597444][2326:2326] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326079.597466][2326:2326] CHIP:TS: Retaining current Last Known Good Time [1655326079.599280][2326:2326] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0xF2495982D9C810C1 [1655326079.599356][2326:2326] CHIP:IN: UDP::Init bind&listen port=5550 [1655326079.599497][2326:2326] CHIP:IN: UDP::Init bound to port=5550 [1655326079.599541][2326:2326] CHIP:IN: UDP::Init bind&listen port=5550 [1655326079.599645][2326:2326] CHIP:IN: UDP::Init bound to port=5550 [1655326079.599682][2326:2326] CHIP:IN: TransportMgr initialized [1655326079.629161][2326:2331] CHIP:DL: CHIP task running [1655326079.629304][2326:2331] CHIP:TOO: Sending command to node 0x1 [1655326079.629346][2326:2331] CHIP:CSM: FindOrEstablishSession: PeerId = 3507FA7A67620D99:0000000000000001 [1655326079.629374][2326:2331] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655326079.629465][2326:2331] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 1 --> 2 [1655326079.629537][2326:2331] CHIP:DIS: MINMDNS: Sending query ANY/UNICAST for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326079.630127][2326:2331] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1655326079.630560][2326:2331] CHIP:DIS: mDNS broadcast had only partial success: 7 successes and 1 failures. [1655326079.630884][2326:2331] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326079.630937][2326:2331] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326079.630965][2326:2331] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326079.631003][2326:2331] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326079.631033][2326:2331] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326079.631564][2326:2331] CHIP:DIS: Lookup clearing interface for non LL address [1655326079.631595][2326:2331] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: new best score: 6 [1655326079.631615][2326:2331] CHIP:DIS: Checking node lookup status after 2 ms [1655326079.631634][2326:2331] CHIP:DIS: Keeping DNSSD lookup active [1655326079.631763][2326:2331] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326079.631806][2326:2331] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326079.631832][2326:2331] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326079.631865][2326:2331] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326079.631892][2326:2331] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326079.631915][2326:2331] CHIP:DIS: Discovered node without a pending query [1655326079.632266][2326:2331] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: score has not improved: 6 [1655326079.632289][2326:2331] CHIP:DIS: Checking node lookup status after 2 ms [1655326079.632307][2326:2331] CHIP:DIS: Keeping DNSSD lookup active [1655326079.830281][2326:2331] CHIP:DIS: Checking node lookup status after 200 ms [1655326079.830347][2326:2331] CHIP:CTL: Updating device address to UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76]:5540 while in state 2 [1655326079.830372][2326:2331] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 2 --> 3 [1655326079.830569][2326:2331] CHIP:IN: SecureSession[0xaaab01cdc360]: Allocated Type:2 LSID:32601 [1655326079.830610][2326:2331] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655326079.831395][2326:2331] CHIP:SC: Including MRP parameters [1655326079.831603][2326:2331] CHIP:IN: Prepared unauthenticated message 0xaaab01cda668 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 1523i with MessageCounter:86467741. [1655326079.831652][2326:2331] CHIP:IN: Sending unauthenticated msg 0xaaab01cda668 with MessageCounter:86467741 to 0x0000000000000000 at monotonic time: 00000000000EDD23 msec [1655326079.831838][2326:2331] CHIP:SC: Sent Sigma1 msg [1655326079.831876][2326:2331] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 3 --> 4 [1655326079.831908][2326:2331] CHIP:DIS: Discovery does not require any more timeouts [1655326079.945762][2326:2331] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:158284778 on exchange 1523i [1655326079.945816][2326:2331] CHIP:EM: Found matching exchange: 1523i, Delegate: 0xffff800015c0 [1655326079.945865][2326:2331] CHIP:EM: Rxd Ack; Removing MessageCounter:86467741 from Retrans Table on exchange 1523i [1655326079.945886][2326:2331] CHIP:EM: Removed CHIP MessageCounter:86467741 from RetransTable on exchange 1523i [1655326079.965600][2326:2331] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:158284779 on exchange 1523i [1655326079.965656][2326:2331] CHIP:EM: Found matching exchange: 1523i, Delegate: 0xffff800015c0 [1655326079.965691][2326:2331] CHIP:EM: CHIP MessageCounter:86467741 not in RetransTable on exchange 1523i [1655326079.965731][2326:2331] CHIP:SC: Received Sigma2Resume msg [1655326079.965841][2326:2331] CHIP:SC: Found MRP parameters in the message [1655326079.965877][2326:2331] CHIP:SC: Peer assigned session session ID 39509 [1655326079.969862][2326:2331] CHIP:SC: Sending status report. Protocol code 0, exchange 1523 [1655326079.969936][2326:2331] CHIP:EM: Piggybacking Ack for MessageCounter:158284779 on exchange: 1523i [1655326079.969986][2326:2331] CHIP:IN: Prepared unauthenticated message 0xaaab01cda668 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 1523i with MessageCounter:86467742. [1655326079.970037][2326:2331] CHIP:IN: Sending unauthenticated msg 0xaaab01cda668 with MessageCounter:86467742 to 0x0000000000000000 at monotonic time: 00000000000EDDAD msec [1655326079.970325][2326:2331] CHIP:IN: SecureSession[0xaaab01cdc360]: Activated - Type:2 LSID:32601 [1655326079.970366][2326:2331] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:32601 PSID:39509! [1655326079.970465][2326:2331] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 4 --> 5 [1655326079.970595][2326:2331] CHIP:TOO: cluster 0x0000_0101, attribute: 0x0000_0011, endpoint 1 [1655326079.970632][2326:2331] CHIP:TOO: Sending ReadAttribute to: [1655326079.970668][2326:2331] CHIP:DMG: SendReadRequest ReadClient[0xffff800032a0]: Sending Read Request [1655326079.970807][2326:2331] CHIP:IN: Prepared secure message 0xaaab01cda688 to 0x0000000000000001 (1) of type 0x2 and protocolId (0, 1) on exchange 1524i with MessageCounter:189519151. [1655326079.970929][2326:2331] CHIP:IN: Sending encrypted msg 0xaaab01cda688 with MessageCounter:189519151 to 0x0000000000000001 (1) at monotonic time: 00000000000EDDAE msec [1655326079.971120][2326:2331] CHIP:DMG: MoveToState ReadClient[0xffff800032a0]: Moving to [AwaitingIn] [1655326080.021633][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 53.0.16.172.in-addr.arpa [1655326080.021692][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.021720][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.021747][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.021771][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 53.0.16.172.in-addr.arpa [1655326080.021797][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.021824][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.021850][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.021919][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 53.0.16.172.in-addr.arpa [1655326080.021948][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.021974][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022000][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.022022][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 53.0.16.172.in-addr.arpa [1655326080.022047][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022072][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022098][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.022215][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 53.0.16.172.in-addr.arpa [1655326080.022245][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022271][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022297][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.022318][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 53.0.16.172.in-addr.arpa [1655326080.022343][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022369][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022394][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.022454][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 53.0.16.172.in-addr.arpa [1655326080.022483][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022508][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022534][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.022556][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 53.0.16.172.in-addr.arpa [1655326080.022581][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022606][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022632][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.022691][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 53.0.16.172.in-addr.arpa [1655326080.022719][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022745][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022771][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.022792][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 53.0.16.172.in-addr.arpa [1655326080.022817][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022842][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022868][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.022927][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 53.0.16.172.in-addr.arpa [1655326080.022955][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.022980][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.023007][2326:2331] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.023028][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 53.0.16.172.in-addr.arpa [1655326080.023053][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.023078][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326080.023103][2326:2331] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.3.3.0.0.1.1.D.F.ip6.arpa [1655326080.025788][2326:2331] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:158284780 on exchange 1523i [1655326080.025840][2326:2331] CHIP:EM: Found matching exchange: 1523i, Delegate: (nil) [1655326080.025889][2326:2331] CHIP:EM: Rxd Ack; Removing MessageCounter:86467742 from Retrans Table on exchange 1523i [1655326080.025911][2326:2331] CHIP:EM: Removed CHIP MessageCounter:86467742 from RetransTable on exchange 1523i [1655326080.055794][2326:2331] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:35028779 on exchange 1524i [1655326080.055847][2326:2331] CHIP:EM: Found matching exchange: 1524i, Delegate: 0xffff800032a0 [1655326080.055893][2326:2331] CHIP:EM: Rxd Ack; Removing MessageCounter:189519151 from Retrans Table on exchange 1524i [1655326080.055914][2326:2331] CHIP:EM: Removed CHIP MessageCounter:189519151 from RetransTable on exchange 1524i [1655326080.055979][2326:2331] CHIP:DMG: ReportDataMessage = [1655326080.056003][2326:2331] CHIP:DMG: { [1655326080.056021][2326:2331] CHIP:DMG: AttributeReportIBs = [1655326080.056049][2326:2331] CHIP:DMG: [ [1655326080.056081][2326:2331] CHIP:DMG: AttributeReportIB = [1655326080.056115][2326:2331] CHIP:DMG: { [1655326080.056138][2326:2331] CHIP:DMG: AttributeDataIB = [1655326080.056163][2326:2331] CHIP:DMG: { [1655326080.056190][2326:2331] CHIP:DMG: DataVersion = 0xb3865720, [1655326080.056214][2326:2331] CHIP:DMG: AttributePathIB = [1655326080.056242][2326:2331] CHIP:DMG: { [1655326080.056269][2326:2331] CHIP:DMG: Endpoint = 0x1, [1655326080.056297][2326:2331] CHIP:DMG: Cluster = 0x101, [1655326080.056325][2326:2331] CHIP:DMG: Attribute = 0x0000_0011, [1655326080.056351][2326:2331] CHIP:DMG: } [1655326080.056388][2326:2331] CHIP:DMG: [1655326080.056431][2326:2331] CHIP:DMG: Data = 10, [1655326080.056553][2326:2331] CHIP:DMG: }, [1655326080.056598][2326:2331] CHIP:DMG: [1655326080.056628][2326:2331] CHIP:DMG: }, [1655326080.056662][2326:2331] CHIP:DMG: [1655326080.056687][2326:2331] CHIP:DMG: ], [1655326080.056719][2326:2331] CHIP:DMG: [1655326080.056744][2326:2331] CHIP:DMG: SuppressResponse = true, [1655326080.056769][2326:2331] CHIP:DMG: InteractionModelRevision = 1 [1655326080.056796][2326:2331] CHIP:DMG: } [1655326080.056986][2326:2331] CHIP:TOO: Endpoint: 1 Cluster: 0x0000_0101 Attribute 0x0000_0011 DataVersion: 3011925792 [1655326080.057042][2326:2331] CHIP:TOO: NumberOfTotalUsersSupported: 10 [1655326080.057138][2326:2331] CHIP:EM: Sending Standalone Ack for MessageCounter:35028779 on exchange 1524i [1655326080.057221][2326:2331] CHIP:IN: Prepared secure message 0xffff8a7cd9d8 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 1524i with MessageCounter:189519152. [1655326080.057263][2326:2331] CHIP:IN: Sending encrypted msg 0xffff8a7cd9d8 with MessageCounter:189519152 to 0x0000000000000001 (1) at monotonic time: 00000000000EDE04 msec [1655326080.057394][2326:2331] CHIP:EM: Flushed pending ack for MessageCounter:35028779 on exchange 1524i [1655326080.057571][2326:2326] CHIP:CTL: Shutting down the commissioner [1655326080.057702][2326:2326] CHIP:CTL: Shutting down the controller [1655326080.057734][2326:2326] CHIP:CTL: Shutting down the commissioner [1655326080.057811][2326:2326] CHIP:CTL: Shutting down the controller [1655326080.057841][2326:2326] CHIP:IN: Expiring all connections for fabric 1!! [1655326080.057861][2326:2326] CHIP:IN: SecureSession[0xaaab01cdc360]: MarkForRemoval Type:2 LSID:32601 [1655326080.057880][2326:2326] CHIP:IN: SecureSession[0xaaab01cdc360]: Released - Type:2 LSID:32601 [1655326080.057931][2326:2326] CHIP:CTL: Shutting down the commissioner [1655326080.058018][2326:2326] CHIP:CTL: Shutting down the controller [1655326080.058046][2326:2326] CHIP:IN: Expiring all connections for fabric 2!! [1655326080.058083][2326:2326] CHIP:CTL: Shutting down the commissioner [1655326080.058178][2326:2326] CHIP:CTL: Shutting down the controller [1655326080.058198][2326:2326] CHIP:IN: Expiring all connections for fabric 3!! [1655326080.058227][2326:2326] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655326080.058736][2326:2326] CHIP:DMG: IM WH moving to [Uninitialized] [1655326080.058774][2326:2326] CHIP:DMG: IM WH moving to [Uninitialized] [1655326080.058798][2326:2326] CHIP:DMG: IM WH moving to [Uninitialized] [1655326080.058818][2326:2326] CHIP:DMG: IM WH moving to [Uninitialized] [1655326080.058840][2326:2326] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655326080.058929][2326:2326] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655326080.059199][2326:2326] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-NHDUMn) [1655326080.059902][2326:2326] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655326080.059964][2326:2326] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655326080.059991][2326:2326] CHIP:DL: Inet Layer shutdown [1655326080.060014][2326:2326] CHIP:DL: BLE shutdown [1655326080.060037][2326:2326] CHIP:DL: System Layer shutdown ---- pi@ubuntu:~$ ./chip-tool doorlock set-user 0 1 xxx 6452 1 0 0 1 1 --timedInteractionTimeoutMs 1000 [1655326116.375461][2333:2333] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655326116.376035][2333:2333] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655326116.376204][2333:2333] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655326116.376318][2333:2333] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655326116.376762][2333:2333] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-WW8KPf) [1655326116.377372][2333:2333] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655326116.377428][2333:2333] CHIP:DL: NVS set: chip-counters/reboot-count = 4 (0x4) [1655326116.378133][2333:2333] CHIP:DL: Got Ethernet interface: eth0 [1655326116.378595][2333:2333] CHIP:DL: Found the primary Ethernet interface:eth0 [1655326116.379028][2333:2333] CHIP:DL: Got WiFi interface: wlan0 [1655326116.379102][2333:2333] CHIP:DL: Failed to reset WiFi statistic counts [1655326116.379177][2333:2333] CHIP:IN: UDP::Init bind&listen port=0 [1655326116.379305][2333:2333] CHIP:IN: UDP::Init bound to port=46612 [1655326116.379332][2333:2333] CHIP:IN: UDP::Init bind&listen port=0 [1655326116.379471][2333:2333] CHIP:IN: UDP::Init bound to port=59466 [1655326116.379498][2333:2333] CHIP:IN: BLEBase::Init - setting/overriding transport [1655326116.379519][2333:2333] CHIP:IN: TransportMgr initialized [1655326116.379571][2333:2333] CHIP:FP: Initializing FabricTable from persistent storage [1655326116.379744][2333:2333] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326116.379828][2333:2333] CHIP:FP: Loading from storage for fabric index 0x1 [1655326116.380462][2333:2333] CHIP:FP: Loading from storage for fabric index 0x2 [1655326116.380923][2333:2333] CHIP:FP: Loading from storage for fabric index 0x3 [1655326116.384363][2333:2333] CHIP:ZCL: Using ZAP configuration... [1655326116.386680][2333:2333] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1655326116.389318][2333:2333] CHIP:DL: MDNS failed to join multicast group on wpan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1655326116.389687][2333:2333] CHIP:CTL: System State Initialized... [1655326116.389751][2333:2333] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326116.389814][2333:2333] CHIP:CTL: Setting attestation nonce to random value [1655326116.389878][2333:2333] CHIP:CTL: Setting CSR nonce to random value [1655326116.389955][2333:2333] CHIP:IN: UDP::Init bind&listen port=5550 [1655326116.390126][2333:2333] CHIP:IN: UDP::Init bound to port=5550 [1655326116.390159][2333:2333] CHIP:IN: UDP::Init bind&listen port=5550 [1655326116.390286][2333:2333] CHIP:IN: UDP::Init bound to port=5550 [1655326116.390311][2333:2333] CHIP:IN: TransportMgr initialized [1655326116.390389][2333:2333] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326116.390421][2333:2333] CHIP:CTL: Setting attestation nonce to random value [1655326116.390501][2333:2333] CHIP:CTL: Setting CSR nonce to random value [1655326116.393355][2333:2333] CHIP:CTL: Generating NOC [1655326116.394197][2333:2333] CHIP:FP: Validating NOC chain [1655326116.396003][2333:2333] CHIP:FP: NOC chain validation successful [1655326116.396162][2333:2333] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655326116.396190][2333:2333] CHIP:FP: Assigned compressed fabric ID: 0x3507FA7A67620D99, node ID: 0x000000000001B669 [1655326116.401647][2333:2333] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655326116.401707][2333:2333] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326116.401731][2333:2333] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326116.401753][2333:2333] CHIP:TS: Retaining current Last Known Good Time [1655326116.403233][2333:2333] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x3507FA7A67620D99 [1655326116.403315][2333:2333] CHIP:IN: UDP::Init bind&listen port=5550 [1655326116.403481][2333:2333] CHIP:IN: UDP::Init bound to port=5550 [1655326116.403512][2333:2333] CHIP:IN: UDP::Init bind&listen port=5550 [1655326116.403604][2333:2333] CHIP:IN: UDP::Init bound to port=5550 [1655326116.403629][2333:2333] CHIP:IN: TransportMgr initialized [1655326116.403717][2333:2333] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326116.403806][2333:2333] CHIP:CTL: Setting attestation nonce to random value [1655326116.403870][2333:2333] CHIP:CTL: Setting CSR nonce to random value [1655326116.404841][2333:2333] CHIP:CTL: Generating NOC [1655326116.405711][2333:2333] CHIP:FP: Validating NOC chain [1655326116.407447][2333:2333] CHIP:FP: NOC chain validation successful [1655326116.407604][2333:2333] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655326116.407632][2333:2333] CHIP:FP: Assigned compressed fabric ID: 0xD4B726C925D03E8C, node ID: 0x000000000001B669 [1655326116.413185][2333:2333] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655326116.413238][2333:2333] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326116.413262][2333:2333] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326116.413284][2333:2333] CHIP:TS: Retaining current Last Known Good Time [1655326116.459500][2333:2333] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0xD4B726C925D03E8C [1655326116.459587][2333:2333] CHIP:IN: UDP::Init bind&listen port=5550 [1655326116.459726][2333:2333] CHIP:IN: UDP::Init bound to port=5550 [1655326116.459753][2333:2333] CHIP:IN: UDP::Init bind&listen port=5550 [1655326116.459843][2333:2333] CHIP:IN: UDP::Init bound to port=5550 [1655326116.459868][2333:2333] CHIP:IN: TransportMgr initialized [1655326116.459980][2333:2333] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326116.460020][2333:2333] CHIP:CTL: Setting attestation nonce to random value [1655326116.460139][2333:2333] CHIP:CTL: Setting CSR nonce to random value [1655326116.461144][2333:2333] CHIP:CTL: Generating NOC [1655326116.462090][2333:2333] CHIP:FP: Validating NOC chain [1655326116.463812][2333:2333] CHIP:FP: NOC chain validation successful [1655326116.463972][2333:2333] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655326116.464000][2333:2333] CHIP:FP: Assigned compressed fabric ID: 0xF2495982D9C810C1, node ID: 0x000000000001B669 [1655326116.468948][2333:2333] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655326116.469000][2333:2333] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326116.469023][2333:2333] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326116.469045][2333:2333] CHIP:TS: Retaining current Last Known Good Time [1655326116.470400][2333:2333] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0xF2495982D9C810C1 [1655326116.470479][2333:2333] CHIP:IN: UDP::Init bind&listen port=5550 [1655326116.470622][2333:2333] CHIP:IN: UDP::Init bound to port=5550 [1655326116.470650][2333:2333] CHIP:IN: UDP::Init bind&listen port=5550 [1655326116.470738][2333:2333] CHIP:IN: UDP::Init bound to port=5550 [1655326116.470763][2333:2333] CHIP:IN: TransportMgr initialized [1655326116.500445][2333:2338] CHIP:DL: CHIP task running [1655326116.500622][2333:2338] CHIP:TOO: Sending command to node 0x1 [1655326116.500666][2333:2338] CHIP:CSM: FindOrEstablishSession: PeerId = 3507FA7A67620D99:0000000000000001 [1655326116.500693][2333:2338] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655326116.500822][2333:2338] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 1 --> 2 [1655326116.500919][2333:2338] CHIP:DIS: MINMDNS: Sending query ANY/UNICAST for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326116.501710][2333:2338] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1655326116.502459][2333:2338] CHIP:DIS: mDNS broadcast had only partial success: 7 successes and 1 failures. [1655326116.503406][2333:2338] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326116.503477][2333:2338] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326116.503510][2333:2338] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326116.503553][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326116.503589][2333:2338] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326116.504181][2333:2338] CHIP:DIS: Lookup clearing interface for non LL address [1655326116.504215][2333:2338] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: new best score: 6 [1655326116.504239][2333:2338] CHIP:DIS: Checking node lookup status after 3 ms [1655326116.504261][2333:2338] CHIP:DIS: Keeping DNSSD lookup active [1655326116.504397][2333:2338] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326116.504459][2333:2338] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326116.504516][2333:2338] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326116.504582][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326116.504614][2333:2338] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326116.504652][2333:2338] CHIP:DIS: Discovered node without a pending query [1655326116.505091][2333:2338] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: score has not improved: 6 [1655326116.505128][2333:2338] CHIP:DIS: Checking node lookup status after 4 ms [1655326116.505149][2333:2338] CHIP:DIS: Keeping DNSSD lookup active [1655326116.701089][2333:2338] CHIP:DIS: Checking node lookup status after 200 ms [1655326116.701151][2333:2338] CHIP:CTL: Updating device address to UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76]:5540 while in state 2 [1655326116.701175][2333:2338] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 2 --> 3 [1655326116.701372][2333:2338] CHIP:IN: SecureSession[0xaaaaee8ddcf0]: Allocated Type:2 LSID:44400 [1655326116.701413][2333:2338] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655326116.702156][2333:2338] CHIP:SC: Including MRP parameters [1655326116.702371][2333:2338] CHIP:IN: Prepared unauthenticated message 0xaaaaee8dc178 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 28755i with MessageCounter:228683103. [1655326116.702434][2333:2338] CHIP:IN: Sending unauthenticated msg 0xaaaaee8dc178 with MessageCounter:228683103 to 0x0000000000000000 at monotonic time: 00000000000F6D29 msec [1655326116.702678][2333:2338] CHIP:SC: Sent Sigma1 msg [1655326116.702713][2333:2338] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 3 --> 4 [1655326116.702772][2333:2338] CHIP:DIS: Discovery does not require any more timeouts [1655326116.914380][2333:2338] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:158284781 on exchange 28755i [1655326116.914434][2333:2338] CHIP:EM: Found matching exchange: 28755i, Delegate: 0xffff940015c0 [1655326116.914480][2333:2338] CHIP:EM: Rxd Ack; Removing MessageCounter:228683103 from Retrans Table on exchange 28755i [1655326116.914501][2333:2338] CHIP:EM: Removed CHIP MessageCounter:228683103 from RetransTable on exchange 28755i [1655326116.934275][2333:2338] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:158284782 on exchange 28755i [1655326116.934330][2333:2338] CHIP:EM: Found matching exchange: 28755i, Delegate: 0xffff940015c0 [1655326116.934363][2333:2338] CHIP:EM: CHIP MessageCounter:228683103 not in RetransTable on exchange 28755i [1655326116.934404][2333:2338] CHIP:SC: Received Sigma2Resume msg [1655326116.934516][2333:2338] CHIP:SC: Found MRP parameters in the message [1655326116.934552][2333:2338] CHIP:SC: Peer assigned session session ID 39510 [1655326116.938570][2333:2338] CHIP:SC: Sending status report. Protocol code 0, exchange 28755 [1655326116.938640][2333:2338] CHIP:EM: Piggybacking Ack for MessageCounter:158284782 on exchange: 28755i [1655326116.938689][2333:2338] CHIP:IN: Prepared unauthenticated message 0xaaaaee8dc178 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 28755i with MessageCounter:228683104. [1655326116.938740][2333:2338] CHIP:IN: Sending unauthenticated msg 0xaaaaee8dc178 with MessageCounter:228683104 to 0x0000000000000000 at monotonic time: 00000000000F6E16 msec [1655326116.939034][2333:2338] CHIP:IN: SecureSession[0xaaaaee8ddcf0]: Activated - Type:2 LSID:44400 [1655326116.939075][2333:2338] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:44400 PSID:39510! [1655326116.939108][2333:2338] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 4 --> 5 [1655326116.939164][2333:2338] CHIP:TOO: Sending cluster (0x00000101) command (0x0000001A) on endpoint 1 [1655326116.939216][2333:2338] CHIP:DMG: ICR moving to [AddingComm] [1655326116.939294][2333:2338] CHIP:DMG: ICR moving to [AddedComma] [1655326116.939573][2333:2338] CHIP:IN: Prepared secure message 0xaaaaee8dc198 to 0x0000000000000001 (1) of type 0xa and protocolId (0, 1) on exchange 28756i with MessageCounter:169366430. [1655326116.939630][2333:2338] CHIP:IN: Sending encrypted msg 0xaaaaee8dc198 with MessageCounter:169366430 to 0x0000000000000001 (1) at monotonic time: 00000000000F6E17 msec [1655326116.939817][2333:2338] CHIP:DMG: ICR moving to [AwaitingTi] [1655326116.989386][2333:2338] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:158284783 on exchange 28755i [1655326116.989439][2333:2338] CHIP:EM: Found matching exchange: 28755i, Delegate: (nil) [1655326116.989488][2333:2338] CHIP:EM: Rxd Ack; Removing MessageCounter:228683104 from Retrans Table on exchange 28755i [1655326116.989509][2333:2338] CHIP:EM: Removed CHIP MessageCounter:228683104 from RetransTable on exchange 28755i [1655326117.019397][2333:2338] CHIP:EM: Received message of type 0x1 with protocolId (0, 1) and MessageCounter:193111246 on exchange 28756i [1655326117.019447][2333:2338] CHIP:EM: Found matching exchange: 28756i, Delegate: 0xffff94004370 [1655326117.019489][2333:2338] CHIP:EM: Rxd Ack; Removing MessageCounter:169366430 from Retrans Table on exchange 28756i [1655326117.019513][2333:2338] CHIP:EM: Removed CHIP MessageCounter:169366430 from RetransTable on exchange 28756i [1655326117.019573][2333:2338] CHIP:DMG: StatusResponseMessage = [1655326117.019602][2333:2338] CHIP:DMG: { [1655326117.019625][2333:2338] CHIP:DMG: Status = 0x00 (SUCCESS), [1655326117.019650][2333:2338] CHIP:DMG: InteractionModelRevision = 1 [1655326117.019673][2333:2338] CHIP:DMG: } [1655326117.019698][2333:2338] CHIP:IM: Received status response, status is 0x00 (SUCCESS) [1655326117.019735][2333:2338] CHIP:EM: Piggybacking Ack for MessageCounter:193111246 on exchange: 28756i [1655326117.019804][2333:2338] CHIP:IN: Prepared secure message 0xaaaaee8dc178 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 28756i with MessageCounter:169366431. [1655326117.019839][2333:2338] CHIP:IN: Sending encrypted msg 0xaaaaee8dc178 with MessageCounter:169366431 to 0x0000000000000001 (1) at monotonic time: 00000000000F6E67 msec [1655326117.020034][2333:2338] CHIP:DMG: ICR moving to [CommandSen] [1655326117.123623][2333:2338] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.123706][2333:2338] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.123747][2333:2338] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326117.123782][2333:2338] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.123806][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.123826][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326117.123847][2333:2338] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.123881][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.123902][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326117.123921][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326117.123946][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326117.123974][2333:2338] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326117.124004][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.124029][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.124049][2333:2338] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326117.124069][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.124089][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.124108][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.124130][2333:2338] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.124151][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.124171][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326117.124203][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.124236][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.124261][2333:2338] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326117.124288][2333:2338] CHIP:DIS: Discovered node without a pending query [1655326117.124318][2333:2338] CHIP:DIS: Discovery does not require any more timeouts [1655326117.124396][2333:2338] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.124443][2333:2338] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.124480][2333:2338] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326117.124542][2333:2338] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.124564][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.124584][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326117.124608][2333:2338] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.124642][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.124668][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326117.124692][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326117.124717][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326117.124746][2333:2338] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326117.124779][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.124809][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.124834][2333:2338] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326117.124858][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.124883][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.124908][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.124935][2333:2338] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.124966][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.124992][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326117.125022][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.125052][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.125076][2333:2338] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326117.125102][2333:2338] CHIP:DIS: Discovered node without a pending query [1655326117.125127][2333:2338] CHIP:DIS: Discovery does not require any more timeouts [1655326117.125271][2333:2338] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.125319][2333:2338] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.125356][2333:2338] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326117.125393][2333:2338] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.125421][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.125441][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326117.125466][2333:2338] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.125500][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.125526][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326117.125550][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326117.125574][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326117.125604][2333:2338] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326117.125637][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.125668][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.125693][2333:2338] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326117.125717][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.125741][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.125761][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.125783][2333:2338] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.125809][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.125834][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326117.125863][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.125893][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.125918][2333:2338] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326117.125944][2333:2338] CHIP:DIS: Discovered node without a pending query [1655326117.125969][2333:2338] CHIP:DIS: Discovery does not require any more timeouts [1655326117.126034][2333:2338] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.126078][2333:2338] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.126113][2333:2338] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326117.126151][2333:2338] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.126177][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.126201][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326117.126227][2333:2338] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.126259][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.126283][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326117.126307][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326117.126331][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326117.126359][2333:2338] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326117.126392][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.126422][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.126447][2333:2338] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326117.126471][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.126495][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.126525][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.126552][2333:2338] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.126578][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.126602][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326117.126632][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.126662][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.126687][2333:2338] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326117.126712][2333:2338] CHIP:DIS: Discovered node without a pending query [1655326117.126736][2333:2338] CHIP:DIS: Discovery does not require any more timeouts [1655326117.126795][2333:2338] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.126835][2333:2338] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.126871][2333:2338] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326117.126909][2333:2338] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.126935][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.126959][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326117.126985][2333:2338] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.127050][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.127100][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326117.127147][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326117.127193][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326117.127224][2333:2338] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326117.127257][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.127286][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.127309][2333:2338] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326117.127333][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.127356][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.127380][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.127405][2333:2338] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.127430][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.127450][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326117.127478][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.127507][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.127531][2333:2338] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326117.127555][2333:2338] CHIP:DIS: Discovered node without a pending query [1655326117.127579][2333:2338] CHIP:DIS: Discovery does not require any more timeouts [1655326117.127646][2333:2338] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.127688][2333:2338] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.127723][2333:2338] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326117.127760][2333:2338] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.127784][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.127807][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326117.127832][2333:2338] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.127863][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326117.127887][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326117.127912][2333:2338] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326117.127935][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326117.127961][2333:2338] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326117.127992][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.128021][2333:2338] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.128044][2333:2338] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326117.128067][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.128090][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.128113][2333:2338] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326117.128135][2333:2338] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326117.128159][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326117.128182][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326117.128211][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.128239][2333:2338] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326117.128263][2333:2338] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326117.128285][2333:2338] CHIP:DIS: Discovered node without a pending query [1655326117.128307][2333:2338] CHIP:DIS: Discovery does not require any more timeouts [1655326117.144473][2333:2338] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:193111247 on exchange 28756i [1655326117.144548][2333:2338] CHIP:EM: Found matching exchange: 28756i, Delegate: 0xffff94004370 [1655326117.144589][2333:2338] CHIP:EM: Rxd Ack; Removing MessageCounter:169366431 from Retrans Table on exchange 28756i [1655326117.144610][2333:2338] CHIP:EM: Removed CHIP MessageCounter:169366431 from RetransTable on exchange 28756i [1655326117.144642][2333:2338] CHIP:DMG: ICR moving to [ResponseRe] [1655326117.144689][2333:2338] CHIP:DMG: InvokeResponseMessage = [1655326117.144710][2333:2338] CHIP:DMG: { [1655326117.144730][2333:2338] CHIP:DMG: suppressResponse = false, [1655326117.144751][2333:2338] CHIP:DMG: InvokeResponseIBs = [1655326117.144778][2333:2338] CHIP:DMG: [ [1655326117.144799][2333:2338] CHIP:DMG: InvokeResponseIB = [1655326117.144828][2333:2338] CHIP:DMG: { [1655326117.144850][2333:2338] CHIP:DMG: CommandStatusIB = [1655326117.144876][2333:2338] CHIP:DMG: { [1655326117.144899][2333:2338] CHIP:DMG: CommandPathIB = [1655326117.144926][2333:2338] CHIP:DMG: { [1655326117.144954][2333:2338] CHIP:DMG: EndpointId = 0x1, [1655326117.144982][2333:2338] CHIP:DMG: ClusterId = 0x101, [1655326117.145009][2333:2338] CHIP:DMG: CommandId = 0x1a, [1655326117.145035][2333:2338] CHIP:DMG: }, [1655326117.145065][2333:2338] CHIP:DMG: [1655326117.145088][2333:2338] CHIP:DMG: StatusIB = [1655326117.145115][2333:2338] CHIP:DMG: { [1655326117.145143][2333:2338] CHIP:DMG: status = 0x00 (SUCCESS), [1655326117.145169][2333:2338] CHIP:DMG: }, [1655326117.145195][2333:2338] CHIP:DMG: [1655326117.145218][2333:2338] CHIP:DMG: }, [1655326117.145245][2333:2338] CHIP:DMG: [1655326117.145266][2333:2338] CHIP:DMG: }, [1655326117.145293][2333:2338] CHIP:DMG: [1655326117.145312][2333:2338] CHIP:DMG: ], [1655326117.145339][2333:2338] CHIP:DMG: [1655326117.145359][2333:2338] CHIP:DMG: InteractionModelRevision = 1 [1655326117.145378][2333:2338] CHIP:DMG: }, [1655326117.145433][2333:2338] CHIP:DMG: Received Command Response Status for Endpoint=1 Cluster=0x0000_0101 Command=0x0000_001A Status=0x0 [1655326117.145471][2333:2338] CHIP:DMG: ICR moving to [AwaitingDe] [1655326117.145523][2333:2338] CHIP:EM: Sending Standalone Ack for MessageCounter:193111247 on exchange 28756i [1655326117.145598][2333:2338] CHIP:IN: Prepared secure message 0xffffa920f9d8 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 28756i with MessageCounter:169366432. [1655326117.145633][2333:2338] CHIP:IN: Sending encrypted msg 0xffffa920f9d8 with MessageCounter:169366432 to 0x0000000000000001 (1) at monotonic time: 00000000000F6EE5 msec [1655326117.145772][2333:2338] CHIP:EM: Flushed pending ack for MessageCounter:193111247 on exchange 28756i [1655326117.145977][2333:2333] CHIP:CTL: Shutting down the commissioner [1655326117.146106][2333:2333] CHIP:CTL: Shutting down the controller [1655326117.146139][2333:2333] CHIP:CTL: Shutting down the commissioner [1655326117.146218][2333:2333] CHIP:CTL: Shutting down the controller [1655326117.146252][2333:2333] CHIP:IN: Expiring all connections for fabric 1!! [1655326117.146276][2333:2333] CHIP:IN: SecureSession[0xaaaaee8ddcf0]: MarkForRemoval Type:2 LSID:44400 [1655326117.146299][2333:2333] CHIP:IN: SecureSession[0xaaaaee8ddcf0]: Released - Type:2 LSID:44400 [1655326117.146347][2333:2333] CHIP:CTL: Shutting down the commissioner [1655326117.146427][2333:2333] CHIP:CTL: Shutting down the controller [1655326117.146450][2333:2333] CHIP:IN: Expiring all connections for fabric 2!! [1655326117.146486][2333:2333] CHIP:CTL: Shutting down the commissioner [1655326117.146577][2333:2333] CHIP:CTL: Shutting down the controller [1655326117.146600][2333:2333] CHIP:IN: Expiring all connections for fabric 3!! [1655326117.146629][2333:2333] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655326117.147419][2333:2333] CHIP:DMG: IM WH moving to [Uninitialized] [1655326117.147592][2333:2333] CHIP:DMG: IM WH moving to [Uninitialized] [1655326117.147633][2333:2333] CHIP:DMG: IM WH moving to [Uninitialized] [1655326117.147654][2333:2333] CHIP:DMG: IM WH moving to [Uninitialized] [1655326117.147676][2333:2333] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655326117.147883][2333:2333] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655326117.148593][2333:2333] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-PNc0sZ) [1655326117.149686][2333:2333] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655326117.149754][2333:2333] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655326117.149781][2333:2333] CHIP:DL: Inet Layer shutdown [1655326117.149803][2333:2333] CHIP:DL: BLE shutdown [1655326117.149826][2333:2333] CHIP:DL: System Layer shutdown ----- pi@ubuntu:~$ ./chip-tool doorlock get-user 1 1 1 [1655326163.959791][2342:2342] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655326163.960350][2342:2342] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655326163.960569][2342:2342] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655326163.960689][2342:2342] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655326163.961028][2342:2342] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-OOJkyI) [1655326163.961623][2342:2342] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655326163.961678][2342:2342] CHIP:DL: NVS set: chip-counters/reboot-count = 5 (0x5) [1655326163.962303][2342:2342] CHIP:DL: Got Ethernet interface: eth0 [1655326163.962797][2342:2342] CHIP:DL: Found the primary Ethernet interface:eth0 [1655326163.963202][2342:2342] CHIP:DL: Got WiFi interface: wlan0 [1655326163.963276][2342:2342] CHIP:DL: Failed to reset WiFi statistic counts [1655326163.963352][2342:2342] CHIP:IN: UDP::Init bind&listen port=0 [1655326163.963476][2342:2342] CHIP:IN: UDP::Init bound to port=37513 [1655326163.963503][2342:2342] CHIP:IN: UDP::Init bind&listen port=0 [1655326163.963602][2342:2342] CHIP:IN: UDP::Init bound to port=57693 [1655326163.963627][2342:2342] CHIP:IN: BLEBase::Init - setting/overriding transport [1655326163.963648][2342:2342] CHIP:IN: TransportMgr initialized [1655326163.963697][2342:2342] CHIP:FP: Initializing FabricTable from persistent storage [1655326163.963868][2342:2342] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326163.963958][2342:2342] CHIP:FP: Loading from storage for fabric index 0x1 [1655326163.964421][2342:2342] CHIP:FP: Loading from storage for fabric index 0x2 [1655326163.964821][2342:2342] CHIP:FP: Loading from storage for fabric index 0x3 [1655326163.968018][2342:2342] CHIP:ZCL: Using ZAP configuration... [1655326163.970342][2342:2342] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1655326163.972525][2342:2342] CHIP:DL: MDNS failed to join multicast group on wpan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1655326163.972872][2342:2342] CHIP:CTL: System State Initialized... [1655326163.972933][2342:2342] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326163.972997][2342:2342] CHIP:CTL: Setting attestation nonce to random value [1655326163.973062][2342:2342] CHIP:CTL: Setting CSR nonce to random value [1655326163.973139][2342:2342] CHIP:IN: UDP::Init bind&listen port=5550 [1655326163.973242][2342:2342] CHIP:IN: UDP::Init bound to port=5550 [1655326163.973269][2342:2342] CHIP:IN: UDP::Init bind&listen port=5550 [1655326163.973358][2342:2342] CHIP:IN: UDP::Init bound to port=5550 [1655326163.973383][2342:2342] CHIP:IN: TransportMgr initialized [1655326163.973438][2342:2342] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326163.973468][2342:2342] CHIP:CTL: Setting attestation nonce to random value [1655326163.973518][2342:2342] CHIP:CTL: Setting CSR nonce to random value [1655326163.977673][2342:2342] CHIP:CTL: Generating NOC [1655326163.978540][2342:2342] CHIP:FP: Validating NOC chain [1655326163.980280][2342:2342] CHIP:FP: NOC chain validation successful [1655326163.980442][2342:2342] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655326163.980470][2342:2342] CHIP:FP: Assigned compressed fabric ID: 0x3507FA7A67620D99, node ID: 0x000000000001B669 [1655326163.986598][2342:2342] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655326163.986691][2342:2342] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326163.986713][2342:2342] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326163.986730][2342:2342] CHIP:TS: Retaining current Last Known Good Time [1655326163.988233][2342:2342] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x3507FA7A67620D99 [1655326163.988312][2342:2342] CHIP:IN: UDP::Init bind&listen port=5550 [1655326163.988461][2342:2342] CHIP:IN: UDP::Init bound to port=5550 [1655326163.988504][2342:2342] CHIP:IN: UDP::Init bind&listen port=5550 [1655326163.988598][2342:2342] CHIP:IN: UDP::Init bound to port=5550 [1655326163.988622][2342:2342] CHIP:IN: TransportMgr initialized [1655326163.988726][2342:2342] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326163.988767][2342:2342] CHIP:CTL: Setting attestation nonce to random value [1655326163.988828][2342:2342] CHIP:CTL: Setting CSR nonce to random value [1655326163.989801][2342:2342] CHIP:CTL: Generating NOC [1655326163.990614][2342:2342] CHIP:FP: Validating NOC chain [1655326163.992325][2342:2342] CHIP:FP: NOC chain validation successful [1655326163.992502][2342:2342] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655326163.992535][2342:2342] CHIP:FP: Assigned compressed fabric ID: 0xD4B726C925D03E8C, node ID: 0x000000000001B669 [1655326164.045187][2342:2342] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655326164.045240][2342:2342] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326164.045264][2342:2342] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326164.045286][2342:2342] CHIP:TS: Retaining current Last Known Good Time [1655326164.046708][2342:2342] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0xD4B726C925D03E8C [1655326164.046820][2342:2342] CHIP:IN: UDP::Init bind&listen port=5550 [1655326164.046959][2342:2342] CHIP:IN: UDP::Init bound to port=5550 [1655326164.046987][2342:2342] CHIP:IN: UDP::Init bind&listen port=5550 [1655326164.047081][2342:2342] CHIP:IN: UDP::Init bound to port=5550 [1655326164.047106][2342:2342] CHIP:IN: TransportMgr initialized [1655326164.047215][2342:2342] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326164.047257][2342:2342] CHIP:CTL: Setting attestation nonce to random value [1655326164.047316][2342:2342] CHIP:CTL: Setting CSR nonce to random value [1655326164.048287][2342:2342] CHIP:CTL: Generating NOC [1655326164.049167][2342:2342] CHIP:FP: Validating NOC chain [1655326164.050915][2342:2342] CHIP:FP: NOC chain validation successful [1655326164.051074][2342:2342] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655326164.051102][2342:2342] CHIP:FP: Assigned compressed fabric ID: 0xF2495982D9C810C1, node ID: 0x000000000001B669 [1655326164.056214][2342:2342] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655326164.056265][2342:2342] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326164.056289][2342:2342] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326164.056311][2342:2342] CHIP:TS: Retaining current Last Known Good Time [1655326164.057696][2342:2342] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0xF2495982D9C810C1 [1655326164.057773][2342:2342] CHIP:IN: UDP::Init bind&listen port=5550 [1655326164.057909][2342:2342] CHIP:IN: UDP::Init bound to port=5550 [1655326164.057937][2342:2342] CHIP:IN: UDP::Init bind&listen port=5550 [1655326164.058028][2342:2342] CHIP:IN: UDP::Init bound to port=5550 [1655326164.058053][2342:2342] CHIP:IN: TransportMgr initialized [1655326164.099921][2342:2347] CHIP:DL: CHIP task running [1655326164.100456][2342:2347] CHIP:TOO: Sending command to node 0x1 [1655326164.100531][2342:2347] CHIP:CSM: FindOrEstablishSession: PeerId = 3507FA7A67620D99:0000000000000001 [1655326164.100556][2342:2347] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655326164.100594][2342:2347] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 1 --> 2 [1655326164.100648][2342:2347] CHIP:DIS: MINMDNS: Sending query ANY/UNICAST for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.101435][2342:2347] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1655326164.102120][2342:2347] CHIP:DIS: mDNS broadcast had only partial success: 7 successes and 1 failures. [1655326164.202386][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 53.0.16.172.in-addr.arpa [1655326164.202462][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.e.f.3.8.5.e.f.f.f.1.0.f.5.6.e.0.0.0.0.0.0.0.0.3.3.0.0.1.1.d.f.ip6.arpa [1655326164.202545][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 53.0.16.172.in-addr.arpa [1655326164.202577][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.e.f.3.8.5.e.f.f.f.1.0.f.5.6.e.0.0.0.0.0.0.0.0.3.3.0.0.1.1.d.f.ip6.arpa [1655326164.202704][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.e.f.3.8.5.e.f.f.f.1.0.f.5.6.e.0.0.0.0.0.0.0.0.3.3.0.0.1.1.d.f.ip6.arpa [1655326164.202795][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.e.f.3.8.5.e.f.f.f.1.0.f.5.6.e.0.0.0.0.0.0.0.0.3.3.0.0.1.1.d.f.ip6.arpa [1655326164.202865][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.e.f.3.8.5.e.f.f.f.1.0.f.5.6.e.0.0.0.0.0.0.0.0.3.3.0.0.1.1.d.f.ip6.arpa [1655326164.202931][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.e.f.3.8.5.e.f.f.f.1.0.f.5.6.e.0.0.0.0.0.0.0.0.3.3.0.0.1.1.d.f.ip6.arpa [1655326164.265570][2342:2347] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.265654][2342:2347] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.265696][2342:2347] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326164.265727][2342:2347] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.265751][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.265772][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326164.265794][2342:2347] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.265828][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.265856][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326164.265881][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326164.265902][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326164.265931][2342:2347] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326164.265954][2342:2347] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326164.265989][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.266010][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.266031][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.266055][2342:2347] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.266077][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.266098][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326164.266123][2342:2347] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326164.266741][2342:2347] CHIP:DIS: Lookup clearing interface for non LL address [1655326164.266785][2342:2347] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: new best score: 6 [1655326164.266811][2342:2347] CHIP:DIS: Checking node lookup status after 166 ms [1655326164.266834][2342:2347] CHIP:DIS: Keeping DNSSD lookup active [1655326164.266940][2342:2347] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.266992][2342:2347] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.267031][2342:2347] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326164.267076][2342:2347] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.267105][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.267130][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326164.267155][2342:2347] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.267201][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.267228][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326164.267254][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326164.267277][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326164.267319][2342:2347] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326164.267346][2342:2347] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326164.267371][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.267396][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.267420][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.267457][2342:2347] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.267483][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.267508][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326164.267541][2342:2347] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326164.267568][2342:2347] CHIP:DIS: Discovered node without a pending query [1655326164.268019][2342:2347] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: score has not improved: 6 [1655326164.268057][2342:2347] CHIP:DIS: Checking node lookup status after 167 ms [1655326164.268081][2342:2347] CHIP:DIS: Keeping DNSSD lookup active [1655326164.268254][2342:2347] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.268306][2342:2347] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.268356][2342:2347] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326164.268390][2342:2347] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.268416][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.268450][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326164.268476][2342:2347] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.268573][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.268611][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326164.268637][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326164.268661][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326164.268691][2342:2347] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326164.268727][2342:2347] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326164.268753][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.268778][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.268802][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.268829][2342:2347] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.268855][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.268891][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326164.268916][2342:2347] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326164.268942][2342:2347] CHIP:DIS: Discovered node without a pending query [1655326164.269393][2342:2347] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: score has not improved: 6 [1655326164.269431][2342:2347] CHIP:DIS: Checking node lookup status after 168 ms [1655326164.269454][2342:2347] CHIP:DIS: Keeping DNSSD lookup active [1655326164.269538][2342:2347] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.269596][2342:2347] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.269634][2342:2347] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326164.269678][2342:2347] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.269706][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.269730][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326164.269755][2342:2347] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.269789][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.269826][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326164.269852][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326164.269875][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326164.269904][2342:2347] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326164.269941][2342:2347] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326164.269966][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.269990][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.270015][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.270041][2342:2347] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.270078][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.270102][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326164.270127][2342:2347] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326164.270161][2342:2347] CHIP:DIS: Discovered node without a pending query [1655326164.270569][2342:2347] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: score has not improved: 6 [1655326164.270605][2342:2347] CHIP:DIS: Checking node lookup status after 170 ms [1655326164.270627][2342:2347] CHIP:DIS: Keeping DNSSD lookup active [1655326164.270706][2342:2347] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.270761][2342:2347] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.270799][2342:2347] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326164.270842][2342:2347] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.270869][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.270893][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326164.270919][2342:2347] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.270964][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.270990][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326164.271014][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326164.271037][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326164.271076][2342:2347] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326164.271104][2342:2347] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326164.271128][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.271152][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.271177][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.271213][2342:2347] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.271239][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.271264][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326164.271288][2342:2347] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326164.271322][2342:2347] CHIP:DIS: Discovered node without a pending query [1655326164.271720][2342:2347] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: score has not improved: 6 [1655326164.271752][2342:2347] CHIP:DIS: Checking node lookup status after 171 ms [1655326164.271775][2342:2347] CHIP:DIS: Keeping DNSSD lookup active [1655326164.271854][2342:2347] CHIP:DIS: MINMDNS: received SRV record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.271909][2342:2347] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.271946][2342:2347] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326164.271989][2342:2347] CHIP:DIS: MINMDNS: received TXT record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.272017][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.272041][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _meshcop._udp.local [1655326164.272075][2342:2347] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.272109][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _services._dns-sd._udp.local [1655326164.272135][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _I3507FA7A67620D99._sub._matter._tcp.local [1655326164.272159][2342:2347] CHIP:DIS: MINMDNS: received PTR record for _matter._tcp.local [1655326164.272183][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326164.272222][2342:2347] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326164.272248][2342:2347] CHIP:DIS: MINMDNS: received A record for ubuntu.local [1655326164.272272][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.272297][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.272333][2342:2347] CHIP:DIS: MINMDNS: received AAAA record for ubuntu.local [1655326164.272361][2342:2347] CHIP:DIS: MINMDNS: received (47) record for OpenThread_BorderRouter._meshcop._udp.local [1655326164.272387][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326164.272411][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 4E9F38BA038A7528.local [1655326164.272448][2342:2347] CHIP:DIS: MINMDNS: received (47) record for ubuntu.local [1655326164.272474][2342:2347] CHIP:DIS: Discovered node without a pending query [1655326164.272906][2342:2347] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: score has not improved: 6 [1655326164.272941][2342:2347] CHIP:DIS: Checking node lookup status after 172 ms [1655326164.272963][2342:2347] CHIP:DIS: Keeping DNSSD lookup active [1655326164.301133][2342:2347] CHIP:DIS: Checking node lookup status after 200 ms [1655326164.301183][2342:2347] CHIP:CTL: Updating device address to UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76]:5540 while in state 2 [1655326164.301207][2342:2347] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 2 --> 3 [1655326164.301418][2342:2347] CHIP:IN: SecureSession[0xaaab13ed3590]: Allocated Type:2 LSID:32774 [1655326164.301459][2342:2347] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655326164.302197][2342:2347] CHIP:SC: Including MRP parameters [1655326164.302424][2342:2347] CHIP:IN: Prepared unauthenticated message 0xaaab13ed18c8 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 63898i with MessageCounter:22769304. [1655326164.302474][2342:2347] CHIP:IN: Sending unauthenticated msg 0xaaab13ed18c8 with MessageCounter:22769304 to 0x0000000000000000 at monotonic time: 0000000000102719 msec [1655326164.302717][2342:2347] CHIP:SC: Sent Sigma1 msg [1655326164.302758][2342:2347] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 3 --> 4 [1655326164.302789][2342:2347] CHIP:DIS: Discovery does not require any more timeouts [1655326164.366042][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366099][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366134][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366165][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366240][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366276][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366309][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366340][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366470][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366523][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366557][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366587][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366669][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366705][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366747][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366778][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366859][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366894][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366925][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.366955][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.367035][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.367069][2342:2347] CHIP:DIS: MINMDNS: received PTR record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.367100][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.E.F.3.8.5.E.F.F.F.1.0.F.5.6.E.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.367140][2342:2347] CHIP:DIS: MINMDNS: received (47) record for 3.8.4.7.D.2.3.8.5.0.5.F.7.7.0.6.0.0.0.0.0.0.0.0.0.0.0.0.0.8.E.F.ip6.arpa [1655326164.427772][2342:2347] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:158284784 on exchange 63898i [1655326164.427827][2342:2347] CHIP:EM: Found matching exchange: 63898i, Delegate: 0xffff6c001c60 [1655326164.427869][2342:2347] CHIP:EM: Rxd Ack; Removing MessageCounter:22769304 from Retrans Table on exchange 63898i [1655326164.427926][2342:2347] CHIP:EM: Removed CHIP MessageCounter:22769304 from RetransTable on exchange 63898i [1655326164.447693][2342:2347] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:158284785 on exchange 63898i [1655326164.447868][2342:2347] CHIP:EM: Found matching exchange: 63898i, Delegate: 0xffff6c001c60 [1655326164.447931][2342:2347] CHIP:EM: CHIP MessageCounter:22769304 not in RetransTable on exchange 63898i [1655326164.448002][2342:2347] CHIP:SC: Received Sigma2Resume msg [1655326164.448170][2342:2347] CHIP:SC: Found MRP parameters in the message [1655326164.448219][2342:2347] CHIP:SC: Peer assigned session session ID 39511 [1655326164.453176][2342:2347] CHIP:SC: Sending status report. Protocol code 0, exchange 63898 [1655326164.453248][2342:2347] CHIP:EM: Piggybacking Ack for MessageCounter:158284785 on exchange: 63898i [1655326164.453297][2342:2347] CHIP:IN: Prepared unauthenticated message 0xaaab13ed18c8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 63898i with MessageCounter:22769305. [1655326164.453349][2342:2347] CHIP:IN: Sending unauthenticated msg 0xaaab13ed18c8 with MessageCounter:22769305 to 0x0000000000000000 at monotonic time: 00000000001027B0 msec [1655326164.453678][2342:2347] CHIP:IN: SecureSession[0xaaab13ed3590]: Activated - Type:2 LSID:32774 [1655326164.453722][2342:2347] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:32774 PSID:39511! [1655326164.453756][2342:2347] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 4 --> 5 [1655326164.453807][2342:2347] CHIP:TOO: Sending cluster (0x00000101) command (0x0000001B) on endpoint 1 [1655326164.453867][2342:2347] CHIP:DMG: ICR moving to [AddingComm] [1655326164.453930][2342:2347] CHIP:DMG: ICR moving to [AddedComma] [1655326164.454046][2342:2347] CHIP:IN: Prepared secure message 0xaaab13ed18e8 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 63899i with MessageCounter:237689839. [1655326164.454091][2342:2347] CHIP:IN: Sending encrypted msg 0xaaab13ed18e8 with MessageCounter:237689839 to 0x0000000000000001 (1) at monotonic time: 00000000001027B1 msec [1655326164.454309][2342:2347] CHIP:DMG: ICR moving to [CommandSen] [1655326164.507718][2342:2347] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:158284786 on exchange 63898i [1655326164.507776][2342:2347] CHIP:EM: Found matching exchange: 63898i, Delegate: (nil) [1655326164.507825][2342:2347] CHIP:EM: Rxd Ack; Removing MessageCounter:22769305 from Retrans Table on exchange 63898i [1655326164.507852][2342:2347] CHIP:EM: Removed CHIP MessageCounter:22769305 from RetransTable on exchange 63898i [1655326164.557550][2342:2347] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:80556781 on exchange 63899i [1655326164.557601][2342:2347] CHIP:EM: Found matching exchange: 63899i, Delegate: 0xffff6c005b80 [1655326164.557644][2342:2347] CHIP:EM: Rxd Ack; Removing MessageCounter:237689839 from Retrans Table on exchange 63899i [1655326164.557670][2342:2347] CHIP:EM: Removed CHIP MessageCounter:237689839 from RetransTable on exchange 63899i [1655326164.557708][2342:2347] CHIP:DMG: ICR moving to [ResponseRe] [1655326164.557763][2342:2347] CHIP:DMG: InvokeResponseMessage = [1655326164.557789][2342:2347] CHIP:DMG: { [1655326164.557813][2342:2347] CHIP:DMG: suppressResponse = false, [1655326164.557838][2342:2347] CHIP:DMG: InvokeResponseIBs = [1655326164.557874][2342:2347] CHIP:DMG: [ [1655326164.557899][2342:2347] CHIP:DMG: InvokeResponseIB = [1655326164.557938][2342:2347] CHIP:DMG: { [1655326164.557966][2342:2347] CHIP:DMG: CommandDataIB = [1655326164.557998][2342:2347] CHIP:DMG: { [1655326164.558027][2342:2347] CHIP:DMG: CommandPathIB = [1655326164.558064][2342:2347] CHIP:DMG: { [1655326164.558098][2342:2347] CHIP:DMG: EndpointId = 0x1, [1655326164.558133][2342:2347] CHIP:DMG: ClusterId = 0x101, [1655326164.558166][2342:2347] CHIP:DMG: CommandId = 0x1c, [1655326164.558196][2342:2347] CHIP:DMG: }, [1655326164.558229][2342:2347] CHIP:DMG: [1655326164.558258][2342:2347] CHIP:DMG: CommandFields = [1655326164.558288][2342:2347] CHIP:DMG: { [1655326164.558346][2342:2347] CHIP:DMG: 0x0 = 1, [1655326164.558382][2342:2347] CHIP:DMG: 0x1 = "xxx", [1655326164.558415][2342:2347] CHIP:DMG: 0x2 = 6452, [1655326164.558448][2342:2347] CHIP:DMG: 0x3 = 1, [1655326164.558480][2342:2347] CHIP:DMG: 0x4 = 0, [1655326164.558511][2342:2347] CHIP:DMG: 0x5 = 0, [1655326164.558543][2342:2347] CHIP:DMG: 0x7 = 1, [1655326164.558576][2342:2347] CHIP:DMG: 0x8 = 1, [1655326164.558607][2342:2347] CHIP:DMG: }, [1655326164.558635][2342:2347] CHIP:DMG: }, [1655326164.558670][2342:2347] CHIP:DMG: [1655326164.558696][2342:2347] CHIP:DMG: }, [1655326164.558730][2342:2347] CHIP:DMG: [1655326164.558754][2342:2347] CHIP:DMG: ], [1655326164.558787][2342:2347] CHIP:DMG: [1655326164.558811][2342:2347] CHIP:DMG: InteractionModelRevision = 1 [1655326164.558835][2342:2347] CHIP:DMG: }, [1655326164.558904][2342:2347] CHIP:DMG: Received Command Response Data, Endpoint=1 Cluster=0x0000_0101 Command=0x0000_001C [1655326164.558948][2342:2347] CHIP:TOO: Endpoint: 1 Cluster: 0x0000_0101 Command 0x0000_001C [1655326164.559126][2342:2347] CHIP:TOO: GetUserResponse: { [1655326164.559164][2342:2347] CHIP:TOO: userIndex: 1 [1655326164.559189][2342:2347] CHIP:TOO: userName: xxx [1655326164.559214][2342:2347] CHIP:TOO: userUniqueId: 6452 [1655326164.559240][2342:2347] CHIP:TOO: userStatus: 1 [1655326164.559264][2342:2347] CHIP:TOO: userType: 0 [1655326164.559287][2342:2347] CHIP:TOO: credentialRule: 0 [1655326164.559311][2342:2347] CHIP:TOO: credentials: null [1655326164.559336][2342:2347] CHIP:TOO: creatorFabricIndex: 1 [1655326164.559360][2342:2347] CHIP:TOO: lastModifiedFabricIndex: 1 [1655326164.559383][2342:2347] CHIP:TOO: nextUserIndex: null [1655326164.559407][2342:2347] CHIP:TOO: } [1655326164.559450][2342:2347] CHIP:DMG: ICR moving to [AwaitingDe] [1655326164.559499][2342:2347] CHIP:EM: Sending Standalone Ack for MessageCounter:80556781 on exchange 63899i [1655326164.559573][2342:2347] CHIP:IN: Prepared secure message 0xffff819e69d8 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 63899i with MessageCounter:237689840. [1655326164.559613][2342:2347] CHIP:IN: Sending encrypted msg 0xffff819e69d8 with MessageCounter:237689840 to 0x0000000000000001 (1) at monotonic time: 000000000010281B msec [1655326164.559748][2342:2347] CHIP:EM: Flushed pending ack for MessageCounter:80556781 on exchange 63899i [1655326164.559938][2342:2342] CHIP:CTL: Shutting down the commissioner [1655326164.560058][2342:2342] CHIP:CTL: Shutting down the controller [1655326164.560085][2342:2342] CHIP:CTL: Shutting down the commissioner [1655326164.560156][2342:2342] CHIP:CTL: Shutting down the controller [1655326164.560185][2342:2342] CHIP:IN: Expiring all connections for fabric 1!! [1655326164.560206][2342:2342] CHIP:IN: SecureSession[0xaaab13ed3590]: MarkForRemoval Type:2 LSID:32774 [1655326164.560225][2342:2342] CHIP:IN: SecureSession[0xaaab13ed3590]: Released - Type:2 LSID:32774 [1655326164.560267][2342:2342] CHIP:CTL: Shutting down the commissioner [1655326164.560342][2342:2342] CHIP:CTL: Shutting down the controller [1655326164.560361][2342:2342] CHIP:IN: Expiring all connections for fabric 2!! [1655326164.560393][2342:2342] CHIP:CTL: Shutting down the commissioner [1655326164.560479][2342:2342] CHIP:CTL: Shutting down the controller [1655326164.560540][2342:2342] CHIP:IN: Expiring all connections for fabric 3!! [1655326164.560567][2342:2342] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655326164.561031][2342:2342] CHIP:DMG: IM WH moving to [Uninitialized] [1655326164.561056][2342:2342] CHIP:DMG: IM WH moving to [Uninitialized] [1655326164.561073][2342:2342] CHIP:DMG: IM WH moving to [Uninitialized] [1655326164.561089][2342:2342] CHIP:DMG: IM WH moving to [Uninitialized] [1655326164.561107][2342:2342] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655326164.561222][2342:2342] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655326164.561467][2342:2342] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-FqYcnw) [1655326164.562205][2342:2342] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655326164.562277][2342:2342] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655326164.562304][2342:2342] CHIP:DL: Inet Layer shutdown [1655326164.562327][2342:2342] CHIP:DL: BLE shutdown [1655326164.562351][2342:2342] CHIP:DL: System Layer shutdown ----- pi@ubuntu:~$ ./chip-tool doorlock set-user 0 2 xxx 6451 1 10 3 1 1 --timedInteractionTimeoutMs 1000 [1655326494.682174][2424:2424] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655326494.682743][2424:2424] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655326494.682959][2424:2424] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655326494.683076][2424:2424] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655326494.683536][2424:2424] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ajd08V) [1655326494.684154][2424:2424] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655326494.684210][2424:2424] CHIP:DL: NVS set: chip-counters/reboot-count = 6 (0x6) [1655326494.684942][2424:2424] CHIP:DL: Got Ethernet interface: eth0 [1655326494.685347][2424:2424] CHIP:DL: Found the primary Ethernet interface:eth0 [1655326494.685831][2424:2424] CHIP:DL: Got WiFi interface: wlan0 [1655326494.685907][2424:2424] CHIP:DL: Failed to reset WiFi statistic counts [1655326494.685986][2424:2424] CHIP:IN: UDP::Init bind&listen port=0 [1655326494.686118][2424:2424] CHIP:IN: UDP::Init bound to port=41238 [1655326494.686145][2424:2424] CHIP:IN: UDP::Init bind&listen port=0 [1655326494.686279][2424:2424] CHIP:IN: UDP::Init bound to port=50321 [1655326494.686306][2424:2424] CHIP:IN: BLEBase::Init - setting/overriding transport [1655326494.686328][2424:2424] CHIP:IN: TransportMgr initialized [1655326494.686384][2424:2424] CHIP:FP: Initializing FabricTable from persistent storage [1655326494.686588][2424:2424] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326494.686709][2424:2424] CHIP:FP: Loading from storage for fabric index 0x1 [1655326494.687203][2424:2424] CHIP:FP: Loading from storage for fabric index 0x2 [1655326494.687596][2424:2424] CHIP:FP: Loading from storage for fabric index 0x3 [1655326494.690713][2424:2424] CHIP:ZCL: Using ZAP configuration... [1655326494.693075][2424:2424] CHIP:DL: MDNS failed to join multicast group on wlan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1655326494.695544][2424:2424] CHIP:DL: MDNS failed to join multicast group on wpan0 for address type IPv4: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:772: Inet Error 0x00000110: Address not found [1655326494.695931][2424:2424] CHIP:CTL: System State Initialized... [1655326494.695994][2424:2424] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326494.696059][2424:2424] CHIP:CTL: Setting attestation nonce to random value [1655326494.696182][2424:2424] CHIP:CTL: Setting CSR nonce to random value [1655326494.696262][2424:2424] CHIP:IN: UDP::Init bind&listen port=5550 [1655326494.696364][2424:2424] CHIP:IN: UDP::Init bound to port=5550 [1655326494.696391][2424:2424] CHIP:IN: UDP::Init bind&listen port=5550 [1655326494.696541][2424:2424] CHIP:IN: UDP::Init bound to port=5550 [1655326494.696570][2424:2424] CHIP:IN: TransportMgr initialized [1655326494.696653][2424:2424] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326494.696734][2424:2424] CHIP:CTL: Setting attestation nonce to random value [1655326494.696788][2424:2424] CHIP:CTL: Setting CSR nonce to random value [1655326494.699579][2424:2424] CHIP:CTL: Generating NOC [1655326494.700434][2424:2424] CHIP:FP: Validating NOC chain [1655326494.702285][2424:2424] CHIP:FP: NOC chain validation successful [1655326494.702452][2424:2424] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655326494.702481][2424:2424] CHIP:FP: Assigned compressed fabric ID: 0x3507FA7A67620D99, node ID: 0x000000000001B669 [1655326494.711871][2424:2424] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655326494.711927][2424:2424] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326494.711952][2424:2424] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326494.711973][2424:2424] CHIP:TS: Retaining current Last Known Good Time [1655326494.713739][2424:2424] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x3507FA7A67620D99 [1655326494.713822][2424:2424] CHIP:IN: UDP::Init bind&listen port=5550 [1655326494.713966][2424:2424] CHIP:IN: UDP::Init bound to port=5550 [1655326494.713994][2424:2424] CHIP:IN: UDP::Init bind&listen port=5550 [1655326494.714085][2424:2424] CHIP:IN: UDP::Init bound to port=5550 [1655326494.714109][2424:2424] CHIP:IN: TransportMgr initialized [1655326494.714215][2424:2424] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326494.714365][2424:2424] CHIP:CTL: Setting attestation nonce to random value [1655326494.714429][2424:2424] CHIP:CTL: Setting CSR nonce to random value [1655326494.715375][2424:2424] CHIP:CTL: Generating NOC [1655326494.716235][2424:2424] CHIP:FP: Validating NOC chain [1655326494.718013][2424:2424] CHIP:FP: NOC chain validation successful [1655326494.718180][2424:2424] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655326494.718208][2424:2424] CHIP:FP: Assigned compressed fabric ID: 0xD4B726C925D03E8C, node ID: 0x000000000001B669 [1655326494.723168][2424:2424] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655326494.723218][2424:2424] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326494.723242][2424:2424] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326494.723263][2424:2424] CHIP:TS: Retaining current Last Known Good Time [1655326494.724652][2424:2424] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0xD4B726C925D03E8C [1655326494.724733][2424:2424] CHIP:IN: UDP::Init bind&listen port=5550 [1655326494.724872][2424:2424] CHIP:IN: UDP::Init bound to port=5550 [1655326494.724900][2424:2424] CHIP:IN: UDP::Init bind&listen port=5550 [1655326494.724995][2424:2424] CHIP:IN: UDP::Init bound to port=5550 [1655326494.725020][2424:2424] CHIP:IN: TransportMgr initialized [1655326494.725194][2424:2424] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655326494.725237][2424:2424] CHIP:CTL: Setting attestation nonce to random value [1655326494.725330][2424:2424] CHIP:CTL: Setting CSR nonce to random value [1655326494.726238][2424:2424] CHIP:CTL: Generating NOC [1655326494.727141][2424:2424] CHIP:FP: Validating NOC chain [1655326494.728898][2424:2424] CHIP:FP: NOC chain validation successful [1655326494.729066][2424:2424] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655326494.729094][2424:2424] CHIP:FP: Assigned compressed fabric ID: 0xF2495982D9C810C1, node ID: 0x000000000001B669 [1655326494.734067][2424:2424] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655326494.734119][2424:2424] CHIP:TS: Last Known Good Time: 2022-06-16T10:33:40 [1655326494.734143][2424:2424] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655326494.734164][2424:2424] CHIP:TS: Retaining current Last Known Good Time [1655326494.735508][2424:2424] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0xF2495982D9C810C1 [1655326494.735585][2424:2424] CHIP:IN: UDP::Init bind&listen port=5550 [1655326494.735721][2424:2424] CHIP:IN: UDP::Init bound to port=5550 [1655326494.735748][2424:2424] CHIP:IN: UDP::Init bind&listen port=5550 [1655326494.735844][2424:2424] CHIP:IN: UDP::Init bound to port=5550 [1655326494.735869][2424:2424] CHIP:IN: TransportMgr initialized [1655326494.766068][2424:2429] CHIP:DL: CHIP task running [1655326494.766206][2424:2429] CHIP:TOO: Sending command to node 0x1 [1655326494.766249][2424:2429] CHIP:CSM: FindOrEstablishSession: PeerId = 3507FA7A67620D99:0000000000000001 [1655326494.766275][2424:2429] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655326494.766400][2424:2429] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 1 --> 2 [1655326494.766475][2424:2429] CHIP:DIS: MINMDNS: Sending query ANY/UNICAST for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326494.767122][2424:2429] CHIP:DIS: Warning: Attempt to mDNS broadcast failed on wlan0: ../../examples/chip-tool/third_party/connectedhomeip/src/inet/UDPEndPointImplSockets.cpp:417: OS Error 0x02000065: Network is unreachable [1655326494.767464][2424:2429] CHIP:DIS: mDNS broadcast had only partial success: 7 successes and 1 failures. [1655326494.768576][2424:2429] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326494.768641][2424:2429] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326494.768675][2424:2429] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326494.768721][2424:2429] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326494.768757][2424:2429] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326494.769394][2424:2429] CHIP:DIS: Lookup clearing interface for non LL address [1655326494.769443][2424:2429] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: new best score: 6 [1655326494.769473][2424:2429] CHIP:DIS: Checking node lookup status after 3 ms [1655326494.769497][2424:2429] CHIP:DIS: Keeping DNSSD lookup active [1655326494.769685][2424:2429] CHIP:DIS: MINMDNS: received SRV record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326494.769743][2424:2429] CHIP:DIS: MINMDNS: Operational SRV for 3507FA7A67620D99-0000000000000001: 4E9F38BA038A7528.local [1655326494.769776][2424:2429] CHIP:DIS: MINMDNS: received TXT record for 3507FA7A67620D99-0000000000000001._matter._tcp.local [1655326494.769819][2424:2429] CHIP:DIS: MINMDNS: received AAAA record for 4E9F38BA038A7528.local [1655326494.769853][2424:2429] CHIP:DIS: MINMDNS: IP address fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76 found for 4E9F38BA038A7528.local [1655326494.769884][2424:2429] CHIP:DIS: Discovered node without a pending query [1655326494.770360][2424:2429] CHIP:DIS: UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76%eth0]:5540: score has not improved: 6 [1655326494.770399][2424:2429] CHIP:DIS: Checking node lookup status after 4 ms [1655326494.770421][2424:2429] CHIP:DIS: Keeping DNSSD lookup active [1655326494.966765][2424:2429] CHIP:DIS: Checking node lookup status after 201 ms [1655326494.966826][2424:2429] CHIP:CTL: Updating device address to UDP:[fd12:c411:e4a6:d11c:c128:393b:b2c3:6c76]:5540 while in state 2 [1655326494.966851][2424:2429] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 2 --> 3 [1655326494.967050][2424:2429] CHIP:IN: SecureSession[0xaaab155d49a0]: Allocated Type:2 LSID:30423 [1655326494.967091][2424:2429] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655326494.967865][2424:2429] CHIP:SC: Including MRP parameters [1655326494.968081][2424:2429] CHIP:IN: Prepared unauthenticated message 0xaaab155d2c58 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 25347i with MessageCounter:22924294. [1655326494.968132][2424:2429] CHIP:IN: Sending unauthenticated msg 0xaaab155d2c58 with MessageCounter:22924294 to 0x0000000000000000 at monotonic time: 00000000001532C3 msec [1655326494.968325][2424:2429] CHIP:SC: Sent Sigma1 msg [1655326494.968359][2424:2429] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 3 --> 4 [1655326494.968385][2424:2429] CHIP:DIS: Discovery does not require any more timeouts [1655326495.085702][2424:2429] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:158284787 on exchange 25347i [1655326495.085757][2424:2429] CHIP:EM: Found matching exchange: 25347i, Delegate: 0xffff880015c0 [1655326495.085800][2424:2429] CHIP:EM: Rxd Ack; Removing MessageCounter:22924294 from Retrans Table on exchange 25347i [1655326495.085858][2424:2429] CHIP:EM: Removed CHIP MessageCounter:22924294 from RetransTable on exchange 25347i [1655326495.105487][2424:2429] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:158284788 on exchange 25347i [1655326495.105541][2424:2429] CHIP:EM: Found matching exchange: 25347i, Delegate: 0xffff880015c0 [1655326495.105575][2424:2429] CHIP:EM: CHIP MessageCounter:22924294 not in RetransTable on exchange 25347i [1655326495.105621][2424:2429] CHIP:SC: Received Sigma2Resume msg [1655326495.105740][2424:2429] CHIP:SC: Found MRP parameters in the message [1655326495.105774][2424:2429] CHIP:SC: Peer assigned session session ID 39512 [1655326495.109855][2424:2429] CHIP:SC: Sending status report. Protocol code 0, exchange 25347 [1655326495.109928][2424:2429] CHIP:EM: Piggybacking Ack for MessageCounter:158284788 on exchange: 25347i [1655326495.109978][2424:2429] CHIP:IN: Prepared unauthenticated message 0xaaab155d2c58 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 25347i with MessageCounter:22924295. [1655326495.110030][2424:2429] CHIP:IN: Sending unauthenticated msg 0xaaab155d2c58 with MessageCounter:22924295 to 0x0000000000000000 at monotonic time: 0000000000153351 msec [1655326495.110317][2424:2429] CHIP:IN: SecureSession[0xaaab155d49a0]: Activated - Type:2 LSID:30423 [1655326495.110358][2424:2429] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:30423 PSID:39512! [1655326495.110391][2424:2429] CHIP:CTL: OperationalDeviceProxy[3507FA7A67620D99:0000000000000001]: State change 4 --> 5 [1655326495.110449][2424:2429] CHIP:TOO: Sending cluster (0x00000101) command (0x0000001A) on endpoint 1 [1655326495.110509][2424:2429] CHIP:DMG: ICR moving to [AddingComm] [1655326495.110703][2424:2429] CHIP:DMG: ICR moving to [AddedComma] [1655326495.110839][2424:2429] CHIP:IN: Prepared secure message 0xaaab155d2c78 to 0x0000000000000001 (1) of type 0xa and protocolId (0, 1) on exchange 25348i with MessageCounter:26422984. [1655326495.110935][2424:2429] CHIP:IN: Sending encrypted msg 0xaaab155d2c78 with MessageCounter:26422984 to 0x0000000000000001 (1) at monotonic time: 0000000000153352 msec [1655326495.111126][2424:2429] CHIP:DMG: ICR moving to [AwaitingTi] [1655326495.165741][2424:2429] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:158284789 on exchange 25347i [1655326495.165797][2424:2429] CHIP:EM: Found matching exchange: 25347i, Delegate: (nil) [1655326495.165854][2424:2429] CHIP:EM: Rxd Ack; Removing MessageCounter:22924295 from Retrans Table on exchange 25347i [1655326495.165882][2424:2429] CHIP:EM: Removed CHIP MessageCounter:22924295 from RetransTable on exchange 25347i [1655326495.190764][2424:2429] CHIP:EM: Received message of type 0x1 with protocolId (0, 1) and MessageCounter:204629587 on exchange 25348i [1655326495.190817][2424:2429] CHIP:EM: Found matching exchange: 25348i, Delegate: 0xffff88004450 [1655326495.190862][2424:2429] CHIP:EM: Rxd Ack; Removing MessageCounter:26422984 from Retrans Table on exchange 25348i [1655326495.190887][2424:2429] CHIP:EM: Removed CHIP MessageCounter:26422984 from RetransTable on exchange 25348i [1655326495.190954][2424:2429] CHIP:DMG: StatusResponseMessage = [1655326495.190984][2424:2429] CHIP:DMG: { [1655326495.191009][2424:2429] CHIP:DMG: Status = 0x00 (SUCCESS), [1655326495.191040][2424:2429] CHIP:DMG: InteractionModelRevision = 1 [1655326495.191063][2424:2429] CHIP:DMG: } [1655326495.191089][2424:2429] CHIP:IM: Received status response, status is 0x00 (SUCCESS) [1655326495.191132][2424:2429] CHIP:EM: Piggybacking Ack for MessageCounter:204629587 on exchange: 25348i [1655326495.191207][2424:2429] CHIP:IN: Prepared secure message 0xaaab155d2c58 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 25348i with MessageCounter:26422985. [1655326495.191245][2424:2429] CHIP:IN: Sending encrypted msg 0xaaab155d2c58 with MessageCounter:26422985 to 0x0000000000000001 (1) at monotonic time: 00000000001533A2 msec [1655326495.191442][2424:2429] CHIP:DMG: ICR moving to [CommandSen] [1655326495.285763][2424:2429] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:204629588 on exchange 25348i [1655326495.285817][2424:2429] CHIP:EM: Found matching exchange: 25348i, Delegate: 0xffff88004450 [1655326495.285861][2424:2429] CHIP:EM: Rxd Ack; Removing MessageCounter:26422985 from Retrans Table on exchange 25348i [1655326495.285882][2424:2429] CHIP:EM: Removed CHIP MessageCounter:26422985 from RetransTable on exchange 25348i [1655326495.285915][2424:2429] CHIP:DMG: ICR moving to [ResponseRe] [1655326495.285964][2424:2429] CHIP:DMG: InvokeResponseMessage = [1655326495.285985][2424:2429] CHIP:DMG: { [1655326495.286006][2424:2429] CHIP:DMG: suppressResponse = false, [1655326495.286027][2424:2429] CHIP:DMG: InvokeResponseIBs = [1655326495.286059][2424:2429] CHIP:DMG: [ [1655326495.286080][2424:2429] CHIP:DMG: InvokeResponseIB = [1655326495.286110][2424:2429] CHIP:DMG: { [1655326495.286131][2424:2429] CHIP:DMG: CommandStatusIB = [1655326495.286157][2424:2429] CHIP:DMG: { [1655326495.286180][2424:2429] CHIP:DMG: CommandPathIB = [1655326495.286207][2424:2429] CHIP:DMG: { [1655326495.286235][2424:2429] CHIP:DMG: EndpointId = 0x1, [1655326495.286263][2424:2429] CHIP:DMG: ClusterId = 0x101, [1655326495.286306][2424:2429] CHIP:DMG: CommandId = 0x1a, [1655326495.286338][2424:2429] CHIP:DMG: }, [1655326495.286375][2424:2429] CHIP:DMG: [1655326495.286404][2424:2429] CHIP:DMG: StatusIB = [1655326495.286438][2424:2429] CHIP:DMG: { [1655326495.286471][2424:2429] CHIP:DMG: status = 0x00 (SUCCESS), [1655326495.286503][2424:2429] CHIP:DMG: }, [1655326495.286534][2424:2429] CHIP:DMG: [1655326495.286562][2424:2429] CHIP:DMG: }, [1655326495.286665][2424:2429] CHIP:DMG: [1655326495.286700][2424:2429] CHIP:DMG: }, [1655326495.286732][2424:2429] CHIP:DMG: [1655326495.286757][2424:2429] CHIP:DMG: ], [1655326495.286788][2424:2429] CHIP:DMG: [1655326495.286814][2424:2429] CHIP:DMG: InteractionModelRevision = 1 [1655326495.286838][2424:2429] CHIP:DMG: }, [1655326495.286933][2424:2429] CHIP:DMG: Received Command Response Status for Endpoint=1 Cluster=0x0000_0101 Command=0x0000_001A Status=0x0 [1655326495.286982][2424:2429] CHIP:DMG: ICR moving to [AwaitingDe] [1655326495.287041][2424:2429] CHIP:EM: Sending Standalone Ack for MessageCounter:204629588 on exchange 25348i [1655326495.287174][2424:2429] CHIP:IN: Prepared secure message 0xffff8fffd9d8 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 25348i with MessageCounter:26422986. [1655326495.287220][2424:2429] CHIP:IN: Sending encrypted msg 0xffff8fffd9d8 with MessageCounter:26422986 to 0x0000000000000001 (1) at monotonic time: 0000000000153402 msec [1655326495.287393][2424:2429] CHIP:EM: Flushed pending ack for MessageCounter:204629588 on exchange 25348i [1655326495.287755][2424:2424] CHIP:CTL: Shutting down the commissioner [1655326495.287897][2424:2424] CHIP:CTL: Shutting down the controller [1655326495.287930][2424:2424] CHIP:CTL: Shutting down the commissioner [1655326495.288009][2424:2424] CHIP:CTL: Shutting down the controller [1655326495.288041][2424:2424] CHIP:IN: Expiring all connections for fabric 1!! [1655326495.288065][2424:2424] CHIP:IN: SecureSession[0xaaab155d49a0]: MarkForRemoval Type:2 LSID:30423 [1655326495.288089][2424:2424] CHIP:IN: SecureSession[0xaaab155d49a0]: Released - Type:2 LSID:30423 [1655326495.288136][2424:2424] CHIP:CTL: Shutting down the commissioner [1655326495.288215][2424:2424] CHIP:CTL: Shutting down the controller [1655326495.288238][2424:2424] CHIP:IN: Expiring all connections for fabric 2!! [1655326495.288273][2424:2424] CHIP:CTL: Shutting down the commissioner [1655326495.288366][2424:2424] CHIP:CTL: Shutting down the controller [1655326495.288389][2424:2424] CHIP:IN: Expiring all connections for fabric 3!! [1655326495.288418][2424:2424] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655326495.288914][2424:2424] CHIP:DMG: IM WH moving to [Uninitialized] [1655326495.288940][2424:2424] CHIP:DMG: IM WH moving to [Uninitialized] [1655326495.288961][2424:2424] CHIP:DMG: IM WH moving to [Uninitialized] [1655326495.288981][2424:2424] CHIP:DMG: IM WH moving to [Uninitialized] [1655326495.289003][2424:2424] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655326495.289083][2424:2424] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655326495.289333][2424:2424] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-LK8o3a) [1655326495.289974][2424:2424] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655326495.290027][2424:2424] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655326495.290053][2424:2424] CHIP:DL: Inet Layer shutdown [1655326495.290075][2424:2424] CHIP:DL: BLE shutdown [1655326495.290098][2424:2424] CHIP:DL: System Layer shutdown