[Python-ideas] Efficient debug logging

[Abe Dillon]

There are several mechanisms in the logging module to handle this use-case.
First, note that logging functions can take multiple arguments (
https://docs.python.org/3/library/logging.html?highlight=logging#logging.Logger.debug
):

>>> import logging
>>> msg = "hello, %s! %s to %s you!"
>>> args = ("world", "pleased", "meet")
>>> logging.warning(msg, *args)
WARNING:root:hello, world! pleased to meet you!

None of the string formatting will take place if the log call is below the
level of the logger. It might be worth while to add a class that stores an
unevaluated function, then evaluates the function when __str__ or __repr__
is called:

>>> class MessageFunction:
...     def __init__(self, func, *args, **kwargs):
...         self.func = func
...         self.args = args
...         self.kwags = kwargs
...     def __str__(self):
...         return str(self.func(*self.args, **self.kwargs))
...     def __repr__(self):
...         return repr(self.func(*self.args, **self.kwargs))

>>> import logging
>>> logging.debug("result = %s", MessageFunction(expensive_func, *args,
**kwargs))

You can also add Filters to your logger:
https://docs.python.org/3/library/logging.html?highlight=logging#logging.Filter


On Tue, Feb 14, 2017 at 11:51 AM, MRAB <python at mrabarnett.plus.com> wrote:

> On 2017-02-14 15:51, Barry Scott wrote:
>
>> A common pattern I use is to have logging calls for debug and information
>> with my applications.
>> The logging calls can be separately enabled and disabled.
>>
>> For example:
>>
>> debug_log_enabled = False
>> def debugLog( msg ):
>>       If debug_log_enabled:
>>             print( ‘Debug: %s’ % (msg,) )
>>
>> Then the caller can simple write:
>>
>> def main():
>>       debugLog( ‘Start of main’ )
>>
>> This is fine until the evaluation of the msg becomes expensive.
>>
>>         debugLog( ‘info is %r’ % (expensiveFunction(),) )
>>
>> What would be nice is to be able to avoid evaluation the tuple of
>> arguments if debug is
>> disabled as this can be expensive. I can write this:
>>
>>         if debug_log_enabled:  debugLog( ‘info is %r’ %
>> (expensiveFunction(),) )
>>
>> But that is a more code then I would like to write. And if the debug code
>> is a performance problem cannot
>> be left in the production code.
>>
>> I could combine the boolean and the log function by using a class to tidy
>> up the implementation.
>>
>> class DebugLog:
>>         def __init__( self, enabled = False ):
>>                 self.enabled = enabled
>>
>>         def __bool__( self ):
>>                 return self.enabled
>>
>>         def __call__( self, msg ):
>>                 if self.enabled: print( ‘Debug: %s’ % (msg,) )
>>
>> And call like this:
>>
>>         dbg_log = DebugLog()
>>
>>        If dbg_log: dbg_log( ‘a debug message’ )
>>
>> But I’d like to only write:
>>
>>         dbg_log( ‘a debug message’ )
>>
>> And have the evaluation of the argument skipped unless its dbg_log is
>> enabled.
>>
>> I cannot see how to do this with python as it stands.
>>
>> Something would have to be added to allow python to short circuit the
>> argument tuple evaluation.
>>
>> Maybe python can check for a special dunder on the class that know how to
>> do this idiom, __if_true_call__?
>>
>> Thoughts?
>>
>> You could let your debugging function accept a callable and use lambda to
> delay execution:
>
> def debugLog(msg):
>     if debug_log_enabled:
>         if callable(msg):
>             msg = msg()
>
>         print('Debug: %s' % (msg, ))
>
>
> debugLog('Start of main')
>
> debugLog(lambda: 'info is %r' % (expensiveFunction(), ))
>
>
> _______________________________________________
> Python-ideas mailing list
> Python-ideas at python.org
> https://mail.python.org/mailman/listinfo/python-ideas
> Code of Conduct: http://python.org/psf/codeofconduct/
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.python.org/pipermail/python-ideas/attachments/20170214/2b4aaf35/attachment-0001.html>