ubuntu@ubuntu:~$ sudo docker exec -it th-sdk bash root@ubuntu:~# ./chip-tool colorcontrol read current-hue 0xc717f6d3a01495c0 1 [1708942927.728564][24:24] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1708942927.729887][24:24] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1708942927.729950][24:24] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1708942927.735264][24:24] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1708942927.735630][24:24] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1708942927.735792][24:24] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1708942927.736280][24:24] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-F932JS) [1708942927.736970][24:24] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708942927.737044][24:24] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2) [1708942927.737915][24:24] CHIP:DL: Got Ethernet interface: eth0 [1708942927.738620][24:24] CHIP:DL: Found the primary Ethernet interface:eth0 [1708942927.739278][24:24] CHIP:DL: Got WiFi interface: wlan0 [1708942927.739348][24:24] CHIP:DL: Failed to reset WiFi statistic counts [1708942927.739402][24:24] CHIP:IN: UDP::Init bind&listen port=0 [1708942927.739510][24:24] CHIP:IN: UDP::Init bound to port=58332 [1708942927.739532][24:24] CHIP:IN: BLEBase::Init - setting/overriding transport [1708942927.739549][24:24] CHIP:IN: TransportMgr initialized [1708942927.739599][24:24] CHIP:FP: Initializing FabricTable from persistent storage [1708942927.739749][24:24] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708942927.741273][24:24] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x6645D01DA61A7C10, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1 [1708942927.744324][24:24] CHIP:ZCL: Using ZAP configuration... [1708942927.748001][24:24] CHIP:DL: Avahi client registered [1708942927.748122][24:24] CHIP:CTL: System State Initialized... [1708942927.748355][24:24] CHIP:CTL: Setting attestation nonce to random value [1708942927.748408][24:24] CHIP:CTL: Setting CSR nonce to random value [1708942927.748484][24:24] CHIP:IN: UDP::Init bind&listen port=5550 [1708942927.748608][24:24] CHIP:IN: UDP::Init bound to port=5550 [1708942927.748632][24:24] CHIP:IN: TransportMgr initialized [1708942927.749068][24:26] CHIP:DL: CHIP task running [1708942927.749271][24:26] CHIP:DL: HandlePlatformSpecificBLEEvent 32786 [1708942927.749852][24:26] CHIP:CTL: Setting attestation nonce to random value [1708942927.750024][24:26] CHIP:CTL: Setting CSR nonce to random value [1708942927.751139][24:26] CHIP:CTL: Generating NOC [1708942927.752076][24:26] CHIP:FP: Validating NOC chain [1708942927.753785][24:26] CHIP:FP: NOC chain validation successful [1708942927.753949][24:26] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669 [1708942927.753983][24:26] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48 [1708942927.754004][24:26] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00 [1708942927.754023][24:26] CHIP:TS: Retaining current Last Known Good Time [1708942927.763718][24:26] CHIP:FP: Metadata for Fabric 0x1 persisted to storage. [1708942927.765766][24:26] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1708942927.767781][24:26] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 6645D01DA61A7C10) [1708942927.767837][24:26] CHIP:IN: UDP::Init bind&listen port=5550 [1708942927.767950][24:26] CHIP:IN: UDP::Init bound to port=5550 [1708942927.767970][24:26] CHIP:IN: TransportMgr initialized [1708942927.783071][24:26] CHIP:TOO: Sending command to node 0xc717f6d3a01495c0 [1708942927.783907][24:26] CHIP:CSM: FindOrEstablishSession: PeerId = [1:C717F6D3A01495C0] [1708942927.783942][24:26] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found [1708942927.783972][24:26] CHIP:DIS: OperationalSessionSetup[1:C717F6D3A01495C0]: State change 1 --> 2 [1708942927.784001][24:26] CHIP:DIS: Resolving 6645D01DA61A7C10:C717F6D3A01495C0 ... [1708942927.786036][24:26] CHIP:DL: Avahi resolve found [1708942927.786104][24:26] CHIP:DIS: Node ID resolved for 6645D01DA61A7C10:C717F6D3A01495C0 [1708942927.786124][24:26] CHIP:DIS: Hostname: E45F010F1A010000 [1708942927.786149][24:26] CHIP:DIS: IP Address #1: fe80::e65f:1ff:fe0f:1a01 [1708942927.786168][24:26] CHIP:DIS: Port: 5540 [1708942927.786186][24:26] CHIP:DIS: Mrp Interval idle: not present [1708942927.786204][24:26] CHIP:DIS: Mrp Interval active: not present [1708942927.786222][24:26] CHIP:DIS: Mrp Active Threshold: not present [1708942927.786240][24:26] CHIP:DIS: TCP Supported: 0 [1708942927.786257][24:26] CHIP:DIS: ICD: not present [1708942927.786384][24:26] CHIP:DIS: UDP:[fe80::e65f:1ff:fe0f:1a01%eth0]:5540: new best score: 7 [1708942927.786405][24:26] CHIP:DIS: Checking node lookup status after 3 ms [1708942927.786422][24:26] CHIP:DIS: Keeping DNSSD lookup active [1708942927.983702][24:26] CHIP:DIS: Checking node lookup status after 200 ms [1708942927.983869][24:26] CHIP:DIS: OperationalSessionSetup[1:C717F6D3A01495C0]: Updating device address to UDP:[fe80::e65f:1ff:fe0f:1a01%eth0]:5540 while in state 2 [1708942927.983892][24:26] CHIP:DIS: OperationalSessionSetup[1:C717F6D3A01495C0]: State change 2 --> 3 [1708942927.984048][24:26] CHIP:IN: SecureSession[0xffff9400eef0]: Allocated Type:2 LSID:46677 [1708942927.984090][24:26] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0xC717F6D3A01495C0 [1708942927.985130][24:26] CHIP:EM: <<< [E:43771i S:0 M:209653949] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0f:1a01%eth0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1) [1708942927.985340][24:26] CHIP:SC: Sent Sigma1 msg [1708942927.985368][24:26] CHIP:DIS: OperationalSessionSetup[1:C717F6D3A01495C0]: State change 3 --> 4 [1708942928.008053][24:26] CHIP:EM: >>> [E:43771i S:0 M:202460937 (Ack:209653949)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) [1708942928.008099][24:26] CHIP:EM: Found matching exchange: 43771i, Delegate: 0xffff9400ec48 [1708942928.008135][24:26] CHIP:EM: Rxd Ack; Removing MessageCounter:209653949 from Retrans Table on exchange 43771i [1708942928.008262][24:26] CHIP:SC: Received Sigma2 msg [1708942928.008302][24:26] CHIP:SC: Peer assigned session session ID 27277 [1708942928.012067][24:26] CHIP:SC: Found MRP parameters in the message [1708942928.012142][24:26] CHIP:SC: Sending Sigma3 [1708942928.012907][24:26] CHIP:EM: <<< [E:43771i S:0 M:209653950 (Ack:202460937)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0f:1a01%eth0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3) [1708942928.013094][24:26] CHIP:SC: Sent Sigma3 msg [1708942928.028289][24:26] CHIP:EM: >>> [E:43771i S:0 M:202460938 (Ack:209653950)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) [1708942928.028327][24:26] CHIP:EM: Found matching exchange: 43771i, Delegate: 0xffff9400ec48 [1708942928.028362][24:26] CHIP:EM: Rxd Ack; Removing MessageCounter:209653950 from Retrans Table on exchange 43771i [1708942928.028410][24:26] CHIP:SC: Success status report received. Session was established [1708942928.033084][24:26] CHIP:SC: SecureSession[0xffff9400eef0, LSID:46677]: State change 'kEstablishing' --> 'kActive' [1708942928.033135][24:26] CHIP:IN: SecureSession[0xffff9400eef0]: Activated - Type:2 LSID:46677 [1708942928.033153][24:26] CHIP:IN: New secure session activated for device , LSID:46677 PSID:27277! [1708942928.033179][24:26] CHIP:DIS: OperationalSessionSetup[1:C717F6D3A01495C0]: State change 4 --> 5 [1708942928.033257][24:26] CHIP:TOO: Sending ReadAttribute to: [1708942928.033324][24:26] CHIP:TOO: cluster 0x0000_0300, attribute: 0x0000_0000, endpoint 1 [1708942928.033365][24:26] CHIP:DMG: SendReadRequest ReadClient[0xffff9400a4c0]: Sending Read Request [1708942928.033667][24:26] CHIP:EM: <<< [E:43772i S:46677 M:262291853] (S) Msg TX to 1:C717F6D3A01495C0 [7C10] [UDP:[fe80::e65f:1ff:fe0f:1a01%eth0]:5540] --- Type 0001:02 (IM:ReadRequest) [1708942928.033865][24:26] CHIP:DMG: MoveToState ReadClient[0xffff9400a4c0]: Moving to [AwaitingIn] [1708942928.034025][24:26] CHIP:EM: <<< [E:43771i S:0 M:209653951 (Ack:202460938)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::e65f:1ff:fe0f:1a01%eth0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) [1708942928.034114][24:26] CHIP:EM: Flushed pending ack for MessageCounter:202460938 on exchange 43771i [1708942928.041532][24:26] CHIP:EM: >>> [E:43772i S:46677 M:51821939 (Ack:262291853)] (S) Msg RX from 1:C717F6D3A01495C0 [7C10] --- Type 0001:05 (IM:ReportData) [1708942928.041575][24:26] CHIP:EM: Found matching exchange: 43772i, Delegate: 0xffff9400a4d0 [1708942928.041610][24:26] CHIP:EM: Rxd Ack; Removing MessageCounter:262291853 from Retrans Table on exchange 43772i [1708942928.041671][24:26] CHIP:DMG: ReportDataMessage = [1708942928.041695][24:26] CHIP:DMG: { [1708942928.041716][24:26] CHIP:DMG: AttributeReportIBs = [1708942928.041744][24:26] CHIP:DMG: [ [1708942928.041766][24:26] CHIP:DMG: AttributeReportIB = [1708942928.041796][24:26] CHIP:DMG: { [1708942928.041818][24:26] CHIP:DMG: AttributeDataIB = [1708942928.041850][24:26] CHIP:DMG: { [1708942928.041887][24:26] CHIP:DMG: DataVersion = 0xed61b8, [1708942928.041919][24:26] CHIP:DMG: AttributePathIB = [1708942928.041953][24:26] CHIP:DMG: { [1708942928.041987][24:26] CHIP:DMG: Endpoint = 0x1, [1708942928.042016][24:26] CHIP:DMG: Cluster = 0x300, [1708942928.042044][24:26] CHIP:DMG: Attribute = 0x0000_0000, [1708942928.042068][24:26] CHIP:DMG: } [1708942928.042096][24:26] CHIP:DMG: [1708942928.042125][24:26] CHIP:DMG: Data = 47, [1708942928.042150][24:26] CHIP:DMG: }, [1708942928.042178][24:26] CHIP:DMG: [1708942928.042198][24:26] CHIP:DMG: }, [1708942928.042224][24:26] CHIP:DMG: [1708942928.042246][24:26] CHIP:DMG: ], [1708942928.042273][24:26] CHIP:DMG: [1708942928.042295][24:26] CHIP:DMG: SuppressResponse = true, [1708942928.042317][24:26] CHIP:DMG: InteractionModelRevision = 11 [1708942928.042338][24:26] CHIP:DMG: } [1708942928.042468][24:26] CHIP:TOO: Endpoint: 1 Cluster: 0x0000_0300 Attribute 0x0000_0000 DataVersion: 15557048 [1708942928.042531][24:26] CHIP:TOO: CurrentHue: 47 [1708942928.042806][24:26] CHIP:EM: <<< [E:43772i S:46677 M:262291854 (Ack:51821939)] (S) Msg TX to 1:C717F6D3A01495C0 [7C10] [UDP:[fe80::e65f:1ff:fe0f:1a01%eth0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) [1708942928.042940][24:26] CHIP:EM: Flushed pending ack for MessageCounter:51821939 on exchange 43772i [1708942928.043130][24:24] CHIP:CTL: Shutting down the commissioner [1708942928.043213][24:24] CHIP:CTL: Shutting down the controller [1708942928.043260][24:24] CHIP:IN: Expiring all sessions for fabric 0x1!! [1708942928.043303][24:24] CHIP:IN: SecureSession[0xffff9400eef0]: MarkForEviction Type:2 LSID:46677 [1708942928.043324][24:24] CHIP:SC: SecureSession[0xffff9400eef0, LSID:46677]: State change 'kActive' --> 'kPendingEviction' [1708942928.043343][24:24] CHIP:IN: SecureSession[0xffff9400eef0]: Released - Type:2 LSID:46677 [1708942928.043428][24:24] CHIP:FP: Forgetting fabric 0x1 [1708942928.043496][24:24] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708942928.043670][24:24] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708942928.043692][24:24] CHIP:TS: Reverted Last Known Good Time to previous value [1708942928.043733][24:24] CHIP:CTL: Shutting down the commissioner [1708942928.043839][24:24] CHIP:CTL: Shutting down the controller [1708942928.043938][24:24] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack [1708942928.044126][24:24] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet [1708942928.044330][24:24] CHIP:FP: Shutting down FabricTable [1708942928.044384][24:24] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48 [1708942928.044502][24:24] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48 [1708942928.044522][24:24] CHIP:TS: Reverted Last Known Good Time to previous value [1708942928.044885][24:24] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-73oJ3U) [1708942928.045874][24:24] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini) [1708942928.045957][24:24] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0) [1708942928.045979][24:24] CHIP:DL: Inet Layer shutdown [1708942928.045996][24:24] CHIP:DL: BLE shutdown [1708942928.046018][24:24] CHIP:DL: System Layer shutdown root@ubuntu:~#