Barton on RDK-B

Scope

Ultimate goal is to bringup barton in RDK-B and make it available for community as IoT reference

Key insights

Platform selection
Vendor integration
OSS component support
BartonCore integration
Reference Application
Validation with Matter device

Block diagram

bartcorear

RDK-B IoT Build

Prelimanary
- RDK-B Banana Pi R4 - Beta Engineering Release(05 Feb 2025)
Vendor integration
Comcast recipe changes
- For testing alone.we manually added changes & customized
- Add missing changes like gn
linenoise upstep
update ssid and password in reference/src/reference-network-credentials-provider.c & recompile
My yocto
- barton-exp-recipes.docx
Update image install
- +IMAGE_INSTALL_append = " parodus parodus2ccsp cpcd otbr-agent bluez5-bluetoothd bt-host-cpc-hci-bridge opkg opkg-utils xz barton"

Barton core

c-GW:~# ls /usr/lib/libbrtnDeviceServiceShared.so
/usr/lib/libbrtnDeviceServiceShared.so
root@Filogic-GW:~#
-GW:~# ls /usr/bin/brtn-ds-reference
/usr/bin/brtn-ds-reference
root@Filogic-GW:~#

Verification of barton in RDK-B

mkdir /nvram/icontrol
Make sure we have below services up and running
- cpcd
- otbr-agent
- bt-host-cpc-hci-bridge-attach.service
- bt-host-cpc-hci-bridge.service
mkdir -p /home/root/.brtn-ds
start this application brtn-ds-reference

root@Filogic-GW:~# brtn-ds-reference 
2025-04-10 22:52:47.089 : [zigbeeDriverCommon 112400] - DEBUG: zigbeeDriverCommonCreateDeviceDriver
2025-04-10 22:52:47.110 : [deviceDriverManager 112400] - DEBUG: Loading device driver zigbeeLight
2025-04-10 22:52:47.111 : [zigbeeDriverCommon 112400] - DEBUG: zigbeeDriverCommonCreateDeviceDriver
2025-04-10 22:52:47.111 : [deviceDriverManager 112400] - DEBUG: Loading device driver ZigBeeSensorDD
2025-04-10 22:52:47.111 : [zigbeeDriverCommon 112400] - DEBUG: zigbeeDriverCommonCreateDeviceDriver
2025-04-10 22:52:47.111 : [deviceDriverManager 112400] - DEBUG: Loading device driver zigbeeThermostat
2025-04-10 22:52:47.111 : [zigbeeDriverCommon 112400] - DEBUG: zigbeeDriverCommonCreateDeviceDriver
2025-04-10 22:52:47.111 : [deviceDriverManager 112400] - DEBUG: Loading device driver zigbeeDoorLock
2025-04-10 22:52:47.111 : [zigbeeDriverCommon 112400] - DEBUG: zigbeeDriverCommonCreateDeviceDriver
2025-04-10 22:52:47.111 : [deviceDriverManager 112400] - DEBUG: Loading device driver ZigBeePresenceDD
2025-04-10 22:52:47.111 : [zigbeeDriverCommon 112400] - DEBUG: zigbeeDriverCommonCreateDeviceDriver
2025-04-10 22:52:47.111 : [deviceDriverManager 112400] - DEBUG: Loading device driver zigbeeLightController
2025-04-10 22:52:47.111 : [zigbeeDriverCommon 112400] - DEBUG: zigbeeDriverCommonCreateDeviceDriver
2025-04-10 22:52:47.111 : [deviceDriverManager 112400] - DEBUG: Loading device driver ZigBeeWindowCDD
2025-04-10 22:52:47.111 : [deviceService 112400] - INFO: subsystem 'matter' registered
2025-04-10 22:52:47.114 : [Matter 112400] - DEBUG: MatterDriverFactory (RegisterDriver): matterDoorLock
2025-04-10 22:52:47.114 : [deviceDriverManager 112400] - DEBUG: Loading device driver matterDoorLock
2025-04-10 22:52:47.114 : [Matter 112400] - DEBUG: MatterDriverFactory (RegisterDriver): matterLight
2025-04-10 22:52:47.114 : [deviceDriverManager 112400] - DEBUG: Loading device driver matterLight
2025-04-10 22:52:47.114 : [Matter 112400] - DEBUG: MatterDriverFactory (RegisterDriver): matterWindowCovering
2025-04-10 22:52:47.114 : [deviceDriverManager 112400] - DEBUG: Loading device driver matterWindowCovering
2025-04-10 22:52:47.114 : [deviceService 112400] - INFO: subsystem 'thread' registered
2025-04-10 22:52:47.114 : [deviceService 112400] - INFO: subsystem 'zigbee' registered
2025-04-10 22:52:47.174 : [backupUtil 112400] - DEBUG: File is safe to read, /home/root/.brtn-ds/storage/devicedb/systemProperties
2025-04-10 22:52:47.175 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_bool: Error getting property 'zigbee.testing.fy
2025-04-10 22:52:47.175 : [deviceCommunicationWatchdog 112400] - DEBUG: commFailWatchdogThreadProc: starting up
2025-04-10 22:52:47.177 : [libdeviceDescriptors 112400] - DEBUG: deviceDescriptorsInit:  using AllowList /home/root/.brtn-ds/AllowList.xml, and DenyList /home/root/.brtn-ds/l
2025-04-10 22:52:47.177 : [deviceDriverManager 112400] - DEBUG: deviceDriverManagerInitialize
2025-04-10 22:52:47.177 : [DevInit 112400] - DEBUG: creating threadpool; workers=0
2025-04-10 22:52:47.177 : [deviceService 112400] - DEBUG: subsystemManagerInitialize
2025-04-10 22:52:47.177 : [deviceService 112400] - DEBUG: subsystemManager: checkSubsystemForMigration - Saving new matterSubsystemVersion (1)
2025-04-10 22:52:47.184 : [storage 112400] - DEBUG: storageSave: saved file /home/root/.brtn-ds/storage/devicedb/systemProperties in 7ms
2025-04-10 22:52:47.184 : [deviceService 112400] - DEBUG: subsystemManager: checkSubsystemForMigration - Saving new threadSubsystemVersion (1)
2025-04-10 22:52:47.196 : [storage 112400] - DEBUG: storageSave: saved file /home/root/.brtn-ds/storage/devicedb/systemProperties in 11ms
2025-04-10 22:52:47.196 : [Matter 112400] - DEBUG: MatterSubsystem (matterSubsystemInitialize): 
2025-04-10 22:52:47.196 : [threadSubsystem 112400] - DEBUG: initialize: 
2025-04-10 22:52:47.196 : [repeatTask 112400] - DEBUG: registering shutdown hook
2025-04-10 22:52:47.196 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_string: Error getting property 'barton.thread.y
2025-04-10 22:52:47.196 : [threadSubsystem 112400] - DEBUG: initialize: Using Thread network name: TestNetwork
2025-04-10 22:52:47.196 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_bool: Error getting property 'cpe.zigbee.repory
2025-04-10 22:52:47.196 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_bool: Error getting property 'cpe.diagnostics.y
2025-04-10 22:52:47.196 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_uint64: Error getting property 'cpe.diagnosticy
2025-04-10 22:52:47.196 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_uint64: Error getting property 'cpe.diagnosticy
2025-04-10 22:52:47.196 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_uint64: Error getting property 'cpe.diagnosticy
2025-04-10 22:52:47.196 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_uint64: Error getting property 'cpe.diagnosticy
2025-04-10 22:52:47.196 : [deviceDriverManager 112400] - DEBUG: deviceDriverManagerStartDeviceDrivers
2025-04-10 22:52:47.196 : [zigbeeDriverCommon 112400] - DEBUG: startup zigbeeLight
2025-04-10 22:52:47.196 : [zigbeeSubsystem 112400] - DEBUG: zigbeeSubsystemRegisterDiscoveryHandler: zigbeeLight
2025-04-10 22:52:47.196 : [zigbeeDriverCommon 112400] - DEBUG: startup ZigBeeSensorDD
2025-04-10 22:52:47.196 : [zigbeeSubsystem 112400] - DEBUG: zigbeeSubsystemRegisterDiscoveryHandler: ZigBeeSensorDD
2025-04-10 22:52:47.196 : [zigbeeDriverCommon 112400] - DEBUG: startup zigbeeThermostat
2025-04-10 22:52:47.196 : [zigbeeSubsystem 112400] - DEBUG: zigbeeSubsystemRegisterDiscoveryHandler: zigbeeThermostat
2025-04-10 22:52:47.196 : [zigbeeDriverCommon 112400] - DEBUG: startup zigbeeDoorLock
2025-04-10 22:52:47.196 : [zigbeeSubsystem 112400] - DEBUG: zigbeeSubsystemRegisterDiscoveryHandler: zigbeeDoorLock
2025-04-10 22:52:47.196 : [zigbeeDriverCommon 112400] - DEBUG: startup ZigBeePresenceDD
2025-04-10 22:52:47.196 : [zigbeeSubsystem 112400] - DEBUG: zigbeeSubsystemRegisterDiscoveryHandler: ZigBeePresenceDD
2025-04-10 22:52:47.196 : [zigbeeDriverCommon 112400] - DEBUG: startup zigbeeLightController
2025-04-10 22:52:47.196 : [zigbeeSubsystem 112400] - DEBUG: zigbeeSubsystemRegisterDiscoveryHandler: zigbeeLightController
2025-04-10 22:52:47.196 : [zigbeeDriverCommon 112400] - DEBUG: startup ZigBeeWindowCDD
2025-04-10 22:52:47.196 : [zigbeeSubsystem 112400] - DEBUG: zigbeeSubsystemRegisterDiscoveryHandler: ZigBeeWindowCDD
2025-04-10 22:52:47.196 : [MatterBaseDD 112400] - DEBUG: (Startup): 
2025-04-10 22:52:47.196 : [MatterBaseDD 112400] - DEBUG: (Startup): 
2025-04-10 22:52:47.196 : [MatterBaseDD 112400] - DEBUG: (Startup): 
2025-04-10 22:52:47.196 : [deviceService 112400] - DEBUG: subsystemManagerAllDriversStarted
2025-04-10 22:52:47.196 : [deviceService 112400] - INFO: subsystemManager: subsystemManagerIsReadyForDevices - Subsystem matter is not yet ready
2025-04-10 22:52:47.196 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_uint64: Error getting property 'touchscreen.sey
2025-04-10 22:52:47.197 : [threadSubsystem 112400] - DEBUG: initTaskFunc: 
2025-04-10 22:52:47.198 : [threadSubsystem 112400] - DEBUG: initializeThreadStack: 
2025-04-10 22:52:47.198 : [openThreadClient 112400] - DEBUG: Connect: 
2025-04-10 22:52:47.206 : [MatterSDK 112400] - DEBUG: [CTL] Setting attestation nonce to random value
2025-04-10 22:52:47.209 : [MatterSDK 112400] - DEBUG: [CTL] Setting CSR nonce to random value
2025-04-10 22:52:47.210 : [Matter 112400] - DEBUG: (Init): 
2025-04-10 22:52:47.211 : [storage 112400] - DEBUG: storageSave: saved file /home/root/.brtn-ds/storage/devicedb/systemProperties in 15ms
2025-04-10 22:52:47.211 : [threadSubsystem 112400] - WARN: initializeThreadStack: No network configuration loaded; a new network will be created
2025-04-10 22:52:47.211 : [Matter 112400] - DEBUG: (Init): Local node ID: 0xd8730fd2953874
2025-04-10 22:52:47.211 : [openThreadClient 112400] - DEBUG: CreateNetwork: 
2025-04-10 22:52:47.212 : [openThreadClient 112400] - DEBUG: operator(): Successfully created network TestNetwork
2025-04-10 22:52:47.212 : [device-service-property-provider 112400] - WARN: b_device_service_property_provider_get_property_as_uint64: Error getting property 'barton.matter.y
2025-04-10 22:52:47.212 : [Matter 112400] - DEBUG: (Init): Using vendor ID: 0xfff1
2025-04-10 22:52:47.213 : [threadSubsystem 112400] - ERROR: initializeThreadStack: Failed to create network, trying again in 60 seconds...
2025-04-10 22:52:47.232 : [MatterSDK 112400] - DEBUG: [DL] NVS set: chip-counters/reboot-count = 11 (0xB)
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL] Got Ethernet interface: eth1
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL] Found the primary Ethernet interface:eth1
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL] Device Configuration:
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL]   Serial Number: TEST_SN
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL]   Vendor Id: 65521 (0xFFF1)
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL]   Product Id: 32769 (0x8001)
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL]   Product Name: TEST_PRODUCT
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL]   Hardware Version: 0
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL]   Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL]   Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL]   Manufacturing Date: (not set)
2025-04-10 22:52:47.233 : [MatterSDK 112400] - DEBUG: [DL]   Device Type: 65535 (0xFFFF)
2025-04-10 22:52:47.244 : [Matter 112400] - DEBUG: (Start): 
2025-04-10 22:52:47.244 : [MatterSDK 112400] - DEBUG: [SVR] Initializing subscription resumption storage...
2025-04-10 22:52:47.256 : [MatterSDK 112400] - DEBUG: [SVR] Server initializing...
2025-04-10 22:52:47.256 : [MatterSDK 112400] - DEBUG: [TS] Last Known Good Time: 2025-04-09T22:50:10
2025-04-10 22:52:47.262 : [MatterSDK 112400] - DEBUG: [FP] Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xA7B405C82BDF3872, FabricId 0x0000000000000001, 1
2025-04-10 22:52:47.263 : [MatterSDK 112400] - DEBUG: [DMG] AccessControl: initializing
2025-04-10 22:52:47.263 : [MatterSDK 112400] - DEBUG: [DMG] barton::AccessControlDelegate::Init
2025-04-10 22:52:47.263 : [MatterSDK 112400] - DEBUG: [DMG] AccessControl: setting
2025-04-10 22:52:47.263 : [MatterSDK 112400] - DEBUG: [DMG] DefaultAclStorage: initializing
2025-04-10 22:52:47.273 : [MatterSDK 112400] - DEBUG: [DMG] DefaultAclStorage: 1 entries loaded
2025-04-10 22:52:47.273 : [MatterSDK 112400] - DEBUG: [SVR] WARNING: mTestEventTriggerDelegate is null
2025-04-10 22:52:47.314 : [MatterSDK 112400] - DEBUG: [ZCL] Using ZAP configuration...
2025-04-10 22:52:47.314 : [MatterSDK 112400] - DEBUG: [DMG] AccessControlCluster: initializing
2025-04-10 22:52:47.314 : [MatterSDK 112400] - DEBUG: [ZCL] Initiating Admin Commissioning cluster.
2025-04-10 22:52:47.317 : [tbrmd 112400] - DEBUG: Init: 
2025-04-10 22:52:47.317 : [MatterSDK 112400] - DEBUG: [SVR] Fabric already commissioned. Disabling BLE advertisement
2025-04-10 22:52:47.317 : [MatterSDK 112400] - DEBUG: [DIS] Updating services using commissioning mode 0
2025-04-10 22:52:47.327 : [MatterSDK 112400] - DEBUG: [DIS] CHIP minimal mDNS started advertising.
2025-04-10 22:52:47.345 : [MatterSDK 112400] - DEBUG: [DIS] Advertise operational node A7B405C82BDF3872-00D8730FD2953874
2025-04-10 22:52:47.345 : [MatterSDK 112400] - DEBUG: [DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: A7B405C82BDF3872-00D8730FD2953874.
2025-04-10 22:52:47.360 : [MatterSDK 112400] - DEBUG: [DIS] mDNS service published: _matter._tcp
2025-04-10 22:52:47.360 : [MatterSDK 112400] - DEBUG: [DIS] Advertise commission parameter vendorID=65521 productID=32769 discriminator=0000/00 cm=0 cp=0
2025-04-10 22:52:47.360 : [MatterSDK 112400] - DEBUG: [DIS] CHIP minimal mDNS configured as 'Commissioner device'; instance name: EE7F91E4F8DE6D17.
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DIS] mDNS service published: _matterd._udp
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [IN] CASE Server enabling CASE session setups
2025-04-10 22:52:47.377 : [MatterSDK 112400] - ERROR: [IM] WARNING ┌────────────────────────────────────────────────────
2025-04-10 22:52:47.377 : [MatterSDK 112400] - ERROR: [IM] WARNING │ Interaction Model Engine running in 'Checked' mode.
2025-04-10 22:52:47.377 : [MatterSDK 112400] - ERROR: [IM] WARNING │ This executes BOTH ember and data-model code paths.
2025-04-10 22:52:47.377 : [MatterSDK 112400] - ERROR: [IM] WARNING │ which is inefficient and consumes more flash space.
2025-04-10 22:52:47.377 : [MatterSDK 112400] - ERROR: [IM] WARNING │ This should be done for testing only.
2025-04-10 22:52:47.377 : [MatterSDK 112400] - ERROR: [IM] WARNING └────────────────────────────────────────────────────
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [SVR] Joining Multicast groups
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [SVR] Server initialization complete
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [SVR] Server Listening...
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL] Device Configuration:
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL]   Serial Number: TEST_SN
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL]   Vendor Id: 65521 (0xFFF1)
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL]   Product Id: 32769 (0x8001)
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL]   Product Name: TEST_PRODUCT
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL]   Hardware Version: 0
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL]   Setup Pin Code (0 for UNKNOWN/ERROR): 20202021
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL]   Setup Discriminator (0xFFFF for UNKNOWN/ERROR): 3840 (0xF00)
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL]   Manufacturing Date: (not set)
2025-04-10 22:52:47.377 : [MatterSDK 112400] - DEBUG: [DL]   Device Type: 65535 (0xFFFF)
2025-04-10 22:52:47.378 : [MatterStorage 112400] - DEBUG: (SyncGetKeyValue): key = g/gcc
2025-04-10 22:52:47.379 : [MatterStorage 112400] - DEBUG: (SyncGetKeyValue): key = g/gdc
2025-04-10 22:52:47.379 : [MatterStorage 112400] - DEBUG: (SyncSetKeyValue): key = g/gcc
2025-04-10 22:52:47.387 : [MatterStorage 112400] - DEBUG: (SyncSetKeyValue): key = g/gdc
2025-04-10 22:52:47.400 : [MatterSDK 112400] - DEBUG: [ZCL] Using ZAP configuration...
2025-04-10 22:52:47.400 : [MatterSDK 112400] - DEBUG: [DMG] AccessControlCluster: initializing
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - DEBUG: [ZCL] Initiating Admin Commissioning cluster.
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.400 : [MatterSDK 112400] - ERROR: [IM] Duplicate attribute override registration failed
2025-04-10 22:52:47.401 : [MatterSDK 112400] - ERROR: [IM] WARNING ┌────────────────────────────────────────────────────
2025-04-10 22:52:47.401 : [MatterSDK 112400] - ERROR: [IM] WARNING │ Interaction Model Engine running in 'Checked' mode.
2025-04-10 22:52:47.401 : [MatterSDK 112400] - ERROR: [IM] WARNING │ This executes BOTH ember and data-model code paths.
2025-04-10 22:52:47.401 : [MatterSDK 112400] - ERROR: [IM] WARNING │ which is inefficient and consumes more flash space.
2025-04-10 22:52:47.401 : [MatterSDK 112400] - ERROR: [IM] WARNING │ This should be done for testing only.
2025-04-10 22:52:47.401 : [MatterSDK 112400] - ERROR: [IM] WARNING └────────────────────────────────────────────────────
2025-04-10 22:52:47.401 : [MatterSDK 112400] - DEBUG: [CTL] Intermediate CA is not needed
2025-04-10 22:52:47.401 : [MatterSDK 112400] - DEBUG: [FP] Validating NOC chain
2025-04-10 22:52:47.402 : [MatterSDK 112400] - DEBUG: [FP] NOC chain validation successful
2025-04-10 22:52:47.402 : [MatterSDK 112400] - DEBUG: [FP] Updated fabric at index: 0x1, Node ID: 0x00D8730FD2953874
2025-04-10 22:52:47.402 : [MatterSDK 112400] - DEBUG: [TS] Last Known Good Time: 2025-04-09T22:50:10
2025-04-10 22:52:47.403 : [MatterSDK 112400] - DEBUG: [TS] New proposed Last Known Good Time: 2025-04-09T22:50:10
2025-04-10 22:52:47.403 : [MatterSDK 112400] - DEBUG: [TS] Retaining current Last Known Good Time
2025-04-10 22:52:47.403 : [MatterStorage 112400] - DEBUG: (SyncGetKeyValue): key = g/sri
2025-04-10 22:52:47.421 : [MatterSDK 112400] - DEBUG: [FP] Metadata for Fabric 0x1 persisted to storage.
2025-04-10 22:52:47.433 : [MatterSDK 112400] - DEBUG: [TS] Committing Last Known Good Time to storage: 2025-04-09T22:50:10
2025-04-10 22:52:47.442 : [MatterSDK 112400] - DEBUG: [ZCL] OpCreds: Fabric index 0x1 was committed to storage. Compressed Fabric Id 0xA7B405C82BDF3872, FabricId 000000000001
2025-04-10 22:52:47.451 : [MatterSDK 112400] - DEBUG: [CTL] Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: A7B405C82BDF3872)
2025-04-10 22:52:47.451 : [MatterStorage 112400] - DEBUG: (SyncGetKeyValue): key = f/1/g
2025-04-10 22:52:47.451 : [MatterStorage 112400] - DEBUG: (SyncGetKeyValue): key = f/1/k/0
2025-04-10 22:52:47.465 : [MatterSDK 112400] - DEBUG: [FP] Metadata for Fabric 0x1 persisted to storage.
2025-04-10 22:52:47.465 : [Matter 112400] - DEBUG: (ConfigureOTAProviderNode): 
2025-04-10 22:52:47.465 : [Matter 112400] - DEBUG: (IsAccessibleByOTARequestors): 
2025-04-10 22:52:47.465 : [MatterSDK 112400] - DEBUG: [DIS] Advertise operational node A7B405C82BDF3872-00D8730FD2953874
2025-04-10 22:52:47.465 : [MatterSDK 112400] - DEBUG: [DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: A7B405C82BDF3872-00D8730FD2953874.
2025-04-10 22:52:47.481 : [MatterSDK 112400] - DEBUG: [DIS] mDNS service published: _matter._tcp
2025-04-10 22:52:47.481 : [MatterSDK 112400] - DEBUG: [SPT] InitCommissioner nodeId=0x00D8730FD2953874 fabric.fabricId=0x0000000000000001 fabricIndex=0x1
2025-04-10 22:52:47.481 : [Matter 112400] - WARN: (SetAccessRestrictionList): Setting Access Restrictions
2025-04-10 22:52:47.481 : [Matter 112400] - DEBUG: (StackThreadProc): 
2025-04-10 22:52:47.481 : [deviceService 112400] - DEBUG: onSubsystemInitialized: 'matter'
2025-04-10 22:52:47.481 : [deviceDriverManager 112400] - DEBUG: deviceDriverManagerGetDeviceDriversBySubsystem: subsystem=matter
2025-04-10 22:52:47.482 : [deviceService 112400] - DEBUG: subsystemManager: subsystemManagerGetRegisteredSubsystems - 
2025-04-10 22:52:47.482 : [deviceService 112400] - DEBUG: subsystemManager: subsystemManagerGetSubsystemStatusJson - 
2025-04-10 22:52:47.482 : [Matter 112400] - DEBUG: MatterSubsystem (getStatusJson): 
2025-04-10 22:52:47.482 : [deviceService 112400] - DEBUG: subsystemManager: subsystemManagerGetSubsystemStatusJson - 
2025-04-10 22:52:47.482 : [threadSubsystem 112400] - DEBUG: getStatusJson: 
2025-04-10 22:52:47.482 : [deviceService 112400] - INFO: subsystemManager: subsystemManagerIsReadyForDevices - Subsystem thread is not yet ready
2025-04-10 22:52:47.568 : [MatterSDK 112400] - ERROR: [DL] Disabling CHIPoBLE service due to error: src/platform/Linux/BLEManagerImpl.cpp:551: Ble Error 0x00000401: BLE adape
2025-04-10 22:52:47.568 : [MatterSDK 112400] - DEBUG: [DIS] Updating services using commissioning mode 0
2025-04-10 22:52:47.577 : [MatterSDK 112400] - DEBUG: [DIS] CHIP minimal mDNS started advertising.
2025-04-10 22:52:47.608 : [MatterSDK 112400] - DEBUG: [DIS] Advertise operational node A7B405C82BDF3872-00D8730FD2953874
2025-04-10 22:52:47.608 : [MatterSDK 112400] - DEBUG: [DIS] CHIP minimal mDNS configured as 'Operational device'; instance name: A7B405C82BDF3872-00D8730FD2953874.
2025-04-10 22:52:47.624 : [MatterSDK 112400] - DEBUG: [DIS] mDNS service published: _matter._tcp
2025-04-10 22:52:47.624 : [MatterSDK 112400] - DEBUG: [DIS] Advertise commission parameter vendorID=65521 productID=32769 discriminator=0000/00 cm=0 cp=0
2025-04-10 22:52:47.624 : [MatterSDK 112400] - DEBUG: [DIS] CHIP minimal mDNS configured as 'Commissioner device'; instance name: EE7F91E4F8DE6D17.
2025-04-10 22:52:47.639 : [MatterSDK 112400] - DEBUG: [DIS] mDNS service published: _matterd._udp
2025-04-10 22:52:47.639 : [tbrmd 112400] - DEBUG: OnMatterPlatformEventHandler: 
2025-04-10 22:52:47.639 : [Matter 112400] - DEBUG: (EventHandler): EventType=8012
2025-04-10 22:52:47.639 : [tbrmd 112400] - DEBUG: OnMatterPlatformEventHandler: 
2025-04-10 22:52:47.639 : [Matter 112400] - DEBUG: (EventHandler): EventType=8016

CLI

deviceService> help
Core:
        discoverStart|dstart <device class> [setup code] : Start discovery for a device class with optional setup code for Matter devices
        discoverStop|dstop  : Stop device discovery
        listDevices|list [-i] [device class] : list all devices, or all devices in a class. Use -i to show device IDs only
        printDevice|pd <uuid> : print information for a device
        printAllDevices|pa [device class] : print information for all devices, or all devices in a class
        readResource|rr <uri> : read the value of a resource
        Examples:
                readResource /000d6f000aae8410/r/communicationFailure

        writeResource|wr <uri> [value] : write the value of a resource
        Examples:
                writeResource /000d6f000aae8410/ep/1/r/label "Front Door"

        execResource|er <uri> [value] : execute a resource
        queryResources|qr <uri pattern> : query resources with a pattern
        Examples:
                qr */lowBatt

        readMetadata|rm <uri> : read metadata
        Examples:
                rm /000d6f000aae8410/m/lpmPolicy

        writeMetadata|wm <uri> : write metadata
        Examples:
                wm /000d6f000aae8410/m/lpmPolicy never

        queryMetadata|qm <uri pattern> : query metadata through a uri pattern
        Examples:
                qm */rejoins

        getStatus|gs  : Get the status of device service
        dumpDevice|dd <uuid> : Dump all details about a device
        dumpAllDevices|dump  : Dump all details about all devices
        removeDevice|rd <uuid> : Remove a device by uuid
        removeEndpoint|re <uri> : Remove an endpoint by uri
        getProperty|gp <key> : Get a property value
        setProperty|sp <key> [value] : Set a property value
        ddl override <path> | clearoverride | process | bypass | clearbypass : Configure and control device descriptor processing
        Examples:
                ddl override /opt/etc/AllowList.xml.override
                ddl clearoverride
                ddl process
                ddl bypass
                ddl clearbypass

Matter:
        commissionDevice|cd <setup payload> : Commission a specific device with the provided setup payload
        addMatterDevice|amd <node id> : Add a Matter device, which has already been commissioned onto the fabric, to the databaseafter locating and configuring it
        openCommissioningWindow|ocw <node id> [timeout secs] : Open the commissioning window locally (node id 0) or for a specific node id. Omit timeout for defaults
Thread:
        setNat64Enabled|sne <true|false> : Enable or disable the Thread Border Router's NAT64 system
        activateEphemeralKeyMode|aekm  : Activate ephemeral key mode and print the ePSKc
deviceService>

system status

    root@Filogic-GW:~# systemctl status otbr-agent
* otbr-agent.service - OpenThread Border Router service
     Loaded: loaded (8;;file://Filogic-GW/lib/systemd/system/otbr-agent.service/lib/systemd/system/otbr-agent.service8;;; disabled; vendor preset: disabled)
     Active: active (running) since Thu 2022-04-28 17:42:30 UTC; 2 years 11 months ago
TriggeredBy: * otbr-agent.path
   Main PID: 1856 (otbr-agent)
      Tasks: 2 (limit: 4713)
     Memory: 4.7M
     CGroup: /system.slice/otbr-agent.service
             `- 1856 otbr-agent -v -d5 -I wpan0 -B brlan0 "spinel+cpc://cpcd_0?iid=2&iid-list=0" trel://brlan0

Notice: journal has been rotated since unit was started, output may be incomplete.
root@Filogic-GW:~# 
root@Filogic-GW:~# systemctl status cpcd      
* cpcd.service - Service for the 802.15.4 co-processor communication daemon
     Loaded: loaded (8;;file://Filogic-GW/lib/systemd/system/cpcd.service/lib/systemd/system/cpcd.service8;;; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2022-04-28 17:42:28 UTC; 2 years 11 months ago
   Main PID: 1767 (cpcd)
      Tasks: 5 (limit: 4713)
     Memory: 1.5M
     CGroup: /system.slice/cpcd.service
             `- 1767 /usr/bin/cpcd -c /etc/cpcd.conf

Notice: journal has been rotated since unit was started, output may be incomplete.
root@Filogic-GW:~# 

root@Filogic-GW:~# systemctl status bt-host-cpc-hci-bridge-attach.service
* bt-host-cpc-hci-bridge-attach.service - Attach Bluetooth HCI Bridge
     Loaded: loaded (8;;file://Filogic-GW/lib/systemd/system/bt-host-cpc-hci-bridge-attach.service/lib/systemd/system/bt-host-cpc-hci-bridge-attach.service8;;; enabled; vend)
     Active: active (running) since Thu 2022-04-28 17:42:30 UTC; 2 years 11 months ago
   Main PID: 1872 (btattach)
      Tasks: 1 (limit: 4713)
     Memory: 420.0K
     CGroup: /system.slice/bt-host-cpc-hci-bridge-attach.service
             `- 1872 /usr/bin/btattach -B /dev/pts/0 -S 115200

Notice: journal has been rotated since unit was started, output may be incomplete.
root@Filogic-GW:~# systemctl status bt-host-cpc-hci-bridge.service
* bt-host-cpc-hci-bridge.service - Bluetooth CPC HCI Bridge
     Loaded: loaded (8;;file://Filogic-GW/lib/systemd/system/bt-host-cpc-hci-bridge.service/lib/systemd/system/bt-host-cpc-hci-bridge.service8;;; enabled; vendor preset: ena)
     Active: active (running) since Thu 2022-04-28 17:42:28 UTC; 2 years 11 months ago
   Main PID: 1768 (bt_host_cpc_hci)
      Tasks: 2 (limit: 4713)
     Memory: 484.0K
     CGroup: /system.slice/bt-host-cpc-hci-bridge.service
             `- 1768 /usr/bin/bt_host_cpc_hci_bridge

Notice: journal has been rotated since unit was started, output may be incomplete.
root@Filogic-GW:~# igmpProxyRun: difftime is > 1000 secs, resetting to 0

wpan0

Matter onboarding stages Barton

MatterBarton

Vendor integration

Silabs radio integration
- OpenThread & Bluetooth platform integration in BPI R4 with silabs radio

OSS component support

linenoise upstep
- Revision details
  - https://github.com/antirez/linenoise/commit/d895173d679be70bcd8b23041fff3e458e1a3506
  - Recipe changes
    - linenoise
    - Note:depending on usage please include 001 patch too
- File location
  - /home/cpokur625/BI/meta-rdk-ext/recipes-support/linenoise

Verification with matter device

deviceService> cd 03764151187
Attempting to commission device
2025-04-10 23:05:26.638 : [Matter 177014] - DEBUG: MatterSubsystem (matterSubsystemCommissionDevice): 
2025-04-10 23:05:26.638 : [MatterCommishOrch 177014] - DEBUG: (Commission): 
2025-04-10 23:05:26.638 : [Matter 177014] - INFO: MatterSubsystem (onDeviceCommissioningStatusChanged): Commissioning status = Pending
2025-04-10 23:05:26.638 : [MatterCommishOrch 177014] - DEBUG: (CommissionWorkFunc): 
2025-04-10 23:05:26.638 : [Matter 177014] - DEBUG: (GetCommissioningParams): 
2025-04-10 23:05:26.638 : [threadSubsystem 177014] - DEBUG: threadSubsystemGetNetworkInfo: 
2025-04-10 23:05:26.638 : [Matter 177014] - WARN: (GetCommissioningParams): Was unable to get thread operational dataset from the subsystem
2025-04-10 23:05:26.638 : [MatterCommishOrch 177014] - DEBUG: (CommissionWorkFunc): Calling PairDevice()
2025-04-10 23:05:26.638 : [MatterSDK 177014] - DEBUG: [CTL] Setting wifi credentials from parameters
2025-04-10 23:05:26.638 : [MatterSDK 177014] - DEBUG: [CTL] Setting attestation nonce to random value
2025-04-10 23:05:26.638 : [MatterSDK 177014] - DEBUG: [CTL] Setting CSR nonce to random value
2025-04-10 23:05:26.638 : [MatterSDK 177014] - DEBUG: [CTL] Starting commissioning discovery over BLE
2025-04-10 23:05:26.638 : [MatterSDK 177014] - DEBUG: [CTL] WiFi-PAF: has RendezvousInformationFlag::kWiFiPAF
2025-04-10 23:05:26.638 : [MatterSDK 177014] - DEBUG: [CTL] Starting commissioning discovery over DNS-SD
2025-04-10 23:05:26.639 : [Matter 177014] - INFO: MatterSubsystem (onDeviceCommissioningStatusChanged): Commissioning status = Started
2025-04-10 23:05:26.639 : [MatterSDK 177014] - DEBUG: [BLE] BLE removing known devices
2025-04-10 23:05:26.641 : [MatterSDK 177014] - DEBUG: [BLE] BLE initiating scan
2025-04-10 23:05:26.677 : [MatterCommishOrch 177014] - DEBUG: OnDiscoveredDevice: fe80::32de:4bff:fedb:8034
2025-04-10 23:05:26.677 : [Matter 177014] - INFO: MatterSubsystem (onDeviceCommissioningStatusChanged): Commissioning status = DeviceFound
2025-04-10 23:05:26.677 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:26.677 : [MatterSDK 177014] - DEBUG: [CTL] Attempting PASE connection to UDP:[fe80::32de:4bff:fedb:8034%brlan0]:5540
2025-04-10 23:05:26.678 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16090i S:0 M:149377291] (U) Msg TX from 0227AE897A7DC92D to 0:0000000000000000 [0000] [UDP:[fe80::32de:4bff)
2025-04-10 23:05:26.678 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16090i S:0 M:149377291] (U) Msg Retransmission to 0:0000000000000000 in 396ms [State:Active II:5000 AI:300 ]
2025-04-10 23:05:26.678 : [MatterSDK 177014] - DEBUG: [SC] Sent PBKDF param request [II:500ms AI:300ms AT:4000ms)
2025-04-10 23:05:26.678 : [MatterSDK 177014] - DEBUG: [CTL] Commission called for node ID 0x3F5A1FB8162C478C
2025-04-10 23:05:26.687 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16090i S:0 M:114414583 (Ack:149377291)] (U) Msg RX from 0:0000000000000000 [0000] to 0227AE897A7DC92D --- T)
2025-04-10 23:05:26.689 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16090i S:0 M:114414584 (Ack:149377291)] (U) Msg RX from 0:0000000000000000 [0000] to 0227AE897A7DC92D --- T)
2025-04-10 23:05:26.758 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16090i S:0 M:149377292 (Ack:114414584)] (U) Msg TX from 0227AE897A7DC92D to 0:0000000000000000 [0000] [UDP:)
2025-04-10 23:05:26.759 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16090i S:0 M:149377292] (U) Msg Retransmission to 0:0000000000000000 in 358ms [State:Active II:5000 AI:300 ]
2025-04-10 23:05:26.764 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16090i S:0 M:114414585 (Ack:149377292)] (U) Msg RX from 0:0000000000000000 [0000] to 0227AE897A7DC92D --- T)
2025-04-10 23:05:27.688 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16090i S:0 M:114414586 (Ack:149377292)] (U) Msg RX from 0:0000000000000000 [0000] to 0227AE897A7DC92D --- T)
2025-04-10 23:05:27.690 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16090i S:0 M:149377293 (Ack:114414586)] (U) Msg TX from 0227AE897A7DC92D to 0:0000000000000000 [0000] [UDP:)
2025-04-10 23:05:27.690 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16090i S:0 M:149377293] (U) Msg Retransmission to 0:0000000000000000 in 384ms [State:Active II:5000 AI:300 ]
2025-04-10 23:05:27.693 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.694 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.695 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.697 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.698 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.699 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.700 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.701 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.701 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.702 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.704 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.705 : [MatterSDK 177014] - DEBUG: [CTL] Discovered device to be commissioned over DNS-SD
2025-04-10 23:05:27.705 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16090i S:0 M:114414587 (Ack:149377293)] (U) Msg RX from 0:0000000000000000 [0000] to 0227AE897A7DC92D --- T)
2025-04-10 23:05:27.706 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16090i S:0 M:114414588 (Ack:149377293)] (U) Msg RX from 0:0000000000000000 [0000] to 0227AE897A7DC92D --- T)
2025-04-10 23:05:27.706 : [MatterSDK 177014] - DEBUG: [SC] SecureSession[0x7f54007d90, LSID:211]: State change 'kEstablishing' --> 'kActive'
2025-04-10 23:05:27.706 : [MatterSDK 177014] - DEBUG: [CTL] PASE session established with commissionee. Stopping discovery.
2025-04-10 23:05:27.820 : [MatterSDK 177014] - DEBUG: [BLE] Scan complete. No matching device found.
2025-04-10 23:05:27.820 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
2025-04-10 23:05:27.820 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'ReadCommissioningInfo'
2025-04-10 23:05:27.820 : [MatterSDK 177014] - DEBUG: [CTL] Sending read request for commissioning information
2025-04-10 23:05:27.820 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:27.820 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16091i S:211 M:118507442] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:27.821 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16091i S:211 M:118507442] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 402ms [State:Active II:5000 AI:30]
2025-04-10 23:05:27.821 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16090i S:0 M:149377294 (Ack:114414588)] (U) Msg TX from 0227AE897A7DC92D to 0:0000000000000000 [0000] [UDP:)
2025-04-10 23:05:27.821 : [tbrmd 177014] - DEBUG: OnMatterPlatformEventHandler: 
2025-04-10 23:05:27.821 : [Matter 177014] - DEBUG: (EventHandler): EventType=8018
2025-04-10 23:05:27.862 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16091i S:211 M:201451909 (Ack:118507442)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:27.863 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='ReadCommissioningInfo' error='src/controll'
2025-04-10 23:05:27.863 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'ReadCommissioningInfo'
2025-04-10 23:05:27.863 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'ReadCommissioningInfo' -> 'ReadCommissioningInfo2'
2025-04-10 23:05:27.863 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'ReadCommissioningInfo2'
2025-04-10 23:05:27.863 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:27.863 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16092i S:211 M:118507443] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:27.863 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16092i S:211 M:118507443] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 401ms [State:Active II:5000 AI:30]
2025-04-10 23:05:27.864 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16091i S:211 M:118507444 (Ack:201451909)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:27.873 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16092i S:211 M:201451910 (Ack:118507443)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:27.873 : [MatterSDK 177014] - DEBUG: [CTL] ----- NetworkCommissioning Features: has WiFi. endpointid = 0
2025-04-10 23:05:27.873 : [MatterCommishOrch 177014] - DEBUG: (OnReadCommissioningInfo): Node 0000000000000000
2025-04-10 23:05:27.873 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='ReadCommissioningInfo2' error='src/control'
2025-04-10 23:05:27.873 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'ReadCommissioningInfo2'
2025-04-10 23:05:27.873 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'ReadCommissioningInfo2' -> 'ArmFailSafe'
2025-04-10 23:05:27.873 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'ArmFailSafe'
2025-04-10 23:05:27.873 : [MatterSDK 177014] - DEBUG: [CTL] Arming failsafe (60 seconds)
2025-04-10 23:05:27.874 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16093i S:211 M:118507445] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:27.874 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16093i S:211 M:118507445] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 401ms [State:Active II:5000 AI:30]
2025-04-10 23:05:27.875 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16092i S:211 M:118507446 (Ack:201451910)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:27.883 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16093i S:211 M:201451911 (Ack:118507445)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:27.883 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
2025-04-10 23:05:27.884 : [MatterSDK 177014] - DEBUG: [CTL] Received ArmFailSafe response errorCode=0
2025-04-10 23:05:27.884 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='ArmFailSafe' error='src/controller/CHIPDev'
2025-04-10 23:05:27.884 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'ArmFailSafe'
2025-04-10 23:05:27.884 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
2025-04-10 23:05:27.884 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'ConfigRegulatory'
2025-04-10 23:05:27.884 : [MatterSDK 177014] - DEBUG: [CTL] Setting Regulatory Config
2025-04-10 23:05:27.884 : [MatterSDK 177014] - DEBUG: [CTL] Device does not support configurable regulatory location
2025-04-10 23:05:27.884 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16094i S:211 M:118507447] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:27.884 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16094i S:211 M:118507447] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 388ms [State:Active II:5000 AI:30]
2025-04-10 23:05:27.884 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16093i S:211 M:118507448 (Ack:201451911)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:27.985 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16094i S:211 M:201451912 (Ack:118507447)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:27.985 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
2025-04-10 23:05:27.985 : [MatterSDK 177014] - DEBUG: [CTL] Received SetRegulatoryConfig response errorCode=0
2025-04-10 23:05:27.985 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='ConfigRegulatory' error='src/controller/CH'
2025-04-10 23:05:27.985 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'ConfigRegulatory'
2025-04-10 23:05:27.985 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest'
2025-04-10 23:05:27.985 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'SendPAICertificateRequest'
2025-04-10 23:05:27.985 : [MatterSDK 177014] - DEBUG: [CTL] Sending request for PAI certificate
2025-04-10 23:05:27.985 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16095i S:211 M:118507449] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:27.985 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16095i S:211 M:118507449] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 359ms [State:Active II:5000 AI:30]
2025-04-10 23:05:27.986 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16094i S:211 M:118507450 (Ack:201451912)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:28.018 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16095i S:211 M:201451913 (Ack:118507449)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:28.018 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
2025-04-10 23:05:28.018 : [MatterSDK 177014] - DEBUG: [CTL] Received certificate chain from the device
2025-04-10 23:05:28.018 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='SendPAICertificateRequest' error='src/cont'
2025-04-10 23:05:28.018 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'SendPAICertificateRequest'
2025-04-10 23:05:28.018 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
2025-04-10 23:05:28.018 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'SendDACCertificateRequest'
2025-04-10 23:05:28.018 : [MatterSDK 177014] - DEBUG: [CTL] Sending request for DAC certificate
2025-04-10 23:05:28.019 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16096i S:211 M:118507451] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:28.019 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16096i S:211 M:118507451] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 331ms [State:Active II:5000 AI:30]
2025-04-10 23:05:28.019 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16095i S:211 M:118507452 (Ack:201451913)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:28.032 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16096i S:211 M:201451914 (Ack:118507451)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:28.032 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
2025-04-10 23:05:28.032 : [MatterSDK 177014] - DEBUG: [CTL] Received certificate chain from the device
2025-04-10 23:05:28.032 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='SendDACCertificateRequest' error='src/cont'
2025-04-10 23:05:28.032 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'SendDACCertificateRequest'
2025-04-10 23:05:28.032 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
2025-04-10 23:05:28.032 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'SendAttestationRequest'
2025-04-10 23:05:28.032 : [MatterSDK 177014] - DEBUG: [CTL] Sending Attestation Request to the device.
2025-04-10 23:05:28.032 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16097i S:211 M:118507453] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:28.033 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16097i S:211 M:118507453] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 349ms [State:Active II:5000 AI:30]
2025-04-10 23:05:28.033 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16096i S:211 M:118507454 (Ack:201451914)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:28.047 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16097i S:211 M:201451915 (Ack:118507453)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:28.237 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16097i S:211 M:201451916 (Ack:118507453)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:28.237 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
2025-04-10 23:05:28.237 : [MatterSDK 177014] - DEBUG: [CTL] Received Attestation Information from the device
2025-04-10 23:05:28.237 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='SendAttestationRequest' error='src/control'
2025-04-10 23:05:28.237 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'SendAttestationRequest'
2025-04-10 23:05:28.237 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
2025-04-10 23:05:28.237 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'AttestationVerification'
2025-04-10 23:05:28.237 : [MatterSDK 177014] - DEBUG: [CTL] Verifying attestation
2025-04-10 23:05:28.252 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='AttestationVerification' error='src/contro'
2025-04-10 23:05:28.252 : [MatterSDK 177014] - ERROR: [CTL] Error on commissioning step 'AttestationVerification': 'src/controller/CHIPDeviceController.cpp:1283: CHIP Error '
2025-04-10 23:05:28.252 : [MatterSDK 177014] - ERROR: [CTL] Failed verifying attestation information. Now checking DAC chain revoked status.
2025-04-10 23:05:28.252 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'AttestationVerification' -> 'AttestationRevocationCheck'
2025-04-10 23:05:28.252 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'AttestationRevocationCheck' with completion status = 'src/controller/CHIPDevi'
2025-04-10 23:05:28.252 : [MatterSDK 177014] - DEBUG: [CTL] Verifying device's DAC chain revocation status
2025-04-10 23:05:28.252 : [MatterSDK 177014] - ERROR: [CTL] Failed in verifying 'Attestation Information' command received from the device: err 101. Look at AttestationVerifs
2025-04-10 23:05:28.252 : [MatterSDK 177014] - DEBUG: [CTL] Proceeding without changing fail-safe timer value as delegate has not set it
2025-04-10 23:05:28.252 : [MatterSDK 177014] - DEBUG: [CTL] Device attestation completed, delegating continuation to client
2025-04-10 23:05:28.252 : [Matter 177014] - DEBUG: (OnDeviceAttestationCompleted): 
2025-04-10 23:05:28.252 : [Matter 177014] - WARN: (OnDeviceAttestationCompleted): Attestation failed, but we are allowing it anyway
2025-04-10 23:05:28.252 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='AttestationRevocationCheck' error='/usr/sr'
2025-04-10 23:05:28.252 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'AttestationRevocationCheck'
2025-04-10 23:05:28.252 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'AttestationRevocationCheck' -> 'SendOpCertSigningRequest'
2025-04-10 23:05:28.252 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'SendOpCertSigningRequest'
2025-04-10 23:05:28.253 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16098i S:211 M:118507455] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:28.253 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16098i S:211 M:118507455] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 376ms [State:Active II:5000 AI:30]
2025-04-10 23:05:28.253 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16097i S:211 M:118507456 (Ack:201451916)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:28.260 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16098i S:211 M:201451917 (Ack:118507455)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:28.807 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16098i S:211 M:201451918 (Ack:118507455)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:28.807 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
2025-04-10 23:05:28.807 : [MatterSDK 177014] - DEBUG: [CTL] Received certificate signing request from the device
2025-04-10 23:05:28.807 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='SendOpCertSigningRequest' error='src/contr'
2025-04-10 23:05:28.807 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'SendOpCertSigningRequest'
2025-04-10 23:05:28.807 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR'
2025-04-10 23:05:28.807 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'ValidateCSR'
2025-04-10 23:05:28.810 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='ValidateCSR' error='src/credentials/attest'
2025-04-10 23:05:28.810 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'ValidateCSR'
2025-04-10 23:05:28.810 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain'
2025-04-10 23:05:28.810 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'GenerateNOCChain'
2025-04-10 23:05:28.810 : [MatterSDK 177014] - DEBUG: [CTL] Getting certificate chain for the device from the issuer
2025-04-10 23:05:28.813 : [MatterSDK 177014] - DEBUG: [CTL] Verifying Certificate Signing Request
2025-04-10 23:05:28.813 : [MatterStorage 177014] - DEBUG: (SyncGetKeyValue): key = comcastSelfSignedRootCA_privateKey
2025-04-10 23:05:28.813 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16098i S:211 M:118507457 (Ack:201451918)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:28.814 : [MatterStorage 177014] - DEBUG: (SyncGetKeyValue): key = comcastSelfSignedRootCA_certificate
2025-04-10 23:05:28.818 : [MatterSDK 177014] - DEBUG: [CTL] Received callback from the CA for NOC Chain generation. Status third_party/comcast/controller/certifier-credentias
2025-04-10 23:05:28.818 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='GenerateNOCChain' error='third_party/comca'
2025-04-10 23:05:28.818 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'GenerateNOCChain'
2025-04-10 23:05:28.819 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'SendTrustedRootCert'
2025-04-10 23:05:28.819 : [MatterSDK 177014] - DEBUG: [CTL] Sending root certificate to the device
2025-04-10 23:05:28.819 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16099i S:211 M:118507458] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:28.819 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16099i S:211 M:118507458] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 363ms [State:Active II:5000 AI:30]
2025-04-10 23:05:28.819 : [MatterSDK 177014] - DEBUG: [CTL] Sent root certificate to the device
2025-04-10 23:05:28.825 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16099i S:211 M:201451919 (Ack:118507458)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:29.218 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16099i S:211 M:201451920 (Ack:118507458)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:29.218 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
2025-04-10 23:05:29.218 : [MatterSDK 177014] - DEBUG: [CTL] Device confirmed that it has received the root certificate
2025-04-10 23:05:29.218 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='SendTrustedRootCert' error='src/controller'
2025-04-10 23:05:29.218 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'SendTrustedRootCert'
2025-04-10 23:05:29.218 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
deviceSe[  578.403586] systemd-journald[1074]: Data hash table of /run/log/journal/9d4624db79514687a5f674609ebd66ba/system.journal has a fill level at 75.0 (5461 of 7281 ite.
2025-04-10[  578.426153] systemd-journald[1074]: /run/log/journal/9d4624db79514687a5f674609ebd66ba/system.journal: Journal header limits reached or header out-of-date, rotat.
 23:05:29.218 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'SendNOC'
2025-04-10 23:05:29.218 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16100i S:211 M:118507459] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::32de:4b)
2025-04-10 23:05:29.218 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16100i S:211 M:118507459] (S) Msg Retransmission to 0:FFFFFFFB00000000 in 374ms [State:Active II:5000 AI:30]
2025-04-10 23:05:29.219 : [MatterSDK 177014] - DEBUG: [CTL] Sent operational certificate to the device
2025-04-10 23:05:29.219 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16099i S:211 M:118507460 (Ack:201451920)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:29.232 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16100i S:211 M:201451921 (Ack:118507459)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16100i S:211 M:201451922 (Ack:118507459)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] to 0000000000000000 ---)
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [CTL] Device returned status 0 on receiving the NOC
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [CTL] Operational credentials provisioned on device 0x7f540075a0
2025-04-10 23:05:29.825 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='SendNOC' error='src/controller/CHIPDeviceC'
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'SendNOC'
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'SendNOC' -> 'kEvictPreviousCaseSessions'
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'kEvictPreviousCaseSessions'
2025-04-10 23:05:29.825 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='kEvictPreviousCaseSessions' error='src/con'
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'kEvictPreviousCaseSessions'
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'kEvictPreviousCaseSessions' -> 'kFindOperationalForStayActive'
2025-04-10 23:05:29.825 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'kFindOperationalForStayActive'
2025-04-10 23:05:29.826 : [MatterSDK 177014] - DEBUG: [DIS] Lookup started for A7B405C82BDF3872-3F5A1FB8162C478C
2025-04-10 23:05:29.827 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16100i S:211 M:118507461 (Ack:201451922)] (S) Msg TX from 0000000000000000 to 0:FFFFFFFB00000000 [0000] [UD)
2025-04-10 23:05:29.848 : [MatterSDK 177014] - DEBUG: [DIS] UDP:[fe80::32de:4bff:fedb:8034%brlan0]:5540: new best score: 7 (for A7B405C82BDF3872-3F5A1FB8162C478C)
2025-04-10 23:05:29.849 : [MatterSDK 177014] - DEBUG: [DIS] UDP:[fd4b:12ad:104e:599c:32de:4bff:fedb:8034%brlan0]:5540: new best score: 3 (for A7B405C82BDF3872-3F5A1FB8162C47)
2025-04-10 23:05:29.850 : [MatterSDK 177014] - DEBUG: [DIS] UDP:[fd7d:45d6:186:d26b:32de:4bff:fedb:8034%brlan0]:5540: new best score: 3 (for A7B405C82BDF3872-3F5A1FB8162C478)
2025-04-10 23:05:29.850 : [MatterSDK 177014] - DEBUG: [DIS] Checking node lookup status for A7B405C82BDF3872-3F5A1FB8162C478C after 24 ms
2025-04-10 23:05:29.850 : [MatterSDK 177014] - DEBUG: [DIS] Keeping DNSSD lookup active
2025-04-10 23:05:30.025 : [MatterSDK 177014] - DEBUG: [DIS] Checking node lookup status for A7B405C82BDF3872-3F5A1FB8162C478C after 200 ms
2025-04-10 23:05:30.026 : [MatterSDK 177014] - DEBUG: [SC] Initiating session on local FabricIndex 1 from 0x00D8730FD2953874 -> 0x3F5A1FB8162C478C
2025-04-10 23:05:30.026 : [MatterStorage 177014] - DEBUG: (SyncGetKeyValue): key = f/1/g
2025-04-10 23:05:30.026 : [MatterStorage 177014] - DEBUG: (SyncGetKeyValue): key = f/1/k/0
2025-04-10 23:05:30.026 : [MatterStorage 177014] - DEBUG: (SyncGetKeyValue): key = f/1/s/3F5A1FB8162C478C
2025-04-10 23:05:30.027 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16101i S:0 M:149377295] (U) Msg TX from 476540822FB0C115 to 0:0000000000000000 [0000] [UDP:[fe80::32de:4bff)
2025-04-10 23:05:30.027 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16101i S:0 M:149377295] (U) Msg Retransmission to 0:0000000000000000 in 5845ms [State:Idle II:5000 AI:300 A]
2025-04-10 23:05:30.027 : [MatterSDK 177014] - DEBUG: [SC] Sent Sigma1 msg to <3F5A1FB8162C478C, 1> [II:500ms AI:300ms AT:4000ms]
2025-04-10 23:05:30.032 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16101i S:0 M:114414589 (Ack:149377295)] (U) Msg RX from 0:0000000000000000 [0000] to 476540822FB0C115 --- T)
2025-04-10 23:05:30.576 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16101i S:0 M:114414590 (Ack:149377295)] (U) Msg RX from 0:0000000000000000 [0000] to 476540822FB0C115 --- T)
2025-04-10 23:05:30.576 : [MatterSDK 177014] - DEBUG: [SC] Received Sigma2 msg
2025-04-10 23:05:30.581 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16101i S:0 M:149377296 (Ack:114414590)] (U) Msg TX from 476540822FB0C115 to 0:0000000000000000 [0000] [UDP:)
2025-04-10 23:05:30.581 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16101i S:0 M:149377296] (U) Msg Retransmission to 0:0000000000000000 in 412ms [State:Active II:5000 AI:300 ]
2025-04-10 23:05:30.581 : [MatterSDK 177014] - DEBUG: [SC] Sent Sigma3 msg
2025-04-10 23:05:30.595 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16101i S:0 M:114414591 (Ack:149377296)] (U) Msg RX from 0:0000000000000000 [0000] to 476540822FB0C115 --- T)
2025-04-10 23:05:30.938 : [MatterSDK 177014] - DEBUG: [DL] Thread role changed to: leader
2025-04-10 23:05:30.941 : [tbrmd 177014] - DEBUG: OnMatterPlatformEventHandler: 
2025-04-10 23:05:30.941 : [Matter 177014] - DEBUG: (EventHandler): EventType=8001
2025-04-10 23:05:30.941 : [tbrmd 177014] - DEBUG: OnMatterPlatformEventHandler: 
2025-04-10 23:05:30.941 : [Matter 177014] - DEBUG: (EventHandler): EventType=800b
2025-04-10 23:05:31.490 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16101i S:0 M:114414592 (Ack:149377296)] (U) Msg RX from 0:0000000000000000 [0000] to 476540822FB0C115 --- T)
2025-04-10 23:05:31.490 : [MatterSDK 177014] - DEBUG: [SC] Success status report received. Session was established
2025-04-10 23:05:31.490 : [MatterStorage 177014] - DEBUG: (SyncGetKeyValue): key = g/sri
2025-04-10 23:05:31.490 : [MatterStorage 177014] - DEBUG: (SyncSetKeyValue): key = f/1/s/3F5A1FB8162C478C
2025-04-10 23:05:31.505 : [MatterStorage 177014] - DEBUG: (SyncSetKeyValue): key = g/s/cM6ELQOpl5yTZb8rmQBNpA==
2025-04-10 23:05:31.522 : [MatterStorage 177014] - DEBUG: (SyncSetKeyValue): key = g/sri
2025-04-10 23:05:31.531 : [MatterSDK 177014] - DEBUG: [SC] SecureSession[0x7f54025d30, LSID:212]: State change 'kEstablishing' --> 'kActive'
2025-04-10 23:05:31.532 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='kFindOperationalForStayActive' error='src/'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'kFindOperationalForStayActive'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'kFindOperationalForStayActive' -> 'ICDSendStayActive'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'ICDSendStayActive'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Skipping kICDSendStayActive
2025-04-10 23:05:31.532 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='ICDSendStayActive' error='src/controller/C'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'ICDSendStayActive'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'ICDSendStayActive' -> 'kFindOperationalForCommissioningComplete'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'kFindOperationalForCommissioningComplete'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [DIS] Found an existing secure session to [1:3F5A1FB8162C478C]!
2025-04-10 23:05:31.532 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='kFindOperationalForCommissioningComplete' '
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'kFindOperationalForCommissioningComplete'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'kFindOperationalForCommissioningComplete' -> 'SendComplete'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'SendComplete'
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16102i S:212 M:141370255] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16102i S:212 M:141370255] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 377ms [State:Active II:5000 AI:30]
2025-04-10 23:05:31.532 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16101i S:0 M:149377297 (Ack:114414592)] (U) Msg TX from 476540822FB0C115 to 0:0000000000000000 [0000] [UDP:)
2025-04-10 23:05:31.532 : [tbrmd 177014] - DEBUG: OnMatterPlatformEventHandler: 
2025-04-10 23:05:31.532 : [Matter 177014] - DEBUG: (EventHandler): EventType=8018
2025-04-10 23:05:31.909 : [MatterSDK 177014] - DEBUG: [EM] <<1 [E:16102i S:212 M:141370255] (S) Msg Retransmission to 1:3F5A1FB8162C478C
2025-04-10 23:05:31.909 : [MatterSDK 177014] - DEBUG: [EM] ??2 [E:16102i S:212 M:141370255] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 347ms [State:Active II:5000 AI:30]
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16102i S:212 M:183602762 (Ack:141370255)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [CTL] Received CommissioningComplete response, errorCode=0
2025-04-10 23:05:31.910 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='SendComplete' error='src/controller/CHIPDe'
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'SendComplete'
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning stage next step: 'SendComplete' -> 'Cleanup'
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [CTL] Performing next commissioning step 'Cleanup'
2025-04-10 23:05:31.910 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningStatusUpdate): Node 3f5a1fb8162c478c stageCompleted='Cleanup' error='src/controller/CHIPDeviceC'
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [CTL] Successfully finished commissioning step 'Cleanup'
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [SC] SecureSession[0x7f54007d90, LSID:211]: State change 'kActive' --> 'kPendingEviction'
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [CTL] Commissioning complete for node ID 0x3F5A1FB8162C478C: success
2025-04-10 23:05:31.910 : [MatterCommishOrch 177014] - DEBUG: (OnCommissioningSuccess): Node 3f5a1fb8162c478c commissioned successfully
2025-04-10 23:05:31.910 : [Matter 177014] - INFO: MatterSubsystem (onDeviceCommissioningStatusChanged): Commissioning status = CommissionedSuccessfully
2025-04-10 23:05:31.910 : [MatterCommishOrch 177014] - DEBUG: (Commission): Done waiting for commissioning
2025-04-10 23:05:31.910 : [MatterCommishOrch 177014] - DEBUG: (Pair): Pairing device with node id 3f5a1fb8162c478c
2025-04-10 23:05:31.910 : [MatterCommishOrch 177014] - DEBUG: (SendCommissioningComplete): nodeId 3f5a1fb8162c478c
2025-04-10 23:05:31.910 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16102i S:212 M:141370256 (Ack:183602762)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:31.911 : [MatterSDK 177014] - DEBUG: [DIS] Found an existing secure session to [1:3F5A1FB8162C478C]!
2025-04-10 23:05:31.911 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16103i S:212 M:141370257] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:31.911 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16103i S:212 M:141370257] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 407ms [State:Active II:5000 AI:30]
2025-04-10 23:05:31.911 : [Matter 177014] - INFO: MatterSubsystem (onDeviceCommissioningStatusChanged): Commissioning status = DiscoveryPending

                                                                                                                                               ** (brtn-ds-reference:177014):d
2025-04-10 23:05:31.911 : [MatterSDK 177014] - DEBUG: [DIS] Found an existing secure session to [1:3F5A1FB8162C478C]!
2025-04-10 23:05:31.911 : [MatterDiscoverer 177014] - DEBUG: (OnDeviceConnectedFn): 
2025-04-10 23:05:31.911 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:31.912 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16104i S:212 M:141370258] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:31.912 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16104i S:212 M:141370258] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 361ms [State:Active II:5000 AI:30]
deviceService> 
               (brtn-ds-reference:177014): GLib-CRITICAL **: 23:05:32.244: g_hash_table_unref: assertion 'hash_table != NULL' failed
2025-04-10 23:05:32.025 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16102i S:212 M:183602763 (Ack:141370255)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.029 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16103i S:212 M:183602764 (Ack:141370257)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)

                                                                                                                                                                             d
2025-04-10 23:05:32.030 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16103i S:212 M:141370259 (Ack:183602764)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.039 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16104i S:212 M:183602765 (Ack:141370258)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.039 : [MatterDiscoverer 177014] - DEBUG: (OnAttributeData): Cluster 33, attribute 0
2025-04-10 23:05:32.039 : [MatterDiscoverer 177014] - DEBUG: (OnAttributeData): Cluster 28, attribute f
2025-04-10 23:05:32.039 : [MatterDiscoverer 177014] - DEBUG: (OnAttributeData): Cluster 28, attribute a
2025-04-10 23:05:32.039 : [MatterDiscoverer 177014] - DEBUG: (OnAttributeData): Cluster 28, attribute 9
2025-04-10 23:05:32.039 : [MatterDiscoverer 177014] - DEBUG: (OnAttributeData): Cluster 28, attribute 7
2025-04-10 23:05:32.039 : [MatterDiscoverer 177014] - DEBUG: (OnAttributeData): Cluster 28, attribute 3
2025-04-10 23:05:32.039 : [MatterDiscoverer 177014] - DEBUG: (OnAttributeData): Cluster 28, attribute 1
2025-04-10 23:05:32.039 : [MatterDiscoverer 177014] - DEBUG: (DiscoverEndpoint): endpoint 0
2025-04-10 23:05:32.039 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16105i S:212 M:141370260] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16105i S:212 M:141370260] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 377ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16106i S:212 M:141370261] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16106i S:212 M:141370261] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 409ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16107i S:212 M:141370262] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16107i S:212 M:141370262] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 378ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16108i S:212 M:141370263] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16108i S:212 M:141370263] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 334ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.040 : [MatterDiscoverer 177014] - DEBUG: (OnDone): 
2025-04-10 23:05:32.040 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16104i S:212 M:141370264 (Ack:183602765)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.054 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16105i S:212 M:183602766 (Ack:141370260)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.054 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16105i S:212 M:141370265 (Ack:183602766)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.060 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16106i S:212 M:183602767 (Ack:141370261)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.060 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16106i S:212 M:141370266 (Ack:183602767)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.063 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16107i S:212 M:183602768 (Ack:141370262)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.063 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16107i S:212 M:141370267 (Ack:183602768)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.068 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16108i S:212 M:183602769 (Ack:141370263)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.068 : [MatterDiscoverer 177014] - DEBUG: (DiscoverEndpoint): endpoint 1
2025-04-10 23:05:32.068 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:32.069 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16109i S:212 M:141370268] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.069 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16109i S:212 M:141370268] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 391ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.069 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:32.069 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16110i S:212 M:141370269] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.069 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16110i S:212 M:141370269] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 399ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.069 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:32.069 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16111i S:212 M:141370270] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.069 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16111i S:212 M:141370270] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 337ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.069 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:32.070 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16112i S:212 M:141370271] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.070 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16112i S:212 M:141370271] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 332ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.070 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16108i S:212 M:141370272 (Ack:183602769)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.081 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16109i S:212 M:183602770 (Ack:141370268)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.082 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16109i S:212 M:141370273 (Ack:183602770)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.085 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16110i S:212 M:183602771 (Ack:141370269)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.085 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16110i S:212 M:141370274 (Ack:183602771)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.087 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16111i S:212 M:183602772 (Ack:141370270)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.087 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16111i S:212 M:141370275 (Ack:183602772)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.107 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16112i S:212 M:183602773 (Ack:141370271)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.107 : [MatterCommishOrch 177014] - DEBUG: (Pair): Done waiting for discovery
2025-04-10 23:05:32.107 : [Matter 177014] - INFO: MatterSubsystem (onDeviceCommissioningStatusChanged): Commissioning status = DiscoveryCompleted
2025-04-10 23:05:32.107 : [MatterDoorLockDD 177014] - DEBUG: (ClaimDevice): 
2025-04-10 23:05:32.107 : [MatterLightDD 177014] - DEBUG: (ClaimDevice): 
2025-04-10 23:05:32.107 : [Matter 177014] - INFO: MatterDriverFactory (GetDriver): matterLight claimed the device
2025-04-10 23:05:32.107 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16112i S:212 M:141370276 (Ack:183602773)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.107 : [deviceService 177014] - DEBUG: deviceServiceDeviceFound: deviceClass=light, deviceClassVersion=3, uuid=3f5a1fb8162c478c, manufacturer=TP-Link, mod1
2025-04-10 23:05:32.107 : [device-service-property-provider 177014] - WARN: b_device_service_property_provider_get_property_as_string: Error getting property 'cpe.denylistedy
2025-04-10 23:05:32.107 : [libdeviceDescriptors 177014] - DEBUG: deviceDescriptorsGet: manufacturer=TP-Link, model=Mini Smart Wi-Fi Plug, hardwareVersion=1, firmwareVersion=1
2025-04-10 23:05:32.107 : [libdeviceDescriptors 177014] - DEBUG: no device descriptors loaded yet, attempting parse
2025-04-10 23:05:32.107 : [libdeviceDescriptorParser 177014] - WARN: Invalid/missing device descriptor list at /home/root/.brtn-ds/AllowList.xml
2025-04-10 23:05:32.107 : [libdeviceDescriptors 177014] - DEBUG: no device descriptors available.
2025-04-10 23:05:32.107 : [deviceService 177014] - DEBUG: deviceServiceDeviceFound: device added with 'neverReject'; allowing device to be paired
device discovered! uuid=3f5a1fb8162c478c, manufacturer=TP-Link, model=Mini Smart Wi-Fi Plug, hardwareVersion=1, firmwareVersion=0x00000001
2025-04-10 23:05:32.244 : [MatterBaseDD 177014] - DEBUG: (configureDevice): 
2025-04-10 23:05:32.244 : [MatterBaseDD 177014] - DEBUG: (ConnectAndExecute): 
2025-04-10 23:05:32.244 : [MatterSDK 177014] - DEBUG: [DIS] Found an existing secure session to [1:3F5A1FB8162C478C]!
2025-04-10 23:05:32.244 : [MatterBaseDD 177014] - DEBUG: (ConfigureDevice): 
2025-04-10 23:05:32.244 : [MatterBaseDD 177014] - DEBUG: (ConfigureOTARequestorCluster): 
2025-04-10 23:05:32.244 : [OTARequestorCluster 177014] - DEBUG: (SetDefaultOTAProviders): 
2025-04-10 23:05:32.245 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16113i S:212 M:141370277] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.245 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16113i S:212 M:141370277] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 378ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.245 : [MatterBaseDD 177014] - DEBUG: (ConfigureSubscription): 
2025-04-10 23:05:32.245 : [MatterBaseDD 177014] - DEBUG: (CalculateFinalSubscriptionIntervalSecs): 
2025-04-10 23:05:32.245 : [MatterBaseDD 177014] - DEBUG: (GetCommonClustersToSubscribeTo): 
2025-04-10 23:05:32.245 : [MatterLightDD 177014] - DEBUG: (GetClustersToSubscribeTo): 
2025-04-10 23:05:32.245 : [MatterBaseDD 177014] - INFO: (CalculateFinalSubscriptionIntervalSecs): Reducing max interval ceiling from 3600 secs to 1680 secs to line up with ct
2025-04-10 23:05:32.245 : [MatterBaseDD 177014] - DEBUG: (CalculateFinalSubscriptionIntervalSecs): Will request min interval floor of 1 seconds for the subscription on 3f5a1c
2025-04-10 23:05:32.245 : [MatterBaseDD 177014] - DEBUG: (CalculateFinalSubscriptionIntervalSecs): Will request max interval ceiling of 1680 seconds for the subscription on c
2025-04-10 23:05:32.245 : [MatterSDK 177014] - DEBUG: [DMG] 0 data version filters provided, 0 not relevant, 0 encoded, 0 skipped due to lack of space
2025-04-10 23:05:32.245 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370278] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:05:32.246 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370278] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 410ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.301 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16113i S:212 M:183602774 (Ack:141370277)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.301 : [MatterCluster 177014] - DEBUG: (OnResponse): 
2025-04-10 23:05:32.301 : [MatterCluster 177014] - DEBUG: (OnResponse): 
2025-04-10 23:05:32.301 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16113i S:212 M:141370279 (Ack:183602774)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.319 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602775 (Ack:141370278)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.320 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370280 (Ack:183602775)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.320 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370280] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 350ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.332 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602776 (Ack:141370280)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.333 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370281 (Ack:183602776)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.333 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370281] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 331ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.347 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602777 (Ack:141370281)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.348 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370282 (Ack:183602777)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.348 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370282] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 400ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.366 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602778 (Ack:141370282)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.367 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370283 (Ack:183602778)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.367 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370283] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 342ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.388 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602779 (Ack:141370283)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.389 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370284 (Ack:183602779)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.390 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370284] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 353ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.409 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602780 (Ack:141370284)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.410 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370285 (Ack:183602780)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.410 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370285] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 367ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.431 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602781 (Ack:141370285)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.431 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370286 (Ack:183602781)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.432 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370286] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 410ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.443 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602782 (Ack:141370286)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.444 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370287 (Ack:183602782)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.444 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370287] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 370ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.460 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602783 (Ack:141370287)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.461 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370288 (Ack:183602783)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.461 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370288] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 379ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.477 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602784 (Ack:141370288)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.478 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370289 (Ack:183602784)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.479 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370289] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 376ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.490 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602785 (Ack:141370289)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.491 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370290 (Ack:183602785)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.491 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370290] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 346ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.509 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602786 (Ack:141370290)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.510 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370291 (Ack:183602786)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.510 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370291] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 342ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.522 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602787 (Ack:141370291)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.522 : [deviceService 177014] - DEBUG: updateResource: deviceUuid=3f5a1fb8162c478c, endpointId=(null), resourceId=firmwareVersion, newValue=0x00000001
2025-04-10 23:05:32.522 : [deviceService 177014] - DEBUG: updateResource: deviceUuid=3f5a1fb8162c478c, endpointId=(null), resourceId=firmwareVersionString, newValue=1.0.0 Bu7
2025-04-10 23:05:32.522 : [deviceService 177014] - DEBUG: updateResource: deviceUuid=3f5a1fb8162c478c, endpointId=(null), resourceId=macAddress, newValue=30de4bdb8034
2025-04-10 23:05:32.522 : [deviceService 177014] - DEBUG: updateResource: deviceUuid=3f5a1fb8162c478c, endpointId=(null), resourceId=networkType, newValue=wifi
2025-04-10 23:05:32.522 : [MatterLightDD 177014] - DEBUG: (OnOffChanged): 
2025-04-10 23:05:32.522 : [deviceService 177014] - DEBUG: updateResource: deviceUuid=3f5a1fb8162c478c, endpointId=1, resourceId=isOn, newValue=false
2025-04-10 23:05:32.523 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370292 (Ack:183602787)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.523 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16114i S:212 M:141370292] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 363ms [State:Active II:5000 AI:30]
2025-04-10 23:05:32.533 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16114i S:212 M:183602788 (Ack:141370292)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:05:32.533 : [MatterSDK 177014] - DEBUG: [DMG] SubscribeResponse is received
2025-04-10 23:05:32.533 : [MatterSDK 177014] - DEBUG: [DMG] Subscription established with SubscriptionID = 0x74308e6d MinInterval = 1s MaxInterval = 1680s Peer = 01:3F5A1FB8C
2025-04-10 23:05:32.534 : [MatterSDK 177014] - DEBUG: [DMG] Refresh LivenessCheckTime for 1693265 milliseconds with SubscriptionId = 0x74308e6d Peer = 01:3F5A1FB8162C478C
2025-04-10 23:05:32.534 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16114i S:212 M:141370293 (Ack:183602788)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:05:32.534 : [MatterBaseDD 177014] - DEBUG: (ConnectAndExecute): Processed 2 async task(s) in 288 ms
2025-04-10 23:05:32.534 : [MatterBaseDD 177014] - DEBUG: (fetchInitialResourceValues): 
2025-04-10 23:05:32.534 : [MatterBaseDD 177014] - DEBUG: (ConnectAndExecute): 
2025-04-10 23:05:32.534 : [MatterSDK 177014] - DEBUG: [DIS] Found an existing secure session to [1:3F5A1FB8162C478C]!
2025-04-10 23:05:32.534 : [MatterLightDD 177014] - DEBUG: (FetchInitialResourceValues): 
2025-04-10 23:05:32.534 : [OnOffCluster 177014] - DEBUG: (GetOnOff): 
2025-04-10 23:05:32.534 : [MatterLightDD 177014] - DEBUG: (OnOffReadComplete): 
2025-04-10 23:05:32.534 : [MatterBaseDD 177014] - DEBUG: (ConnectAndExecute): Processed 1 async task(s) in 0 ms
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG: Initial Resource Values:
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG:    firmwareUpdateStatus=NULL
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG:    dateAdded=1744326332534
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG:    manufacturer=TP-Link
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG:    model=Mini Smart Wi-Fi Plug
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG:    dateLastContacted=1744326332534
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG:    hardwareVersion=1
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG:    1/isOn=false
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG:    communicationFailure=false
2025-04-10 23:05:32.534 : [initialResourceValues 177014] - DEBUG:    firmwareVersion=0x00000001
2025-04-10 23:05:32.535 : [MatterLightDD 177014] - DEBUG: (RegisterResources): 
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/manufacturer
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/model
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/hardwareVersion
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/firmwareVersion
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/firmwareUpdateStatus
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/dateAdded
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/dateLastContacted
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/communicationFailure
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/resetToFactoryDefaults
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/serialNumber
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/firmwareVersionString
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/macAddress
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/r/networkType
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/ep/1
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/ep/1/r/label
2025-04-10 23:05:32.535 : [deviceService 177014] - DEBUG: Created URI: /3f5a1fb8162c478c/ep/1/r/isOn
2025-04-10 23:05:32.548 : [storage 177014] - DEBUG: storageSave: saved file /home/root/.brtn-ds/storage/devicedb/3f5a1fb8162c478c in 13ms
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG: device finalized:
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG: Device
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:       uuid=3f5a1fb8162c478c
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:       deviceClass=light
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:       deviceClassVersion=3
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:       uri=/3f5a1fb8162c478c
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:       managingDeviceDriver=matterLight
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:       resources:
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/manufacturer] [id=manufacturer] [endpointId=(null)] [type=com.icontk
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/model] [id=model] [endpointId=(null)] [type=com.icontrol.string] [mg
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/hardwareVersion] [id=hardwareVersion] [endpointId=(null)] [type=com1
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/firmwareVersion] [id=firmwareVersion] [endpointId=(null)] [type=com1
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/firmwareUpdateStatus] [id=firmwareUpdateStatus] [endpointId=(null)])
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/dateAdded] [id=dateAdded] [endpointId=(null)] [type=com.icontrol.da4
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/dateLastContacted] [id=dateLastContacted] [endpointId=(null)] [type4
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/communicationFailure] [id=communicationFailure] [endpointId=(null)]e
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/resetToFactoryDefaults] [id=resetToFactoryDefaults] [endpointId=(nu)
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/serialNumber] [id=serialNumber] [endpointId=(null)] [type=com.icont)
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/firmwareVersionString] [id=firmwareVersionString] [endpointId=(null7
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/macAddress] [id=macAddress] [endpointId=(null)] [type=com.icontrol.4
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Resource [uri=/3f5a1fb8162c478c/r/networkType] [id=networkType] [endpointId=(null)] [type=com.icontroi
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:       endpoints:
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:               Endpoint
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                       id=1
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                       uri=/3f5a1fb8162c478c/ep/1
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                       profile=light
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                       profileVersion=0
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                       deviceUuid=3f5a1fb8162c478c
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                       enabled=true
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                       resources:
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                               Resource [uri=/3f5a1fb8162c478c/ep/1/r/label] [id=label] [endpointId=1] [type=com.icot
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                               Resource [uri=/3f5a1fb8162c478c/ep/1/r/isOn] [id=isOn] [endpointId=1] [type=com.iconte
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:                       metadata:
2025-04-10 23:05:32.548 : [deviceService 177014] - DEBUG:       metadata:
device added! deviceId=3f5a1fb8162c478c, uri=/3f5a1fb8162c478c, deviceClass=light, deviceClassVersion=3
endpoint added! deviceUuid=3f5a1fb8162c478c, id=1, uri=/3f5a1fb8162c478c/ep/1, profile=light, profileVersion=0
device discovery completed! uuid=3f5a1fb8162c478c, class=light
2025-04-10 23:05:32.549 : [MatterBaseDD 177014] - DEBUG: (DevicePersisted): 
2025-04-10 23:05:32.549 : [MatterDetailsStorage 177014] - ERROR: (Get): Failed to parse details metadata JSON: (null)
2025-04-10 23:05:32.549 : [deviceService 177014] - DEBUG: setMetadata: deviceUuid=3f5a1fb8162c478c, endpointId=(null), name=matterDetails, value={"vendor":"TP-Link","product}
2025-04-10 23:05:32.558 : [storage 177014] - DEBUG: storageSave: saved file /home/root/.brtn-ds/storage/devicedb/3f5a1fb8162c478c in 8ms
metadata updated: uri=/3f5a1fb8162c478c/m/matterDetails, value={"vendor":"TP-Link","product":"Mini Smart Wi-Fi Plug","hwVer":"1","swVer":"0x00000001","swStr":"1.0.0 Build 22}
2025-04-10 23:05:32.558 : [deviceCommunicationWatchdog 177014] - DEBUG: deviceCommunicationWatchdogMonitorDevice: start monitoring 3f5a1fb8162c478c with commFailTimeoutSecone
2025-04-10 23:05:32.558 : [Matter 177014] - INFO: MatterSubsystem (onDeviceCommissioningStatusChanged): Commissioning status = CommissionedSuccessfully
deviceService> 

deviceService> listDevices
3f5a1fb8162c478c: Class: light
        Endpoint 1: Profile: light, Label: Matter Light
2025-04-10 23:05

deviceService> readResource /3f5a1fb8162c478c/r/manufacturer
TP-Link
2025-04-10 23:12:22.037 : [openThreadClient 177014] - ERROR: CreateNetwork: Timed out waiting for create network response.
2025-04-10 23:12:22.037 : [threadSubsystem 177014] - ERROR: initializeThreadStack: Failed to create network, trying again in 60 seconds...
2025-04-10 23:12:25.038 : [openThreadClient 177014] - DEBUG: DBusMessageFilter: Active dataset tlvs changed
2025-04-10 23:12:25.038 : [deviceService 177014] - DEBUG: subsystemManager: subsystemManagerGetRegisteredSubsystems - 
2025-04-10 23:12:25.038 : [deviceService 177014] - DEBUG: subsystemManager: subsystemManagerGetSubsystemStatusJson - 
2025-04-10 23:12:25.038 : [threadSubsystem 177014] - DEBUG: getStatusJson: 
2025-04-10 23:12:25.038 : [deviceService 177014] - DEBUG: subsystemManager: subsystemManagerGetSubsystemStatusJson - 
2025-04-10 23:12:25.038 : [Matter 177014] - DEBUG: MatterSubsystem (getStatusJson): 
2025-04-10 23:12:30.072 : [MatterSDK 177014] - DEBUG: [DL] Thread role changed to: leader
deviceService> wr /3f5a1fb8162c478c/ep/1/r/isOn true
2025-04-10 23:13:08.348 : [MatterBaseDD 177014] - DEBUG: (writeResource): 
2025-04-10 23:13:08.348 : [MatterBaseDD 177014] - DEBUG: (ConnectAndExecute): 
2025-04-10 23:13:08.348 : [MatterSDK 177014] - DEBUG: [DIS] Found an existing secure session to [1:3F5A1FB8162C478C]!
2025-04-10 23:13:08.348 : [MatterLightDD 177014] - DEBUG: (WriteResource): isOn = true
2025-04-10 23:13:08.349 : [OnOffCluster 177014] - DEBUG: (SetOnOff): 
2025-04-10 23:13:08.349 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16115i S:212 M:141370297] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UDP:[fe80::32de:4b)
2025-04-10 23:13:08.349 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:16115i S:212 M:141370297] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 6861ms [State:Idle II:5000 AI:300]
2025-04-10 23:13:08.402 : [deviceCommunicationWatchdog 177014] - DEBUG: deviceCommunicationWatchdogPetDevice: petting 3f5a1fb8162c478c
2025-04-10 23:13:08.402 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:16115i S:212 M:183602795 (Ack:141370297)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
2025-04-10 23:13:08.402 : [MatterSDK 177014] - DEBUG: [DMG] Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0001 Status=0x0
2025-04-10 23:13:08.402 : [MatterCluster 177014] - DEBUG: (OnResponse): 
2025-04-10 23:13:08.402 : [MatterBaseDD 177014] - DEBUG: (ConnectAndExecute): Processed 1 async task(s) in 53 ms
2025-04-10 23:13:08.402 : [deviceService 177014] - DEBUG: updateResource: deviceUuid=3f5a1fb8162c478c, endpointId=1, resourceId=isOn, newValue=true
2025-04-10 23:13:08.402 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:16115i S:212 M:141370298 (Ack:183602795)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)

resourceUpdated: id=isOn, uri=/3f5a1fb8162c478c/ep/1/r/isOn, ownerId=3f5a1fb8162c478c, value=true, type=com.icontrol.boolean, mode=0x7b (rw-del-)
2025-04-10 23:13:08.469 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:65433r S:212 M:183602796] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 --- Type 0001:05 (I)
2025-04-10 23:13:08.469 : [MatterLightDD 177014] - DEBUG: (OnOffChanged): 
2025-04-10 23:13:08.469 : [deviceService 177014] - DEBUG: updateResource: deviceUuid=3f5a1fb8162c478c, endpointId=1, resourceId=isOn, newValue=true
2025-04-10 23:13:08.469 : [MatterSDK 177014] - DEBUG: [DMG] Refresh LivenessCheckTime for 1693265 milliseconds with SubscriptionId = 0x74308e6d Peer = 01:3F5A1FB8162C478C
2025-04-10 23:13:08.469 : [MatterSDK 177014] - DEBUG: [EM] <<< [E:65433r S:212 M:141370299 (Ack:183602796)] (S) Msg TX from 00D8730FD2953874 to 1:3F5A1FB8162C478C [3872] [UD)
2025-04-10 23:13:08.470 : [MatterSDK 177014] - DEBUG: [EM] ??1 [E:65433r S:212 M:141370299] (S) Msg Retransmission to 1:3F5A1FB8162C478C in 336ms [State:Active II:5000 AI:30]
2025-04-10 23:13:08.480 : [MatterSDK 177014] - DEBUG: [EM] >>> [E:65433r S:212 M:183602797 (Ack:141370299)] (S) Msg RX from 1:3F5A1FB8162C478C [3872] to 00D8730FD2953874 ---)
deviceService> 

deviceService> 

deviceService> rr /3f5a1fb8162c478c/ep/1/r/isOn
true
deviceService>

Demo video (April 10 2025)

barton-Matter-IoT-Demo.mp4

RDK Resources

[RDK Preferred]

Code Management Facility

RDK Forums

[RDK Conferences]

RDK Support

Archives

Scope

Key insights

Block diagram

RDK-B IoT Build

Prelimanary

Barton core

Verification of barton in RDK-B

CLI

Matter onboarding stages Barton

Vendor integration

Silabs radio integration

OSS component support

linenoise upstep

Verification with matter device

Demo video (April 10 2025)

RDK Resources

[*RDK Preferred*]

Code Management Facility

RDK Forums

[RDK Conferences]

RDK Support

Archives

Barton on RDK-B

Scope

Key insights

Block diagram

RDK-B IoT Build

Prelimanary

Barton core

Verification of barton in RDK-B

CLI

Matter onboarding stages Barton

Vendor integration

Silabs radio integration

OSS component support

linenoise upstep

Verification with matter device

Demo video (April 10 2025)

[RDK Preferred]