--- title: Another look at python's logging library date: 2023-10-13 tags: [code, python] description: Python's logging library is a mixed bag. There is much more complexity than would be needed for such a simple task. So let's take a look. --- Python's [logging](https://docs.python.org/3/library/logging.html) library is a mixed bag. The code was clearly written in a pre-python3 and pre-pep8 era, so it has a lot of sharp edges. It also feels like there is much more complexity than would be needed for such a simple task. But this library also offers a lot of flexibility for advanced users as well as shortcuts for simple use cases. So let's take a look. ## Creating log records Typically you would create log records like this: ```python import logging logger = logging.getLogger(__name__) def myfunc(): logger.error('something went wrong') ``` First you create a logger instance with the name of the current module (e.g. `'myproject.utils'`). Loggers form a hierarchy that is derived from their names. For example, the logger `'myproject.utils'` would propagate to `'myproject'`. The root logger is available as `logging.root`. You do not have to use the module name, but it is a good default. Once you have a logger you can create log records. There is a method for each log level (`debug()`, `info()`, `warn()`, `error()`, and `critical()`). Each of these will also extract some information from the call stack, e.g. the path and line of the place where it was triggered. There is also `exception()` which is the same as `error()` but will also capture the stack trace. For very simple cases, you can skip the logger and use shortcut functions instead, e.g. `logging.error()`. These will use the root logger. If handlers have not yet been configured (see next section), these shortcuts will also make sure that log records are written to stderr. ## Configuring handlers Log records are sent to stderr by default. In production settings you usually want something more involved, so you have to configure handlers. `logging` provides many useful handlers such as `StreamHandler` to write to stderr or `SMTPHandler` to send mails. Many more handlers are available from third party packages. Handlers have some options. First, you may want to filter which log records are even considered for a given handler. You can set a minimum level or add a custom `Filter` object for more complex conditions. After that, you need to convert the log record to a string. The default format is `%(levelname)s:%(name)s:%(message)s`. But you can customize it using a `Formatter` object. Unfortunately, there are multiple different options to configure handlers. Let's first create the necessary objects manually: ```python import logging from logging.handlers import SMTPHandler formatter = logging.Formatter( '%(asctime)s %(levelname)-8s %(name)s %(message)s' ) logging.root.setLevel(logging.NOTSET) streamhandler = logging.StreamHandler() streamhandler.setLevel(logging.INFO) streamhandler.setFormatter(formatter) logging.root.addHandler(streamhandler) smtphandler = SMTPHandler( 'localhost', 'me@localhost', 'you@localhost', 'new log message', ) smtphandler.setLevel(logging.ERROR) smtphandler.setFormatter(formatter) logging.root.addHandler(smtphandler) ``` The second option is to use the shortcut function `basicConfig()` which has all kinds of defaults. A simple call to `basicConfig()` will configure a stream handler. You can do more with it, but it breaks down pretty quickly. For the example above, `basicConfig()` doesn't really have any benefits. The third option is to use a dictionary: ```python import logging.config logging.config.dictConfig({ 'version': 1, 'formatters': { 'default': { 'format': '%(asctime)s %(levelname)-8s %(name)s %(message)s' }, }, 'handlers': { 'console': { 'class': 'logging.StreamHandler', 'level': 'INFO', 'formatter': 'default', }, 'mail': { 'class': 'logging.handlers.SMTPHandler', 'mailhost': 'localhost', 'fromaddr': 'me@localhost', 'toaddrs': 'you@localhost', 'subject': 'new log message', 'level': 'ERROR', 'formatter': 'default', }, }, 'root': { 'handlers': ['console', 'mail'], 'level': 'NOTSET', }, }) ``` The main benefit of this version is that you can encode this dictionary as a JSON string, so it can be used with all kinds of setups. The final option is to use `logging.config.listen()` to start a TCP server that can receive configuration in JSON format. I am not sure why you would want to do that and I find it rather strange that this is included in the standard library. ## Attaching handlers to specific loggers In most cases you will want to attach your handlers to the root logger and then filter records there. But you can also attach handlers to different loggers. Consider this example: ``` logging.config.dictConfig({ 'version': 1, 'handlers': { 'console': { 'class': 'logging.StreamHandler', }, 'audit-file': { 'class': 'logging.FileHandler', 'filename': 'audit.log', }, }, 'loggers': { 'audit': { 'handlers': ['audit-file'], 'propagate': False, }, }, 'root': { 'handlers': ['console'], 'level': 'NOTSET', }, }) ``` This way, log records from the "audit" namespace will be logged to a file instead of stderr. ## Recommendations `logging` has lots of flexibility, so much so that it is sometimes hard to know how to do simple things. So here are some recommendations: - Attach handlers to the root logger. - Use `dictConfig()`, as it gives you full control and can be used in any setup. - It is theoretically possible to set a minimum level for both loggers and handlers. I can't think of any case where a minimum level on a logger is useful, so you should stick to using it on handlers. - All loggers and handlers are initialized with no minimum level (i.e. `NOTSET`). The only exception is the root logger which has a minimum level of `WARNING`. To avoid confusion, I strongly recommend to reset that to `NOTSET`. ## Wishful thinking With that said, there are some things in `logging` that I wish were different: - All handlers should accept `level` and `formatter` as keyword arguments. The current way to construct them is just awkward. - The root logger should have the `NOTSET` level. - The default format should include the time. A log message without the time is pretty much useless. Sometimes your logging pipeline will attach a time automatically (e.g. journald). But for all other cases you basically have to configure a custom formatter. - Python has accumulated a bunch of string formatting syntaxes, and consequently `logging` offers different formatting styles (%, {, and $). This is just silly. Everyone should just use the default style. - `logging.config.listen()` has no place in the standard library and should be removed. - This is a bigger thing, but I am just not sold on the whole hierarchy idea. It adds a lot of complexity without a tangible benefit because you could achieve the same thing with filters. ## Conclusion The right logging configuration is crucial. If your logs get lost you cannot debug issues. And if you do not get notified about errors, you might not even realize what is going on. I personally have wasted too much time with complex logging configurations. So it was high time to take a deeper look into this. I hope my recommendations will prove to be helpful.