pytest-dev / pytest-dev/pytest
Mechanism to log current test to file logger
Nobody has claimed this yet.
- Dominant language
- Python
- Stars
- 14.5k
- Forks
- 3.4k
- Avg merge
- 2d 9h
- Merged PRs (30d)
- 35
Description
What's the problem this feature will solve?
I commonly use different log levels for the cli and file log level, e.g. cli logger at logging.INFO and file logger at logging.DEBUG. This way I can open the file log if I want a more detailed look at the logs, while keeping the cli output as clean as possible. However, I have not been able to conveniently figure out which test is running from browsing the file logs. The cli logger outputs the current test executed (and PASSED/FAILED) directly to the cli, but as far as I'm aware this is not possible to get from the file log.
Describe the solution you'd like
pytest could accept a ini file argument (e.g. log_file_verbosity or log_file_trace) that shows the same tracing output as the cli logger.
A file log with indistinguishable log calls like this:
11:09:23.436 INFO hello there
11:09:23.437 INFO tralala
11:09:23.437 INFO bla bla
11:09:23.438 CRITICAL critical
11:09:23.438 ERROR error
11:09:23.438 WARNING warning
11:09:23.438 INFO info
11:09:23.438 DEBUG debug
11:09:23.438 TRACE trace
11:09:23.439 INFO returning fixture setup
11:09:23.439 INFO fixture setup 42
11:09:23.440 INFO my hovercraft is full of eels
11:09:23.440 INFO fixture teardown
11:09:23.440 INFO returning fixture teardown
...can get split up like this:
Running test system/test_demonstration.py::TestDemonstration::test_simple_assert
11:09:50.849 INFO hello there
Running test system/test_demonstration.py::TestDemonstration::test_set_assert
11:09:50.851 INFO tralala
11:09:50.851 INFO bla bla
Running test system/test_demonstration.py::TestDemonstration::test_logging_levels
11:09:50.852 CRITICAL critical
11:09:50.852 ERROR error
11:09:50.852 WARNING warning
11:09:50.852 INFO info
11:09:50.852 DEBUG debug
11:09:50.852 TRACE trace
Running test system/test_demonstration.py::TestDemonstration::test_with_simple_fixture
11:09:50.853 INFO returning fixture setup
11:09:50.853 INFO fixture setup 42
11:09:50.854 INFO my hovercraft is full of eels
11:09:50.854 INFO fixture teardown
11:09:50.854 INFO returning fixture teardown
Alternative Solutions
Currently, I use this workaround which is kind of icky:
@pytest.hookimpl(hookwrapper=True)
def pytest_runtest_setup(item):
file_handler = item.config.pluginmanager.get_plugin('logging-plugin').log_file_handler
# HACK: Temporarily monkeypatch the log file formatter class and write the
# test name to file
try:
orig_formatter = file_handler.formatter
file_handler.setFormatter(logging.Formatter())
for line in ('', f'Running test {item.nodeid}'):
file_handler.emit(logging.LogRecord('N/A', logging.INFO, 'N/A', 0, line, None, None))
finally:
file_handler.setFormatter(orig_formatter)
yield
Additional context
Contributor guide
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start by tracing the pytest_runtest_setup hook and the logging-plugin's log_file_handler shown in the workaround, then review how pytest ini options configure file logging. The requested behavior is a configurable file-log trace that identifies each current test and its result while preserving the detailed log output; verify it against the demonstrated test sequence.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- python
- Domain
- testing
- Issue type
- Feature
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100