What is the best string formatting technique for logging in Python?

#python #discuss #5days5blogposts #programming

First, let's do a quick recap of all of the possible string formatting techniques in Python:

printf-style, % operator, oldschool



# example with %s format specifier
>>> name = "Guido"
>>> "Hello %s" % name
'Hello Guido'

# version with a mapping
>>> year = 2021
>>> "Hello %(name)s from year %(year)d" % {"name": name, "year": year}
'Hello Guido from year 2021'

Template Strings, since Python 2.4



from string import Template

t = Template("Hello $name")

>>> t.substitute(name=name)
'Hello Guido'

t = Template("Hello $name from year $year")

>>> t.substitute(name=name, year=year)
'Hello Guido from year 2021'

str.format, since Python 3.0



>>> "Hello, {}".format(name)
'Hello, Guido'

>>> "Hello {name} from year {year}".format(name=name, year=year)
'Hello Guido from year 2021'

f-Strings, Python 3.6+



>>> f"Hello {name}"
'Hello Guido'

>>> f"Hello {name} from year {year}"
'Hello Guido from year 2021'

The f-Strings method is the most recent, the fastest and usually the most convenient way of formatting strings in Python.

Here's a great article where you can learn more about string formatting in Python:

https://realpython.com/python-string-formatting/

The logging module

The logging module was added to the Python standard library way back when the only way of formatting strings was to use the printf formatting technique. As the documentation states, at least for now, there's no way to change that while maintaining backwards compatibility. The logger methods (debug(), info(), error() etc.) take positional parameters for the logging message. Therefore, the recommended way of string formatting is to pass the actual message with string formatting specifiers (%s, %r, %x etc.) and the other arguments we want to append to the main message.



import logging

logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)

name = "Guido"

>>> logger.info("Hello %s from logger!", name)
INFO:__main__:Hello Guido from logger!

# NOTE: not this way, you need to pass args to the info method:
# logger.info("Hello %s from logger!" % name)

Although the logging methods accept other formatting styles and the official Python logging cookbook gives us a few workarounds, printf technique, in particular, is recommended by the docs. Let's focus now on the two main advantages of this approach.

Performance

Passing the message arguments using the printf-style enables postponing the formatting to the very last moment before the message is outputted via the handler. Therefore, the interpolation won't be applied unless the logging level is sufficient enough. This might come quite handy when dealing with some heavy computational data:



import logging
from dataclasses import dataclass

logging.basicConfig(level=logging.ERROR)
logger = logging.getLogger(__name__)


@dataclass
class Developer:
    name: str

    def __str__(self) -> str:
        print("Some super heavy calculation going on")
        return self.__repr__()


developer = Developer(name="Guido")

# info won't be logged since we've set up log level to error
>>> logger.info(f"Hello {developer} from logger!")
Some super heavy calculation going on

>>> logger.info("Hello %s from logger!", developer)
# prints nothing

On the other hand, it's also questionable. If you need to avoid an automatic call of the str() method of your object, it might be an indicator that something is wrong with your code, and you ultimately need to perform some refactoring. Let's move on to the second advantage of printf-style logging. This one is more obvious and straightforward.

Working with log aggregators

If you're using a log aggregator in your project, like, for example, Sentry (which is awesome!), the printf-style logging becomes quite helpful. If you call the same log statement many times with immediate string interpolation, you will get multiple occurrences of the same log message:



logger.error(f"Something went wrong with {obj}")

However, if you use the printf technique, all of the records will be grouped as occurrences of the same log message, with different values for %s:



logger.error("Something went wrong with %s", obj)

Summary

Considering all the advantages of the printf-style log formatting, is it worth giving up super clean and modern f-Strings? Or is it an overkill? Or maybe you have found some new third party library that handles the string formatting for logging better? Let me know your thoughts below!