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 |