Conditionally evaluated debug statements in Python

debugging, logging, python

Solution

I wonder how much a call to `logging.debug` impacts the performance when there are no handlers.

However the `if __debug__:` statement is evaluated only once, even in the body of a function

$ python -O
Python 2.6.6 (r266:84292, Dec 26 2010, 22:31:48)
[GCC 4.4.5] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import dis
>>> import logging
>>> def debug(*a, **kw):
...  if __debug__:
...   logging.debug(*a, **kw)
... 
>>> dis.dis(debug)
  2           0 LOAD_CONST               0 (None)
              3 RETURN_VALUE        
>>> 

and the logger can format the message for you using the string formatting operator. Here a slightly modified example taken from the logging.debug documentation

FORMAT = '%(asctime)-15s %(clientip)s %(user)-8s %(message)s'
logging.basicConfig(format=FORMAT)
d = { 'clientip' : '192.168.0.1', 'user' : 'fbloggs' }
debug('Protocol problem: %s', 'connection reset', extra=d)

In this case the message string is never evaluated if the optimizations are turned off.

Problem

Python has a few ways of printing "trace" output. `print`, `import logging`, `stdout.write` can be used to print debugging info, but they all have one drawback: even if the logger's threshold is too high or the stream is closed, Python will still evaluate the arguments to the print statement. (Strict Evaluation) This could cost a string format or more. The obvious fix is to put the string-creating code into a lambda, and use our own logging function to call the lambda conditionally (this one checks the `__debug__` builtin variable, which is set to False whenever python is started with `-O` for optimizations) : ``` def debug(f): if __debug__: print f() #stdout.write(f()) #logging.debug(f()) for currentItem in allItems: debug(lambda:"Working on {0}".format(currentItem)) ``` The advantage is not calling `str(currentItem)` and `string.format` in release builds, and the disadvantage is having to type in `lambda:` on every logging statement. Python's `assert` statement is treated specially by the Python compiler. If python is run with `-O`, then any assert statements are discarded without any evaluation. You can exploit this to make another conditionally-evaluated logging statement: ``` assert(logging.debug("Working on {0}".format(currentItem)) or True) ``` This line will not be evaluated when Python is started with `-O`. The short-circuit operators 'and' and 'or' can even be used: ``` __debug__ and logging.debug("Working on {0}".format(currentItem)); ``` But now we're up to 28 characters plus the code for the output string. The question I'm getting to: Are there any standard python statements or functions that have the same conditional-evaluation properties as the `assert` statement? Or, does anyone have any alternatives to the methods presented here?

Original source