• State Not Answered
  • Replies 7 replies
  • Subscribers 73 subscribers
  • Views 7 views
  • Users 0 members are here
Attachments (7) Download All
Nordic Case Info
  • Case ID: 344919
Options

Matter Test Harness for certification

Himansu

Hi,

I'm doing a test with a matter test harness.
An error occurs in test case _TC-CNET-4.16, _TC-CADMIN-1.22 and _TC-DGGEN-2.3.

1. _TC-CNET-4.16: Step 2: should receive NetworkIDNotFound which is '3'
2. _TC-CADMIN-1.22: step 5: got success response instead of Invalid command
3. _TC-DGGEN-2.3: Step 3: got Constraint Error instead of Invalid Command

I would like to know how to solve this problem.

Test Harness Enviornment:

Board: Rraspberry PI4
Version: 2.10.2+spring2024

Sha: 2a350c8

DUT:

Board: nrf52840(BL654) custom board

SDK:2.7.0

Sample Application : Matter Door Lock

Please see attached log and PICS file for more information.

Thanks,

Himansu Donga
FAIL-TC-DGGEN-2.3.logFAIL_TC-CNET-4.16.logAML_PICS_XML_version V_27_SVE_1.3.1.zip

  • 0

    Hello,

    1. _TC-CNET-4.16: Step 2: should receive NetworkIDNotFound which is '3'

    Looking through the test steps mentioned here https://github.com/nrfconnect/sdk-connectedhomeip/blob/master/src/app/tests/suites/certification/Test_TC_CNET_4_16.yaml it indicates that you've not set up the PIXIT.CNET.THREAD_2ND_OPERATIONALDATASET correct.

    TH sends a remove-network command for PIXIT.CNET.THREAD_2ND_OPERATIONALDATASET, which based on your log should be 1111111122222222. The test expects it to fail with networking status 3 because this PAN ID should not be existing on your device, but instead it sends networkingStatus: 0 (success).

    As mentioned this might happen if you either set up your dataset wrong, or it was not given at all since the default input is 1111111122222222 and that is the network ID that actually exists and that the DUT is commissioned on. Providing any other value should work.

    2. _TC-CADMIN-1.22: step 5: got success response instead of Invalid command

    Could you add the log for this step as well?

    3. _TC-DGGEN-2.3: Step 3: got Constraint Error instead of Invalid Command

    I might need some more time looking into this one, but in the meanwhile could you refer to 11.12.7.1 in the Matter spec and see if you've configured it according to the spec? 

    Kind regards,
    Andreas

  • 0

    Could you add the log for this step as well?

    Ans: Pls find attached file for log.CADMIN-1-22_2025_05_10_21_26_12.log

  • 0

    FAIL_TC-ADMIN-1.22_2.txt

    Fullscreen FAIL-TC-CADMIN-1.22-Step5.txt Download 
    ubuntu@ubuntu:~/apps$ ./chip-tool  pairing open-commissioning-window 1 1 901 2000 3423
[1747181689.846912][3900:3900] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1747181689.848043][3900:3900] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1747181689.848086][3900:3900] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1747181689.853309][3900:3900] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1747181689.853626][3900:3900] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1747181689.853768][3900:3900] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1747181689.854087][3900:3900] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Fhy44B)
[1747181689.854726][3900:3900] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1747181689.854783][3900:3900] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2)
[1747181689.855719][3900:3900] CHIP:DL: Got Ethernet interface: eth0
[1747181689.856365][3900:3900] CHIP:DL: Found the primary Ethernet interface:eth0
[1747181689.857046][3900:3900] CHIP:DL: Got WiFi interface: wlan0
[1747181689.857119][3900:3900] CHIP:DL: Failed to reset WiFi statistic counts
[1747181689.857175][3900:3900] CHIP:IN: UDP::Init bind&listen port=0
[1747181689.857302][3900:3900] CHIP:IN: UDP::Init bound to port=59696
[1747181689.857326][3900:3900] CHIP:IN: BLEBase::Init - setting/overriding transport
[1747181689.857355][3900:3900] CHIP:IN: TransportMgr initialized
[1747181689.857408][3900:3900] CHIP:FP: Initializing FabricTable from persistent storage
[1747181689.857581][3900:3900] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1747181689.859159][3900:3900] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x9FF6358D4C9156A9, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1747181689.861352][3900:3900] CHIP:ZCL: Using ZAP configuration...
[1747181689.865075][3900:3900] CHIP:DL: Avahi client registered
[1747181689.865194][3900:3900] CHIP:CTL: System State Initialized...
[1747181689.865376][3900:3900] CHIP:CTL: Setting attestation nonce to random value
[1747181689.865436][3900:3900] CHIP:CTL: Setting CSR nonce to random value
[1747181689.865521][3900:3900] CHIP:IN: UDP::Init bind&listen port=5550
[1747181689.865673][3900:3900] CHIP:IN: UDP::Init bound to port=5550
[1747181689.865697][3900:3900] CHIP:IN: TransportMgr initialized
[1747181689.866013][3900:3902] CHIP:DL: CHIP task running
[1747181689.866248][3900:3902] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
[1747181689.866625][3900:3902] CHIP:CTL: Setting attestation nonce to random value
[1747181689.866852][3900:3902] CHIP:CTL: Setting CSR nonce to random value
[1747181689.867895][3900:3902] CHIP:CTL: Generating NOC
[1747181689.868860][3900:3902] CHIP:FP: Validating NOC chain
[1747181689.870827][3900:3902] CHIP:FP: NOC chain validation successful
[1747181689.870996][3900:3902] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1747181689.871030][3900:3902] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1747181689.871054][3900:3902] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1747181689.871074][3900:3902] CHIP:TS: Retaining current Last Known Good Time
[1747181689.876098][3900:3902] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1747181689.877930][3900:3902] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1747181689.879560][3900:3902] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 9FF6358D4C9156A9)
[1747181689.879612][3900:3902] CHIP:IN: UDP::Init bind&listen port=5550
[1747181689.879722][3900:3902] CHIP:IN: UDP::Init bound to port=5550
[1747181689.879744][3900:3902] CHIP:IN: TransportMgr initialized
[1747181689.902398][3900:3902] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001]
[1747181689.902450][3900:3902] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1747181689.902484][3900:3902] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 2
[1747181689.902516][3900:3902] CHIP:DIS: Resolving 9FF6358D4C9156A9:0000000000000001 ...
[1747181689.904085][3900:3902] CHIP:DL: Avahi resolve found
[1747181689.904153][3900:3902] CHIP:DIS: Node ID resolved for 9FF6358D4C9156A9:0000000000000001
[1747181689.904174][3900:3902] CHIP:DIS:        Hostname: 7E09CFA3BB2EF4F3
[1747181689.904198][3900:3902] CHIP:DIS:        IP Address #1: fd11:22::3982:2271:515d:4a83
[1747181689.904218][3900:3902] CHIP:DIS:        Port: 5540
[1747181689.904237][3900:3902] CHIP:DIS:        Mrp Interval idle: 5000 ms
[1747181689.904255][3900:3902] CHIP:DIS:        Mrp Interval active: 2500 ms
[1747181689.904274][3900:3902] CHIP:DIS:        Mrp Active Threshold: 500 ms
[1747181689.904292][3900:3902] CHIP:DIS:        TCP Supported: 0
[1747181689.904309][3900:3902] CHIP:DIS:        ICD: not present
[1747181689.905098][3900:3902] CHIP:DIS: Lookup clearing interface for non LL address
[1747181689.905188][3900:3902] CHIP:DIS: UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540: new best score: 3
[1747181689.905211][3900:3902] CHIP:DIS: Checking node lookup status after 2 ms
[1747181689.905229][3900:3902] CHIP:DIS: Keeping DNSSD lookup active
[1747181690.103565][3900:3902] CHIP:DIS: Checking node lookup status after 201 ms
[1747181690.103705][3900:3902] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: Updating device address to UDP:[fd11:22::3982:2271:515d:4a83]:5540 while in state 2
[1747181690.103768][3900:3902] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 2 --> 3
[1747181690.104088][3900:3902] CHIP:IN: SecureSession[0xffff7000edd0]: Allocated Type:2 LSID:4449
[1747181690.104191][3900:3902] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000000001
[1747181690.106396][3900:3902] CHIP:EM: <<< [E:37782i S:0 M:215371205] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:22::3982:2271:515d:4a83]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1747181690.106973][3900:3902] CHIP:SC: Sent Sigma1 msg
[1747181690.107053][3900:3902] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 3 --> 4
[1747181690.475051][3900:3902] CHIP:EM: >>> [E:37782i S:0 M:157386237 (Ack:215371205)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1747181690.475153][3900:3902] CHIP:EM: Found matching exchange: 37782i, Delegate: 0xffff7000eb28
[1747181690.475234][3900:3902] CHIP:EM: Rxd Ack; Removing MessageCounter:215371205 from Retrans Table on exchange 37782i
[1747181690.622962][3900:3902] CHIP:EM: >>> [E:37782i S:0 M:157386238 (Ack:215371205)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
[1747181690.623068][3900:3902] CHIP:EM: Found matching exchange: 37782i, Delegate: 0xffff7000eb28
[1747181690.623132][3900:3902] CHIP:EM: CHIP MessageCounter:215371205 not in RetransTable on exchange 37782i
[1747181690.623240][3900:3902] CHIP:SC: Received Sigma2 msg
[1747181690.623327][3900:3902] CHIP:SC: Peer assigned session session ID 6268
[1747181690.632020][3900:3902] CHIP:SC: Found MRP parameters in the message
[1747181690.632143][3900:3902] CHIP:SC: Sending Sigma3
[1747181690.633433][3900:3902] CHIP:EM: <<< [E:37782i S:0 M:215371206 (Ack:157386238)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
[1747181690.633884][3900:3902] CHIP:SC: Sent Sigma3 msg
[1747181691.060155][3900:3902] CHIP:EM: >>> [E:37782i S:0 M:157386239 (Ack:215371206)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1747181691.060216][3900:3902] CHIP:EM: Found matching exchange: 37782i, Delegate: 0xffff7000eb28
[1747181691.060264][3900:3902] CHIP:EM: Rxd Ack; Removing MessageCounter:215371206 from Retrans Table on exchange 37782i
[1747181691.247417][3900:3902] CHIP:EM: >>> [E:37782i S:0 M:157386240 (Ack:215371206)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1747181691.247518][3900:3902] CHIP:EM: Found matching exchange: 37782i, Delegate: 0xffff7000eb28
[1747181691.247582][3900:3902] CHIP:EM: CHIP MessageCounter:215371206 not in RetransTable on exchange 37782i
[1747181691.247688][3900:3902] CHIP:SC: Success status report received. Session was established
[1747181691.254415][3900:3902] CHIP:SC: SecureSession[0xffff7000edd0, LSID:4449]: State change 'kEstablishing' --> 'kActive'
[1747181691.254514][3900:3902] CHIP:IN: SecureSession[0xffff7000edd0]: Activated - Type:2 LSID:4449
[1747181691.254568][3900:3902] CHIP:IN: New secure session activated for device <0000000000000001, 1>, LSID:4449 PSID:6268!
[1747181691.254634][3900:3902] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 4 --> 5
[1747181691.254876][3900:3902] CHIP:DMG: SendReadRequest ReadClient[0xffff7000a4c0]: Sending Read Request
[1747181691.255413][3900:3902] CHIP:EM: <<< [E:37783i S:4449 M:120802994] (S) Msg TX to 1:0000000000000001 [56A9] [UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540] --- Type 0001:02 (IM:ReadRequest)
[1747181691.256003][3900:3902] CHIP:DMG: MoveToState ReadClient[0xffff7000a4c0]: Moving to [AwaitingIn]
[1747181691.256339][3900:3902] CHIP:EM: <<< [E:37782i S:0 M:215371207 (Ack:157386240)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1747181691.256652][3900:3902] CHIP:EM: Flushed pending ack for MessageCounter:157386240 on exchange 37782i
[1747181691.580238][3900:3902] CHIP:EM: >>> [E:37783i S:4449 M:99251886 (Ack:120802994)] (S) Msg RX from 1:0000000000000001 [56A9] --- Type 0001:05 (IM:ReportData)
[1747181691.580305][3900:3902] CHIP:EM: Found matching exchange: 37783i, Delegate: 0xffff7000a4d0
[1747181691.580358][3900:3902] CHIP:EM: Rxd Ack; Removing MessageCounter:120802994 from Retrans Table on exchange 37783i
[1747181691.580439][3900:3902] CHIP:DMG: ReportDataMessage =
[1747181691.580473][3900:3902] CHIP:DMG: {
[1747181691.580501][3900:3902] CHIP:DMG:        AttributeReportIBs =
[1747181691.580541][3900:3902] CHIP:DMG:        [
[1747181691.580570][3900:3902] CHIP:DMG:                AttributeReportIB =
[1747181691.580636][3900:3902] CHIP:DMG:                {
[1747181691.580669][3900:3902] CHIP:DMG:                        AttributeDataIB =
[1747181691.580705][3900:3902] CHIP:DMG:                        {
[1747181691.580758][3900:3902] CHIP:DMG:                                DataVersion = 0xfd1b1703,
[1747181691.580805][3900:3902] CHIP:DMG:                                AttributePathIB =
[1747181691.580856][3900:3902] CHIP:DMG:                                {
[1747181691.580895][3900:3902] CHIP:DMG:                                        Endpoint = 0x0,
[1747181691.580949][3900:3902] CHIP:DMG:                                        Cluster = 0x28,
[1747181691.580990][3900:3902] CHIP:DMG:                                        Attribute = 0x0000_0002,
[1747181691.581039][3900:3902] CHIP:DMG:                                }
[1747181691.581081][3900:3902] CHIP:DMG:
[1747181691.581122][3900:3902] CHIP:DMG:                                Data = 5547,
[1747181691.581171][3900:3902] CHIP:DMG:                        },
[1747181691.581211][3900:3902] CHIP:DMG:
[1747181691.581254][3900:3902] CHIP:DMG:                },
[1747181691.581291][3900:3902] CHIP:DMG:
[1747181691.581332][3900:3902] CHIP:DMG:        ],
[1747181691.581372][3900:3902] CHIP:DMG:
[1747181691.581403][3900:3902] CHIP:DMG:        SuppressResponse = true,
[1747181691.581447][3900:3902] CHIP:DMG:        InteractionModelRevision = 11
[1747181691.581476][3900:3902] CHIP:DMG: }
[1747181691.581691][3900:3902] CHIP:CTL: Received VID for the device. Value 5547
[1747181691.581726][3900:3902] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001]
[1747181691.581755][3900:3902] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1747181691.581799][3900:3902] CHIP:DIS: Found an existing secure session to [1:0000000000000001]!
[1747181691.581835][3900:3902] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5
[1747181691.581926][3900:3902] CHIP:DMG: SendReadRequest ReadClient[0xffff700092c0]: Sending Read Request
[1747181691.582215][3900:3902] CHIP:EM: <<< [E:37784i S:4449 M:120802995] (S) Msg TX to 1:0000000000000001 [56A9] [UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540] --- Type 0001:02 (IM:ReadRequest)
[1747181691.582509][3900:3902] CHIP:DMG: MoveToState ReadClient[0xffff700092c0]: Moving to [AwaitingIn]
[1747181691.582769][3900:3902] CHIP:EM: <<< [E:37783i S:4449 M:120802996 (Ack:99251886)] (S) Msg TX to 1:0000000000000001 [56A9] [UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1747181691.582926][3900:3902] CHIP:EM: Flushed pending ack for MessageCounter:99251886 on exchange 37783i
[1747181692.091910][3900:3902] CHIP:EM: >>> [E:37784i S:4449 M:99251887 (Ack:120802995)] (S) Msg RX from 1:0000000000000001 [56A9] --- Type 0001:05 (IM:ReportData)
[1747181692.091996][3900:3902] CHIP:EM: Found matching exchange: 37784i, Delegate: 0xffff700092d0
[1747181692.092065][3900:3902] CHIP:EM: Rxd Ack; Removing MessageCounter:120802995 from Retrans Table on exchange 37784i
[1747181692.092173][3900:3902] CHIP:DMG: ReportDataMessage =
[1747181692.092222][3900:3902] CHIP:DMG: {
[1747181692.092269][3900:3902] CHIP:DMG:        AttributeReportIBs =
[1747181692.092337][3900:3902] CHIP:DMG:        [
[1747181692.092389][3900:3902] CHIP:DMG:                AttributeReportIB =
[1747181692.092457][3900:3902] CHIP:DMG:                {
[1747181692.092512][3900:3902] CHIP:DMG:                        AttributeDataIB =
[1747181692.092582][3900:3902] CHIP:DMG:                        {
[1747181692.092645][3900:3902] CHIP:DMG:                                DataVersion = 0xfd1b1703,
[1747181692.092708][3900:3902] CHIP:DMG:                                AttributePathIB =
[1747181692.092775][3900:3902] CHIP:DMG:                                {
[1747181692.092955][3900:3902] CHIP:DMG:                                        Endpoint = 0x0,
[1747181692.093029][3900:3902] CHIP:DMG:                                        Cluster = 0x28,
[1747181692.093099][3900:3902] CHIP:DMG:                                        Attribute = 0x0000_0004,
[1747181692.093221][3900:3902] CHIP:DMG:                                }
[1747181692.093297][3900:3902] CHIP:DMG:
[1747181692.093365][3900:3902] CHIP:DMG:                                Data = 1,
[1747181692.093427][3900:3902] CHIP:DMG:                        },
[1747181692.093497][3900:3902] CHIP:DMG:
[1747181692.093610][3900:3902] CHIP:DMG:                },
[1747181692.093676][3900:3902] CHIP:DMG:
[1747181692.093726][3900:3902] CHIP:DMG:        ],
[1747181692.093789][3900:3902] CHIP:DMG:
[1747181692.093840][3900:3902] CHIP:DMG:        SuppressResponse = true,
[1747181692.093892][3900:3902] CHIP:DMG:        InteractionModelRevision = 11
[1747181692.093940][3900:3902] CHIP:DMG: }
[1747181692.094148][3900:3902] CHIP:CTL: Received PID for the device. Value 1
[1747181692.094200][3900:3902] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000000001]
[1747181692.094246][3900:3902] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1747181692.094451][3900:3902] CHIP:DIS: Found an existing secure session to [1:0000000000000001]!
[1747181692.094512][3900:3902] CHIP:DIS: OperationalSessionSetup[1:0000000000000001]: State change 1 --> 5
[1747181692.094576][3900:3902] CHIP:CTL: OpenCommissioningWindow for device ID 0x0000000000000001
[1747181692.094740][3900:3902] CHIP:DMG: ICR moving to [AddingComm]
[1747181692.094860][3900:3902] CHIP:DMG: ICR moving to [AddedComma]
[1747181692.095249][3900:3902] CHIP:EM: <<< [E:37785i S:4449 M:120802997] (S) Msg TX to 1:0000000000000001 [56A9] [UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540] --- Type 0001:0A (IM:TimedRequest)
[1747181692.095580][3900:3902] CHIP:DMG: ICR moving to [AwaitingTi]
[1747181692.095920][3900:3902] CHIP:EM: <<< [E:37784i S:4449 M:120802998 (Ack:99251887)] (S) Msg TX to 1:0000000000000001 [56A9] [UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1747181692.096117][3900:3902] CHIP:EM: Flushed pending ack for MessageCounter:99251887 on exchange 37784i
[1747181692.606218][3900:3902] CHIP:EM: >>> [E:37785i S:4449 M:99251888 (Ack:120802997)] (S) Msg RX from 1:0000000000000001 [56A9] --- Type 0001:01 (IM:StatusResponse)
[1747181692.606342][3900:3902] CHIP:EM: Found matching exchange: 37785i, Delegate: 0xffff70008628
[1747181692.606415][3900:3902] CHIP:EM: Rxd Ack; Removing MessageCounter:120802997 from Retrans Table on exchange 37785i
[1747181692.606512][3900:3902] CHIP:DMG: StatusResponseMessage =
[1747181692.606574][3900:3902] CHIP:DMG: {
[1747181692.606625][3900:3902] CHIP:DMG:        Status = 0x00 (SUCCESS),
[1747181692.606678][3900:3902] CHIP:DMG:        InteractionModelRevision = 11
[1747181692.606727][3900:3902] CHIP:DMG: }
[1747181692.606778][3900:3902] CHIP:IM: Received status response, status is 0x00 (SUCCESS)
[1747181692.607127][3900:3902] CHIP:EM: <<< [E:37785i S:4449 M:120802999 (Ack:99251888)] (S) Msg TX to 1:0000000000000001 [56A9] [UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1747181692.607533][3900:3902] CHIP:DMG: ICR moving to [AwaitingRe]
[1747181693.136297][3900:3902] CHIP:EM: >>> [E:37785i S:4449 M:99251889 (Ack:120802999)] (S) Msg RX from 1:0000000000000001 [56A9] --- Type 0001:09 (IM:InvokeCommandResponse)
[1747181693.136390][3900:3902] CHIP:EM: Found matching exchange: 37785i, Delegate: 0xffff70008628
[1747181693.136468][3900:3902] CHIP:EM: Rxd Ack; Removing MessageCounter:120802999 from Retrans Table on exchange 37785i
[1747181693.136544][3900:3902] CHIP:DMG: ICR moving to [ResponseRe]
[1747181693.136640][3900:3902] CHIP:DMG: InvokeResponseMessage =
[1747181693.136693][3900:3902] CHIP:DMG: {
[1747181693.136741][3900:3902] CHIP:DMG:        suppressResponse = false,
[1747181693.136791][3900:3902] CHIP:DMG:        InvokeResponseIBs =
[1747181693.136858][3900:3902] CHIP:DMG:        [
[1747181693.136907][3900:3902] CHIP:DMG:                InvokeResponseIB =
[1747181693.136976][3900:3902] CHIP:DMG:                {
[1747181693.137029][3900:3902] CHIP:DMG:                        CommandStatusIB =
[1747181693.137090][3900:3902] CHIP:DMG:                        {
[1747181693.137145][3900:3902] CHIP:DMG:                                CommandPathIB =
[1747181693.137218][3900:3902] CHIP:DMG:                                {
[1747181693.137288][3900:3902] CHIP:DMG:                                        EndpointId = 0x0,
[1747181693.137357][3900:3902] CHIP:DMG:                                        ClusterId = 0x3c,
[1747181693.137428][3900:3902] CHIP:DMG:                                        CommandId = 0x0,
[1747181693.137495][3900:3902] CHIP:DMG:                                },
[1747181693.137571][3900:3902] CHIP:DMG:
[1747181693.137628][3900:3902] CHIP:DMG:                                StatusIB =
[1747181693.137694][3900:3902] CHIP:DMG:                                {
[1747181693.137763][3900:3902] CHIP:DMG:                                        status = 0x00 (SUCCESS),
[1747181693.137831][3900:3902] CHIP:DMG:                                },
[1747181693.137898][3900:3902] CHIP:DMG:
[1747181693.137956][3900:3902] CHIP:DMG:                        },
[1747181693.138022][3900:3902] CHIP:DMG:
[1747181693.138083][3900:3902] CHIP:DMG:                },
[1747181693.138148][3900:3902] CHIP:DMG:
[1747181693.138196][3900:3902] CHIP:DMG:        ],
[1747181693.138260][3900:3902] CHIP:DMG:
[1747181693.138387][3900:3902] CHIP:DMG:        InteractionModelRevision = 11
[1747181693.138437][3900:3902] CHIP:DMG: },
[1747181693.138571][3900:3902] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003C Command=0x0000_0000 Status=0x0
[1747181693.138629][3900:3902] CHIP:CTL: Successfully opened pairing window on the device
[1747181693.138733][3900:3902] CHIP:CTL: Manual pairing code: [31711002791]
[1747181693.138793][3900:3902] CHIP:CTL: SetupQRCode: [MT:WUDA0UZ427..O74P300]
[1747181693.138931][3900:3902] CHIP:DMG: ICR moving to [AwaitingDe]
[1747181693.139283][3900:3902] CHIP:EM: <<< [E:37785i S:4449 M:120803000 (Ack:99251889)] (S) Msg TX to 1:0000000000000001 [56A9] [UDP:[fd11:22::3982:2271:515d:4a83%otbr0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1747181693.139611][3900:3902] CHIP:EM: Flushed pending ack for MessageCounter:99251889 on exchange 37785i
[1747181693.140008][3900:3900] CHIP:CTL: Shutting down the commissioner
[1747181693.140185][3900:3900] CHIP:CTL: Shutting down the controller
[1747181693.140239][3900:3900] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1747181693.140284][3900:3900] CHIP:IN: SecureSession[0xffff7000edd0]: MarkForEviction Type:2 LSID:4449
[1747181693.140331][3900:3900] CHIP:SC: SecureSession[0xffff7000edd0, LSID:4449]: State change 'kActive' --> 'kPendingEviction'
[1747181693.140378][3900:3900] CHIP:IN: SecureSession[0xffff7000edd0]: Released - Type:2 LSID:4449
[1747181693.140489][3900:3900] CHIP:FP: Forgetting fabric 0x1
[1747181693.140555][3900:3900] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1747181693.140863][3900:3900] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1747181693.140932][3900:3900] CHIP:TS: Reverted Last Known Good Time to previous value
[1747181693.141024][3900:3900] CHIP:CTL: Shutting down the commissioner
[1747181693.141198][3900:3900] CHIP:CTL: Shutting down the controller
[1747181693.141253][3900:3900] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1747181693.141546][3900:3900] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1747181693.141731][3900:3900] CHIP:FP: Shutting down FabricTable
[1747181693.141800][3900:3900] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1747181693.142031][3900:3900] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1747181693.142096][3900:3900] CHIP:TS: Reverted Last Known Good Time to previous value
[1747181693.142544][3900:3900] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-xkR8xQ)
[1747181693.143676][3900:3900] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1747181693.143792][3900:3900] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1747181693.143843][3900:3900] CHIP:DL: Inet Layer shutdown
[1747181693.143886][3900:3900] CHIP:DL: BLE shutdown
[1747181693.143934][3900:3900] CHIP:DL: System Layer shutdown
    FAIL_TC-CADMIN-1.22.txt

  • 0

    Hi Team,

    Found issue in SDK 2.7.0

    Thanks,

    Himansu

Related
Terms of service