我自己的项目里日志踩坑的教训比业务代码出bug还多。从最开始print大法到后来用logging觉得“配置一下就行”再到线上日志丢失、乱码、磁盘爆掉各种翻车才慢慢摸出一套真正能用于生产环境的Python日志记录Logging最佳实践。这篇文章不打算从官方文档的概念讲起直接讲我实际踩过的坑和现在稳定运行的配置方案适合刚接触logging的新手也适合写过一些代码但日志系统一直没理顺的工程人员。日志系统解决的核心问题就一个当程序出问题时你能在最短时间内还原现场。它不需要花哨但要可靠、可读、可配置。你写的每一行日志都是在为未来的排查工作存证据而这些证据的质量取决于你从设计阶段就开始的规划。1. 先想清楚你的日志要回答什么问题写日志之前先问自己一个问题三个月后一个完全不了解这段代码的人包括未来的你看到这段日志能不能还原出当时发生了什么这个视角转换非常关键。大部分人写日志的通病是站在原地看自己写过的代码“好像差不多都记了”但实际上真正排查问题的时候发现关键信息全是空的。1.1 日志不是越多越好而是每个条目都要能回答问题我一直强调一个观点日志的每一行都应该能回答至少一个明确的问题。比如“这个请求是从哪里来的”“这笔交易为什么失败”“这个定时任务为什么没跑”等等如果一条日志回答不了任何问题它就是噪音只会把真正有用的信号淹没。我在审查团队代码时经常问这几个问题这条日志记录的是事件发生前、发生中还是发生后它有没有携带足够的上下文用户ID、订单号、请求ID、函数参数的关键值如果这条日志是error级别那它旁边有没有配套的上下文信息还是只孤零零一个异常堆栈这些问题的答案决定了日志系统最终是工具还是负担。举个例子一个订单处理函数里如果只写logger.error(订单处理失败)这条日志基本等于没写。改进后应该是logger.error( 订单处理失败: order_id%s, user_id%s, stage%s, error%s, order_id, user_id, stage, exc_infoTrue )两者之间隔着一次完整的排查效率差距。前者你得再去翻代码猜测是哪个订单、哪个阶段出的错后者一眼就能定位。日志里的上下文信息和日志级别一样重要甚至更重要。1.2 从“记录状态”到“还原现场”的思维转变很多人写日志的思路是“记录状态”——程序走到哪一步就打一条“step 1 done”“step 2 done”这种。这种方式不能说错但它忽略了真正关键的东西状态之间的关联和差异。真正有用的日志系统应该能让你还原现场而不只是确认程序“走到了”某个位置。还原现场至少需要三层信息第一层是事件本身也就是发生了什么第二层是事件发生的上下文包括时间、位置、关键参数第三层是事件的影响范围包括涉及了哪个请求、哪个任务、哪个资源。这其实是一个从点、线到面的信息立体化过程。我在实际项目中养成了一个习惯在决定打印一条日志之前先在脑子里模拟一遍排查场景。想象这条日志出问题后你会怎么用它来定位如果发现还要翻代码结合上下文才能看懂那这条日志写得太差了应该重写。这种“以终为始”的日志设计方式比任何规范都管用。2. Logger/Handler/Formatter三段式架构为什么是这个设计Python的logging模块核心逻辑其实不复杂Logger负责接收日志并判断要不要处理Handler负责把日志发送到目的地控制台、文件、网络等Formatter负责把日志打包成什么格式。理解这三者的分工和协作方式是配置合理日志系统的前提。2.1 logging模块的三个核心角色Logger是入口。你代码里的logger.info(xxx)实际上是往Logger里丢了一条日志消息Logger会根据自身的级别level判断这条消息是否达到处理门槛如果达到了就交给它名下的所有Handler去处理。Handler是出口。它决定日志去哪儿。StreamHandler输出到控制台或任何类文件对象FileHandler输出到文件RotatingFileHandler带轮转地输出到文件还有各种第三方Handler可以输出到syslog、kafka、ES等但核心机制都一样。Formatter是包装工。它把一条日志消息LogRecord按照指定模板序列化为字符串。这里的字段很丰富包括asctime时间、namelogger名字、levelname级别、message日志正文、filename/lineno哪个文件的哪一行、process/thread进程/线程ID等。举个最常见的配置示例import logging logger logging.getLogger(app.order) formatter logging.Formatter( fmt%(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s, datefmt%Y-%m-%d %H:%M:%S ) console_handler logging.StreamHandler() console_handler.setFormatter(formatter) logger.setLevel(logging.DEBUG) console_handler.setLevel(logging.DEBUG) logger.addHandler(console_handler)这套结构的好处是解耦。Logger负责的是业务逻辑层面你代码里的调用Handler负责的是输出策略层面输出到哪、什么级别才输出Formatter负责的是展示形式层面最终呈现成什么样。三者可以独立调整互不影响。2.2 级别传播机制为什么你的日志“打了却不显示”在logging模块里有一个非常容易踩坑的设计——Logger的层级结构和传播机制propagate。Logger有名字层级关系比如app.order是app的子logger。默认情况下一条日志消息从子logger发出后不仅会流经子logger自己的Handler还会传播给祖先Logger的Handler直到root。这个设计本意是好的让你可以在app这一层统一挂Handler所有子logger都共享输出。但它经常出问题比较典型的是以下两个场景。第一个场景你给logger设置了DEBUG级别但忘了给它挂Handler日志消息传播给了root而root的默认级别是WARNING于是你所有info级别的日志全部消失。这不是logger坏了而是级别链路没理清。第二个场景你在根logger挂了一个Handler又在子logger挂了另一个Handler结果每条日志被打印两次。这是因为传播机制导致同一条日志经过了两个Handler。排除方式很简单子logger设置propagate False打断向上传播。我处理这个问题的方式是项目里只维护一个根logging配置业务代码里只用命名好的logger不重复挂Handler。需要差异输出时比如某些模块要单独写文件再在对应logger上挂专门Handler并设置propagate False。2.3 一套可以复用的基础配置模板分享一下我目前比较稳定的基础配置。这个模板可以直接复制到项目里使用通过logging.config.dictConfig加载逻辑清晰也方便统一管理import logging.config LOGGING_CONFIG { version: 1, disable_existing_loggers: False, formatters: { standard: { format: %(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s, datefmt: %Y-%m-%d %H:%M:%S } }, handlers: { console: { class: logging.StreamHandler, level: DEBUG, formatter: standard }, file: { class: logging.handlers.RotatingFileHandler, level: INFO, formatter: standard, filename: app.log, maxBytes: 10 * 1024 * 1024, backupCount: 5, encoding: utf-8 } }, loggers: { app: { level: DEBUG, handlers: [console, file], propagate: False } }, root: { level: WARNING, handlers: [console] } } logging.config.dictConfig(LOGGING_CONFIG)这个模板的特点是业务logger集中在app下级别DEBUG同时输出控制台和文件第三方库的日志requests、urllib等走root配置默认只显示WARNING以上不会被大量调试信息淹没。实际项目里我会再挂一个QueueHandler这个后面讲性能时再说。3. 格式化与输出的工程化细节格式化这部分看起来只是字符串模板的问题但它是日志系统里最能影响日常使用体验的环节。格式设计好了扫一眼日志就能判断出问题大概在什么位置格式设计不好几千行日志堆在一起肉眼完全分不清主次。3.1 格式化字符串该记的信息一个都不能少我推荐的日志格式至少包含这些字段时间、级别、logger名字、源文件路径与行号、thread/process信息然后是消息正文。时间这个字段必须带完整日期和时分秒有条件还可以加上毫秒%(msecs)d因为日志按秒分时无法区分同秒内的多条记录。级别固定宽度输出%(levelname)-8s在终端里能对齐成列扫读非常舒服。关于%(funcName)s和%(lineno)d很多人觉得不加也行但实际排查问题时这俩字段经常能帮你快速跳过几十个无关日志直接定位到出问题的代码行。尤其是Python这种动态语言函数调用链和文件位置在运行时才确定没有行号要自己搜索半天。关于%(process)d和%(thread)d多进程或多线程应用建议加上。同一时刻可能有多个请求并发执行日志交错在一起没有进程线程ID几乎无法拆开。我一般会配合threading.current_thread().name或者用自定义Filter注入request_id之类让每条日志都能追溯到对应的请求。3.2 控制台与文件输出编码、缓存、换行这些小事控制台输出最常见的坑是编码问题。Windows的终端默认编码经常是GBK日志里一旦包含Unicode字符比如中文或emoji打印到控制台就会抛UnicodeEncodeError程序本身再正常也会被日志系统打断。我在Windows机器上不止一次遇到过这个情况最后用自定义StreamHandler包装sys.stderr强制用UTF-8编码但更省事的方案是在启动入口就设置sys.stdout.reconfigure(encodingutf-8)。文件输出方面务必设置encodingutf-8。Python的FileHandler默认编码是系统语言环境的编码在Linux上通常是UTF-8问题不大但在Windows上可能是GBK存下来的日志文件后续分析时容易出现编码混乱。还有一点FileHandler会默认打开文件的追加模式但部分场景下如果不小心覆盖写modew整个历史日志就没了。还有一个经常被忽略的细节日志文件需要保证目录存在。FileHandler不会自动创建多级目录启动时报FileNotFoundError的情况太常见了。建议在配置handler之前加上Path(log_file).parent.mkdir(parentsTrue, exist_okTrue)。3.3 结构化日志当机器也要读日志时如果你已经进入微服务、容器、云原生的环境纯文本日志会越来越显得不够用。当日志要进入ELK、Loki或CloudWatch这类日志平台机器解析的成本会非常高这时**结构化日志JSON格式**是大势所趋。结构化日志的核心思路是每条日志不是一串拼好的字符串而是一组键值对。字段名就是查询索引内容就是条件。格式为JSON直接能被日志平台解析比如{ time: 2025-05-01T14:23:45.123Z, level: ERROR, logger: app.order, message: 订单处理失败, order_id: A123456, user_id: 1024, processing_ms: 152.3 }Python里实现结构化日志最简单的方式是自定义Formatter在format()方法里把LogRecord的额外字段整理成字典再json.dumps序列化输出import json import logging class JsonFormatter(logging.Formatter): def format(self, record): base { time: self.formatTime(record, %Y-%m-%dT%H:%M:%S), level: record.levelname, logger: record.name, message: record.getMessage(), path: f{record.filename}:{record.lineno} } if record.exc_info: base[exc_info] self.formatException(record.exc_info) if hasattr(record, extra_fields): base.update(record.extra_fields) return json.dumps(base, ensure_asciiFalse)使用方式也简单需要附加字段时用extra参数logger.info(订单处理失败, extra{extra_fields: {order_id: A123456}})这里有个注意点你要把额外字段作为extra_dict传入避免直接覆盖LogRecord内置属性导致冲突。具体形式可以根据项目情况调整但核心思路是——让日志既给人看也给机器看。4. 文件轮转与性能日志写多了会拖垮业务logging模块用起来简单但真要支撑高流量业务性能问题就躲不掉了。日志写入是同步I/O操作如果每一条日志都等待文件写入完成再继续执行业务本身的吞吐量必然被拖累。这部分聊聊常见的轮转策略、异步日志方案和动态调级。4.1 RotatingFileHandler与TimedRotatingFileHandler文件无限增长是个显性问题磁盘空间被日志占满的事故在业内并不少见。RotatingFileHandler按照文件大小轮转TimedRotatingFileHandler按时间轮转比如按天、按小时两者也可以配合使用要看你自己的实际场景。我倾向于按大小轮转为主原因是排查问题时主要关心最近的数据量而按时间轮转可能导致单文件过大一天好几GB打开文件分析很困难。大小轮转的话能控制单文件上限比如每个文件10MB、保留最近5个文件这样磁盘占用稳定在50MB左右够排查绝大多数短期问题。配置参数中maxBytes控制单个文件多大时触发轮转backupCount控制保留的备份文件数。比如maxBytes10*1024*1024, backupCount5就会生成app.log、app.log.1、app.log.2直到app.log.5旧文件依次滚动不会无限堆积。有个重要细节TimedRotatingFileHandler在文件命名上用的是时间后缀而不是序号。它有whenmidnight、whenH等参数但跨天轮转时要注意时区问题不然轮转时机和本地时间对不上。而且它只能保证“按时间切开”不能保证单个文件大小如果一天日志量大依然会撑爆磁盘。条件允许时我优先用RotatingFileHandler。4.2 线程/进程安全与队列高并发时的正确写法先说明一个容易混淆的点FileHandler本身是线程安全的因为logging模块内部用锁保护了对流式对象的写入但它不是进程安全的多进程multiprocessing同时写同一个文件时争抢或交错就会出问题。多进程场景下常见方案有三种按进程号拆分成不同文件名比如app_12456.log让所有进程把日志发到一个统一的消息队列或日志服务由独立进程负责写入用QueueHandlerQueueListener方案在进程内做生产消费分离把磁盘I/O从业务线程中剥离开。QueueHandlerQueueListener是多线程应用非常高效的异步日志方案。核心逻辑是业务线程把日志消息放进内存队列立刻返回后台监听线程从队列取消息执行实际输出业务线程的I/O等待几乎为零。我现场项目里把几百条/秒的同步日志换成这种方案后热点接口的P99耗时有明显改善。import logging import logging.handlers import queue log_queue queue.Queue(-1) queue_handler logging.handlers.QueueHandler(log_queue) file_handler logging.handlers.RotatingFileHandler( filenameapp.log, maxBytes10*1024*1024, backupCount5, encodingutf-8 ) file_handler.setFormatter(standard_formatter) listener logging.handlers.QueueListener(log_queue, file_handler) listener.start() logger logging.getLogger(app) logger.addHandler(queue_handler)这个方案有几个细节要注意。第一队列要用无限队列Queue(-1)否则队列满了会丢弃日志第二服务关闭前要调用listener.stop()保证队列里剩余日志全部落盘第三进程退出时队列里的日志可能丢失所以atexit钩子要挂上。4.3 日志级别动态调整线上排查的救命操作日志级别的静态配置有个硬伤线上出问题时你想要的是更详细的信息但通常线上跑的是INFO甚至WARNING级别DEBUG级别的日志根本没输出。重启服务切换级别又面临代价高、出错影响面大的问题。我推荐在项目里加一个动态调整日志级别的接口。最简单的方式是基于Flask或FastAPI开一个内部接口收到请求时全局调整某个logger的级别app.post(/internal/log/level) def set_log_level(level: str, logger_name: str app): logger logging.getLogger(logger_name) try: logger.setLevel(level.upper()) except ValueError: return {error: invalid level}, 400 return {logger: logger_name, level: logger.getEffectiveLevel()}这样排查问题时可以先临时打开DEBUG复现一轮再关闭整个过程服务不需要重启对业务的影响面几乎为零。安全提醒这类接口一定要限制在内网或加上认证否则等于给攻击者开了信息泄露的通道。5. 常见问题与排查技巧实录这部分内容是实打实的踩坑记录每个问题我都真实遇到并排查过给解决方案的同时也讲讲排查思路。5.1 日志丢失、重复、乱码这类“玄学”问题日志丢失比较多的情况是logger没设置级别用默认NOTSET往上找祖先配置结果祖先也没有正确处理最终消息被root丢弃。排查步骤是先确认logger.getEffectiveLevel()返回的值如果高于你想要的值就说明没有按预期设置上。日志重复里最典型的是“每条日志打印两遍”。原因基本如上文所说子logger挂Handler的同时没有关propagate消息既被子logger自己的Handler输出了一遍又传播给root又被输出了一遍。解决办法就是子logger设置propagateFalse或者在root里去掉重复的目的地。乱码问题要分开看文件乱码通常是文件编码设置不对确认FileHandler的encoding参数是utf-8控制台乱码是终端编码问题设置PYTHONIOENCODINGutf-8环境变量或者在入口处重配sys.stderr。还有一种是字符串本身包含非法字节检查和清洗数据源即可定位。5.2 敏感信息过滤日志不该记录的坚决不进文件日志系统只负责记录但信息边界是要自己守住的。用户的手机号、身份证、银行卡、密码、Token/Cookie这些字段原则上不允许出现在日志里。个人经验是建立一套“字段黑名单正则脱敏”机制在格式化输出之前统一走一遍过滤逻辑。比如自定义一个Formatter在format()里对原始消息做脱敏再输出import re class MaskFormatter(logging.Formatter): SENSITIVE_PATTERNS [ (re.compile(r(password[\]?\s*[:]\s*[\]?)([^\\s,}])), r\1***), (re.compile(r(token[\]?\s*[:]\s*[\]?)([^\\s,}])), r\1***), (re.compile(r(card_no[\]?\s*[:]\s*[\]?)([^\\s,}])), r\1***), ] def format(self, record): message record.getMessage() for pattern, replacement in self.SENSITIVE_PATTERNS: message pattern.sub(replacement, message) record.msg message return super().format(record)这虽然不能防御所有场景但能做到第一道闸门。最稳妥的策略是日志语句就不该把敏感字段传进来从源头切断而不是事后脱敏。哪怕要有也只用掩码后的值。5.3 异常处理中日志的写法捕获与抛出之间如何取舍logger.exception只能在except代码块里使用它会自动附上当前异常堆栈。但很多人在不恰当的层次用了它导致日志充斥着大段堆栈但上下文信息却是空的。正确的做法是分层记录底层模块如数据库访问层只把异常背景记到debug或info级别方便追踪。业务层在捕获到异常后记录一条exception日志包含业务上下文订单ID、操作类型等。外层应用入口如API层再捕获一次记录一条error日志附带请求级别的信息。这样可以保证最外层的日志是“人类可读的异常概览”最内层保留了技术细节。如果每层都只丢一个无上下文的裸exception那在日志平台搜索时你会被几百条雷同堆栈淹死。另外一个习惯是不要用print输出异常print无法携带级别、时间、位置、线程等信息也绕过了日志系统的统一管理。排查问题时你会后悔的。6. 日志的测试与维护像对待核心代码一样对待日志日志不是写完一遍就完事的。它跟业务代码一样需要测试、维护、演进。这里分享一下我维护日志系统的一些做法。6.1 用断言测试日志输出比肉眼可靠得多线上日志格式改动后人工去翻日志文件检查是否正确费时费力还容易漏。推荐的方案是在单元测试里用caplogpytest自带断言日志输出内容、级别和字段。from pytest import LogCaptureFixture def test_order_logs_order_id(caplog: LogCaptureFixture): with caplog.at_level(logging.INFO, loggerapp.order): place_order(A123456) assert A123456 in caplog.text assert any(r.levelname INFO for r in caplog.records)有了这层保障之后调整Formatter格式、改动Handler配置时不容易把日志内容改坏而不自知。这套测试开销很小但防回归效果极佳。6.2 日志即接口字段变更是需要评审的变更我越来越觉得日志系统本身就应该被当作对外接口来维护。日志字段是下游日志平台的数据结构约定是排查问题的合同。想明白这一点之后你会更加谨慎地处理日志字段可以新增但尽量不删、不改。字段改名至少要同步下游告警规则否则告警直接失效。平时代码review时不只是看业务逻辑还要看日志语句写得是否规范是否在正确的级别、是否携带足够的上下文、是否有敏感字段。团队里约定统一的日志规范文档比起每个人各自发挥要省心得多。6.3 监控日志本身谁来看护看护者最后说一下日志自身的可观测性。日志系统如果静默失效业务代码还正常跑排查时才发现日志断更了几个小时这就比较被动了。维护生产环境的日志至少要监控三件事日志文件是否还在增长、最近日志是否存在ERROR/WARN级别的突发、队列阻塞情况是否异常。这些可以直接接入你已有的监控体系。比如用文件大小或最后修改时间做告警用日志关键词频率做告警用队列深度做告警。日志系统是工具工具本身也需要被监控这一步千万别省。写到这里关于Python日志记录Logging最佳实践想分享的基本都说完了。我自己的体会是日志系统的设计到最后拼的不是技巧而是习惯每条日志都要能回答问题每个级别都要有明确的使用场景每个字段都要经过安全性把关。把这几条刻到日常编码里比背一堆配置参数更值得。如果只让我留一个建议的话那就是尽早把日志当成产品来设计——它的用户是未来那个正在深夜排查问题的你。你今天花在日志设计上的每一分钟都会在某个紧急时刻加倍还回来。