Python中的多行日志记录

Question

我正在使用Python 3.3.5和日志记录模块将信息记录到本地文件（来自不同的线程）。有时我想输出一些额外的信息，但并不确定那些信息是什么（例如可能是单行文本或字典）。

我想做的是在日志记录被写入后向我的日志文件添加这些额外信息。此外，在日志级别为错误（或更高级别）时才需要这些额外信息。

理想情况下，它应该看起来像：

2014-04-08 12:24:01 - INFO     - CPU load not exceeded
2014-04-08 12:24:26 - INFO     - Service is running
2014-04-08 12:24:34 - ERROR    - Could not find any active server processes
Additional information, might be several lines.
Dict structured information would be written as follows:
key1=value1
key2=value2
2014-04-08 12:25:16 - INFO     - Database is responding

除了编写自定义日志格式化程序外，我找不到更符合我的要求的选项。我已经阅读了有关过滤器和上下文的内容，但这似乎并不是很匹配。

或者，我可以使用标准I/O将内容写入文件，但大多数功能已经存在于Logging模块中，并且此外它还是线程安全的。

如果您有任何意见或建议，我们将非常感激。如果确实需要自定义日志格式化程序，则在何处开始的任何指针都将非常棒。

- DocZerø

---

正如@BorrajaX在下面的回答中提到的那样，多行日志记录是一种不好的做法。我建议您实现记录JSON结构，并可选择将其解析为YAML以便在本地轻松阅读。我没有在Python中做过这个，但我在Node中做过，并发现它是两全其美的最佳选择。 - Mig82

Answer 1

请记住，许多人认为多行日志消息是一种不好的做法（这是可以理解的，因为如果您有像DataDog或Splunk这样的日志处理器，它们非常适合处理单行日志，那么多行日志将很难解析），您可以使用extra参数并使用自定义格式化程序附加内容到将要显示的消息中（请参阅logging包文档中“extra”用法）。

import logging

class CustomFilter(logging.Filter):
    def filter(self, record):
        if hasattr(record, 'dct') and len(record.dct) > 0:
            for k, v in record.dct.iteritems():
                record.msg = record.msg + '\n\t' + k + ': ' + v
        return super(CustomFilter, self).filter(record)
        
if __name__ == "__main__":
    logging.getLogger().setLevel(logging.DEBUG)
    extra_logger = logging.getLogger('extra_logger')
    extra_logger.setLevel(logging.INFO)
    extra_logger.addFilter(CustomFilter())
    logging.debug("Nothing special here... Keep walking")
    extra_logger.info("This shows extra",
                      extra={'dct': {"foo": "bar", "baz": "loren"}})
    extra_logger.debug("You shouldn't be seeing this in the output")
    extra_logger.setLevel(logging.DEBUG)
    extra_logger.debug("Now you should be seeing it!")
    

那段代码的输出结果是：

DEBUG:root:Nothing special here... Keep walking
INFO:extra_logger:This shows extra
        foo: bar
        baz: loren
DEBUG:extra_logger:Now you should be seeing it!

我仍然建议在您的自定义过滤器中调用super的filter函数，主要是因为这个函数决定是否显示消息（例如，如果您的记录器级别设置为logging.INFO，并且您使用extra_logger.debug记录某些内容，则该消息不应被看到，如上面的示例所示）

- BorrajaX

Answer 2

我只是在输出文本中添加了\n符号。

- user297171

---

如果我将日志格式化器定义为lf = logging.Formatter('%(levelname)-8s - %(message)s\\n%(detail)s')，并定义一个FileHandler来将日志写入文件，则输出结果将包含\n，而不会被转换成换行符。 - DocZerø

按照“记录指南”进行操作。使用 str.format() 格式来替代默认的基于百分号的格式 - 这样它将尊重特殊符号。 - user297171

Answer 3

我在我的小型应用程序中使用简单的行拆分器：

for line in logmessage.splitlines():
            writemessage = logtime + " - " + line + "\n"
            logging.info(str(writemessage))

请注意，这并不是线程安全的，可能只适用于大量日志记录应用程序。

然而，您可以将几乎任何内容输出到日志中，因为它将保留您的格式。例如，我曾使用它来输出使用json.dumps(parsed, indent=4, sort_keys=True)格式化的JSON API响应。

- Kamaradski

Answer 4

在定义我的LogFormatter字符串时，似乎我犯了一个小错误：不小心转义了换行符，错误地认为将多行输出写入日志文件是不可能的。

感谢@Barafu指出这一点（这就是为什么我将正确答案分配给他的原因）。

以下是示例代码：

import logging
lf = logging.Formatter('%(levelname)-8s - %(message)s\n%(detail)s')
lh = logging.FileHandler(filename=r'c:\temp\test.log')
lh.setFormatter(lf)
log = logging.getLogger()
log.setLevel(logging.DEBUG)
log.addHandler(lh)
log.debug('test', extra={'detail': 'This is a multi-line\ncomment to test the formatter'})

生成的输出将如下所示：

DEBUG    - test
This is a multi-line
comment to test the formatter

注意：

如果没有详细的信息需要记录，而您传递了一个空字符串，日志记录器仍将输出一个换行符。因此，剩下的问题是：我们如何使这个条件成立？

一种方法是在实际记录信息之前更新日志格式化程序，如此处所述。

- DocZerø