给小工具记录运行信息：logging 基础配置的级别、格式与配置时机

如果你写了一个自建的小工具，想在它运行时留下“开始执行”“某一步完成”“出错了”这类记录，标准库 logging 就是为这个场景准备的。

按 Python 官方 logging 文档的说明，这个模块定义了一组函数和类，用来为应用和库实现灵活的事件记录系统。它给出的惯用写法是：在模块里用 logging.getLogger(__name__) 取一个模块级 logger，然后用这个 logger 去记录。文档举的例子是，myapp.py 里先调用 logging.basicConfig(filename='myapp.log', level=logging.INFO)，再通过 logger.info() 写入消息，运行后日志文件里会出现类似 INFO:__main__:Started 这样的行。

所以最小结构是两步：第一步，用 getLogger 拿到 logger；第二步，用 basicConfig 配置根 logger 的级别和输出位置。文档特别说明，basicConfig() 提供了一种快速配置根 logger 的方式，能覆盖很多使用场景；在多数情况下只需要配置根 logger，因为下层模块级 logger 的消息最终都会转发到它的处理器。

本文只处理一个自建场景：在练习目录里新建一个脚本，让它把运行信息写进一个新建的练习日志文件。不涉及网络、不涉及第三方库，也不记录密钥、Cookie 或任何真实用户资料。

动手前建议在练习目录里操作，例如 exercise/，不要拿正在用的工具直接改。下面所有路径和内容都是自建练习示例。

配置之前先弄清级别，因为它决定哪些消息会被记下来。

按文档的级别表，常用级别从低到高是：DEBUG（10，详细信息，通常只在诊断问题时关心）、INFO（20，确认事情按预期进行）、WARNING（30，表示发生了意外或将来可能出问题，软件仍能工作）、ERROR（40，较严重的问题，软件某项功能没能完成）、CRITICAL（50，严重错误，程序本身可能无法继续运行）。

关键的一条是：文档说明根 logger 创建时的级别是 WARNING。也就是说，如果你什么都不配置，INFO 和 DEBUG 级别的消息不会出现在输出里。想让工具的运行信息被记下来，通常要把级别调到 INFO。

可以这样理解这个门槛：logger 上设置的级别是阈值，低于它的消息会被忽略。文档在 setLevel 的说明里写的是，严重程度低于 level 的消息会被忽略，达到或高于 level 的消息才会被处理。

一个容易踩的点：logger 创建时的级别是 NOTSET，不是 WARNING。文档说明，非根 logger 处于 NOTSET 时会向上找祖先 logger 的级别，直到找到一个不是 NOTSET 的祖先，或者到达根 logger。所以你在子 logger 上不设级别，实际生效的是根 logger 的级别。这也是为什么只配置根 logger 往往就够了。

本文只讲级别怎么选，不涉及自定义级别数值。

级别定好之后，第二个要决定的是每行日志写什么。这由 basicConfig 的 format 参数控制。

文档在 Formatter 部分说明，fmt 是一个格式字符串，可用的映射键来自 LogRecord 对象的属性；如果不指定，默认用 '%(message)s'，也就是只输出消息本身。

对一个小工具来说，只输出消息往往不够用，因为你事后想知道“什么时候”“哪个模块”记的。文档列出的常用属性包括：asctime（记录创建时的人类可读时间）、levelname（级别名称）、name（logger 名称）、message（消息）。

下面是一个自建示例，把时间、级别、logger 名称和消息拼成一行：

import logging

logging.basicConfig(
    filename="exercise/tool_run.log",
    level=logging.INFO,
    format="%(asctime)s %(levelname)s %(name)s %(message)s",
)

logger = logging.getLogger(__name__)
logger.info("工具开始运行")
logger.info("第一步完成")

运行后，exercise/tool_run.log 里会出现类似这样的行（时间以实际运行为准）：

2024-03-15 10:20:30,123 INFO __main__ 工具开始运行
2024-03-15 10:20:30,124 INFO __main__ 第一步完成

关于时间格式：文档说明，如果 format 里包含 asctime，会调用 formatTime()；不指定 datefmt 时，默认格式是 '%Y-%m-%d %H:%M:%S,uuu'，其中 uuu 是毫秒值。

本文只演示这一种格式串，不涉及 style 参数的其他取值。

basicConfig 放在脚本的哪个位置，会影响它是否生效。

文档在 basicConfig 的说明里有一条重要限制：如果根 logger 已经有处理器，basicConfig() 不会做任何事。也就是说，它只在根 logger 还没有被配置过的时候起作用。

这条限制决定了配置时机：应该在脚本开始处、导入 logging 之后、调用任何 logger 方法之前，先调用 basicConfig。如果你先记了一条消息，再调用 basicConfig，配置可能不会按预期生效。

一个自建示例，把配置放在最前面：

import logging

logging.basicConfig(
    filename="exercise/tool_run.log",
    level=logging.INFO,
    format="%(asctime)s %(levelname)s %(name)s %(message)s",
)

logger = logging.getLogger(__name__)


def run_step():
    logger.info("执行一步")


logger.info("工具开始运行")
run_step()
logger.info("工具结束运行")

这里把 basicConfig 放在 getLogger 之前、任何 logger.info 之前。这样配置先落地，后面的记录才按你设定的级别和格式走。

另一个相关点：文档说明，用 getLogger(__name__) 取到的 logger 名称就是模块名，多次用同一个名字调用 getLogger 会返回同一个 Logger 对象。所以同一个模块里反复取 logger 不会产生多个实例。

本文只讲配置放在脚本开头这一种时机，不涉及用配置文件或字典配置的方式。

basicConfig 的 filename 参数决定日志写到哪里。

文档给出的惯用示例用的是 filename='myapp.log'，日志被写进这个文件。如果你不传 filename，basicConfig 默认把日志输出到终端（标准错误流）。

对小工具来说，两种选择各有用途：想事后翻查，就写文件；只想在运行时看一眼，就不传 filename。

一个自建示例，只输出到终端：

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(levelname)s %(message)s",
)

logger = logging.getLogger(__name__)
logger.info("这条只显示在终端")

如果同时想要文件和终端两份，basicConfig 一次调用只能指定一种主要输出方式；要同时输出到两处，需要自己添加处理器。文档在 Logger 部分说明，处理器负责把日志记录发送到合适的目的地，可以用 addHandler() 挂到 logger 上。

本文只演示 basicConfig 的 filename 和不传 filename 两种基本情况，不展开多处理器配置。

一个边界：写文件时，日志会追加到已有文件后面，不会清空原文件。所以练习时建议用一个专门的新文件名，例如 exercise/tool_run.log，不要指向你正在用的其他文件。

配置写完之后，怎么确认它按预期工作？

第一步，运行脚本。第二步，打开你指定的日志文件，例如 exercise/tool_run.log。第三步，逐行核对三件事：

1. 级别对不对。你设了 level=logging.INFO，那么 INFO 和更高级别的消息应该出现，DEBUG 消息不应该出现。

2. 格式对不对。你设的 format 里有 asctime、levelname、name、message，每行就应该有这四段。

3. 内容对不对。你记的每条消息应该都在，没有多出你没写过的行。

如果发现 DEBUG 消息没出现，先别改格式，回去看级别：根 logger 默认是 WARNING，你设了 INFO 之后，DEBUG 仍然低于阈值，会被忽略。这是级别在起作用，不是格式写错了。

如果发现日志文件是空的，按顺序排查：

- 脚本里有没有调用过 logger.info 或其他记录方法。

- basicConfig 是不是在第一次记录之前调用的。

- 你打开的是不是脚本里写的那个文件路径。

如果发现日志行重复出现，检查是不是给同一个 logger 或它的祖先重复挂了处理器。文档在 propagate 的说明里提醒，如果给一个 logger 和它的一个或多个祖先都挂了处理器，同一条记录可能被多次发出。

本文只给出这三类检查方向，不涉及日志轮转或日志分析工具。

logging 会把消息原样写进文件，所以写什么由你决定。

本文的范围限定在新建练习日志，因此有两条限制要提前说清：

第一，不要记录密钥、令牌、Cookie 或任何真实用户资料。日志文件通常是明文，写进去就等于留了一份副本。练习时用自建假数据，例如把用户标识写成 user-001 这类占位值。

第二，本文只操作练习目录里的自建文件。不要拿正在用的工具日志或系统日志直接改，也不要把 filename 指向你不确定归属的路径。

关于日志文件本身：文档没有规定日志文件的保存期限或大小上限，本文也不给这些数值。如果你需要控制文件大小或按时间切分，那属于 logging.handlers 的范围，本文不展开。

关于级别选择：文档给出的级别含义是通用描述，不是针对某个具体工具的强制标准。你的工具该记 INFO 还是 DEBUG，取决于你想在事后看到多少细节。本文只说明各级别的含义和默认门槛，不替你决定该用哪一级。

参考资料：Python 官方 logging 模块文档，https://docs.python.org/3/library/logging.html。本文所有路径和文件名均为自建练习示例。