project-chip / certification-tool

A test harness and tooling designed to simplify development, testing, and certification for devices, guided by the Connectivity Standards Alliance.
https://csa-iot.org/
Apache License 2.0
42 stars 24 forks source link

[Bug] [TC-ACE-1.1] The test expects no error but the "FAILURE" error occured. #488

Open KEEPHEADU opened 1 week ago

KEEPHEADU commented 1 week ago

Describe the bug

The same error occurred in TC-ACE-1.1, TC-ACL-1.1, TC-ACL-2.10, TC-ACL-2.4, TC-ACL-2.5 and other tests.

INFO       | 2024-10-28 03:22:55.442945 | Test Step Completed [PASSED]: Start chip-tool test
INFO       | 2024-10-28 03:22:55.448085 | Executing Test Step: Step 1: TH1 commissions DUT using admin node ID N1
CHIPTOOL   | 2024-10-28 03:23:05.457670 | CHIP:TOO Command: delay wait-for-commissionee 2542879121297813341 
CHIPTOOL   | 2024-10-28 03:23:05.460319 | CHIP:IN Expiring all sessions for node <234A1F168BB6AF5D, 1>!!
CHIPTOOL   | 2024-10-28 03:23:05.462514 | CHIP:IN SecureSession[0xffff88036b70]: MarkForEviction Type:2 LSID:58182
CHIPTOOL   | 2024-10-28 03:23:05.464745 | CHIP:SC SecureSession[0xffff88036b70, LSID:58182]: State change 'kActive' --> 'kPendingEviction'
CHIPTOOL   | 2024-10-28 03:23:05.466222 | CHIP:IN SecureSession[0xffff88036b70]: Released - Type:2 LSID:58182
CHIPTOOL   | 2024-10-28 03:23:05.467146 | CHIP:CSM FindOrEstablishSession: PeerId = [1:234A1F168BB6AF5D]
CHIPTOOL   | 2024-10-28 03:23:05.468175 | CHIP:CSM FindOrEstablishSession: No existing OperationalSessionSetup instance found
CHIPTOOL   | 2024-10-28 03:23:05.469170 | CHIP:DIS OperationalSessionSetup[1:234A1F168BB6AF5D]: State change 1 --> 2
CHIPTOOL   | 2024-10-28 03:23:05.470066 | CHIP:DIS Resolving 68ED195F9A727981:234A1F168BB6AF5D ...
CHIPTOOL   | 2024-10-28 03:23:05.470949 | CHIP:DL Avahi resolve found
CHIPTOOL   | 2024-10-28 03:23:05.471885 | CHIP:DIS Node ID resolved for 68ED195F9A727981:234A1F168BB6AF5D
CHIPTOOL   | 2024-10-28 03:23:05.472771 | CHIP:DIS  Hostname: E628034FFBC9D702
CHIPTOOL   | 2024-10-28 03:23:05.473631 | CHIP:DIS  IP Address #1: fd11:32::126e:ca00:83be:42ac
CHIPTOOL   | 2024-10-28 03:23:05.474529 | CHIP:DIS  Port: 5540
CHIPTOOL   | 2024-10-28 03:23:05.475714 | CHIP:DIS  Mrp Interval idle: 15800 ms
CHIPTOOL   | 2024-10-28 03:23:05.476839 | CHIP:DIS  Mrp Interval active: 2500 ms
CHIPTOOL   | 2024-10-28 03:23:05.477911 | CHIP:DIS  Mrp Active Threshold: 1000 ms
CHIPTOOL   | 2024-10-28 03:23:05.478972 | CHIP:DIS  TCP Supported: 0
CHIPTOOL   | 2024-10-28 03:23:05.480136 | CHIP:DIS  ICD: not present
CHIPTOOL   | 2024-10-28 03:23:05.481209 | CHIP:DIS Lookup clearing interface for non LL address
CHIPTOOL   | 2024-10-28 03:23:05.482290 | CHIP:DIS UDP:[fd11:32::126e:ca00:83be:42ac%vetha20529f]:5540: new best score: 5
CHIPTOOL   | 2024-10-28 03:23:05.483407 | CHIP:DIS Checking node lookup status after 3 ms
CHIPTOOL   | 2024-10-28 03:23:05.484565 | CHIP:DIS Keeping DNSSD lookup active
CHIPTOOL   | 2024-10-28 03:23:05.485724 | CHIP:DIS Checking node lookup status after 200 ms
CHIPTOOL   | 2024-10-28 03:23:05.486678 | CHIP:DIS OperationalSessionSetup[1:234A1F168BB6AF5D]: Updating device address to UDP:[fd11:32::126e:ca00:83be:42ac]:5540 while in state 2
CHIPTOOL   | 2024-10-28 03:23:05.487644 | CHIP:DIS OperationalSessionSetup[1:234A1F168BB6AF5D]: State change 2 --> 3
CHIPTOOL   | 2024-10-28 03:23:05.488554 | CHIP:IN SecureSession[0xffff88036b70]: Allocated Type:2 LSID:58183
CHIPTOOL   | 2024-10-28 03:23:05.489425 | CHIP:SC Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x234A1F168BB6AF5D
CHIPTOOL   | 2024-10-28 03:23:05.490318 | CHIP:DMG >> to UDP:[fd11:32::126e:ca00:83be:42ac]:5540 | 118767019 | [Secure Channel  (0) / Certificate Authenticated Session Establishment Sigma '1' (0x30) / Session = 0 / Exchange = 41560]
CHIPTOOL   | 2024-10-28 03:23:05.491202 | CHIP:DMG Header Flags =
CHIPTOOL   | 2024-10-28 03:23:05.492151 | CHIP:DMG {
CHIPTOOL   | 2024-10-28 03:23:05.493048 | CHIP:DMG     Message (0x04) =
CHIPTOOL   | 2024-10-28 03:23:05.493924 | CHIP:DMG     {
CHIPTOOL   | 2024-10-28 03:23:05.494787 | CHIP:DMG         SourceNodeId = BD83E8AC8128D09F
CHIPTOOL   | 2024-10-28 03:23:05.495718 | CHIP:DMG     }
CHIPTOOL   | 2024-10-28 03:23:05.496679 | CHIP:DMG     Exchange (0x05) =
CHIPTOOL   | 2024-10-28 03:23:05.497745 | CHIP:DMG     {
CHIPTOOL   | 2024-10-28 03:23:05.498646 | CHIP:DMG         Initiator = true
CHIPTOOL   | 2024-10-28 03:23:05.499567 | CHIP:DMG         NeedsAck = true
CHIPTOOL   | 2024-10-28 03:23:05.500508 | CHIP:DMG     }
CHIPTOOL   | 2024-10-28 03:23:05.501389 | CHIP:DMG }
CHIPTOOL   | 2024-10-28 03:23:05.502253 | CHIP:DMG  
CHIPTOOL   | 2024-10-28 03:23:05.503113 | CHIP:DMG Decrypted Payload (212 bytes) =
CHIPTOOL   | 2024-10-28 03:23:05.504080 | CHIP:DMG {
CHIPTOOL   | 2024-10-28 03:23:05.504964 | CHIP:DMG     data = 1530012038e640160bf25f7597755d99fc58bbb6127fd9c07914ff64d9a7528f045790f6250247e33003207e48432ee5c0344920c3e3beb56e80e915088618291af2706f2e7617aa02aafc30044104b1c45b876dce51abd7912a275e3fa73115e5626d8a38ee68179585dec6316812a2208425c273b5c7d32857a32fbed43e39504b0e52b6cba08ff7fe2ad5d5d73b35052501f40125022c012503a00f24041124050b2606000003012407011830061087e8bada573ac14c7bc7ca7bd71998123007107afd853442e525543f39d5577b0e0a2f18
CHIPTOOL   | 2024-10-28 03:23:05.505875 | CHIP:DMG }
CHIPTOOL   | 2024-10-28 03:23:05.506766 | CHIP:DMG  
CHIPTOOL   | 2024-10-28 03:23:05.507698 | CHIP:DMG Parameters =
CHIPTOOL   | 2024-10-28 03:23:05.508593 | CHIP:DMG {
CHIPTOOL   | 2024-10-28 03:23:05.509461 | CHIP:DMG     InitiatorRandom (32) = 38E640160BF25F7597755D99FC58BBB6127FD9C07914FF64D9A7528F045790F6
CHIPTOOL   | 2024-10-28 03:23:05.510338 | CHIP:DMG     InitiatorSessionId = 58183
CHIPTOOL   | 2024-10-28 03:23:05.511198 | CHIP:DMG     DestinationId (32) = 7E48432EE5C0344920C3E3BEB56E80E915088618291AF2706F2E7617AA02AAFC
CHIPTOOL   | 2024-10-28 03:23:05.512154 | CHIP:DMG     InitiatorEphPubKey (65) = 04B1C45B876DCE51ABD7912A275E3FA73115E5626D8A38EE68179585DEC6316812A2208425C273B5C7D32857A32FBED43E39504B0E52B6CBA08FF7FE2AD5D5D73B
CHIPTOOL   | 2024-10-28 03:23:05.513064 | CHIP:DMG     SED =
CHIPTOOL   | 2024-10-28 03:23:05.513944 | CHIP:DMG     {
CHIPTOOL   | 2024-10-28 03:23:05.514812 | CHIP:DMG         Idle Retransmit Timeout = 500
CHIPTOOL   | 2024-10-28 03:23:05.518787 | CHIP:DMG         Active Retransmit Timeout = 300
CHIPTOOL   | 2024-10-28 03:23:05.519952 | CHIP:DMG     }
CHIPTOOL   | 2024-10-28 03:23:05.520909 | CHIP:DMG     ResumptionID (16) = 87E8BADA573AC14C7BC7CA7BD7199812
CHIPTOOL   | 2024-10-28 03:23:05.521828 | CHIP:DMG     InitiatorResumeMIC (16) = 7AFD853442E525543F39D5577B0E0A2F
CHIPTOOL   | 2024-10-28 03:23:05.526835 | CHIP:DMG }
CHIPTOOL   | 2024-10-28 03:23:05.528438 | CHIP:DMG  
CHIPTOOL   | 2024-10-28 03:23:05.529439 | CHIP:DMG  
CHIPTOOL   | 2024-10-28 03:23:05.530366 | CHIP:DMG Additional Fields =
CHIPTOOL   | 2024-10-28 03:23:05.533436 | CHIP:DMG {
CHIPTOOL   | 2024-10-28 03:23:05.534509 | CHIP:DMG     peer_address = UDP:[fd11:32::126e:ca00:83be:42ac]:5540
CHIPTOOL   | 2024-10-28 03:23:05.535546 | CHIP:DMG }
CHIPTOOL   | 2024-10-28 03:23:05.536542 | CHIP:DMG  
CHIPTOOL   | 2024-10-28 03:23:05.539770 | CHIP:EM <<< [E:41560i S:0 M:118767019] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fd11:32::126e:ca00:83be:42ac]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
CHIPTOOL   | 2024-10-28 03:23:05.540869 | CHIP:SC Sent Sigma1 msg
CHIPTOOL   | 2024-10-28 03:23:05.541801 | CHIP:DIS OperationalSessionSetup[1:234A1F168BB6AF5D]: State change 3 --> 4
WARNING    | 2024-10-28 03:23:05.545195 | Test Failure: The test expects no error but the "FAILURE" error occured.
INFO       | 2024-10-28 03:23:05.546664 | Test Step Completed [FAILED]: Step 1: TH1 commissions DUT using admin node ID N1
[TC-ACE-1.1.txt](https://github.com/user-attachments/files/17714090/TC-ACE-1.1.txt)

Steps to reproduce the behavior

No response

Expected behavior

No response

Log files

No response

PICS file

No response

Screenshots

No response

Environment

No response

Additional Information

No response

KEEPHEADU commented 1 week ago

TC-ACE-1.1.txt

Attach detailed log.