Skip to content

Split the system tests log file into stages#801

Open
PranjalManhgaye wants to merge 10 commits into
precice:developfrom
PranjalManhgaye:issue-790-system-tests-logs
Open

Split the system tests log file into stages#801
PranjalManhgaye wants to merge 10 commits into
precice:developfrom
PranjalManhgaye:issue-790-system-tests-logs

Conversation

@PranjalManhgaye
Copy link
Copy Markdown
Collaborator

Description

Fixes #790.
Right now, system-tests-stdout.log and system-tests-stderr.log only appear after a test finishes, which makes it hard to inspect failures during long Docker builds or solver runs.
This PR changes the logging so output is written to disk while the test is running. The existing combined logs are still kept, but there are now also separate phase logs:

  • system-tests-build.log
  • system-tests-solver.log
  • system-tests-fieldcompare.log

Scope: 4 files only (~350 LOC). No tutorial or reference-result changes.
Largest change: streaming Docker output in Systemtest.py (replaces communicate() buffering).
I also cleaned up the console output a bit:

  • [n/m] progress prefix
  • less noisy logging (INFO: removed)
  • clearer grouping/banners
  • PASS / FAIL markers on TTY
    The PR is split into 4 commits so the logging change can be reviewed separately from the console formatting cleanup.

Checklist

  • I added a summary of any user-facing changes (compared to the last release) in the changelog-entries/<PRnumber>.md.
  • New tutorial case (e.g., new fluid-openfoam folder for existing tutorial)? Add it to the respective README.md.
  • New tutorial? Update the website.

Resources

Write build, solver, and fieldcompare output incrementally to
system-tests-stdout.log and system-tests-stderr.log, and add phase
logs (system-tests-build.log, -solver.log, -fieldcompare.log) so
failures can be debugged before a test finishes. Extend CI artifact
globs for the new log files.

Fixes the log-file part of precice#790.
Drop INFO prefix on routine log lines, put test index at the start of
start/finish messages, and add blank lines between tests for easier
scanning in CI and local runs.

Addresses the console formatting part of precice#790.
@PranjalManhgaye
Copy link
Copy Markdown
Collaborator Author

PranjalManhgaye commented May 27, 2026

passed (17/17), but the console output still looks like the old style, is this workflow expected to run with develop runner scripts, so formatting changes from this PR may not appear there?

@MakisH
Copy link
Copy Markdown
Member

MakisH commented May 27, 2026

@PranjalManhgaye I am not sure if this is currently documented (please check), but the trigger-system-tests does not take the tools/tests/ from the PR branch. This is often misleading when testing changes to the system tests scripts.

By the way, I think this PR can use a more descriptive title. How about "Split the system tests log file into stages"?

Do not forget to update the documentation and the hints in the workflow files (look for the original file name).

@PranjalManhgaye PranjalManhgaye changed the title Issue 790 system tests logs Split the system tests log file into stages May 27, 2026
Document combined and per-stage system test logs in README and job summary hints, and clarify workflow artifact step names to reflect staged log files.
@PranjalManhgaye PranjalManhgaye requested a review from MakisH May 31, 2026 09:44
Copy link
Copy Markdown
Member

@MakisH MakisH left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice job!

Running locally, I get the following example output (plus the respective files):

$ python systemtests.py --suites="elastic-tube-1d" --build_args="TUTORIALS_REF:develop,PYTHON_BINDINGS_REF:develop"

Using log-level: INFO
WARNING: No argument provided for needed parameter PRECICE_REF. Substituting with main
WARNING: No argument provided for needed parameter PLATFORM. Substituting with ubuntu_2404
WARNING: No argument provided for needed parameter PRECICE_PRESET. Substituting with production-audit
About to run 5 systemtest(s) in the directory /home/gc/repos/precice/tutorials/runs:
 [Elastic tube 1D (fluid-cpp, solid-cpp), Elastic tube 1D (fluid-cpp, solid-python), Elastic tube 1D (fluid-fortran, solid-fortran), Elastic tube 1D (fluid-fortran-module, solid-fortran-module), Elastic tube 1D (fluid-python, solid-python)]

================================================================================
[1/5] Started Elastic tube 1D (fluid-cpp, solid-cpp)
From github.com:PranjalManhgaye/tutorials
 * branch              issue-790-system-tests-logs -> FETCH_HEAD
Docker compose build for Elastic tube 1D (fluid-cpp, solid-cpp)
Docker compose solver for Elastic tube 1D (fluid-cpp, solid-cpp)
Docker compose fieldcompare for Elastic tube 1D (fluid-cpp, solid-cpp)
[1/5] Finished Elastic tube 1D (fluid-cpp, solid-cpp) in 24.5s [✅ PASS]
================================================================================

================================================================================
[2/5] Started Elastic tube 1D (fluid-cpp, solid-python)
From github.com:PranjalManhgaye/tutorials
 * branch              issue-790-system-tests-logs -> FETCH_HEAD
Overwrote <max-time> to 0.1 in /home/gc/repos/precice/tutorials/runs/elastic-tube-1d_fluid-cpp-solid-python_2026-05-31-230350/precice-config.xml
Docker compose build for Elastic tube 1D (fluid-cpp, solid-python)
Docker compose solver for Elastic tube 1D (fluid-cpp, solid-python)
CRITICAL: Systemtest Elastic tube 1D (fluid-cpp, solid-python) timed out during docker compose solver after 900s. Killing the process.
CRITICAL: Could not run the tutorial, Elastic tube 1D (fluid-cpp, solid-python) failed
[2/5] Finished Elastic tube 1D (fluid-cpp, solid-python) in 957.6s [❌ FAIL]
================================================================================

================================================================================
[3/5] Started Elastic tube 1D (fluid-fortran, solid-fortran)
From github.com:PranjalManhgaye/tutorials
 * branch              issue-790-system-tests-logs -> FETCH_HEAD
Docker compose build for Elastic tube 1D (fluid-fortran, solid-fortran)
Docker compose solver for Elastic tube 1D (fluid-fortran, solid-fortran)
Docker compose fieldcompare for Elastic tube 1D (fluid-fortran, solid-fortran)
[3/5] Finished Elastic tube 1D (fluid-fortran, solid-fortran) in 20.6s [✅ PASS]
================================================================================

================================================================================
[4/5] Started Elastic tube 1D (fluid-fortran-module, solid-fortran-module)
From github.com:PranjalManhgaye/tutorials
 * branch              issue-790-system-tests-logs -> FETCH_HEAD
Docker compose build for Elastic tube 1D (fluid-fortran-module, solid-fortran-module)
Docker compose solver for Elastic tube 1D (fluid-fortran-module, solid-fortran-module)
Docker compose fieldcompare for Elastic tube 1D (fluid-fortran-module, solid-fortran-module)
[4/5] Finished Elastic tube 1D (fluid-fortran-module, solid-fortran-module) in 26.1s [✅ PASS]
================================================================================

================================================================================
[5/5] Started Elastic tube 1D (fluid-python, solid-python)
From github.com:PranjalManhgaye/tutorials
 * branch              issue-790-system-tests-logs -> FETCH_HEAD
Docker compose build for Elastic tube 1D (fluid-python, solid-python)
Docker compose solver for Elastic tube 1D (fluid-python, solid-python)
Docker compose fieldcompare for Elastic tube 1D (fluid-python, solid-python)
CRITICAL: Fieldcompare returned non zero exit code, therefore Elastic tube 1D (fluid-python, solid-python) failed
[5/5] Finished Elastic tube 1D (fluid-python, solid-python) in 12.2s [❌ FAIL]
================================================================================

Success running Elastic tube 1D (fluid-cpp, solid-cpp)
ERROR: Failed to run Elastic tube 1D (fluid-cpp, solid-python)
Success running Elastic tube 1D (fluid-fortran, solid-fortran)
Success running Elastic tube 1D (fluid-fortran-module, solid-fortran-module)
ERROR: Failed to run Elastic tube 1D (fluid-python, solid-python)
+----------------------------------------------------------------+---------+-------------------+-----------------+-----------------------+
| systemtest                                                     | success | building time [s] | solver time [s] | fieldcompare time [s] |
+----------------------------------------------------------------+---------+-------------------+-----------------+-----------------------+
| Elastic tube 1D (fluid-cpp, solid-cpp)                         |    1    |        0.5        |      14.9       |          5.6          |
+----------------------------------------------------------------+---------+-------------------+-----------------+-----------------------+
| Elastic tube 1D (fluid-cpp, solid-python)                      |    0    |       43.7        |      910.2      |          0.0          |
+----------------------------------------------------------------+---------+-------------------+-----------------+-----------------------+
| Elastic tube 1D (fluid-fortran, solid-fortran)                 |    1    |        0.4        |      10.2       |          6.6          |
+----------------------------------------------------------------+---------+-------------------+-----------------+-----------------------+
| Elastic tube 1D (fluid-fortran-module, solid-fortran-module)   |    1    |        1.1        |      14.1       |          4.8          |
+----------------------------------------------------------------+---------+-------------------+-----------------+-----------------------+
| Elastic tube 1D (fluid-python, solid-python)                   |    0    |        1.3        |       4.4       |          2.5          |
+----------------------------------------------------------------+---------+-------------------+-----------------+-----------------------+

Since you are touching the general formatting of the logs:

  • For the header, I think that listing the tests to run as an enumeration would be useful to vertically scan them.
  • I would also display the test suites to run.
  • Before the summary table, I would leave an empty line.

Suggested format (the argument warnings depend on the tests to run):

Selected test suite(s):

- elastic-tube-1d

About to run 5 test(s) in the directory /home/gc/repos/precice/tutorials/runs:

1. Elastic tube 1D (fluid-cpp, solid-cpp)
2. Elastic tube 1D (fluid-cpp, solid-python)
3. Elastic tube 1D (fluid-fortran, solid-fortran)
4. Elastic tube 1D (fluid-fortran-module, solid-fortran-module)
5. Elastic tube 1D (fluid-python, solid-python)]

WARNING: No argument provided for needed parameter PRECICE_REF. Substituting with main
WARNING: No argument provided for needed parameter PLATFORM. Substituting with ubuntu_2404
WARNING: No argument provided for needed parameter PRECICE_PRESET. Substituting with production-audit
Using log-level: INFO

I also tested this on GitHub Actions, here: https://github.com/precice/tutorials/actions/runs/26725804527

Comment thread .github/workflows/generate_reference_results_workflow.yml Outdated
Comment thread .github/workflows/run_testsuite_workflow.yml Outdated
Comment thread changelog-entries/801.md Outdated
Comment thread tools/tests/systemtests/Systemtest.py Outdated
Comment thread tools/tests/systemtests.py Outdated
Comment thread tools/tests/systemtests/Systemtest.py
Comment thread tools/tests/systemtests.py Outdated
Comment thread tools/tests/systemtests.py
Comment on lines +60 to +61
if gh_actions:
print(f"::group::{title}")
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice feature, maybe we can use it elsewhere as well.
I have not yet seen how it looks on GitHub Actions.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

However, on GitHub Actions, the grouping appears strange and in the end:

Screenshot from 2026-06-01 00-08-28

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

the ==== banners were fighting ::group:: on Actions, so you got empty folds at the end , I dropped the banners on GHA and made sure every group closes in a finally , If it still looks off on the next run , I can turn grouping off on Actions and keep it local only

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Another run: https://github.com/precice/tutorials/actions/runs/26750224389/job/78836049633

The groups still look wrong. I think the idea is nice, it just needs some tweaking. Note that the pass/fail should be visible without having to expand the group.

The === are not needed, the empty line in between is already clear enough.

Screenshot from 2026-06-01 12-53-19

Comment thread tools/tests/systemtests.py Outdated
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Before printing the success/fail summary , an empty line would be good:

Image

Comment on lines +132 to +135
if result.success:
status_label = _style("✅ PASS", 32)
else:
status_label = _style("❌ FAIL", 31)
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These status symbols could also be added to the table:

Image

(also in the job summary)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

System tests logs appear only at the end

2 participants