[Bug] Logs are only sent at the end and truncated when running TC-IDM-10.2 from the TH UI.

[fabiowmm]

Describe the bug

The test run logs are not sent in real-time and are getting truncated.

Steps to reproduce the behavior

Just try to run TC-IDM-10.2 from TH.

Expected behavior

Logs dynamically generated as the test goes.

Log files

No response

PICS file

No response

Screenshots

No response

Environment

No response

Additional Information

No response

[tcarmelveilleux]

Added logs/details here:

Both in a complete fail case (due to saying "yes" to commission when not needed) and when saying "no" (but config error present), the logs were basically absent to know what was going on, in the UI.

There is >1 minute of logs completely missing:

PYTHON_TEST | 2024-08-12 23:38:39.380528 | [1723505919.201421][14:23] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
PYTHON_TEST | 2024-08-12 23:38:39.504612 | Didn't find any CertificateAuthorities in storage -- creating a new CertificateAuthority + FabricAdmin...
PYTHON_TEST | 2024-08-12 23:38:39.881359 | Long dispatch time: 353 ms, for event type 2

............ nothing between these 2 lines, but lots would have happened...

PYTHON_TEST | 2024-08-12 23:39:14.018592 | Shutting down the stack...
PYTHON_TEST | 2024-08-12 23:39:14.036823 | ERROR:root:Final result: FAIL !
ERROR      | 2024-08-12 23:39:14.663678 | Test Case Error: Error occurred during setup of test case TC_IDM_10_2. Failed to commission DUT
INFO       | 2024-08-12 23:39:14.665845 | Test Cleanup
INFO       | 2024-08-12 23:39:14.667642 | Test Case Completed [ERROR]: TC-IDM-10.2

For the case where there was some running, it claimed that the test passed when it failed, and the logs from the Python test were completely unusable in the UI, but were OK in the file downloaded afterwards, although most of the chip stack logs are missing.

SAYS_PASS_BUT_LOGS_CORRUPT_UI_Test_Run_2024_08_12_23_40_30.log

FAIL_WITH_NO_LOGS___UI_Test_Run_2024_08_12_23_38_21.log

[rquidute]

The following issues have been created for the listed problems:
[Bug] TH logs do not include line breaks: #356
[Bug] TH does not commission the DUT when qr-code parameter is set: #358
[Feature] Add real-time log streaming from test in TH: #345

[rquidute]

Hi @tcarmelveilleux I'm investigating the issue related to the logs lines that are missing.

I performed the test TC-IDM-10.2 both in TH and inside docker container
Looking at the logs I was not able to identify the missing logs line.
Am I missing something?

I'm using a new SDK SHA: c4a5a95348c66f60a5a33e6ff0389e949589aaa6

Execution with DUT Commissioned

• TH (Should the DUT be commissioned to run this test case? YES ): TC-IDM-10.2 - TH Commissioned YES.log

• Container: Using this command in order to Commission the DUT: python3 /root/python_testing/scripts/sdk/test_harness_client.py commission --trace-to json:log --commissioning-method on-network --qr-code MT:-24J042C00KA0648G00 TC-IDM-10.2 - Container Commissioned YES.log

Run command: python3 /root/python_testing/scripts/sdk/test_harness_client.py sdk/TC_DeviceConformance TC_DeviceConformance --tests test_TC_IDM_10_2 --trace-to json:log --qr-code MT:-24J042C00KA0648G00 --PICS /var/tmp/pics

Execution DUT NOT Commissioned:

• TH (Should the DUT be commissioned to run this test case? NO): TC-IDM-10.2 - TH Commissioned NO.log

• Container: TC-IDM-10.2 - Container Commissioned NO.log

Run command: python3 /root/python_testing/scripts/sdk/test_harness_client.py sdk/TC_DeviceConformance TC_DeviceConformance --tests test_TC_IDM_10_2 --trace-to json:log --qr-code MT:-24J042C00KA0648G00 --PICS /var/tmp/pics

Project Config: Project_Config.json

[rquidute]

Sharing the TH execution logs using the TE2 SDK SHA: d0d91272068f267cf880f9d56787ca28da885673

TC-IDM-10.2 - TH Commissioned YES (2): TC-IDM-10.2 - TH Commissioned YES (2).log

TC-IDM-10.2 - TH Commissioned NO (2): TC-IDM-10.2 - TH Commissioned NO (2).log

[rquidute]

Hi @tcarmelveilleux Gentle reminder, did you get the chance to analyze my 2 last comments above?