Python 日志模块logging的使用

logging模块是Python内置的标准模块，主要用于输出运行日志，可以设置输出日志的等级、日志保存路径、日志文件回滚等，相比print，具备如下优点：

• 可以通过设置不同的日志等级，在release版本中只输出重要信息，而不必显示大量的调试信息
• print将所有信息都输出到标准输出中，严重影响开发者从标准输出中查看其它数据；logging则可以由开发者决定将信息输出到什么地方，以及怎么输出。

logging模块的主要优点：

• 对多线程支持
• 通过不同级别对日志进行分类
• 灵活性和可配置性
• 将如何记录日志与记录什么内容分离

logging模块的组成

logging库采用了模块化的设计，logging模块四大组件：

日志事件信息是以LogRecord实例的形式在Logger, Handler, Filter, Formatter之间传递。

官方的logging模块工作流程图如下：

logging的整个工作流程：

• 判断Logger对象对于设置的级别是否可用，如果可用，则往下执行，否则，流程结束。
• 创建LogRecord对象，如果注册到Logger对象中的Filter对象过滤后返回False，则不记录日志，流程结束，否则，则向下执行。
• LogRecord对象将Handler对象传入当前的Logger对象，（图中的子流程）如果Handler对象的日志级别大于设置的日志级别，再判断注册到Handler对象中的Filter对象过滤后是否返回True而放行输出日志信息，否则不放行，流程结束。
• 如果传入的Handler大于Logger中设置的级别，也即Handler有效，则往下执行，否则，流程结束。
• 判断这个Logger对象是否还有父Logger对象，如果没有（代表当前Logger对象是最顶层的Logger对象rootLogger），流程结束。否则将Logger对象设置为它的父Logger对象，重复上面的3、4两步，输出父类Logger对象中的日志输出，直到是rootLogger为止。

组件之间的关联关系：

• 日志器（logger）需要通过处理器（handler）将日志信息输出到目标位置
• 不同的处理器（handler）可以将日志输出到不同的位置
• 日志器（logger）可以设置多个处理器（handler）将同一条日志记录输出到不同的位置
• 每个处理器（handler）都可以设置自己的过滤器（filter）实现日志过滤，从而只保留感兴趣的日志
• 每个处理器（handler）都可以设置自己的格式器（formatter）实现同一条日志以不同的格式输出到不同的地方

一条日志信息要想被最终输出需要依次经过以下几次过滤：

• 日志器等级过滤
• 日志器的过滤器过滤
• 日志器的处理器等级过滤
• 日志器的处理器的过滤器过滤

总言之：日志器（logger）是入口，真正干活的是处理器（handler），处理器（handler）还可以通过过滤器（filter）和格式器（formatter）对要输出的日志内容做过滤和格式化等处理操作。Logger可以包含一个或多个Handler和Filter，Logger与Handler或Fitler是一对多的关系。一个Logger实例可以新增多个Handler，一个Handler可以新增多个格式化器或多个过滤器，而且日志级别将会继承。

LogRecord

Logger每次记录日志都会创建LogRecord实例，LogRecord的这些属性用来将日志数据记录合并到格式化字符串中。下表列出了常用属性名：

日志器Logger

Logger对象是logging库中最为常用的对象，Logger对象的作用主要有三个：

• 为应用暴露出info、warning、error等方法，应用可以通过这些方法创建对应级别的日志。
• 根据Filter和日志级别的设置，来决定哪些日志可以被传入给下一个流程处理，
• 将日志传递到所有相关的Handler中。

Logger从来不直接实例化，经常通过module-level函数logging.getLogger(name)来获得，其中如果name不给定就用root。每一个实例都有一个名字，它们在概念上组织成一个层级式的命名空间，用dots(periods)作为分割符，例如’scan’是’scan.text’,’scan.html’,’scan.pdf’的父Logger。Logger的名称可以任意命名，用以表示记录的信息是在应用程序的哪个部分产生。这种命名方式里面，后面的loggers是前面logger的子logger，自动继承父loggers的log信息，正因为此,没有必要把一个应用的所有logger都配置一遍，只要把顶层的logger配置好了，然后子logger根据需要继承就行了。

命名Logger的一个好的习惯是使用module-level logger，在每一个模块中使用logging，命令如下：logger = logging.getLogger(__name__)

如果添加一个Handler到Logger和它的一个或多个祖先中，它可能会被多次打印相同的记录。一般来说，不应该将一个Handler添加给多个Logger，如果只将Handler添加到合适的Logger而它是Logger层次中的长老，那么它将看到所有子Logger记录的事件。

Logger对象最常用的方法分为两类：配置方法和消息发送方法

最常用的配置方法如下：

关于Logger.setLevel()方法的说明：内建等级中，级别最低的是DEBUG，级别最高的是CRITICAL。例如setLevel(logging.INFO)，此时函数参数为INFO，那么该logger将只会处理INFO、WARNING、ERROR和CRITICAL级别的日志，而DEBUG级别的消息将会被忽略/丢弃。

logger.setLevel(logging.ERROR) #设置日志级别为ERROR，即只有日志级别大于等于ERROR的日志才会输出。需要说明的是，root logger总是会有一个明确的level设置（默认为WARNING）。

日志级别（从高到低）：

logger对象配置完成后，可以使用下面的方法来创建日志记录：

kwargs中会检查四个关键字参数exc_info、stack_info、stacklevel和extra。

• exc_info参数的求值不为False时，则会将异常信息添加到日志消息中，这通常是传入一个元组（格式类似于exc_info()的返回）或者exception实例；否则会自行调用sys.exc_info()获取异常信息。
• stack_info的值默认为False，如果为True则将堆栈信息也添加到日志消息中去，包括到logging被调用的过程。和exc_info不同的是，前者是记录从堆栈底部到当前线程中日志记录调用的堆栈帧stack frame，后者是在搜索异常处理程序时的异常跟踪记录。
• stacklevel默认为1，如果大于1，则日志事件在产生LogRecord，堆栈帧创建时会跳过对应数量的行号和函数名。
• extra是保留关键字参数，用于传递字典，这个字典可以填充到LogRecord的__dict__中，以供后续使用这些用户自定义属性。比如在formatter中定义了fmt=’%(asctime)-15s %(clientip)s %(user)-8s %(message)s’，那么可以在使用logger接口时传入：warning(“Problem: %s”, “connection timeout”, extra={‘clientip’:’192.168.0.1′,’user’:’fbloggs’})。

说明：

• exception()与Logger.error()的区别在于：Logger.exception()将会输出堆栈追踪信息，另外通常只是在一个exception handler中调用该方法。
• log()与Logger.debug()、Logger.info()等方法相比，虽然需要多传一个level参数，显得不是那么方便，但是当需要记录自定义level的日志时还是需要该方法来完成。

处理器handler

Handler对象的作用是（基于日志消息的level）将消息分发到handler指定的位置（文件、网络、邮件等）。Logger对象可以通过addHandler()方法为自己添加0个或者更多个handler对象。比如，一个应用程序可能想要实现以下几个日志需求：

• 把所有日志都发送到一个日志文件中
• 把所有严重级别大于等于error的日志发送到stdout（标准输出）
• 把所有严重级别为critical的日志发送到一个email邮件地址

这种场景就需要 3 个不同的 handlers，每个 handler 负责发送一个特定严重级别的日志到一个特定的位置。

一个 handler 中只有非常少数的方法是需要应用开发人员去关心的。对于使用内建 handler 对象的应用开发人员来说，似乎唯一相关的 handler 方法就是下面这几个配置方法：

需要说明的是，应用程序代码不应该直接实例化和使用 Handler 实例。因为 Handler 是一个基类，它只定义了所有 handlers 都应该有的接口，同时提供了一些子类可以直接使用或覆盖的默认行为。下面是一些常用的 Handler：

过滤器 Filter

Filter 实际上是作为 logger.level 的补充，提供了更细粒度的工具，用于确定要输出哪些 LogRecord。多种 filter 可以同时应用在 logger 和 handler 中。用户可以声明它们自己的 filter 作为对象，使用 filter 方法获取 LogRecord 作为输入，并提供 True/False 作为输出。Filter 可以被 Handler 和 Logger 用来做比 level 更细粒度的、更复杂的过滤功能。Filter 是一个过滤器基类，它只允许某个 logger 层级下的日志事件通过过滤。该类定义如下：

class Filter:
    def filter(self, record):
        """
        Return a value indicating true if the record is to be
        processed. Possibly modify the record, if deemed
        appropriate by the filter.
        """

比如，一个 filter 实例化时传递的 name 参数值为 ‘A.B’，那么该 filter 实例将只允许名称为类似如下规则的 loggers 产生的日志记录通过过滤：’A.B’，’A.B,C’，’A.B.C.D’，’A.B.D’，而名称为 ‘A.BB’,’B.A.B’ 的 loggers 产生的日志则会被过滤掉。如果 name 的值为空字符串，则允许所有的日志事件通过过滤。

filter 方法用于具体控制传递的 record 记录是否能通过过滤，如果该方法返回值为 0 表示不能通过过滤，返回值为非 0 表示可以通过过滤。

说明：

• 如果有需要，也可以在 filter(record) 方法内部改变该 record，比如添加、删除或修改一些属性。
• 我们还可以通过 filter 做一些统计工作，比如可以计算下被一个特殊的 logger 或 handler 所处理的 record 数量等。

格式器 Formatter

Formater 对象用于配置日志信息的最终顺序、结构和内容。与 logging.Handler 基类不同的是，应用代码可以直接实例化 Formatter 类。另外，如果你的应用程序需要一些特殊的处理行为，也可以实现一个 Formatter 的子类来完成。

Formatter 类的构造方法定义如下：

logging.Formatter.__init__(fmt=None, datefmt=None, style=’%’)

可见，该构造方法接收 3 个可选参数：

• fmt：指定消息格式化字符串，如果不指定该参数则默认使用 message 的原始值
• datefmt：指定日期格式字符串，如果不指定该参数则默认使用 “%Y-%m-%d %H:%M:%S”
• style：Python 3.2 新增的参数，可取值为 ‘%’, ‘{‘ 和 ‘$’，如果不指定该参数则默认使用 ‘%’

formatter 指定了 LogRecord 最终输出的形态。如果没有提供，默认使用 ‘%(message)s’，这个值仅包含 LogRecord 调用时传入的消息。一般的格式器由 logging 库提供，其构造方法为 ft=logging.Formatter.__init__(fmt=None, datefmt=None, style=’%’)，然后占位符可以在一个 LogRecord 中声明所有属性；如果不指定 datafmt 则默认是 %Y-%m-%d %H:%M:%S 的样式。

logging 模块的配置

像这样的日志记录系统的主要好处是，可以控制从应用程序获得的日志记录输出的数量和内容，而无需更改该应用程序的源代码。因此，尽管可以通过日志 API 执行配置，但也必须能够在根本不更改应用程序的情况下更改日志配置。对于像 Zope 这样的长时间运行的程序，应该可以在程序运行时更改日志记录配置。

配置包括以下内容：

• 记录器或处理程序应该感兴趣的日志记录级别。
• 哪些处理程序应该附加到哪些记录器。
• 哪些过滤器应该附加到哪些处理程序和记录器。
• 指定特定于某些处理程序和筛选器的属性。

一般来说，对于用户如何配置日志输出，每个应用程序都有自己的需求。但是，每个应用程序都将通过标准机制为日志系统指定所需的配置。

最简单的配置是单个处理程序的配置，将其写入stderr，并连接到根记录器。导入日志模块后，通过调用basicConfig()函数来设置此配置。

基本配置basicConfig

下面是一个最简单的设置：

logging.basicConfig(level="INFO")

这会搭建一个基础的StreamHandler，这样就会在控制台上输出在INFO层级之上的任何LogRecord。下面是基础设置的一些参数：

字典配置dictConfig

可以用字典来说明元素的设置。这个字典应当由不同的部分组成，包括logger、handler、formatter以及一些基本的通用参数。代码示例：

config = {
    'disable_existing_loggers': False,
    'version': 1,
    'formatters': {
        'short': {
            'format': '%(asctime)s %(levelname)s %(name)s:%(message)s'
        },
    },
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'formatter': 'short',
            'class': 'logging.StreamHandler',
        },
    },
    'loggers': {
        '': {
            'handlers': ['console'],
            'level': 'DEBUG',
        },
        'plugins': {
            'handlers': ['console'],
            'level': 'INFO',
            'propagate': False
        }
    },
}

import logging.config
logging.config.dictConfig(config)

当被引用时，dictConfig将会禁用所有运行的记录器，除非disable_existing_loggers被设置为False。这通常是需要的，因为很多模块声明了一个全局记录器，它在dictConfig被调用之前被导入的时候将会实例化。

文件配置fileConfig

logging.conf采用了模式匹配的方式进行配置，正则表达式是r’^[(.*)]$’，从而匹配出所有的组件。对于同一个组件具有多个实例的情况使用逗号’，’进行分隔。

配置文件：

# logger.conf
###############################################
[loggers]
keys=root,example01,example02
[logger_root]
level=DEBUG
handlers=hand01,hand02
[logger_example01]
handlers=hand01,hand02
qualname=example01
propagate=0
[logger_example02]
handlers=hand01,hand03
qualname=example02
propagate=0
###############################################
[handlers]
keys=hand01,hand02,hand03
[handler_hand01]
class=StreamHandler
level=INFO
formatter=form02
args=(sys.stderr,)
[handler_hand02]
class=FileHandler
level=DEBUG
formatter=form01
args=('myapp.log','a')
[handler_hand03]
class=handlers.RotatingFileHandler
level=INFO
formatter=form02
args=('myapp.log','a',10*1024*1024,5)
###############################################
[formatters]
keys=form01,form02
[formatter_form01]
format=%(asctime)s%(filename)s[line:%(lineno)d]%(levelname)s%(message)s
datefmt=%a,%d%b%Y%H:%M:%S
[formatter_form02]
format=%(name)-12s:%(levelname)-8s%(message)s
datefmt=

然后在代码中使用：

import logging
import logging.config

logging.config.fileConfig("logger.conf")
logger = logging.getLogger("example01")

logging模块使用实例

基本使用

import logging

logging.basicConfig()
logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

输出结果：

WARNING:root:This is a warning message
ERROR:root:This is an error message
CRITICAL:root:This is a critical message

默认打印的日志级别是 WARNING，不输出到文件，格式默认。当然，我们可以在 basicConfig 中传入一些参数进行定制：

import logging

logging.basicConfig(filename="test.log",
filemode="w",
format="%(asctime)s %(name)s:%(levelname)s:%(message)s",
datefmt="%Y-%m-%d %H:%M:%S",
level=logging.DEBUG)

logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

运行完毕，我们就可以在 test.log 中看到如下内容了：

2021-07-08 18:48:43 root:DEBUG:This is a debug message
2021-07-08 18:48:43 root:INFO:This is an info message
2021-07-08 18:48:43 root:WARNING:This is a warning message
2021-07-08 18:48:43 root:ERROR:This is an error message
2021-07-08 18:48:43 root:CRITICAL:This is a critical message

注意，此时输出到文件中，因此屏幕是不会打印任何内容的。

自定义 logger

代码示例：

import logging

logger = logging.getLogger("logger")

handler1 = logging.StreamHandler()
handler2 = logging.FileHandler(filename="test.log")

logger.setLevel(logging.DEBUG)
handler1.setLevel(logging.WARNING)
handler2.setLevel(logging.DEBUG)

formatter = logging.Formatter("%(asctime)s %(name)s %(levelname)s %(message)s")
handler1.setFormatter(formatter)
handler2.setFormatter(formatter)

logger.addHandler(handler1)
logger.addHandler(handler2)

logger.debug('This is a customer debug message')
logger.info('This is an customer info message')
logger.warning('This is a customer warning message')
logger.error('This is an customer error message')
logger.critical('This is a customer critical message')

控制台输出结果：

2021-07-08 18:45:46,879 logger WARNING This is a customer warning message
2021-07-08 18:45:46,879 logger ERROR This is an customer error message
2021-07-08 18:45:46,879 logger CRITICAL This is a customer critical message

文件输出结果：

2021-07-08 18:45:46,879 logger DEBUG This is a customer debug message
2021-07-08 18:45:46,879 logger INFO This is an customer info message
2021-07-08 18:45:46,879 logger WARNING This is a customer warning message
2021-07-08 18:45:46,879 logger ERROR This is an customer error message
2021-07-08 18:45:46,879 logger CRITICAL This is a customer critical message

备注：创建了自定义的 Logger 对象，就不要在用 logging 中的日志输出方法了，这些方法使用的是默认配置的 Logger 对象，输出的日志信息会重复。

实战中的问题

中文乱码解决方案

# 自定义 Logger 配置
handler = logging.FileHandler(filename="test.log", encoding="utf-8")

# 使用默认的 Logger 配置
logging.basicConfig(handlers=[logging.FileHandler("test.log", encoding="utf-8")], level=logging.DEBUG)

临时禁用日志输出

logging.disable(logging.INFO)

logger.disabled = True

日志文件按照时间划分或者按照大小划分

# 每隔 1000 Byte 划分一个日志文件，备份文件为 3 个
file_handler = logging.handlers.RotatingFileHandler("test.log", mode="w", maxBytes=1000, backupCount=3, encoding="utf-8")

# 每隔 1 小时划分一个日志文件，interval 是时间间隔，备份文件为 10 个
handler2 = logging.handlers.TimedRotatingFileHandler("test.log", when="H", interval=1, backupCount=10)

记录 JSON 日志

import logging
import logging.config
import json

ATTR_TO_JSON = ['created', 'filename', 'funcName', 'levelname', 'lineno', 'module', 'msecs', 'msg', 'name', 'pathname', 'process', 'processName', 'relativeCreated', 'thread', 'threadName']

class JsonFormatter:
    def format(self, record):
        obj = {attr: getattr(record, attr) for attr in ATTR_TO_JSON}
        return json.dumps(obj, indent=4)

handler = logging.StreamHandler()
handler.formatter = JsonFormatter()
logger = logging.getLogger(__name__)
logger.addHandler(handler)
logger.error("Hello")

参考链接：

• PEP 282 — A Logging System
• Python Logging: A Stroll Through the Source Code