9

What is the recommended method for logging variables using Python logging, and why is it better?

Old-style interpolation:

apple = "green"
logger.debug("apple is %s", apple)

or

New-style .format()

logger.debug("apple is {}".format(apple))

I have heard that interpolation is preferred, because it only evaluates the string if it's going to be printed, but I haven’t verified if it actually matters.

xjcl
  • 12,848
  • 6
  • 67
  • 89
jonatan
  • 9,011
  • 2
  • 30
  • 34
  • 1
    probably doesn't matter. In 99% of cases, if the run time of your logging is significant, something is wrong. – gbtimmon Dec 13 '17 at 16:12
  • This is covered in [the docs](https://docs.python.org/2/howto/logging.html#optimization) – roganjosh Dec 13 '17 at 16:13
  • @gbtimmon I'm not sure I agree with that sentiment. I might dump `debug` logging all over my code during testing with any arbitrarily long string output. The fact that interpolation means I can simply remove all of that overhead by changing the logging level means I don't have to go back and hash a load of lines out. – roganjosh Dec 13 '17 at 16:27
  • 1
    New-style interpolation is neither of those. Introduced at 3.6 you can use an "f" string: `logger.debug(f"apple is {apple}")` – cdarke Dec 13 '17 at 16:47
  • 1
    @ronganjosh Meh well if you want to do that much debug statements I suppose thats a personal choice, but my point was that it would have to be a TON of logging before its going to be the bottle neck in your process. If you program spends more time logging then anything else, then I think you are logging too much. – gbtimmon Dec 13 '17 at 18:36

2 Answers2

3
logger.debug("apple is {}".format(apple))

logger.debug(f"apple is {apple}")

New-style formatting will always build a string. If this is expensive (e.g. logging a large pandas DataFrame), this will impact performance.

logger.debug("apple is %s", apple)

Old-style interpolation only builds the logging string if the message will actually end up being logged. If you app's loglevel is one of INFO/WARNING/ERROR/CRITICAL, it will only log messages of at least that loglevel. So this DEBUG-level message would not get logged and the interpolation is skipped.

In conclusion, yes, interpolation saves formatting effort (effectively calls to __str__) -- if this actually matters depends on your app.

xjcl
  • 12,848
  • 6
  • 67
  • 89
2

Use = feature of f-strings since Python 3.8

logger.debug(f"{apple=}")

Output apple=green. See Python: Print a variable's name and value?.

Hans Ginzel
  • 8,192
  • 3
  • 24
  • 22