Python logging模块实战:告别print,掌握日志配置与轮转
发布时间:2026/10/2 19:59:25来源:尧图网络
我最早学Python那会儿排错基本全靠print。print(走到这里了)print(数据长这样),print(报错了看看是哪一行)……程序一旦跑起来就盯着控制台狂翻日志一多连哪条对应哪个模块都分不清。后来用了Python内置的日志模块logging才算是从这种原始状态里解脱出来。logging不是第三方库是Python标准库自带的日志模块装好Python就能用不需要pip install任何东西。它能帮你把程序的运行过程按重要程度分级记录下来可以输出到控制台也可以写到文件还能按日期或者按大小自动切割程序崩了之后回头看日志就能复现当时的现场。这篇文章想写给正在学Python的新手、写爬虫脚本的数据分析师以及维护长期运行服务的同学把这套日志玩法讲透顺便把我踩过的坑一并列出。1. 先从 print 告别日志模块到底解决了什么问题1.1 print 的三个软肋很多新手觉得print挺好用的又不是不能用。确实几十行的小脚本print完全够用。但项目一旦变大print的三个软肋就藏不住了。第一print没有级别概念。调试信息、正常运行信息、出错信息全部糊在一起屏幕上全是“”“-------”之类的手工分隔线。生产环境想看error根本筛不出来只能靠眼睛找。第二print没有上下文。你只知道“数据到这里了”但不知道是哪条日志、哪个函数、第几行。真出问题的时候你得自己猜测是哪次循环、哪个线程。第三print只能往控制台输出。程序关掉窗口日志就没了就算用重定向写到文件也完全没法做自动切割、按天归档。而logging把这些全部解决了。每一条日志可以统一带上时间、模块名、函数名、行号可以按级别一键过滤可以同时写文件和控制台文件还能自动轮转。说白了print是随手记在草稿纸上的便签logging是一个带索引的档案柜。1.2 日志级别你手里的分级开关logging把日志分成五个常用级别从低到高分别是DEBUG、INFO、WARNING、ERROR、CRITICAL。底层对应的数值是这样的级别数值典型使用场景DEBUG10调试期间的细节信息比如循环里的中间结果、请求参数INFO20正常流程的关键事件比如任务开始、任务结束、处理了多少条数据WARNING30程序还能继续跑但已经存在潜在风险比如接口变慢、重试发生、数据缺字段ERROR40某个功能坏了但主程序没崩比如某条数据解析失败CRITICAL50程序已经无法继续运行比如配置缺失、数据库连不上记住一个原则级别不是用来标榜代码价值的是用来控制信息量的。我在实际项目里的默认组合是——调试阶段开DEBUG日常运行开INFO上线服务至少提到WARNING。日志系统最怕的不是没有日志而是日志太多把真正需要关心的东西淹没了。另外logging里的级别过滤是单向的也就是说你设了LevelINFO那么DEBUG不会输出INFO及以上的才会输出。这一点后面排错时会反复用到。2. 基础配置把 logging.basicConfig 用明白2.1 三行代码搭好第一个 loggerlogging的入门方式非常简单调用一次basicConfig就行。import logging logging.basicConfig( levellogging.INFO, format%(asctime)s [%(levelname)s] %(name)s:%(lineno)d - %(message)s, datefmt%Y-%m-%d %H:%M:%S ) logger logging.getLogger(__name__) logger.info(程序启动) logger.warning(磁盘空间不足)这段配置做完你的程序里所有通过logger输出的日志都会带上时间、级别、模块名和行号。比如会输出像这样的内容2025-01-06 14:23:11 [INFO] __main__:7 - 程序启动注意最后一行用的是logging.getLogger(__name__)而不是直接logging.info。用__name__的好处是在多个文件的工程里日志会自动带上当前模块名比如爬虫模块、数据处理模块、策略模块的日志一眼就能分开。2.2 格式与时间参数日志字段怎么挑format字符串里能放的字段非常多我常用的这几个最重要占位符含义%(asctime)s日志产生时间%(levelname)s日志级别%(name)slogger名字通常是模块名%(lineno)d行号%(funcName)s函数名%(threadName)s线程名%(message)s日志正文很多网上的教程会把格式写得特别花哨什么彩色输出、对齐缩进、加文件路径全都有。我的建议是别贪多字段越多日志越膨胀定位信息够用就好。我长期用的是这一套%(asctime)s [%(levelname)s] %(name)s:%(lineno)d - %(message)s时间格式datefmt也要自己指定。如果不写默认输出会带逗号和毫秒像2025-01-06 14:23:11,123这种后面做日志分析时不方便。用datefmt%Y-%m-%d %H:%M:%S把毫秒去掉就行。2.3 写日志文件的几个关键注意脚本要跑很久的时候最好把日志写到文件里配置变成这样logging.basicConfig( filenameapp.log, filemodea, levellogging.INFO, format%(asctime)s [%(levelname)s] %(message)s, encodingutf-8 )这里有两个坑我要特别提醒。一个是filemode。默认是a也就是追加模式如果手滑写成w那每次程序启动都会把旧日志清空上次运行的问题记录就全没了。另一个是encodingutf-8在Windows环境下不指定的话控制台和文件很容易出现中文乱码。还有一条最容易被忽略的规则basicConfig在整个python进程里只能生效一次。重复调用并不会更新配置第二次之后的调用会被直接忽略。所以如果你在模块A里调用一次又在模块B里调用一次实际生效的只有第一次的那套配置。后面进阶内容里我们要用更灵活的方式绕开这个限制。3. 进阶组合Logger、Handler、Formatter 的实战玩法3.1 basicConfig 撑不住的场景basicConfig适合写一次性脚本。但你很快会遇到几个让它手忙脚乱的场景想让日志同时输出到控制台和文件basicConfig做不到想让日志按文件大小自动切割做不到想让ERROR单独进一个文件其他信息进另一个文件更做不到。这时候就得理解logging真正的三层结构。我自己的经验是只要项目要连续跑几天或者需要复盘历史日志就别再用basicConfig凑合了直接上手Handler的组合方式。刚开始会觉得代码变多但这一套可以复制到之后的所有项目里。3.2 Logger、Handler、Formatter 到底谁管谁logging的三层结构可以打个比方。Logger是前台登记台你所有业务代码只管调用logger.info、logger.error它负责收集消息。Handler是快递通道它决定了消息被送往哪里——文件通道、控制台通道、网络通道。Formatter是信封上的书写规范它决定了日志长什么样。一个Logger可以挂多个Handler每个Handler可以用不同的级别、不同的Formatter。这就是“同一条日志同时进控制台和文件”的基础。每一层的职责很清晰Logger管入口Handler管出口Formatter管排版。3.3 同时输出到控制台和文件的配置模板下面这个是我在实际项目里反复复用的最小模板直接把配置函数粘贴到工程入口文件里其他模块只管getLogger()拿名字就行import logging def setup_logger(): logger logging.getLogger(my_app) logger.setLevel(logging.DEBUG) fmt logging.Formatter( %(asctime)s [%(levelname)s] %(name)s:%(lineno)d - %(message)s, datefmt%Y-%m-%d %H:%M:%S ) file_handler logging.FileHandler(app.log, encodingutf-8) file_handler.setLevel(logging.DEBUG) file_handler.setFormatter(fmt) console_handler logging.StreamHandler() console_handler.setLevel(logging.INFO) console_handler.setFormatter(fmt) logger.addHandler(file_handler) logger.addHandler(console_handler) return logger这里最实用的一点是文件里记录全量DEBUG控制台只显示INFO及以上的内容。这样你在终端看日志不会被刷爆出问题后翻文件又能找到细节。两个Handler的级别是独立控制的这是logging最灵活的地方。有一点必须记住如果这个setup_logger函数被调用两次同一个logger会被重复挂上两套Handler日志就会重复打印。后面第5节我会专门讲怎么避免。3.4 日志文件的自动切割长时间运行的脚本日志文件会越来越大。logging标准库带了两把好用的刀一个是按大小切一个是按时间切。按大小切割用RotatingFileHandlerfrom logging.handlers import RotatingFileHandler file_handler RotatingFileHandler( app.log, maxBytes10 * 1024 * 1024, # 单个文件达到10MB就切 backupCount5, # 保留最近5个备份 encodingutf-8, )当app.log超过10MB时会自动重命名为app.log.1新日志写到新的app.log再满一次app.log.1变成app.log.2依此类推最多保留到app.log.5最旧的被删除。总磁盘占用大约60MB。这个方案适合日志量不稳定的服务比如有时候一天几百MB有时候一周才几十KB。按时间切割用TimedRotatingFileHandlerfrom logging.handlers import TimedRotatingFileHandler daily_handler TimedRotatingFileHandler( app.log, whenmidnight, # 每天零点切割 interval1, backupCount30, # 保留最近30份 encodingutf-8 )when参数支持的取值有S秒、M分、H小时、D天、midnight零点、W0周一凌晨。我用得最多的是midnight和H前者适合每天归档后者适合高频脚本按小时切。有个细节我要提醒轮转删除不是即时的。backupCount的效果会在下一次切割发生时体现如果程序中间长时间没产生日志旧文件也不会立刻被清理。所以如果你有严格的磁盘容量控制还需要额外写一个定时清理任务兜底。4. 典型场景实战爬虫、量化、数据处理该怎么记日志4.1 爬虫日志记录请求、解析结果与重试爬虫是最需要日志的场景之一因为一跑就是几百上千个页面中途挂了连跑到哪都不知道。我在写爬虫时会在三个位置打点请求前、请求成功、出现异常。import logging import requests logger logging.getLogger(spider) def fetch_page(page: int): url fhttps://example.com/list?page{page} logger.info(开始抓取第 %d 页%s, page, url) try: resp requests.get(url, timeout10) resp.raise_for_status() items parse(resp.text) logger.info(第 %d 页解析出 %d 条数据, page, len(items)) return items except requests.RequestException as exc: logger.warning(第 %d 页请求失败%s进入重试, page, exc) return retry_fetch(page)这里有一个很容易搞错的点请求失败该用WARNING还是ERROR我的标准是如果后面还有重试机制就用WARNING因为这只是暂时的风险如果重试全部失败、这条数据要放弃才升级到ERROR。这样翻日志时通过日志级别就能快速判断是“偶发抖动”还是“大面积故障”。还有一个经验数据量大时不要每条item都打INFO会刷屏到日志文件疯涨。我通常每1000条打一条进度或者等一页处理完打一条汇总。另外注意我在日志里用的是%s占位符而不是字符串拼接。这样在日志级别被过滤掉时程序不会白做格式化性能会好不少后面量化部分还会细说。4.2 量化脚本高频循环下的日志节流量化策略的代码循环频率极高tick级的数据能让你一秒钟输出几百行。最容易犯的错误就是每个tick都打印一次持仓、价格、指标结果日志文件一小时就几个GB实盘都跑不动。我的做法是分级加节流。中间计算的指标全部放DEBUG只在信号发生变化时才打INFOif new_signal ! old_signal: logger.info( 信号变化%s - %s目标仓位 %.2f, old_signal, new_signal, target_pos ) old_signal new_signal再配合每分钟一条汇总日志记录当前持仓、累计盈亏、阶段耗时。这样复盘时能还原决策过程又不会让日志淹没磁盘。还有性能上的讲究。写量化代码时我见过有人写logger.debug(持仓: str(positions))这非常亏。因为Python会先执行字符串拼接再去调logger即使DEBUG级别被过滤拼接的开销也照付。正确写法是用占位符延迟拼接logger.debug(当前持仓: %s, positions)级别被过滤时格式化根本不会执行。这句话在回测脚本里可能只差几毫秒但在tick循环里差别可能就是卡顿与流畅的分界线。4.3 数据处理管道分阶段日志帮你定位耗时和缺失用pandas、numpy处理数据时管道越长越需要日志。我曾经处理一个几千万行的大表清洗、去重、合并、聚合跑了三个多小时中途崩了。没有日志的话只能从头再来一遍试错有了分阶段日志直接看最后一条输出就知道崩在哪一步。我的习惯是每个处理阶段都记录shape和耗时import logging import time import pandas as pd logger logging.getLogger(etl) def run_pipeline(): t0 time.monotonic() df pd.read_csv(raw.csv) logger.info(读取完成shape%s耗时 %.2f 秒, df.shape, time.monotonic() - t0) df df.drop_duplicates() logger.info(去重后 shape%s, df.shape) df[score] df[score].fillna(0) missing int(df.isna().sum().sum()) logger.warning(填充缺失值完成剩余缺失 %d 个, missing) df.to_excel(result.xlsx, indexFalse) logger.info(写入结果文件完成行数 %d, len(df))这种“每步记录形状和耗时”的习惯能让你在复盘管道时一眼看出哪个环节膨胀了、哪个环节最耗时。很多处理瓶颈就是靠这种日志发现的。另外如果脚本是挂在服务器上运行的记得用nohup python run.py stdout.log 21这类方式跑。但要注意重定向到stdout.log不会自动轮转长期任务最后还是回到第3节里讲的文件Handler方案把日志交给logging自己管理。5. 常见问题与排查技巧实录5.1 日志重复打印最经典的大坑日志重复打印是几乎所有Python开发者都会遇到一次的问题。现象是终端里同一条日志出现两遍三遍越调越多。原因无非三个多次调用basicConfig、多次给同一个logger挂Handler、或者子logger默认向父logger传播导致重复。最直接的解决办法是在配置函数里先清理已有Handlerlogger logging.getLogger(my_app) if logger.hasHandlers(): logger.handlers.clear()更规范的做法是整个工程只在入口位置调用一次setup函数其他模块只负责getLogger(__name__)取名字不新增Handler。如果你的代码里到处都在addHandler迟早会撞上重复打印的墙。5.2 中文乱码日志里全是乱码多半是编码问题。在Windows环境下Python默认的文件编码可能是gbk写出来的日志用UTF-8的编辑器打开就乱。解决方式很简单所有FileHandler和basicConfig都加上encodingutf-8。控制台乱码则是另一回事。Windows终端默认编码可能不是UTF-8可以用chcp 65001切换代码页或者在环境变量里设置PYTHONIOENCODINGutf-8。我的习惯是“文件统一UTF-8控制台尽量UTF-8”两边都用同一个编码基本不会再踩这个坑。5.3 多线程与多进程的日志安全多线程场景下logging是线程安全的Handler内部有锁多个线程往同一个logger写日志不会交错乱序直接放心用。但多进程就没这么省心了。多个进程同时写同一个日志文件文件写入会互相踩踏出现截断、串行错乱。常见的解决方案有三个每个进程写独立的日志文件通过QueueHandler把日志汇总到专用线程统一写盘或者干脆把日志交给专门的日志服务。对于大多数场景最简单的是给每个进程单独命名日志文件比如app_worker_1.log、app_worker_2.log。5.4 日志丢失与级别不生效最后这一组问题排查起来更隐蔽。日志级别不生效的常见原因是logger级别和Handler级别叠加限制。logger.setLevel(Debug)只能保证消息进入logger真正能否输出还要看Handler自己的setLevel。如果logger是DEBUG而Handler是INFO那DEBUG日志还是不会写进文件。所以排查时两个级别都要检查。日志“消失”也有几个经典坑如果你的logger没有挂任何Handler同时又设置了propagate False日志消息就真的无影无踪了。还有一种情况是没配置任何Handler时logging会有一个兜底行为WARNING及以上默认输出到sys.stderr让你以为日志还在等自定义Handler就位后行为又变了会让人很困惑。文件没生成也别急着怀疑代码先检查日志目标目录是否存在、当前用户有没有写权限。这些坑我基本都踩过一遍。踩过之后形成的固定习惯是把第3节的配置函数放在项目入口全局只用一份logger配置日志格式固定凡是长时间运行的程序一律不依赖print不依赖控制台全部交给logging文件Handler管理。我个人最深的体会是日志模块最好的使用时机不是程序出故障之后而是动手写第一行业务代码之前。花30秒配好logger看起来是多了一步其实是整个项目里回报率最高的投资。后面你维护脚本、排查数据管道、复盘策略运行都会感谢当初认真配日志的自己。
网站建设高端定制企业官网