Problem
Pytest's documentation states (emphasis mine)
specify --log-cli-format and --log-cli-date-format which mirror and default to --log-format and --log-date-format if not provided, but are applied only to the console logging handler
[...]
--log-file-format and --log-file-date-format which are equal to --log-format and --log-date-format but are applied to the log file logging handler
This works as intended with the --log-cli-... options: When I have a pytest.ini file with log_cli = true and run pytest --log-format "%(message)s" the console uses the specified format, even though I did not specify --log-cli-format, but the more general --log-format.
For the --log-file-... options, I interpreted the wording "equal" just the same as I interpreted "mirror and default to", so I was very surprised that pytest --log-file log.txt --log-format "%(message)s" did not change the log format of log.txt.
I debugged into _pytest and found that the option is queried using log_file_format = get_option_ini(config, "log_file_format", "log_format") which indicates that my interpretation of the documentation is the intended behavior. However, contrary to log_cli_format, the log_file_format option is defined with a default=DEFAULT_LOG_FORMAT. This causes get_option_ini to return the default for log_file_format in every case. The additionally specified fallback log_format is never checked.
From git blame it seems the commit "Merge the pytest-catchlog plugin" introduced the bug (?) 6 years ago, affecting every version from 3.3.0 till today (). But as the name suggests, that commit did not really change the code, but only directly included it into the _pytest project. So the bug is even older than that.
Minimal Reproducible Example
Here is a minimal script reproduce the unexpected behavior. I used Python 3.9 on Windows 10, but that should be irrelevant here.
Create an empty directory and add a file test_logging.py with content
import logging
def test_format():
logging.error('my message')
Then run this powershell script in that directory. You should be able to run this script with minimal changes in a posix sh shell on Linux too (e.g. python3 instead of python and source venv/bin/activate instead of venv/Scripts/activate).
python -m venv venv
venv\Scripts\activate
pip install pytest
pip freeze
pytest --log-file log.txt --log-format "%(message)s"
type log.txt
This is the relevant output from pytest freeze
colorama==0.4.6
exceptiongroup==1.1.3
iniconfig==2.0.0
packaging==23.1
pluggy==1.2.0
pytest==7.4.0
tomli==2.0.1
and type log.txt:
ERROR root:test_logging.py:3 my message
As you can see, the custom log format wasn't used for the file. Instead, pytest's DEFAULT_LOG_FORMAT was used.
When I specify --log-file-format "%(message)s instead, I get the expected log.txt:
Solution
Remove the default value for --log-file-format so that it falls back to --log-format and only uses the default format if neither of them are defined. Same for --log-file-date-format.
If you want to do it like this, I can create a pull request for you. I only created this issue first, in case you wanted to keep the behavior; see below:
Alternative: officially declare the bug as a feature, update the documentation, and remove the dead fallbacks to the general log_format/log_date_format options from the code.
I would be really sad if you went with the latter option. But it would be understandable, because the bug is ancient and I couldn't find any complains about this yet.
Problem
Pytest's documentation states (emphasis mine)
This works as intended with the
--log-cli-...options: When I have a pytest.ini file withlog_cli = trueand runpytest --log-format "%(message)s"the console uses the specified format, even though I did not specify--log-cli-format, but the more general--log-format.For the
--log-file-...options, I interpreted the wording "equal" just the same as I interpreted "mirror and default to", so I was very surprised thatpytest --log-file log.txt --log-format "%(message)s"did not change the log format oflog.txt.I debugged into _pytest and found that the option is queried using
log_file_format = get_option_ini(config, "log_file_format", "log_format")which indicates that my interpretation of the documentation is the intended behavior. However, contrary tolog_cli_format, thelog_file_formatoption is defined with adefault=DEFAULT_LOG_FORMAT. This causesget_option_inito return the default forlog_file_formatin every case. The additionally specified fallbacklog_formatis never checked.From git blame it seems the commit "Merge the pytest-catchlog plugin" introduced the bug (?) 6 years ago, affecting every version from 3.3.0 till today (). But as the name suggests, that commit did not really change the code, but only directly included it into the _pytest project. So the bug is even older than that.
Minimal Reproducible Example
Here is a minimal script reproduce the unexpected behavior. I used Python 3.9 on Windows 10, but that should be irrelevant here.
Create an empty directory and add a file
test_logging.pywith contentThen run this powershell script in that directory. You should be able to run this script with minimal changes in a posix sh shell on Linux too (e.g.
python3instead ofpythonandsource venv/bin/activateinstead ofvenv/Scripts/activate).This is the relevant output from
pytest freezeand
type log.txt:As you can see, the custom log format wasn't used for the file. Instead, pytest's
DEFAULT_LOG_FORMATwas used.When I specify
--log-file-format "%(message)sinstead, I get the expectedlog.txt:Solution
Remove the default value for
--log-file-formatso that it falls back to--log-formatand only uses the default format if neither of them are defined. Same for--log-file-date-format.If you want to do it like this, I can create a pull request for you. I only created this issue first, in case you wanted to keep the behavior; see below:
Alternative: officially declare the bug as a feature, update the documentation, and remove the dead fallbacks to the general
log_format/log_date_formatoptions from the code.I would be really sad if you went with the latter option. But it would be understandable, because the bug is ancient and I couldn't find any complains about this yet.