Skip to content

log_file_format does not default to log_format #11314

@schaetzc

Description

@schaetzc

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:

my message

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.

Metadata

Metadata

Assignees

No one assigned

    Labels

    plugin: loggingrelated to the logging builtin plugintype: enhancementnew feature or API change, should be merged into features branch

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions