./chip-tool accesscontrol write acl '[{"fabricIndex": 1, "privilege": 5, "authMode": 2, "subjects": [112233], "targets": [{"cluster": null, "endpoint": 0, "deviceType": null}]}, {"fabricIndex": 1, "privilege": 3, "authMode": 3, "subjects": null, "targets": [{"cluster": null, "endpoint": 1, "deviceType": null}]}]' 1 0 [1655797203.197386][9346:9346] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655797203.198002][9346:9346] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655797203.198180][9346:9346] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655797203.198295][9346:9346] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655797203.198646][9346:9346] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-NdAM9y) [1655797203.199280][9346:9346] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797203.199333][9346:9346] CHIP:DL: NVS set: chip-counters/reboot-count = 3 (0x3) [1655797203.200184][9346:9346] CHIP:DL: Got Ethernet interface: eth0 [1655797203.200785][9346:9346] CHIP:DL: Found the primary Ethernet interface:eth0 [1655797203.201365][9346:9346] CHIP:DL: Got WiFi interface: wlan0 [1655797203.201438][9346:9346] CHIP:DL: Failed to reset WiFi statistic counts [1655797203.201525][9346:9346] CHIP:IN: UDP::Init bind&listen port=0 [1655797203.201658][9346:9346] CHIP:IN: UDP::Init bound to port=52507 [1655797203.201683][9346:9346] CHIP:IN: BLEBase::Init - setting/overriding transport [1655797203.201705][9346:9346] CHIP:IN: TransportMgr initialized [1655797203.201754][9346:9346] CHIP:FP: Initializing FabricTable from persistent storage [1655797203.201899][9346:9346] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797203.201985][9346:9346] CHIP:FP: Loading from storage for fabric index 0x1 [1655797203.202415][9346:9346] CHIP:FP: Loading from storage for fabric index 0x2 [1655797203.202759][9346:9346] CHIP:FP: Loading from storage for fabric index 0x3 [1655797203.205944][9346:9346] CHIP:ZCL: Using ZAP configuration... [1655797203.210455][9346:9346] CHIP:DL: Avahi client registered [1655797203.211931][9346:9346] CHIP:CTL: System State Initialized... [1655797203.212039][9346:9346] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797203.212079][9346:9346] CHIP:CTL: Setting attestation nonce to random value [1655797203.212130][9346:9346] CHIP:CTL: Setting CSR nonce to random value [1655797203.212217][9346:9346] CHIP:IN: UDP::Init bind&listen port=5550 [1655797203.212363][9346:9346] CHIP:IN: UDP::Init bound to port=5550 [1655797203.212417][9346:9346] CHIP:IN: TransportMgr initialized [1655797203.212502][9346:9346] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797203.212536][9346:9346] CHIP:CTL: Setting attestation nonce to random value [1655797203.212590][9346:9346] CHIP:CTL: Setting CSR nonce to random value [1655797203.215551][9346:9346] CHIP:CTL: Generating NOC [1655797203.216594][9346:9346] CHIP:FP: Validating NOC chain [1655797203.218731][9346:9346] CHIP:FP: NOC chain validation successful [1655797203.218944][9346:9346] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655797203.218977][9346:9346] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655797203.225425][9346:9346] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655797203.225492][9346:9346] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797203.225519][9346:9346] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797203.225544][9346:9346] CHIP:TS: Retaining current Last Known Good Time [1655797203.227232][9346:9346] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655797203.227332][9346:9346] CHIP:IN: UDP::Init bind&listen port=5550 [1655797203.227487][9346:9346] CHIP:IN: UDP::Init bound to port=5550 [1655797203.227519][9346:9346] CHIP:IN: TransportMgr initialized [1655797203.227632][9346:9346] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797203.227676][9346:9346] CHIP:CTL: Setting attestation nonce to random value [1655797203.227741][9346:9346] CHIP:CTL: Setting CSR nonce to random value [1655797203.228708][9346:9346] CHIP:CTL: Generating NOC [1655797203.229579][9346:9346] CHIP:FP: Validating NOC chain [1655797203.231350][9346:9346] CHIP:FP: NOC chain validation successful [1655797203.231537][9346:9346] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655797203.231566][9346:9346] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655797203.237382][9346:9346] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655797203.237445][9346:9346] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797203.237470][9346:9346] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797203.237491][9346:9346] CHIP:TS: Retaining current Last Known Good Time [1655797203.238909][9346:9346] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655797203.238995][9346:9346] CHIP:IN: UDP::Init bind&listen port=5550 [1655797203.239130][9346:9346] CHIP:IN: UDP::Init bound to port=5550 [1655797203.239157][9346:9346] CHIP:IN: TransportMgr initialized [1655797203.239265][9346:9346] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797203.239305][9346:9346] CHIP:CTL: Setting attestation nonce to random value [1655797203.239367][9346:9346] CHIP:CTL: Setting CSR nonce to random value [1655797203.240256][9346:9346] CHIP:CTL: Generating NOC [1655797203.241177][9346:9346] CHIP:FP: Validating NOC chain [1655797203.242982][9346:9346] CHIP:FP: NOC chain validation successful [1655797203.243167][9346:9346] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655797203.243194][9346:9346] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655797203.248939][9346:9346] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655797203.249001][9346:9346] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797203.249025][9346:9346] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797203.249046][9346:9346] CHIP:TS: Retaining current Last Known Good Time [1655797203.250517][9346:9346] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655797203.250602][9346:9346] CHIP:IN: UDP::Init bind&listen port=5550 [1655797203.250734][9346:9346] CHIP:IN: UDP::Init bound to port=5550 [1655797203.250761][9346:9346] CHIP:IN: TransportMgr initialized [1655797203.282951][9346:9351] CHIP:DL: CHIP task running [1655797203.283195][9346:9351] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655797203.283250][9346:9351] CHIP:TOO: Sending command to node 0x1 [1655797203.283284][9346:9351] CHIP:CSM: FindOrEstablishSession: PeerId = 4783EB7116FFC3BC:0000000000000001 [1655797203.283311][9346:9351] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655797203.283351][9346:9351] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 1 --> 2 [1655797203.283394][9346:9351] CHIP:DIS: Resolving 4783EB7116FFC3BC:0000000000000001 ... [1655797203.395021][9346:9351] CHIP:DL: Avahi resolve found [1655797203.395290][9346:9351] CHIP:DIS: Node ID resolved for 4783EB7116FFC3BC:0000000000000001 [1655797203.395361][9346:9351] CHIP:DIS: Hostname: E45F010EBEFC0000 [1655797203.395430][9346:9351] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0e:befc [1655797203.395523][9346:9351] CHIP:DIS: Port: 5540 [1655797203.395580][9346:9351] CHIP:DIS: Mrp Interval idle: 5000 ms [1655797203.395635][9346:9351] CHIP:DIS: Mrp Interval active: 300 ms [1655797203.396178][9346:9351] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540: new best score: 3 [1655797203.396247][9346:9351] CHIP:DIS: Checking node lookup status after 112 ms [1655797203.396299][9346:9351] CHIP:DIS: Keeping DNSSD lookup active [1655797203.483879][9346:9351] CHIP:DIS: Checking node lookup status after 200 ms [1655797203.484142][9346:9351] CHIP:CTL: Updating device address to UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540 while in state 2 [1655797203.484204][9346:9351] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 2 --> 3 [1655797203.484686][9346:9351] CHIP:IN: SecureSession[0xaaab0a45d320]: Allocated Type:2 LSID:33313 [1655797203.484772][9346:9351] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655797203.486249][9346:9351] CHIP:SC: Including MRP parameters [1655797203.486748][9346:9351] CHIP:IN: Prepared unauthenticated message 0xaaab0a4588f8 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 48988i with MessageCounter:163335024. [1655797203.486851][9346:9351] CHIP:IN: Sending unauthenticated msg 0xaaab0a4588f8 with MessageCounter:163335024 to 0x0000000000000000 at monotonic time: 0000000000A4D9E2 msec [1655797203.487206][9346:9351] CHIP:SC: Sent Sigma1 msg [1655797203.487274][9346:9351] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 3 --> 4 [1655797203.487338][9346:9351] CHIP:DIS: Discovery does not require any more timeouts [1655797203.489590][9346:9351] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:8995126 on exchange 48988i [1655797203.489674][9346:9351] CHIP:EM: Found matching exchange: 48988i, Delegate: 0xffff700011a0 [1655797203.489757][9346:9351] CHIP:EM: Rxd Ack; Removing MessageCounter:163335024 from Retrans Table on exchange 48988i [1655797203.489819][9346:9351] CHIP:EM: Removed CHIP MessageCounter:163335024 from RetransTable on exchange 48988i [1655797203.489894][9346:9351] CHIP:SC: Received Sigma2Resume msg [1655797203.490056][9346:9351] CHIP:SC: Found MRP parameters in the message [1655797203.490126][9346:9351] CHIP:SC: Peer assigned session session ID 1167 [1655797203.496242][9346:9351] CHIP:SC: Sending status report. Protocol code 0, exchange 48988 [1655797203.496322][9346:9351] CHIP:EM: Piggybacking Ack for MessageCounter:8995126 on exchange: 48988i [1655797203.496417][9346:9351] CHIP:IN: Prepared unauthenticated message 0xaaab0a4588f8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 48988i with MessageCounter:163335025. [1655797203.496476][9346:9351] CHIP:IN: Sending unauthenticated msg 0xaaab0a4588f8 with MessageCounter:163335025 to 0x0000000000000000 at monotonic time: 0000000000A4D9EC msec [1655797203.496775][9346:9351] CHIP:IN: SecureSession[0xaaab0a45d320]: Activated - Type:2 LSID:33313 [1655797203.496817][9346:9351] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:33313 PSID:1167! [1655797203.496853][9346:9351] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 4 --> 5 [1655797203.496938][9346:9351] CHIP:TOO: cluster 0x0000_001F, attribute: 0x0000_0000, endpoint 0 [1655797203.497025][9346:9351] CHIP:DMG: WriteClient moving to [AddAttribu] [1655797203.497114][9346:9351] CHIP:DMG: WriteClient moving to [AddAttribu] [1655797203.497157][9346:9351] CHIP:DMG: WriteClient moving to [AddAttribu] [1655797203.497278][9346:9351] CHIP:IN: Prepared secure message 0xaaab0a458918 to 0x0000000000000001 (1) of type 0x6 and protocolId (0, 1) on exchange 48989i with MessageCounter:215652722. [1655797203.497331][9346:9351] CHIP:IN: Sending encrypted msg 0xaaab0a458918 with MessageCounter:215652722 to 0x0000000000000001 (1) at monotonic time: 0000000000A4D9EC msec [1655797203.497500][9346:9351] CHIP:DMG: WriteClient moving to [AwaitingRe] [1655797203.502776][9346:9351] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8995127 on exchange 48988i [1655797203.502819][9346:9351] CHIP:EM: Found matching exchange: 48988i, Delegate: (nil) [1655797203.502866][9346:9351] CHIP:EM: Rxd Ack; Removing MessageCounter:163335025 from Retrans Table on exchange 48988i [1655797203.502900][9346:9351] CHIP:EM: Removed CHIP MessageCounter:163335025 from RetransTable on exchange 48988i [1655797203.511455][9346:9351] CHIP:EM: Received message of type 0x7 with protocolId (0, 1) and MessageCounter:81377239 on exchange 48989i [1655797203.511497][9346:9351] CHIP:EM: Found matching exchange: 48989i, Delegate: 0xffff70003eb0 [1655797203.511537][9346:9351] CHIP:EM: Rxd Ack; Removing MessageCounter:215652722 from Retrans Table on exchange 48989i [1655797203.511568][9346:9351] CHIP:EM: Removed CHIP MessageCounter:215652722 from RetransTable on exchange 48989i [1655797203.511606][9346:9351] CHIP:DMG: WriteClient moving to [ResponseRe] [1655797203.511679][9346:9351] CHIP:DMG: WriteResponseMessage = [1655797203.511713][9346:9351] CHIP:DMG: { [1655797203.511743][9346:9351] CHIP:DMG: AttributeStatusIBs = [1655797203.511784][9346:9351] CHIP:DMG: [ [1655797203.511817][9346:9351] CHIP:DMG: AttributeStatusIB = [1655797203.511854][9346:9351] CHIP:DMG: { [1655797203.511888][9346:9351] CHIP:DMG: AttributePathIB = [1655797203.511935][9346:9351] CHIP:DMG: { [1655797203.511984][9346:9351] CHIP:DMG: Endpoint = 0x0, [1655797203.512031][9346:9351] CHIP:DMG: Cluster = 0x1f, [1655797203.512077][9346:9351] CHIP:DMG: Attribute = 0x0000_0000, [1655797203.512119][9346:9351] CHIP:DMG: } [1655797203.512166][9346:9351] CHIP:DMG: [1655797203.512207][9346:9351] CHIP:DMG: StatusIB = [1655797203.512249][9346:9351] CHIP:DMG: { [1655797203.512291][9346:9351] CHIP:DMG: status = 0x00 (SUCCESS), [1655797203.512333][9346:9351] CHIP:DMG: }, [1655797203.512392][9346:9351] CHIP:DMG: [1655797203.512429][9346:9351] CHIP:DMG: }, [1655797203.512478][9346:9351] CHIP:DMG: [1655797203.512510][9346:9351] CHIP:DMG: AttributeStatusIB = [1655797203.512546][9346:9351] CHIP:DMG: { [1655797203.512580][9346:9351] CHIP:DMG: AttributePathIB = [1655797203.512622][9346:9351] CHIP:DMG: { [1655797203.512664][9346:9351] CHIP:DMG: Endpoint = 0x0, [1655797203.512709][9346:9351] CHIP:DMG: Cluster = 0x1f, [1655797203.512755][9346:9351] CHIP:DMG: Attribute = 0x0000_0000, [1655797203.512799][9346:9351] CHIP:DMG: ListIndex = Null, [1655797203.512841][9346:9351] CHIP:DMG: } [1655797203.512888][9346:9351] CHIP:DMG: [1655797203.512928][9346:9351] CHIP:DMG: StatusIB = [1655797203.512969][9346:9351] CHIP:DMG: { [1655797203.513010][9346:9351] CHIP:DMG: status = 0x00 (SUCCESS), [1655797203.513052][9346:9351] CHIP:DMG: }, [1655797203.513093][9346:9351] CHIP:DMG: [1655797203.513209][9346:9351] CHIP:DMG: }, [1655797203.513263][9346:9351] CHIP:DMG: [1655797203.513296][9346:9351] CHIP:DMG: AttributeStatusIB = [1655797203.513332][9346:9351] CHIP:DMG: { [1655797203.513365][9346:9351] CHIP:DMG: AttributePathIB = [1655797203.513406][9346:9351] CHIP:DMG: { [1655797203.513449][9346:9351] CHIP:DMG: Endpoint = 0x0, [1655797203.513494][9346:9351] CHIP:DMG: Cluster = 0x1f, [1655797203.513540][9346:9351] CHIP:DMG: Attribute = 0x0000_0000, [1655797203.513584][9346:9351] CHIP:DMG: ListIndex = Null, [1655797203.513625][9346:9351] CHIP:DMG: } [1655797203.513672][9346:9351] CHIP:DMG: [1655797203.513712][9346:9351] CHIP:DMG: StatusIB = [1655797203.513752][9346:9351] CHIP:DMG: { [1655797203.513794][9346:9351] CHIP:DMG: status = 0x00 (SUCCESS), [1655797203.513839][9346:9351] CHIP:DMG: }, [1655797203.513880][9346:9351] CHIP:DMG: [1655797203.513914][9346:9351] CHIP:DMG: }, [1655797203.513952][9346:9351] CHIP:DMG: [1655797203.513984][9346:9351] CHIP:DMG: ], [1655797203.514032][9346:9351] CHIP:DMG: [1655797203.514064][9346:9351] CHIP:DMG: InteractionModelRevision = 1 [1655797203.514095][9346:9351] CHIP:DMG: } [1655797203.514260][9346:9351] CHIP:DMG: WriteClient moving to [AwaitingDe] [1655797203.514340][9346:9351] CHIP:EM: Sending Standalone Ack for MessageCounter:81377239 on exchange 48989i [1655797203.514441][9346:9351] CHIP:IN: Prepared secure message 0xffff85644958 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 48989i with MessageCounter:215652723. [1655797203.514493][9346:9351] CHIP:IN: Sending encrypted msg 0xffff85644958 with MessageCounter:215652723 to 0x0000000000000001 (1) at monotonic time: 0000000000A4D9FE msec [1655797203.514665][9346:9351] CHIP:EM: Flushed pending ack for MessageCounter:81377239 on exchange 48989i [1655797203.515060][9346:9346] CHIP:CTL: Shutting down the commissioner [1655797203.515205][9346:9346] CHIP:CTL: Shutting down the controller [1655797203.515263][9346:9346] CHIP:CTL: Shutting down the commissioner [1655797203.515355][9346:9346] CHIP:CTL: Shutting down the controller [1655797203.515409][9346:9346] CHIP:IN: Expiring all connections for fabric 1!! [1655797203.515451][9346:9346] CHIP:IN: SecureSession[0xaaab0a45d320]: MarkForRemoval Type:2 LSID:33313 [1655797203.515494][9346:9346] CHIP:IN: SecureSession[0xaaab0a45d320]: Released - Type:2 LSID:33313 [1655797203.515570][9346:9346] CHIP:CTL: Shutting down the commissioner [1655797203.515671][9346:9346] CHIP:CTL: Shutting down the controller [1655797203.515715][9346:9346] CHIP:IN: Expiring all connections for fabric 2!! [1655797203.515778][9346:9346] CHIP:CTL: Shutting down the commissioner [1655797203.515870][9346:9346] CHIP:CTL: Shutting down the controller [1655797203.515912][9346:9346] CHIP:IN: Expiring all connections for fabric 3!! [1655797203.515968][9346:9346] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655797203.517531][9346:9346] CHIP:DMG: IM WH moving to [Uninitialized] [1655797203.517665][9346:9346] CHIP:DMG: IM WH moving to [Uninitialized] [1655797203.517746][9346:9346] CHIP:DMG: IM WH moving to [Uninitialized] [1655797203.517824][9346:9346] CHIP:DMG: IM WH moving to [Uninitialized] [1655797203.517903][9346:9346] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655797203.518110][9346:9346] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655797203.518537][9346:9346] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-WGPMUz) [1655797203.519556][9346:9346] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797203.519661][9346:9346] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655797203.519709][9346:9346] CHIP:DL: Inet Layer shutdown [1655797203.519750][9346:9346] CHIP:DL: BLE shutdown [1655797203.519790][9346:9346] CHIP:DL: System Layer shutdown ./chip-tool groupkeymanagement key-set-write '{"groupKeySetID": 42,"groupKeySecurityPolicy": 0, "epochKey0":"d0d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime0": 2220000,"epochKey1":"d1d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime1": 2220001,"epochKey2":"d2d1d2d3d4d5d6d7d8d9dadbdcdddedf", "epochStartTime2": 2220002 }' 1 0 [1655797310.441600][9358:9358] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655797310.442203][9358:9358] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655797310.442367][9358:9358] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655797310.442476][9358:9358] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655797310.442829][9358:9358] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-rkvTAS) [1655797310.443482][9358:9358] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797310.443538][9358:9358] CHIP:DL: NVS set: chip-counters/reboot-count = 4 (0x4) [1655797310.444531][9358:9358] CHIP:DL: Got Ethernet interface: eth0 [1655797310.445128][9358:9358] CHIP:DL: Found the primary Ethernet interface:eth0 [1655797310.445709][9358:9358] CHIP:DL: Got WiFi interface: wlan0 [1655797310.445781][9358:9358] CHIP:DL: Failed to reset WiFi statistic counts [1655797310.445872][9358:9358] CHIP:IN: UDP::Init bind&listen port=0 [1655797310.445997][9358:9358] CHIP:IN: UDP::Init bound to port=44385 [1655797310.446023][9358:9358] CHIP:IN: BLEBase::Init - setting/overriding transport [1655797310.446044][9358:9358] CHIP:IN: TransportMgr initialized [1655797310.446080][9358:9358] CHIP:FP: Initializing FabricTable from persistent storage [1655797310.446226][9358:9358] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797310.446311][9358:9358] CHIP:FP: Loading from storage for fabric index 0x1 [1655797310.446743][9358:9358] CHIP:FP: Loading from storage for fabric index 0x2 [1655797310.447079][9358:9358] CHIP:FP: Loading from storage for fabric index 0x3 [1655797310.450770][9358:9358] CHIP:ZCL: Using ZAP configuration... [1655797310.455661][9358:9358] CHIP:DL: Avahi client registered [1655797310.457205][9358:9358] CHIP:CTL: System State Initialized... [1655797310.457328][9358:9358] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797310.457374][9358:9358] CHIP:CTL: Setting attestation nonce to random value [1655797310.457435][9358:9358] CHIP:CTL: Setting CSR nonce to random value [1655797310.457556][9358:9358] CHIP:IN: UDP::Init bind&listen port=5550 [1655797310.457734][9358:9358] CHIP:IN: UDP::Init bound to port=5550 [1655797310.457766][9358:9358] CHIP:IN: TransportMgr initialized [1655797310.457852][9358:9358] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797310.457903][9358:9358] CHIP:CTL: Setting attestation nonce to random value [1655797310.457963][9358:9358] CHIP:CTL: Setting CSR nonce to random value [1655797310.461345][9358:9358] CHIP:CTL: Generating NOC [1655797310.462340][9358:9358] CHIP:FP: Validating NOC chain [1655797310.464526][9358:9358] CHIP:FP: NOC chain validation successful [1655797310.464744][9358:9358] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655797310.464778][9358:9358] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655797310.470576][9358:9358] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655797310.470626][9358:9358] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797310.470652][9358:9358] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797310.470673][9358:9358] CHIP:TS: Retaining current Last Known Good Time [1655797310.471972][9358:9358] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655797310.472043][9358:9358] CHIP:IN: UDP::Init bind&listen port=5550 [1655797310.472180][9358:9358] CHIP:IN: UDP::Init bound to port=5550 [1655797310.472217][9358:9358] CHIP:IN: TransportMgr initialized [1655797310.472313][9358:9358] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797310.472351][9358:9358] CHIP:CTL: Setting attestation nonce to random value [1655797310.472431][9358:9358] CHIP:CTL: Setting CSR nonce to random value [1655797310.473281][9358:9358] CHIP:CTL: Generating NOC [1655797310.474080][9358:9358] CHIP:FP: Validating NOC chain [1655797310.475764][9358:9358] CHIP:FP: NOC chain validation successful [1655797310.475913][9358:9358] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655797310.475940][9358:9358] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655797310.480945][9358:9358] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655797310.480995][9358:9358] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797310.481020][9358:9358] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797310.481041][9358:9358] CHIP:TS: Retaining current Last Known Good Time [1655797310.482253][9358:9358] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655797310.482318][9358:9358] CHIP:IN: UDP::Init bind&listen port=5550 [1655797310.482442][9358:9358] CHIP:IN: UDP::Init bound to port=5550 [1655797310.482468][9358:9358] CHIP:IN: TransportMgr initialized [1655797310.482562][9358:9358] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797310.482599][9358:9358] CHIP:CTL: Setting attestation nonce to random value [1655797310.482659][9358:9358] CHIP:CTL: Setting CSR nonce to random value [1655797310.483479][9358:9358] CHIP:CTL: Generating NOC [1655797310.484308][9358:9358] CHIP:FP: Validating NOC chain [1655797310.486056][9358:9358] CHIP:FP: NOC chain validation successful [1655797310.486205][9358:9358] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655797310.486233][9358:9358] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655797310.491274][9358:9358] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655797310.491325][9358:9358] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797310.491349][9358:9358] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797310.491371][9358:9358] CHIP:TS: Retaining current Last Known Good Time [1655797310.492626][9358:9358] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655797310.492694][9358:9358] CHIP:IN: UDP::Init bind&listen port=5550 [1655797310.492821][9358:9358] CHIP:IN: UDP::Init bound to port=5550 [1655797310.492846][9358:9358] CHIP:IN: TransportMgr initialized [1655797310.523415][9358:9363] CHIP:DL: CHIP task running [1655797310.523648][9358:9363] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655797310.523685][9358:9363] CHIP:TOO: Sending command to node 0x1 [1655797310.523721][9358:9363] CHIP:CSM: FindOrEstablishSession: PeerId = 4783EB7116FFC3BC:0000000000000001 [1655797310.523747][9358:9363] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655797310.523787][9358:9363] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 1 --> 2 [1655797310.523818][9358:9363] CHIP:DIS: Resolving 4783EB7116FFC3BC:0000000000000001 ... [1655797310.525661][9358:9363] CHIP:DL: Avahi resolve found [1655797310.525738][9358:9363] CHIP:DIS: Node ID resolved for 4783EB7116FFC3BC:0000000000000001 [1655797310.525766][9358:9363] CHIP:DIS: Hostname: E45F010EBEFC0000 [1655797310.525798][9358:9363] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0e:befc [1655797310.525822][9358:9363] CHIP:DIS: Port: 5540 [1655797310.525845][9358:9363] CHIP:DIS: Mrp Interval idle: 5000 ms [1655797310.525867][9358:9363] CHIP:DIS: Mrp Interval active: 300 ms [1655797310.526160][9358:9363] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540: new best score: 3 [1655797310.526188][9358:9363] CHIP:DIS: Checking node lookup status after 2 ms [1655797310.526209][9358:9363] CHIP:DIS: Keeping DNSSD lookup active [1655797310.724512][9358:9363] CHIP:DIS: Checking node lookup status after 201 ms [1655797310.724732][9358:9363] CHIP:CTL: Updating device address to UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540 while in state 2 [1655797310.724772][9358:9363] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 2 --> 3 [1655797310.725059][9358:9363] CHIP:IN: SecureSession[0xaaaacb5f1070]: Allocated Type:2 LSID:3418 [1655797310.725116][9358:9363] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655797310.726198][9358:9363] CHIP:SC: Including MRP parameters [1655797310.726810][9358:9363] CHIP:IN: Prepared unauthenticated message 0xaaaacb5ef468 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 10028i with MessageCounter:71274108. [1655797310.726917][9358:9363] CHIP:IN: Sending unauthenticated msg 0xaaaacb5ef468 with MessageCounter:71274108 to 0x0000000000000000 at monotonic time: 0000000000A67CCA msec [1655797310.727272][9358:9363] CHIP:SC: Sent Sigma1 msg [1655797310.727343][9358:9363] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 3 --> 4 [1655797310.727413][9358:9363] CHIP:DIS: Discovery does not require any more timeouts [1655797310.729807][9358:9363] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:8995128 on exchange 10028i [1655797310.729881][9358:9363] CHIP:EM: Found matching exchange: 10028i, Delegate: 0xffff700011a0 [1655797310.729959][9358:9363] CHIP:EM: Rxd Ack; Removing MessageCounter:71274108 from Retrans Table on exchange 10028i [1655797310.730020][9358:9363] CHIP:EM: Removed CHIP MessageCounter:71274108 from RetransTable on exchange 10028i [1655797310.730094][9358:9363] CHIP:SC: Received Sigma2Resume msg [1655797310.730270][9358:9363] CHIP:SC: Found MRP parameters in the message [1655797310.730363][9358:9363] CHIP:SC: Peer assigned session session ID 1168 [1655797310.737871][9358:9363] CHIP:SC: Sending status report. Protocol code 0, exchange 10028 [1655797310.737943][9358:9363] CHIP:EM: Piggybacking Ack for MessageCounter:8995128 on exchange: 10028i [1655797310.737997][9358:9363] CHIP:IN: Prepared unauthenticated message 0xaaaacb5ef468 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 10028i with MessageCounter:71274109. [1655797310.738048][9358:9363] CHIP:IN: Sending unauthenticated msg 0xaaaacb5ef468 with MessageCounter:71274109 to 0x0000000000000000 at monotonic time: 0000000000A67CD5 msec [1655797310.738356][9358:9363] CHIP:IN: SecureSession[0xaaaacb5f1070]: Activated - Type:2 LSID:3418 [1655797310.738391][9358:9363] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:3418 PSID:1168! [1655797310.738422][9358:9363] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 4 --> 5 [1655797310.738481][9358:9363] CHIP:TOO: Sending cluster (0x0000003F) command (0x00000000) on endpoint 0 [1655797310.738540][9358:9363] CHIP:DMG: ICR moving to [AddingComm] [1655797310.738661][9358:9363] CHIP:DMG: ICR moving to [AddedComma] [1655797310.738806][9358:9363] CHIP:IN: Prepared secure message 0xaaaacb5ef488 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 10029i with MessageCounter:164455270. [1655797310.738862][9358:9363] CHIP:IN: Sending encrypted msg 0xaaaacb5ef488 with MessageCounter:164455270 to 0x0000000000000001 (1) at monotonic time: 0000000000A67CD6 msec [1655797310.739028][9358:9363] CHIP:DMG: ICR moving to [CommandSen] [1655797310.745723][9358:9363] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8995129 on exchange 10028i [1655797310.745761][9358:9363] CHIP:EM: Found matching exchange: 10028i, Delegate: (nil) [1655797310.745805][9358:9363] CHIP:EM: Rxd Ack; Removing MessageCounter:71274109 from Retrans Table on exchange 10028i [1655797310.745834][9358:9363] CHIP:EM: Removed CHIP MessageCounter:71274109 from RetransTable on exchange 10028i [1655797310.752518][9358:9363] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:242504472 on exchange 10029i [1655797310.752570][9358:9363] CHIP:EM: Found matching exchange: 10029i, Delegate: 0xffff70003f20 [1655797310.752618][9358:9363] CHIP:EM: Rxd Ack; Removing MessageCounter:164455270 from Retrans Table on exchange 10029i [1655797310.752653][9358:9363] CHIP:EM: Removed CHIP MessageCounter:164455270 from RetransTable on exchange 10029i [1655797310.752696][9358:9363] CHIP:DMG: ICR moving to [ResponseRe] [1655797310.752779][9358:9363] CHIP:DMG: InvokeResponseMessage = [1655797310.752816][9358:9363] CHIP:DMG: { [1655797310.752864][9358:9363] CHIP:DMG: suppressResponse = false, [1655797310.752902][9358:9363] CHIP:DMG: InvokeResponseIBs = [1655797310.752960][9358:9363] CHIP:DMG: [ [1655797310.752998][9358:9363] CHIP:DMG: InvokeResponseIB = [1655797310.753058][9358:9363] CHIP:DMG: { [1655797310.753097][9358:9363] CHIP:DMG: CommandStatusIB = [1655797310.753158][9358:9363] CHIP:DMG: { [1655797310.753203][9358:9363] CHIP:DMG: CommandPathIB = [1655797310.753266][9358:9363] CHIP:DMG: { [1655797310.753329][9358:9363] CHIP:DMG: EndpointId = 0x0, [1655797310.753398][9358:9363] CHIP:DMG: ClusterId = 0x3f, [1655797310.753455][9358:9363] CHIP:DMG: CommandId = 0x0, [1655797310.753520][9358:9363] CHIP:DMG: }, [1655797310.753587][9358:9363] CHIP:DMG: [1655797310.753632][9358:9363] CHIP:DMG: StatusIB = [1655797310.753695][9358:9363] CHIP:DMG: { [1655797310.753762][9358:9363] CHIP:DMG: status = 0x00 (SUCCESS), [1655797310.753816][9358:9363] CHIP:DMG: }, [1655797310.753878][9358:9363] CHIP:DMG: [1655797310.753921][9358:9363] CHIP:DMG: }, [1655797310.753983][9358:9363] CHIP:DMG: [1655797310.754021][9358:9363] CHIP:DMG: }, [1655797310.754080][9358:9363] CHIP:DMG: [1655797310.754127][9358:9363] CHIP:DMG: ], [1655797310.754173][9358:9363] CHIP:DMG: [1655797310.754221][9358:9363] CHIP:DMG: InteractionModelRevision = 1 [1655797310.754257][9358:9363] CHIP:DMG: }, [1655797310.754351][9358:9363] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003F Command=0x0000_0000 Status=0x0 [1655797310.754426][9358:9363] CHIP:DMG: ICR moving to [AwaitingDe] [1655797310.754503][9358:9363] CHIP:EM: Sending Standalone Ack for MessageCounter:242504472 on exchange 10029i [1655797310.754586][9358:9363] CHIP:IN: Prepared secure message 0xffff86139958 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 10029i with MessageCounter:164455271. [1655797310.754638][9358:9363] CHIP:IN: Sending encrypted msg 0xffff86139958 with MessageCounter:164455271 to 0x0000000000000001 (1) at monotonic time: 0000000000A67CE6 msec [1655797310.754778][9358:9363] CHIP:EM: Flushed pending ack for MessageCounter:242504472 on exchange 10029i [1655797310.754980][9358:9358] CHIP:CTL: Shutting down the commissioner [1655797310.755102][9358:9358] CHIP:CTL: Shutting down the controller [1655797310.755147][9358:9358] CHIP:CTL: Shutting down the commissioner [1655797310.755223][9358:9358] CHIP:CTL: Shutting down the controller [1655797310.755267][9358:9358] CHIP:IN: Expiring all connections for fabric 1!! [1655797310.755301][9358:9358] CHIP:IN: SecureSession[0xaaaacb5f1070]: MarkForRemoval Type:2 LSID:3418 [1655797310.755334][9358:9358] CHIP:IN: SecureSession[0xaaaacb5f1070]: Released - Type:2 LSID:3418 [1655797310.755398][9358:9358] CHIP:CTL: Shutting down the commissioner [1655797310.755475][9358:9358] CHIP:CTL: Shutting down the controller [1655797310.755509][9358:9358] CHIP:IN: Expiring all connections for fabric 2!! [1655797310.755559][9358:9358] CHIP:CTL: Shutting down the commissioner [1655797310.755635][9358:9358] CHIP:CTL: Shutting down the controller [1655797310.755669][9358:9358] CHIP:IN: Expiring all connections for fabric 3!! [1655797310.755713][9358:9358] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655797310.756940][9358:9358] CHIP:DMG: IM WH moving to [Uninitialized] [1655797310.756994][9358:9358] CHIP:DMG: IM WH moving to [Uninitialized] [1655797310.757026][9358:9358] CHIP:DMG: IM WH moving to [Uninitialized] [1655797310.757057][9358:9358] CHIP:DMG: IM WH moving to [Uninitialized] [1655797310.757089][9358:9358] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655797310.757184][9358:9358] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655797310.757565][9358:9358] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-dcplYz) [1655797310.758498][9358:9358] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797310.758588][9358:9358] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655797310.758632][9358:9358] CHIP:DL: Inet Layer shutdown [1655797310.758668][9358:9358] CHIP:DL: BLE shutdown [1655797310.758705][9358:9358] CHIP:DL: System Layer shutdown ./chip-tool groups add-group 0x0001 grp1 1 0 [1655797437.028007][9367:9367] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655797437.028588][9367:9367] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655797437.028778][9367:9367] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655797437.028894][9367:9367] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655797437.029266][9367:9367] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Kri8LI) [1655797437.029956][9367:9367] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797437.030024][9367:9367] CHIP:DL: NVS set: chip-counters/reboot-count = 5 (0x5) [1655797437.030931][9367:9367] CHIP:DL: Got Ethernet interface: eth0 [1655797437.031592][9367:9367] CHIP:DL: Found the primary Ethernet interface:eth0 [1655797437.032247][9367:9367] CHIP:DL: Got WiFi interface: wlan0 [1655797437.032341][9367:9367] CHIP:DL: Failed to reset WiFi statistic counts [1655797437.032479][9367:9367] CHIP:IN: UDP::Init bind&listen port=0 [1655797437.032637][9367:9367] CHIP:IN: UDP::Init bound to port=60101 [1655797437.032668][9367:9367] CHIP:IN: BLEBase::Init - setting/overriding transport [1655797437.032694][9367:9367] CHIP:IN: TransportMgr initialized [1655797437.032754][9367:9367] CHIP:FP: Initializing FabricTable from persistent storage [1655797437.032942][9367:9367] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797437.033041][9367:9367] CHIP:FP: Loading from storage for fabric index 0x1 [1655797437.033578][9367:9367] CHIP:FP: Loading from storage for fabric index 0x2 [1655797437.033991][9367:9367] CHIP:FP: Loading from storage for fabric index 0x3 [1655797437.037797][9367:9367] CHIP:ZCL: Using ZAP configuration... [1655797437.043164][9367:9367] CHIP:DL: Avahi client registered [1655797437.044650][9367:9367] CHIP:CTL: System State Initialized... [1655797437.044769][9367:9367] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797437.044810][9367:9367] CHIP:CTL: Setting attestation nonce to random value [1655797437.044861][9367:9367] CHIP:CTL: Setting CSR nonce to random value [1655797437.044947][9367:9367] CHIP:IN: UDP::Init bind&listen port=5550 [1655797437.045090][9367:9367] CHIP:IN: UDP::Init bound to port=5550 [1655797437.045118][9367:9367] CHIP:IN: TransportMgr initialized [1655797437.045196][9367:9367] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797437.045226][9367:9367] CHIP:CTL: Setting attestation nonce to random value [1655797437.045276][9367:9367] CHIP:CTL: Setting CSR nonce to random value [1655797437.048134][9367:9367] CHIP:CTL: Generating NOC [1655797437.049079][9367:9367] CHIP:FP: Validating NOC chain [1655797437.050912][9367:9367] CHIP:FP: NOC chain validation successful [1655797437.051103][9367:9367] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655797437.051132][9367:9367] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655797437.057438][9367:9367] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655797437.057503][9367:9367] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797437.057529][9367:9367] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797437.057550][9367:9367] CHIP:TS: Retaining current Last Known Good Time [1655797437.059091][9367:9367] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655797437.059177][9367:9367] CHIP:IN: UDP::Init bind&listen port=5550 [1655797437.059310][9367:9367] CHIP:IN: UDP::Init bound to port=5550 [1655797437.059337][9367:9367] CHIP:IN: TransportMgr initialized [1655797437.059445][9367:9367] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797437.059485][9367:9367] CHIP:CTL: Setting attestation nonce to random value [1655797437.059550][9367:9367] CHIP:CTL: Setting CSR nonce to random value [1655797437.060587][9367:9367] CHIP:CTL: Generating NOC [1655797437.061446][9367:9367] CHIP:FP: Validating NOC chain [1655797437.063215][9367:9367] CHIP:FP: NOC chain validation successful [1655797437.063452][9367:9367] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655797437.063484][9367:9367] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655797437.069657][9367:9367] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655797437.069720][9367:9367] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797437.069746][9367:9367] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797437.069767][9367:9367] CHIP:TS: Retaining current Last Known Good Time [1655797437.071312][9367:9367] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655797437.071399][9367:9367] CHIP:IN: UDP::Init bind&listen port=5550 [1655797437.071529][9367:9367] CHIP:IN: UDP::Init bound to port=5550 [1655797437.071556][9367:9367] CHIP:IN: TransportMgr initialized [1655797437.071668][9367:9367] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797437.071710][9367:9367] CHIP:CTL: Setting attestation nonce to random value [1655797437.071771][9367:9367] CHIP:CTL: Setting CSR nonce to random value [1655797437.072802][9367:9367] CHIP:CTL: Generating NOC [1655797437.073717][9367:9367] CHIP:FP: Validating NOC chain [1655797437.075451][9367:9367] CHIP:FP: NOC chain validation successful [1655797437.075605][9367:9367] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655797437.075631][9367:9367] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655797437.081171][9367:9367] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655797437.081223][9367:9367] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797437.081247][9367:9367] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797437.081269][9367:9367] CHIP:TS: Retaining current Last Known Good Time [1655797437.082603][9367:9367] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655797437.082670][9367:9367] CHIP:IN: UDP::Init bind&listen port=5550 [1655797437.082797][9367:9367] CHIP:IN: UDP::Init bound to port=5550 [1655797437.082822][9367:9367] CHIP:IN: TransportMgr initialized [1655797437.115653][9367:9372] CHIP:DL: CHIP task running [1655797437.115888][9367:9372] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655797437.115922][9367:9372] CHIP:TOO: Sending command to node 0x1 [1655797437.115958][9367:9372] CHIP:CSM: FindOrEstablishSession: PeerId = 4783EB7116FFC3BC:0000000000000001 [1655797437.115983][9367:9372] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655797437.116023][9367:9372] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 1 --> 2 [1655797437.116053][9367:9372] CHIP:DIS: Resolving 4783EB7116FFC3BC:0000000000000001 ... [1655797437.227803][9367:9372] CHIP:DL: Avahi resolve found [1655797437.228081][9367:9372] CHIP:DIS: Node ID resolved for 4783EB7116FFC3BC:0000000000000001 [1655797437.228147][9367:9372] CHIP:DIS: Hostname: E45F010EBEFC0000 [1655797437.228215][9367:9372] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0e:befc [1655797437.228274][9367:9372] CHIP:DIS: Port: 5540 [1655797437.228326][9367:9372] CHIP:DIS: Mrp Interval idle: 5000 ms [1655797437.228432][9367:9372] CHIP:DIS: Mrp Interval active: 300 ms [1655797437.228920][9367:9372] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540: new best score: 3 [1655797437.228987][9367:9372] CHIP:DIS: Checking node lookup status after 113 ms [1655797437.229039][9367:9372] CHIP:DIS: Keeping DNSSD lookup active [1655797437.316489][9367:9372] CHIP:DIS: Checking node lookup status after 201 ms [1655797437.316712][9367:9372] CHIP:CTL: Updating device address to UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540 while in state 2 [1655797437.316765][9367:9372] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 2 --> 3 [1655797437.317102][9367:9372] CHIP:IN: SecureSession[0xaaab0b4f95a0]: Allocated Type:2 LSID:50196 [1655797437.317177][9367:9372] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655797437.318450][9367:9372] CHIP:SC: Including MRP parameters [1655797437.318914][9367:9372] CHIP:IN: Prepared unauthenticated message 0xaaab0b4f4a98 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 7002i with MessageCounter:128301682. [1655797437.319007][9367:9372] CHIP:IN: Sending unauthenticated msg 0xaaab0b4f4a98 with MessageCounter:128301682 to 0x0000000000000000 at monotonic time: 0000000000A86B4A msec [1655797437.319313][9367:9372] CHIP:SC: Sent Sigma1 msg [1655797437.319373][9367:9372] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 3 --> 4 [1655797437.319431][9367:9372] CHIP:DIS: Discovery does not require any more timeouts [1655797437.321091][9367:9372] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:8995130 on exchange 7002i [1655797437.321157][9367:9372] CHIP:EM: Found matching exchange: 7002i, Delegate: 0xffff900011a0 [1655797437.321225][9367:9372] CHIP:EM: Rxd Ack; Removing MessageCounter:128301682 from Retrans Table on exchange 7002i [1655797437.321277][9367:9372] CHIP:EM: Removed CHIP MessageCounter:128301682 from RetransTable on exchange 7002i [1655797437.321341][9367:9372] CHIP:SC: Received Sigma2Resume msg [1655797437.321487][9367:9372] CHIP:SC: Found MRP parameters in the message [1655797437.321546][9367:9372] CHIP:SC: Peer assigned session session ID 1169 [1655797437.329530][9367:9372] CHIP:SC: Sending status report. Protocol code 0, exchange 7002 [1655797437.329611][9367:9372] CHIP:EM: Piggybacking Ack for MessageCounter:8995130 on exchange: 7002i [1655797437.329665][9367:9372] CHIP:IN: Prepared unauthenticated message 0xaaab0b4f4a98 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 7002i with MessageCounter:128301683. [1655797437.329716][9367:9372] CHIP:IN: Sending unauthenticated msg 0xaaab0b4f4a98 with MessageCounter:128301683 to 0x0000000000000000 at monotonic time: 0000000000A86B55 msec [1655797437.329994][9367:9372] CHIP:IN: SecureSession[0xaaab0b4f95a0]: Activated - Type:2 LSID:50196 [1655797437.330034][9367:9372] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:50196 PSID:1169! [1655797437.330066][9367:9372] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 4 --> 5 [1655797437.330124][9367:9372] CHIP:TOO: Sending cluster (0x00000004) command (0x00000000) on endpoint 0 [1655797437.330184][9367:9372] CHIP:DMG: ICR moving to [AddingComm] [1655797437.330219][9367:9372] CHIP:DMG: ICR moving to [AddedComma] [1655797437.330322][9367:9372] CHIP:IN: Prepared secure message 0xaaab0b4f4ab8 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 7003i with MessageCounter:191118412. [1655797437.330368][9367:9372] CHIP:IN: Sending encrypted msg 0xaaab0b4f4ab8 with MessageCounter:191118412 to 0x0000000000000001 (1) at monotonic time: 0000000000A86B55 msec [1655797437.330521][9367:9372] CHIP:DMG: ICR moving to [CommandSen] [1655797437.335262][9367:9372] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8995131 on exchange 7002i [1655797437.335309][9367:9372] CHIP:EM: Found matching exchange: 7002i, Delegate: (nil) [1655797437.335354][9367:9372] CHIP:EM: Rxd Ack; Removing MessageCounter:128301683 from Retrans Table on exchange 7002i [1655797437.335381][9367:9372] CHIP:EM: Removed CHIP MessageCounter:128301683 from RetransTable on exchange 7002i [1655797437.343030][9367:9372] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:171141180 on exchange 7003i [1655797437.343085][9367:9372] CHIP:EM: Found matching exchange: 7003i, Delegate: 0xffff90003f80 [1655797437.343122][9367:9372] CHIP:EM: Rxd Ack; Removing MessageCounter:191118412 from Retrans Table on exchange 7003i [1655797437.343145][9367:9372] CHIP:EM: Removed CHIP MessageCounter:191118412 from RetransTable on exchange 7003i [1655797437.343177][9367:9372] CHIP:DMG: ICR moving to [ResponseRe] [1655797437.343282][9367:9372] CHIP:DMG: InvokeResponseMessage = [1655797437.343308][9367:9372] CHIP:DMG: { [1655797437.343332][9367:9372] CHIP:DMG: suppressResponse = false, [1655797437.343356][9367:9372] CHIP:DMG: InvokeResponseIBs = [1655797437.343386][9367:9372] CHIP:DMG: [ [1655797437.343410][9367:9372] CHIP:DMG: InvokeResponseIB = [1655797437.343447][9367:9372] CHIP:DMG: { [1655797437.343473][9367:9372] CHIP:DMG: CommandDataIB = [1655797437.343505][9367:9372] CHIP:DMG: { [1655797437.343537][9367:9372] CHIP:DMG: CommandPathIB = [1655797437.343575][9367:9372] CHIP:DMG: { [1655797437.343612][9367:9372] CHIP:DMG: EndpointId = 0x0, [1655797437.343650][9367:9372] CHIP:DMG: ClusterId = 0x4, [1655797437.343688][9367:9372] CHIP:DMG: CommandId = 0x0, [1655797437.343723][9367:9372] CHIP:DMG: }, [1655797437.343761][9367:9372] CHIP:DMG: [1655797437.343791][9367:9372] CHIP:DMG: CommandFields = [1655797437.343827][9367:9372] CHIP:DMG: { [1655797437.343892][9367:9372] CHIP:DMG: 0x0 = 0, [1655797437.343927][9367:9372] CHIP:DMG: 0x1 = 1, [1655797437.343964][9367:9372] CHIP:DMG: }, [1655797437.343998][9367:9372] CHIP:DMG: }, [1655797437.344032][9367:9372] CHIP:DMG: [1655797437.344057][9367:9372] CHIP:DMG: }, [1655797437.344087][9367:9372] CHIP:DMG: [1655797437.344110][9367:9372] CHIP:DMG: ], [1655797437.344140][9367:9372] CHIP:DMG: [1655797437.344164][9367:9372] CHIP:DMG: InteractionModelRevision = 1 [1655797437.344187][9367:9372] CHIP:DMG: }, [1655797437.344249][9367:9372] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0004 Command=0x0000_0000 [1655797437.344300][9367:9372] CHIP:TOO: Endpoint: 0 Cluster: 0x0000_0004 Command 0x0000_0000 [1655797437.344358][9367:9372] CHIP:TOO: AddGroupResponse: { [1655797437.344434][9367:9372] CHIP:TOO: status: 0 [1655797437.344459][9367:9372] CHIP:TOO: groupId: 1 [1655797437.344482][9367:9372] CHIP:TOO: } [1655797437.344521][9367:9372] CHIP:DMG: ICR moving to [AwaitingDe] [1655797437.344581][9367:9372] CHIP:EM: Sending Standalone Ack for MessageCounter:171141180 on exchange 7003i [1655797437.344661][9367:9372] CHIP:IN: Prepared secure message 0xffffa2fdd958 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 7003i with MessageCounter:191118413. [1655797437.344703][9367:9372] CHIP:IN: Sending encrypted msg 0xffffa2fdd958 with MessageCounter:191118413 to 0x0000000000000001 (1) at monotonic time: 0000000000A86B64 msec [1655797437.344839][9367:9372] CHIP:EM: Flushed pending ack for MessageCounter:171141180 on exchange 7003i [1655797437.345050][9367:9367] CHIP:CTL: Shutting down the commissioner [1655797437.345148][9367:9367] CHIP:CTL: Shutting down the controller [1655797437.345182][9367:9367] CHIP:CTL: Shutting down the commissioner [1655797437.345234][9367:9367] CHIP:CTL: Shutting down the controller [1655797437.345266][9367:9367] CHIP:IN: Expiring all connections for fabric 1!! [1655797437.345291][9367:9367] CHIP:IN: SecureSession[0xaaab0b4f95a0]: MarkForRemoval Type:2 LSID:50196 [1655797437.345313][9367:9367] CHIP:IN: SecureSession[0xaaab0b4f95a0]: Released - Type:2 LSID:50196 [1655797437.345363][9367:9367] CHIP:CTL: Shutting down the commissioner [1655797437.345421][9367:9367] CHIP:CTL: Shutting down the controller [1655797437.345444][9367:9367] CHIP:IN: Expiring all connections for fabric 2!! [1655797437.345481][9367:9367] CHIP:CTL: Shutting down the commissioner [1655797437.345534][9367:9367] CHIP:CTL: Shutting down the controller [1655797437.345557][9367:9367] CHIP:IN: Expiring all connections for fabric 3!! [1655797437.345589][9367:9367] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655797437.346599][9367:9367] CHIP:DMG: IM WH moving to [Uninitialized] [1655797437.346650][9367:9367] CHIP:DMG: IM WH moving to [Uninitialized] [1655797437.346703][9367:9367] CHIP:DMG: IM WH moving to [Uninitialized] [1655797437.346748][9367:9367] CHIP:DMG: IM WH moving to [Uninitialized] [1655797437.346792][9367:9367] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655797437.346892][9367:9367] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655797437.347222][9367:9367] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-0gFV3Y) [1655797437.347963][9367:9367] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797437.348044][9367:9367] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655797437.348072][9367:9367] CHIP:DL: Inet Layer shutdown [1655797437.348094][9367:9367] CHIP:DL: BLE shutdown [1655797437.348115][9367:9367] CHIP:DL: System Layer shutdown ./chip-tool groupkeymanagement write group-key-map '[{"groupId": 1, "groupKeySetID": 42, "fabricIndex": 1}]' 1 0 [1655797553.994248][9379:9379] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655797553.994816][9379:9379] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655797553.995013][9379:9379] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655797553.995138][9379:9379] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655797553.995518][9379:9379] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-hcwI3f) [1655797553.996201][9379:9379] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797553.996272][9379:9379] CHIP:DL: NVS set: chip-counters/reboot-count = 6 (0x6) [1655797553.997253][9379:9379] CHIP:DL: Got Ethernet interface: eth0 [1655797553.997921][9379:9379] CHIP:DL: Found the primary Ethernet interface:eth0 [1655797553.998630][9379:9379] CHIP:DL: Got WiFi interface: wlan0 [1655797553.998725][9379:9379] CHIP:DL: Failed to reset WiFi statistic counts [1655797553.998822][9379:9379] CHIP:IN: UDP::Init bind&listen port=0 [1655797553.998961][9379:9379] CHIP:IN: UDP::Init bound to port=33229 [1655797553.998987][9379:9379] CHIP:IN: BLEBase::Init - setting/overriding transport [1655797553.999009][9379:9379] CHIP:IN: TransportMgr initialized [1655797553.999063][9379:9379] CHIP:FP: Initializing FabricTable from persistent storage [1655797553.999236][9379:9379] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797553.999326][9379:9379] CHIP:FP: Loading from storage for fabric index 0x1 [1655797553.999773][9379:9379] CHIP:FP: Loading from storage for fabric index 0x2 [1655797554.000137][9379:9379] CHIP:FP: Loading from storage for fabric index 0x3 [1655797554.003722][9379:9379] CHIP:ZCL: Using ZAP configuration... [1655797554.008680][9379:9379] CHIP:DL: Avahi client registered [1655797554.010076][9379:9379] CHIP:CTL: System State Initialized... [1655797554.010180][9379:9379] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797554.010220][9379:9379] CHIP:CTL: Setting attestation nonce to random value [1655797554.010270][9379:9379] CHIP:CTL: Setting CSR nonce to random value [1655797554.010355][9379:9379] CHIP:IN: UDP::Init bind&listen port=5550 [1655797554.010501][9379:9379] CHIP:IN: UDP::Init bound to port=5550 [1655797554.010528][9379:9379] CHIP:IN: TransportMgr initialized [1655797554.010604][9379:9379] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797554.010634][9379:9379] CHIP:CTL: Setting attestation nonce to random value [1655797554.010685][9379:9379] CHIP:CTL: Setting CSR nonce to random value [1655797554.013567][9379:9379] CHIP:CTL: Generating NOC [1655797554.014448][9379:9379] CHIP:FP: Validating NOC chain [1655797554.016252][9379:9379] CHIP:FP: NOC chain validation successful [1655797554.016476][9379:9379] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655797554.016506][9379:9379] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655797554.021864][9379:9379] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655797554.021921][9379:9379] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797554.021946][9379:9379] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797554.021968][9379:9379] CHIP:TS: Retaining current Last Known Good Time [1655797554.023233][9379:9379] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655797554.023304][9379:9379] CHIP:IN: UDP::Init bind&listen port=5550 [1655797554.023433][9379:9379] CHIP:IN: UDP::Init bound to port=5550 [1655797554.023458][9379:9379] CHIP:IN: TransportMgr initialized [1655797554.023552][9379:9379] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797554.023591][9379:9379] CHIP:CTL: Setting attestation nonce to random value [1655797554.023652][9379:9379] CHIP:CTL: Setting CSR nonce to random value [1655797554.024531][9379:9379] CHIP:CTL: Generating NOC [1655797554.025322][9379:9379] CHIP:FP: Validating NOC chain [1655797554.027007][9379:9379] CHIP:FP: NOC chain validation successful [1655797554.027153][9379:9379] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655797554.027179][9379:9379] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655797554.032257][9379:9379] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655797554.032307][9379:9379] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797554.032332][9379:9379] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797554.032355][9379:9379] CHIP:TS: Retaining current Last Known Good Time [1655797554.033653][9379:9379] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655797554.033723][9379:9379] CHIP:IN: UDP::Init bind&listen port=5550 [1655797554.033847][9379:9379] CHIP:IN: UDP::Init bound to port=5550 [1655797554.033872][9379:9379] CHIP:IN: TransportMgr initialized [1655797554.033965][9379:9379] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797554.034003][9379:9379] CHIP:CTL: Setting attestation nonce to random value [1655797554.034062][9379:9379] CHIP:CTL: Setting CSR nonce to random value [1655797554.034872][9379:9379] CHIP:CTL: Generating NOC [1655797554.035689][9379:9379] CHIP:FP: Validating NOC chain [1655797554.037505][9379:9379] CHIP:FP: NOC chain validation successful [1655797554.037687][9379:9379] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655797554.037715][9379:9379] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655797554.042856][9379:9379] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655797554.042909][9379:9379] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797554.042934][9379:9379] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797554.042956][9379:9379] CHIP:TS: Retaining current Last Known Good Time [1655797554.044257][9379:9379] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655797554.044330][9379:9379] CHIP:IN: UDP::Init bind&listen port=5550 [1655797554.044488][9379:9379] CHIP:IN: UDP::Init bound to port=5550 [1655797554.044514][9379:9379] CHIP:IN: TransportMgr initialized [1655797554.135800][9379:9384] CHIP:DL: CHIP task running [1655797554.136059][9379:9384] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655797554.136103][9379:9384] CHIP:TOO: Sending command to node 0x1 [1655797554.136147][9379:9384] CHIP:CSM: FindOrEstablishSession: PeerId = 4783EB7116FFC3BC:0000000000000001 [1655797554.136180][9379:9384] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655797554.136226][9379:9384] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 1 --> 2 [1655797554.136264][9379:9384] CHIP:DIS: Resolving 4783EB7116FFC3BC:0000000000000001 ... [1655797554.138394][9379:9384] CHIP:DL: Avahi resolve found [1655797554.138484][9379:9384] CHIP:DIS: Node ID resolved for 4783EB7116FFC3BC:0000000000000001 [1655797554.138518][9379:9384] CHIP:DIS: Hostname: E45F010EBEFC0000 [1655797554.138552][9379:9384] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0e:befc [1655797554.138582][9379:9384] CHIP:DIS: Port: 5540 [1655797554.138610][9379:9384] CHIP:DIS: Mrp Interval idle: 5000 ms [1655797554.138637][9379:9384] CHIP:DIS: Mrp Interval active: 300 ms [1655797554.138923][9379:9384] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540: new best score: 3 [1655797554.138957][9379:9384] CHIP:DIS: Checking node lookup status after 3 ms [1655797554.138984][9379:9384] CHIP:DIS: Keeping DNSSD lookup active [1655797554.336425][9379:9384] CHIP:DIS: Checking node lookup status after 201 ms [1655797554.336669][9379:9384] CHIP:CTL: Updating device address to UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540 while in state 2 [1655797554.336717][9379:9384] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 2 --> 3 [1655797554.337025][9379:9384] CHIP:IN: SecureSession[0xaaab07e126d0]: Allocated Type:2 LSID:51582 [1655797554.337093][9379:9384] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655797554.338251][9379:9384] CHIP:SC: Including MRP parameters [1655797554.338631][9379:9384] CHIP:IN: Prepared unauthenticated message 0xaaab07e0dba8 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 9841i with MessageCounter:237203634. [1655797554.338770][9379:9384] CHIP:IN: Sending unauthenticated msg 0xaaab07e0dba8 with MessageCounter:237203634 to 0x0000000000000000 at monotonic time: 0000000000AA3466 msec [1655797554.339043][9379:9384] CHIP:SC: Sent Sigma1 msg [1655797554.339097][9379:9384] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 3 --> 4 [1655797554.339147][9379:9384] CHIP:DIS: Discovery does not require any more timeouts [1655797554.341500][9379:9384] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:8995132 on exchange 9841i [1655797554.341558][9379:9384] CHIP:EM: Found matching exchange: 9841i, Delegate: 0xffff940011a0 [1655797554.341619][9379:9384] CHIP:EM: Rxd Ack; Removing MessageCounter:237203634 from Retrans Table on exchange 9841i [1655797554.341663][9379:9384] CHIP:EM: Removed CHIP MessageCounter:237203634 from RetransTable on exchange 9841i [1655797554.341719][9379:9384] CHIP:SC: Received Sigma2Resume msg [1655797554.341839][9379:9384] CHIP:SC: Found MRP parameters in the message [1655797554.341891][9379:9384] CHIP:SC: Peer assigned session session ID 1170 [1655797554.351770][9379:9384] CHIP:SC: Sending status report. Protocol code 0, exchange 9841 [1655797554.351859][9379:9384] CHIP:EM: Piggybacking Ack for MessageCounter:8995132 on exchange: 9841i [1655797554.351923][9379:9384] CHIP:IN: Prepared unauthenticated message 0xaaab07e0dba8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 9841i with MessageCounter:237203635. [1655797554.351983][9379:9384] CHIP:IN: Sending unauthenticated msg 0xaaab07e0dba8 with MessageCounter:237203635 to 0x0000000000000000 at monotonic time: 0000000000AA3473 msec [1655797554.352344][9379:9384] CHIP:IN: SecureSession[0xaaab07e126d0]: Activated - Type:2 LSID:51582 [1655797554.352427][9379:9384] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:51582 PSID:1170! [1655797554.352466][9379:9384] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 4 --> 5 [1655797554.352566][9379:9384] CHIP:TOO: cluster 0x0000_003F, attribute: 0x0000_0000, endpoint 0 [1655797554.352660][9379:9384] CHIP:DMG: WriteClient moving to [AddAttribu] [1655797554.352740][9379:9384] CHIP:DMG: WriteClient moving to [AddAttribu] [1655797554.352889][9379:9384] CHIP:IN: Prepared secure message 0xaaab07e0dbc8 to 0x0000000000000001 (1) of type 0x6 and protocolId (0, 1) on exchange 9842i with MessageCounter:106569307. [1655797554.352940][9379:9384] CHIP:IN: Sending encrypted msg 0xaaab07e0dbc8 with MessageCounter:106569307 to 0x0000000000000001 (1) at monotonic time: 0000000000AA3474 msec [1655797554.353117][9379:9384] CHIP:DMG: WriteClient moving to [AwaitingRe] [1655797554.357589][9379:9384] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8995133 on exchange 9841i [1655797554.357638][9379:9384] CHIP:EM: Found matching exchange: 9841i, Delegate: (nil) [1655797554.357689][9379:9384] CHIP:EM: Rxd Ack; Removing MessageCounter:237203635 from Retrans Table on exchange 9841i [1655797554.357722][9379:9384] CHIP:EM: Removed CHIP MessageCounter:237203635 from RetransTable on exchange 9841i [1655797554.364250][9379:9384] CHIP:EM: Received message of type 0x7 with protocolId (0, 1) and MessageCounter:90872315 on exchange 9842i [1655797554.364299][9379:9384] CHIP:EM: Found matching exchange: 9842i, Delegate: 0xffff94003ef0 [1655797554.364349][9379:9384] CHIP:EM: Rxd Ack; Removing MessageCounter:106569307 from Retrans Table on exchange 9842i [1655797554.364412][9379:9384] CHIP:EM: Removed CHIP MessageCounter:106569307 from RetransTable on exchange 9842i [1655797554.364464][9379:9384] CHIP:DMG: WriteClient moving to [ResponseRe] [1655797554.364542][9379:9384] CHIP:DMG: WriteResponseMessage = [1655797554.364583][9379:9384] CHIP:DMG: { [1655797554.364619][9379:9384] CHIP:DMG: AttributeStatusIBs = [1655797554.364668][9379:9384] CHIP:DMG: [ [1655797554.364707][9379:9384] CHIP:DMG: AttributeStatusIB = [1655797554.364752][9379:9384] CHIP:DMG: { [1655797554.364794][9379:9384] CHIP:DMG: AttributePathIB = [1655797554.364857][9379:9384] CHIP:DMG: { [1655797554.364909][9379:9384] CHIP:DMG: Endpoint = 0x0, [1655797554.364969][9379:9384] CHIP:DMG: Cluster = 0x3f, [1655797554.365024][9379:9384] CHIP:DMG: Attribute = 0x0000_0000, [1655797554.365075][9379:9384] CHIP:DMG: } [1655797554.365133][9379:9384] CHIP:DMG: [1655797554.365181][9379:9384] CHIP:DMG: StatusIB = [1655797554.365231][9379:9384] CHIP:DMG: { [1655797554.365287][9379:9384] CHIP:DMG: status = 0x00 (SUCCESS), [1655797554.365343][9379:9384] CHIP:DMG: }, [1655797554.365399][9379:9384] CHIP:DMG: [1655797554.365443][9379:9384] CHIP:DMG: }, [1655797554.365499][9379:9384] CHIP:DMG: [1655797554.365538][9379:9384] CHIP:DMG: AttributeStatusIB = [1655797554.365581][9379:9384] CHIP:DMG: { [1655797554.365622][9379:9384] CHIP:DMG: AttributePathIB = [1655797554.365670][9379:9384] CHIP:DMG: { [1655797554.365719][9379:9384] CHIP:DMG: Endpoint = 0x0, [1655797554.365772][9379:9384] CHIP:DMG: Cluster = 0x3f, [1655797554.365829][9379:9384] CHIP:DMG: Attribute = 0x0000_0000, [1655797554.365881][9379:9384] CHIP:DMG: ListIndex = Null, [1655797554.365935][9379:9384] CHIP:DMG: } [1655797554.365990][9379:9384] CHIP:DMG: [1655797554.366038][9379:9384] CHIP:DMG: StatusIB = [1655797554.366087][9379:9384] CHIP:DMG: { [1655797554.366138][9379:9384] CHIP:DMG: status = 0x00 (SUCCESS), [1655797554.366187][9379:9384] CHIP:DMG: }, [1655797554.366236][9379:9384] CHIP:DMG: [1655797554.366277][9379:9384] CHIP:DMG: }, [1655797554.366325][9379:9384] CHIP:DMG: [1655797554.366363][9379:9384] CHIP:DMG: ], [1655797554.366416][9379:9384] CHIP:DMG: [1655797554.366455][9379:9384] CHIP:DMG: InteractionModelRevision = 1 [1655797554.366492][9379:9384] CHIP:DMG: } [1655797554.366644][9379:9384] CHIP:DMG: WriteClient moving to [AwaitingDe] [1655797554.366727][9379:9384] CHIP:EM: Sending Standalone Ack for MessageCounter:90872315 on exchange 9842i [1655797554.366820][9379:9384] CHIP:IN: Prepared secure message 0xffffa6fdd958 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 9842i with MessageCounter:106569308. [1655797554.366879][9379:9384] CHIP:IN: Sending encrypted msg 0xffffa6fdd958 with MessageCounter:106569308 to 0x0000000000000001 (1) at monotonic time: 0000000000AA3482 msec [1655797554.367057][9379:9384] CHIP:EM: Flushed pending ack for MessageCounter:90872315 on exchange 9842i [1655797554.367322][9379:9379] CHIP:CTL: Shutting down the commissioner [1655797554.367449][9379:9379] CHIP:CTL: Shutting down the controller [1655797554.367500][9379:9379] CHIP:CTL: Shutting down the commissioner [1655797554.367583][9379:9379] CHIP:CTL: Shutting down the controller [1655797554.367631][9379:9379] CHIP:IN: Expiring all connections for fabric 1!! [1655797554.367668][9379:9379] CHIP:IN: SecureSession[0xaaab07e126d0]: MarkForRemoval Type:2 LSID:51582 [1655797554.367705][9379:9379] CHIP:IN: SecureSession[0xaaab07e126d0]: Released - Type:2 LSID:51582 [1655797554.367772][9379:9379] CHIP:CTL: Shutting down the commissioner [1655797554.367858][9379:9379] CHIP:CTL: Shutting down the controller [1655797554.367897][9379:9379] CHIP:IN: Expiring all connections for fabric 2!! [1655797554.367952][9379:9379] CHIP:CTL: Shutting down the commissioner [1655797554.368033][9379:9379] CHIP:CTL: Shutting down the controller [1655797554.368070][9379:9379] CHIP:IN: Expiring all connections for fabric 3!! [1655797554.368119][9379:9379] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655797554.369587][9379:9379] CHIP:DMG: IM WH moving to [Uninitialized] [1655797554.369649][9379:9379] CHIP:DMG: IM WH moving to [Uninitialized] [1655797554.369682][9379:9379] CHIP:DMG: IM WH moving to [Uninitialized] [1655797554.369714][9379:9379] CHIP:DMG: IM WH moving to [Uninitialized] [1655797554.369749][9379:9379] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655797554.369853][9379:9379] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655797554.370231][9379:9379] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-zvKjAk) [1655797554.371228][9379:9379] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797554.371323][9379:9379] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655797554.371366][9379:9379] CHIP:DL: Inet Layer shutdown [1655797554.371402][9379:9379] CHIP:DL: BLE shutdown [1655797554.371438][9379:9379] CHIP:DL: System Layer shutdown ./chip-tool groups view-group 0x0001 1 0 [1655797654.052359][9390:9390] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655797654.052983][9390:9390] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655797654.053192][9390:9390] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655797654.053323][9390:9390] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655797654.053701][9390:9390] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-W0sg2n) [1655797654.054404][9390:9390] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797654.054474][9390:9390] CHIP:DL: NVS set: chip-counters/reboot-count = 7 (0x7) [1655797654.055384][9390:9390] CHIP:DL: Got Ethernet interface: eth0 [1655797654.056026][9390:9390] CHIP:DL: Found the primary Ethernet interface:eth0 [1655797654.056716][9390:9390] CHIP:DL: Got WiFi interface: wlan0 [1655797654.056805][9390:9390] CHIP:DL: Failed to reset WiFi statistic counts [1655797654.057013][9390:9390] CHIP:IN: UDP::Init bind&listen port=0 [1655797654.057167][9390:9390] CHIP:IN: UDP::Init bound to port=48482 [1655797654.057196][9390:9390] CHIP:IN: BLEBase::Init - setting/overriding transport [1655797654.057218][9390:9390] CHIP:IN: TransportMgr initialized [1655797654.057273][9390:9390] CHIP:FP: Initializing FabricTable from persistent storage [1655797654.057443][9390:9390] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797654.057535][9390:9390] CHIP:FP: Loading from storage for fabric index 0x1 [1655797654.058012][9390:9390] CHIP:FP: Loading from storage for fabric index 0x2 [1655797654.058377][9390:9390] CHIP:FP: Loading from storage for fabric index 0x3 [1655797654.063284][9390:9390] CHIP:ZCL: Using ZAP configuration... [1655797654.068212][9390:9390] CHIP:DL: Avahi client registered [1655797654.069642][9390:9390] CHIP:CTL: System State Initialized... [1655797654.069746][9390:9390] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797654.069786][9390:9390] CHIP:CTL: Setting attestation nonce to random value [1655797654.069842][9390:9390] CHIP:CTL: Setting CSR nonce to random value [1655797654.069930][9390:9390] CHIP:IN: UDP::Init bind&listen port=5550 [1655797654.070077][9390:9390] CHIP:IN: UDP::Init bound to port=5550 [1655797654.070104][9390:9390] CHIP:IN: TransportMgr initialized [1655797654.070181][9390:9390] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797654.070213][9390:9390] CHIP:CTL: Setting attestation nonce to random value [1655797654.070263][9390:9390] CHIP:CTL: Setting CSR nonce to random value [1655797654.073118][9390:9390] CHIP:CTL: Generating NOC [1655797654.073999][9390:9390] CHIP:FP: Validating NOC chain [1655797654.075808][9390:9390] CHIP:FP: NOC chain validation successful [1655797654.075994][9390:9390] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655797654.076022][9390:9390] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655797654.085746][9390:9390] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655797654.085802][9390:9390] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797654.085826][9390:9390] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797654.085848][9390:9390] CHIP:TS: Retaining current Last Known Good Time [1655797654.088351][9390:9390] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655797654.088439][9390:9390] CHIP:IN: UDP::Init bind&listen port=5550 [1655797654.088564][9390:9390] CHIP:IN: UDP::Init bound to port=5550 [1655797654.088588][9390:9390] CHIP:IN: TransportMgr initialized [1655797654.088684][9390:9390] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797654.088723][9390:9390] CHIP:CTL: Setting attestation nonce to random value [1655797654.088784][9390:9390] CHIP:CTL: Setting CSR nonce to random value [1655797654.089623][9390:9390] CHIP:CTL: Generating NOC [1655797654.090419][9390:9390] CHIP:FP: Validating NOC chain [1655797654.092696][9390:9390] CHIP:FP: NOC chain validation successful [1655797654.092911][9390:9390] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655797654.092948][9390:9390] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655797654.102682][9390:9390] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655797654.102737][9390:9390] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797654.102766][9390:9390] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797654.102791][9390:9390] CHIP:TS: Retaining current Last Known Good Time [1655797654.105325][9390:9390] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655797654.105398][9390:9390] CHIP:IN: UDP::Init bind&listen port=5550 [1655797654.105535][9390:9390] CHIP:IN: UDP::Init bound to port=5550 [1655797654.105563][9390:9390] CHIP:IN: TransportMgr initialized [1655797654.105671][9390:9390] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797654.105712][9390:9390] CHIP:CTL: Setting attestation nonce to random value [1655797654.105781][9390:9390] CHIP:CTL: Setting CSR nonce to random value [1655797654.106700][9390:9390] CHIP:CTL: Generating NOC [1655797654.107615][9390:9390] CHIP:FP: Validating NOC chain [1655797654.109735][9390:9390] CHIP:FP: NOC chain validation successful [1655797654.109918][9390:9390] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655797654.109948][9390:9390] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655797654.121379][9390:9390] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655797654.121434][9390:9390] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797654.121463][9390:9390] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797654.121487][9390:9390] CHIP:TS: Retaining current Last Known Good Time [1655797654.124025][9390:9390] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655797654.124115][9390:9390] CHIP:IN: UDP::Init bind&listen port=5550 [1655797654.124285][9390:9390] CHIP:IN: UDP::Init bound to port=5550 [1655797654.124322][9390:9390] CHIP:IN: TransportMgr initialized [1655797654.185339][9390:9395] CHIP:DL: CHIP task running [1655797654.185610][9390:9395] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655797654.185659][9390:9395] CHIP:TOO: Sending command to node 0x1 [1655797654.185709][9390:9395] CHIP:CSM: FindOrEstablishSession: PeerId = 4783EB7116FFC3BC:0000000000000001 [1655797654.185748][9390:9395] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655797654.185801][9390:9395] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 1 --> 2 [1655797654.185844][9390:9395] CHIP:DIS: Resolving 4783EB7116FFC3BC:0000000000000001 ... [1655797654.297208][9390:9395] CHIP:DL: Avahi resolve found [1655797654.297324][9390:9395] CHIP:DIS: Node ID resolved for 4783EB7116FFC3BC:0000000000000001 [1655797654.297368][9390:9395] CHIP:DIS: Hostname: E45F010EBEFC0000 [1655797654.297414][9390:9395] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0e:befc [1655797654.297454][9390:9395] CHIP:DIS: Port: 5540 [1655797654.297490][9390:9395] CHIP:DIS: Mrp Interval idle: 5000 ms [1655797654.297527][9390:9395] CHIP:DIS: Mrp Interval active: 300 ms [1655797654.297878][9390:9395] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540: new best score: 3 [1655797654.297923][9390:9395] CHIP:DIS: Checking node lookup status after 112 ms [1655797654.297956][9390:9395] CHIP:DIS: Keeping DNSSD lookup active [1655797654.386262][9390:9395] CHIP:DIS: Checking node lookup status after 200 ms [1655797654.386445][9390:9395] CHIP:CTL: Updating device address to UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540 while in state 2 [1655797654.386549][9390:9395] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 2 --> 3 [1655797654.386745][9390:9395] CHIP:IN: SecureSession[0xaaab0072f2b0]: Allocated Type:2 LSID:45227 [1655797654.386785][9390:9395] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655797654.387557][9390:9395] CHIP:SC: Including MRP parameters [1655797654.387792][9390:9395] CHIP:IN: Prepared unauthenticated message 0xaaab0072aa38 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 26358i with MessageCounter:16200011. [1655797654.387842][9390:9395] CHIP:IN: Sending unauthenticated msg 0xaaab0072aa38 with MessageCounter:16200011 to 0x0000000000000000 at monotonic time: 0000000000ABBB37 msec [1655797654.388143][9390:9395] CHIP:SC: Sent Sigma1 msg [1655797654.388192][9390:9395] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 3 --> 4 [1655797654.388237][9390:9395] CHIP:DIS: Discovery does not require any more timeouts [1655797654.389333][9390:9395] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:8995134 on exchange 26358i [1655797654.389388][9390:9395] CHIP:EM: Found matching exchange: 26358i, Delegate: 0xffff840011a0 [1655797654.389442][9390:9395] CHIP:EM: Rxd Ack; Removing MessageCounter:16200011 from Retrans Table on exchange 26358i [1655797654.389481][9390:9395] CHIP:EM: Removed CHIP MessageCounter:16200011 from RetransTable on exchange 26358i [1655797654.389531][9390:9395] CHIP:SC: Received Sigma2Resume msg [1655797654.389643][9390:9395] CHIP:SC: Found MRP parameters in the message [1655797654.389690][9390:9395] CHIP:SC: Peer assigned session session ID 1171 [1655797654.397771][9390:9395] CHIP:SC: Sending status report. Protocol code 0, exchange 26358 [1655797654.397863][9390:9395] CHIP:EM: Piggybacking Ack for MessageCounter:8995134 on exchange: 26358i [1655797654.397932][9390:9395] CHIP:IN: Prepared unauthenticated message 0xaaab0072aa38 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 26358i with MessageCounter:16200012. [1655797654.398000][9390:9395] CHIP:IN: Sending unauthenticated msg 0xaaab0072aa38 with MessageCounter:16200012 to 0x0000000000000000 at monotonic time: 0000000000ABBB41 msec [1655797654.398344][9390:9395] CHIP:IN: SecureSession[0xaaab0072f2b0]: Activated - Type:2 LSID:45227 [1655797654.398395][9390:9395] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:45227 PSID:1171! [1655797654.398440][9390:9395] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 4 --> 5 [1655797654.398512][9390:9395] CHIP:TOO: Sending cluster (0x00000004) command (0x00000001) on endpoint 0 [1655797654.398589][9390:9395] CHIP:DMG: ICR moving to [AddingComm] [1655797654.398636][9390:9395] CHIP:DMG: ICR moving to [AddedComma] [1655797654.398754][9390:9395] CHIP:IN: Prepared secure message 0xaaab0072aa58 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 26359i with MessageCounter:162889816. [1655797654.398813][9390:9395] CHIP:IN: Sending encrypted msg 0xaaab0072aa58 with MessageCounter:162889816 to 0x0000000000000001 (1) at monotonic time: 0000000000ABBB42 msec [1655797654.398981][9390:9395] CHIP:DMG: ICR moving to [CommandSen] [1655797654.406830][9390:9395] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8995135 on exchange 26358i [1655797654.406873][9390:9395] CHIP:EM: Found matching exchange: 26358i, Delegate: (nil) [1655797654.406918][9390:9395] CHIP:EM: Rxd Ack; Removing MessageCounter:16200012 from Retrans Table on exchange 26358i [1655797654.406946][9390:9395] CHIP:EM: Removed CHIP MessageCounter:16200012 from RetransTable on exchange 26358i [1655797654.410568][9390:9395] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:113020035 on exchange 26359i [1655797654.410626][9390:9395] CHIP:EM: Found matching exchange: 26359i, Delegate: 0xffff84005630 [1655797654.410681][9390:9395] CHIP:EM: Rxd Ack; Removing MessageCounter:162889816 from Retrans Table on exchange 26359i [1655797654.410725][9390:9395] CHIP:EM: Removed CHIP MessageCounter:162889816 from RetransTable on exchange 26359i [1655797654.410778][9390:9395] CHIP:DMG: ICR moving to [ResponseRe] [1655797654.410861][9390:9395] CHIP:DMG: InvokeResponseMessage = [1655797654.410905][9390:9395] CHIP:DMG: { [1655797654.410949][9390:9395] CHIP:DMG: suppressResponse = false, [1655797654.410993][9390:9395] CHIP:DMG: InvokeResponseIBs = [1655797654.411051][9390:9395] CHIP:DMG: [ [1655797654.411095][9390:9395] CHIP:DMG: InvokeResponseIB = [1655797654.411155][9390:9395] CHIP:DMG: { [1655797654.411203][9390:9395] CHIP:DMG: CommandDataIB = [1655797654.411275][9390:9395] CHIP:DMG: { [1655797654.411329][9390:9395] CHIP:DMG: CommandPathIB = [1655797654.411389][9390:9395] CHIP:DMG: { [1655797654.411450][9390:9395] CHIP:DMG: EndpointId = 0x0, [1655797654.411515][9390:9395] CHIP:DMG: ClusterId = 0x4, [1655797654.411578][9390:9395] CHIP:DMG: CommandId = 0x1, [1655797654.411637][9390:9395] CHIP:DMG: }, [1655797654.411699][9390:9395] CHIP:DMG: [1655797654.411754][9390:9395] CHIP:DMG: CommandFields = [1655797654.411819][9390:9395] CHIP:DMG: { [1655797654.411919][9390:9395] CHIP:DMG: 0x0 = 0, [1655797654.411988][9390:9395] CHIP:DMG: 0x1 = 1, [1655797654.412055][9390:9395] CHIP:DMG: 0x2 = "grp1", [1655797654.412119][9390:9395] CHIP:DMG: }, [1655797654.412175][9390:9395] CHIP:DMG: }, [1655797654.412237][9390:9395] CHIP:DMG: [1655797654.412287][9390:9395] CHIP:DMG: }, [1655797654.412343][9390:9395] CHIP:DMG: [1655797654.412461][9390:9395] CHIP:DMG: ], [1655797654.412523][9390:9395] CHIP:DMG: [1655797654.412568][9390:9395] CHIP:DMG: InteractionModelRevision = 1 [1655797654.412610][9390:9395] CHIP:DMG: }, [1655797654.412716][9390:9395] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0004 Command=0x0000_0001 [1655797654.412798][9390:9395] CHIP:TOO: Endpoint: 0 Cluster: 0x0000_0004 Command 0x0000_0001 [1655797654.412888][9390:9395] CHIP:TOO: ViewGroupResponse: { [1655797654.412945][9390:9395] CHIP:TOO: status: 0 [1655797654.412988][9390:9395] CHIP:TOO: groupId: 1 [1655797654.413029][9390:9395] CHIP:TOO: groupName: grp1 [1655797654.413069][9390:9395] CHIP:TOO: } [1655797654.413137][9390:9395] CHIP:DMG: ICR moving to [AwaitingDe] [1655797654.413218][9390:9395] CHIP:EM: Sending Standalone Ack for MessageCounter:113020035 on exchange 26359i [1655797654.413324][9390:9395] CHIP:IN: Prepared secure message 0xffff8e7cd958 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 26359i with MessageCounter:162889817. [1655797654.413390][9390:9395] CHIP:IN: Sending encrypted msg 0xffff8e7cd958 with MessageCounter:162889817 to 0x0000000000000001 (1) at monotonic time: 0000000000ABBB51 msec [1655797654.413555][9390:9395] CHIP:EM: Flushed pending ack for MessageCounter:113020035 on exchange 26359i [1655797654.413845][9390:9390] CHIP:CTL: Shutting down the commissioner [1655797654.413987][9390:9390] CHIP:CTL: Shutting down the controller [1655797654.414043][9390:9390] CHIP:CTL: Shutting down the commissioner [1655797654.414134][9390:9390] CHIP:CTL: Shutting down the controller [1655797654.414187][9390:9390] CHIP:IN: Expiring all connections for fabric 1!! [1655797654.414229][9390:9390] CHIP:IN: SecureSession[0xaaab0072f2b0]: MarkForRemoval Type:2 LSID:45227 [1655797654.414270][9390:9390] CHIP:IN: SecureSession[0xaaab0072f2b0]: Released - Type:2 LSID:45227 [1655797654.414342][9390:9390] CHIP:CTL: Shutting down the commissioner [1655797654.414440][9390:9390] CHIP:CTL: Shutting down the controller [1655797654.414481][9390:9390] CHIP:IN: Expiring all connections for fabric 2!! [1655797654.414541][9390:9390] CHIP:CTL: Shutting down the commissioner [1655797654.414632][9390:9390] CHIP:CTL: Shutting down the controller [1655797654.414674][9390:9390] CHIP:IN: Expiring all connections for fabric 3!! [1655797654.414728][9390:9390] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655797654.416132][9390:9390] CHIP:DMG: IM WH moving to [Uninitialized] [1655797654.416196][9390:9390] CHIP:DMG: IM WH moving to [Uninitialized] [1655797654.416232][9390:9390] CHIP:DMG: IM WH moving to [Uninitialized] [1655797654.416269][9390:9390] CHIP:DMG: IM WH moving to [Uninitialized] [1655797654.416308][9390:9390] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655797654.416481][9390:9390] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655797654.416913][9390:9390] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-h2sxur) [1655797654.418024][9390:9390] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797654.418127][9390:9390] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655797654.418175][9390:9390] CHIP:DL: Inet Layer shutdown [1655797654.418216][9390:9390] CHIP:DL: BLE shutdown [1655797654.418256][9390:9390] CHIP:DL: System Layer shutdown ./chip-tool groupkeymanagement key-set-read 42 1 0 [1655797739.329353][9399:9399] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655797739.329916][9399:9399] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655797739.330088][9399:9399] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655797739.330219][9399:9399] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655797739.330594][9399:9399] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-HGRw9R) [1655797739.331235][9399:9399] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797739.331288][9399:9399] CHIP:DL: NVS set: chip-counters/reboot-count = 8 (0x8) [1655797739.332162][9399:9399] CHIP:DL: Got Ethernet interface: eth0 [1655797739.332787][9399:9399] CHIP:DL: Found the primary Ethernet interface:eth0 [1655797739.333389][9399:9399] CHIP:DL: Got WiFi interface: wlan0 [1655797739.333463][9399:9399] CHIP:DL: Failed to reset WiFi statistic counts [1655797739.333557][9399:9399] CHIP:IN: UDP::Init bind&listen port=0 [1655797739.333687][9399:9399] CHIP:IN: UDP::Init bound to port=55033 [1655797739.333712][9399:9399] CHIP:IN: BLEBase::Init - setting/overriding transport [1655797739.333735][9399:9399] CHIP:IN: TransportMgr initialized [1655797739.333793][9399:9399] CHIP:FP: Initializing FabricTable from persistent storage [1655797739.333958][9399:9399] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797739.334044][9399:9399] CHIP:FP: Loading from storage for fabric index 0x1 [1655797739.334520][9399:9399] CHIP:FP: Loading from storage for fabric index 0x2 [1655797739.334872][9399:9399] CHIP:FP: Loading from storage for fabric index 0x3 [1655797739.338170][9399:9399] CHIP:ZCL: Using ZAP configuration... [1655797739.342473][9399:9399] CHIP:DL: Avahi client registered [1655797739.343687][9399:9399] CHIP:CTL: System State Initialized... [1655797739.343768][9399:9399] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797739.343808][9399:9399] CHIP:CTL: Setting attestation nonce to random value [1655797739.343859][9399:9399] CHIP:CTL: Setting CSR nonce to random value [1655797739.343933][9399:9399] CHIP:IN: UDP::Init bind&listen port=5550 [1655797739.344077][9399:9399] CHIP:IN: UDP::Init bound to port=5550 [1655797739.344104][9399:9399] CHIP:IN: TransportMgr initialized [1655797739.344187][9399:9399] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797739.344217][9399:9399] CHIP:CTL: Setting attestation nonce to random value [1655797739.344267][9399:9399] CHIP:CTL: Setting CSR nonce to random value [1655797739.347197][9399:9399] CHIP:CTL: Generating NOC [1655797739.348061][9399:9399] CHIP:FP: Validating NOC chain [1655797739.350340][9399:9399] CHIP:FP: NOC chain validation successful [1655797739.350585][9399:9399] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655797739.350620][9399:9399] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655797739.357803][9399:9399] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655797739.357873][9399:9399] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797739.357905][9399:9399] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797739.357931][9399:9399] CHIP:TS: Retaining current Last Known Good Time [1655797739.359725][9399:9399] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655797739.359825][9399:9399] CHIP:IN: UDP::Init bind&listen port=5550 [1655797739.359970][9399:9399] CHIP:IN: UDP::Init bound to port=5550 [1655797739.360012][9399:9399] CHIP:IN: TransportMgr initialized [1655797739.360129][9399:9399] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797739.360182][9399:9399] CHIP:CTL: Setting attestation nonce to random value [1655797739.360243][9399:9399] CHIP:CTL: Setting CSR nonce to random value [1655797739.361177][9399:9399] CHIP:CTL: Generating NOC [1655797739.362061][9399:9399] CHIP:FP: Validating NOC chain [1655797739.363876][9399:9399] CHIP:FP: NOC chain validation successful [1655797739.364084][9399:9399] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655797739.364115][9399:9399] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655797739.371915][9399:9399] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655797739.371977][9399:9399] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797739.372003][9399:9399] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797739.372025][9399:9399] CHIP:TS: Retaining current Last Known Good Time [1655797739.373634][9399:9399] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655797739.373724][9399:9399] CHIP:IN: UDP::Init bind&listen port=5550 [1655797739.373880][9399:9399] CHIP:IN: UDP::Init bound to port=5550 [1655797739.373910][9399:9399] CHIP:IN: TransportMgr initialized [1655797739.374045][9399:9399] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797739.374087][9399:9399] CHIP:CTL: Setting attestation nonce to random value [1655797739.374150][9399:9399] CHIP:CTL: Setting CSR nonce to random value [1655797739.375088][9399:9399] CHIP:CTL: Generating NOC [1655797739.376008][9399:9399] CHIP:FP: Validating NOC chain [1655797739.377954][9399:9399] CHIP:FP: NOC chain validation successful [1655797739.378164][9399:9399] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655797739.378216][9399:9399] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655797739.384282][9399:9399] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655797739.384345][9399:9399] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797739.384370][9399:9399] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797739.384410][9399:9399] CHIP:TS: Retaining current Last Known Good Time [1655797739.385959][9399:9399] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655797739.386045][9399:9399] CHIP:IN: UDP::Init bind&listen port=5550 [1655797739.386197][9399:9399] CHIP:IN: UDP::Init bound to port=5550 [1655797739.386230][9399:9399] CHIP:IN: TransportMgr initialized [1655797739.422581][9399:9404] CHIP:DL: CHIP task running [1655797739.422830][9399:9404] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655797739.422867][9399:9404] CHIP:TOO: Sending command to node 0x1 [1655797739.422912][9399:9404] CHIP:CSM: FindOrEstablishSession: PeerId = 4783EB7116FFC3BC:0000000000000001 [1655797739.422940][9399:9404] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655797739.422980][9399:9404] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 1 --> 2 [1655797739.423013][9399:9404] CHIP:DIS: Resolving 4783EB7116FFC3BC:0000000000000001 ... [1655797739.424814][9399:9404] CHIP:DL: Avahi resolve found [1655797739.424890][9399:9404] CHIP:DIS: Node ID resolved for 4783EB7116FFC3BC:0000000000000001 [1655797739.424916][9399:9404] CHIP:DIS: Hostname: E45F010EBEFC0000 [1655797739.424951][9399:9404] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0e:befc [1655797739.424976][9399:9404] CHIP:DIS: Port: 5540 [1655797739.424998][9399:9404] CHIP:DIS: Mrp Interval idle: 5000 ms [1655797739.425021][9399:9404] CHIP:DIS: Mrp Interval active: 300 ms [1655797739.425278][9399:9404] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540: new best score: 3 [1655797739.425306][9399:9404] CHIP:DIS: Checking node lookup status after 2 ms [1655797739.425327][9399:9404] CHIP:DIS: Keeping DNSSD lookup active [1655797739.623648][9399:9404] CHIP:DIS: Checking node lookup status after 201 ms [1655797739.623939][9399:9404] CHIP:CTL: Updating device address to UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540 while in state 2 [1655797739.624002][9399:9404] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 2 --> 3 [1655797739.624451][9399:9404] CHIP:IN: SecureSession[0xaaaad891bff0]: Allocated Type:2 LSID:3897 [1655797739.624536][9399:9404] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655797739.626021][9399:9404] CHIP:SC: Including MRP parameters [1655797739.626481][9399:9404] CHIP:IN: Prepared unauthenticated message 0xaaaad89174d8 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 2639i with MessageCounter:218426094. [1655797739.626586][9399:9404] CHIP:IN: Sending unauthenticated msg 0xaaaad89174d8 with MessageCounter:218426094 to 0x0000000000000000 at monotonic time: 0000000000AD082E msec [1655797739.626917][9399:9404] CHIP:SC: Sent Sigma1 msg [1655797739.626985][9399:9404] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 3 --> 4 [1655797739.627050][9399:9404] CHIP:DIS: Discovery does not require any more timeouts [1655797739.628447][9399:9404] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:8995136 on exchange 2639i [1655797739.628521][9399:9404] CHIP:EM: Found matching exchange: 2639i, Delegate: 0xffff8c0011a0 [1655797739.628597][9399:9404] CHIP:EM: Rxd Ack; Removing MessageCounter:218426094 from Retrans Table on exchange 2639i [1655797739.628657][9399:9404] CHIP:EM: Removed CHIP MessageCounter:218426094 from RetransTable on exchange 2639i [1655797739.628730][9399:9404] CHIP:SC: Received Sigma2Resume msg [1655797739.628884][9399:9404] CHIP:SC: Found MRP parameters in the message [1655797739.628950][9399:9404] CHIP:SC: Peer assigned session session ID 1172 [1655797739.637915][9399:9404] CHIP:SC: Sending status report. Protocol code 0, exchange 2639 [1655797739.637986][9399:9404] CHIP:EM: Piggybacking Ack for MessageCounter:8995136 on exchange: 2639i [1655797739.638037][9399:9404] CHIP:IN: Prepared unauthenticated message 0xaaaad89174d8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 2639i with MessageCounter:218426095. [1655797739.638087][9399:9404] CHIP:IN: Sending unauthenticated msg 0xaaaad89174d8 with MessageCounter:218426095 to 0x0000000000000000 at monotonic time: 0000000000AD0839 msec [1655797739.638345][9399:9404] CHIP:IN: SecureSession[0xaaaad891bff0]: Activated - Type:2 LSID:3897 [1655797739.638378][9399:9404] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:3897 PSID:1172! [1655797739.638408][9399:9404] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 4 --> 5 [1655797739.638463][9399:9404] CHIP:TOO: Sending cluster (0x0000003F) command (0x00000001) on endpoint 0 [1655797739.638518][9399:9404] CHIP:DMG: ICR moving to [AddingComm] [1655797739.638578][9399:9404] CHIP:DMG: ICR moving to [AddedComma] [1655797739.638672][9399:9404] CHIP:IN: Prepared secure message 0xaaaad89174f8 to 0x0000000000000001 (1) of type 0x8 and protocolId (0, 1) on exchange 2640i with MessageCounter:102584737. [1655797739.638715][9399:9404] CHIP:IN: Sending encrypted msg 0xaaaad89174f8 with MessageCounter:102584737 to 0x0000000000000001 (1) at monotonic time: 0000000000AD083A msec [1655797739.638848][9399:9404] CHIP:DMG: ICR moving to [CommandSen] [1655797739.646609][9399:9404] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8995137 on exchange 2639i [1655797739.646646][9399:9404] CHIP:EM: Found matching exchange: 2639i, Delegate: (nil) [1655797739.646687][9399:9404] CHIP:EM: Rxd Ack; Removing MessageCounter:218426095 from Retrans Table on exchange 2639i [1655797739.646714][9399:9404] CHIP:EM: Removed CHIP MessageCounter:218426095 from RetransTable on exchange 2639i [1655797739.649971][9399:9404] CHIP:EM: Received message of type 0x9 with protocolId (0, 1) and MessageCounter:24619757 on exchange 2640i [1655797739.650020][9399:9404] CHIP:EM: Found matching exchange: 2640i, Delegate: 0xffff8c0055f0 [1655797739.650068][9399:9404] CHIP:EM: Rxd Ack; Removing MessageCounter:102584737 from Retrans Table on exchange 2640i [1655797739.650108][9399:9404] CHIP:EM: Removed CHIP MessageCounter:102584737 from RetransTable on exchange 2640i [1655797739.650153][9399:9404] CHIP:DMG: ICR moving to [ResponseRe] [1655797739.650233][9399:9404] CHIP:DMG: InvokeResponseMessage = [1655797739.650274][9399:9404] CHIP:DMG: { [1655797739.650313][9399:9404] CHIP:DMG: suppressResponse = false, [1655797739.650354][9399:9404] CHIP:DMG: InvokeResponseIBs = [1655797739.650430][9399:9404] CHIP:DMG: [ [1655797739.650473][9399:9404] CHIP:DMG: InvokeResponseIB = [1655797739.650532][9399:9404] CHIP:DMG: { [1655797739.650576][9399:9404] CHIP:DMG: CommandDataIB = [1655797739.650633][9399:9404] CHIP:DMG: { [1655797739.650687][9399:9404] CHIP:DMG: CommandPathIB = [1655797739.650751][9399:9404] CHIP:DMG: { [1655797739.650808][9399:9404] CHIP:DMG: EndpointId = 0x0, [1655797739.650865][9399:9404] CHIP:DMG: ClusterId = 0x3f, [1655797739.650921][9399:9404] CHIP:DMG: CommandId = 0x2, [1655797739.650976][9399:9404] CHIP:DMG: }, [1655797739.651033][9399:9404] CHIP:DMG: [1655797739.651085][9399:9404] CHIP:DMG: CommandFields = [1655797739.651142][9399:9404] CHIP:DMG: { [1655797739.651227][9399:9404] CHIP:DMG: 0x0 = [1655797739.651284][9399:9404] CHIP:DMG: { [1655797739.651344][9399:9404] CHIP:DMG: 0x0 = 42, [1655797739.651405][9399:9404] CHIP:DMG: 0x1 = 0, [1655797739.651465][9399:9404] CHIP:DMG: 0x2 = NULL [1655797739.651525][9399:9404] CHIP:DMG: 0x3 = 2220000, [1655797739.651584][9399:9404] CHIP:DMG: 0x4 = NULL [1655797739.651644][9399:9404] CHIP:DMG: 0x5 = 2220001, [1655797739.651704][9399:9404] CHIP:DMG: 0x6 = NULL [1655797739.651763][9399:9404] CHIP:DMG: 0x7 = 2220002, [1655797739.651821][9399:9404] CHIP:DMG: }, [1655797739.651877][9399:9404] CHIP:DMG: }, [1655797739.651928][9399:9404] CHIP:DMG: }, [1655797739.651989][9399:9404] CHIP:DMG: [1655797739.652032][9399:9404] CHIP:DMG: }, [1655797739.652087][9399:9404] CHIP:DMG: [1655797739.652126][9399:9404] CHIP:DMG: ], [1655797739.652182][9399:9404] CHIP:DMG: [1655797739.652223][9399:9404] CHIP:DMG: InteractionModelRevision = 1 [1655797739.652262][9399:9404] CHIP:DMG: }, [1655797739.652374][9399:9404] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003F Command=0x0000_0002 [1655797739.652507][9399:9404] CHIP:TOO: Endpoint: 0 Cluster: 0x0000_003F Command 0x0000_0002 [1655797739.652665][9399:9404] CHIP:TOO: KeySetReadResponse: { [1655797739.652708][9399:9404] CHIP:TOO: groupKeySet: { [1655797739.652758][9399:9404] CHIP:TOO: GroupKeySetID: 42 [1655797739.652800][9399:9404] CHIP:TOO: GroupKeySecurityPolicy: 0 [1655797739.652837][9399:9404] CHIP:TOO: EpochKey0: null [1655797739.652876][9399:9404] CHIP:TOO: EpochStartTime0: 2220000 [1655797739.652914][9399:9404] CHIP:TOO: EpochKey1: null [1655797739.652952][9399:9404] CHIP:TOO: EpochStartTime1: 2220001 [1655797739.652989][9399:9404] CHIP:TOO: EpochKey2: null [1655797739.653027][9399:9404] CHIP:TOO: EpochStartTime2: 2220002 [1655797739.653064][9399:9404] CHIP:TOO: } [1655797739.653099][9399:9404] CHIP:TOO: } [1655797739.653171][9399:9404] CHIP:DMG: ICR moving to [AwaitingDe] [1655797739.653257][9399:9404] CHIP:EM: Sending Standalone Ack for MessageCounter:24619757 on exchange 2640i [1655797739.653371][9399:9404] CHIP:IN: Prepared secure message 0xffffa143b958 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 2640i with MessageCounter:102584738. [1655797739.653437][9399:9404] CHIP:IN: Sending encrypted msg 0xffffa143b958 with MessageCounter:102584738 to 0x0000000000000001 (1) at monotonic time: 0000000000AD0849 msec [1655797739.653616][9399:9404] CHIP:EM: Flushed pending ack for MessageCounter:24619757 on exchange 2640i [1655797739.653862][9399:9399] CHIP:CTL: Shutting down the commissioner [1655797739.653991][9399:9399] CHIP:CTL: Shutting down the controller [1655797739.654044][9399:9399] CHIP:CTL: Shutting down the commissioner [1655797739.654128][9399:9399] CHIP:CTL: Shutting down the controller [1655797739.654178][9399:9399] CHIP:IN: Expiring all connections for fabric 1!! [1655797739.654217][9399:9399] CHIP:IN: SecureSession[0xaaaad891bff0]: MarkForRemoval Type:2 LSID:3897 [1655797739.654255][9399:9399] CHIP:IN: SecureSession[0xaaaad891bff0]: Released - Type:2 LSID:3897 [1655797739.654327][9399:9399] CHIP:CTL: Shutting down the commissioner [1655797739.654415][9399:9399] CHIP:CTL: Shutting down the controller [1655797739.654452][9399:9399] CHIP:IN: Expiring all connections for fabric 2!! [1655797739.654509][9399:9399] CHIP:CTL: Shutting down the commissioner [1655797739.654591][9399:9399] CHIP:CTL: Shutting down the controller [1655797739.654629][9399:9399] CHIP:IN: Expiring all connections for fabric 3!! [1655797739.654679][9399:9399] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655797739.656081][9399:9399] CHIP:DMG: IM WH moving to [Uninitialized] [1655797739.656145][9399:9399] CHIP:DMG: IM WH moving to [Uninitialized] [1655797739.656180][9399:9399] CHIP:DMG: IM WH moving to [Uninitialized] [1655797739.656213][9399:9399] CHIP:DMG: IM WH moving to [Uninitialized] [1655797739.656249][9399:9399] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655797739.656354][9399:9399] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655797739.656805][9399:9399] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-sX1IDg) [1655797739.657917][9399:9399] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797739.658019][9399:9399] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655797739.658064][9399:9399] CHIP:DL: Inet Layer shutdown [1655797739.658100][9399:9399] CHIP:DL: BLE shutdown [1655797739.658136][9399:9399] CHIP:DL: System Layer shutdown ./chip-tool groupkeymanagement read group-table 1 0 [1655797908.019264][9410:9410] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655797908.020052][9410:9410] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655797908.020215][9410:9410] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655797908.020329][9410:9410] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655797908.020718][9410:9410] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-FfwV1M) [1655797908.021340][9410:9410] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797908.021393][9410:9410] CHIP:DL: NVS set: chip-counters/reboot-count = 9 (0x9) [1655797908.022279][9410:9410] CHIP:DL: Got Ethernet interface: eth0 [1655797908.022862][9410:9410] CHIP:DL: Found the primary Ethernet interface:eth0 [1655797908.023443][9410:9410] CHIP:DL: Got WiFi interface: wlan0 [1655797908.023514][9410:9410] CHIP:DL: Failed to reset WiFi statistic counts [1655797908.023602][9410:9410] CHIP:IN: UDP::Init bind&listen port=0 [1655797908.023732][9410:9410] CHIP:IN: UDP::Init bound to port=39234 [1655797908.023757][9410:9410] CHIP:IN: BLEBase::Init - setting/overriding transport [1655797908.023778][9410:9410] CHIP:IN: TransportMgr initialized [1655797908.023825][9410:9410] CHIP:FP: Initializing FabricTable from persistent storage [1655797908.023984][9410:9410] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797908.024069][9410:9410] CHIP:FP: Loading from storage for fabric index 0x1 [1655797908.024566][9410:9410] CHIP:FP: Loading from storage for fabric index 0x2 [1655797908.024921][9410:9410] CHIP:FP: Loading from storage for fabric index 0x3 [1655797908.028453][9410:9410] CHIP:ZCL: Using ZAP configuration... [1655797908.033002][9410:9410] CHIP:DL: Avahi client registered [1655797908.034245][9410:9410] CHIP:CTL: System State Initialized... [1655797908.034335][9410:9410] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797908.034374][9410:9410] CHIP:CTL: Setting attestation nonce to random value [1655797908.034425][9410:9410] CHIP:CTL: Setting CSR nonce to random value [1655797908.034510][9410:9410] CHIP:IN: UDP::Init bind&listen port=5550 [1655797908.034656][9410:9410] CHIP:IN: UDP::Init bound to port=5550 [1655797908.034684][9410:9410] CHIP:IN: TransportMgr initialized [1655797908.034756][9410:9410] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797908.034786][9410:9410] CHIP:CTL: Setting attestation nonce to random value [1655797908.034837][9410:9410] CHIP:CTL: Setting CSR nonce to random value [1655797908.037997][9410:9410] CHIP:CTL: Generating NOC [1655797908.038970][9410:9410] CHIP:FP: Validating NOC chain [1655797908.040977][9410:9410] CHIP:FP: NOC chain validation successful [1655797908.041156][9410:9410] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655797908.041187][9410:9410] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655797908.047218][9410:9410] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655797908.047275][9410:9410] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797908.047303][9410:9410] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797908.047328][9410:9410] CHIP:TS: Retaining current Last Known Good Time [1655797908.048731][9410:9410] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655797908.048800][9410:9410] CHIP:IN: UDP::Init bind&listen port=5550 [1655797908.048925][9410:9410] CHIP:IN: UDP::Init bound to port=5550 [1655797908.048951][9410:9410] CHIP:IN: TransportMgr initialized [1655797908.049047][9410:9410] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797908.049088][9410:9410] CHIP:CTL: Setting attestation nonce to random value [1655797908.049149][9410:9410] CHIP:CTL: Setting CSR nonce to random value [1655797908.049974][9410:9410] CHIP:CTL: Generating NOC [1655797908.050762][9410:9410] CHIP:FP: Validating NOC chain [1655797908.052495][9410:9410] CHIP:FP: NOC chain validation successful [1655797908.052650][9410:9410] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655797908.052678][9410:9410] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655797908.057972][9410:9410] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655797908.058022][9410:9410] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797908.058047][9410:9410] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797908.058068][9410:9410] CHIP:TS: Retaining current Last Known Good Time [1655797908.059348][9410:9410] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655797908.059412][9410:9410] CHIP:IN: UDP::Init bind&listen port=5550 [1655797908.059535][9410:9410] CHIP:IN: UDP::Init bound to port=5550 [1655797908.059561][9410:9410] CHIP:IN: TransportMgr initialized [1655797908.059657][9410:9410] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655797908.059694][9410:9410] CHIP:CTL: Setting attestation nonce to random value [1655797908.059756][9410:9410] CHIP:CTL: Setting CSR nonce to random value [1655797908.060616][9410:9410] CHIP:CTL: Generating NOC [1655797908.061444][9410:9410] CHIP:FP: Validating NOC chain [1655797908.063129][9410:9410] CHIP:FP: NOC chain validation successful [1655797908.063279][9410:9410] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655797908.063305][9410:9410] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655797908.068620][9410:9410] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655797908.068670][9410:9410] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655797908.068694][9410:9410] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655797908.068716][9410:9410] CHIP:TS: Retaining current Last Known Good Time [1655797908.070270][9410:9410] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655797908.070344][9410:9410] CHIP:IN: UDP::Init bind&listen port=5550 [1655797908.070473][9410:9410] CHIP:IN: UDP::Init bound to port=5550 [1655797908.070499][9410:9410] CHIP:IN: TransportMgr initialized [1655797908.105237][9410:9415] CHIP:DL: CHIP task running [1655797908.105492][9410:9415] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655797908.105550][9410:9415] CHIP:TOO: Sending command to node 0x1 [1655797908.105589][9410:9415] CHIP:CSM: FindOrEstablishSession: PeerId = 4783EB7116FFC3BC:0000000000000001 [1655797908.105618][9410:9415] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655797908.105661][9410:9415] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 1 --> 2 [1655797908.105694][9410:9415] CHIP:DIS: Resolving 4783EB7116FFC3BC:0000000000000001 ... [1655797908.219294][9410:9415] CHIP:DL: Avahi resolve found [1655797908.219391][9410:9415] CHIP:DIS: Node ID resolved for 4783EB7116FFC3BC:0000000000000001 [1655797908.219420][9410:9415] CHIP:DIS: Hostname: E45F010EBEFC0000 [1655797908.219450][9410:9415] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0e:befc [1655797908.219474][9410:9415] CHIP:DIS: Port: 5540 [1655797908.219497][9410:9415] CHIP:DIS: Mrp Interval idle: 5000 ms [1655797908.219519][9410:9415] CHIP:DIS: Mrp Interval active: 300 ms [1655797908.219782][9410:9415] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540: new best score: 3 [1655797908.219823][9410:9415] CHIP:DIS: Checking node lookup status after 114 ms [1655797908.219845][9410:9415] CHIP:DIS: Keeping DNSSD lookup active [1655797908.306081][9410:9415] CHIP:DIS: Checking node lookup status after 200 ms [1655797908.306371][9410:9415] CHIP:CTL: Updating device address to UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540 while in state 2 [1655797908.306434][9410:9415] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 2 --> 3 [1655797908.306821][9410:9415] CHIP:IN: SecureSession[0xaaaad662a630]: Allocated Type:2 LSID:3888 [1655797908.306905][9410:9415] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655797908.308497][9410:9415] CHIP:SC: Including MRP parameters [1655797908.308989][9410:9415] CHIP:IN: Prepared unauthenticated message 0xaaaad6625d98 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 2981i with MessageCounter:265734703. [1655797908.309097][9410:9415] CHIP:IN: Sending unauthenticated msg 0xaaaad6625d98 with MessageCounter:265734703 to 0x0000000000000000 at monotonic time: 0000000000AF9B18 msec [1655797908.309435][9410:9415] CHIP:SC: Sent Sigma1 msg [1655797908.309505][9410:9415] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 3 --> 4 [1655797908.309571][9410:9415] CHIP:DIS: Discovery does not require any more timeouts [1655797908.310841][9410:9415] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:8995138 on exchange 2981i [1655797908.310916][9410:9415] CHIP:EM: Found matching exchange: 2981i, Delegate: 0xffff7c0011a0 [1655797908.310993][9410:9415] CHIP:EM: Rxd Ack; Removing MessageCounter:265734703 from Retrans Table on exchange 2981i [1655797908.311052][9410:9415] CHIP:EM: Removed CHIP MessageCounter:265734703 from RetransTable on exchange 2981i [1655797908.311125][9410:9415] CHIP:SC: Received Sigma2Resume msg [1655797908.311281][9410:9415] CHIP:SC: Found MRP parameters in the message [1655797908.311349][9410:9415] CHIP:SC: Peer assigned session session ID 1173 [1655797908.319069][9410:9415] CHIP:SC: Sending status report. Protocol code 0, exchange 2981 [1655797908.319144][9410:9415] CHIP:EM: Piggybacking Ack for MessageCounter:8995138 on exchange: 2981i [1655797908.319198][9410:9415] CHIP:IN: Prepared unauthenticated message 0xaaaad6625d98 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 2981i with MessageCounter:265734704. [1655797908.319249][9410:9415] CHIP:IN: Sending unauthenticated msg 0xaaaad6625d98 with MessageCounter:265734704 to 0x0000000000000000 at monotonic time: 0000000000AF9B22 msec [1655797908.319517][9410:9415] CHIP:IN: SecureSession[0xaaaad662a630]: Activated - Type:2 LSID:3888 [1655797908.319554][9410:9415] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:3888 PSID:1173! [1655797908.319585][9410:9415] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 4 --> 5 [1655797908.319685][9410:9415] CHIP:TOO: cluster 0x0000_003F, attribute: 0x0000_0001, endpoint 0 [1655797908.319818][9410:9415] CHIP:TOO: Sending ReadAttribute to: [1655797908.319862][9410:9415] CHIP:DMG: SendReadRequest ReadClient[0xffff7c005980]: Sending Read Request [1655797908.319990][9410:9415] CHIP:IN: Prepared secure message 0xaaaad6625db8 to 0x0000000000000001 (1) of type 0x2 and protocolId (0, 1) on exchange 2982i with MessageCounter:96600905. [1655797908.320038][9410:9415] CHIP:IN: Sending encrypted msg 0xaaaad6625db8 with MessageCounter:96600905 to 0x0000000000000001 (1) at monotonic time: 0000000000AF9B23 msec [1655797908.320193][9410:9415] CHIP:DMG: MoveToState ReadClient[0xffff7c005980]: Moving to [AwaitingIn] [1655797908.328621][9410:9415] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8995139 on exchange 2981i [1655797908.328661][9410:9415] CHIP:EM: Found matching exchange: 2981i, Delegate: (nil) [1655797908.328703][9410:9415] CHIP:EM: Rxd Ack; Removing MessageCounter:265734704 from Retrans Table on exchange 2981i [1655797908.328731][9410:9415] CHIP:EM: Removed CHIP MessageCounter:265734704 from RetransTable on exchange 2981i [1655797908.332066][9410:9415] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:36642417 on exchange 2982i [1655797908.332110][9410:9415] CHIP:EM: Found matching exchange: 2982i, Delegate: 0xffff7c005980 [1655797908.332154][9410:9415] CHIP:EM: Rxd Ack; Removing MessageCounter:96600905 from Retrans Table on exchange 2982i [1655797908.332188][9410:9415] CHIP:EM: Removed CHIP MessageCounter:96600905 from RetransTable on exchange 2982i [1655797908.332273][9410:9415] CHIP:DMG: ReportDataMessage = [1655797908.332312][9410:9415] CHIP:DMG: { [1655797908.332344][9410:9415] CHIP:DMG: AttributeReportIBs = [1655797908.332411][9410:9415] CHIP:DMG: [ [1655797908.332449][9410:9415] CHIP:DMG: AttributeReportIB = [1655797908.332496][9410:9415] CHIP:DMG: { [1655797908.332534][9410:9415] CHIP:DMG: AttributeDataIB = [1655797908.332586][9410:9415] CHIP:DMG: { [1655797908.332633][9410:9415] CHIP:DMG: DataVersion = 0x62f194d6, [1655797908.332679][9410:9415] CHIP:DMG: AttributePathIB = [1655797908.332729][9410:9415] CHIP:DMG: { [1655797908.332783][9410:9415] CHIP:DMG: Endpoint = 0x0, [1655797908.332839][9410:9415] CHIP:DMG: Cluster = 0x3f, [1655797908.332894][9410:9415] CHIP:DMG: Attribute = 0x0000_0001, [1655797908.332943][9410:9415] CHIP:DMG: } [1655797908.332994][9410:9415] CHIP:DMG: [1655797908.333042][9410:9415] CHIP:DMG: Data = [ [1655797908.333091][9410:9415] CHIP:DMG: [1655797908.333142][9410:9415] CHIP:DMG: ], [1655797908.333191][9410:9415] CHIP:DMG: }, [1655797908.333239][9410:9415] CHIP:DMG: [1655797908.333279][9410:9415] CHIP:DMG: }, [1655797908.333339][9410:9415] CHIP:DMG: [1655797908.333375][9410:9415] CHIP:DMG: AttributeReportIB = [1655797908.333429][9410:9415] CHIP:DMG: { [1655797908.333469][9410:9415] CHIP:DMG: AttributeDataIB = [1655797908.333514][9410:9415] CHIP:DMG: { [1655797908.333565][9410:9415] CHIP:DMG: DataVersion = 0x62f194d6, [1655797908.333615][9410:9415] CHIP:DMG: AttributePathIB = [1655797908.333662][9410:9415] CHIP:DMG: { [1655797908.333714][9410:9415] CHIP:DMG: Endpoint = 0x0, [1655797908.333769][9410:9415] CHIP:DMG: Cluster = 0x3f, [1655797908.333821][9410:9415] CHIP:DMG: Attribute = 0x0000_0001, [1655797908.333872][9410:9415] CHIP:DMG: ListIndex = Null, [1655797908.333920][9410:9415] CHIP:DMG: } [1655797908.333970][9410:9415] CHIP:DMG: [1655797908.334017][9410:9415] CHIP:DMG: Data = [1655797908.334064][9410:9415] CHIP:DMG: { [1655797908.334142][9410:9415] CHIP:DMG: 0xfe = 1, [1655797908.334194][9410:9415] CHIP:DMG: 0x1 = 1, [1655797908.334243][9410:9415] CHIP:DMG: 0x2 = [ [1655797908.334295][9410:9415] CHIP:DMG: 0, [1655797908.334353][9410:9415] CHIP:DMG: ], [1655797908.334407][9410:9415] CHIP:DMG: 0x3 = "grp1", [1655797908.334456][9410:9415] CHIP:DMG: }, [1655797908.334501][9410:9415] CHIP:DMG: }, [1655797908.334555][9410:9415] CHIP:DMG: [1655797908.334595][9410:9415] CHIP:DMG: }, [1655797908.334645][9410:9415] CHIP:DMG: [1655797908.334680][9410:9415] CHIP:DMG: ], [1655797908.334734][9410:9415] CHIP:DMG: [1655797908.334771][9410:9415] CHIP:DMG: SuppressResponse = true, [1655797908.334811][9410:9415] CHIP:DMG: InteractionModelRevision = 1 [1655797908.334846][9410:9415] CHIP:DMG: } [1655797908.335185][9410:9415] CHIP:TOO: Endpoint: 0 Cluster: 0x0000_003F Attribute 0x0000_0001 DataVersion: 1659999446 [1655797908.335315][9410:9415] CHIP:TOO: GroupTable: 1 entries [1655797908.335408][9410:9415] CHIP:TOO: [1]: { [1655797908.335461][9410:9415] CHIP:TOO: GroupId: 1 [1655797908.335500][9410:9415] CHIP:TOO: Endpoints: 1 entries [1655797908.335541][9410:9415] CHIP:TOO: [1]: 0 [1655797908.335580][9410:9415] CHIP:TOO: GroupName: grp1 [1655797908.335616][9410:9415] CHIP:TOO: FabricIndex: 1 [1655797908.335649][9410:9415] CHIP:TOO: } [1655797908.335750][9410:9415] CHIP:EM: Sending Standalone Ack for MessageCounter:36642417 on exchange 2982i [1655797908.335840][9410:9415] CHIP:IN: Prepared secure message 0xffff83ffd958 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 2982i with MessageCounter:96600906. [1655797908.335895][9410:9415] CHIP:IN: Sending encrypted msg 0xffff83ffd958 with MessageCounter:96600906 to 0x0000000000000001 (1) at monotonic time: 0000000000AF9B33 msec [1655797908.336042][9410:9415] CHIP:EM: Flushed pending ack for MessageCounter:36642417 on exchange 2982i [1655797908.336282][9410:9410] CHIP:CTL: Shutting down the commissioner [1655797908.336434][9410:9410] CHIP:CTL: Shutting down the controller [1655797908.336482][9410:9410] CHIP:CTL: Shutting down the commissioner [1655797908.336559][9410:9410] CHIP:CTL: Shutting down the controller [1655797908.336604][9410:9410] CHIP:IN: Expiring all connections for fabric 1!! [1655797908.336638][9410:9410] CHIP:IN: SecureSession[0xaaaad662a630]: MarkForRemoval Type:2 LSID:3888 [1655797908.336671][9410:9410] CHIP:IN: SecureSession[0xaaaad662a630]: Released - Type:2 LSID:3888 [1655797908.336733][9410:9410] CHIP:CTL: Shutting down the commissioner [1655797908.336809][9410:9410] CHIP:CTL: Shutting down the controller [1655797908.336844][9410:9410] CHIP:IN: Expiring all connections for fabric 2!! [1655797908.336893][9410:9410] CHIP:CTL: Shutting down the commissioner [1655797908.336965][9410:9410] CHIP:CTL: Shutting down the controller [1655797908.336998][9410:9410] CHIP:IN: Expiring all connections for fabric 3!! [1655797908.337043][9410:9410] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655797908.338233][9410:9410] CHIP:DMG: IM WH moving to [Uninitialized] [1655797908.338285][9410:9410] CHIP:DMG: IM WH moving to [Uninitialized] [1655797908.338317][9410:9410] CHIP:DMG: IM WH moving to [Uninitialized] [1655797908.338346][9410:9410] CHIP:DMG: IM WH moving to [Uninitialized] [1655797908.338378][9410:9410] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655797908.338468][9410:9410] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655797908.338816][9410:9410] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-9xs9Iv) [1655797908.339685][9410:9410] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655797908.339773][9410:9410] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655797908.339812][9410:9410] CHIP:DL: Inet Layer shutdown [1655797908.339845][9410:9410] CHIP:DL: BLE shutdown [1655797908.339878][9410:9410] CHIP:DL: System Layer shutdown ./chip-tool groupsettings add-group grp1 0x0001 [1655798009.765096][9425:9425] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655798009.765653][9425:9425] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655798009.765816][9425:9425] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655798009.765931][9425:9425] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655798009.766289][9425:9425] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-MfGIw2) [1655798009.767000][9425:9425] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798009.767054][9425:9425] CHIP:DL: NVS set: chip-counters/reboot-count = 10 (0xA) [1655798009.768010][9425:9425] CHIP:DL: Got Ethernet interface: eth0 [1655798009.768766][9425:9425] CHIP:DL: Found the primary Ethernet interface:eth0 [1655798009.769446][9425:9425] CHIP:DL: Got WiFi interface: wlan0 [1655798009.769528][9425:9425] CHIP:DL: Failed to reset WiFi statistic counts [1655798009.769624][9425:9425] CHIP:IN: UDP::Init bind&listen port=0 [1655798009.769772][9425:9425] CHIP:IN: UDP::Init bound to port=56272 [1655798009.769803][9425:9425] CHIP:IN: BLEBase::Init - setting/overriding transport [1655798009.769827][9425:9425] CHIP:IN: TransportMgr initialized [1655798009.769880][9425:9425] CHIP:FP: Initializing FabricTable from persistent storage [1655798009.770062][9425:9425] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798009.770164][9425:9425] CHIP:FP: Loading from storage for fabric index 0x1 [1655798009.770697][9425:9425] CHIP:FP: Loading from storage for fabric index 0x2 [1655798009.771106][9425:9425] CHIP:FP: Loading from storage for fabric index 0x3 [1655798009.774987][9425:9425] CHIP:ZCL: Using ZAP configuration... [1655798009.779767][9425:9425] CHIP:DL: Avahi client registered [1655798009.781252][9425:9425] CHIP:CTL: System State Initialized... [1655798009.781364][9425:9425] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798009.781404][9425:9425] CHIP:CTL: Setting attestation nonce to random value [1655798009.781457][9425:9425] CHIP:CTL: Setting CSR nonce to random value [1655798009.781575][9425:9425] CHIP:IN: UDP::Init bind&listen port=5550 [1655798009.781745][9425:9425] CHIP:IN: UDP::Init bound to port=5550 [1655798009.781772][9425:9425] CHIP:IN: TransportMgr initialized [1655798009.781847][9425:9425] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798009.781891][9425:9425] CHIP:CTL: Setting attestation nonce to random value [1655798009.781942][9425:9425] CHIP:CTL: Setting CSR nonce to random value [1655798009.784936][9425:9425] CHIP:CTL: Generating NOC [1655798009.785817][9425:9425] CHIP:FP: Validating NOC chain [1655798009.787675][9425:9425] CHIP:FP: NOC chain validation successful [1655798009.787956][9425:9425] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655798009.787987][9425:9425] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655798009.794183][9425:9425] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655798009.794242][9425:9425] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798009.794271][9425:9425] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798009.794295][9425:9425] CHIP:TS: Retaining current Last Known Good Time [1655798009.795847][9425:9425] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655798009.795924][9425:9425] CHIP:IN: UDP::Init bind&listen port=5550 [1655798009.796077][9425:9425] CHIP:IN: UDP::Init bound to port=5550 [1655798009.796118][9425:9425] CHIP:IN: TransportMgr initialized [1655798009.796237][9425:9425] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798009.796280][9425:9425] CHIP:CTL: Setting attestation nonce to random value [1655798009.796349][9425:9425] CHIP:CTL: Setting CSR nonce to random value [1655798009.797380][9425:9425] CHIP:CTL: Generating NOC [1655798009.798285][9425:9425] CHIP:FP: Validating NOC chain [1655798009.800337][9425:9425] CHIP:FP: NOC chain validation successful [1655798009.800531][9425:9425] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655798009.800559][9425:9425] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655798009.805978][9425:9425] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655798009.806027][9425:9425] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798009.806052][9425:9425] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798009.806074][9425:9425] CHIP:TS: Retaining current Last Known Good Time [1655798009.807448][9425:9425] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655798009.807520][9425:9425] CHIP:IN: UDP::Init bind&listen port=5550 [1655798009.807656][9425:9425] CHIP:IN: UDP::Init bound to port=5550 [1655798009.807682][9425:9425] CHIP:IN: TransportMgr initialized [1655798009.807784][9425:9425] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798009.807831][9425:9425] CHIP:CTL: Setting attestation nonce to random value [1655798009.807891][9425:9425] CHIP:CTL: Setting CSR nonce to random value [1655798009.808808][9425:9425] CHIP:CTL: Generating NOC [1655798009.809663][9425:9425] CHIP:FP: Validating NOC chain [1655798009.811395][9425:9425] CHIP:FP: NOC chain validation successful [1655798009.811546][9425:9425] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655798009.811573][9425:9425] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655798009.817071][9425:9425] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655798009.817122][9425:9425] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798009.817147][9425:9425] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798009.817169][9425:9425] CHIP:TS: Retaining current Last Known Good Time [1655798009.818513][9425:9425] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655798009.818579][9425:9425] CHIP:IN: UDP::Init bind&listen port=5550 [1655798009.818706][9425:9425] CHIP:IN: UDP::Init bound to port=5550 [1655798009.818730][9425:9425] CHIP:IN: TransportMgr initialized [1655798009.854642][9425:9430] CHIP:DL: CHIP task running [1655798009.854911][9425:9430] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655798009.860529][9425:9425] CHIP:CTL: Shutting down the commissioner [1655798009.860648][9425:9425] CHIP:CTL: Shutting down the controller [1655798009.860682][9425:9425] CHIP:CTL: Shutting down the commissioner [1655798009.860735][9425:9425] CHIP:CTL: Shutting down the controller [1655798009.860761][9425:9425] CHIP:IN: Expiring all connections for fabric 1!! [1655798009.860831][9425:9425] CHIP:CTL: Shutting down the commissioner [1655798009.860907][9425:9425] CHIP:CTL: Shutting down the controller [1655798009.860929][9425:9425] CHIP:IN: Expiring all connections for fabric 2!! [1655798009.860971][9425:9425] CHIP:CTL: Shutting down the commissioner [1655798009.861031][9425:9425] CHIP:CTL: Shutting down the controller [1655798009.861057][9425:9425] CHIP:IN: Expiring all connections for fabric 3!! [1655798009.861104][9425:9425] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655798009.862164][9425:9425] CHIP:DMG: IM WH moving to [Uninitialized] [1655798009.862211][9425:9425] CHIP:DMG: IM WH moving to [Uninitialized] [1655798009.862237][9425:9425] CHIP:DMG: IM WH moving to [Uninitialized] [1655798009.862259][9425:9425] CHIP:DMG: IM WH moving to [Uninitialized] [1655798009.862282][9425:9425] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655798009.862374][9425:9425] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655798009.862679][9425:9425] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-HhbbQt) [1655798009.863493][9425:9425] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798009.863575][9425:9425] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655798009.863603][9425:9425] CHIP:DL: Inet Layer shutdown [1655798009.863625][9425:9425] CHIP:DL: BLE shutdown [1655798009.863647][9425:9425] CHIP:DL: System Layer shutdown ./chip-tool groupsettings add-keysets 0x42 0 0x000000000021dfe hex:d0d1d2d3d4d5d6d7d8d9dadbdcdddedf [1655798052.902014][9433:9433] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655798052.902548][9433:9433] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655798052.902712][9433:9433] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655798052.902822][9433:9433] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655798052.903172][9433:9433] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-lOEfdM) [1655798052.903808][9433:9433] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798052.903861][9433:9433] CHIP:DL: NVS set: chip-counters/reboot-count = 11 (0xB) [1655798052.904858][9433:9433] CHIP:DL: Got Ethernet interface: eth0 [1655798052.905439][9433:9433] CHIP:DL: Found the primary Ethernet interface:eth0 [1655798052.906021][9433:9433] CHIP:DL: Got WiFi interface: wlan0 [1655798052.906096][9433:9433] CHIP:DL: Failed to reset WiFi statistic counts [1655798052.906186][9433:9433] CHIP:IN: UDP::Init bind&listen port=0 [1655798052.906317][9433:9433] CHIP:IN: UDP::Init bound to port=34714 [1655798052.906343][9433:9433] CHIP:IN: BLEBase::Init - setting/overriding transport [1655798052.906365][9433:9433] CHIP:IN: TransportMgr initialized [1655798052.906426][9433:9433] CHIP:FP: Initializing FabricTable from persistent storage [1655798052.906592][9433:9433] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798052.906678][9433:9433] CHIP:FP: Loading from storage for fabric index 0x1 [1655798052.907166][9433:9433] CHIP:FP: Loading from storage for fabric index 0x2 [1655798052.907526][9433:9433] CHIP:FP: Loading from storage for fabric index 0x3 [1655798052.911204][9433:9433] CHIP:ZCL: Using ZAP configuration... [1655798052.915501][9433:9433] CHIP:DL: Avahi client registered [1655798052.916815][9433:9433] CHIP:CTL: System State Initialized... [1655798052.916907][9433:9433] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798052.916948][9433:9433] CHIP:CTL: Setting attestation nonce to random value [1655798052.917000][9433:9433] CHIP:CTL: Setting CSR nonce to random value [1655798052.917114][9433:9433] CHIP:IN: UDP::Init bind&listen port=5550 [1655798052.917283][9433:9433] CHIP:IN: UDP::Init bound to port=5550 [1655798052.917310][9433:9433] CHIP:IN: TransportMgr initialized [1655798052.917418][9433:9433] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798052.917448][9433:9433] CHIP:CTL: Setting attestation nonce to random value [1655798052.917498][9433:9433] CHIP:CTL: Setting CSR nonce to random value [1655798052.920604][9433:9433] CHIP:CTL: Generating NOC [1655798052.921496][9433:9433] CHIP:FP: Validating NOC chain [1655798052.924036][9433:9433] CHIP:FP: NOC chain validation successful [1655798052.924263][9433:9433] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655798052.924301][9433:9433] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655798052.932170][9433:9433] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655798052.932237][9433:9433] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798052.932273][9433:9433] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798052.932305][9433:9433] CHIP:TS: Retaining current Last Known Good Time [1655798052.933748][9433:9433] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655798052.933819][9433:9433] CHIP:IN: UDP::Init bind&listen port=5550 [1655798052.933943][9433:9433] CHIP:IN: UDP::Init bound to port=5550 [1655798052.933968][9433:9433] CHIP:IN: TransportMgr initialized [1655798052.934066][9433:9433] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798052.934103][9433:9433] CHIP:CTL: Setting attestation nonce to random value [1655798052.934166][9433:9433] CHIP:CTL: Setting CSR nonce to random value [1655798052.934988][9433:9433] CHIP:CTL: Generating NOC [1655798052.935773][9433:9433] CHIP:FP: Validating NOC chain [1655798052.937502][9433:9433] CHIP:FP: NOC chain validation successful [1655798052.937654][9433:9433] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655798052.937681][9433:9433] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655798052.943048][9433:9433] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655798052.943099][9433:9433] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798052.943124][9433:9433] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798052.943145][9433:9433] CHIP:TS: Retaining current Last Known Good Time [1655798052.944566][9433:9433] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655798052.944639][9433:9433] CHIP:IN: UDP::Init bind&listen port=5550 [1655798052.944765][9433:9433] CHIP:IN: UDP::Init bound to port=5550 [1655798052.944792][9433:9433] CHIP:IN: TransportMgr initialized [1655798052.944918][9433:9433] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798052.944960][9433:9433] CHIP:CTL: Setting attestation nonce to random value [1655798052.945024][9433:9433] CHIP:CTL: Setting CSR nonce to random value [1655798052.945887][9433:9433] CHIP:CTL: Generating NOC [1655798052.946753][9433:9433] CHIP:FP: Validating NOC chain [1655798052.948548][9433:9433] CHIP:FP: NOC chain validation successful [1655798052.948729][9433:9433] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655798052.948755][9433:9433] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655798052.954647][9433:9433] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655798052.954706][9433:9433] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798052.954731][9433:9433] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798052.954753][9433:9433] CHIP:TS: Retaining current Last Known Good Time [1655798052.956204][9433:9433] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655798052.956282][9433:9433] CHIP:IN: UDP::Init bind&listen port=5550 [1655798052.956483][9433:9433] CHIP:IN: UDP::Init bound to port=5550 [1655798052.956511][9433:9433] CHIP:IN: TransportMgr initialized [1655798052.994765][9433:9438] CHIP:DL: CHIP task running [1655798052.995003][9433:9438] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655798052.998774][9433:9433] CHIP:CTL: Shutting down the commissioner [1655798052.998873][9433:9433] CHIP:CTL: Shutting down the controller [1655798052.998904][9433:9433] CHIP:CTL: Shutting down the commissioner [1655798052.998955][9433:9433] CHIP:CTL: Shutting down the controller [1655798052.998980][9433:9433] CHIP:IN: Expiring all connections for fabric 1!! [1655798052.999046][9433:9433] CHIP:CTL: Shutting down the commissioner [1655798052.999109][9433:9433] CHIP:CTL: Shutting down the controller [1655798052.999141][9433:9433] CHIP:IN: Expiring all connections for fabric 2!! [1655798052.999176][9433:9433] CHIP:CTL: Shutting down the commissioner [1655798052.999237][9433:9433] CHIP:CTL: Shutting down the controller [1655798052.999260][9433:9433] CHIP:IN: Expiring all connections for fabric 3!! [1655798052.999292][9433:9433] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655798053.000258][9433:9433] CHIP:DMG: IM WH moving to [Uninitialized] [1655798053.000297][9433:9433] CHIP:DMG: IM WH moving to [Uninitialized] [1655798053.000319][9433:9433] CHIP:DMG: IM WH moving to [Uninitialized] [1655798053.000339][9433:9433] CHIP:DMG: IM WH moving to [Uninitialized] [1655798053.000362][9433:9433] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655798053.000458][9433:9433] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655798053.000783][9433:9433] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-WUD3rK) [1655798053.001484][9433:9433] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798053.001549][9433:9433] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655798053.001576][9433:9433] CHIP:DL: Inet Layer shutdown [1655798053.001598][9433:9433] CHIP:DL: BLE shutdown [1655798053.001621][9433:9433] CHIP:DL: System Layer shutdown ./chip-tool groupsettings bind-keyset 0x0001 0x42 [1655798085.804480][9439:9439] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655798085.805055][9439:9439] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655798085.805258][9439:9439] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655798085.805379][9439:9439] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655798085.805757][9439:9439] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-7nkKLy) [1655798085.806441][9439:9439] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798085.806505][9439:9439] CHIP:DL: NVS set: chip-counters/reboot-count = 12 (0xC) [1655798085.807419][9439:9439] CHIP:DL: Got Ethernet interface: eth0 [1655798085.808080][9439:9439] CHIP:DL: Found the primary Ethernet interface:eth0 [1655798085.808795][9439:9439] CHIP:DL: Got WiFi interface: wlan0 [1655798085.808883][9439:9439] CHIP:DL: Failed to reset WiFi statistic counts [1655798085.808993][9439:9439] CHIP:IN: UDP::Init bind&listen port=0 [1655798085.809150][9439:9439] CHIP:IN: UDP::Init bound to port=60929 [1655798085.809180][9439:9439] CHIP:IN: BLEBase::Init - setting/overriding transport [1655798085.809202][9439:9439] CHIP:IN: TransportMgr initialized [1655798085.809253][9439:9439] CHIP:FP: Initializing FabricTable from persistent storage [1655798085.809457][9439:9439] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798085.809553][9439:9439] CHIP:FP: Loading from storage for fabric index 0x1 [1655798085.810102][9439:9439] CHIP:FP: Loading from storage for fabric index 0x2 [1655798085.810522][9439:9439] CHIP:FP: Loading from storage for fabric index 0x3 [1655798085.814243][9439:9439] CHIP:ZCL: Using ZAP configuration... [1655798085.818807][9439:9439] CHIP:DL: Avahi client registered [1655798085.820249][9439:9439] CHIP:CTL: System State Initialized... [1655798085.820360][9439:9439] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798085.820435][9439:9439] CHIP:CTL: Setting attestation nonce to random value [1655798085.820490][9439:9439] CHIP:CTL: Setting CSR nonce to random value [1655798085.820588][9439:9439] CHIP:IN: UDP::Init bind&listen port=5550 [1655798085.820761][9439:9439] CHIP:IN: UDP::Init bound to port=5550 [1655798085.820790][9439:9439] CHIP:IN: TransportMgr initialized [1655798085.820878][9439:9439] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798085.820923][9439:9439] CHIP:CTL: Setting attestation nonce to random value [1655798085.820976][9439:9439] CHIP:CTL: Setting CSR nonce to random value [1655798085.823824][9439:9439] CHIP:CTL: Generating NOC [1655798085.824830][9439:9439] CHIP:FP: Validating NOC chain [1655798085.826696][9439:9439] CHIP:FP: NOC chain validation successful [1655798085.826909][9439:9439] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655798085.826941][9439:9439] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655798085.833367][9439:9439] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655798085.833433][9439:9439] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798085.833457][9439:9439] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798085.833479][9439:9439] CHIP:TS: Retaining current Last Known Good Time [1655798085.835064][9439:9439] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655798085.835152][9439:9439] CHIP:IN: UDP::Init bind&listen port=5550 [1655798085.835283][9439:9439] CHIP:IN: UDP::Init bound to port=5550 [1655798085.835330][9439:9439] CHIP:IN: TransportMgr initialized [1655798085.835459][9439:9439] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798085.835509][9439:9439] CHIP:CTL: Setting attestation nonce to random value [1655798085.835572][9439:9439] CHIP:CTL: Setting CSR nonce to random value [1655798085.836557][9439:9439] CHIP:CTL: Generating NOC [1655798085.837471][9439:9439] CHIP:FP: Validating NOC chain [1655798085.839279][9439:9439] CHIP:FP: NOC chain validation successful [1655798085.839489][9439:9439] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655798085.839521][9439:9439] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655798085.845676][9439:9439] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655798085.845738][9439:9439] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798085.845764][9439:9439] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798085.845786][9439:9439] CHIP:TS: Retaining current Last Known Good Time [1655798085.847299][9439:9439] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655798085.847386][9439:9439] CHIP:IN: UDP::Init bind&listen port=5550 [1655798085.847523][9439:9439] CHIP:IN: UDP::Init bound to port=5550 [1655798085.847550][9439:9439] CHIP:IN: TransportMgr initialized [1655798085.847664][9439:9439] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798085.847705][9439:9439] CHIP:CTL: Setting attestation nonce to random value [1655798085.847768][9439:9439] CHIP:CTL: Setting CSR nonce to random value [1655798085.848700][9439:9439] CHIP:CTL: Generating NOC [1655798085.849595][9439:9439] CHIP:FP: Validating NOC chain [1655798085.851383][9439:9439] CHIP:FP: NOC chain validation successful [1655798085.851582][9439:9439] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655798085.851609][9439:9439] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655798085.857202][9439:9439] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655798085.857250][9439:9439] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798085.857275][9439:9439] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798085.857297][9439:9439] CHIP:TS: Retaining current Last Known Good Time [1655798085.858615][9439:9439] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655798085.858683][9439:9439] CHIP:IN: UDP::Init bind&listen port=5550 [1655798085.858807][9439:9439] CHIP:IN: UDP::Init bound to port=5550 [1655798085.858831][9439:9439] CHIP:IN: TransportMgr initialized [1655798085.892179][9439:9444] CHIP:DL: CHIP task running [1655798085.892466][9439:9444] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655798085.898010][9439:9439] CHIP:CTL: Shutting down the commissioner [1655798085.898126][9439:9439] CHIP:CTL: Shutting down the controller [1655798085.898165][9439:9439] CHIP:CTL: Shutting down the commissioner [1655798085.898230][9439:9439] CHIP:CTL: Shutting down the controller [1655798085.898259][9439:9439] CHIP:IN: Expiring all connections for fabric 1!! [1655798085.898314][9439:9439] CHIP:CTL: Shutting down the commissioner [1655798085.898378][9439:9439] CHIP:CTL: Shutting down the controller [1655798085.898406][9439:9439] CHIP:IN: Expiring all connections for fabric 2!! [1655798085.898449][9439:9439] CHIP:CTL: Shutting down the commissioner [1655798085.898513][9439:9439] CHIP:CTL: Shutting down the controller [1655798085.898541][9439:9439] CHIP:IN: Expiring all connections for fabric 3!! [1655798085.898581][9439:9439] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655798085.899676][9439:9439] CHIP:DMG: IM WH moving to [Uninitialized] [1655798085.899728][9439:9439] CHIP:DMG: IM WH moving to [Uninitialized] [1655798085.899753][9439:9439] CHIP:DMG: IM WH moving to [Uninitialized] [1655798085.899778][9439:9439] CHIP:DMG: IM WH moving to [Uninitialized] [1655798085.899805][9439:9439] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655798085.899888][9439:9439] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655798085.900240][9439:9439] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-bJ0ew3) [1655798085.901102][9439:9439] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798085.901181][9439:9439] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655798085.901215][9439:9439] CHIP:DL: Inet Layer shutdown [1655798085.901242][9439:9439] CHIP:DL: BLE shutdown [1655798085.901269][9439:9439] CHIP:DL: System Layer shutdown ./chip-tool groupsettings show-groups [1655798112.900691][9446:9446] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655798112.901261][9446:9446] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655798112.901436][9446:9446] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655798112.901548][9446:9446] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655798112.901936][9446:9446] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-4XXO7F) [1655798112.902587][9446:9446] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798112.902639][9446:9446] CHIP:DL: NVS set: chip-counters/reboot-count = 13 (0xD) [1655798112.903553][9446:9446] CHIP:DL: Got Ethernet interface: eth0 [1655798112.904156][9446:9446] CHIP:DL: Found the primary Ethernet interface:eth0 [1655798112.904955][9446:9446] CHIP:DL: Got WiFi interface: wlan0 [1655798112.905047][9446:9446] CHIP:DL: Failed to reset WiFi statistic counts [1655798112.905153][9446:9446] CHIP:IN: UDP::Init bind&listen port=0 [1655798112.905345][9446:9446] CHIP:IN: UDP::Init bound to port=47362 [1655798112.905377][9446:9446] CHIP:IN: BLEBase::Init - setting/overriding transport [1655798112.905404][9446:9446] CHIP:IN: TransportMgr initialized [1655798112.905464][9446:9446] CHIP:FP: Initializing FabricTable from persistent storage [1655798112.905698][9446:9446] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798112.905811][9446:9446] CHIP:FP: Loading from storage for fabric index 0x1 [1655798112.906404][9446:9446] CHIP:FP: Loading from storage for fabric index 0x2 [1655798112.906872][9446:9446] CHIP:FP: Loading from storage for fabric index 0x3 [1655798112.911091][9446:9446] CHIP:ZCL: Using ZAP configuration... [1655798112.916062][9446:9446] CHIP:DL: Avahi client registered [1655798112.917421][9446:9446] CHIP:CTL: System State Initialized... [1655798112.917528][9446:9446] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798112.917568][9446:9446] CHIP:CTL: Setting attestation nonce to random value [1655798112.917618][9446:9446] CHIP:CTL: Setting CSR nonce to random value [1655798112.917703][9446:9446] CHIP:IN: UDP::Init bind&listen port=5550 [1655798112.917851][9446:9446] CHIP:IN: UDP::Init bound to port=5550 [1655798112.917879][9446:9446] CHIP:IN: TransportMgr initialized [1655798112.917965][9446:9446] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798112.917994][9446:9446] CHIP:CTL: Setting attestation nonce to random value [1655798112.918046][9446:9446] CHIP:CTL: Setting CSR nonce to random value [1655798112.921003][9446:9446] CHIP:CTL: Generating NOC [1655798112.921855][9446:9446] CHIP:FP: Validating NOC chain [1655798112.923699][9446:9446] CHIP:FP: NOC chain validation successful [1655798112.923951][9446:9446] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655798112.923982][9446:9446] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655798112.930426][9446:9446] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655798112.930482][9446:9446] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798112.930510][9446:9446] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798112.930535][9446:9446] CHIP:TS: Retaining current Last Known Good Time [1655798112.932077][9446:9446] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655798112.932154][9446:9446] CHIP:IN: UDP::Init bind&listen port=5550 [1655798112.932295][9446:9446] CHIP:IN: UDP::Init bound to port=5550 [1655798112.932322][9446:9446] CHIP:IN: TransportMgr initialized [1655798112.932459][9446:9446] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798112.932504][9446:9446] CHIP:CTL: Setting attestation nonce to random value [1655798112.932570][9446:9446] CHIP:CTL: Setting CSR nonce to random value [1655798112.933499][9446:9446] CHIP:CTL: Generating NOC [1655798112.934391][9446:9446] CHIP:FP: Validating NOC chain [1655798112.936465][9446:9446] CHIP:FP: NOC chain validation successful [1655798112.936626][9446:9446] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655798112.936653][9446:9446] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655798112.942114][9446:9446] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655798112.942163][9446:9446] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798112.942187][9446:9446] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798112.942209][9446:9446] CHIP:TS: Retaining current Last Known Good Time [1655798112.943680][9446:9446] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655798112.943755][9446:9446] CHIP:IN: UDP::Init bind&listen port=5550 [1655798112.943880][9446:9446] CHIP:IN: UDP::Init bound to port=5550 [1655798112.943906][9446:9446] CHIP:IN: TransportMgr initialized [1655798112.944010][9446:9446] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798112.944048][9446:9446] CHIP:CTL: Setting attestation nonce to random value [1655798112.944109][9446:9446] CHIP:CTL: Setting CSR nonce to random value [1655798112.944970][9446:9446] CHIP:CTL: Generating NOC [1655798112.945804][9446:9446] CHIP:FP: Validating NOC chain [1655798112.947496][9446:9446] CHIP:FP: NOC chain validation successful [1655798112.947646][9446:9446] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655798112.947673][9446:9446] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655798112.953632][9446:9446] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655798112.953693][9446:9446] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798112.953716][9446:9446] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798112.953739][9446:9446] CHIP:TS: Retaining current Last Known Good Time [1655798112.955283][9446:9446] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655798112.955370][9446:9446] CHIP:IN: UDP::Init bind&listen port=5550 [1655798112.955497][9446:9446] CHIP:IN: UDP::Init bound to port=5550 [1655798112.955524][9446:9446] CHIP:IN: TransportMgr initialized [1655798112.994378][9446:9451] CHIP:DL: CHIP task running [1655798112.994651][9446:9451] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 +-------------------------------------------------------------------------------------+ | Available Groups : | +-------------------------------------------------------------------------------------+ | Group Id | KeySet Id | Group Name | | 0x101 0x1a1 Group #1 | | 0x102 0x1a2 Group #2 | | 0x1 0x42 grp1 | +-------------------------------------------------------------------------------------+ [1655798112.996074][9446:9446] CHIP:CTL: Shutting down the commissioner [1655798112.996173][9446:9446] CHIP:CTL: Shutting down the controller [1655798112.996205][9446:9446] CHIP:CTL: Shutting down the commissioner [1655798112.996258][9446:9446] CHIP:CTL: Shutting down the controller [1655798112.996283][9446:9446] CHIP:IN: Expiring all connections for fabric 1!! [1655798112.996330][9446:9446] CHIP:CTL: Shutting down the commissioner [1655798112.996409][9446:9446] CHIP:CTL: Shutting down the controller [1655798112.996435][9446:9446] CHIP:IN: Expiring all connections for fabric 2!! [1655798112.996472][9446:9446] CHIP:CTL: Shutting down the commissioner [1655798112.996527][9446:9446] CHIP:CTL: Shutting down the controller [1655798112.996549][9446:9446] CHIP:IN: Expiring all connections for fabric 3!! [1655798112.996579][9446:9446] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655798112.997525][9446:9446] CHIP:DMG: IM WH moving to [Uninitialized] [1655798112.997565][9446:9446] CHIP:DMG: IM WH moving to [Uninitialized] [1655798112.997587][9446:9446] CHIP:DMG: IM WH moving to [Uninitialized] [1655798112.997609][9446:9446] CHIP:DMG: IM WH moving to [Uninitialized] [1655798112.997631][9446:9446] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655798112.997699][9446:9446] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655798112.997993][9446:9446] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-NV5QU8) [1655798112.998728][9446:9446] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798112.998796][9446:9446] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655798112.998824][9446:9446] CHIP:DL: Inet Layer shutdown [1655798112.998846][9446:9446] CHIP:DL: BLE shutdown [1655798112.998868][9446:9446] CHIP:DL: System Layer shutdown ./chip-tool basic write node-label newnode 0xffffffffffff0001 0 [1655798250.644868][9462:9462] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655798250.645438][9462:9462] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655798250.645605][9462:9462] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655798250.645714][9462:9462] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655798250.646069][9462:9462] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-0nVALJ) [1655798250.646701][9462:9462] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798250.646756][9462:9462] CHIP:DL: NVS set: chip-counters/reboot-count = 15 (0xF) [1655798250.647613][9462:9462] CHIP:DL: Got Ethernet interface: eth0 [1655798250.648195][9462:9462] CHIP:DL: Found the primary Ethernet interface:eth0 [1655798250.648977][9462:9462] CHIP:DL: Got WiFi interface: wlan0 [1655798250.649057][9462:9462] CHIP:DL: Failed to reset WiFi statistic counts [1655798250.649150][9462:9462] CHIP:IN: UDP::Init bind&listen port=0 [1655798250.649283][9462:9462] CHIP:IN: UDP::Init bound to port=56998 [1655798250.649309][9462:9462] CHIP:IN: BLEBase::Init - setting/overriding transport [1655798250.649330][9462:9462] CHIP:IN: TransportMgr initialized [1655798250.649377][9462:9462] CHIP:FP: Initializing FabricTable from persistent storage [1655798250.649547][9462:9462] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798250.649637][9462:9462] CHIP:FP: Loading from storage for fabric index 0x1 [1655798250.650107][9462:9462] CHIP:FP: Loading from storage for fabric index 0x2 [1655798250.650476][9462:9462] CHIP:FP: Loading from storage for fabric index 0x3 [1655798250.654475][9462:9462] CHIP:ZCL: Using ZAP configuration... [1655798250.659061][9462:9462] CHIP:DL: Avahi client registered [1655798250.660370][9462:9462] CHIP:CTL: System State Initialized... [1655798250.660498][9462:9462] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798250.660541][9462:9462] CHIP:CTL: Setting attestation nonce to random value [1655798250.660596][9462:9462] CHIP:CTL: Setting CSR nonce to random value [1655798250.660696][9462:9462] CHIP:IN: UDP::Init bind&listen port=5550 [1655798250.660875][9462:9462] CHIP:IN: UDP::Init bound to port=5550 [1655798250.660984][9462:9462] CHIP:IN: TransportMgr initialized [1655798250.661091][9462:9462] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798250.661136][9462:9462] CHIP:CTL: Setting attestation nonce to random value [1655798250.661195][9462:9462] CHIP:CTL: Setting CSR nonce to random value [1655798250.664732][9462:9462] CHIP:CTL: Generating NOC [1655798250.665791][9462:9462] CHIP:FP: Validating NOC chain [1655798250.668150][9462:9462] CHIP:FP: NOC chain validation successful [1655798250.668399][9462:9462] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655798250.668437][9462:9462] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655798250.675040][9462:9462] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655798250.675094][9462:9462] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798250.675119][9462:9462] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798250.675140][9462:9462] CHIP:TS: Retaining current Last Known Good Time [1655798250.676583][9462:9462] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655798250.676657][9462:9462] CHIP:IN: UDP::Init bind&listen port=5550 [1655798250.676799][9462:9462] CHIP:IN: UDP::Init bound to port=5550 [1655798250.676826][9462:9462] CHIP:IN: TransportMgr initialized [1655798250.676945][9462:9462] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798250.676983][9462:9462] CHIP:CTL: Setting attestation nonce to random value [1655798250.677043][9462:9462] CHIP:CTL: Setting CSR nonce to random value [1655798250.677917][9462:9462] CHIP:CTL: Generating NOC [1655798250.678734][9462:9462] CHIP:FP: Validating NOC chain [1655798250.680466][9462:9462] CHIP:FP: NOC chain validation successful [1655798250.680636][9462:9462] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655798250.680662][9462:9462] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655798250.686212][9462:9462] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655798250.686260][9462:9462] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798250.686284][9462:9462] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798250.686306][9462:9462] CHIP:TS: Retaining current Last Known Good Time [1655798250.687695][9462:9462] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655798250.687762][9462:9462] CHIP:IN: UDP::Init bind&listen port=5550 [1655798250.687900][9462:9462] CHIP:IN: UDP::Init bound to port=5550 [1655798250.687927][9462:9462] CHIP:IN: TransportMgr initialized [1655798250.688043][9462:9462] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798250.688090][9462:9462] CHIP:CTL: Setting attestation nonce to random value [1655798250.688153][9462:9462] CHIP:CTL: Setting CSR nonce to random value [1655798250.689033][9462:9462] CHIP:CTL: Generating NOC [1655798250.689879][9462:9462] CHIP:FP: Validating NOC chain [1655798250.691614][9462:9462] CHIP:FP: NOC chain validation successful [1655798250.691779][9462:9462] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655798250.691806][9462:9462] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655798250.697370][9462:9462] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655798250.697421][9462:9462] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798250.697445][9462:9462] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798250.697466][9462:9462] CHIP:TS: Retaining current Last Known Good Time [1655798250.698883][9462:9462] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655798250.698954][9462:9462] CHIP:IN: UDP::Init bind&listen port=5550 [1655798250.699094][9462:9462] CHIP:IN: UDP::Init bound to port=5550 [1655798250.699120][9462:9462] CHIP:IN: TransportMgr initialized [1655798250.733351][9462:9467] CHIP:DL: CHIP task running [1655798250.733584][9462:9467] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655798250.733630][9462:9467] CHIP:TOO: Sending command to group 0x1 [1655798250.733685][9462:9467] CHIP:TOO: Sending Write Attribute to Group 1, on Fabric 1, for cluster 40 with attributeId 5 [1655798250.733742][9462:9467] CHIP:DMG: WriteClient moving to [AddAttribu] [1655798250.734324][9462:9467] CHIP:IN: Prepared outgoing group message 0xffff95aa2f28 to 0x0000000000000000 (1) of type 0x6 and protocolId (0, 1) on exchange 37525i with MessageCounter:14000. [1655798250.734388][9462:9467] CHIP:IN: Sending encrypted group msg 0xffff95aa2f28 with MessageCounter:14000 to 1 at monotonic time: 0000000000B4D4B2 msec to Multicast IPV6 address : UDP:[ff35:40:fd00::100:1]:5540 with GroupID of 1 and fabric index of 1 [1655798250.734529][9462:9467] CHIP:DMG: WriteClient moving to [AwaitingRe] [1655798250.734557][9462:9467] CHIP:DMG: Closing on group Communication [1655798250.734577][9462:9467] CHIP:DMG: WriteClient moving to [AwaitingDe] [1655798250.734815][9462:9462] CHIP:CTL: Shutting down the commissioner [1655798250.734902][9462:9462] CHIP:CTL: Shutting down the controller [1655798250.734934][9462:9462] CHIP:CTL: Shutting down the commissioner [1655798250.734984][9462:9462] CHIP:CTL: Shutting down the controller [1655798250.735007][9462:9462] CHIP:IN: Expiring all connections for fabric 1!! [1655798250.735051][9462:9462] CHIP:CTL: Shutting down the commissioner [1655798250.735103][9462:9462] CHIP:CTL: Shutting down the controller [1655798250.735125][9462:9462] CHIP:IN: Expiring all connections for fabric 2!! [1655798250.735160][9462:9462] CHIP:CTL: Shutting down the commissioner [1655798250.735213][9462:9462] CHIP:CTL: Shutting down the controller [1655798250.735236][9462:9462] CHIP:IN: Expiring all connections for fabric 3!! [1655798250.735267][9462:9462] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655798250.736164][9462:9462] CHIP:DMG: IM WH moving to [Uninitialized] [1655798250.736206][9462:9462] CHIP:DMG: IM WH moving to [Uninitialized] [1655798250.736230][9462:9462] CHIP:DMG: IM WH moving to [Uninitialized] [1655798250.736251][9462:9462] CHIP:DMG: IM WH moving to [Uninitialized] [1655798250.736273][9462:9462] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655798250.736339][9462:9462] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655798250.736639][9462:9462] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ok26Yu) [1655798250.737356][9462:9462] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798250.737425][9462:9462] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655798250.737451][9462:9462] CHIP:DL: Inet Layer shutdown [1655798250.737472][9462:9462] CHIP:DL: BLE shutdown [1655798250.737495][9462:9462] CHIP:DL: System Layer shutdown ./chip-tool accesscontrol write acl '[{"fabricIndex": 1, "privilege": 5, "authMode": 2, "subjects": [112233], "targets": [{"cluster": null, "endpoint": 0, "deviceType": null}]}, {"fabricIndex": 1, "privilege": 3, "authMode": 2, "subjects": null, "targets": [{"cluster": null, "endpoint": 0, "deviceType": null}]}]' 1 0 [1655798791.443944][9516:9516] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655798791.444517][9516:9516] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655798791.444686][9516:9516] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655798791.444796][9516:9516] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655798791.445152][9516:9516] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-26Q4Vb) [1655798791.445783][9516:9516] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798791.445837][9516:9516] CHIP:DL: NVS set: chip-counters/reboot-count = 20 (0x14) [1655798791.446699][9516:9516] CHIP:DL: Got Ethernet interface: eth0 [1655798791.447273][9516:9516] CHIP:DL: Found the primary Ethernet interface:eth0 [1655798791.447849][9516:9516] CHIP:DL: Got WiFi interface: wlan0 [1655798791.447925][9516:9516] CHIP:DL: Failed to reset WiFi statistic counts [1655798791.448011][9516:9516] CHIP:IN: UDP::Init bind&listen port=0 [1655798791.448138][9516:9516] CHIP:IN: UDP::Init bound to port=35805 [1655798791.448164][9516:9516] CHIP:IN: BLEBase::Init - setting/overriding transport [1655798791.448187][9516:9516] CHIP:IN: TransportMgr initialized [1655798791.448221][9516:9516] CHIP:FP: Initializing FabricTable from persistent storage [1655798791.448424][9516:9516] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798791.448519][9516:9516] CHIP:FP: Loading from storage for fabric index 0x1 [1655798791.449009][9516:9516] CHIP:FP: Loading from storage for fabric index 0x2 [1655798791.449401][9516:9516] CHIP:FP: Loading from storage for fabric index 0x3 [1655798791.453063][9516:9516] CHIP:ZCL: Using ZAP configuration... [1655798791.457356][9516:9516] CHIP:DL: Avahi client registered [1655798791.458640][9516:9516] CHIP:CTL: System State Initialized... [1655798791.458736][9516:9516] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798791.458776][9516:9516] CHIP:CTL: Setting attestation nonce to random value [1655798791.458902][9516:9516] CHIP:CTL: Setting CSR nonce to random value [1655798791.458986][9516:9516] CHIP:IN: UDP::Init bind&listen port=5550 [1655798791.459134][9516:9516] CHIP:IN: UDP::Init bound to port=5550 [1655798791.459161][9516:9516] CHIP:IN: TransportMgr initialized [1655798791.459239][9516:9516] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798791.459272][9516:9516] CHIP:CTL: Setting attestation nonce to random value [1655798791.459323][9516:9516] CHIP:CTL: Setting CSR nonce to random value [1655798791.462272][9516:9516] CHIP:CTL: Generating NOC [1655798791.463115][9516:9516] CHIP:FP: Validating NOC chain [1655798791.465086][9516:9516] CHIP:FP: NOC chain validation successful [1655798791.465259][9516:9516] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655798791.465288][9516:9516] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655798791.472645][9516:9516] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655798791.472704][9516:9516] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798791.472735][9516:9516] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798791.472761][9516:9516] CHIP:TS: Retaining current Last Known Good Time [1655798791.474537][9516:9516] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655798791.474697][9516:9516] CHIP:IN: UDP::Init bind&listen port=5550 [1655798791.474850][9516:9516] CHIP:IN: UDP::Init bound to port=5550 [1655798791.474882][9516:9516] CHIP:IN: TransportMgr initialized [1655798791.474975][9516:9516] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798791.475020][9516:9516] CHIP:CTL: Setting attestation nonce to random value [1655798791.475094][9516:9516] CHIP:CTL: Setting CSR nonce to random value [1655798791.476094][9516:9516] CHIP:CTL: Generating NOC [1655798791.477148][9516:9516] CHIP:FP: Validating NOC chain [1655798791.478887][9516:9516] CHIP:FP: NOC chain validation successful [1655798791.479044][9516:9516] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655798791.479072][9516:9516] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655798791.484948][9516:9516] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655798791.484999][9516:9516] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798791.485023][9516:9516] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798791.485046][9516:9516] CHIP:TS: Retaining current Last Known Good Time [1655798791.486502][9516:9516] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655798791.486571][9516:9516] CHIP:IN: UDP::Init bind&listen port=5550 [1655798791.486695][9516:9516] CHIP:IN: UDP::Init bound to port=5550 [1655798791.486720][9516:9516] CHIP:IN: TransportMgr initialized [1655798791.486822][9516:9516] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798791.486861][9516:9516] CHIP:CTL: Setting attestation nonce to random value [1655798791.486924][9516:9516] CHIP:CTL: Setting CSR nonce to random value [1655798791.487932][9516:9516] CHIP:CTL: Generating NOC [1655798791.488795][9516:9516] CHIP:FP: Validating NOC chain [1655798791.490483][9516:9516] CHIP:FP: NOC chain validation successful [1655798791.490638][9516:9516] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655798791.490664][9516:9516] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655798791.496610][9516:9516] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655798791.496661][9516:9516] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798791.496686][9516:9516] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798791.496707][9516:9516] CHIP:TS: Retaining current Last Known Good Time [1655798791.498159][9516:9516] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655798791.498228][9516:9516] CHIP:IN: UDP::Init bind&listen port=5550 [1655798791.498357][9516:9516] CHIP:IN: UDP::Init bound to port=5550 [1655798791.498383][9516:9516] CHIP:IN: TransportMgr initialized [1655798791.534141][9516:9521] CHIP:DL: CHIP task running [1655798791.534380][9516:9521] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655798791.534418][9516:9521] CHIP:TOO: Sending command to node 0x1 [1655798791.534451][9516:9521] CHIP:CSM: FindOrEstablishSession: PeerId = 4783EB7116FFC3BC:0000000000000001 [1655798791.534477][9516:9521] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655798791.534518][9516:9521] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 1 --> 2 [1655798791.534644][9516:9521] CHIP:DIS: Resolving 4783EB7116FFC3BC:0000000000000001 ... [1655798791.645765][9516:9521] CHIP:DL: Avahi resolve found [1655798791.645879][9516:9521] CHIP:DIS: Node ID resolved for 4783EB7116FFC3BC:0000000000000001 [1655798791.645923][9516:9521] CHIP:DIS: Hostname: E45F010EBEFC0000 [1655798791.645970][9516:9521] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0e:befc [1655798791.646009][9516:9521] CHIP:DIS: Port: 5540 [1655798791.646046][9516:9521] CHIP:DIS: Mrp Interval idle: 5000 ms [1655798791.646084][9516:9521] CHIP:DIS: Mrp Interval active: 300 ms [1655798791.646431][9516:9521] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540: new best score: 3 [1655798791.646478][9516:9521] CHIP:DIS: Checking node lookup status after 112 ms [1655798791.646514][9516:9521] CHIP:DIS: Keeping DNSSD lookup active [1655798791.734874][9516:9521] CHIP:DIS: Checking node lookup status after 200 ms [1655798791.735144][9516:9521] CHIP:CTL: Updating device address to UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540 while in state 2 [1655798791.735209][9516:9521] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 2 --> 3 [1655798791.735586][9516:9521] CHIP:IN: SecureSession[0xaaaac68a0f80]: Allocated Type:2 LSID:39047 [1655798791.735672][9516:9521] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655798791.737453][9516:9521] CHIP:SC: Including MRP parameters [1655798791.737935][9516:9521] CHIP:IN: Prepared unauthenticated message 0xaaaac689f2e8 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 53391i with MessageCounter:175996201. [1655798791.738039][9516:9521] CHIP:IN: Sending unauthenticated msg 0xaaaac689f2e8 with MessageCounter:175996201 to 0x0000000000000000 at monotonic time: 0000000000BD15FD msec [1655798791.738383][9516:9521] CHIP:SC: Sent Sigma1 msg [1655798791.738452][9516:9521] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 3 --> 4 [1655798791.738521][9516:9521] CHIP:DIS: Discovery does not require any more timeouts [1655798791.739876][9516:9521] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:8995148 on exchange 53391i [1655798791.739950][9516:9521] CHIP:EM: Found matching exchange: 53391i, Delegate: 0xffffa40011a0 [1655798791.740027][9516:9521] CHIP:EM: Rxd Ack; Removing MessageCounter:175996201 from Retrans Table on exchange 53391i [1655798791.740088][9516:9521] CHIP:EM: Removed CHIP MessageCounter:175996201 from RetransTable on exchange 53391i [1655798791.740160][9516:9521] CHIP:SC: Received Sigma2Resume msg [1655798791.740314][9516:9521] CHIP:SC: Found MRP parameters in the message [1655798791.740424][9516:9521] CHIP:SC: Peer assigned session session ID 1178 [1655798791.749213][9516:9521] CHIP:SC: Sending status report. Protocol code 0, exchange 53391 [1655798791.749290][9516:9521] CHIP:EM: Piggybacking Ack for MessageCounter:8995148 on exchange: 53391i [1655798791.749342][9516:9521] CHIP:IN: Prepared unauthenticated message 0xaaaac689f2e8 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 53391i with MessageCounter:175996202. [1655798791.749392][9516:9521] CHIP:IN: Sending unauthenticated msg 0xaaaac689f2e8 with MessageCounter:175996202 to 0x0000000000000000 at monotonic time: 0000000000BD1609 msec [1655798791.749665][9516:9521] CHIP:IN: SecureSession[0xaaaac68a0f80]: Activated - Type:2 LSID:39047 [1655798791.749700][9516:9521] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:39047 PSID:1178! [1655798791.749731][9516:9521] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 4 --> 5 [1655798791.749805][9516:9521] CHIP:TOO: cluster 0x0000_001F, attribute: 0x0000_0000, endpoint 0 [1655798791.749875][9516:9521] CHIP:DMG: WriteClient moving to [AddAttribu] [1655798791.750045][9516:9521] CHIP:DMG: WriteClient moving to [AddAttribu] [1655798791.750084][9516:9521] CHIP:DMG: WriteClient moving to [AddAttribu] [1655798791.750193][9516:9521] CHIP:IN: Prepared secure message 0xaaaac689f308 to 0x0000000000000001 (1) of type 0x6 and protocolId (0, 1) on exchange 53392i with MessageCounter:168461316. [1655798791.750237][9516:9521] CHIP:IN: Sending encrypted msg 0xaaaac689f308 with MessageCounter:168461316 to 0x0000000000000001 (1) at monotonic time: 0000000000BD1609 msec [1655798791.750384][9516:9521] CHIP:DMG: WriteClient moving to [AwaitingRe] [1655798791.758536][9516:9521] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8995149 on exchange 53391i [1655798791.758586][9516:9521] CHIP:EM: Found matching exchange: 53391i, Delegate: (nil) [1655798791.758639][9516:9521] CHIP:EM: Rxd Ack; Removing MessageCounter:175996202 from Retrans Table on exchange 53391i [1655798791.758677][9516:9521] CHIP:EM: Removed CHIP MessageCounter:175996202 from RetransTable on exchange 53391i [1655798791.772640][9516:9521] CHIP:EM: Received message of type 0x7 with protocolId (0, 1) and MessageCounter:134682042 on exchange 53392i [1655798791.772718][9516:9521] CHIP:EM: Found matching exchange: 53392i, Delegate: 0xffffa4004870 [1655798791.772793][9516:9521] CHIP:EM: Rxd Ack; Removing MessageCounter:168461316 from Retrans Table on exchange 53392i [1655798791.772853][9516:9521] CHIP:EM: Removed CHIP MessageCounter:168461316 from RetransTable on exchange 53392i [1655798791.772923][9516:9521] CHIP:DMG: WriteClient moving to [ResponseRe] [1655798791.773043][9516:9521] CHIP:DMG: WriteResponseMessage = [1655798791.773103][9516:9521] CHIP:DMG: { [1655798791.773157][9516:9521] CHIP:DMG: AttributeStatusIBs = [1655798791.773232][9516:9521] CHIP:DMG: [ [1655798791.773292][9516:9521] CHIP:DMG: AttributeStatusIB = [1655798791.773359][9516:9521] CHIP:DMG: { [1655798791.773423][9516:9521] CHIP:DMG: AttributePathIB = [1655798791.773502][9516:9521] CHIP:DMG: { [1655798791.773580][9516:9521] CHIP:DMG: Endpoint = 0x0, [1655798791.773671][9516:9521] CHIP:DMG: Cluster = 0x1f, [1655798791.773755][9516:9521] CHIP:DMG: Attribute = 0x0000_0000, [1655798791.773832][9516:9521] CHIP:DMG: } [1655798791.773916][9516:9521] CHIP:DMG: [1655798791.773989][9516:9521] CHIP:DMG: StatusIB = [1655798791.774066][9516:9521] CHIP:DMG: { [1655798791.774143][9516:9521] CHIP:DMG: status = 0x00 (SUCCESS), [1655798791.774227][9516:9521] CHIP:DMG: }, [1655798791.774302][9516:9521] CHIP:DMG: [1655798791.774365][9516:9521] CHIP:DMG: }, [1655798791.774450][9516:9521] CHIP:DMG: [1655798791.774511][9516:9521] CHIP:DMG: AttributeStatusIB = [1655798791.774580][9516:9521] CHIP:DMG: { [1655798791.774643][9516:9521] CHIP:DMG: AttributePathIB = [1655798791.774717][9516:9521] CHIP:DMG: { [1655798791.774793][9516:9521] CHIP:DMG: Endpoint = 0x0, [1655798791.774881][9516:9521] CHIP:DMG: Cluster = 0x1f, [1655798791.774956][9516:9521] CHIP:DMG: Attribute = 0x0000_0000, [1655798791.775042][9516:9521] CHIP:DMG: ListIndex = Null, [1655798791.775116][9516:9521] CHIP:DMG: } [1655798791.775198][9516:9521] CHIP:DMG: [1655798791.775271][9516:9521] CHIP:DMG: StatusIB = [1655798791.775347][9516:9521] CHIP:DMG: { [1655798791.775421][9516:9521] CHIP:DMG: status = 0x00 (SUCCESS), [1655798791.775498][9516:9521] CHIP:DMG: }, [1655798791.775573][9516:9521] CHIP:DMG: [1655798791.775640][9516:9521] CHIP:DMG: }, [1655798791.775727][9516:9521] CHIP:DMG: [1655798791.775787][9516:9521] CHIP:DMG: AttributeStatusIB = [1655798791.775851][9516:9521] CHIP:DMG: { [1655798791.775914][9516:9521] CHIP:DMG: AttributePathIB = [1655798791.775988][9516:9521] CHIP:DMG: { [1655798791.776064][9516:9521] CHIP:DMG: Endpoint = 0x0, [1655798791.776145][9516:9521] CHIP:DMG: Cluster = 0x1f, [1655798791.776227][9516:9521] CHIP:DMG: Attribute = 0x0000_0000, [1655798791.776314][9516:9521] CHIP:DMG: ListIndex = Null, [1655798791.776428][9516:9521] CHIP:DMG: } [1655798791.776517][9516:9521] CHIP:DMG: [1655798791.776588][9516:9521] CHIP:DMG: StatusIB = [1655798791.776665][9516:9521] CHIP:DMG: { [1655798791.776740][9516:9521] CHIP:DMG: status = 0x00 (SUCCESS), [1655798791.776818][9516:9521] CHIP:DMG: }, [1655798791.776892][9516:9521] CHIP:DMG: [1655798791.776960][9516:9521] CHIP:DMG: }, [1655798791.777057][9516:9521] CHIP:DMG: [1655798791.777120][9516:9521] CHIP:DMG: ], [1655798791.777212][9516:9521] CHIP:DMG: [1655798791.777273][9516:9521] CHIP:DMG: InteractionModelRevision = 1 [1655798791.777331][9516:9521] CHIP:DMG: } [1655798791.777632][9516:9521] CHIP:DMG: WriteClient moving to [AwaitingDe] [1655798791.777758][9516:9521] CHIP:EM: Sending Standalone Ack for MessageCounter:134682042 on exchange 53392i [1655798791.777899][9516:9521] CHIP:IN: Prepared secure message 0xffffb9b0b958 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 53392i with MessageCounter:168461317. [1655798791.777990][9516:9521] CHIP:IN: Sending encrypted msg 0xffffb9b0b958 with MessageCounter:168461317 to 0x0000000000000001 (1) at monotonic time: 0000000000BD1625 msec [1655798791.778205][9516:9521] CHIP:EM: Flushed pending ack for MessageCounter:134682042 on exchange 53392i [1655798791.778535][9516:9516] CHIP:CTL: Shutting down the commissioner [1655798791.778716][9516:9516] CHIP:CTL: Shutting down the controller [1655798791.778789][9516:9516] CHIP:CTL: Shutting down the commissioner [1655798791.778912][9516:9516] CHIP:CTL: Shutting down the controller [1655798791.778983][9516:9516] CHIP:IN: Expiring all connections for fabric 1!! [1655798791.779039][9516:9516] CHIP:IN: SecureSession[0xaaaac68a0f80]: MarkForRemoval Type:2 LSID:39047 [1655798791.779095][9516:9516] CHIP:IN: SecureSession[0xaaaac68a0f80]: Released - Type:2 LSID:39047 [1655798791.779190][9516:9516] CHIP:CTL: Shutting down the commissioner [1655798791.779316][9516:9516] CHIP:CTL: Shutting down the controller [1655798791.779372][9516:9516] CHIP:IN: Expiring all connections for fabric 2!! [1655798791.779452][9516:9516] CHIP:CTL: Shutting down the commissioner [1655798791.779574][9516:9516] CHIP:CTL: Shutting down the controller [1655798791.779630][9516:9516] CHIP:IN: Expiring all connections for fabric 3!! [1655798791.779700][9516:9516] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655798791.781084][9516:9516] CHIP:DMG: IM WH moving to [Uninitialized] [1655798791.781134][9516:9516] CHIP:DMG: IM WH moving to [Uninitialized] [1655798791.781163][9516:9516] CHIP:DMG: IM WH moving to [Uninitialized] [1655798791.781190][9516:9516] CHIP:DMG: IM WH moving to [Uninitialized] [1655798791.781220][9516:9516] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655798791.781304][9516:9516] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655798791.781637][9516:9516] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Z5YCoe) [1655798791.782475][9516:9516] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798791.782553][9516:9516] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655798791.782591][9516:9516] CHIP:DL: Inet Layer shutdown [1655798791.782621][9516:9516] CHIP:DL: BLE shutdown [1655798791.782651][9516:9516] CHIP:DL: System Layer shutdown ./chip-tool basic read node-label 1 0 [1655798455.534287][9485:9485] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1655798455.534840][9485:9485] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1655798455.535004][9485:9485] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1655798455.535114][9485:9485] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1655798455.535468][9485:9485] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-cXUN4L) [1655798455.536107][9485:9485] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798455.536165][9485:9485] CHIP:DL: NVS set: chip-counters/reboot-count = 17 (0x11) [1655798455.537120][9485:9485] CHIP:DL: Got Ethernet interface: eth0 [1655798455.537736][9485:9485] CHIP:DL: Found the primary Ethernet interface:eth0 [1655798455.538356][9485:9485] CHIP:DL: Got WiFi interface: wlan0 [1655798455.538433][9485:9485] CHIP:DL: Failed to reset WiFi statistic counts [1655798455.538526][9485:9485] CHIP:IN: UDP::Init bind&listen port=0 [1655798455.538660][9485:9485] CHIP:IN: UDP::Init bound to port=46449 [1655798455.538688][9485:9485] CHIP:IN: BLEBase::Init - setting/overriding transport [1655798455.538711][9485:9485] CHIP:IN: TransportMgr initialized [1655798455.538747][9485:9485] CHIP:FP: Initializing FabricTable from persistent storage [1655798455.538921][9485:9485] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798455.539019][9485:9485] CHIP:FP: Loading from storage for fabric index 0x1 [1655798455.539544][9485:9485] CHIP:FP: Loading from storage for fabric index 0x2 [1655798455.539943][9485:9485] CHIP:FP: Loading from storage for fabric index 0x3 [1655798455.543632][9485:9485] CHIP:ZCL: Using ZAP configuration... [1655798455.548082][9485:9485] CHIP:DL: Avahi client registered [1655798455.549433][9485:9485] CHIP:CTL: System State Initialized... [1655798455.549522][9485:9485] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798455.549562][9485:9485] CHIP:CTL: Setting attestation nonce to random value [1655798455.549613][9485:9485] CHIP:CTL: Setting CSR nonce to random value [1655798455.549720][9485:9485] CHIP:IN: UDP::Init bind&listen port=5550 [1655798455.549886][9485:9485] CHIP:IN: UDP::Init bound to port=5550 [1655798455.549913][9485:9485] CHIP:IN: TransportMgr initialized [1655798455.549999][9485:9485] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798455.550041][9485:9485] CHIP:CTL: Setting attestation nonce to random value [1655798455.550091][9485:9485] CHIP:CTL: Setting CSR nonce to random value [1655798455.553050][9485:9485] CHIP:CTL: Generating NOC [1655798455.553948][9485:9485] CHIP:FP: Validating NOC chain [1655798455.555789][9485:9485] CHIP:FP: NOC chain validation successful [1655798455.556076][9485:9485] CHIP:FP: Added new fabric at index: 0x1, Initialized: 1 [1655798455.556105][9485:9485] CHIP:FP: Assigned compressed fabric ID: 0x4783EB7116FFC3BC, node ID: 0x000000000001B669 [1655798455.562561][9485:9485] CHIP:FP: Fabric (0x1) persisted to storage. Calling OnFabricPersistedToStorage [1655798455.562619][9485:9485] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798455.562648][9485:9485] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798455.562672][9485:9485] CHIP:TS: Retaining current Last Known Good Time [1655798455.564267][9485:9485] CHIP:CTL: Joined the fabric at index 1. Compressed fabric ID is: 0x4783EB7116FFC3BC [1655798455.564344][9485:9485] CHIP:IN: UDP::Init bind&listen port=5550 [1655798455.564519][9485:9485] CHIP:IN: UDP::Init bound to port=5550 [1655798455.564550][9485:9485] CHIP:IN: TransportMgr initialized [1655798455.564680][9485:9485] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798455.564722][9485:9485] CHIP:CTL: Setting attestation nonce to random value [1655798455.564790][9485:9485] CHIP:CTL: Setting CSR nonce to random value [1655798455.565761][9485:9485] CHIP:CTL: Generating NOC [1655798455.566672][9485:9485] CHIP:FP: Validating NOC chain [1655798455.568777][9485:9485] CHIP:FP: NOC chain validation successful [1655798455.568954][9485:9485] CHIP:FP: Added new fabric at index: 0x2, Initialized: 1 [1655798455.568982][9485:9485] CHIP:FP: Assigned compressed fabric ID: 0x3CFA125D622AFC73, node ID: 0x000000000001B669 [1655798455.574614][9485:9485] CHIP:FP: Fabric (0x2) persisted to storage. Calling OnFabricPersistedToStorage [1655798455.574669][9485:9485] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798455.574695][9485:9485] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798455.574716][9485:9485] CHIP:TS: Retaining current Last Known Good Time [1655798455.576139][9485:9485] CHIP:CTL: Joined the fabric at index 2. Compressed fabric ID is: 0x3CFA125D622AFC73 [1655798455.576211][9485:9485] CHIP:IN: UDP::Init bind&listen port=5550 [1655798455.576349][9485:9485] CHIP:IN: UDP::Init bound to port=5550 [1655798455.576473][9485:9485] CHIP:IN: TransportMgr initialized [1655798455.576568][9485:9485] CHIP:CTL: Stopping commissioning discovery over DNS-SD [1655798455.576615][9485:9485] CHIP:CTL: Setting attestation nonce to random value [1655798455.576675][9485:9485] CHIP:CTL: Setting CSR nonce to random value [1655798455.577542][9485:9485] CHIP:CTL: Generating NOC [1655798455.578387][9485:9485] CHIP:FP: Validating NOC chain [1655798455.580093][9485:9485] CHIP:FP: NOC chain validation successful [1655798455.580257][9485:9485] CHIP:FP: Added new fabric at index: 0x3, Initialized: 1 [1655798455.580284][9485:9485] CHIP:FP: Assigned compressed fabric ID: 0x486C967E8B3953BE, node ID: 0x000000000001B669 [1655798455.585855][9485:9485] CHIP:FP: Fabric (0x3) persisted to storage. Calling OnFabricPersistedToStorage [1655798455.585904][9485:9485] CHIP:TS: Last Known Good Time: 2022-06-21T06:53:10 [1655798455.585929][9485:9485] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1655798455.585952][9485:9485] CHIP:TS: Retaining current Last Known Good Time [1655798455.587362][9485:9485] CHIP:CTL: Joined the fabric at index 3. Compressed fabric ID is: 0x486C967E8B3953BE [1655798455.587431][9485:9485] CHIP:IN: UDP::Init bind&listen port=5550 [1655798455.587566][9485:9485] CHIP:IN: UDP::Init bound to port=5550 [1655798455.587602][9485:9485] CHIP:IN: TransportMgr initialized [1655798455.621872][9485:9490] CHIP:DL: CHIP task running [1655798455.622120][9485:9490] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1655798455.622156][9485:9490] CHIP:TOO: Sending command to node 0x1 [1655798455.622191][9485:9490] CHIP:CSM: FindOrEstablishSession: PeerId = 4783EB7116FFC3BC:0000000000000001 [1655798455.622218][9485:9490] CHIP:CSM: FindOrEstablishSession: No existing OperationalDeviceProxy instance found [1655798455.622258][9485:9490] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 1 --> 2 [1655798455.622288][9485:9490] CHIP:DIS: Resolving 4783EB7116FFC3BC:0000000000000001 ... [1655798455.623989][9485:9490] CHIP:DL: Avahi resolve found [1655798455.624069][9485:9490] CHIP:DIS: Node ID resolved for 4783EB7116FFC3BC:0000000000000001 [1655798455.624095][9485:9490] CHIP:DIS: Hostname: E45F010EBEFC0000 [1655798455.624126][9485:9490] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0e:befc [1655798455.624150][9485:9490] CHIP:DIS: Port: 5540 [1655798455.624172][9485:9490] CHIP:DIS: Mrp Interval idle: 5000 ms [1655798455.624195][9485:9490] CHIP:DIS: Mrp Interval active: 300 ms [1655798455.624486][9485:9490] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540: new best score: 3 [1655798455.624517][9485:9490] CHIP:DIS: Checking node lookup status after 3 ms [1655798455.624539][9485:9490] CHIP:DIS: Keeping DNSSD lookup active [1655798455.821870][9485:9490] CHIP:DIS: Checking node lookup status after 200 ms [1655798455.822179][9485:9490] CHIP:CTL: Updating device address to UDP:[fe80::e65f:1ff:fe0e:befc%eth0]:5540 while in state 2 [1655798455.822243][9485:9490] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 2 --> 3 [1655798455.822632][9485:9490] CHIP:IN: SecureSession[0xaaaada2a8730]: Allocated Type:2 LSID:7044 [1655798455.822714][9485:9490] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1655798455.824508][9485:9490] CHIP:SC: Including MRP parameters [1655798455.824980][9485:9490] CHIP:IN: Prepared unauthenticated message 0xaaaada2a6a18 to 0x0000000000000000 (0) of type 0x30 and protocolId (0, 0) on exchange 14597i with MessageCounter:129290448. [1655798455.825085][9485:9490] CHIP:IN: Sending unauthenticated msg 0xaaaada2a6a18 with MessageCounter:129290448 to 0x0000000000000000 at monotonic time: 0000000000B7F5D4 msec [1655798455.825418][9485:9490] CHIP:SC: Sent Sigma1 msg [1655798455.825485][9485:9490] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 3 --> 4 [1655798455.825550][9485:9490] CHIP:DIS: Discovery does not require any more timeouts [1655798455.827414][9485:9490] CHIP:EM: Received message of type 0x33 with protocolId (0, 0) and MessageCounter:8995142 on exchange 14597i [1655798455.827488][9485:9490] CHIP:EM: Found matching exchange: 14597i, Delegate: 0xffff700011a0 [1655798455.827565][9485:9490] CHIP:EM: Rxd Ack; Removing MessageCounter:129290448 from Retrans Table on exchange 14597i [1655798455.827622][9485:9490] CHIP:EM: Removed CHIP MessageCounter:129290448 from RetransTable on exchange 14597i [1655798455.827694][9485:9490] CHIP:SC: Received Sigma2Resume msg [1655798455.827845][9485:9490] CHIP:SC: Found MRP parameters in the message [1655798455.827912][9485:9490] CHIP:SC: Peer assigned session session ID 1175 [1655798455.836115][9485:9490] CHIP:SC: Sending status report. Protocol code 0, exchange 14597 [1655798455.836188][9485:9490] CHIP:EM: Piggybacking Ack for MessageCounter:8995142 on exchange: 14597i [1655798455.836238][9485:9490] CHIP:IN: Prepared unauthenticated message 0xaaaada2a6a18 to 0x0000000000000000 (0) of type 0x40 and protocolId (0, 0) on exchange 14597i with MessageCounter:129290449. [1655798455.836287][9485:9490] CHIP:IN: Sending unauthenticated msg 0xaaaada2a6a18 with MessageCounter:129290449 to 0x0000000000000000 at monotonic time: 0000000000B7F5DF msec [1655798455.836581][9485:9490] CHIP:IN: SecureSession[0xaaaada2a8730]: Activated - Type:2 LSID:7044 [1655798455.836615][9485:9490] CHIP:IN: New secure session created for device <0000000000000001, 1>, LSID:7044 PSID:1175! [1655798455.836645][9485:9490] CHIP:CTL: OperationalDeviceProxy[4783EB7116FFC3BC:0000000000000001]: State change 4 --> 5 [1655798455.836737][9485:9490] CHIP:TOO: cluster 0x0000_0028, attribute: 0x0000_0005, endpoint 0 [1655798455.836774][9485:9490] CHIP:TOO: Sending ReadAttribute to: [1655798455.836808][9485:9490] CHIP:DMG: SendReadRequest ReadClient[0xffff70002df0]: Sending Read Request [1655798455.836929][9485:9490] CHIP:IN: Prepared secure message 0xaaaada2a6a38 to 0x0000000000000001 (1) of type 0x2 and protocolId (0, 1) on exchange 14598i with MessageCounter:205435501. [1655798455.836973][9485:9490] CHIP:IN: Sending encrypted msg 0xaaaada2a6a38 with MessageCounter:205435501 to 0x0000000000000001 (1) at monotonic time: 0000000000B7F5E0 msec [1655798455.837113][9485:9490] CHIP:DMG: MoveToState ReadClient[0xffff70002df0]: Moving to [AwaitingIn] [1655798455.844760][9485:9490] CHIP:EM: Received message of type 0x10 with protocolId (0, 0) and MessageCounter:8995143 on exchange 14597i [1655798455.844797][9485:9490] CHIP:EM: Found matching exchange: 14597i, Delegate: (nil) [1655798455.844838][9485:9490] CHIP:EM: Rxd Ack; Removing MessageCounter:129290449 from Retrans Table on exchange 14597i [1655798455.844865][9485:9490] CHIP:EM: Removed CHIP MessageCounter:129290449 from RetransTable on exchange 14597i [1655798455.847134][9485:9490] CHIP:EM: Received message of type 0x5 with protocolId (0, 1) and MessageCounter:147442002 on exchange 14598i [1655798455.847184][9485:9490] CHIP:EM: Found matching exchange: 14598i, Delegate: 0xffff70002df0 [1655798455.847232][9485:9490] CHIP:EM: Rxd Ack; Removing MessageCounter:205435501 from Retrans Table on exchange 14598i [1655798455.847270][9485:9490] CHIP:EM: Removed CHIP MessageCounter:205435501 from RetransTable on exchange 14598i [1655798455.847353][9485:9490] CHIP:DMG: ReportDataMessage = [1655798455.847396][9485:9490] CHIP:DMG: { [1655798455.847439][9485:9490] CHIP:DMG: AttributeReportIBs = [1655798455.847490][9485:9490] CHIP:DMG: [ [1655798455.847529][9485:9490] CHIP:DMG: AttributeReportIB = [1655798455.847580][9485:9490] CHIP:DMG: { [1655798455.847622][9485:9490] CHIP:DMG: AttributeDataIB = [1655798455.847672][9485:9490] CHIP:DMG: { [1655798455.847726][9485:9490] CHIP:DMG: DataVersion = 0x236593b9, [1655798455.847778][9485:9490] CHIP:DMG: AttributePathIB = [1655798455.847827][9485:9490] CHIP:DMG: { [1655798455.847880][9485:9490] CHIP:DMG: Endpoint = 0x0, [1655798455.847937][9485:9490] CHIP:DMG: Cluster = 0x28, [1655798455.847996][9485:9490] CHIP:DMG: Attribute = 0x0000_0005, [1655798455.848050][9485:9490] CHIP:DMG: } [1655798455.848106][9485:9490] CHIP:DMG: [1655798455.848164][9485:9490] CHIP:DMG: Data = "", [1655798455.848215][9485:9490] CHIP:DMG: }, [1655798455.848268][9485:9490] CHIP:DMG: [1655798455.848314][9485:9490] CHIP:DMG: }, [1655798455.848361][9485:9490] CHIP:DMG: [1655798455.848431][9485:9490] CHIP:DMG: ], [1655798455.848483][9485:9490] CHIP:DMG: [1655798455.848523][9485:9490] CHIP:DMG: SuppressResponse = true, [1655798455.848565][9485:9490] CHIP:DMG: InteractionModelRevision = 1 [1655798455.848603][9485:9490] CHIP:DMG: } [1655798455.848801][9485:9490] CHIP:TOO: Endpoint: 0 Cluster: 0x0000_0028 Attribute 0x0000_0005 DataVersion: 593859513 [1655798455.848855][9485:9490] CHIP:TOO: NodeLabel: [1655798455.848982][9485:9490] CHIP:EM: Sending Standalone Ack for MessageCounter:147442002 on exchange 14598i [1655798455.849083][9485:9490] CHIP:IN: Prepared secure message 0xffff82fdd958 to 0x0000000000000001 (1) of type 0x10 and protocolId (0, 0) on exchange 14598i with MessageCounter:205435502. [1655798455.849143][9485:9490] CHIP:IN: Sending encrypted msg 0xffff82fdd958 with MessageCounter:205435502 to 0x0000000000000001 (1) at monotonic time: 0000000000B7F5EC msec [1655798455.849295][9485:9490] CHIP:EM: Flushed pending ack for MessageCounter:147442002 on exchange 14598i [1655798455.849557][9485:9485] CHIP:CTL: Shutting down the commissioner [1655798455.849690][9485:9485] CHIP:CTL: Shutting down the controller [1655798455.849739][9485:9485] CHIP:CTL: Shutting down the commissioner [1655798455.849821][9485:9485] CHIP:CTL: Shutting down the controller [1655798455.849870][9485:9485] CHIP:IN: Expiring all connections for fabric 1!! [1655798455.849908][9485:9485] CHIP:IN: SecureSession[0xaaaada2a8730]: MarkForRemoval Type:2 LSID:7044 [1655798455.849944][9485:9485] CHIP:IN: SecureSession[0xaaaada2a8730]: Released - Type:2 LSID:7044 [1655798455.850011][9485:9485] CHIP:CTL: Shutting down the commissioner [1655798455.850097][9485:9485] CHIP:CTL: Shutting down the controller [1655798455.850135][9485:9485] CHIP:IN: Expiring all connections for fabric 2!! [1655798455.850189][9485:9485] CHIP:CTL: Shutting down the commissioner [1655798455.850270][9485:9485] CHIP:CTL: Shutting down the controller [1655798455.850307][9485:9485] CHIP:IN: Expiring all connections for fabric 3!! [1655798455.850356][9485:9485] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1655798455.851668][9485:9485] CHIP:DMG: IM WH moving to [Uninitialized] [1655798455.851726][9485:9485] CHIP:DMG: IM WH moving to [Uninitialized] [1655798455.851758][9485:9485] CHIP:DMG: IM WH moving to [Uninitialized] [1655798455.851792][9485:9485] CHIP:DMG: IM WH moving to [Uninitialized] [1655798455.851827][9485:9485] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1655798455.851927][9485:9485] CHIP:BLE: BleConnectionDelegate::CancelConnection is not implemented. [1655798455.852295][9485:9485] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-u0FjNo) [1655798455.853299][9485:9485] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1655798455.853399][9485:9485] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1655798455.853442][9485:9485] CHIP:DL: Inet Layer shutdown [1655798455.853478][9485:9485] CHIP:DL: BLE shutdown [1655798455.853513][9485:9485] CHIP:DL: System Layer shutdown