Update default output formatting for pytest CI

[ischoegl]

Problem description

The changes of CI introduced with #1020 create some overly verbose output even for short tests. While the changes to the progress bar per se are ok (alternative would be to pass -v so output resembles old style), some of the timing/logging information should not be displayed by default. Note: pytest also respects settings in configuration files.

Steps to reproduce

This is one of the shorter tests within the test suite ...

docker@xps13:/src$ scons test-python-reaction
scons: Reading SConscript files ...
[...]
============================================== test session starts ===============================================
platform linux -- Python 3.6.9, pytest-3.3.2, py-1.5.2, pluggy-0.6.0
rootdir: /src, inifile:
collected 33 items                                                                                               

../../build/python/cantera/test/test_reaction.py .................................                         [100%]

--------------------------------- generated xml file: /src/test/work/pytest.xml ----------------------------------
=========================================== slowest 50 test durations ============================================
0.04s setup    build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_duplicate
0.02s call     build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_duplicate
0.01s setup    build/python/cantera/test/test_reaction.py::TestElementary::test_add_rxn
0.00s setup    build/python/cantera/test/test_reaction.py::TestElementaryNew::test_add_rxn
0.00s setup    build/python/cantera/test/test_reaction.py::TestCustom::test_add_rxn
0.00s call     build/python/cantera/test/test_reaction.py::TestElementaryNew::test_add_rxn
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_from_dict
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_no_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestElementary::test_add_rxn
0.00s call     build/python/cantera/test/test_reaction.py::TestElementaryNew::test_replace_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_replace_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestElementary::test_from_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestElementary::test_from_dict
0.00s call     build/python/cantera/test/test_reaction.py::TestElementaryNew::test_from_dict
0.00s call     build/python/cantera/test/test_reaction.py::TestElementaryNew::test_no_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestElementary::test_replace_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestElementary::test_from_parts
0.00s call     build/python/cantera/test/test_reaction.py::TestElementaryNew::test_from_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_from_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_custom
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_from_func
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_add_rxn
0.00s call     build/python/cantera/test/test_reaction.py::TestElementary::test_no_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_implicit_three_body
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_from_parts
0.00s call     build/python/cantera/test/test_reaction.py::TestElementaryNew::test_from_parts
0.00s teardown build/python/cantera/test/test_reaction.py::TestElementary::test_from_dict
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_wrong_rate
0.00s teardown build/python/cantera/test/test_reaction.py::TestElementary::test_from_rate
0.00s teardown build/python/cantera/test/test_reaction.py::TestCustom::test_from_dict
0.00s teardown build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_duplicate
0.00s teardown build/python/cantera/test/test_reaction.py::TestCustom::test_from_rate
0.00s call     build/python/cantera/test/test_reaction.py::TestCustom::test_rate
0.00s teardown build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_implicit_three_body
0.00s call     build/python/cantera/test/test_reaction.py::TestElementary::test_wrong_rate
0.00s teardown build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_not_three_body
0.00s setup    build/python/cantera/test/test_reaction.py::TestCustom::test_rate
0.00s teardown build/python/cantera/test/test_reaction.py::TestElementaryNew::test_add_rxn
0.00s teardown build/python/cantera/test/test_reaction.py::TestCustom::test_custom
0.00s setup    build/python/cantera/test/test_reaction.py::TestCustom::test_from_dict
0.00s call     build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_short_serialization
0.00s teardown build/python/cantera/test/test_reaction.py::TestElementaryNew::test_from_parts
0.00s teardown build/python/cantera/test/test_reaction.py::TestElementary::test_rate
0.00s teardown build/python/cantera/test/test_reaction.py::TestElementary::test_from_parts
0.00s teardown build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_user_override
0.00s teardown build/python/cantera/test/test_reaction.py::TestElementaryNew::test_from_rate
0.00s teardown build/python/cantera/test/test_reaction.py::TestElementary::test_add_rxn
0.00s teardown build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_short_serialization
0.00s teardown build/python/cantera/test/test_reaction.py::TestElementaryNew::test_no_rate
0.00s teardown build/python/cantera/test/test_reaction.py::TestCustom::test_add_rxn
===================================================== PASSES =====================================================
______________________________________ TestImplicitThirdBody.test_duplicate ______________________________________
_________________________________ TestImplicitThirdBody.test_implicit_three_body _________________________________
_________________________________ TestImplicitThirdBody.test_non_integer_stoich __________________________________
___________________________________ TestImplicitThirdBody.test_not_three_body ____________________________________
_________________________________ TestImplicitThirdBody.test_short_serialization _________________________________
____________________________________ TestImplicitThirdBody.test_user_override ____________________________________
__________________________________________ TestElementary.test_add_rxn ___________________________________________
_________________________________________ TestElementary.test_from_dict __________________________________________
_________________________________________ TestElementary.test_from_parts _________________________________________
_________________________________________ TestElementary.test_from_rate __________________________________________
__________________________________________ TestElementary.test_no_rate ___________________________________________
____________________________________________ TestElementary.test_rate ____________________________________________
________________________________________ TestElementary.test_replace_rate ________________________________________
_________________________________________ TestElementary.test_wrong_rate _________________________________________
____________________________________________ TestCustom.test_add_rxn _____________________________________________
_____________________________________________ TestCustom.test_custom _____________________________________________
___________________________________________ TestCustom.test_from_dict ____________________________________________
___________________________________________ TestCustom.test_from_func ____________________________________________
___________________________________________ TestCustom.test_from_parts ___________________________________________
___________________________________________ TestCustom.test_from_rate ____________________________________________
____________________________________________ TestCustom.test_no_rate _____________________________________________
______________________________________________ TestCustom.test_rate ______________________________________________
___________________________________________ TestCustom.test_rate_func ____________________________________________
__________________________________________ TestCustom.test_replace_rate __________________________________________
___________________________________________ TestCustom.test_wrong_rate ___________________________________________
_________________________________________ TestElementaryNew.test_add_rxn _________________________________________
________________________________________ TestElementaryNew.test_from_dict ________________________________________
_______________________________________ TestElementaryNew.test_from_parts ________________________________________
________________________________________ TestElementaryNew.test_from_rate ________________________________________
_________________________________________ TestElementaryNew.test_no_rate _________________________________________
__________________________________________ TestElementaryNew.test_rate ___________________________________________
______________________________________ TestElementaryNew.test_replace_rate _______________________________________
_______________________________________ TestElementaryNew.test_wrong_rate ________________________________________
=========================================== 33 passed in 0.12 seconds ============================================
scons: done building targets.

System information

• Cantera version: 2.6.0a2

Other thoughts

I should have noticed this earlier ...

[speth]

That output is quite different from what I get, using the latest version of pytest:

====================================================== test session starts =======================================================
platform linux -- Python 3.8.3, pytest-6.2.3, py-1.10.0, pluggy-0.13.1
rootdir: /home/speth/src/cantera
plugins: github-actions-annotate-failures-0.1.2
collected 33 items                                                                                                               

../../build/python/cantera/test/test_reaction.py .................................                                         [100%]

============================================================= PASSES =============================================================
-------------------------------- generated xml file: /home/speth/src/cantera/test/work/pytest.xml --------------------------------
====================================================== slowest 50 durations ======================================================
0.17s setup    build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_duplicate
0.07s call     build/python/cantera/test/test_reaction.py::TestImplicitThirdBody::test_duplicate
0.02s setup    build/python/cantera/test/test_reaction.py::TestElementary::test_add_rxn
0.02s setup    build/python/cantera/test/test_reaction.py::TestCustom::test_add_rxn
0.01s setup    build/python/cantera/test/test_reaction.py::TestElementaryNew::test_add_rxn

(45 durations < 0.005s hidden.  Use -vv to show these durations.)
======================================================= 33 passed in 0.70s =======================================================

(eliding the other output that's not related to pytest).

The Pytest version you're using is a little old (2017). As you mentioned configuration file settings, do you have any present that might be affecting this?

The options that I set it up to run with (-raP) shouldn't print anything about tests that succeed and don't generate any output. And as the output inidicates, durations should only be reported for tests that take more than 5 ms, although there is a note to say that something about the --durations option changed in version 6.0.0.

[ischoegl]

I keep a pretty 'vanilla' tool chain on purpose, so there aren't any configuration options (that I am aware of). I had some suspicions that it may have been system python (again), but the same output shows up for (system) python3.

[ischoegl]

I am attaching a more complete log for the entire test suite, see pytest.log (relevant portion starts around line 1033). There appear to be some differences based on the pytest version. Beyond, I have the following comments:

• I believe passing the -v option to pytest may be nicer than the progress bar
• timing information is not something most users are interested in, so it should only be provided if scons has a suitable flag set

Beyond, I get a lot of logging information from cti2yaml that may be confusing to most; however, this may be specific to my pytest version. (Edit: it is displayed by regular CI also)

[ischoegl]

Switching from system pytest to the version installed by pip takes care of the odd output formatting.

Remaining output formatting quibbles are addressed by #1034 (except for the logging output for cti2yaml from test_convert.py, which may or may not be a feature).