grl@grl-Inspiron-15-5518:~/Feb16_Dut/connectedhomeip/out/chip-tool$ ./chip-tool interactive start [1722921797.794] [10536:10536] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs [1722921797.794] [10536:10536] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs [1722921797.794] [10536:10536] [DL] ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs [1722921797.794] [10536:10536] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini [1722921797.794] [10536:10536] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini [1722921797.794] [10536:10536] [DL] ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini [1722921797.795] [10536:10536] [DL] writing settings to file (/tmp/chip_counters.ini-U7BLMR) [1722921797.795] [10536:10536] [DL] renamed tmp file to file (/tmp/chip_counters.ini) [1722921797.795] [10536:10536] [DL] NVS set: chip-counters/reboot-count = 3 (0x3) [1722921797.795] [10536:10536] [DL] Got Ethernet interface: enxd03745ce8f62 [1722921797.795] [10536:10536] [DL] Found the primary Ethernet interface:enxd03745ce8f62 [1722921797.795] [10536:10536] [DL] Got WiFi interface: wlp0s20f3 [1722921797.796] [10536:10536] [DL] Found the primary WiFi interface:wlp0s20f3 [1722921797.796] [10536:10536] [IN] UDP::Init bind&listen port=0 [1722921797.796] [10536:10536] [IN] UDP::Init bound to port=49262 [1722921797.796] [10536:10536] [IN] BLEBase::Init - setting/overriding transport [1722921797.796] [10536:10536] [IN] TransportMgr initialized [1722921797.796] [10536:10536] [FP] Initializing FabricTable from persistent storage [1722921797.796] [10536:10536] [TS] Last Known Good Time: 2023-10-14T01:16:48 [1722921797.796] [10536:10536] [FP] Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xDB04E40838302D16, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1 [1722921797.797] [10536:10536] [ZCL] Using ZAP configuration... [1722921797.798] [10536:10536] [DL] Avahi client registered [1722921797.798] [10536:10536] [IN] CASE Server enabling CASE session setups [1722921797.798] [10536:10536] [IN] SecureSession[0x55dc2cf7a2d0]: Allocated Type:2 LSID:526 [1722921797.798] [10536:10536] [SC] Allocated SecureSession (0x55dc2cf7a2d0) - waiting for Sigma1 msg [1722921797.798] [10536:10536] [IM] WARNING ┌──────────────────────────────────────────────────── [1722921797.798] [10536:10536] [IM] WARNING │ Interaction Model Engine running in 'Checked' mode. [1722921797.798] [10536:10536] [IM] WARNING │ This executes BOTH ember and data-model code paths. [1722921797.798] [10536:10536] [IM] WARNING │ which is inefficient and consumes more flash space. [1722921797.798] [10536:10536] [IM] WARNING │ This should be done for testing only. [1722921797.798] [10536:10536] [IM] WARNING └──────────────────────────────────────────────────── [1722921797.798] [10536:10536] [CTL] System State Initialized... [1722921797.798] [10536:10536] [CTL] Setting attestation nonce to random value [1722921797.798] [10536:10536] [CTL] Setting CSR nonce to random value [1722921797.798] [10536:10536] [IN] UDP::Init bind&listen port=5550 [1722921797.798] [10536:10536] [IN] UDP::Init bound to port=5550 [1722921797.798] [10536:10536] [IN] TransportMgr initialized [1722921797.798] [10536:10538] [DL] CHIP task running [1722921797.798] [10536:10538] [DL] HandlePlatformSpecificBLEEvent 32786 >>> icdmanagement register-client 112233 1 hex:abcdef1234567890abcdef1234567890 0 1 0 [1722921805.670] [10536:10536] [TOO] Command: >>> icdmanagement register-client 112233 1 hex:abcdef1234567890abcdef1234567890 0 1 0 [1722921805.670] [10536:10536] [TOO] Unknown cluster or command set: >>> Usage: cluster_name command_name [param1 param2 ...] or: command_set_name command_name [param1 param2 ...] +-------------------------------------------------------------------------------------+ | Clusters: | +-------------------------------------------------------------------------------------+ | * accesscontrol | | * accountlogin | | * actions | | * activatedcarbonfiltermonitoring | | * administratorcommissioning | | * airquality | | * applicationbasic | | * applicationlauncher | | * audiooutput | | * ballastconfiguration | | * barriercontrol | | * basicinformation | | * binaryinputbasic | | * binding | | * booleanstate | | * booleanstateconfiguration | | * bridgeddevicebasicinformation | | * carbondioxideconcentrationmeasurement | | * carbonmonoxideconcentrationmeasurement | | * channel | | * colorcontrol | | * commissionercontrol | | * contentappobserver | | * contentcontrol | | * contentlauncher | | * demandresponseloadcontrol | | * descriptor | | * deviceenergymanagement | | * deviceenergymanagementmode | | * diagnosticlogs | | * dishwasheralarm | | * dishwashermode | | * doorlock | | * ecosysteminformation | | * electricalenergymeasurement | | * electricalmeasurement | | * electricalpowermeasurement | | * energyevse | | * energyevsemode | | * energypreference | | * ethernetnetworkdiagnostics | | * fancontrol | | * faultinjection | | * fixedlabel | | * flowmeasurement | | * formaldehydeconcentrationmeasurement | | * generalcommissioning | | * generaldiagnostics | | * groupkeymanagement | | * groups | | * hepafiltermonitoring | | * icdmanagement | | * identify | | * illuminancemeasurement | | * keypadinput | | * laundrydryercontrols | | * laundrywashercontrols | | * laundrywashermode | | * levelcontrol | | * localizationconfiguration | | * lowpower | | * mediainput | | * mediaplayback | | * messages | | * microwaveovencontrol | | * microwaveovenmode | | * modeselect | | * networkcommissioning | | * nitrogendioxideconcentrationmeasurement | | * occupancysensing | | * onoff | | * onoffswitchconfiguration | | * operationalcredentials | | * operationalstate | | * otasoftwareupdateprovider | | * otasoftwareupdaterequestor | | * ovencavityoperationalstate | | * ovenmode | | * ozoneconcentrationmeasurement | | * pm10concentrationmeasurement | | * pm1concentrationmeasurement | | * pm25concentrationmeasurement | | * powersource | | * powersourceconfiguration | | * powertopology | | * pressuremeasurement | | * proxyconfiguration | | * proxydiscovery | | * proxyvalid | | * pulsewidthmodulation | | * pumpconfigurationandcontrol | | * radonconcentrationmeasurement | | * refrigeratoralarm | | * refrigeratorandtemperaturecontrolledcabinetmode | | * relativehumiditymeasurement | | * rvccleanmode | | * rvcoperationalstate | | * rvcrunmode | | * samplemei | | * scenesmanagement | | * servicearea | | * smokecoalarm | | * softwarediagnostics | | * switch | | * targetnavigator | | * temperaturecontrol | | * temperaturemeasurement | | * thermostat | | * thermostatuserinterfaceconfiguration | | * threadborderroutermanagement | | * threadnetworkdiagnostics | | * threadnetworkdirectory | | * timeformatlocalization | | * timesynchronization | | * timer | | * totalvolatileorganiccompoundsconcentrationmeasurement | | * unitlocalization | | * unittesting | | * userlabel | | * valveconfigurationandcontrol | | * wakeonlan | | * waterheatermanagement | | * waterheatermode | | * wifinetworkdiagnostics | | * wifinetworkmanagement | | * windowcovering | +-------------------------------------------------------------------------------------+ +-------------------------------------------------------------------------------------+ | Command sets: | +-------------------------------------------------------------------------------------+ | * any | | - Commands for sending IM messages based on cluster id, not cluster name. | | * delay | | - Commands for waiting for something to happen. | | * discover | | - Commands for device discovery. | | * groupsettings | | - Commands for manipulating group keys and memberships for chip-tool itself. | | * icd | | - Commands for client-side ICD management. | | * pairing | | - Commands for commissioning devices. | | * payload | | - Commands for parsing and generating setup payloads. | | * sessionmanagement | | - Commands for managing CASE and PASE session state. | | * subscriptions | | - Commands for shutting down subscriptions. | | * interactive | | - Commands for starting long-lived interactive modes. | | * storage | | - Commands for managing persistent data stored by chip-tool. | +-------------------------------------------------------------------------------------+ >>> icdmanagement register-client 112233 1 hex:abcdef1234567890abcdef1234567890 0 1 0 [1722921906.687] [10536:10536] [TOO] Command: icdmanagement register-client 112233 1 hex:abcdef1234567890abcdef1234567890 0 1 0 [1722921906.688] [10536:10538] [CTL] Setting attestation nonce to random value [1722921906.688] [10536:10538] [CTL] Setting CSR nonce to random value [1722921906.690] [10536:10538] [CTL] Generating NOC [1722921906.690] [10536:10538] [FP] Validating NOC chain [1722921906.691] [10536:10538] [FP] NOC chain validation successful [1722921906.691] [10536:10538] [FP] Updated fabric at index: 0x1, Node ID: 0x000000000001B669 [1722921906.691] [10536:10538] [TS] Last Known Good Time: 2023-10-14T01:16:48 [1722921906.691] [10536:10538] [TS] New proposed Last Known Good Time: 2021-01-01T00:00:00 [1722921906.691] [10536:10538] [TS] Retaining current Last Known Good Time [1722921906.739] [10536:10538] [FP] Metadata for Fabric 0x1 persisted to storage. [1722921906.759] [10536:10538] [TS] Committing Last Known Good Time to storage: 2023-10-14T01:16:48 [1722921906.780] [10536:10538] [CTL] Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: DB04E40838302D16) [1722921906.780] [10536:10538] [IN] UDP::Init bind&listen port=5550 [1722921906.780] [10536:10538] [IN] UDP::Init bound to port=5550 [1722921906.780] [10536:10538] [IN] TransportMgr initialized [1722921906.780] [10536:10538] [DIS] Updating services using commissioning mode 0 [1722921906.780] [10536:10538] [DL] Using WiFi MAC for hostname [1722921906.780] [10536:10538] [DIS] Advertise operational node DB04E40838302D16-000000000001B669 [1722921906.780] [10536:10538] [DL] PublishService DB04E40838302D16-000000000001B669._matter._tcp49262.-1 [1722921906.782] [10536:10538] [DL] Using addresses from interface id=0 name= [1722921906.786] [10536:10538] [DIS] mDNS service published: _matter._tcp; instance name: DB04E40838302D16-000000000001B669 [1722921906.786] [10536:10538] [DL] Using WiFi MAC for hostname [1722921906.786] [10536:10538] [DIS] Advertise commission parameter vendorID=65521 productID=32769 discriminator=0000/00 cm=0 cp=0 [1722921906.791] [10536:10538] [DL] PublishService 4650778B0DC81CCB._matterd._udp5550.-1 [1722921906.792] [10536:10538] [DL] Using addresses from interface id=0 name= [1722921906.794] [10536:10538] [DIS] mDNS service published: _matterd._udp; instance name: 4650778B0DC81CCB [1722921906.955] [10536:10538] [TOO] Sending command to node 0x1 [1722921906.956] [10536:10538] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001] [1722921906.956] [10536:10538] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found [1722921906.956] [10536:10538] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2 [1722921906.956] [10536:10538] [DIS] Resolving DB04E40838302D16:0000000000000001 ... [1722921906.956] [10536:10538] [DIS] Lookup started for DB04E40838302D16-0000000000000001 [1722921906.956] [10536:10538] [DL] Long dispatch time: 269 ms, for event type 2 [1722921907.058] [10536:10538] [DL] Avahi resolve found [1722921907.058] [10536:10538] [DIS] Node ID resolved for DB04E40838302D16-0000000000000001 [1722921907.058] [10536:10538] [DIS] Hostname: 8C1D96786A130000 [1722921907.058] [10536:10538] [DIS] IP Address #1: fe80::a70c:61dc:df51:6945 [1722921907.058] [10536:10538] [DIS] Port: 5540 [1722921907.058] [10536:10538] [DIS] Mrp Interval idle: 5500 ms [1722921907.058] [10536:10538] [DIS] Mrp Interval active: 500 ms [1722921907.058] [10536:10538] [DIS] Mrp Active Threshold: 5000 ms [1722921907.058] [10536:10538] [DIS] TCP Client Supported: 1 [1722921907.058] [10536:10538] [DIS] TCP Server Supported: 1 [1722921907.058] [10536:10538] [DIS] The ICD operates in SIT [1722921907.058] [10536:10538] [DIS] UDP:[fe80::a70c:61dc:df51:6945%enxd03745ce8f62]:5540: new best score: 7 (for DB04E40838302D16-0000000000000001) [1722921907.058] [10536:10538] [DIS] Checking node lookup status for DB04E40838302D16-0000000000000001 after 103 ms [1722921907.058] [10536:10538] [DIS] Keeping DNSSD lookup active [1722921907.156] [10536:10538] [DIS] Checking node lookup status for DB04E40838302D16-0000000000000001 after 201 ms [1722921907.156] [10536:10538] [DIS] OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fe80::a70c:61dc:df51:6945%enxd03745ce8f62]:5540 while in state 2 [1722921907.156] [10536:10538] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3 [1722921907.156] [10536:10538] [IN] SecureSession[0x7f5670024fc0]: Allocated Type:2 LSID:527 [1722921907.156] [10536:10538] [SC] Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001 [1722921907.157] [10536:10538] [EM] <<< [E:4361i S:0 M:193887324] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::a70c:61dc:df51:6945%enxd03745ce8f62]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196) [1722921907.157] [10536:10538] [SC] Sent Sigma1 msg to <0000000000000001, 1> [1722921907.157] [10536:10538] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4 [1722921907.158] [10536:10538] [EM] >>> [E:4361i S:0 M:74142873 (Ack:193887324)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:751) [1722921907.158] [10536:10538] [EM] Found matching exchange: 4361i, Delegate: 0x7f5670024cd8 [1722921907.158] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:193887324 from Retrans Table on exchange 4361i [1722921907.158] [10536:10538] [SC] Received Sigma2 msg [1722921907.158] [10536:10538] [SC] Peer assigned session session ID 28627 [1722921907.160] [10536:10538] [SC] Found MRP parameters in the message [1722921907.160] [10536:10538] [SC] Sending Sigma3 [1722921907.161] [10536:10538] [EM] <<< [E:4361i S:0 M:193887325 (Ack:74142873)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::a70c:61dc:df51:6945%enxd03745ce8f62]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598) [1722921907.161] [10536:10538] [SC] Sent Sigma3 msg [1722921907.188] [10536:10538] [EM] >>> [E:4361i S:0 M:74142874 (Ack:193887325)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) (B:34) [1722921907.188] [10536:10538] [EM] Found matching exchange: 4361i, Delegate: 0x7f5670024cd8 [1722921907.188] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:193887325 from Retrans Table on exchange 4361i [1722921907.188] [10536:10538] [SC] Success status report received. Session was established [1722921907.252] [10536:10538] [SC] SecureSession[0x7f5670024fc0, LSID:527]: State change 'kEstablishing' --> 'kActive' [1722921907.252] [10536:10538] [IN] SecureSession[0x7f5670024fc0]: Activated - Type:2 LSID:527 [1722921907.252] [10536:10538] [IN] New secure session activated for device <0000000000000001, 1>, LSID:527 PSID:28627! [1722921907.252] [10536:10538] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5 [1722921907.252] [10536:10538] [TOO] Sending cluster (0x00000046) command (0x00000000) on endpoint 0 [1722921907.252] [10536:10538] [DMG] ICR moving to [AddingComm] [1722921907.252] [10536:10538] [DMG] ICR moving to [AddedComma] [1722921907.252] [10536:10538] [EM] <<< [E:4362i S:527 M:139124906] (S) Msg TX to 1:0000000000000001 [2D16] [UDP:[fe80::a70c:61dc:df51:6945%enxd03745ce8f62]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:90) [1722921907.252] [10536:10538] [DMG] ICR moving to [AwaitingRe] [1722921907.252] [10536:10538] [EM] <<< [E:4361i S:0 M:193887326 (Ack:74142874)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::a70c:61dc:df51:6945%enxd03745ce8f62]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26) [1722921907.252] [10536:10538] [EM] Flushed pending ack for MessageCounter:74142874 on exchange 4361i [1722921907.252] [10536:10538] [DL] HandlePlatformSpecificBLEEvent 32792 [1722921907.256] [10536:10538] [EM] >>> [E:4362i S:527 M:47968231 (Ack:139124906)] (S) Msg RX from 1:0000000000000001 [2D16] --- Type 0001:09 (IM:InvokeCommandResponse) (B:70) [1722921907.256] [10536:10538] [EM] Found matching exchange: 4362i, Delegate: 0x7f56700209f8 [1722921907.256] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:139124906 from Retrans Table on exchange 4362i [1722921907.256] [10536:10538] [DMG] ICR moving to [ResponseRe] [1722921907.256] [10536:10538] [DMG] InvokeResponseMessage = [1722921907.257] [10536:10538] [DMG] { [1722921907.257] [10536:10538] [DMG] suppressResponse = false, [1722921907.257] [10536:10538] [DMG] InvokeResponseIBs = [1722921907.257] [10536:10538] [DMG] [ [1722921907.257] [10536:10538] [DMG] InvokeResponseIB = [1722921907.257] [10536:10538] [DMG] { [1722921907.257] [10536:10538] [DMG] CommandDataIB = [1722921907.257] [10536:10538] [DMG] { [1722921907.257] [10536:10538] [DMG] CommandPathIB = [1722921907.257] [10536:10538] [DMG] { [1722921907.257] [10536:10538] [DMG] EndpointId = 0x0, [1722921907.257] [10536:10538] [DMG] ClusterId = 0x46, [1722921907.257] [10536:10538] [DMG] CommandId = 0x1, [1722921907.257] [10536:10538] [DMG] }, [1722921907.257] [10536:10538] [DMG] [1722921907.257] [10536:10538] [DMG] CommandFields = [1722921907.257] [10536:10538] [DMG] { [1722921907.257] [10536:10538] [DMG] 0x0 = 1676866595 (unsigned), [1722921907.257] [10536:10538] [DMG] }, [1722921907.257] [10536:10538] [DMG] }, [1722921907.257] [10536:10538] [DMG] [1722921907.257] [10536:10538] [DMG] }, [1722921907.257] [10536:10538] [DMG] [1722921907.257] [10536:10538] [DMG] ], [1722921907.257] [10536:10538] [DMG] [1722921907.257] [10536:10538] [DMG] InteractionModelRevision = 11 [1722921907.257] [10536:10538] [DMG] }, [1722921907.257] [10536:10538] [DMG] Received Command Response Data, Endpoint=0 Cluster=0x0000_0046 Command=0x0000_0001 [1722921907.257] [10536:10538] [TOO] Endpoint: 0 Cluster: 0x0000_0046 Command 0x0000_0001 [1722921907.263] [10536:10538] [TOO] RegisterClientResponse: { [1722921907.263] [10536:10538] [TOO] ICDCounter: 1676866595 [1722921907.263] [10536:10538] [TOO] } [1722921907.317] [10536:10538] [DMG] ICR moving to [AwaitingDe] [1722921907.317] [10536:10538] [EM] <<< [E:4362i S:527 M:139124907 (Ack:47968231)] (S) Msg TX to 1:0000000000000001 [2D16] [UDP:[fe80::a70c:61dc:df51:6945%enxd03745ce8f62]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34) [1722921907.317] [10536:10538] [EM] Flushed pending ack for MessageCounter:47968231 on exchange 4362i [1722921907.587] [10536:10538] [DL] Avahi group established [1722921907.595] [10536:10538] [DL] Avahi group established generaldiagnostics test-event-trigger hex:00112233445566778899AABBCCDDEEFF 0x0046000000000003 1 0 [1722921915.029] [10536:10536] [TOO] Command: generaldiagnostics test-event-trigger hex:00112233445566778899AABBCCDDEEFF 0x0046000000000003 1 0 [1722921915.030] [10536:10538] [TOO] Sending command to node 0x1 [1722921915.030] [10536:10538] [CSM] FindOrEstablishSession: PeerId = [1:0000000000000001] [1722921915.030] [10536:10538] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found [1722921915.030] [10536:10538] [DIS] Found an existing secure session to [1:0000000000000001]! [1722921915.030] [10536:10538] [DIS] OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5 [1722921915.030] [10536:10538] [TOO] Sending cluster (0x00000033) command (0x00000000) on endpoint 0 [1722921915.030] [10536:10538] [DMG] ICR moving to [AddingComm] [1722921915.030] [10536:10538] [DMG] ICR moving to [AddedComma] [1722921915.030] [10536:10538] [EM] <<< [E:4363i S:527 M:139124908] (S) Msg TX to 1:0000000000000001 [2D16] [UDP:[fe80::a70c:61dc:df51:6945%enxd03745ce8f62]:5540] --- Type 0001:08 (IM:InvokeCommandRequest) (B:88) [1722921915.031] [10536:10538] [DMG] ICR moving to [AwaitingRe] [1722921915.033] [10536:10538] [EM] >>> [E:4363i S:527 M:47968232 (Ack:139124908)] (S) Msg RX from 1:0000000000000001 [2D16] --- Type 0001:09 (IM:InvokeCommandResponse) (B:67) [1722921915.033] [10536:10538] [EM] Found matching exchange: 4363i, Delegate: 0x7f56700209f8 [1722921915.033] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:139124908 from Retrans Table on exchange 4363i [1722921915.033] [10536:10538] [DMG] ICR moving to [ResponseRe] [1722921915.033] [10536:10538] [DMG] InvokeResponseMessage = [1722921915.033] [10536:10538] [DMG] { [1722921915.033] [10536:10538] [DMG] suppressResponse = false, [1722921915.033] [10536:10538] [DMG] InvokeResponseIBs = [1722921915.033] [10536:10538] [DMG] [ [1722921915.033] [10536:10538] [DMG] InvokeResponseIB = [1722921915.033] [10536:10538] [DMG] { [1722921915.033] [10536:10538] [DMG] CommandStatusIB = [1722921915.033] [10536:10538] [DMG] { [1722921915.033] [10536:10538] [DMG] CommandPathIB = [1722921915.033] [10536:10538] [DMG] { [1722921915.033] [10536:10538] [DMG] EndpointId = 0x0, [1722921915.033] [10536:10538] [DMG] ClusterId = 0x33, [1722921915.033] [10536:10538] [DMG] CommandId = 0x0, [1722921915.033] [10536:10538] [DMG] }, [1722921915.033] [10536:10538] [DMG] [1722921915.033] [10536:10538] [DMG] StatusIB = [1722921915.033] [10536:10538] [DMG] { [1722921915.033] [10536:10538] [DMG] status = 0x00 (SUCCESS), [1722921915.033] [10536:10538] [DMG] }, [1722921915.033] [10536:10538] [DMG] [1722921915.033] [10536:10538] [DMG] }, [1722921915.033] [10536:10538] [DMG] [1722921915.033] [10536:10538] [DMG] }, [1722921915.033] [10536:10538] [DMG] [1722921915.033] [10536:10538] [DMG] ], [1722921915.033] [10536:10538] [DMG] [1722921915.033] [10536:10538] [DMG] InteractionModelRevision = 11 [1722921915.033] [10536:10538] [DMG] }, [1722921915.033] [10536:10538] [DMG] Received Command Response Status for Endpoint=0 Cluster=0x0000_0033 Command=0x0000_0000 Status=0x0 [1722921915.033] [10536:10538] [DMG] ICR moving to [AwaitingDe] [1722921915.033] [10536:10538] [EM] <<< [E:4363i S:527 M:139124909 (Ack:47968232)] (S) Msg TX to 1:0000000000000001 [2D16] [UDP:[fe80::a70c:61dc:df51:6945%enxd03745ce8f62]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34) [1722921915.033] [10536:10538] [EM] Flushed pending ack for MessageCounter:47968232 on exchange 4363i [1722921915.232] [10536:10538] [EM] >>> [E:21695r S:0 M:74142875] (U) Msg RX from 0:63185DF2050D6ADB [0000] --- Type 0000:50 (SecureChannel:ICD_CheckInMessage) (B:57) [1722921915.232] [10536:10538] [EM] Handling via exchange: 21695r, Delegate: 0x55dc29713b20 [1722921915.232] [10536:10538] [ICD] Check In Message processing complete: start_counter=1676866595 offset=1 nodeid=<000000000001B669, 1> [1722921915.232] [10536:10538] [TOO] The node <000000000001B669, 1> is not the one we are interested in. [1722921929.714] [10536:10538] [EM] >>> [E:21696r S:0 M:74142876] (U) Msg RX from 0:68423D4EDF91C961 [0000] --- Type 0000:50 (SecureChannel:ICD_CheckInMessage) (B:57) [1722921929.714] [10536:10538] [EM] Handling via exchange: 21696r, Delegate: 0x55dc29713b20 [1722921929.714] [10536:10538] [ICD] Trying to establish a CASE session for re-registering an ICD client [1722921929.714] [10536:10538] [CSM] FindOrEstablishSession: PeerId = [1:000000000001B669] [1722921929.714] [10536:10538] [CSM] FindOrEstablishSession: No existing OperationalSessionSetup instance found [1722921929.714] [10536:10538] [DIS] OperationalSessionSetup[1:000000000001B669]: State change 1 --> 2 [1722921929.714] [10536:10538] [DIS] Resolving DB04E40838302D16:000000000001B669 ... [1722921929.715] [10536:10538] [DIS] Lookup started for DB04E40838302D16-000000000001B669 [1722921929.716] [10536:10538] [DL] Avahi resolve found [1722921929.716] [10536:10538] [DIS] Node ID resolved for DB04E40838302D16-000000000001B669 [1722921929.716] [10536:10538] [DIS] Hostname: 8C1D96786A130000 [1722921929.716] [10536:10538] [DIS] IP Address #1: fe80::7d4b:a2b1:f206:c28 [1722921929.716] [10536:10538] [DIS] Port: 49262 [1722921929.716] [10536:10538] [DIS] Mrp Interval idle: not present [1722921929.716] [10536:10538] [DIS] Mrp Interval active: not present [1722921929.716] [10536:10538] [DIS] Mrp Active Threshold: not present [1722921929.716] [10536:10538] [DIS] TCP Client Supported: 1 [1722921929.716] [10536:10538] [DIS] TCP Server Supported: 1 [1722921929.716] [10536:10538] [DIS] ICD: not present [1722921929.716] [10536:10538] [DIS] UDP:[fe80::7d4b:a2b1:f206:c28%enxd03745ce8f62]:49262: new best score: 7 (for DB04E40838302D16-000000000001B669) [1722921929.716] [10536:10538] [DIS] Checking node lookup status for DB04E40838302D16-000000000001B669 after 1 ms [1722921929.716] [10536:10538] [DIS] Keeping DNSSD lookup active [1722921929.915] [10536:10538] [DIS] Checking node lookup status for DB04E40838302D16-000000000001B669 after 201 ms [1722921929.915] [10536:10538] [DIS] OperationalSessionSetup[1:000000000001B669]: Updating device address to UDP:[fe80::7d4b:a2b1:f206:c28%enxd03745ce8f62]:49262 while in state 2 [1722921929.915] [10536:10538] [DIS] OperationalSessionSetup[1:000000000001B669]: State change 2 --> 3 [1722921929.915] [10536:10538] [IN] SecureSession[0x7f56700282c0]: Allocated Type:2 LSID:528 [1722921929.915] [10536:10538] [SC] Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x000000000001B669 [1722921929.916] [10536:10538] [EM] <<< [E:4364i S:0 M:193887327] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::7d4b:a2b1:f206:c28%enxd03745ce8f62]:49262] --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196) [1722921929.916] [10536:10538] [SC] Sent Sigma1 msg to <000000000001B669, 1> [1722921929.916] [10536:10538] [DIS] OperationalSessionSetup[1:000000000001B669]: State change 3 --> 4 [1722921929.957] [10536:10538] [EM] >>> [E:4364r S:0 M:193887327] (U) Msg RX from 0:B8F6D53D529EBFF3 [0000] --- Type 0000:30 (SecureChannel:CASE_Sigma1) (B:196) [1722921929.957] [10536:10538] [EM] Handling via exchange: 4364r, Delegate: 0x55dc2cf80860 [1722921929.957] [10536:10538] [IN] CASE Server received Sigma1 message . Starting handshake. EC 0x7f56700285a0 [1722921929.958] [10536:10538] [SC] Received Sigma1 msg [1722921929.958] [10536:10538] [SC] Found MRP parameters in the message [1722921929.958] [10536:10538] [SC] Peer assigned session key ID 528 [1722921929.958] [10536:10538] [SC] CASE matched destination ID: fabricIndex 1, NodeID 0x000000000001B669 [1722921929.959] [10536:10538] [EM] <<< [E:4364r S:0 M:193887328 (Ack:193887327)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::a70c:61dc:df51:6945%wlp0s20f3]:49262] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:754) [1722921929.959] [10536:10538] [SC] Sent Sigma2 msg [1722921929.959] [10536:10538] [EM] >>> [E:4364i S:0 M:193887328 (Ack:193887327)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2) (B:754) [1722921929.959] [10536:10538] [EM] Found matching exchange: 4364i, Delegate: 0x7f5670024cd8 [1722921929.960] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:193887327 from Retrans Table on exchange 4364i [1722921929.960] [10536:10538] [SC] Received Sigma2 msg [1722921929.960] [10536:10538] [SC] Peer assigned session session ID 526 [1722921929.961] [10536:10538] [SC] Found MRP parameters in the message [1722921929.961] [10536:10538] [SC] Sending Sigma3 [1722921929.962] [10536:10538] [EM] <<< [E:4364i S:0 M:193887329 (Ack:193887328)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::7d4b:a2b1:f206:c28%enxd03745ce8f62]:49262] --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598) [1722921929.962] [10536:10538] [SC] Sent Sigma3 msg [1722921929.963] [10536:10538] [EM] >>> [E:4364r S:0 M:193887329 (Ack:193887328)] (U) Msg RX from 0:B8F6D53D529EBFF3 [0000] --- Type 0000:32 (SecureChannel:CASE_Sigma3) (B:598) [1722921929.963] [10536:10538] [EM] Found matching exchange: 4364r, Delegate: 0x55dc2cf80898 [1722921929.963] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:193887328 from Retrans Table on exchange 4364r [1722921929.963] [10536:10538] [SC] Received Sigma3 msg [1722921929.966] [10536:10538] [SC] Sending status report. Protocol code 0, exchange 4364 [1722921929.966] [10536:10538] [EM] <<< [E:4364r S:0 M:193887330 (Ack:193887329)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::a70c:61dc:df51:6945%wlp0s20f3]:49262] --- Type 0000:40 (SecureChannel:StatusReport) (B:34) [1722921929.966] [10536:10538] [SC] SecureSession[0x55dc2cf7a2d0, LSID:526]: State change 'kEstablishing' --> 'kActive' [1722921929.966] [10536:10538] [IN] SecureSession[0x55dc2cf7a2d0]: Activated - Type:2 LSID:526 [1722921929.966] [10536:10538] [IN] New secure session activated for device <000000000001B669, 1>, LSID:526 PSID:528! [1722921929.966] [10536:10538] [IN] CASE Session established to peer: <000000000001B669, 1> [1722921929.967] [10536:10538] [IN] SecureSession[0x7f5670028430]: Allocated Type:2 LSID:529 [1722921929.967] [10536:10538] [SC] Allocated SecureSession (0x7f5670028430) - waiting for Sigma1 msg [1722921929.967] [10536:10538] [DL] HandlePlatformSpecificBLEEvent 32792 [1722921929.967] [10536:10538] [EM] >>> [E:4364i S:0 M:193887330 (Ack:193887329)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport) (B:34) [1722921929.967] [10536:10538] [EM] Found matching exchange: 4364i, Delegate: 0x7f5670024cd8 [1722921929.967] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:193887329 from Retrans Table on exchange 4364i [1722921929.967] [10536:10538] [SC] Success status report received. Session was established [1722921929.968] [10536:10538] [SC] SecureSession[0x7f56700282c0, LSID:528]: State change 'kEstablishing' --> 'kActive' [1722921929.968] [10536:10538] [IN] SecureSession[0x7f56700282c0]: Activated - Type:2 LSID:528 [1722921929.968] [10536:10538] [IN] New secure session activated for device <000000000001B669, 1>, LSID:528 PSID:526! [1722921929.968] [10536:10538] [DIS] OperationalSessionSetup[1:000000000001B669]: State change 4 --> 5 [1722921929.968] [10536:10538] [DMG] ICR moving to [AddingComm] [1722921929.968] [10536:10538] [DMG] ICR moving to [AddedComma] [1722921929.968] [10536:10538] [EM] <<< [E:4365i S:528 M:33965130] (S) Msg TX to 1:000000000001B669 [2D16] [UDP:[fe80::7d4b:a2b1:f206:c28%enxd03745ce8f62]:49262] --- Type 0001:08 (IM:InvokeCommandRequest) (B:74) [1722921929.968] [10536:10538] [DMG] ICR moving to [AwaitingRe] [1722921929.968] [10536:10538] [EM] <<< [E:4364i S:0 M:193887331 (Ack:193887330)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::7d4b:a2b1:f206:c28%enxd03745ce8f62]:49262] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26) [1722921929.968] [10536:10538] [EM] Flushed pending ack for MessageCounter:193887330 on exchange 4364i [1722921929.968] [10536:10538] [DL] HandlePlatformSpecificBLEEvent 32792 [1722921929.969] [10536:10538] [EM] >>> [E:4365r S:526 M:33965130] (S) Msg RX from 1:000000000001B669 [2D16] --- Type 0001:08 (IM:InvokeCommandRequest) (B:74) [1722921929.969] [10536:10538] [EM] Handling via exchange: 4365r, Delegate: 0x55dc297178c8 [1722921929.969] [10536:10538] [DMG] InvokeRequestMessage = [1722921929.969] [10536:10538] [DMG] { [1722921929.969] [10536:10538] [DMG] suppressResponse = false, [1722921929.969] [10536:10538] [DMG] timedRequest = false, [1722921929.969] [10536:10538] [DMG] InvokeRequests = [1722921929.969] [10536:10538] [DMG] [ [1722921929.969] [10536:10538] [DMG] CommandDataIB = [1722921929.969] [10536:10538] [DMG] { [1722921929.969] [10536:10538] [DMG] CommandPathIB = [1722921929.969] [10536:10538] [DMG] { [1722921929.969] [10536:10538] [DMG] EndpointId = 0x0, [1722921929.969] [10536:10538] [DMG] ClusterId = 0x46, [1722921929.969] [10536:10538] [DMG] CommandId = 0x0, [1722921929.969] [10536:10538] [DMG] }, [1722921929.969] [10536:10538] [DMG] [1722921929.969] [10536:10538] [DMG] CommandFields = [1722921929.969] [10536:10538] [DMG] { [1722921929.969] [10536:10538] [DMG] 0x0 = 112233 (unsigned), [1722921929.969] [10536:10538] [DMG] 0x1 = 1 (unsigned), [1722921929.969] [10536:10538] [DMG] 0x2 = [ [1722921929.969] [10536:10538] [DMG] [1722921929.969] [10536:10538] [DMG] ] (0 bytes) [1722921929.969] [10536:10538] [DMG] 0x4 = 0 (unsigned), [1722921929.969] [10536:10538] [DMG] }, [1722921929.969] [10536:10538] [DMG] }, [1722921929.969] [10536:10538] [DMG] [1722921929.969] [10536:10538] [DMG] ], [1722921929.969] [10536:10538] [DMG] [1722921929.969] [10536:10538] [DMG] InteractionModelRevision = 11 [1722921929.969] [10536:10538] [DMG] }, [1722921929.969] [10536:10538] [DMG] No command 0x0000_0000 in Cluster 0x0000_0046 on Endpoint 0x0 [1722921929.969] [10536:10538] [DMG] Endpoint=0 Cluster=0x0000_0046 Command=0x0000_0000 status 0x7f (UNSUPPORTED_ENDPOINT) (no additional context) [1722921929.969] [10536:10538] [DMG] Command handler moving to [NewRespons] [1722921929.969] [10536:10538] [DMG] Command handler moving to [ Preparing] [1722921929.969] [10536:10538] [DMG] Command handler moving to [AddingComm] [1722921929.969] [10536:10538] [DMG] Command handler moving to [AddedComma] [1722921929.969] [10536:10538] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 1 [1722921929.969] [10536:10538] [DMG] Decreasing reference count for CommandHandlerImpl, remaining 0 [1722921929.969] [10536:10538] [DMG] Command handler moving to [AwaitingDe] [1722921929.969] [10536:10538] [EM] <<< [E:4365r S:526 M:77402085 (Ack:33965130)] (S) Msg TX to 1:000000000001B669 [2D16] [UDP:[fe80::a70c:61dc:df51:6945%wlp0s20f3]:49262] --- Type 0001:09 (IM:InvokeCommandResponse) (B:67) [1722921929.970] [10536:10538] [DMG] Command response sender moving to [AllInvokeR] [1722921929.970] [10536:10538] [EM] >>> [E:4364r S:0 M:193887331 (Ack:193887330)] (U) Msg RX from 0:B8F6D53D529EBFF3 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:26) [1722921929.970] [10536:10538] [EM] Found matching exchange: 4364r, Delegate: (nil) [1722921929.970] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:193887330 from Retrans Table on exchange 4364r [1722921929.970] [10536:10538] [EM] >>> [E:4365i S:528 M:77402085 (Ack:33965130)] (S) Msg RX from 1:000000000001B669 [2D16] --- Type 0001:09 (IM:InvokeCommandResponse) (B:67) [1722921929.970] [10536:10538] [EM] Found matching exchange: 4365i, Delegate: 0x7f56700209f8 [1722921929.970] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:33965130 from Retrans Table on exchange 4365i [1722921929.970] [10536:10538] [DMG] ICR moving to [ResponseRe] [1722921929.970] [10536:10538] [DMG] InvokeResponseMessage = [1722921929.970] [10536:10538] [DMG] { [1722921929.970] [10536:10538] [DMG] suppressResponse = false, [1722921929.970] [10536:10538] [DMG] InvokeResponseIBs = [1722921929.970] [10536:10538] [DMG] [ [1722921929.970] [10536:10538] [DMG] InvokeResponseIB = [1722921929.970] [10536:10538] [DMG] { [1722921929.970] [10536:10538] [DMG] CommandStatusIB = [1722921929.970] [10536:10538] [DMG] { [1722921929.970] [10536:10538] [DMG] CommandPathIB = [1722921929.970] [10536:10538] [DMG] { [1722921929.970] [10536:10538] [DMG] EndpointId = 0x0, [1722921929.970] [10536:10538] [DMG] ClusterId = 0x46, [1722921929.970] [10536:10538] [DMG] CommandId = 0x0, [1722921929.970] [10536:10538] [DMG] }, [1722921929.970] [10536:10538] [DMG] [1722921929.970] [10536:10538] [DMG] StatusIB = [1722921929.970] [10536:10538] [DMG] { [1722921929.970] [10536:10538] [DMG] status = 0x7f (UNSUPPORTED_ENDPOINT), [1722921929.970] [10536:10538] [DMG] }, [1722921929.970] [10536:10538] [DMG] [1722921929.970] [10536:10538] [DMG] }, [1722921929.970] [10536:10538] [DMG] [1722921929.971] [10536:10538] [DMG] }, [1722921929.971] [10536:10538] [DMG] [1722921929.971] [10536:10538] [DMG] ], [1722921929.971] [10536:10538] [DMG] [1722921929.971] [10536:10538] [DMG] InteractionModelRevision = 11 [1722921929.971] [10536:10538] [DMG] }, [1722921929.971] [10536:10538] [DMG] Received Command Response Status for Endpoint=0 Cluster=0x0000_0046 Command=0x0000_0000 Status=0x7f [1722921929.971] [10536:10538] [ICD] RegisterClient command failed: IM Error 0x0000057F: General error: 0x7f (UNSUPPORTED_ENDPOINT) [1722921929.971] [10536:10538] [ICD] Re-registration with new key failed with error : IM Error 0x0000057F: General error: 0x7f (UNSUPPORTED_ENDPOINT) [1722921929.971] [10536:10538] [DMG] ICR moving to [AwaitingDe] [1722921929.971] [10536:10538] [EM] <<< [E:4365i S:528 M:33965131 (Ack:77402085)] (S) Msg TX to 1:000000000001B669 [2D16] [UDP:[fe80::7d4b:a2b1:f206:c28%enxd03745ce8f62]:49262] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34) [1722921929.971] [10536:10538] [EM] Flushed pending ack for MessageCounter:77402085 on exchange 4365i [1722921929.971] [10536:10538] [EM] >>> [E:4365r S:526 M:33965131 (Ack:77402085)] (S) Msg RX from 1:000000000001B669 [2D16] --- Type 0000:10 (SecureChannel:StandaloneAck) (B:34) [1722921929.971] [10536:10538] [EM] Found matching exchange: 4365r, Delegate: (nil) [1722921929.971] [10536:10538] [EM] Rxd Ack; Removing MessageCounter:77402085 from Retrans Table on exchange 4365r