[Python-ideas] Efficient debug logging

[MRAB]

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(), ))