search

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
26 stars 13 forks source link

[TC-DGGEN-2.1] Semi auto - Test case is failing after test step 10a due to unexpected error #39

Open raju-apple opened 8 months ago

raju-apple commented 8 months ago

From chip-certification-tool created by Rajashreekalmane: CHIP-Specifications/chip-certification-tool#948

Describe the bug

[TC-DGGEN-2.1] Semi auto - Test case is failing after test step 10a due to unexpected error

CHIP:TOO TotalOperationalHours: 0 Test Step Completed [PASSED]: Step 10a: TH reads the TotalOperationalHours attribute from the DUT. Store the value in operational_hours1. Executing Test Step: Wait for 2 hours and 5 minutes. Test Step Completed [PASSED]: Wait for 2 hours and 5 minutes. Executing Test Step: Step 10a: TH reads the TotalOperationalHours attribute from the DUT. Verify that operational_hours2 is greater than operational_hours1. Test Step Error: Error occurred during execution of test case TC-DGGEN-2.1. no close frame received or sent Test Step Completed [ERROR]: Step 10a: TH reads the TotalOperationalHours attribute from the DUT. Verify that operational_hours2 is greater than operational_hours1. Test Case Completed[ERROR]: TC-DGGEN-2.1 (Semi-automated) Unpairing chip_tool from device

PFA screenshot below

image

Steps to reproduce the behavior

Environment Version: TH Fall2023 Sha: 58a51bef

Log files

DGGEN.txt

PICS file

General Diagnostics Cluster Test Plan.txt

raju-apple commented 8 months ago

Still facing the same issue in latest Image.

PFA log below : image

Environment Version: TH Fall2023 Sha: 3f84bff5

Log : UI_Test_Run_2023_10_06_12_51_12.log

ccruzagralopes commented 8 months ago

I was not able to get to the bottom of this issue, but here is what I got so far:

After the waiting step that lasts +2h, the web socket used to connect to the chip-tool binary running in the SDK image sends a keep alive ping that is timing out.

The odd thing is that, according to the debug logs, the timeout is happening less than 1 second after sending the ping. And the pong is received right after failing the connection.

DEBUG    | 2023-11-01 15:49:44.862 | websockets.legacy.protocol:keepalive_ping:1262 | % sending keepalive ping
DEBUG    | 2023-11-01 15:49:44.867 | websockets.legacy.protocol:write_frame_sync:1178 | > PING ec 0e f1 e9 [binary, 4 bytes]
DEBUG    | 2023-11-01 15:49:44.876 | websockets.legacy.protocol:keepalive_ping:1262 | % sending keepalive ping
DEBUG    | 2023-11-01 15:49:44.881 | websockets.legacy.protocol:write_frame_sync:1178 | > PING d1 44 3a 20 [binary, 4 bytes]
DEBUG    | 2023-11-01 15:49:44.946 | websockets.legacy.protocol:fail_connection:1412 | ! failing connection with code 1006
DEBUG    | 2023-11-01 15:49:44.948 | websockets.legacy.protocol:connection_lost:1497 | = connection is CLOSED
DEBUG    | 2023-11-01 15:49:44.963 | websockets.legacy.protocol:read_frame:1172 | < PONG d1 44 3a 20 [binary, 4 bytes]
DEBUG    | 2023-11-01 15:49:44.969 | app.test_engine.test_db_observer:dispatch:54 | Received Dispatch event
DEBUG    | 2023-11-01 15:49:44.973 | app.test_engine.test_db_observer:__onTestRunUpdate:66 | Test Run Observer received
DEBUG    | 2023-11-01 15:49:44.995 | app.test_engine.test_ui_observer:dispatch:47 | Received Dispatch event
DEBUG    | 2023-11-01 15:49:45.001 | app.test_engine.test_ui_observer:__onTestRunUpdate:59 | Test Run Observer received
DEBUG    | 2023-11-01 15:50:20.197 | websockets.legacy.protocol:write_frame_sync:1178 | > TEXT '{"type": "test_log_records", "payload": [{"leve...execution_index": 33}]}' [586 bytes]
DEBUG    | 2023-11-01 15:50:20.200 | websockets.legacy.protocol:keepalive_ping:1272 | ! timed out waiting for keepalive pong
DEBUG    | 2023-11-01 15:50:20.201 | websockets.legacy.protocol:fail_connection:1412 | ! failing connection with code 1011
DEBUG    | 2023-11-01 15:50:20.202 | websockets.legacy.protocol:fail_connection:1436 | = connection is CLOSING
DEBUG    | 2023-11-01 15:50:20.203 | websockets.legacy.protocol:write_frame_sync:1178 | > CLOSE 1011 (internal error) keepalive ping timeout [24 bytes]
ERROR    | 2023-11-01 15:50:20.212 | app.test_engine.models.test_step:record_error:51 | Test Step Error: Error occurred during execution of test case TC-DGGEN-2.1. no close frame received or sent

TC-DGGEN-2.1_DEBUG.log

Since this is only impacting one test case and it can be performed outside TH, I'm moving to a higher priority issue.

Rajashreekalmane commented 6 months ago

Still facing the same issue in latest Image.

PFA log below : image

Environment Version: main - dev Sha: f17ef

Log : UI_Test_Run_2023_12_14_11_10_56.log c4

Rajashreekalmane commented 4 months ago

Still we are facing the same issue in latest Image Version: 2.10-beta3+spring2024 Sha: 1fd1429

image

PFA Execution Log UI_Test_Run_2024_02_26_13_00_33(1).log

Yinxq commented 4 months ago

Hi, @Rajashreekalmane, we are experiencing the same problem, has this been solved? Our solution now is to write a sh file to run these test commands.

Rajashreekalmane commented 2 weeks ago

Still I am facing the same issue in latest image. Image version and SHA :
Version: 2.10.1+spring2024 Sha: 432d504