Skip to content

Real-time Python test logs: include the output before the first test step - #393

Merged
rquidute merged 1 commit into
project-chip:v2.16-developfrom
rquidute:fix/1166-realtime-log-pre-step-gap
Oct 13, 2026
Merged

rquidute merged 1 commit into
project-chip:v2.16-developfrom
rquidute:fix/1166-realtime-log-pre-step-gap

Conversation

@rquidute

@rquidute rquidute commented Oct 9, 2026

Copy link
Copy Markdown
Contributor

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

_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
@coderabbitai

coderabbitai Bot commented Oct 9, 2026 •

Copy link
Copy Markdown

Review in Change Stack →

No actionable comments were generated in the recent review. 🎉

ℹ️ Recent review info
⚙️ Run configuration
  • Configuration used: Organization UI
  • Review profile: CHILL
  • Plan: Advanced
  • Run ID: 8f96d74f-dc97-4021-b435-71d136700508

📥 Commits

Reviewing files that changed from the base of the PR and between ce3ccc8 and 6eb1f80.


📒 Files selected for processing (2)
  • test_collections/matter/sdk_tests/support/python_testing/models/test_case.py
  • test_collections/matter/sdk_tests/support/tests/python_tests/test_python_test_case.py

Included review availability: This review used your included allowance. Your plan provides up to 1 included review per hour; 0 remain after this review.



📝 Walkthrough

Walkthrough

PythonTestCase._extract_logs_for_step now extracts output from the last logged position through the next step marker, or through the end of the file. Regression tests cover setup output before the first marker, output associated with skipped steps, and ordered extraction without missing or duplicate expected lines.


Priority: ➖ Normal

Merge Risk: ⚪ Minimal · up to 6eb1f

No actionable issue is established; the change is mergeable subject to normal CI checks.

Pre-merge checks | Passed 5
✅ Passed checks (5 passed)
Check name Status Explanation
Title check Passed The title clearly identifies the main change: preserving output before the first Python test step in real-time logs.
Description check Passed The description directly explains the logging change, the lost output, the tests, and the reported validation results.
Docstring Coverage Passed Docstring coverage is 100.00% which is sufficient. The required threshold is 80.00%. Docstring coverage is scoped to functions touched by this diff. Analyzed 6 functions across 2 files.
Linked Issues check Passed Check skipped because no linked issues were found for this pull request.
Out of Scope Changes check Passed Check skipped because no linked issues were found for this pull request.


  • Autofix · Keep fixing CodeRabbit findings and required CI, and resolving merge conflicts

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands.

@mergify

mergify Bot commented Oct 9, 2026 •

Copy link
Copy Markdown

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.

@rquidute
rquidute requested a review from antonio-amjr October 9, 2026 22:30
@rquidute rquidute self-assigned this Oct 9, 2026
@rquidute

Copy link
Copy Markdown
Contributor Author

Merge priority. Backend PR #398 (real-time Python test logs on by default) has been merged into v2.16-develop, and it depends on this PR. Until this one lands, the default real-time mode drops everything the test prints before Step 1 (e.g. ~28.8k of ~52.7k lines for TC-ACE-1.3). This PR is clean and all checks pass; merging it next closes that gap.

@rquidute
rquidute merged commit 224cbf9 into project-chip:v2.16-develop Oct 13, 2026
9 checks passed
@rquidute
rquidute deleted the fix/1166-realtime-log-pre-step-gap branch October 13, 2026 17:35
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants