懒惰的logging器消息string评估

我在我的Python应用程序中使用标准的Python日志logging模块:

导入日志
 logging.basicConfig(级别= logging.INFO)
 logger = logging.getLogger(“log”)
而真:
   logger.debug('stupid log message'+''.join([str(i)for i in range(20)]))
   # 做一点事

问题是虽然debugging级别没有启用,但是愚蠢的日志消息在每次循环迭代中被评估,这严重损害了性能。

有没有解决scheme?

在C ++中,我们有提供这样的macros的log4cxx包:
LOG4CXX_DEBUG(logger, messasage)
这有效评估

 if(log4cxx :: debugEnabled(logger)){
     log4cxx.log(logger,log4cxx :: LOG4CXX_DEBUG,message)
 }

但是由于Python中没有macros(AFAIK),如果有一个有效的方法来做日志?

日志logging模块已经部分支持你想要做的事情。 做这个:

 log.debug("Some message: a=%sb=%s", a, b) 

而不是这个:

 log.debug("Some message: a=%sb=%s" % (a, b)) 

日志logging模块足够智能,不会产生完整的日志消息,除非消息实际上被logging在某处。

要将此function应用于您的特定请求,您可以创build一个lazyjoin类。

 class lazyjoin: def __init__(self, s, items): self.s = s self.items = items def __str__(self): return self.s.join(self.items) 

像这样使用它(注意使用生成器expression式,增加懒惰):

 logger.info('Stupid log message %s', lazyjoin(' ', (str(i) for i in range(20)))) 

这是一个演示,显示这个作品。

 >>> import logging >>> logging.basicConfig(level=logging.INFO) >>> logger = logging.getLogger("log") >>> class DoNotStr: ... def __str__(self): ... raise AssertionError("the code should not have called this") ... >>> logger.info('Message %s', DoNotStr()) Traceback (most recent call last): ... AssertionError: the code should not have called this >>> logger.debug('Message %s', DoNotStr()) >>> 

在演示中,logger.info()调用命中断言错误,而logger.debug()没有得到那么多。

当然以下不如macros观效率:

 if logger.isEnabledFor(logging.DEBUG): logger.debug( 'Stupid log message ' + ' '.join([str(i) for i in range(20)]) ) 

但简单, 懒惰的评估, 比接受的答案快4倍

 class lazyjoin: def __init__(self, s, items): self.s = s self.items = items def __str__(self): return self.s.join(self.items) logger.debug( 'Stupid log message %s', lazyjoin(' ', (str(i) for i in range(20))) ) 

看我的设置基准-SRC 。

 import logging import time logging.basicConfig(level=logging.INFO) logger = logging.getLogger("log") class Lazy(object): def __init__(self,func): self.func=func def __str__(self): return self.func() logger.debug(Lazy(lambda: time.sleep(20))) logger.info(Lazy(lambda: "Stupid log message " + ' '.join([str(i) for i in range(20)]))) # INFO:log:Stupid log message 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 

如果你运行脚本,你会注意到第一个logger.debug命令不需要20秒的时间来执行。 这显示日志logging级别低于设置级别时不会评估参数。

正如Shane指出的那样,使用

 log.debug("Some message: a=%sb=%s", a, b) 

而不是这个:

 log.debug("Some message: a=%sb=%s" % (a, b)) 

如果消息被实际logging,则只通过执行string格式化来节省一些时间。

但是,这并不能完全解决问题,因为您可能必须预先处理值以格式化为string,例如:

 log.debug("Some message: a=%sb=%s", foo.get_a(), foo.get_b()) 

在这种情况下, 即使没有logging发生, obj.get_a()obj.get_b()也会被计算出来。

解决scheme是使用lambda函数,但这需要一些额外的机制:

 class lazy_log_debug(object): def __init__(self, func): self.func = func logging.debug("%s", self) def __str__(self): return self.func() 

…那么你可以用以下日志:

 lazy_log_debug(lambda: "Some message: a=%sb=%s" % (foo.get_a(), foo.get_b())) 

在这种情况下, 只有log.debug决定执行格式化时才会调用lambda函数,因此调用__str__方法。

请注意:这个解决scheme的开销可能会超过这个好处:-)但是至less在理论上,它可以做到完全懒惰的日志logging。