【译】Python3.8官方Logging文档（完整版）

01

—

基础部分

日志是用来的记录程序运行事件的工具。当 程序员 可以通过添加日志打印的代码来记录程序运行过程中发生的某些事件时。这些事件包含了诸如变量数据在内的描述信息，当然也包括开发人员认为重要的诸如日志级别等信息。

什么时候使用Loggin包

针对简单的场景，Loggin包提供了一系列方便的函数。其中包括debug()、info()、warning()、error()以及 critical()。下面的表格列举了什么函数适用于什么场景。

日志函数的命名依据于约定俗成的事件级别。不同事件级别的适用范围可以参考下面的这个表格（按照级别的严重程度升序排列）：

缺省的事件级别为 WARNING ，也就是说只有 WAR NIN G 级别已经高于 WAR NIN G 级别的事件可以被捕捉到。如果需要其他级别的信息，可以显式的设置日志级别。

针对捕捉到的运行事件有多种的处理措施，最简单的措施就是在控制台打印出来，当然也可以把这些事件信息记录到磁盘。

简单演示

下面是一个非常简单的用例：

import logging
logging.warning('Watch out!')  # 信息会被输出到控制台
logging.info('I told you so')  # 这时不会打印任何信息

运行上述代码，执行结果如下：

WARNING:root:Watch out!

INFO 级别的消息没有输出是因为缺省的日志级别是 WARNING 级别。观察输出信息，其中包含了日志级别以及调用日志函数时的入参信息（示例中为 ‘Watch out!’ ）。你可能会对中间的root有些疑惑，稍后会解释的。实际使用时，你可以根据需要灵活调整输出格式，对于输出格式稍后也会进一步解释。

把日志写入文件

这一部分是介绍比较实用的一种形式——是把日志记录在文件中。如果你打算运行下面的代码示例，记得新打开一个 Python 运行界面，而不是继续使用上面运行过的。

import logging
logging.basicConfig(filename='example.log',level=logging.DEBUG)
logging.debug('This message should go to the log file')
logging.info('So should this')
logging.warning('And this, too')

执行完这段代码之后，打开日志文件就会发现多了这些日志内容：

DEBUG:root:This message should go to the log file
INFO:root:So should this
WARNING:root:And this, too

上面的实例也展示了可以在一开始通过配置改变日志级别。因为一开始就把日志级别设置为了 DEBUG ，所以对应的日志也被记录了下来。

如果你你希望通过以下方式在命令行配置日志级别：

--log=INFO

如果向--log传递了符合规范的变量值，可以使用：

getattr(logging, loglevel.upper())

来获取入参，进而传递给basicConfig()函数。或许你也想到了需要对入参进行校验，下面提供了一个校验入参的示例：

# assuming loglevel is bound to the string value obtained from the
# command line argument. Convert to upper case to allow the user to
# specify --log=DEBUG or --log=debug
numeric_level = getattr(logging, loglevel.upper(), None)
if not isinstance(numeric_level, int):
    raise ValueError('Invalid log level: %s' % loglevel)
logging.basicConfig(level=numeric_level, ...)

basicConfig()函数的调用必须在debug()、info()以及其他日志输出函数之前。必须指出的是，baiscConfig()函数仅在第一次调用的时候生效，再次调用将不会产生任何作用。

如果你多次运行了上面的代码，你会发现日志文件里保存了多次运行的日志信息。可能你不需要把每次运行的日志信息都记录下来，而是仅保留最新的一次，那么你可以通过改变 filemode   入参来实现，下面是一个示例：

logging.basicConfig(filename='example.log', filemode='w', level=logging.DEBUG)

这样话，虽然多次运行都是一样的日志，但是只有最新一次的运行日志被保留下来，之前的都会被刷掉。

在多个模块中使用Logging

如果你的程序包含多个模块，你可以参考下面的示例来组织你的代码：

# myapp.py
import logging
import mylib

def main():
    logging.basicConfig(filename='myapp.log', level=logging.INFO)
    logging.info('Started')
    mylib.do_something()
    logging.info('Finished')

if __name__ == '__main__':
    main()

# mylib.py
import logging

def do_something():
    logging.info('Doing something')

运行 myapp.py 后，你会发现 myapp.log 记录的日志信息如下：

INFO:root:Started
INFO:root:Doing something
INFO:root:Finished

实际结果和你期望的一样。 mylib.py 的示例你可以灵活运用在你自己的多模块程序中。不过，需要注意的是，在这个简单的示例中，不同py文件的日志被穿插保存。《高级部分》（老张后面的推送会更新）部分会提供给你进一步的区分不同py文件日志信息的方法。

记录变量信息

通过格式化字符串的方式可以将想要保存的描述信息以及变量方便的保存下来。举个例子：

import logging
logging.warning('%s before you %s', 'Look', 'leap!')

运行结果如下：

WARNING:root:Look before you leap!

和你看到的一样，将变量格式化到描述信息的方式是使用的%这种旧的形式。这是为了向后兼容：logging包比新的格式化方式（比如str.format()、string.Template）诞生的要早。虽然logging也支持新的格式化方式，但是这里不做介绍。

自定义日志信息的格式

如果有需要，你可以自定义日志消息的格式：

import logging
logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)
logging.debug('This message should appear on the console')
logging.info('So should this')
logging.warning('And this, too')

运行结果如下：

DEBUG:This message should appear on the console
INFO:So should this
WARNING:And this, too

可以看到之前一直在日志消息里面出现的“root”消失了。还有其他好多配置项，但是在简单场景下，你需要也许仅是levelname（级别），message（事件描述、变量信息），以及事件的发生时间。下面一章介绍时间配置。

展示时间信息

你可以通过增加 ‘%(asctime)s’来让你的程序输出时间信息：

import logging
logging.basicConfig(format='%(asctime)s %(message)s')
logging.warning('is when this event was logged.')

运行结果如下：

2010-12-12 11:41:42,612 is when this event was logged.

如上所示，默认的时间输出格式是 ISO8601 或者RFC 3339标准。如果你需要自定义时间格式，可以在调用basicConfig显示传入参数 datefmt ，示例如下：

import logging
logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%m/%d/%Y %I:%M:%S %p')
logging.warning('is when this event was logged.')

运行结果如下：

12/12/2010 11:46:36 AM is when this event was logged.

datefmt 的格式配置信息同time.strftime()一样。

总结

通过对《基础部分》的学习，你应该掌握了如何在程序里添加日志代码。logging还提供了高阶用法，为了能够掌握高阶用法，你应该继续阅读《高级部分》（老张这里顺道挖个坑）。

但是如果你仅仅是想跟上面介绍一样，简单的在程序里面使用日志，并且你有什么不明白的地方，可以把问题发在：

https://groups.google.com/forum/#!forum/comp.lang.python

你会很快收到回复的。

02

—

高级部分

logger = logging.getLogger(__name__)

severity:logger name:message

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

%Y-%m-%d %H:%M:%S

'%(asctime)s - %(levelname)s - %(message)s'

import logging

# create logger
logger = logging.getLogger('simple_example')
logger.setLevel(logging.DEBUG)

# create console handler and set level to debug
ch = logging.StreamHandler()
ch.setLevel(logging.DEBUG)

# create formatter
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# add formatter to ch
ch.setFormatter(formatter)

# add ch to logger
logger.addHandler(ch)

# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warning('warn message')
logger.error('error message')
logger.critical('critical message')

$ python simple_logging_module.py
2005-03-19 15:10:26,618 - simple_example - DEBUG - debug message
2005-03-19 15:10:26,620 - simple_example - INFO - info message
2005-03-19 15:10:26,695 - simple_example - WARNING - warn message
2005-03-19 15:10:26,697 - simple_example - ERROR - error message
2005-03-19 15:10:26,773 - simple_example - CRITICAL - critical message

import logging
import logging.config

logging.config.fileConfig('logging.conf')

# create logger
logger = logging.getLogger('simpleExample')

# 'application' code
logger.debug('debug message')
logger.info('info message')
logger.warning('warn message')
logger.error('error message')
logger.critical('critical message')

[loggers]
keys=root,simpleExample

[handlers]
keys=consoleHandler

[formatters]
keys=simpleFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_simpleExample]
level=DEBUG
handlers=consoleHandler
qualname=simpleExample
propagate=0

[handler_consoleHandler]
class=StreamHandler
level=DEBUG
formatter=simpleFormatter
args=(sys.stdout,)

[formatter_simpleFormatter]
format=%(asctime)s - %(name)s - %(levelname)s - %(message)s
datefmt=

$ python simple_logging_config.py
2005-03-19 15:38:55,977 - simpleExample - DEBUG - debug message
2005-03-19 15:38:55,979 - simpleExample - INFO - info message
2005-03-19 15:38:56,054 - simpleExample - WARNING - warn message
2005-03-19 15:38:56,055 - simpleExample - ERROR - error message
2005-03-19 15:38:56,130 - simpleExample - CRITICAL - critical message

version: 1
formatters:
  simple:
    format: '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
handlers:
  console:
    class: logging.StreamHandler
    level: DEBUG
    formatter: simple
    stream: ext://sys.stdout
loggers:
  simpleExample:
    level: DEBUG
    handlers: [console]
    propagate: no
root:
  level: DEBUG
  handlers: [console]

在库中使用logging

如果你会在自己开发的库里面使用logging，那么你需要仔细确认库是如何使用logging的，举个例子：关于loggers的名字。仔细确认如何配置logging是必须的。如果调用方没有使用logging，但是库内部使用了logging， WARNING 级别及以上的日志消息将会输出到sys.stderr。看过了之前的介绍，你应该知道这是默认行为。

如果你期望在没有主动配置的情况不输出这些日志消息，你可以给你的库里面最高层的logger实例添加一个没有任何操作的handler。这样就可以避免日志被打印出来，原因就是对于库内部而言日志消息都会交给这个handler处理，但是这个handler并不会打印输出任何东西。一旦，调用程序主动配置添加了handler对象，你的库内部产生日志消息也会被处理，如果配置的日志级别适配，那么消息将会被打印输出。

在Python3.1版本之后，NullHandler被引入，但是它实际上并不会对日志消息做任何处理。如果你不希望你的库内部日志在配置缺失的情况下被输出到sys.stderr，你可以实例化一个NullHandler，并把它添加到顶层的logger实例。举个例子，如果一个名为foo的库实例化了诸如‘foo.x’、‘foo.x.y’的logger，你可以这样：

import logging
logging.getLogger('foo').addHandler(logging.NullHandler())

在一个组织提供了多个库的场景下，这样做使得实际当中logger的命名为orgname.foo而不是foo。

提示： 对于库，除了NullHandler之外，不要再添加任何其他handler。 这是因为你应该把控制权交给调用方。 只有调用方结合自己的实际情况能够决定使用什么样的handler。 如果你在库里面添加了handler，你可能会影响调用方的单元测试结果，并且输出一些他们不需要的东西。

日志级别跟logger实例关联方式有两种：一是开发人员主动配置，二是通过配置文件加载。当logger实例的日志方法被调用的时候，logger会检查它的级别配置跟日志方法是否匹配。如果logger的级别比日志方法要高，实际上就不会产生任何日志消息。它从构造机制上避免了产生冗余的输出。

日志消息实际上是LogRecord类的实例化。当logger决定生成一条日志消息的时候，实际上是根据消息内容实例化了LogRecord。

日志消息随后会由 Handler子类 的实例 来处理。handler实例会根据日志级别决定一条日志消息的最终流向（可能会有多个流向，诸如用户、编辑、管理员、开发人员）。handler会将LogRecord实例传递到合适的目的地。每个logger实例都可以有0个、1个或者多个handler（还记得addHandler()函数吗）。当一个logger实例产生一条日志消息之后，它的所有handler、它上层logger的所有handler都会被调用（除非这个logger的 propagate 值被置为False），分别处理这个日志消息。

logger实例和handler实例的日志级别可以不一致。它们分别都会根据日志级别做过滤。在handler最终处理日志消息的时候，emit()方法将被用来向传递消息。大多Handler子类都复写了emit()方法。

自定义日志级别

你可能会自定义日志级别，但其实那是没必要，因为这些日志级别就是实践中总结出来的。如果你确定需要自定义，请务必小心，对于库开发而言这样做甚至是有害的。原因是，如果不同的库均自定义了日志级别，但是它们之间又不一致（一个数值可能对应多个不同级别），对于调用方的开发人员简直就是灾难。

实用的handler

作为对Handler基类的补充，几个实用的handler子类如下：

1. StreamHandler实例会将消息发送到数据流（类似于文件对象）。

2. FileHandler实例会将消息写入磁盘文件。

3. BaseRotatingHandler是滚动日志的基类，滚动日志会在指定的时机滚动日志文件。它不能直接被实例化，实际使用的是RotatingFileHandler或者TimedRotatingHandler。

4. RotatingFileHandl er 实例会将消息写入磁盘文件，并在日志文件的占用空间达到最大值的时候滚动日志文件。

5. TimedRotatingHandler实例会将消息写入磁盘文件，并在根据指定的时间间隔滚动日志文件。

6. SockerHandler实例会通过TCP/IP套接字发送日志消息。在3.4版本之后，Unix套接字也开始被支持。

7. DatagramHandler实例会通过UDP发送日志消息。在3.4版本之后，Unix套接字也开始被支持。

8. SMTPHandler实例会将日志消息发送到指定的电子邮箱。

9. SysLogHandler实例可以把日志消息发送到Unix系统日志守护程序（可能是一台远程机器）。

10. NTEventLogHandler实例会把日志消息发送到 Windows NT/2000/XP 系统日志。

11. MemoryHandler实例会把日志消息写入内存的缓冲区，这意味着可以通过指令清除。

12. HTTPHandler实例通过GET或POST的方式把日志消息发到HTTP服务器。

13. WatchedFileHandler实例可以监控日志文件。一旦文件发生改动，它会关闭并重新打开一个同名文件。该handler只可以在类Unix系统上使用，因为Windows系统底层不支持。

14. QueueHandler实例将日志消息保存到一个队列，就像queue或者multiprocessing模块实现的那样。

15. NullHandler实例对于错误日志没有任何响应。如果在功能库的开发中想要使用logging，但是又要在没有配置信息时避免显示类似 ‘No handlers could be found for logger XXX’  这种消息，可以考虑使用NullHandler。

注： NullHandler在3.1版本引入

注： QueueHandler在3.2版本引入

其中NullHandler、StreamHandler和FileHandler在logging核心包中定义。其他的handler在子模块logging.handlers中。（还有一个子模块logging.config用于配置）

已经输出的日志消息在在Formatter类内部被格式化的。通过带有‘%’符号的预格式化的字符串以及一个字典来初始化Formatter对象。

如果想要批处理多条消息，可以考虑使用BufferingFormatter实例。为了方便格式化字符串（即批处理），它提供了针对头尾字符串格式的要求。

如果通过配置logger和handler的日志级别不能够满足你的需要的时候，logger或者handler都可以单独配置Filter实例（通过调用addFilter()函数）。在进一步处理日志消息之前，logger和handler都会调用已注册的filter来判断是否过滤该消息。如果其中任何一个filter实例返回了False，那么这条消息都会被丢弃。

基本的Filter用法是通过logger名来过滤。如果该配置生效，那么发送到指定logger，以及其子类传递上来的日志消息均会被丢弃。

logging的异常处理

logging具备可以消化自身异常的能力。换句话说，logging本身运行产生的诸如配置错误、网络问题之类的错误并不会导致调用程序结束运行。

除了SystemExit和KeyboardInterrupt之外，emit()方法产生的其他异常将会被丢给自身的handleError()方法处理。

handlerError()方法会检查名为 raiseExceptions的 配置项，如果设置了该配置项，handler会将错误信息输出到sys.stderr，如果没有配置该配置项，错误信息会被内部消化。

提示： raiseExceptions 的缺省值是True。 知道你不希望在开发时被这些错误信息牵扯精力，所以默认就是True。 但是建议你在线上环境要将 raiseExceptions 设置为False。

在消息里面使用任何对象

在上面的介绍里，你可能会发现了所有的日志消息都是字符串。并不是说明只有字符串才能当作日志消息传递给logging，实际上，你可以使用任何对象。logging内部会调用这些对象的__str__()方法，将他们转成字符串。你甚至可以完全避免用到字符串，举个例子：SocketHandler在发送消息的时候用到的二进制表示。

优化

虽然只有在最后用到的时候才会格式化日志消息，但是针对日志方法的入参做的运算也是巨大的，你可能期望logging对于被丢弃的消息节省这些计算。你可以通过调用isEnabledFor()方法（该方法接受一个日志界别的入参）来查看logging的行为，如果它返回了True即表明这个级别的日志消息会被Logger实例处理。代码示例如下：

if logger.isEnabledFor(logging.DEBUG):
    logger.debug('Message with %s, %s', expensive_func1(),
                                        expensive_func2())

这样就可以确定logger实例的不处理DEBUG级别的日志， expensive_func1() 和 expensive_func2()   就不会被执行到。

提示： 某些情况下isEnabledFor()方法可能比你想象的更昂贵（举个例子，嵌套的logger中，只有最上层的logger日志级别是高于入参的）。 在这种场景下（或者你只是想要避免嵌套调用一个方法），你可以把首次调用isEnabledFor()的结果缓存下来，后续只调用缓存的本地变量）。 这样你就可以仅在日志配置动态改变时计算新的变量值（其实这种场景并不常见）。

还有一种优化场景就是只有某种情况下希望能尽可能详细的收集日志信息。下表是一些你可以避免的一些资源浪费：

需要提醒的是logging核心模块仅包含基本的一些handler类。剩下的handler并不直接可用，而是需要你主动导入logging.handlers和logging.config。