先给你一个真实到不能再真实的场景凌晨两点半线上一个批处理任务失败了你爬起来打开终端屏幕上刷过一片 print 出来的中间结果可你根本看不出它到底在哪一步崩的、当时的入参是什么、异常堆栈是完整还是被截断。这种时候你才会意识到Python日志记录Logging不是项目快写完才想到的装饰品而是从一开始就该设计好的基础设施。我今年帮朋友排查过好几个项目无一例外都是“先写功能、后补日志”日志里堆满了 DEBUG 级别的内容或者干脆只有一条孤零零的print(done)。等真正出问题时日志给不了任何判断依据。这篇文章想做的就是把 Python 标准库 logging 从设计理念、Handler 选型、配置管理到生产环境的坑用我实际踩过的经历一次说透。适合刚接触 logging 的开发者也适合正在重构老项目、想统一日志方案的团队参考。1. 日志设计先别急着写代码想清楚这三件事1.1 为什么默认别用 print很多人觉得“反正都是输出print 不也一样么”。区别在于 print 是面向终端的临时调试手段它不是日志系统。print 没有级别、没有时间戳、没有代码位置、没有统一的输出控制能力也没法把不同模块的日志路由到不同文件。更麻烦的是print 直接打到 stdout生产环境里你可能连 stdout 都捞不到或者它和业务输出混在一起最后只能靠重启进程碰运气。我见过一个项目所有业务提示都用 print 打某次上线后没人盯着控制台结果磁盘被输出日志撑满了。为什么因为 print 本身不会轮转更不会按大小截断。Python logging 模块从标准库层面解决了这些问题Logger 负责产生日志Handler 负责把日志送到指定目的地Formatter 负责格式化内容Filter 还能在输出前做细粒度控制。四者分工明确才能让日志像水管一样该通哪通哪该过滤的过滤。1.2 Logger 命名与层级getLogger(name) 的真正含义logging 里的 Logger 不是一个个孤立的个体它们天然有父子层级。根 Logger 叫 root所有其他 Logger 都是它的子孙。常见的logging.getLogger(__name__)传进去的名字比如user.service、order.apilogging 会把它按点分隔成层级结构。这样你可以单独给user这个模块设一组 Handler也可以给user.service单独调级别互不影响。我一开始写脚本时偷懒直接在文件顶部写logger logging.getLogger()这拿到的其实是根 Logger。根 Logger 配置简单时没问题但一旦项目复杂几个模块共用根 Logger输出的水平线就很难统一。更推荐的做法是每个模块内都写logger logging.getLogger(__name__)这样日志记录天然带上模块路径排查时能一眼看出是哪条代码路径打出来的消息。还有一点别忽视Logger 默认会把日志向上传播propagate如果你在某层 Logger 上挂了 Handler父级又挂了一遍 Handler大概率会看到同一行日志出现两次这个坑我后面会专门讲。1.3 级别怎么定才不吵架日志级别是团队协作最容易“各说各话”的地方。DEBUG 是给开发时看的详细内部状态INFO 是能描述系统正常运行的业务事件WARNING 是异常但还能继续走的提示ERROR 是当前操作已经失败CRITICAL 是整套服务可能要停。最容易混乱的是 INFO 和 DEBUG 的边界。我的习惯是只要这条日志能回答“系统当前正在做什么、结果如何”就用 INFO如果你想回答“程序是怎么一步步算到这个结果的”那就是 DEBUG。还有一点经常被忽略ERROR 日志一定要带异常上下文。单独写logger.error(xx failed)只记录了一个字符串真正出问题时你根本不知道异常类型和 traceback。应该用logger.exception()或者在logger.error(..., exc_infoTrue)里把完整堆栈带出来否则这条日志的价值至少折损八成都不过分。2. Handler、Formatter 与 Filter让日志去该去的地方2.1 Handler 选型Stream、File、RotatingFile、QueueHandlerlogging 最灵活的地方是 Handler 可插拔。最简单的 StreamHandler 输出到控制台适合开发环境FileHandler 输出到文件适合单进程脚本RotatingFileHandler 按文件大小轮转TimedRotatingFileHandler 按时间轮转适合长期运行的服务。如果你有多进程或多线程同时写日志QueueHandler 配合 QueueListener 是更稳的异步方案这个在第 4 节展开说。选 Handler 不能只看“能不能把日志写出去”还要看它的行为是否匹配你的场景。比如 FileHandler 模式默认是 a也就是追加写不会清空旧文件这点没问题但多进程同时打开同一个文件句柄时轮转期间可能出现日志写丢或者“文件被占用”的报错。所以我的建议是单进程脚本直接用 FileHandler 或 RotatingFileHandlerWeb 服务和多进程任务优先把日志投递到本进程内的 Queue再由独立线程统一写文件避免每个 worker 都抢文件句柄。2.2 Formatter格式串怎么设计才够用一个实用的日志格式大概长这样import logging fmt %(asctime)s | %(name)s | %(levelname)s | %(process)d:%(threadName)s | %(filename)s:%(lineno)d - %(message)s handler logging.StreamHandler() handler.setFormatter(logging.Formatter(fmt, datefmt%Y-%m-%d %H:%M:%S))asctime是时间name是 Logger 名levelname是级别process和threadName能帮你区分请求来自哪个进程或线程filename和lineno能直接定位到源码位置。很多人喜欢把 format 写得很短比如只保留message这样在本地看没问题等日志量一大、要按模块按线程检索时没有上下文信息的日志基本等于噪音。如果你在维护接口服务我强烈建议至少再加一个 request_id 或 trace_id 字段。做法很简单使用logging.Filter往LogRecord里加自定义属性然后 Formatter 的格式串里写成%(request_id)s。比如class RequestIdFilter(logging.Filter): def filter(self, record): record.request_id getattr(record, request_id, -) return True这样每个请求从进入到返回的完整日志链都带同一个 ID排查线上问题时效率直接翻倍。后面第 5 节我会给一个更完整的进阶版本。2.3 Filter别让敏感信息进日志Filter 还可以用来做数据脱敏。我见过不少应用把用户手机号、身份证号直接拼进日志等日志被采集到统一平台后合规风险很大。建议在 Filter 里做一个正则替换import re class SensitiveDataFilter(logging.Filter): def filter(self, record): msg record.getMessage() msg re.sub(r1[3-9]\d{9}, ***********, msg) record.msg msg record.args () return True注意这里修改了 record 之后Formatter 拿到的 message 就已经是脱敏后的结果。更稳的做法是在进入日志系统前就统一脱敏但 Filter 是一个集中的兜底方案适合快速覆盖老代码里已经写死的明文输出。3. 配置管理从单文件脚本到大型项目的三级跳3.1 开发环境basicConfig 够用但别乱用logging.basicConfig()是新手最先接触的配置入口它把 Handler、Formatter 一次性配到根 Logger 上。开发本地脚本时它非常方便两行代码就有完整格式和级别控制import logging logging.basicConfig( levellogging.INFO, format%(asctime)s %(levelname)s %(message)s, )但 basicConfig 有一个非常隐蔽的坑它只在当前进程内、根 Logger 上第一次调用时生效后续调用基本会被忽略。如果你在多个模块里都调了 basicConfig或者某个第三方库提前创建了自己的 Handler你的配置就可能完全不生效。另外一个常见的反模式是在无人值守的脚本里直接logging.basicConfig(levellogging.DEBUG)结果把第三方库的海量 DEBUG 日志也放出来了。开发环境可以这么干生产环境千万别。3.2 生产环境dictConfig 才是正道项目上了一定规模配置文件就是刚需。logging.config.dictConfig()可以把 Logger、Handler、Formatter 定义在字典里逻辑集中、可维护性高也支持从 JSON 或 YAML 文件加载。下面这个配置是我常用的最小骨架import logging.config LOGGING_CONFIG { version: 1, disable_existing_loggers: False, formatters: { default: { format: %(asctime)s | %(name)s | %(levelname)s | %(process)d:%(threadName)s | %(filename)s:%(lineno)d - %(message)s, }, access: { format: %(asctime)s | access | %(message)s, }, }, handlers: { console: { class: logging.StreamHandler, formatter: default, }, app_file: { class: logging.handlers.RotatingFileHandler, filename: logs/app.log, maxBytes: 50 * 1024 * 1024, backupCount: 5, encoding: utf-8, formatter: default, }, }, loggers: { third_party_module: { level: WARNING, handlers: [console], }, }, root: { level: INFO, handlers: [console, app_file], }, } logging.config.dictConfig(LOGGING_CONFIG)这里有两个关键点。第一disable_existing_loggers必须设为False否则 dictConfig 在重新配置时会默认禁掉所有之前已经存在的 Logger某些第三方库的日志会平白消失。第二loggers下的子配置是给特定模块用的你可以让第三方库只输出 WARNING 以上日志而你的业务代码保持 INFO。3.3 第三方库的日志怎么管实际开发中第三方库会各有各的日志习惯。比如某 HTTP 客户端库默认打在 DEBUG某数据库连接池天天刷 INFO如果不做限制日志量会涨得飞快。正确做法是在 dictConfig 里给这些 Logger 单独设级别或者直接设置load_library的 logger 为 WARNING眼不见心不烦。还有一种更细的玩法把第三方库的错误单独接到一个文件方便出问题时只看错误流不被正常日志淹没。你只要在 config 里给那个 Logger 指定独立的 Handler 就行。比如loggers: { urllib3: { level: WARNING, handlers: [third_party_file], propagate: False, }, }注意设置了propagate: False后这条链路就不会再往根 Logger 上传递了避免重复输出。这个技巧同样适用于你自己划分的业务模块。4. 日志轮转、并发与性能上线前必须处理的四个问题4.1 日志文件无限增长怎么办日志文件不轮转迟早会把磁盘塞满。最简单的轮转是RotatingFileHandler按文件大小切分from logging.handlers import RotatingFileHandler handler RotatingFileHandler( app.log, maxBytes50 * 1024 * 1024, backupCount5, encodingutf-8, )maxBytes是单文件达到多大就轮转单位是字节backupCount是保留多少个旧文件。比如上面这个配置会保留app.log、app.log.1一直到app.log.5总共最多 6 个文件。注意maxBytes只有同时设置了backupCount为非零值时才会生效否则不会轮转。时间轮转则用TimedRotatingFileHandler比如每天凌晨切一个文件from logging.handlers import TimedRotatingFileHandler handler TimedRotatingFileHandler( app.log, whenmidnight, backupCount14, encodingutf-8, )这个方案看起来省心但你得注意时区。默认情况下它用的是本地时间如果服务器时区设置不合理或者容器环境里的TZ没配切文件的时间和“今天凌晨”可能完全对不上。更稳妥的是显式传入utcTrue或者自己处理时区偏移。还有一个小坑TimedRotatingFileHandler在轮转时如果旧文件恰好被其他进程占用重命名会失败日志会继续写到旧文件里表现形式就是“日期跨了但文件还是昨天的名字”。4.2 高并发场景下的日志丢失与阻塞logging 模块的各个 Handler 内部有锁所以多线程写同一个文件时单条日志不会出现内容交错。但这不代表多进程也安全。我自己在 gunicorn 多 worker 场景下遇到过日志丢失原因是多个进程同时打开同一个文件描述符当其中一个进程触发轮转、把当前文件 rename 成备份时其他进程还在往旧 inode 里写于是日志内容就“悬空”了旧数据被覆盖后彻底找不回来。推荐方案是使用QueueHandlerQueueListener。主线程把日志放进内存队列后台线程统一从队列取出来再交给自己持有的 Handler 去写文件。这样写磁盘的瓶颈不会卡住业务线程多进程模式也能通过把队列换成分布式队列来做成统一日志管道。简单的本地方案如下import logging import logging.handlers import queue log_queue queue.Queue(-1) queue_handler logging.handlers.QueueHandler(log_queue) file_handler logging.FileHandler(app.log, encodingutf-8) listener logging.handlers.QueueListener( log_queue, file_handler, respect_handler_levelTrue ) listener.start() root_logger logging.getLogger() root_logger.addHandler(queue_handler) root_logger.setLevel(logging.INFO)这段代码里respect_handler_levelTrue表示每个 Handler 可以有自己的最低级别防止后台线程把 DEBUG 也写进文件。最后记得在应用退出前调用listener.stop()否则队列里残留的日志可能会丢。如果你用的是 Web 框架更推荐借助框架本身的 async 钩子来管理 listener 生命周期。4.3 异常堆栈与上下文记录错误别只记一行 message我看到很多项目里是这样写的try: ... except Exception as e: logger.error(f发生错误: {e})这条日志表面上记录了异常文本但完全没有 traceback。出错之后你只知道“发生了数据库连接错误”却不知道是在哪个函数、哪一行触发的也不知道当时的事务状态。正确写法是try: ... except Exception: logger.exception(数据库操作失败)logger.exception()本质上是logger.error(..., exc_infoTrue)它会把当前异常栈完整打出来日志里第一行是你写的 message后面跟着 traceback。如果你在 except 分支之外或者想主动携带异常对象就用logger.error(任务处理失败, exc_infoe)这里exc_info可以传入一个异常元组也可以是True表示使用当前异常上下文。此外最好在 ERROR 日志里带上业务上下文比如订单号、用户 ID、重试次数。可以利用extra参数logger.error(支付回调处理失败, extra{order_id: 20240901, retry: 3})但要小心如果 Formatter 里没有定义order_id字段这样写会直接抛异常因为 logging 要求extra中的键必须被 Formatter 引用。没见过这个坑的人排查起来会很痛苦我后面第 5 节会讲一个让extra更宽容的 Filter 方案。5. 常见问题与排查技巧实录5.1 常见问题速查表症状-原因-解法我把这些年线上踩过的日志问题整理成一个速查表排查时可以直接对号入座症状可能原因解法日志重复输出同一行父 Logger 和子 Logger 都挂了同类 Handler且 propagate 为 True子 Logger 设置propagateFalse或不要在父级重复挂 Handler日志完全消失根 Logger 级别设置太高或没有配置任何 Handler检查 root 的 level 和 handlers确认 dictConfig 的disable_existing_loggers为 False第三方库日志刷屏第三方 Logger 继承根级别到 DEBUG单独给第三方库 Logger 设置 WARNING文件轮转后旧日志丢失多进程写同一文件轮转竞态改用 QueueHandler 单一后台写线程或分布式日志管道时间轮转不生效时区设置不对容器 TZ 未配置设置utcTrue或显式配置时区日志内容出现乱码文件编码默认跟随系统Handler 初始化时加encodingutf-8extra参数导致异常Formatter 未引用 extra 里的键使用带record.__dict__.setdefault的 Filterlogger.exception()之外无法拿到堆栈不是每个读者都知道 exc_info 参数在 except 分支外使用logger.error(..., exc_infoTrue)或显式传入异常5.2 我踩过的几个典型排查过程第一次让我真正重视 logging 配置是某项目在发布后出现大量日志缺失。当时我第一反应是磁盘满了结果df -h一看还剩很多。后来才发现是 dictConfig 里的disable_existing_loggers被默认设为True而项目在 import 阶段就创建了一堆模块级 LoggerdictConfig 重新加载时把它们全禁掉了日志自然从天上消失了。从那以后我写所有配置都会显式写disable_existing_loggers: False并且在有全局异常捕获的服务里加一层兜底日志保证任何未捕获异常都至少有一条 CRITICAL 记录。第二次坑是在用extra给日志打 request_id 时踩到的。我配置的 Formatter 里一开始没有 request_id 字段结果logger.info(..., extra{request_id: 123})直接抛了KeyError。后来我在根 Logger 上加了一个通用 Filter给所有 LogRecord 提前注入默认值import logging class DefaultFieldsFilter(logging.Filter): def filter(self, record): for key in (request_id, order_id, user_id): if key not in record.__dict__: record.__dict__[key] - return True然后 Formatter 里放心写%(request_id)s任何日志都能安全带上这些字段不再担心extra漏传导致崩溃。第三次是帮一个朋友调接口服务的日志压力。高峰期单机每秒写几百条 INFOFileHandler 成了性能瓶颈接口响应偶尔出现卡顿。我们改成 QueueHandler QueueListener 后写日志从同步磁盘 IO 变成了内存队列投递接口响应时间立刻降下来了。不过也提醒一点队列不是无限大queue.Queue(-1)看起来表示无上限但内存终究有边界建议给队列设一个合理上限并且监控队列堆积量防止突发流量把内存打满。5.3 最后再分享一个小技巧给每条日志绑定 request_id排查线上问题时最有效的手段就是把一个请求的完整调用链串起来。我用 Filter 在处理请求入口处生成 request_idimport logging import uuid class RequestIdFilter(logging.Filter): def filter(self, record): record.request_id getattr(record, request_id, None) if record.request_id is None: record.request_id uuid.uuid4().hex[:16] return True配合上下文变量让同一请求里的所有业务函数都共享同一个 request_id。这样一个用户反馈“下单失败”你只要在日志平台搜这个 ID整条链表一目了然。如果你在开发面向多租户的系统还可以在 Filter 里把租户 ID 也写进去日志检索维度会清晰很多。我个人在实际操作中的体会是日志系统最怕的不是“没有写日志”而是“写了很多但没用”。提前做好层级划分、级别约定、统一格式和敏感信息过滤远比等出问题后再补日志省事得多。记住一个原则日志应该让未来的你只需要一次搜索就能定位到问题发生的前因后果。这比任何花哨的配置都更重要。