
我干了这么多年Python有个体会越来越深日志记录Logging就是程序的“黑匣子”。飞机不能没有黑匣子生产环境里跑的服务也不能没有像样的日志。能用好Python自带的logging模块跟只会print(xxx)打天下完全是两个段位。这篇文章我就把这些年攒下的logging实战心得、踩过的坑、以及一套能直接抄作业的配置模板一次性聊透。这篇文章适合刚接触Python日志的小白也适合已经写了一阵子业务代码、但还没系统梳理过日志体系的朋友。1. 先别急着写日志想清楚你要回答什么问题1.1 日志的核心价值不是在记录而是在“复盘”很多初学者对日志的理解就是“把程序运行的信息打出来看看”。这个理解方向对但格局小了。日志真正的作用是让你在系统出问题之后能够完整地复盘“当时到底发生了什么”。线上告警响了、接口超时了、数据对不上了你第一件事一定是翻日志。如果日志里什么都没记或者记了一堆没用的废话那排查问题就变成了大海捞针。我在实际项目里有个很深的感受日志写得好的系统出问题之后半小时内能定位根因日志写得烂的系统光靠猜就可能猜一整天。这里的差距不在于运气而在于当初写日志的时候有没有想清楚一个问题——未来排查问题时我需要从日志里看到什么这个问题听起来空但落到具体场景就很好理解了。比如一个订单系统用户下单失败了你排查时需要知道什么第一用户是谁、订单号是多少第二失败发生在哪个环节是库存校验、支付调用还是数据库写入第三失败的具体原因是什么是参数非法、网络超时还是数据库锁冲突。如果日志里这三类信息都有而且格式统一、方便搜索那排查效率会高出非常多。所以我写日志前通常会先问自己这行日志在未来会遇到什么查询场景这行日志能支撑什么样的复盘分析想明白了这个再去写记录代码日志的质量自然就不一样了。1.2 日志级别DEBUG、INFO、WARNING、ERROR、CRITICAL到底怎么用Python的logging模块定义了五个标准级别从低到高分别是DEBUG、INFO、WARNING、ERROR、CRITICAL。每个级别代表不同的严重程度也对应着不同的使用场景。DEBUG最详细的诊断信息比如“正在调用某某接口参数是xxx”。这类日志只在开发调试时需要生产环境一般不开启。因为正常跑业务根本不需要这么细的信息全打出来只会刷屏。INFO关键的运行节点信息比如“用户下单成功订单号xxx”。这类日志告诉你系统在正常做什么相当于程序的“行为轨迹”。WARNING出现了一些异常情况但不影响主流程继续执行比如“接口响应时间超过2秒需要关注”“缓存未命中回源数据库”。这类日志是隐患的早期信号。ERROR出现了错误某个功能失败了但程序没有崩溃比如“调用支付接口失败订单号xxx”。这类日志是排查问题的重点。CRITICAL非常严重的错误系统可能无法继续运行比如“数据库连接池耗尽服务不可用”。这类日志通常需要立刻告警通知人处理。有个很常见的误区是很多人把ERROR当成唯一的日志出口只要try-except了就往ERROR里写搞得整个日志文件里全是ERROR而真正的INFO轨迹却几乎没有。这种做法的结果是系统报错的时候你确实能看到错误信息但完全不知道这个错误是在什么上下文中发生的——前面经历了哪些步骤当时的输入是什么一概不知。好的日志习惯是INFO记录行为轨迹WARNING记录隐患ERROR记录具体的失败原因和影响范围DEBUG才负责记录那些“过于详细”的细节。层级清晰每个级别各司其职日志才有真正的使用价值。2. 从零搭建日志体系Logger、Handler、Formatter的分工逻辑2.1 三个核心组件的关系一个生活化的类比Python的logging模块里Logger、Handler、Formatter是三个核心组件理清它们的关系是搭建日志体系的第一步。我用一个生活化的类比来解释假设日志系统是一个快递派送体系。Logger就是“快递单上的收件人标签”。你写日志的时候调用的是logger.info(xxx)这个logger决定了日志的“身份”——它属于哪个模块、什么级别的信息要记录下来。每一条日志进入系统首先都要经过Logger这一关Logger根据设置的日志级别过滤掉不需要的信息。Handler就是“快递配送员”。Logger拿到一条日志后需要把它送出去Handler就是干这个的。它决定日志最终流向哪里——是输出到控制台、写入文件、发送到远程日志服务器还是同时输出到多个地方。一个Logger可以挂多个Handler就好比一条信息既可以在控制台看又同时写入文件存档。Formatter就是“快递包装上的面单”。Handler把日志送出去之前Formatter负责决定日志长什么样——时间戳、日志级别、模块名、函数名、消息内容这些字段怎么排版、用什么分隔符都由Formatter控制。Logger负责决定“什么该记”Handler负责决定“记到哪里”Formatter负责决定“记成什么样”。三个组件各管一摊但又互相配合。理解了这层关系后面所有的配置逻辑就都串起来了。2.2 basicConfig的便利与局限Python的logging模块提供了一个快速上手的方法logging.basicConfig()。很多教程一开始都会教你这样写import logging logging.basicConfig(levellogging.INFO, format%(asctime)s - %(levelname)s - %(message)s) logging.info(Hello, world!)这确实很方便三行代码就能跑起来。但我在实际项目里会特别提醒basicConfig适合脚本和小工具不太适合正经的业务系统。原因主要有三个第一basicConfig是“根logger”级别的全局配置一旦设置了格式所有模块的日志都跟着这个格式走。但不同模块的日志需求往往不一样——数据库模块可能想记录SQL和执行耗时HTTP模块想记录请求路径和状态码放在同一个全局格式里就很别扭。第二调用basicConfig多次是无效的。如果程序里有两个模块都调用了basicConfig后调用的不会覆盖先调用的配置还是第一次调用时的那一套。这在大型项目里经常会让人困惑为什么我明明重新设置了格式输出还是老样子第三basicConfig默认的StreamHandler输出到标准错误流如果你想把日志同时写到文件和控制台basicConfig的配置方式会变得很笨拙得手动去操作root.handlers。所以在业务系统里我更推荐的做法是不要用basicConfig而是手动创建Logger实例并为每个Logger显式配置Handler和Formatter。这样每个模块、每个场景都可以有自己的日志策略互不干扰。2.3 手动配置一套完整的日志链路代码示例下面我给出一个手动配置的完整示例把Logger、Handler、Formatter串起来看import logging import sys # 创建Logger实例命名为app logger logging.getLogger(app) logger.setLevel(logging.DEBUG) # 创建控制台Handler console_handler logging.StreamHandler(sys.stdout) console_handler.setLevel(logging.INFO) # 创建文件Handler file_handler logging.FileHandler(app.log, encodingutf-8) file_handler.setLevel(logging.DEBUG) # 定义Formatter console_formatter logging.Formatter(%(asctime)s | %(levelname)-8s | %(message)s) file_formatter logging.Formatter(%(asctime)s | %(levelname)-8s | %(name)s | %(module)s:%(lineno)d | %(message)s) # 为Handler设置Formatter console_handler.setFormatter(console_formatter) file_handler.setFormatter(file_formatter) # 为Logger添加Handler logger.addHandler(console_handler) logger.addHandler(file_handler) # 使用 logger.debug(这是一条调试信息) logger.info(这是一条普通信息) logger.warning(这是一条警告信息)这段代码里有个细节值得注意Logger的级别和Handler的级别是“双重过滤”。Logger的DEBUG级别表示“DEBUG及以上的日志都能进入后续流程”但控制台Handler的INFO级别又过滤了一遍所以DEBUG日志只进文件不进控制台。这种“双重门禁”的设计让我可以灵活地控制不同输出渠道的日志粒度——开发时控制台看INFO就够了但文件里保留最完整的DEBUG记录方便事后深挖。这套手动配置看起来比basicConfig多写了几行代码但换来的是清晰的控制力。在实际项目里我通常会把这套配置封装成一个函数或者一个配置模块统一管理效果非常好。3. 生产环境绕不开的话题日志轮转、格式化与性能3.1 日志轮转不让日志把磁盘写爆生产环境里跑着的服务日志增长速度是超出预期的。一个中等流量的Web服务一天产生几百MB甚至几GB的日志都很正常。如果日志文件无限增长要不了几天磁盘就会被写满到时候不只是这个服务挂了同一台机器上的其他服务也可能被拖下水。解决这个问题靠日志轮转。Python的logging模块原生支持两种轮转方案RotatingFileHandler和TimedRotatingFileHandler。RotatingFileHandler按文件大小轮转。我设置maxBytes1048576010MBbackupCount5那么当日志文件写到10MB时就会自动把当前文件重命名为app.log.1然后新建一个app.log继续写。依次类推app.log.1变成app.log.2最老的app.log.5被删掉。这样磁盘上始终保持最多6个日志文件总量不超过60MB。TimedRotatingFileHandler按时间轮转。比如whenmidnight表示每天零点轮转一次backupCount7表示保留7天的日志。这种方式适合日志大小波动比较大的场景比如某天流量爆发一天写了50MB另一天只写了5MB按时间轮转可以保证保留足够长的历史周期。实际项目中我经常把两种方案结合来考虑大流量、日志量稳定的服务用大小轮转因为可以精确控制磁盘占用日志量波动大、需要按天分析历史的服务用时间轮转。不过需要注意一点轮转不是没有代价的——轮转发生时文件要重命名、新文件要创建这期间如果大量日志写入可能会有短暂的性能抖动。所以轮转操作最好放在业务低谷期或者采用定时轮转尽量减小影响。3.2 日志格式哪些字段值得记录背后有什么考量日志格式这件事看着简单其实讲究不少。好的日志格式是“一行日志就是一个完整的事件记录”任何一行拿出来你都能判断出时间、来源、级别、大致业务。我用过的日志格式里最推荐的信息组合是字段作用示例时间戳定位问题发生的时间点2025-01-15 14:03:22,185日志级别判断严重程度INFO / ERRORLogger名称定位来源模块app.service.order模块与行号快速跳转到代码位置order_service.py:87线程/进程ID排查并发问题Thread-3 / 4521消息正文业务事件的描述用户下单成功订单号20250115140322001这里面有一个字段我特意强调模块和行号。日志里有行号排查问题时可以直接定位到代码的那一行效率完全是两个级别。代价只是每次记录日志时多一次额外的堆栈解析但对绝大多数业务系统来说这个性能开销是完全值得的。时间戳的格式也有讲究。如果日志里只有时间没有日期跨天排查时就会很痛苦。我习惯用%(asctime)s配合datefmt%Y-%m-%d %H:%M:%S把日期和时间都打全。另外如果服务部署在多台机器上时间戳最好统一用UTC避免不同机器时区不一致导致的日志时间线错乱。3.3 性能问题日志别把业务拖垮日志写得好不好性能也是一个绕不开的指标。有些排查类日志比如“每次循环都打一条DEBUG”在高频场景下会把接口响应时间拉长好几倍。我对日志性能的关注点主要有三个日志级别的j判断要前置。比如logger.debug(f处理完成: {data})如果当前日志级别是INFODEBUG根本不会输出但f-string已经执行了字符串格式化白白浪费了CPU。更好的写法是if logger.isEnabledFor(logging.DEBUG): logger.debug(处理完成: %s, data)或者直接让logger自己处理参数。logging模块本身支持延迟格式化写成logger.debug(处理完成: %s, data)就不会在级别不够时做格式化。高频日志要采样。比如某个接口每秒被调用上千次每次成功都打一条INFO这日志很快就会淹没真正有用的错误信息。这种场景我建议只在错误或异常时打日志成功路径不打如果一定要打就采用抽样策略只记录每100次请求中的1次或者只记录超过阈值比如耗时大于500ms的请求。异步日志是个大杀器。在高并发场景下日志写磁盘这个IO操作可能成为瓶颈。解决思路是把日志写入放到独立线程业务线程只负责把日志事件放进队列由后台线程统一刷新到磁盘。Python的logging模块自带QueueHandler和QueueListener可以配合使用。不过这也带来一个代价进程崩溃时队列里还没来得及写盘的日志会丢失。所以异步日志适合日志量巨大、但容忍少量丢失的场景日志量可控时我一般还是用同步写盘保证完整性。4. 踩坑实录重复日志、丢失堆栈与多线程安全4.1 重复日志一条日志打两遍的根因重复日志是logging使用中最常见的问题没有之一。现象是程序里明明只写了一行logger.info(xxx)控制台却输出了两遍甚至更多。这个坑的根因绝大多数时候是同一个Logger被多次添加Handler。比如你写了一个setup_logger()函数里面创建了Logger并添加了Handler然后不小心在两个地方都调用了这个函数或者模块导入的时候配置日志的代码被执行了两次。每次执行都会给同一个Logger实例再挂一个新的Handler之前挂的还在于是日志就被打多遍。还有一种隐蔽的情况logger本身已经挂上了Handler你又调用了logging.basicConfig()而basicConfig又往root logger上挂了一个默认Handler。入口模块用logger打日志经过自己挂的Handler输出一遍又顺着parent链传到root logger再输出一遍就出现了重复。我排查这类问题的方法是在代码里打印logger.handlers看看列表里有几个元素。如果多于一个那就直接找到了问题。标准做法是在添加Handler之前先清理一遍logger.handlers.clear()或者用更优雅的方式if not logger.handlers: # 添加Handler另外如果不想让子模块的日志重复传到root logger我习惯在创建Logger时设置propagateFalse。这个属性控制日志事件是否向上级logger传递。业务Logger设成False日志就只在自己的Handler这里处理不会流向root从源头上消灭了重复日志的隐患。4.2 异常堆栈为什么丢了写日志时还有一个特别常见的问题异常堆栈信息丢了。很多同学在捕获异常后这样写try: result 1 / 0 except ZeroDivisionError as e: logger.error(f计算出错: {e})这样写日志里只有一句“计算出错: division by zero”但异常是在哪个文件、哪一行代码抛出来的完全看不到。排查问题时没有堆栈信息定位难度会大大增加。正确的做法是使用logger.exception()它是专门用来记录异常信息的try: result 1 / 0 except ZeroDivisionError: logger.exception(计算出错)logger.exception()会自动把当前异常堆栈附加到日志消息后面输出结果类似于ERROR - 计算出错 Traceback (most recent call last): File test.py, line 2, in module result 1 / 0 ZeroDivisionError: division by zero如果不想用exception()也可以主动给logger.error()传入exc_infoTruelogger.error(计算出错, exc_infoTrue)效果是一样的。这个细节能帮你少走很多弯路遇到异常第一时间拿到完整堆栈比什么都强。4.3 多线程环境下的日志线程安全问题Python的logging模块自带线程锁同一个Logger实例被多个线程同时调用时日志消息不会交错乱掉。每一条完整的日志消息是原子的不会出现“A线程写了一半被B线程插进来”的情况。但这里有个容易被忽略的坑线程锁保证的是单行日志的完整性不保证多行日志的顺序。比如用户下单这个操作可能跨多个模块、多次调用logger这几条日志虽然是同一个用户的操作但如果A线程和B线程同时在下单日志输出顺序可能会交错成A1、B1、A2、B2而不是A1、A2、B1、B2。排查问题时这种交错会让“还原单个请求的完整流程”变得很难受。解决办法有两个思路一是引入请求IDtrace_id。在请求入口生成一个唯一的ID通过contextvars或者日志的extra参数传递到整个调用链每条日志都带上这个ID。查日志时按trace_id过滤就能把一次请求的所有日志串起来看。这已经是目前主流微服务架构里的标配日志实践了。二是使用独立的日志上下文管理器。Python 3.7之后logging引入了contextvars支持在异步代码里父任务的日志上下文会自动传递给子任务这给异步场景的日志追踪提供了原生支撑。我在做Web服务时最常用的组合是中间件生成trace_id Logger整体带上该字段 日志系统里按trace_id索引。这一套下来不管多线程还是多协程并发都能轻松还原每次请求的完整链路。5. 一套可以直接抄作业的日志配置模板5.1 单体应用推荐配置聊了这么多理论和坑最后给出一套我在实际项目中反复使用、调整后的配置模板。这套模板适用于大多数单体应用兼顾了控制台可读性和文件完整性。import logging from logging.handlers import RotatingFileHandler import sys def setup_logger(nameapp, log_fileapp.log, levellogging.INFO): 统一的日志配置入口 logger logging.getLogger(name) logger.setLevel(level) logger.propagate False # 清理已有Handler避免重复 logger.handlers.clear() fmt %(asctime)s | %(levelname)-8s | %(name)s | %(module)s:%(lineno)d | %(threadName)s | %(message)s datefmt %Y-%m-%d %H:%M:%S # 控制台Handler console_handler logging.StreamHandler(sys.stdout) console_handler.setLevel(level) console_handler.setFormatter(logging.Formatter(fmt, datefmtdatefmt)) # 文件Handler大小轮转 file_handler RotatingFileHandler( log_file, maxBytes10 * 1024 * 1024, backupCount5, encodingutf-8 ) file_handler.setLevel(logging.DEBUG) file_handler.setFormatter(logging.Formatter(fmt, datefmtdatefmt)) logger.addHandler(console_handler) logger.addHandler(file_handler) return logger # 使用示例 logger setup_logger(order_service, logs/order_service.log)这套配置的核心思路是控制台输出INFO级别文件保留DEBUG级别。开发时在控制台看INFO够用回查时翻文件能拿到最完整的DEBUG细节。加上大小轮转磁盘占用可控。如果你在写FastAPI或Flask这类Web应用还可以手动给uvicorn或werkzeug的logger设置同样的格式保持整个服务日志风格的统一。否则你经常会遇到“业务日志规规矩矩框架日志短了一截”的割裂感。5.2 关于结构化日志与JSON格式的思考最近几年日志领域有一个明显的趋势从“给人看的文本”转向“给机器解析的JSON”。因为日志量大了以后靠人工盯着控制台根本不现实大家都是把日志采集到ES、ClickHouse或者云原生日志平台里再用Kibana或者Grafana做查询分析。这种情况下结构化日志的优势就体现出来了——每个字段都是独立索引按字段过滤、聚合、统计都非常方便。我推荐用python-json-logger这个库来输出JSON格式的日志。下面是接入方式from pythonjsonlogger import jsonlogger class CustomJsonFormatter(jsonlogger.JsonFormatter): def add_fields(self, log_record, record, message_dict): super().add_fields(log_record, record, message_dict) log_record[timestamp] record.asctime log_record[level] record.levelname log_record[logger] record.name log_record[module] record.module log_record[line] record.lineno if hasattr(record, trace_id): log_record[trace_id] record.trace_id formatter CustomJsonFormatter( fmt%(asctime)s %(levelname)s %(name)s %(module)s %(lineno)d %(message)s )这里有个小技巧用record.asctime不是直接用%(asctime)s是为了绕过JsonFormatter对消息的分割逻辑保证timestamp字段单独存在。接入结构化日志后日志的查询体验会有质的飞跃。比如以前要在文本日志里用正则匹配某笔订单的所有日志现在一句trace_id: xxx就能把整个调用链拉出来快得多。如果你的服务日志要进入ELK或云日志平台JSON格式是首选。5.3 最后的几点经验之谈跑了一圈下来关于Python日志我最后想再啰嗦三件事。第一日志代码也属于业务代码要进code review。很多人写日志时很随意想到哪写到哪这是不对的。日志记录哪些字段、打在哪个级别、会不会记录敏感信息这些都值得认真设计。我见过有人在日志里直接打印用户的身份证号、银行卡号的案例这就是没认真review的后果。第二敏感信息要过滤。日志里不能出现密码、token、身份证号、手机号这类个人敏感信息。实在需要记录做脱敏处理——比如只保留号码后四位中间用星号代替。这个可以封装一个mask_sensitive(data)工具函数在打日志前统一走一遍。第三日志是给“未来的你”写的。你写日志的时候是那个掌握全部上下文的程序员但你要假设三个月后、一年后有一个什么都不知道的同事甚至就是你自己来排查一个诡异的生产问题他面前只有你写的这些日志。他能不能靠这些日志还原出事故现场如果能你的日志就是合格的。如果不能现在多花五分钟把日志写清楚将来能省下五个小时。Python的logging模块看着简单真正用好它靠的是对业务的理解、对排查需求的预判以及对细节的打磨。希望这篇文章能帮你把日志从“会打”提升到“打得规范、打得有用”的水平。