Fix logging

[jobrachem]

This PR fixes the questionable behavior of changing the root logger's settings.

It also adds the current logger's name to the output of Liesel's log messages. This will allow users to identify the exact logger that is responsible for individual messages, such that those exact loggers can be edited more easily.

[jobrachem]

@hriebl Since pytests caplog captures only log messages emitted to the root logger, I had to implement a workaround from pytest-dev/pytest#3697 to make the test TestDistRegBuilder.test_build_empty (and testing with non-propagating loggers in general) work. Even though this introduces a little more additional code to conftest.py than would be great, I think this is a workable way of moving forward at the moment.

[hriebl]

Thank you very much for looking into this, @jobrachem! This PR helps me to understand the logging module a lot better.

The question I'm wondering about is if we really want to have a non-propagating logger, because that would make the configuration a lot harder. Say we wanted to log the messages from both JAX and Liesel to one file, then we'd need to set the same file handler for two loggers. Or if we wanted to apply the same formatting to all messages, we'd need to adjust the formatter for two handlers of two loggers.

Here's the output of a small experiment on my system:

(liesel) [hannes@dell-fedora ~]$ python
Python 3.10.6 (main, Aug  2 2022, 00:00:00) [GCC 12.1.1 20220507 (Red Hat 12.1.1-1)] on linux
Type "help", "copyright", "credits" or "license" for more information.
>>> import logging
>>> logger = logging.getLogger("root")
>>> logger
<RootLogger root (WARNING)>
>>> logger.handlers
[]
>>> import jax
>>> logger.handlers
[<StreamHandler <stderr> (NOTSET)>]
>>>

So, JAX seems to add a stream handler to stderr to the root logger. How about making our setup function more robust by checking if the root logger already has a stream handler to stderr. Maybe we should also not change the formatter by default to avoid accidentally overriding some user settings?

[jobrachem]

You raise some very good points I think. Especially

Maybe we should also not change the formatter by default to avoid accidentally overriding some user settings?

The only reason that I see why we are adding a handler in the setup_logging function is to change the formatting. If we don't do this, we need no setup_logging function. We then let the liesel logger propagate as usual to the root logger. Now I think we have a decision between two main pathways:

1. Option 1: We define a default format for our log output to stderr.
2. Option 2: We do not touch the default log format and therefore do not add a handler.

If we go with option 1, we need to make it work with existing loggers, either by turning propagation of the liesel logger off or by dealing with existing handlers in a clever way. Intuitively, the latter seems a little risky to me, because we might start to see weird behavior depending on what other libraries do.

Option 2 may be easier and code-wise cleaner than option 1. It also conforms to advice given in the documentation for the logging module: https://docs.python.org/3/howto/logging.html#configuring-logging-for-a-library. However, it is a little dissatisfying to me to have our default logging not follow an easy-to-read-format. As a liesel user, I would not really want to have to configure logging every time I use it to sample a model.

Interestingly, the very thing that messes with our logging seems to be the fact that jax or one of its dependencies started adding a handler to the root logger. In v0.3.13, this was apparently not the case:

>>> import logging
>>> logger = logging.getLogger("root")
>>> logger.handlers
[]
>>> import jax
>>> logger.handlers
[]

[jobrachem]

@hriebl I added the reset_logger function that we talked about. From my side, we are good to go.

[wiep]

Interestingly, the very thing that messes with our logging seems to be the fact that jax or one of its dependencies started adding a handler to the root logger. In v0.3.13, this was apparently not the case:

adding a logger to root is not recommended (if i understood you correctly). should we create an issue concerning the issue in the jax repo?

[hriebl]

Thank you for the latest changes, @jobrachem! Merging.