先说一个我自己的真实经历。有一次线上服务半夜告警接口错误率陡增我第一时间打开日志文件想定位问题结果发现当天的日志只有三行还全是INFO级别的心跳打印。真正出错的堆栈、请求参数、用户ID一条都没有。那一刻我才彻底意识到日志不是写了就行是要在写之前就想清楚它会怎么帮你排查问题。很多人学了Python第一件事就是用print调试后来知道有logging模块就无脑加一句logging.basicConfig(levellogging.INFO)然后到处logging.info(...)。这就是典型的“会调用API但不会设计日志”。运行起来倒是能输出可真出问题的时候不是信息不够就是日志重复再就是被多进程写乱了哪一条都可能让你在凌晨三点怀疑人生。这篇文章我打算把Python Logging从原理到生产落地讲透包括四大组件的关系、日志级别怎么用、为什么basicConfig不适用于大型项目、生产级dictConfig配置、多进程日志方案、时区与性能细节。内容都是我实际项目中踩过的坑和最终沉淀下来的做法可以直接抄作业。1. 为什么你的日志等于白写三个致命误区和一条主线在开始写配置之前先花点时间聊聊最常见的三种错误。这些错误我见过太多次包括我自己早期也犯过。误区一用print代替logging。print不是不能用但它有几个硬伤没有时间戳、没有日志级别、不知道从哪个模块打出来的、无法控制输出目标。更重要的是print会直接写到标准输出在生产环境里如果没人重定向它就跟没写一样。更重要的是print无法区分“调试信息”和“错误信息”你没法说“平时不打印只有出错时打”。logging的价值就在于它可以按级别过滤同一套代码开发环境全量输出生产环境只输出WARNING以上这是print永远做不到的。误区二到处用root logger做basicConfig。你可能在main.py里写了一句logging.basicConfig(levellogging.INFO)然后在其他模块里直接logging.info(...)。这看起来能用但root logger默认没有设置格式也没有设置Handler它是用lastResort处理器输出到stderr的。多个模块都往root logger上挂Handler日志就会重复打印。更麻烦的是你想给某个模块单独调整日志级别用root logger根本无法实现。误区三日志格式里没有时间、模块、行号。很多人觉得默认格式INFO:root:message就够了。真出问题时你会发现你只知道“有一条INFO日志”但不知道是哪一行代码打的、是哪个线程打的、耗时多少毫秒。排查定位能力约等于零。明白了这些就引出了理解logging的一条主线日志的本质是让程序在运行时的行为“可观测”而logging模块的核心设计是Logger负责产生日志Handler负责把日志送出去Formatter负责定义日志长什么样Filter负责决定日志能不能通过。它们之间的连接靠的是“层级”和“传播”。这条主线搞清楚了后面所有配置、所有坑都能想明白为什么。2. Logger、Handler、Formatter、Filter四个组件的关系一张网logging模块并不复杂它只有四个核心组件。但很多人被它们之间的关系搞晕主要因为Logger有父子层级这个设计平时看不见、踩坑时最致命。2.1 Logger日志的入口和层级树Logger是你在代码里调用的对象比如logger.info()。每个Logger都有一个名字名字用点号分隔形成层级树。例如logger logging.getLogger(app)logger logging.getLogger(app.module_a)logger logging.getLogger(app.module_b)它们之间的关系是app.module_a是app的子Loggerapp是root Logger的子Logger。日志在子Logger里产生后默认会向上传播propagate也就是子Logger处理完还会交给父Logger链处理一直到root。这就是为什么很多项目里会出现“日志打了两遍”# main.py logging.basicConfig(levellogging.INFO) logger logging.getLogger(app) logger.info(hello) # 输出一次# module_a.py logger logging.getLogger(app.module_a) logger.info(hello) # 输出一次只从app.module_a这个logger发出去但如果两个模块同时配置了Handler比如app这个logger挂了一个StreamHandler而logging.basicConfig又在root上挂了一个StreamHandler那么app.module_a发出的日志会经过app的Handler输出一次再传播到root由root的Handler再输出一次。结果就是一条日志打两遍。我的建议项目中每个模块都用logging.getLogger(__name__)然后在包的入口处、通过dictConfig统一配置一次Handler。子Logger只负责产生日志不负责“去哪”。你永远不会在一处代码里处理“日志去哪”的逻辑所有Logger默认向上传播统一由顶层Logger或root承接输出。2.2 Handler和Formatter日志去哪和长什么样Handler负责把日志记录写往目标常见的有Handler作用场景StreamHandler输出到控制台、stderr/stdoutFileHandler输出到单个文件RotatingFileHandler按大小滚动文件TimedRotatingFileHandler按时间滚动文件QueueHandler把日志放进队列通常配合QueueListener异步写文件Formatter则负责把LogRecord渲染成字符串。一个生产级的Formatter至少应该包含时间、Logger名称、级别、进程/线程ID、文件名、行号和消息正文。formatter logging.Formatter( fmt%(asctime)s | %(levelname)-8s | %(name)s | %(processName)s | %(filename)s:%(lineno)d | %(message)s, datefmt%Y-%m-%d %H:%M:%S )其中%(filename)s:%(lineno)d尤其重要。没有行号你在日志里只能看到模块名还得再去代码里搜。2.3 Filter精准控制哪些日志该记录Filter经常被人忽略但在两个场景下绝对离不开按请求ID过滤上下文。例如一个请求处理任务里你希望日志自动带上request_id可以自定义一个Filter往LogRecord里注入字段。按业务条件过滤日志。比如你只关心特定用户ID的调试日志或者只关心某个接口的性能日志级别不等于选择条件时Filter最合适。Filter的使用也很简单class RequestIdFilter(logging.Filter): def filter(self, record: logging.LogRecord) - bool: record.request_id get_current_request_id() # 从上下文获取 return True然后在Formatter里加上%(request_id)s字段。这样每一条日志都会带上请求ID排查问题时能直接串起整个调用链。3. 生产级日志配置不是basicConfig而是dictConfigbasicConfig适合脚本但不适合项目。原因很简单它只能在root logger上做一些基础配置没法细粒度地控制多个Logger、多个Handler、多个Formatter。真正要做生产级配置推荐用logging.config.dictConfig用字典描述整个日志体系逻辑清晰、可维护、可热加载。3.1 为什么dictConfig是正道dictConfig最核心的价值是“声明式”。你用一个嵌套字典一次性定义好Logger的级别和挂哪些HandlerHandler的类型、参数、FormatterFormatter的格式代码和配置分离以后要改日志格式、加文件滚动、调整级别都不用动业务代码。而且dictConfig天然适合放在配置文件里用YAML或JSON加载运营同学也能看懂。3.2 一套可直接抄的生产级配置模板下面这套配置我在多个项目里用过覆盖了开发和生产两个场景你可以直接复制过去改改路径import logging.config import sys LOGGING_CONFIG { version: 1, disable_existing_loggers: False, formatters: { default: { format: %(asctime)s | %(levelname)-8s | %(name)s | %(processName)s | %(threadName)s | %(filename)s:%(lineno)d | %(message)s, datefmt: %Y-%m-%d %H:%M:%S, }, access: { format: %(asctime)s | %(levelname)-8s | %(name)s | %(message)s, datefmt: %Y-%m-%d %H:%M:%S, }, }, filters: { request_id: { (): myproject.logging_filters.RequestIdFilter, }, }, handlers: { console: { class: logging.StreamHandler, level: DEBUG, formatter: default, stream: sys.stdout, }, file_info: { class: logging.handlers.TimedRotatingFileHandler, level: INFO, formatter: default, filename: /var/log/myapp/app.log, when: midnight, interval: 1, backupCount: 30, encoding: utf-8, }, file_error: { class: logging.handlers.TimedRotatingFileHandler, level: ERROR, formatter: default, filename: /var/log/myapp/error.log, when: midnight, interval: 1, backupCount: 90, encoding: utf-8, }, }, loggers: { myapp: { level: INFO, handlers: [console, file_info, file_error], propagate: False, }, myapp.access: { level: INFO, handlers: [console, file_info], propagate: False, }, }, root: { level: WARNING, handlers: [console, file_error], }, } logging.config.dictConfig(LOGGING_CONFIG)3.3 关键配置项逐条解读disable_existing_loggers为什么必须置为FalsedictConfig在加载时会默认禁用所有已存在的非root logger如果你的项目有第三方库的logger或者启动早期就创建了logger很容易出现“配置加载后日志静默丢失”的现象。设置成False才能避免这种意外。propagate要不要设置为False我推荐在项目的顶层logger比如myapp上设置为False阻止日志进一步向root传播避免和root上的Handler重复输出。但子logger比如myapp.access也要设置成False因为我们已经显式给它挂了Handler不需要它再向上传播到myapp。这样做的好处是每个logger的日志输出目标完全可控。file_info和file_error分开的意义日常排查问题只看app.log错误和告警单独落到error.log监控系统只盯着error.log告警逻辑简单清晰也不用把大量INFO日志刷进告警通道。为什么用TimedRotatingFileHandler而不是RotatingFileHandler按大小滚动适合日志量比较稳定且磁盘有限的服务按时间滚动更适合排查问题的习惯——我知道某天出问题的服务直接去看那天的日志文件比如app.log.2024-05-20按大小滚动做不到这种时间维度的直觉检索。encodingutf-8一定要设。在Windows环境默认编码可能是gbk日志里一旦出现中文轻则乱码重则直接抛UnicodeEncodeError。加了utf-8能规避绝大多数中文编码问题。4. 多模块与多进程环境下的日志坑踩过之后才知道单机脚本里logging很简单但一上多模块、多进程问题就接踵而来。4.1 多模块下的Logger命名规范与继承很多人喜欢自定义名字比如logging.getLogger(myapp)、logging.getLogger(server)看起来没什么问题但一旦Logger数量多起来你无法从日志里快速定位它属于哪个模块。我一直用logging.getLogger(__name__)让Logger名字和Python模块路径保持一致。比如myproject.service.order一看就知道日志来自service/order.py模块。配合dictConfig里的层级关系天然支持按模块精细调级别。4.2 TimedRotatingFileHandler与多进程的天然冲突这是个经典坑。Linux下用TimedRotatingFileHandler多个进程同时向同一个日志文件写入。平时一切正常但等到午夜滚动时问题出现了多个进程同时尝试去重命名旧文件、创建新文件出现PermissionError或日志写入丢失。原因在于TimedRotatingFileHandler不是进程安全的它的滚动操作是“检查时间、rename文件、创建新文件”这三个步骤不是原子的。多个进程同时执行时竞态条件就会触发。低成本的解决方案是让日志写入只发生在单进程或者使用QueueHandler。4.3 QueueHandler QueueListener异步日志和进程安全一次搞定在生产环境我强烈推荐使用QueueHandlerQueueListener。原理很简单业务进程把日志记录放进一个内存队列Queue这一步非常快不会因为磁盘I/O阻塞业务逻辑。专门的日志监听线程QueueListener从队列里取日志再交给真正的Handler落盘。这个方案的收益是双重的异步I/O提升性能而且log队列由单线程消费文件滚动、写入都只在监听线程里发生天然规避多进程写同一个文件的竞态问题。示例代码import logging import logging.handlers import queue log_queue queue.Queue(-1) queue_handler logging.handlers.QueueHandler(log_queue) queue_handler.setLevel(logging.INFO) console_handler logging.StreamHandler() file_handler logging.handlers.TimedRotatingFileHandler( /var/log/myapp/app.log, whenmidnight, backupCount30, encodingutf-8, ) logger logging.getLogger(myapp) logger.addHandler(queue_handler) logger.setLevel(logging.INFO) listener logging.handlers.QueueListener( log_queue, console_handler, file_handler, respect_handler_levelTrue ) listener.start()respect_handler_levelTrue这个参数很关键它让QueueListener把日志层级判断交给每个Handler自身的level而不是默认的WARNING。不设这个参数你写进队列的INFO日志可能会在Handler层被丢掉排查问题时发现日志“少了一段”。在多进程部署时每个进程都有自己的queue和listener各写各的文件只要文件路径不冲突即可。如果实在需要多个进程写同一个文件可以考虑ConcurrentRotatingFileHandler这类第三方方案但依赖较多不如干脆拆分成“每个进程一份日志文件”再配合日志采集系统统一聚合。5. 日志的时区、编码与性能问题细节决定排查效率日志模块的基本配置搞定后有些细节会在关键时刻狠狠咬你一口。这些细节大多数人不写不知道写出来才觉得通透了。5.1 日志时间戳我坚持用UTC生产环境怎么选logging.Formatter的%(asctime)s默认是本地时间受服务器时区影响。如果你的服务部署在多个地域的机器上日志时间戳会五花八门排查跨地域问题时对不上时间线。我的做法是日志统一记录UTC时间排查问题时在日志分析系统里再做时区转换。这样所有机器的日志在时间维度上是严格一致的。实现方式可以自定义一个Formatterimport logging import time class UTCFormatter(logging.Formatter): converter time.gmtime # 覆盖Formatter默认的本地时间转换然后把这个Formatter挂到FileHandler上。控制台可以继续用本地时间便于开发调试落盘日志用UTC便于运维分析。5.2 编码问题不只是中文乱码那么简单前面提到encodingutf-8这里再补一刀。FileHandler默认编码是locale.getpreferredencoding()在Windows中文系统下通常是gbk在Linux下通常是utf-8。这意味着同一套代码在不同平台部署日志编码居然不一样。为了跨平台稳定FileHandler必须显式指定encodingutf-8。控制台输出也可能有编码问题特别是Windows下用StreamHandler(sys.stdout)时。如果Python解释器用的是utf-8模式还好否则中文会乱码。可以在程序入口做一次sys.stdout.reconfigure(encodingutf-8)或者修改环境变量PYTHONIOENCODINGutf-8。5.3 每条日志尽量带上业务上下文但别把消息拼成一坨很多人的日志是logger.info(fuser {user_id} paid {amount})用f-string拼字符串。这个习惯有两个问题字符串格式化发生在调用前即使日志级别不满足也会执行浪费性能。消息字段都是“死文本”无法被日志采集系统结构化解析。更推荐的做法是日志消息里只放静态模板动态字段放到extra里。例如logger.info(user paid, extra{user_id: user_id, amount: amount})但extra直接加自定义字段前提是Formatter里要有对应的字段占位符否则会报KeyError。这时可以用上前面提到的Filter统一注入上下文。生产环境的做法通常是让日志以JSON格式输出每个字段天然结构化。一个简单的JSON Formatter可以这样写import json import logging class JsonFormatter(logging.Formatter): def format(self, record: logging.LogRecord) - str: data { time: self.formatTime(record), level: record.levelname, logger: record.name, message: record.getMessage(), module: record.module, line: record.lineno, process: record.processName, thread: record.threadName, } if hasattr(record, request_id): data[request_id] record.request_id if record.exc_info: data[exc_info] self.formatException(record.exc_info) return json.dumps(data, ensure_asciiFalse)JSON格式日志在ELK、Loki这类日志系统里清洗方便你不需要写一堆正则去抠字段。5.4 性能优化lazy logging和异常堆栈的正确姿势logging的性能问题主要体现在两个地方第一格式化字符串的开销。应该用lazy logging方式# 推荐 logger.debug(user %s paid %s, user_id, amount) # 不推荐 logger.debug(fuser {user_id} paid {amount})区别在于第一行只有当日志级别满足时才会去格式化拼接第二行无论级别满不满足都会先算一次f-string在高频调用下完全是浪费。第二异常信息的堆栈捕获。很多人喜欢logger.exception(str(e))这没问题但如果你只是logger.error(str(e))就不会带堆栈。排查问题最痛苦的就是只知道“出错”但不知道“哪里出错”。正确的做法是try: do_something() except Exception: logger.exception(do_something failed)logger.exception本质是logger.error(..., exc_infoTrue)它会自动抓取当前异常堆栈输出完整的Traceback。这些堆栈信息在排障时是金子不要省。还有一个性能要点QueueHandler本身就能让业务线程不被磁盘I/O阻塞。如果日志量巨大可以调大Queue的容量并监控队列积压情况。但要注意队列写入也有锁如果业务线程对日志性能极其敏感可以设置一个合理的level让低级别日志在队列入口就被过滤掉。6. 我在实际项目中沉淀下来的日志清单与最终建议最后分享一份我在项目交付前必过的日志检查清单都是被生产事故教育出来的经验。有没有多余的print有就全部替换为logger。每个Logger是否用__name__命名便于自动继承模块结构。日志格式里是否包含时间、级别、模块、行号缺失任意一个排障效率都大打折扣。是否只有一处地方配置Handler不要在多个模块里各自addHandler统一由dictConfig管理。是否区分了文件输出和控制台输出生产环境控制台可以只输出WARNING以上文件尽量保留完整INFO链路。是否设置了编码为utf-8跨平台稳定性靠它。日志时间戳是否统一多机器部署优先用UTC。异常分支是否用了logger.exception或exc_infoTrue保证堆栈不丢失。多进程场景是否处理了日志滚动冲突建议直接上QueueHandlerQueueListener。日志里是否写了敏感信息比如密码、token、身份证号一旦落盘就是事故。可以写一个Filter对敏感字段做脱敏。有没有采样策略在高频打点场景比如心跳日志可以只记录一部分比如用哈希取模让logger只记录user_id % 10 0的用户流量模型立刻可控。第八条再补充一个关键心态日志是“写给未来排障的自己看的信”。你永远不知道下一次线上故障会在什么时候发生也不知道你会以什么样的时间紧迫感去读这些日志。宁可多打一行关键参数也不要省略到只剩一句“failed”。但也不要无脑打大量废话日志否则日志系统先于业务系统崩溃。日志是工程不是作文。