matplotlib / pytest-mpl

A pytest plugin to facilitate image comparison for Matplotlib figures
Other
240 stars 46 forks source link

Improve Logging Configuration: don't modify root logger #182

Closed theOehrly closed 1 year ago

theOehrly commented 1 year ago

Currently, pytest-mpl uses logging.basicConfiguration to configure logging. But this modifies the configuration of the root logger which leads to unexpected and unwanted behaviour when testing code that itself uses logging.

To demonstrate the problem, I will use test_succeeds_faulty_mirror() with an additional logging call added:

@pytest.mark.mpl_image_compare(baseline_dir='http://www.python.org,' + baseline_dir_remote,
                               filename='test_succeeds_remote.png',
                               tolerance=DEFAULT_TOLERANCE)
def test_succeeds_faulty_mirror():
    logging.info("Example INFO message from tested module")
    fig = plt.figure()
    ax = fig.add_subplot(1, 1, 1)
    ax.plot([1, 2, 3])
    return fig

This test already causes a logging message from pytest-mpl itself, because an invalid URL is used. Now addtionally, it simulates that the tested code/module makes use of logging as well.

In pytest the --log-cli-level option can be used to configure the logging level that is output on the cli. By default, no messages are output.

If we now run the above example...

... without pytest-mpl (pytest) there is no logging output as expected.

example.py .                                                                        [100%]

=================================== 1 passed in 0.48s ====================================

... with pytest-mpl (pytest --mpl), suddenly there is logging output from pytest-mpl and from the tested code (should not happen).

example.py INFO:root:Example INFO message from tested module
INFO:pytest-mpl:Downloading http://www.python.orgtest_succeeds_remote.png failed: URLError(gaierror
(11001, 'getaddrinfo failed'))
.                                                                        [100%]

=================================== 1 passed in 1.15s ====================================

... with pytest-mpl and logging configured through pytest (pytest --mpl --log-cli-level=INFO), the logging messages from pytest-mpl are now output twice. (This happens because messages are propagated to the root logger as well and those are then handled by pytest.)

INFO     root:example.py:20 Example INFO message from tested module
INFO:pytest-mpl:Downloading http://www.python.orgtest_succeeds_remote.png failed: URLError(gaierror
(11001, 'getaddrinfo failed'))
INFO     pytest-mpl:plugin.py:375 Downloading http://www.python.orgtest_succeeds_remote.png failed:
 URLError(gaierror(11001, 'getaddrinfo failed'))
PASSED                                                                                      [100%]

======================================= 1 passed in 0.90s ========================================

The main problem here is that it is impossible to turn of logging to the cli when pytest-mpl is used. As shown, this is usually configured in pytest with the --log-cli-level option and similar options. But pytest-mpl's modification of the root logger completely bypasses this. This can make test output fairly unreadable if the tested module itself makes extensive use of logging.

This PR implements the usage of a completely separate logger for pytest-mpl. Its logging configuration is fully independent of pytest and independent of the tested code. Additionally, the same logging format as used for pytest's cli ouput is used.

I did consider tying into pytest's logging functionality directly to make pytest-mpl interact perfectly and use all features, including coloured output and similar. But this would need to rely heavily on non-public API parts of pytest and might therefore be prone to breaking when there are changes in pytest. The minor improvements would not be worth the risk and maintenance effort in my opinion.

Cadair commented 1 year ago

Thanks a lot for the PR, I think it looks good, though I need to check if the docs build also fails on the main branch.

theOehrly commented 1 year ago

I was waiting on feedback for the doc build failure. I looked at it but couldn't really make sense of it.