Python Logging Interpolation
Pylint’s enforcement of percent style string formatting is not about style, it’s a matter of correctness. Formatting strings before passing them to a logger may produce undesirable results with error reporting services like Sentry and may impact application performance/reliability.
Why does Pylint complain?
Let’s look at logging using various string formatting techniques.
import logging
username = 'jdoe'
logging.info(f"{username} logged in") # (1) bad
logging.info("{} logged in".format(username)) # (2) bad
logging.info("%s logged in" % username) # (3) bad
logging.info("%s logged in", username) # (4) good
Pylint, with the proper logging lints enabled, will only accept #4 as valid. Let’s see why by looking at the logging record as it hits a filter.
record: logging.LogRecord ...
# record attributes for our log messages
record.msg, record.args == "jdoe logged in", () # (1)
record.msg, record.args == "jdoe logged in", () # (2)
record.msg, record.args == "jode logged in", () # (3)
record.msg, record.args == "%s logged in", ("jdoe", ) # (4)
We can see that the message #4 hasn’t been formatted, while our pre-formatted values obviously have. This lack of formatting makes the logging module especially useful.
Benefits of delayed log formatting
- Error reporting. Services that install a custom log handler can aggregate logs into single events when the msg has not been formatted.
- Robustness. If there is a problem with formatting a message it will be logged instead of raising an exception.
- Performance. Arguments aren’t evaluated unless logging is enabled
- It’s good practice according to the the Python docs.
Here are some pylints to enable to insure that logging is correct.
logging-not-lazy
logging-format-interpolation
logging-fstring-interpolation