1. 日志系统到底在解决什么问题刚入行那会儿我对日志的理解就是“print大法”——哪里出问题就在哪里加一行打印调试完再删掉。直到有一次线上服务半夜挂了我翻遍代码发现所有调试打印都被清理得干干净净只能靠猜。那次事故之后我才真正开始认真研究标准库里的logging模块也才明白为什么几乎所有成熟项目都会把它作为基础设施来对待。logging模块本质上是一套分级、可配置、多目标输出的日志记录框架。它要解决的核心问题有三个第一让开发者能够按照严重程度对信息分类而不是把所有输出混在一起第二让日志的去向可以灵活配置控制台、文件、网络端点都能作为输出目标第三让日志的格式、级别、过滤规则可以在不修改业务代码的前提下调整。这三点听起来简单但真正在项目里用好需要理解它内部的组件协作方式。这篇文章适合两类人看一类是刚接触Python不久还在用print调试的新手想搞清楚logging到底比print强在哪里另一类是用过logging但只停留在basicConfig层面遇到多模块、多handler、日志重复输出等问题就卡住的中级开发者。我会从模块的组成结构讲起把每个组件的职责和协作关系拆开然后给出可以直接抄作业的配置方案最后分享一些我在实际项目里踩过的坑和总结出来的排查技巧。提示本文所有代码基于Python 3.8及以上版本验证低版本可能存在个别API差异核心概念通用。2. logging模块的四大核心组件拆解很多人用logging就是一句logging.info(something)能用但一旦需求变复杂就懵了。根本原因是没有理解它内部的组件分工。logging模块的设计其实很像一条流水线日志事件从产生到最终落地中间经过了几个各司其职的环节。把这几个环节搞清楚后面所有配置问题都能自己推导出答案。2.1 Logger日志的入口和级别守门人Logger是开发者直接打交道的对象。你调用logging.getLogger(__name__)拿到的就是一个Logger实例。它的核心职责有两个一是提供debug、info、warning、error、critical这几个方法供你记录日志二是在日志真正被处理之前先做一次级别过滤。这里有个关键概念叫有效级别effective level。当你创建一个Logger但没有显式设置级别时它会沿着层级向上查找父Logger的级别直到找到第一个设置了级别的祖先。如果一路找到root logger都没有设置那就用默认的WARNING级别。这个机制导致了一个非常常见的困惑明明在代码里调用了logging.info(...)但什么都没输出——因为root logger默认级别是WARNINGinfo级别被过滤掉了。Logger还有一个容易被忽略的特性是层级结构。用logging.getLogger(app.db)创建的Logger它的父级是logging.getLogger(app)再往上是root。这个层级关系在日志传播propagate时会起作用后面讲Handler的时候会详细说。import logging # 创建两个有父子关系的logger parent logging.getLogger(app) child logging.getLogger(app.db) parent.setLevel(logging.INFO) # child没有设置级别有效级别继承自parent也是INFO print(child.getEffectiveLevel()) # 输出 20 (INFO)2.2 Handler决定日志往哪里去Handler是logging模块里最灵活也最容易出问题的组件。一个Logger可以挂载多个Handler每条通过级别过滤的日志会被分发到所有Handler上。每个Handler可以有自己的级别、自己的格式化器、自己的输出目标。常用的Handler类型包括Handler类型输出目标典型场景StreamHandler控制台stdout/stderr开发调试FileHandler单个文件简单文件记录RotatingFileHandler按大小切割的文件生产环境常规日志TimedRotatingFileHandler按时间切割的文件按天/小时归档NullHandler什么都不做库开发时避免输出这里要重点说一下RotatingFileHandler和TimedRotatingFileHandler的区别因为选错了会导致日志管理出问题。前者按文件大小切割适合日志量不稳定但需要控制单文件体积的场景后者按时间间隔切割适合需要按时间段检索日志的场景。实际项目里我通常两个都用用TimedRotatingFileHandler按天归档同时设置一个较大的maxBytes作为兜底防止某一天日志量暴增把磁盘写满。from logging.handlers import RotatingFileHandler, TimedRotatingFileHandler # 按大小切割单文件最大10MB保留5个备份 size_handler RotatingFileHandler( app.log, maxBytes10*1024*1024, backupCount5, encodingutf-8 ) # 按时间切割每天凌晨切割保留30天 time_handler TimedRotatingFileHandler( app.log, whenmidnight, interval1, backupCount30, encodingutf-8 )注意RotatingFileHandler在多进程环境下是不安全的。如果多个进程同时写同一个文件并触发切割会出现日志丢失或文件损坏。多进程场景需要用ConcurrentRotatingFileHandler或者交给外部工具做日志收集。2.3 Formatter控制日志长什么样Formatter决定了日志最终输出的文本格式。它使用百分号风格的占位符常用的字段包括%(asctime)s— 时间戳%(levelname)s— 级别名称%(name)s— Logger名称%(message)s— 日志内容%(filename)s— 文件名%(lineno)d— 行号%(funcName)s— 函数名%(threadName)s— 线程名%(process)d— 进程ID一个设计良好的格式应该包含足够的问题定位信息但又不能太冗长。我在生产环境常用的格式是这样的formatter logging.Formatter( fmt%(asctime)s | %(levelname)-8s | %(name)s | %(process)d:%(threadName)s | %(filename)s:%(lineno)d | %(message)s, datefmt%Y-%m-%d %H:%M:%S )这个格式看起来字段很多但每个都有明确用途。levelname用-8s左对齐补齐8个字符是为了让不同级别的日志在视觉上对齐方便用grep过滤后阅读。process和threadName在排查并发问题时是救命稻草。filename和lineno让你不用猜日志是从哪行代码打出来的。2.4 Filter精细化的日志过滤器Filter是四个组件里最少被用到但关键时刻很有用的一个。它提供了比级别更细粒度的过滤能力。Filter对象有一个filter(record)方法返回True表示保留这条日志返回False表示丢弃。举几个实际场景你可能想给某个特定模块的日志单独加一个前缀或者想过滤掉包含敏感信息的日志又或者想根据环境变量动态决定某些日志是否输出。这些用Filter都能优雅地解决。class SensitiveFilter(logging.Filter): def filter(self, record): # 过滤掉包含特定关键词的日志 return password not in record.getMessage().lower() # 给handler添加过滤器 handler.addFilter(SensitiveFilter())Filter可以挂在Logger上也可以挂在Handler上。挂在Logger上会影响该Logger的所有Handler挂在Handler上只影响那一个Handler。这个区别在做精细化控制时很重要。3. 从零搭建一套可落地的日志配置理解了组件之后接下来要解决的是“怎么把它们组装起来”。很多教程只讲basicConfig但那个函数在稍微复杂一点的场景下就不够用了。我下面给出一套经过多个项目验证的配置方案从简单到复杂逐步递进。3.1 为什么basicConfig不够用logging.basicConfig()确实方便一行代码就能让日志输出到控制台。但它有几个硬伤第一它只能配置root logger无法为不同的模块设置不同的级别和Handler第二它是一次性配置调用第二次不会生效除非强制覆盖第三它不支持复杂的Handler组合。我见过不少项目在入口文件里写一句logging.basicConfig(levellogging.INFO)然后所有模块都用logging.info()打日志。这种用法在小型脚本里没问题但一旦项目变大就会出现“想单独调高某个模块的日志级别却做不到”的尴尬。3.2 基于字典的配置方案Python 3.2开始logging模块支持用字典来配置这是目前最推荐的配置方式。它的好处是配置和代码分离可以用JSON或YAML文件管理不同环境加载不同配置。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 }, simple: { format: %(levelname)s | %(message)s } }, handlers: { console: { class: logging.StreamHandler, level: DEBUG, formatter: standard, stream: ext://sys.stdout }, file: { class: logging.handlers.RotatingFileHandler, level: INFO, formatter: standard, filename: logs/app.log, maxBytes: 10485760, backupCount: 5, encoding: utf-8 } }, loggers: { app: { level: DEBUG, handlers: [console, file], propagate: False }, app.db: { level: WARNING, handlers: [file], propagate: False } }, root: { level: WARNING, handlers: [console] } } logging.config.dictConfig(LOGGING_CONFIG)这份配置里几个关键点值得展开说。disable_existing_loggers设为False是为了避免在配置加载之前已经创建的Logger被禁用。propagate设为False是为了防止日志向父Logger传播导致重复输出——这是新手最容易踩的坑之一。app.db这个Logger单独设置了WARNING级别意味着数据库模块的DEBUG和INFO日志不会输出但WARNING及以上会写入文件。3.3 多模块项目中的Logger命名规范在大型项目里Logger的命名直接影响到日志的可维护性。我的经验是始终使用__name__作为Logger名称。这样做的好处是Logger的层级结构自动对应包的层级结构你可以通过配置父包的级别来批量控制子模块的日志行为。# 在 app/services/order.py 中 logger logging.getLogger(__name__) # 实际名称是 app.services.order # 在 app/services/payment.py 中 logger logging.getLogger(__name__) # 实际名称是 app.services.payment这样配置的时候只需要给app.services设置一个级别两个子模块都会继承。如果某个子模块需要单独调整再为它创建独立的配置项即可。实操心得不要在工具函数或库代码里调用logging.basicConfig()。库应该只创建Logger并添加NullHandler把配置权交给调用方。否则会出现“引入一个库之后整个项目的日志配置被覆盖”的问题。3.4 日志切割策略的参数计算日志切割的参数不是拍脑袋定的需要根据实际日志量和磁盘空间来算。假设一个服务每天产生约500MB日志你希望保留30天的日志那么总磁盘占用大约是15GB。如果单文件限制在100MB每天会产生5个文件30天就是150个文件。用TimedRotatingFileHandler的时候backupCount的含义是保留多少个备份文件。如果按天切割backupCount30就是保留30天。但要注意如果某天日志量特别大导致文件被多次切割backupCount是按切割次数算的不是按天数算的。所以更稳妥的做法是同时设置maxBytes和backupCount让两个条件共同作用。handler TimedRotatingFileHandler( filenamelogs/app.log, whenmidnight, interval1, backupCount30, encodingutf-8, delayTrue # 延迟到第一次写入时才打开文件 ) handler.suffix %Y%m%ddelayTrue这个参数值得注意。默认情况下Handler创建时就会打开文件即使没有任何日志写入。在开发环境这会导致生成一堆空日志文件。设为True之后只有第一条日志到来时才真正打开文件。4. 实战中高频出现的六个坑与排查方法配置写对了只是第一步实际运行中还会遇到各种意料之外的情况。下面这几个问题是我和周围同事反复遇到过的每个都给出了排查思路和解决方案。4.1 日志重复输出两遍甚至多遍这是最经典的问题。现象是控制台上每条日志出现两次。根本原因通常是Logger的propagate属性为True默认值导致日志既被自己的Handler处理又被父Logger的Handler处理了一遍。排查方法检查出问题的Logger的propagate属性以及它的父Logger上挂了哪些Handler。解决方案有两种要么把子Logger的propagate设为False要么只在root logger上挂Handler子Logger只负责产生日志不挂Handler。# 方案一关闭传播 logger logging.getLogger(app.module) logger.propagate False # 方案二只在root上配置handler子logger不添加handler # 这样日志会自然向上传播到root被处理一次我倾向于方案二因为它更符合logging的设计意图。但方案二的问题是所有日志格式统一无法为不同模块设置不同的输出格式。所以实际项目里两种方案都会用到取决于需求。4.2 日志文件没有按预期切割TimedRotatingFileHandler不切割的常见原因有三个第一when参数设置错误比如写成了D而不是midnight第二进程没有持续运行到切割时间点第三文件被其他进程占用导致重命名失败。排查的时候可以先手动调用handler.doRollover()看是否报错如果报错通常是文件权限或占用问题。另外注意在Windows上文件被占用时无法重命名这是操作系统层面的限制需要考虑用其他方案。4.3 多进程环境下日志丢失或错乱前面提到过标准的FileHandler和RotatingFileHandler在多进程下不安全。多个进程同时写同一个文件轻则日志顺序错乱重则内容互相覆盖。如果切割时机恰好撞上多个进程同时写入还可能直接丢日志。解决方案有几种最简单的是每个进程写自己的文件用进程ID区分文件名进阶方案是用ConcurrentRotatingFileHandler需要额外安装最彻底的方案是引入日志收集组件应用只负责输出到标准输出由外部系统统一收集和存储。import os from logging.handlers import RotatingFileHandler # 每个进程写独立文件 pid os.getpid() handler RotatingFileHandler( flogs/app_{pid}.log, maxBytes10*1024*1024, backupCount3, encodingutf-8 )4.4 日志级别设置不生效明明设置了DEBUG级别但DEBUG日志就是不输出。这种问题的排查顺序是先确认Logger的有效级别再确认Handler的级别最后确认父Logger的级别。三个级别中任何一个高于DEBUGDEBUG日志都会被过滤掉。logger logging.getLogger(app) logger.setLevel(logging.DEBUG) # 检查有效级别 print(logger.getEffectiveLevel()) # 检查每个handler的级别 for h in logger.handlers: print(h.level, h)记住一个原则日志要输出必须同时通过Logger级别和Handler级别的检查。两者是“与”的关系不是“或”的关系。4.5 日志中中文乱码FileHandler默认使用系统编码在部分环境下会导致中文乱码。解决方案是显式指定encodingutf-8。这个问题在跨平台部署时特别常见开发机上是UTF-8服务器上是GBK日志文件打开就是乱码。4.6 异常堆栈信息丢失用logger.error(出错了)只会记录一行文本不会带上异常堆栈。正确做法是用logger.exception()或者在日志调用时传入exc_infoTrue。logger.exception()会自动把当前异常信息附加到日志中非常适合在except块里使用。try: result 1 / 0 except ZeroDivisionError: logger.exception(计算失败) # 自动包含堆栈 # 或者 logger.error(计算失败, exc_infoTrue)常见问题速查表现象可能原因排查动作日志重复输出propagate为True且父子都有Handler检查propagate和Handler分布DEBUG日志不输出Logger或Handler级别过高打印getEffectiveLevel和handler.level文件不切割when参数错误或进程未持续运行手动调用doRollover测试多进程日志错乱多进程写同一文件改为每进程独立文件中文乱码未指定encoding添加encodingutf-8无异常堆栈未传exc_info改用logger.exception5. 进阶用法与性能考量把基础配置跑通之后还有一些进阶场景值得了解。这些内容在普通教程里很少提到但在实际项目中会直接影响日志系统的可用性和性能。5.1 用QueueHandler做异步日志日志写入是I/O操作在高并发场景下可能成为性能瓶颈。特别是当Handler是网络端点或者慢速磁盘时同步写日志会阻塞业务线程。解决方案是引入QueueHandler和QueueListener把日志写入放到独立线程里做。import logging from logging.handlers import QueueHandler, QueueListener import queue log_queue queue.Queue(-1) queue_handler QueueHandler(log_queue) # 真正的handler在独立线程里消费队列 file_handler logging.FileHandler(app.log, encodingutf-8) listener QueueListener(log_queue, file_handler) listener.start() logger logging.getLogger(app) logger.addHandler(queue_handler)这个方案的核心思路是业务线程只负责把日志记录丢进队列内存操作极快后台线程负责实际的I/O写入。实测下来在高频日志场景下能显著降低业务线程的延迟抖动。需要注意的是程序退出时要调用listener.stop()确保队列中的日志被完整写入。5.2 结构化日志的实践传统文本日志适合人看但不适合机器解析。当日志量大了之后通常需要接入日志分析系统这时候结构化日志JSON格式就很有优势了。Python标准库没有内置JSON Formatter但自己写一个并不复杂。import json import logging class JsonFormatter(logging.Formatter): def format(self, record): log_data { time: self.formatTime(record), level: record.levelname, logger: record.name, message: record.getMessage(), file: record.filename, line: record.lineno, } if record.exc_info: log_data[exception] self.formatException(record.exc_info) return json.dumps(log_data, ensure_asciiFalse)用这个Formatter输出的日志每行都是一个合法的JSON对象可以直接被日志分析系统采集和索引。ensure_asciiFalse保证中文不被转义成Unicode码点方便直接阅读。5.3 日志级别选择的经验法则DEBUG、INFO、WARNING、ERROR、CRITICAL这五个级别什么时候用哪个团队里经常有分歧。我总结了一套比较实用的判断标准DEBUG只在开发和排查问题时需要的信息比如变量值、函数入参、分支走向。生产环境通常关闭。INFO记录系统的正常行为轨迹比如服务启动、配置加载、定时任务执行完成。这些日志在生产环境应该保留用于了解系统运行状态。WARNING出现了异常但系统还能继续运行的情况比如重试成功、降级处理生效、配置项缺失使用了默认值。ERROR出现了导致某个功能失败但整体服务还活着的情况比如接口调用失败、数据库查询异常。CRITICAL系统级故障服务已经无法正常提供功能比如数据库连接池耗尽、关键依赖不可用。关键原则是ERROR和CRITICAL应该触发告警WARNING应该被定期审查INFO用于日常巡检DEBUG只在需要时开启。如果ERROR日志每天几百条但没人看说明级别划分有问题需要重新审视。5.4 日志脱敏处理生产环境的日志里可能包含手机号、身份证号、邮箱等敏感信息。直接在日志里明文记录是有合规风险的。处理方式有两种一种是在记录日志之前手动脱敏另一种是用Filter自动处理。import re class MaskingFilter(logging.Filter): PHONE_PATTERN re.compile(r1[3-9]\d{9}) EMAIL_PATTERN re.compile(r[\w.-][\w.-]\.\w) def filter(self, record): msg record.getMessage() msg self.PHONE_PATTERN.sub(1**********, msg) msg self.EMAIL_PATTERN.sub(******.***, msg) record.msg msg record.args () return True把这个Filter挂在Handler上所有经过该Handler的日志都会自动脱敏。注意要同时清空record.args否则格式化时会把原始参数重新拼进去导致脱敏失效。6. 一套完整的生产级配置模板最后给出一份我在多个项目中实际使用过的配置模板涵盖了控制台输出、文件切割、错误日志单独归档、敏感信息脱敏这几个核心需求。可以直接复制到项目里根据实际情况调整。import logging import logging.config import os def setup_logging(log_dirlogs, levelINFO): os.makedirs(log_dir, exist_okTrue) config { version: 1, disable_existing_loggers: False, filters: { masking: { (): your_project.utils.logging.MaskingFilter } }, formatters: { verbose: { format: %(asctime)s | %(levelname)-8s | %(name)s | %(process)d:%(threadName)s | %(filename)s:%(lineno)d | %(message)s, datefmt: %Y-%m-%d %H:%M:%S }, simple: { format: %(levelname)s | %(message)s } }, handlers: { console: { class: logging.StreamHandler, level: DEBUG, formatter: simple, stream: ext://sys.stdout }, app_file: { class: logging.handlers.TimedRotatingFileHandler, level: level, formatter: verbose, filename: os.path.join(log_dir, app.log), when: midnight, interval: 1, backupCount: 30, encoding: utf-8, delay: True, filters: [masking] }, error_file: { class: logging.handlers.TimedRotatingFileHandler, level: ERROR, formatter: verbose, filename: os.path.join(log_dir, error.log), when: midnight, interval: 1, backupCount: 90, encoding: utf-8, delay: True, filters: [masking] } }, loggers: { app: { level: DEBUG, handlers: [console, app_file, error_file], propagate: False } }, root: { level: WARNING, handlers: [console] } } logging.config.dictConfig(config)这份配置的几个设计决策说明一下。错误日志单独一个文件且保留90天是因为排查线上问题时往往需要回溯更久之前的错误记录。普通日志保留30天平衡了存储成本和排查需求。控制台用simple格式是为了开发时看得清爽文件用verbose格式是为了事后排查有足够信息。delayTrue避免生成空文件。脱敏Filter挂在文件Handler上而不是控制台上是因为控制台输出只在开发环境用开发数据通常不敏感。用的时候在项目入口调用一次setup_logging()然后在各个模块里用logging.getLogger(__name__)获取Logger即可。整个项目所有模块的日志行为都统一管理需要调整时只改配置不动业务代码。这套方案我在几个日活百万级的服务上跑过日志量每天几十GB切割和归档都稳定。唯一需要注意的是磁盘空间监控虽然backupCount限制了文件数量但如果单日日志量突然暴增单个文件可能很大。建议配合磁盘告警一起使用或者在Handler层面再加一个maxBytes兜底。