1. 为什么你的Python程序必须认真做日志我在接手别人代码的时候最怕碰到的就是那种满屏print、出错全靠肉眼看控制台的脚本。你别说很多写了三五年Python的人日志还是停留在print(step1 done)的水平。一旦程序出了线上问题你连“这一串数字到底是哪个用户、哪笔订单、哪个分支进来的”都查不到抓瞎就是必然的结局。这次聊的Python日志记录Logging不是教你怎么写几行logging.info充门面而是把日志当作工程基础设施的一部分来设计。它能解决的问题很简单程序运行时不打印出问题时能回溯性能波动时能审计业务异常时能告警。用一句话说就是日志是你程序睁着眼睛睡觉的监控摄像头平时不打扰出事全靠它。适合谁来参考刚接触Python、想把脚本工程化的新手被项目组要求“加规范日志”但不知从何下手的同学以及维护过老系统、被烂日志坑过、想一次性把日志体系搭干净的开发者。下面我会从标准库logging的核心机制讲起逐步给出我实测过的一整套配置方案最后是踩坑实录。2. 核心机制先搞懂Logger、Handler、Formatter、Filter网上搜“Python logging 最佳实践”能翻出几百篇教程但很多人连logging最基础的四个组件都说不清。我先把这四个角色讲明白后面所有配置都是在这几个组件之间搭关系。2.1 Logger日志的入口不是你直接调logging的根记录器很多初学者的第一行是logging.info(hello)这没错但logging.info本质是调了根Logger名字是空字符串的那个。根Logger是个全局默认对象如果你所有代码都往根Logger上怼就很难区分“这个日志是数据库模块打的还是HTTP接口层打的”。最佳实践是每个模块都创建自己的Logger用logger logging.getLogger(__name__)。__name__会带着模块的包路径比如myapp.utils.db_conn。这样有两层好处第一日志记录上天然带模块名搜索日志时直接grep db_conn就能定位第二你可以对不同的Logger设置完全不同的级别和Handler比如让数据库模块只输出WARNING而业务模块输出INFO互不影响。Logger之间的继承关系也很关键。myapp.utils.db_conn是myapp的子Logger而myapp又是根Logger的子Logger。子Logger默认会把日志逐级向上传播给父Logger这就是propagate属性。你如果不清楚这个机制很容易出现“我明明只写了一条日志控制台却打印了两遍”的灵异事件。后面我会专门讲这个坑。2.2 Handler决定日志去哪控制台、文件还是网络Handler负责把日志记录发送到目的地。标准库自带的Handler很够用最常用的几种Handler用途适用场景StreamHandler输出到控制台stderr/stdout本地调试、Docker容器日志FileHandler写入单个文件简单场景按天/按大小旋转RotatingFileHandler按文件大小自动切割单个日志文件可能会无限变大时TimedRotatingFileHandler按时间周期旋转每天/每小时运维习惯按天归档日志SocketHandler/SysLogHandler发送到远程日志服务器集中式日志采集一个Logger可以挂多个Handler。比如生产环境我通常配两个控制台Handler负责在屏幕上看文件Handler负责持久化。两个Handler还可以用不同的级别和Formatter控制台打详细INFO文件里只写WARNING以上这是很常见的设计。2.3 Formatter日志长什么样的模板Formatter负责把日志记录里的字段拼成一行字符串。默认格式是2025-01-15 10:00:00,123 - root - INFO - message但实践中根本不够用。我通常会带上进程号、线程号、模块名、函数名、行号甚至业务追踪ID。log_format %(asctime)s | %(levelname)-8s | %(process)d | %(threadName)s | %(name)s | %(funcName)s:%(lineno)d | %(message)s为什么这么罗嗦举一个真实例子服务挂了你翻日志发现一堆报错但不知道是哪个进程、哪个线程出的。如果日志里没有进程号和线程号多线程环境下你想定位是某个请求触发的都无从下手。funcName和lineno能直接告诉你崩在哪一行省去用traceback猜的时间。2.4 Filter日志的精细安检员Filter用得少但特殊场景很管用。比如你不想让某个敏感模块的调试日志被写进生产文件或者你想给所有日志统一注入一个业务字段Filter可以在不用大改代码的情况下做到。Filter可以挂到Handler上也可以挂到Logger上执行顺序是先Logger的Filter再Handler的Filter。我用得比较多的一个场景是给日志按“数据分片编号”过滤只记录某个分片维度的日志这在脱敏处理和灰度发布排查时特别好用。3. 从零搭建一套生产级日志配置3.1 别再裸用basicConfig了至少换成dictConfiglogging.basicConfig()是官方教程里的Hello World但它只能配置根Logger而且配置一次之后就不能再改。很多项目里我看到有人到处调logging.basicConfig(levellogging.INFO)结果第二次调用根本不生效代码里还堆了一堆logging.getLogger(xxx).setLevel(...)的补丁。我的建议是如果你的项目不是玩具脚本直接用logging.config.dictConfig。它能用字典一次性定义所有Logger、Handler、Formatter的层级关系配置清晰且可在运行时灵活加载。下面这个配置模板我直接用在几个生产项目里可以直接抄import logging.config import json LOGGING_CONFIG { version: 1, disable_existing_loggers: False, formatters: { detailed: { format: %(asctime)s | %(levelname)-8s | %(process)d:%(threadName)s | %(name)s | %(funcName)s:%(lineno)d | %(message)s, datefmt: %Y-%m-%d %H:%M:%S }, simple: { format: %(levelname)-8s | %(name)s | %(message)s } }, handlers: { console: { class: logging.StreamHandler, level: INFO, formatter: simple, stream: ext://sys.stdout }, file_info: { class: logging.handlers.TimedRotatingFileHandler, level: INFO, formatter: detailed, filename: logs/app.log, when: midnight, interval: 1, backupCount: 30, encoding: utf-8 }, file_error: { class: logging.handlers.TimedRotatingFileHandler, level: ERROR, formatter: detailed, filename: logs/error.log, when: midnight, interval: 1, backupCount: 90, encoding: utf-8 } }, loggers: { myapp: { level: INFO, handlers: [console, file_info, file_error], propagate: False }, sqlalchemy: { level: WARNING, handlers: [console], propagate: False } }, root: { level: WARNING, handlers: [console] } } logging.config.dictConfig(LOGGING_CONFIG)这里有几个设计点我解释一下为什么这么写。disable_existing_loggers: False是必须的。dictConfig在加载时会默认禁用所有已有Logger如果你在配置文件之前已经创建了其他模块的Logger不设这个字段它们就全被静音了。这个字段很容易被漏掉漏掉之后最典型的表现是“配置之后有些日志不打了”。file_info和file_error分离是我强烈推荐的做法。所有INFO级别以上的日志都进app.log只有ERROR级别以上的进error.log。这样做的好处很简单线上半夜报警你只需要查error.log不需要在十几万行的app.log里grep。很多团队把日志全塞一个文件出了问题连小半天都翻不完。propagate: False是为了防止日志重复。我把myapp的Logger挂了自己的三个Handler如果还让它向上传播给根Logger而根Logger又有一个指向控制台的Handler那么myapp里的INFO日志会同时被myapp的Handler和根Logger的Handler各打一遍控制台就出现两行一模一样的日志。设置成False表示“我的日志我自己处理不往上抛了”。3.2 日志文件大小与切割策略不是小事文件一大会把磁盘占满切割策略选错会导致丢日志。我见过最蠢的配置是FileHandler 一个logs/目录跑两个月单文件几十GBcat命令都卡死。RotatingFileHandler按字节数切适合单机脚本或小项目。设置maxBytes10485760即10MBbackupCount5总共最多保留50MB日志。这里有个细节maxBytes只有同时设置了backupCount才生效否则还是无限增长。TimedRotatingFileHandler按时间切适合服务常驻。设置whenmidnight表示每天零点切一次backupCount30保留一个月。我个人的经验是生产环境不要用RotatingFileHandler优先TimedRotatingFileHandler。原因有两点第一运维同学的告警和排查习惯是按时间查日志文件名带日期比如app.log.2025-01-15会舒服得多第二当日志量突然暴涨时按大小切会让你在几天内产生大量的碎片文件按时间切至少每天一个目录结构稳定。切割还有一个隐藏问题TimedRotatingFileHandler在Windows上的重命名可能会有权限冲突因为日志文件被进程占用。解决办法是在FileHandler的初始化参数里加delayTrue延迟打开文件直到第一次写入。不过最简单的还是部署到Linux容器里这个痛点会少很多。3.3 日志级别别乱设要分层管理日志级别不是写代码时随意拍的应该有约定。我平时用的标准是DEBUG开发阶段的细节比如每个SQL参数、每个HTTP请求的header。INFO关键业务节点用户下单、支付回调、任务开始和结束以及关键的中间值。WARNING不该发生的但程序能继续跑的事比如接口响应时间超过阈值、磁盘剩余空间低于20%。ERROR某个功能不可用有异常抛出但主进程不死。比如一次API调用失败。CRITICAL整个进程不能继续服务的严重错误比如数据库连接池耗尽、配置缺失。核心原则是DEBUG日志写代码时要大方写INFO日志写业务里程碑WARNING和ERROR日志必须携带上下文。这里特别想说一下“日志里带上下文”这件事。很多人写错误日志只写一个logger.error(database error)。大哥我看到了这条日志我该怎么修至少要把错误码、数据表、SQL片段、异常traceback带进去。logger.exception(Failed to query user)会自动附带上当前的异常堆栈是在except块里必须用的方法别手懒。4. 实用进阶技巧上下文信息与性能优化4.1 给日志加一个“追踪ID”链路串起来在微服务或复杂业务里一次用户操作会跨越好几个模块、好几次异步回调、甚至好几个服务。如果日志之间没有共同标识你根本没法把一条请求的完整生命周期串起来。业界通用做法是trace_id。标准库logging里实现trace_id非常简单用logging.Filter往日志记录里塞一个自定义字段。我先在一个过滤器里生成或读取上下文里的trace_id然后Formatter里加上它。import threading import uuid import logging class TraceIDFilter(logging.Filter): def __init__(self): super().__init__() self._local threading.local() def set_trace_id(self, trace_id: str): self._local.trace_id trace_id def filter(self, record: logging.LogRecord) - bool: if hasattr(self._local, trace_id): record.trace_id self._local.trace_id else: record.trace_id uuid.uuid4().hex[:12] return True然后在Formatter的格式里加上%(trace_id)s最后把Filter挂到Handler上。这样每一条日志都自动带上追踪ID。实际使用中我在Web框架的中间件入口处调用一次set_trace_id把HTTP请求ID或生成的UUID塞进去之后这个线程内所有的日志都会自动带上它。你可能会问多线程环境会不会串不会因为threading.local()保证了每个线程有自己独立的存储空间。异步协程则麻烦一点因为同一个线程内可能有多个任务在切换遇到协程环境建议用contextvars替代threading.local两者思路一样。4.2 日志别阻塞主业务异步队列搞起来如果你的业务是低频CLI脚本日志同步写文件无所谓。但如果是一个高并发的Web服务每次请求都同步写日志文件磁盘IO很快会成为瓶颈拖慢整个接口响应时间。标准库提供了QueueHandler和QueueListener专门解决“日志生产快、消费慢”的问题。设计思路是业务线程只负责把日志记录塞进内存队列一个后台监听线程负责真正写日志。这样日志的写入延迟不直接影响到主业务。import logging import logging.handlers import queue def setup_async_logging(): log_queue queue.Queue(-1) queue_handler logging.handlers.QueueHandler(log_queue) file_handler logging.handlers.TimedRotatingFileHandler( logs/async_app.log, whenmidnight, backupCount7, encodingutf-8 ) formatter logging.Formatter(%(asctime)s | %(levelname)s | %(message)s) file_handler.setFormatter(formatter) listener logging.handlers.QueueListener(log_queue, file_handler) listener.start() return listener, queue_handler这里有三个要点。第一QueueHandler的级别和格式要和目标Handler分开配置。第二listener.start()之后记得在程序退出时调用listener.stop()否则最后几条日志可能会丢失。第三队列大小要控制在合理范围如果日志消费能力跟不上生产速度队列会积压最坏情况是内存爆掉。我一般会设置一个监控队列长度超过10000条就报警。4.3 敏感数据别进日志害人害己日志里最容易犯的错是把用户手机号、身份证号、密码的哈希、支付token等直接打出来。测试环境无所谓生产环境一旦日志泄露你就等着背锅吧。我处理敏感字段有三个方案方案一打日志前用占位符替换比如logger.info(user %s registered, masked_user)。方案二自定义一个Formatter或Filter检测日志内容里的手机号正则统一替换成138****1234。方案三日志存储层直接配置字段脱敏规则如果用的是ELK或云日志服务。最推荐的是方案二因为它是全局生效的不会因为某个同事忘了脱敏就泄露。举个例子在Filter里对最终日志文本做一次正则替换把1[3-9]\d{9}替换成1[3-9]********。别嫌这层处理多耗费点CPU安全相比性能永远是安全优先级高。5. 常见问题与排查技巧实录5.1 日志打印重复出现先查propagate这是所有logging新手第一个会撞上的坑。症状一条INFO日志在控制台刷了两遍或者写进文件里重复了。我把排查步骤整理成了速查表现象可能原因修复方法完全重复的日志行Logger’s own handler propagate to root设置propagateFalse日志看起来像叠加了两套格式多个Handler共用了根Logger检查根Logger的Handler配置避免重复挂某个模块日志出现了两条类似但不等同的该模块同时激活了两个Logger组别用logger logging.getLogger(__name__)保证模块只用一条路径我自己排查这类问题最快的方法是写一个临时脚本遍历所有Loggerfor name in logging.Logger.manager.loggerDict: logger logging.getLogger(name) print(name, logger.handlers, logger.propagate)看看哪些Logger挂了重复的Handlerpropagate是不是还开着。5.2 日志没写入文件先看权限和路径症状控制台有日志文件里就是空的。这种情况十有八九是路径权限问题。我把logs/目录建好但进程是以非root用户启动的没有写权限所以日志静默丢弃。标准库的FileHandler在打不开文件时只是发一条print警告不抛异常所以很容易忽略。另一个常见坑是filename路径里的目录不存在。例如你设置了filenamelogs/app.log但当前工作目录下没有logs目录程序不会自动创建。在dictConfig里我习惯加一个目录检查import os os.makedirs(logs, exist_okTrue)放在dictConfig调用之前保证目录已存在。5.3 中文乱码与编码问题Windows机器上跑Python日志文件名和输出的中文乱码几乎是必踩的坑。原因很简单FileHandler默认用系统编码Windows下可能是GBK。最佳实践是在所有日志文件Handler上显式指定encodingutf-8。我已经在配置模板里写了这一步。如果还乱码检查终端编码是否为UTF-8Windows下可以执行chcp 65001。顺带说一句某些日志收集系统比如ELK默认按UTF-8解析日志如果你的日志文件编码不是UTF-8进ELK之后全是乱码到时候排查问题就更耗费时间。5.4 日志时区和时间格式的坑多人协作项目里有人用北京时区有人用UTC日志时间戳对不上排查问题时会非常痛苦。强烈建议服务端日志统一使用UTC或统一为某固定时区运维侧在展示层再转本地时间。logging.Formatter的asctime默认读取本地时间。要强制UTC可以继承Formatter覆盖converter属性import time import logging class UTCFormatter(logging.Formatter): converter time.gmtime # 使用UTC时间这样所有日志的时间戳都是UTC标准时间跨服务器、跨区域协作时不会产生歧义。5.5 异常日志怎么打才最有价值一个很常见的错误写法try: do_something() except Exception as e: logger.error(fcaught error: {e})摘掉了traceback只剩一句错误消息字符串。真到排查的时候你会发现自己根本不知道是从哪里抛出来的、调用链是什么样的。推荐写法是用logger.exceptiontry: do_something() except Exception: logger.exception(do_something failed)logger.exception自动把当前异常堆栈打印出来并且级别是ERROR。还有一种做法把异常对象直接传给日志记录logger.error(do_something failed, exc_infoTrue)如果你希望保留完整的异常上下文又不想打堆栈可以用logger.log配合stack_infoTrue。总之不要只打e字符串信息量太少。6. 最后分享一点我的个人体会日志这件事看起来简单真正做好并不容易。我经历过一个线上事故凌晨三点告警我打开日志文件发现Modal里全是INFO级别的无用输出真正的ERROR信息被淹没在几万行噪音里愣是翻了半小时没找到关键行。后来我花了半天时间把项目的日志体系重构成了上文说的那套配置级别分层、Handler分离、trace_id透传、异步队列。再遇到线上抖动我只需要进error.log按trace_id一查前后链路十分钟就能理清楚。如果你现在就打算动手改进项目的日志我的建议是别追求一步到位先做到三件事。第一把模块级Logger建立起来所有代码统一用getLogger(__name__)。第二把所有文件Handler加上按天切割和encodingutf-8。第三所有except块里的日志都改成logger.exception。这三件事做完你的排查效率至少提升50%。剩下的dictConfig标准化、trace_id链路、异步队列可以等项目稳定之后逐步引入。日志不是写完就结束的东西它是一条越用越值钱的资产。每次线上故障都是你对日志配置的一次检验。希望这篇内容能帮你把日志这件“小事”真正做得扎实。