Python 日志使用详解

2020-01-30 language python

用 Python 写代码时，经常需要打印日志，其实内部提供了一个灵活的 logging 模块，基本可以满足绝大部分的需求，如下简单介绍其使用方式。

简介

Python 提供了标准的 logging 模块记录日志信息，可以设置格式、日志级别等，如下是最简单的使用，默认会输出到终端。

import logging

logging.basicConfig(
	level=logging.DEBUG,
	format='%(asctime)s - %(filename)s[line:%(lineno)d] - %(levelname)s: %(message)s'
)
logging.debug("this is a loggging debug message for %s", "world")
logging.info("this is a loggging info message for %s", "world")
logging.warning("this is a loggging warning message for %s", "world")
logging.error("this is a loggging error message for %s", "world")
logging.critical("this is a loggging critical message for %s", "world")

上述的日志级别依次递增。

当然，也可以指定输出到文件中。

# or truncate file with filemode=w
logging.basicConfig(filename="/tmp/test.log", filemode="a")

或者在异常地方通过 logger.exception() 输出，会同时包含调用栈信息，也可以用 logger.log("message", logging.DEBUG) 指定 logging 的级别。

除了上述的默认配置日志级别，可以通过 logger.setLevel(loggin.DEBUG) 动态设置，例如全局的可以通过 logging.getLogger().setLevel(logging.INFO) 配置。

基本原理

上述只是简单使用，实际上 logging 库还支持层级管理、多线程，其包含了四大组件：

  • Logger 提供了应用程序可使用的接口，可以实例化为对象；
  • Handler 将 logger 创建的日志记录发送到合适的目的输出，例如文件、标准输出等；
  • Filter 提供了更细粒度的控制工具来决定输出哪条日志记录，丢弃哪条日志记录；
  • Formatter 决定日志记录的最终输出格式。

其中 logger 对象可以通过 Logger 类直接创建实例，不过常用 logging.getLogger() 方法获取，入参是一个可选的 name 标示，默认是 root，当以相同的 name 参数调用时，返回的对象相同。

可以通过如下方式使用。

import logging


class TestFilter(logging.Filter):
    def __init__(self):
        super().__init__(name="foobar")

    def filter(self, record):
        assert isinstance(record, logging.LogRecord)
        if "hello" in record.getMessage():
            return True
        return False


def filter(record):
    assert isinstance(record, logging.LogRecord)
    if "hello" in record.getMessage():
        return True
    return False


# 创建一个 logger ,默认使用 root 作为名称
logger = logging.getLogger("foo")
logger.setLevel(logging.DEBUG)

handler = logging.StreamHandler()
formater = "%(asctime)s %(name)s %(levelname)s: %(message)s"
handler.setFormatter(logging.Formatter(formater))

logger.addHandler(handler)

# logger.addFilter(filter)
logger.addFilter(TestFilter())

logger.info("hey world")
logger.info("hello world")

日志层级

日志会通过 name 参数设置层级，以 . 分割，例如，有一个名称为 foo 的 logger，其它名称分别为 foo.bar、foo.bar.baz 和 foo.bam 都是 foo 的后代。

在当前层级完成日志处理后，默认将日志消息传递给与其祖先相关的 handler 处理，因此，通常只需要设置顶层 logger 即可，例如 handlers、formatter 等，然后按需设置子类。

import logging

# 这里实际上设置了root
logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s %(name)s %(levelname)s: %(message)s'
)

# 创建一个 logger ,默认使用 root 作为名称
logger_foo = logging.getLogger("foo")
logger_bar = logging.getLogger("foo.bar")

# 还可以对当前的 logger 进行配置
# stdout_handler = logging.StreamHandler()
# stdout_handler_fmt = "%(asctime)s %(levelname)s %(message)s"
# stdout_handler.setFormatter(logging.Formatter(stdout_handler_fmt))
# stdout_handler.setLevel(logging.DEBUG)
# logger_bar.addHandler(stdout_handler)
# logger_bar.propagate = True

logger_bar.info("hello world")

另外，也可以将 logger 的 propagate 属性设置为 False 来关闭这种传递机制，也就是 logger_bar.propagate = False 设置，这样上述的示例就不会打印信息。

日志处理流程

日志的写入流程如下图所示。

logging process

简单描述下日志的处理流程：

  1. 用户代码中调用日志记录函数，如 logger.info(...)、logger.debug(...) 等；
  2. 判断日志级别是否满足，可以通过 logger.setLevel(logging.DEBUG) 进行设置；
  3. 根据日志记录函数调用时的入参，创建一个类型为 Class LogRecord 的日志记录对象；
  4. 判断 logger 上设置的过滤器规则，满足则将日志记录交给该 logger 上的各个 handler 处理；
  5. 在 hanlder 中也要判断日志级别是否满足 handler 设置的级别要求，如果满足则格式化输出；
  6. 检查 logger.propagate 的值是否为 True，如果是则继续传递给上级 logger 的 hanlders 处理。

示例

如下示例将日志输出到文件和终端。

import logging

# 创建一个 logger ,默认使用 root 作为名称
logger = logging.getLogger("foobar")
logger.setLevel(logging.DEBUG)

# 创建一个 handler ，用于写入文件，只记录WARN以上日志
file_handler = logging.FileHandler("warn.log")
file_handler.setLevel(logging.WARN)
file_handler_fmt = "%(asctime)s %(levelname)s %(message)s"
file_handler.setFormatter(logging.Formatter(file_handler_fmt))

# 再创建一个 handler ，用于输出到控制台，使用默认格式，只输出日志
stdout_handler = logging.StreamHandler()
stdout_handler.setLevel(logging.DEBUG)

# 给 logger 添加 handler
logger.addHandler(file_handler)
logger.addHandler(stdout_handler)

logger.info("info message")
logger.warning("warn message")

运行会有如下输出。

$ python test.py
info message
warn message
$ cat warn.log
2020-01-30 23:34:18,037 WARNING warn message

也就是同一条日志，可以在终端和日志中定义不同的输出内容、格式等，也就带来了极大的灵活性。

日志切割

也就是根据日期、大小对日志文件进行切割，在 logging.handlers 中提供了很多类似的实现，例如 TimedRotatingFileHandler 和 RotatingFileHandler 类，都继承自 BaseRotatingHandler 类。

示例代码如下。

# 每隔1024B划分一个日志文件，备份文件为 3 个
handler = logging.handlers.RotatingFileHandler(
    "test.log", mode="w", maxBytes=1024, backupCount=3, encoding="utf-8"
)
# 每隔1小时 划分一个日志文件，interval 是时间间隔，备份文件为 10 个
handler = logging.handlers.TimedRotatingFileHandler(
    "test.log", when="H", interval=1, backupCount=10
)

参考

  • 官方帮助文档 Logging Howto 以及 Logging Cookbook，虽然没有搞清楚 Howto 和 Cookbook 啥区别，不过两者都是不错的参考。