Python: How To Do Lazy Debug Logging

I have some python like this: def foo(): logger = logging.getLogger() # do something here logger.debug('blah blah {}'.format(expensive_func())) foo() where expensive_

Solution 1:

Look at this part of the documentation.

Update: Logging already supports lazy evaluation, but slightly differently to the way described in your comnment. For example, see the following script:

import logging

defexpensive_func(*args):
    print('Expensive func called: %s' % (args,))
    returnsum(args)

classDeferredMessage(object):
    def__init__(self, func, *args):
        self.func = func
        self.args = args

    def__str__(self):
        return'Message {0}'.format(self.func(*self.args))

if __name__ == '__main__':
    logging.basicConfig()
    logging.info(DeferredMessage(expensive_func, 1, 2))
    logging.warning(DeferredMessage(expensive_func, 3, 4))
    logging.error(DeferredMessage(expensive_func, 5, 6))

When the above script is run, it should print

Expensive funccalled: (3, 4)
WARNING:root:Message 7
Expensive funccalled: (5, 6)
ERROR:root:Message 11

which shows that a potentially expensive function is only called when necessary. The example above can, of course, be generalised to allow the format string to be passed to the DeferredMessage, and to use kwargs, and so on.

Solution 2:

As Vinay Sajip suggests, you can do the following:

def foo():
    logger = logging.getLogger()
    if logger.isEnabledFor(logging.DEBUG):
        logger.debug('blah blah {}'.format(expensive_func()))
        logger.debug('Message: {}'.format(expf_1(expf_2(some_arg))))
        logger.debug('Message: {}', Lazy(expf_1, Lazy(expf_2, some_arg)))
foo()

Which is already lazy!

That's because the then-expressions

        logger.debug('blah blah {}'.format(expensive_func()))
        logger.debug('Message: {}'.format(expf_1(expf_2(some_arg))))
        logger.debug('Message: {}', Lazy(expf_1, Lazy(expf_2, some_arg)))

are only evaluated if and only if logger.isEnabledFor(logging.DEBUG) returns True, i.e. if and only if their evaluation is needed.

---

Even more

logging.info(DeferredMessage(expensive_func, 1, 2))

is not as lazy as one may think: DeferredMessage(expensive_func, 1, 2) have to be evaluated in an eager fashion. Which is in addition slower than evaluating:

    if logger.isEnabledFor(logging.DEBUG):

Solution 3:

You can use stringlike library to add laziness to your messages

E.g.:

logger.debug(
    'blah blah {value}'
    .format(
        value=LazyString(expensive_func)
    )
)

Lib link: https://github.com/CovenantEyes/py_stringlike