首页 文章

懒惰 Logger 消息字符串评估

提问于
浏览
57

我在我的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

问题是虽然调试级别未启用,但是在每次循环迭代时都会评估该愚蠢的日志消息,这会严重损害性能 .

Is there any solution for this?

在C中我们有 log4cxx 包,提供如下宏:
LOG4CXX_DEBUG(logger, messasage)
这有效地评估为

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

但是由于Python(AFAIK)中没有宏,是否有一种有效的记录方法?

5 回答

  • 31
    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秒 . 这表示当日志记录级别低于设置级别时,不会计算参数 .

  • 13

    日志记录模块已经部分支持您要执行的操作 . 做这个:

    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()没有达到那么远 .

  • 24

    当然,以下内容不如宏有效:

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

    但很简单,evaluates in lazy fashion并且是 4 times faster than the accepted answer

    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 .

  • 67

    正如Shane指出的那样,使用

    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__ 方法 .

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

  • 0

    我在场, Lazyfy

    class Lazyfy(object):
        __slots__ = 'action', 'value'
    
        def __init__(self, action, *value):
            self.action = action
            self.value = value
    
        def __str__(self):
            return self.action(*self.value)
    

    用法:

    from pprint import pformat
    log.debug("big_result: %s", Lazyfy(pformat, big_result))
    log.debug( "x y z: %s", Lazyfy( lambda x, y, z: ' ,'.join( [x, y, z] ), '1', '2', '3' ) )
    

    原来的例子:

    logger.info('Stupid log message %s', Lazyfy(lambda: ' '.join((str(i) for i in range(20)))))
    

    如您所见,这也涵盖了另一个使用lambda函数的答案,但使用了 value 属性和扩展的更多内存 . 但是,它可以节省更多内存:Usage of slots?

    最后,到目前为止,最有效的解决方案仍然是以下建议另一个答案:

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

相关问题