Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Idiomatic Python logging: format string + args list vs. inline string formatting - which is preferred?

Is it advantageous to call logging functions with format string + args list vs. formatting inline?

I've seen (and written) logging code that uses inline string formatting:

logging.warn("%s %s %s" % (arg1, arg2, arg3))

and yet I assume it's better (performance-wise, and more idiomatic) to use:

logging.warn("%s %s %s", arg1, arg2, arg3)

because the second form avoids string formatting operations prior to invoking the logging function. If the current logging level would filter out the log message, no formatting is necessary, reducing computing time and memory allocations.

Am I on the right track here, or have I missed something?

like image 882
Inactivist Avatar asked Aug 14 '12 15:08

Inactivist


1 Answers

IMHO, for messages that are very likely to be displayed, such as those given to error or warn it does not make much of a difference.

For messages that are less likely displayed, I would definitely go for the second version, mainly for performance reasons. I often give large objects as a parameter to info, which implement a costly __str__ method. Clearly, sending this pre-formatted to info would be a performance waste.

UPDATE

I just checked the source code of the logging module and, indeed, formatting is done after checking the log level. For example:

class Logger(Filterer):
    # snip
    def debug(self, msg, *args, **kwargs):
        # snip
        if self.isenabledfor(debug):
            self._log(debug, msg, args, **kwargs)

One can observe that msg and args are untouched between calling log and checking the log level.

UPDATE 2

Spired by Levon, let me add some tests for objects that have a costly __str__ method:

$ python -m timeit -n 1000000 -s "import logging" -s "logger = logging.getLogger('foo')" -s "logger.setLevel(logging.ERROR)" "logger.warn('%s', range(0,100))"
1000000 loops, best of 3: 1.52 usec per loop
$ python -m timeit -n 1000000 -s "import logging" -s "logger = logging.getLogger('foo')" -s "logger.setLevel(logging.ERROR)" "logger.warn('%s' % range(0,100))"
1000000 loops, best of 3: 10.4 usec per loop

In practice, this could give a fairly high performance boost.

like image 177
user1202136 Avatar answered Oct 17 '22 13:10

user1202136