Python 日志模块 - 自上次日志以来的时间

Question

我想在 Python 的日志记录模块生成的日志中添加自上次输入日志以来经过的时间（秒/毫秒）。

这很有用，因此您可以查看日志文件以查看同一步骤是否总是花费相同的时间或发生变化，这表明环境中的某些内容发生了变化（例如数据库性能）。

我知道 %(relativeCreated)d，但这仅显示自记录器启动以来经过的时间，而不是自创建最后一个日志以来经过的时间。基本上 %(relativeCreated)d 是累积值，我想看到的是每个 %(relativeCreated)d 之间的差异。

这就是你用 %(relativeCreated)d 得到的：

2015-07-20 12:31:07,037 (7ms) - INFO - Process started....
2015-07-20 12:31:07,116 (87ms) - INFO - Starting working on xyz
2015-07-20 12:31:07,886 (857ms) - INFO - Progress so far

这就是我需要的：

2015-07-20 12:31:07,037 (duration: 7ms) - INFO - Process started....
2015-07-20 12:31:07,116 (duration: 80ms) - INFO - Starting working on xyz
2015-07-20 12:31:07,886 (duration: 770ms) - INFO - Progress so far

Answer 1

扩展@Simeon Visser 的答案——过滤器是一个简单的存储设备，用于存储自脚本启动以来最后一条消息的相对时间（参见self.last课堂TimeFilter）。

import datetime
import logging

class TimeFilter(logging.Filter):

    def filter(self, record):
        try:
          last = self.last
        except AttributeError:
          last = record.relativeCreated

        delta = datetime.datetime.fromtimestamp(record.relativeCreated/1000.0) - datetime.datetime.fromtimestamp(last/1000.0)

        record.relative = '{0:.2f}'.format(delta.seconds + delta.microseconds/1000000.0)

        self.last = record.relativeCreated
        return True

然后将该过滤器应用于每个日志处理程序，并访问每个日志处理程序的日志格式字符串中的相对时间。

fmt = logging.Formatter(fmt="%(asctime)s (%(relative)ss) %(message)s")
log = logging.getLogger()
[hndl.addFilter(TimeFilter()) for hndl in log.handlers]
[hndl.setFormatter(fmt) for hndl in log.handlers]

Answer 2

这可以使用自定义实例来完成logging.Filter。这是使用该库的示例logaugment，或者您可以查看源代码来构建类似的东西。

import datetime
import logging

import logaugment

logger = logging.getLogger()
handler = logging.StreamHandler()
formatter = logging.Formatter("%(time_since_last)s: %(message)s")
handler.setFormatter(formatter)
logger.addHandler(handler)

创建记录器后，您需要指定一个在每次创建日志记录时调用的函数：

def process_record(record):
    now = datetime.datetime.utcnow()
    try:
        delta = now - process_record.now
    except AttributeError:
        delta = 0
    process_record.now = now
    return {'time_since_last': delta}

logaugment.add(logger, process_record)
logger.warn("My message")

例子：

# 0:00:02.127129: My message

这会将对象转换datetime.timedelta为字符串。您可以使用以下命令将其格式化为以毫秒为单位的值：

try:
    formatted = '{}ms'.format(delta.total_seconds() * 1000)
except AttributeError:
    formatted = '0ms'
return {'time_since_last': formatted}

这需要 Python 2.7+（对于total_seconds()）。