Please don't hijack my Python root logger
Redowan Delowar
August 3, 2024
With the recent explosion of LLM tools, I often like to kill time fiddling with different
LLM client libraries and SDKs in one-off scripts. Lately, I've noticed that some newer tools
frequently mess up the logger settings, meddling with my application logs. While it's less
common in more seasoned libraries, I guess it's worth rehashing why hijacking the root
logger isn't a good idea when writing libraries or other forms of reusable code.
In Python, when I say [root logger], I mean the logger instance that logging.basicConfig
acts on, or the one you get back when you don't specify a name in logging.getLogger(). The
root logger is for the application code to use and if you're a library author, you should
probably steer clear from it. If not, people using your code might get into situations as
follows.
Let's say there's a single file library named lib.py that decides to configure the root
logger:
Now, let's say the user of lib.py imports the frobnicate function and configures the
root logger in the following manner:
Since the application code has set the log threshold to INFO, you might think that running
the code snippet would only print the log message from the application. But instead, you'll
also get the DEBUG message from the library:
It happens because before the application code had the chance to set the log level to
INFO, the library code hijacked the root logger and configured it during the import time
of frobnicate. You can test it by placing the from lib import frobnicate statement after
the logging.basicConfig(...) line in the main.py file. By doing so, the log
configuration in the application code gets to run before the library has the chance to
meddle with it.
This makes things confusing for the library user, and the [Logging how-to] doc advises
against doing so:
> It is strongly advised that you do not log to the root logger in your library. Instead,
> use a logger with a unique and easily identifiable name, such as the name for your
> library's top-level package or module. Logging to the root logger will make it difficult
> or impossible for the application developer to configure the logging verbosity or handlers
> of your library as they wish.
Solving this is quite straightforward. Avoid using the root logger in your library code.
Instead, instantiate your own logger instance and configure it with your heart's content.
This way, your users get to keep using the root logger as they like, and they can also tap
into the library's log messages whenever they need to.
Here's how to achieve that in the library:
Now the library logger no longer conflicts with the application log configuration. The
application code in the main.py from the previous section can remain the same and running
the snippet will only print out the INFO message this time:
This setup also lets the application code access and adjust the library's logger to suit its
needs. Here's how it can be done in the main.py file:
Above, the library user sets up the root logger as usual while also reconfiguring the
library's logger. It's the library author's job to properly name and initialize the logger
in the library code. The logger name and the default behavior should be well-documented as
well.
This allows the application code to retrieve and customize the logger as needed. Note that
calling getLogger with the same name always retrieves the same logger instance.
Also, you should avoid adding any handlers to your library's logger. Doing so can complicate
things for users who may want to attach their own handlers. The logging how-to guide
strongly warns against this:
> It is strongly advised that you do not add any handlers other than NullHandler to your
> library's loggers. This is because the configuration of handlers is the prerogative of the
> application developer who uses your library. The application developer knows their target
> audience and what handlers are most appropriate for their application: if you add handlers
> ‘under the hood', you might well interfere with their ability to carry out unit tests and
> deliver logs which suit their requirements.
If you're looking for a real-life example of how to minimally configure your library's
logger, check out the [httpx codebase]. The logging behavior is well-documented there.
You can easily reconfigure the httpx logger in your application code while making an HTTP
request like this:
Running the script will print the DEBUG messages as follows:
[root logger]:
https://docs.python.org/3/library/logging.html#:~:text=Logged%20messages%20to%20the%20module%2Dlevel%20logger%20get%20forwarded%20to%20handlers%20of%20loggers%20in%20higher%2Dlevel%20modules%2C%20all%20the%20way%20up%20to%20the%20highest%2Dlevel%20logger%20known%20as%20the%20root%20logger%3B%20this%20approach%20is%20known%20as%20hierarchical%20logging
[logging how-to]:
https://docs.python.org/3/howto/logging.html
[httpx codebase]:
https://github.com/search?q=repo%3Aencode%2Fhttpx%20logging&type=code
Discussion in the ATmosphere