懒惰记录消息字符串评估

Question

我使用的是标准的Python记录模块在我的Python应用程序：

 
import logging 
logging.basicConfig(level=logging.INFO) 
logger = logging.getLogger("log") 
while True: 
    logger.debug('Stupid log message " + ' '.join([str(i) for i in range(20)])) 
    # Do something 

的问题是，虽然调试级别不启用，那个愚蠢的日志消息是在每次循环迭代计算，这严重损害了性能。

有没有解决方案？

在C++中，我们有log4cxx包，提供了这样的宏：
LOG4CXX_DEBUG(logger, messasage)
这有效地评估为

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

但因为在Python中没有宏（据我所知），如果有一个有效的方法做日志？

Answer 1

日志记录模块已经部分支持您想要执行的操作。这样做：

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

，而不是这个...：

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

记录模块是足够聪明，除非该消息实际上得到的地方记录到不能产生完整的日志信息。

要将此功能应用于您的特定请求，您可以创建一个lazyjoin类。

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

使用方法如下（注意，使用一台发电机的表情，增加了懒惰）：

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（）没有走到这一步。

Answer 2

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秒执行。这表明当日志记录级别低于设置级别时，不会评估参数。

Answer 3

正如巴蒂尔指出，使用

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

...而不是这样的：

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

只执行字符串，如果实际记录的消息格式可以节省一些时间。

这并不能完全解决问题，不过，因为你可能要预先处理值格式化为字符串，如：

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

在这种情况下，obj.get_a()和obj.get_b()将计算如果没有记录发生，则为，甚至。

的解决方案，这将是使用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=%s b=%s" % (foo.get_a(), foo.get_b())) 

在这种情况下， ，如果log.debug决定执行格式化，则调用lambda函数仅调用，因此调用__str__方法。

请注意：该解决方案的开销可能会超出收益:-)但至少在理论上，它可以完成懒惰的日志记录。

Answer 4

当然下面是​​不是作为一个宏一样高效：

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

，但简单，evaluates in lazy fashion是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))) 
) 

见benchmark-src我建立。