引言
第 4 篇用 basicConfig 一把梭把日志配好了：一个 root 日志器、一个 stderr 处理器、一种格式。这足够撑起小脚本，但真实工具的需求很快会越界：调试期的 DEBUG 细节想落盘、运行时只给用户看 INFO；日志文件无限增长会撑爆磁盘；希望出错时把完整调用栈留下。 这些需求都指向同一个事实：日志系统不是一块铁板，而是由三个可独立拼装的部件组成的流水线。
本篇把第 4 篇的「黑盒配置」拆开，讲透三件套结构——Logger（谁在记）、Handler（记去哪）、Formatter（怎么排版），然后演示经典的双 Handler 分流（控制台 INFO + 文件 DEBUG 并存）、RotatingFileHandler 按字节轮转的真实过程、logging.exception 的异常记录、线程安全机制，最后简述 dictConfig 配置方式。它在章节中的位置：第 6 篇的机器可读输出要求「stdout 纯净」，而本文的「日志进 stderr、进文件」正是纯净的前提；第 8 篇的待办事项工具会把「控制台 + 文件」双通道直接搬进实战。前置知识：第 4 篇的级别体系与 basicConfig，第四章第 8 篇的异常体系。
概念与原理
三件套：职责分离的流水线
logging 把「记录日志」拆成三个可替换的部件。Logger 是入口与过滤器：它检查级别、生成记录对象，并把记录分配给挂在身上的 Handler 列表——Logger 自己不负责输出。Handler 决定去向：StreamHandler 写任意流（默认 stderr），FileHandler 写文件，还有发网络的、走邮件的一族。Formatter 决定排版：把记录对象渲染成字符串，format 字符串里的 %(asctime)s 等字段在此刻求值。一个 Logger 可以挂多个 Handler，同一条记录被复制多份、各自排版、各走各路——这就是「分流」的机制基础。另一个关键机制是传播（propagation）：logger 处理完自己的 Handler 后，默认再把记录交给父级 logger 处理，一直传到 root。传播链让「收敛配置」成为可能：子模块只负责打日志，输出工作统一由父级或 root 完成。
两道过滤闸门
第 4 篇说过记录要过两道闸门，现在两扇门都在眼前了。第一道在 Logger 发出记录前：检查的是有效级别——logger 自己没有设置级别时，沿父链向上找第一个设置过的级别（这就是 __name__ 点分层级的意义）。第二道在每个 Handler 输出前：检查 Handler 自己的级别。两道闸门各管各的，互不替代：logger 级别管「这条记录要不要造出来」，Handler 级别管「这条记录要不要从这个出口出去」。牢记这一点，下一篇的行文里几个经典陷阱都从这里长出来。
为什么要文件轮转
日志文件只增不减是运维事故的常见来源：磁盘写满、服务停摆。RotatingFileHandler 的答案是按大小轮转：每次写入前检查「当前文件字节数 + 新消息字节数」是否超过 maxBytes，一旦超过就滚动一次——把现有文件依次改名为 .1、.2、…，最老的那个删掉，再以原文件名开新文件继续写。backupCount 决定保留几个备份。同类还有按时间轮转的 TimedRotatingFileHandler（用 when 指定按秒/分/时/天轮转，同样配 backupCount），触发维度不同、滚动思路同源；日志量稳定的大流量服务则常把按天归档或直接外包给日志收集系统。初学阶段先吃透按字节这一种即可。留意两点：其一，maxBytes 按字节计数，UTF-8 中文每条消息约占 3 字节/字，不是按「条」数；其二，轮转只发生在「下一次写入时」，单条巨型消息本身不会被切开。
logging.exception 与线程安全
logging.exception(msg) 是 logging.error(msg, exc_info=True) 的简写：除了输出 ERROR 记录，还会把当前异常的完整 traceback 一并写入。它必须在 except 块内调用才有意义——异常上下文只存在于异常处理期间。线程安全方面，logging 模块内部分工明确：basicConfig、dictConfig 等配置操作有模块级锁保护；每个 Handler 自带一把可重入锁（threading.RLock），emit 前后加锁，因此同一个 Handler 的并发写入是串行的，多条线程不会把日志行互相插碎。但要清醒：锁是进程内的，多进程布局（第 17 章会讲）下每个进程各有各的锁，跨进程的日志文件共享需要额外设计。
操作与实现
实测一：控制台 INFO + 文件 DEBUG 的同源分流
下面这个脚本是「双通道」的标准形态：同一个 Logger，控制台 Handler 只放行 INFO 及以上，文件 Handler 放行全部（DEBUG 及以上），两条通道各用一份 Formatter 实例（Formatter 可共享，但为了看清楚各自排版这里给文件也配了相同格式）：
import logging
logger = logging.getLogger("shop")
logger.setLevel(logging.DEBUG)
console = logging.StreamHandler()
console.setLevel(logging.INFO)
file_h = logging.FileHandler("shop.log", encoding="utf-8")
file_h.setLevel(logging.DEBUG)
fmt = logging.Formatter("%(name)s | %(levelname)s | %(message)s")
console.setFormatter(fmt)
file_h.setFormatter(fmt)
logger.addHandler(console)
logger.addHandler(file_h)
logger.debug("细节只在文件里")
logger.info("常规消息：控制台与文件都有")
logger.warning("警告：两边都有")python split.py 2>console_out.txt
echo "--- 控制台（stderr）收到的 ---"
cat console_out.txt
echo "--- 文件收到的 ---"
cat shop.log--- 控制台（stderr）收到的 ---
shop | INFO | 常规消息：控制台与文件都有
shop | WARNING | 警告：两边都有
--- 文件收到的 ---
shop | DEBUG | 细节只在文件里
shop | INFO | 常规消息：控制台与文件都有
shop | WARNING | 警告：两边都有对比两段输出：DEBUG 那条被 console 的 Handler 级别拦下，却通过 file Handler 的闸门进了文件——这就是两道闸门在同一份记录上的分工（本脚本的 logger 级别为 DEBUG，全程放行）。注意此脚本没有调用 basicConfig，root 仍用默认配置，但 shop 挂了自己的 Handler，与 root 井水不犯河水。
实测二：RotatingFileHandler 轮转的完整过程
用小尺寸参数让轮转在本机真实发生。每条消息按 UTF-8 编码是 47 字节（含换行），设 maxBytes=200，则每写满 4 条（188 字节）后，第 5 条到达时触发滚动：
import glob
import logging
import os
from logging.handlers import RotatingFileHandler
for stale in glob.glob("app.log*"):
os.remove(stale) # 清掉历史轮转文件，保证演示可重复
handler = RotatingFileHandler("app.log", maxBytes=200, backupCount=3, encoding="utf-8")
handler.setFormatter(logging.Formatter("%(message)s"))
logger = logging.getLogger("rot")
logger.addHandler(handler)
logger.setLevel(logging.INFO)
for i in range(1, 11):
logger.info("第 %02d 条：一条固定长度的日志消息" % i)
handler.flush()
for path in sorted(glob.glob("app.log*")):
lines = open(path, encoding="utf-8").read().splitlines()
print(path, "行数 =", len(lines), "| 首行:", lines[0] if lines else "")app.log 行数 = 2 | 首行: 第 09 条：一条固定长度的日志消息
app.log.1 行数 = 4 | 首行: 第 05 条：一条固定长度的日志消息
app.log.2 行数 = 4 | 首行: 第 01 条：一条固定长度的日志消息轮转时序与文件内容完全对应：写入第 5 条时第一次滚动，1-4 条整体改名成 app.log.1，新文件装 5-8 条；写入第 9 条时第二次滚动，5-8 条升格为 app.log.1，原来的 app.log.1（1-4 条）顺延为 app.log.2，新文件装 9-10 条。新日志永远在 app.log，旧日志按序号依次变老——这正是运维期望的顺序。若继续写满，app.log.3 会顶掉最老的备份（backupCount=3 只留三个备份文件）。生产环境通常把 maxBytes 设为 10 MB 或 100 MB 量级、backupCount 取 5-10 个。
实测三：logging.exception 记录 traceback
保存为 traceback_demo.py 并运行 python traceback_demo.py：
import logging
logging.basicConfig(level=logging.INFO, format="%(levelname)s: %(message)s")
def divide(a, b):
return a / b
try:
divide(10, 0)
except ZeroDivisionError:
logging.exception("计算失败，详情如下")ERROR: 计算失败，详情如下
Traceback (most recent call last):
File "traceback_demo.py", line 9, in <module>
divide(10, 0)
File "traceback_demo.py", line 6, in divide
return a / b
~~^~~
ZeroDivisionError: division by zero（本机实测时 traceback 里是文件的绝对路径——Windows 上主脚本以绝对路径记录，此处缩写为文件名；你机器上会显示你保存的位置。）这条记录级别是 ERROR，走 basicConfig 造的 root Handler 输出到 stderr。程序没有崩溃：异常已经被 except 接住，记录完 traceback 后流程继续。注意 logging.exception 必须在 except 块内调用；若在别处调用，它拿不到异常上下文，会打出没有实质内容的 NoneType: None。
实测四：dictConfig：把配置从代码中拿出来
Handler 一多，组装代码开始占地方；日志配置还想从配置文件里加载、想被多个入口共享。logging.config.dictConfig 用一份字典描述全部配置——version 字段必填且当前只能是 1：
import logging.config
config = {
"version": 1,
"formatters": {"brief": {"format": "[%(levelname)s] %(name)s: %(message)s"}},
"handlers": {
"console": {"class": "logging.StreamHandler", "formatter": "brief"}
},
"loggers": {"app": {"level": "INFO", "handlers": ["console"]}},
}
logging.config.dictConfig(config)
logging.getLogger("app").info("由 dictConfig 装配的记录器")[INFO] app: 由 dictConfig 装配的记录器字典的层次与三件套一一对应：formatters 定义排版，handlers 实例化处理器（class 是 Handler 类名），loggers 把两者装配到命名空间。这份字典天然可以来自 JSON/YAML 文件，也可以嵌入框架配置——这就是「代码写逻辑、配置写参数」的工程化方向，第 8 篇实战会再见到它的影子。代码直配与 dictConfig 的取舍：脚本与中小工具用前者（所见即所得、IDE 可补全），多模块项目把后者放进配置文件（改日志级别不用发新版本）。
易错点与陷阱
1. propagate 默认开启，消息被打印两次
给子 logger 挂了自己的 Handler 后，记录先经子 Handler 输出，又沿传播链到达 root 再输出一次：
import logging
logging.basicConfig(level=logging.INFO, format="[root] %(message)s")
child = logging.getLogger("shop.order")
h = logging.StreamHandler()
h.setFormatter(logging.Formatter("[child] %(message)s"))
child.addHandler(h)
child.info("这条消息出现几次？")[child] 这条消息出现几次？
[root] 这条消息出现几次？两次。对策两种：给子 logger 设 child.propagate = False（自成一派），或收敛策略——子模块只打日志不挂 Handler，输出统一交给 root 的 Handler（进出都走 root，反而简单）。
2. 把 basicConfig 的 level 当成全局闸门
第 4 篇配过 basicConfig(level=logging.INFO) 后，人会直觉认为「全局 INFO 起步、DEBUG 无处遁形」。但这个级别只落在 root logger 自己身上，对有独立设置的子 logger 形同虚设：
import logging
logging.basicConfig(level=logging.INFO, format="%(message)s")
logger = logging.getLogger("noisy")
logger.setLevel(logging.DEBUG)
logger.debug("root 级别是 INFO，但这条 DEBUG 还是出现了")root 级别是 INFO，但这条 DEBUG 还是出现了原因：noisy 的有效级别是它自己的 DEBUG，第一道闸门放行；传播到 root 时，callHandlers 只按 Handler 的级别（此处未设置，即 NOTSET 全放行）检查，root logger 自己的级别并不参与。摸清「logger 级别管发出、Handler 级别管出口」就能解释这类「漏网之鱼」。这也印证实测一里 shop 挂 Handler 时为何要显式 handler.setLevel(logging.DEBUG)。
3. maxBytes 按字节计，中文占 3 字节
Rotation 的判定是字节数，不是记录条数：UTF-8 下每个汉字 3 字节，一条上百字的中文日志就接近 300 字节。实测二里「固定 47 字节」的消息才能精确卡在每 4 条一轮；换成中文混排后轮转点会漂移。估算容量时按「单条日志的最大字节数 × backupCount × 每条预计条数」留余量。
4. FileHandler 不传 encoding，编码随区域设置漂移
FileHandler("shop.log") 不指定 encoding 时，文件按区域默认编码打开。本机（UTF-8 模式）实测写出 UTF-8；在中文 Windows 的 GBK 区域则写出 GBK——同一份代码在不同机器写出的日志编码不一致，日志解析工具（第五章的日志解析正是此类）会直接乱码。对策统一且简单：创建 FileHandler/RotatingFileHandler 时永远显式传 encoding="utf-8"。
小结
本篇把日志系统拆成了三件套：Logger 管级别与分发、Handler 管去向、Formatter 管排版；两道闸门（logger 的有效级别、handler 自身级别）各司其职；addHandler 让「控制台 INFO + 文件 DEBUG」的同源分流成为现实；RotatingFileHandler 用 maxBytes/backupCount 按字节滚动，实测展示了文件改名、最老删除、新文件重开的完整时序；logging.exception 在 except 块内一次性记录 ERROR 与 traceback；Handler 自带锁保证并发写入不交插；dictConfig 把配置从代码搬进数据。四个易错点集中在传播链重复输出、级别作用域误解、字节计数与编码漂移。下一篇把这些日志能力与参数解析合流，讲退出码与机器可读输出——工具对人和对机器的两副面孔。
练习与思考题
- 在实测一基础上把
logger.setLevel(logging.DEBUG)删掉再运行：DEBUG 记录还会进文件吗？用「有效级别」解释原因。 - 把实测二的 maxBytes 改为 100、消息保持 47 字节，不运行代码先推演轮转时序（每条消息导致滚动的位置、各文件行数），再运行验证你的推演。
- 给「控制台 + 文件」双通道加上第二个 Formatter：文件里带 asctime、控制台不带，验证两个 Handler 可以各用各的排版。
- 用 dictConfig 重写实测一的双 Handler 配置（含 formatters/handlers/loggers 三段），并把 level 参数改为从环境变量读入字符串，体会配置与代码分离的收益。