Repository navigation
Real-time Python test logs: include the output before the first test step - #393
Conversation
_extract_logs_for_step started each step's section at its marker, so text between the logging cursor and the marker was never logged: the setup output produced before Test Step 1 (about 28.8k of 52.7k lines for TC-ACE-1.3) and the output of any skipped step. _log_remaining_content only recovers what follows the last step, so nothing picked it up. Real-time mode therefore logged roughly half of what batch mode logged for the same test. Start the section at the cursor instead. When the marker sits at the cursor (the usual case) the section is unchanged. Refs project-chip/certification-tool#1119
|
No actionable comments were generated in the recent review. 🎉 ℹ️ Recent review info⚙️ Run configuration
📒 Files selected for processing (2)
Included review availability: This review used your included allowance. Your plan provides up to 1 included review per hour; 0 remain after this review. 📝 WalkthroughWalkthrough
Priority: ➖ Normal Merge Risk: ⚪ Minimal · up to No actionable issue is established; the change is mergeable subject to normal CI checks. Pre-merge checks |
|
|
This pull request does not currently match the merge queue conditions, so it cannot be queued from here. The box comes back if it matches again. |
|
Merge priority. Backend PR #398 (real-time Python test logs on by default) has been merged into |
What
In real-time Python test logging,
_extract_logs_for_step()now starts each step's section at the logging cursor instead of at the step's marker, so text between the cursor and the marker is no longer dropped.Why
The old code logged only from a step's marker to the next one, and
_log_remaining_content()only recovered what follows the last step. Everything printed before Step 1 (the test's setup output, ~28.8k lines for TC-ACE-1.3 on a 23-endpoint bridge) and the output of any skipped step was lost. Real-time mode logged ~24k entries against ~52.9k in batch mode for the same test. After the change both modes log the same content (17 runs: lines before Step 1 = 28.8k, ON vs OFF within 0.3%). When the marker is at the cursor, the usual case, the section is unchanged.Tests
3 new unit tests in
test_python_test_case.py: output before the first marker, output of a skipped step, and a whole-file-covered-exactly-once check; the existing cursor/label tests are untouched. The unit tests below were not run locally before opening this PR (they need the Docker/Postgres stack); CI will run them. Behaviour was also checked on a real device: TC-ACE-1.3 through the CLI on an Ubuntu test host.Notes
Independent of the other PRs under the umbrella #1119; it is a prerequisite for the "enable real-time logs by default" PR.
Closes #1166