Please don't hijack my Python root logger

Redowan Delowar August 3, 2024
Source
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

Loading comments...