干过几年Python开发的人迟早会遇到这样一件事代码里到处是print线上环境一出问题第一反应是打开终端盯着输出看。等真正把Python日志记录Logging捋清楚之后我才发现print和logging之间差的不是几行代码而是一整套事件收集思维。这篇日志最佳实践不是API照抄指南而是从核心概念讲到生产级配置外加我踩过的一堆坑把logging的使用边界和正确姿势一次说清。logging是Python标准库自带的模块不用装任何第三方包就能用。它解决的核心问题是让运行中的程序把关键事件按照统一的结构记录下来并且这些记录可以被检索、被追溯、被留作证据。它适合所有用Python写程序的场景——从跑一次就结束的脚本到需要长期运行的Web服务、数据处理任务、爬虫都会从中受益。如果你写的是会被别人接手、需要长期维护的代码那日志设计得怎么样基本决定了将来排查故障要花半天还是一分钟。1. 为什么你的项目需要一个正经的日志系统1.1 先聊一个现实问题print大法为什么撑不到生产环境很多新手写代码调试全靠print。print确实简单脚本阶段用起来相当顺手但到了生产环境至少五个问题会冒出来。第一print没有级别。输出的内容混在一起DEBUG信息、业务信息、错误信息全是一行行裸文本根本没法快速筛选出错误。第二print没有时间戳。出了事你看到一行网络请求失败的输出但根本不知道发生在哪天几点几分排查全靠猜。第三print没有来源信息。程序里几百个print输出后只能靠肉眼认是哪一行的内容大型项目里这几乎是灾难。第四print无法分流。日志通常要被同时写到文件、控制台、日志收集平台print只能往一个stdout里打想拆都拆不开。第五print是不可控的。它不认配置文件没有“调试模式下才输出、正式环境只记重要事件”这种开关写进代码里就很难在不改代码的前提下调整。这些问题单独看都不致命堆叠在一起就是“线上日志失灵”的典型症状。我见过不少人把这结论归为“Python不适合做大型项目”其实不是工具的错是用工具的方式有边界。print的职责是“给正在写代码的人看”logging的职责是“给维护这个系统的人看”两者定位完全不同。1.2 logging不是“更好用的print”它是统一的事件收集通道logging模块的底层设计是把日志当成事件流来处理。整个系统分成四类角色Logger负责“产生事件”Handler负责“把事件送到哪里去”Formatter负责“事件长什么样”Filter负责“哪些事件值得送”。这种分工看起来多绕了一层但实际使用中会发现非常灵活。同一个Logger可以同时挂一个写控制台的Handler、一个写文件的Handler、一个发到远端日志平台的Handler各自拥有独立的级别和格式。线上环境想调高Console的级别、保留文件里的完整DEBUG记录只需要改一行配置代码不用动。另外要注意logging在Python 3里已经是线程安全的多线程环境下日志不会串行写坏。这是很多自造日志方案的硬伤也是我始终推荐直接用标准库的原因——别急着造轮子标准库能覆盖绝大多数需求。1.3 这篇文章能让你拿走什么跟随这篇内容你会把logging模块的核心概念彻底过一遍搞清楚Logger、Handler、Formatter、Filter之间的协作关系然后拿到一套可以直接搬进生产项目的dictConfig配置模板包含按大小滚动、按天滚动、JSON结构化输出最后是一些我亲测踩过的坑——日志重复打印、Windows句柄被占、编码乱码、异步写日志的性能陷阱。这些都是网上文档很少告诉你、但实际项目里一定会碰到的东西。2. 吃透logging模块的五个核心概念2.1 Logger有名字的事件源而不是一个全局单例先纠正一个常见误解logging.getLogger()不是取一个“全局的东西”而是通过名字获取一个Logger对象。名字是有层级关系的用点号分隔。比如你调用了logging.getLogger(app.api)它会自动把app当作自己的父Loggerapi是子Logger再往上是root。层级关系带来一个很重要的行为——传播propagate。子Logger记录的一条日志默认会向上传给父Logger由父Logger的Handler再输出一次。这意味着如果你在模块里只创建Logger、不添加Handler日志也照样能输出因为root上大概率挂了Handler。这很方便但也是“日志重复打印”的头号原因后面踩坑部分会细说。实践中怎么用呢推荐每个模块都用自己的模块名loggerlogger logging.getLogger(__name__)__name__就是当前模块的完整路径比如app.services.task这样日志里自带模块名排查时一眼就能定位到代码位置。注意Logger的级别判断是在事件产生时独立生效的它决定“这条日志要不要被收集起来”收集之后再交给HandlerHandler那边还会再做一次级别过滤。2.2 Handler决定日志流向哪里的出口Handler负责真正把日志写出去。标准库提供了很多种我实际用得最多的是这几个StreamHandler写往控制台或任何类似流对象默认是stderr。开发调试、容器环境里很常用。FileHandler写往文件最简单的持久化方案。RotatingFileHandler按文件大小滚动文件写满maxBytes之后自动重命名新建一个文件继续写。TimedRotatingFileHandler按时间滚动可以按分钟、小时、天、周切换新文件。生产环境最常用的是每天滚动一次。一个Logger可以挂多个Handler这也是logging最灵活的地方。开发环境我要的是“控制台即时看到全量日志”生产环境我要的是“文件记录全量日志 控制台只出错误摘要”这就是同一个Logger挂两个不同Handler的典型场景。2.3 Formatter决定日志最后长什么样的模板Formatter就是把LogRecord对象一条日志事件的完整载体包含Message、时间、级别、Logger名、行号、进程号、线程号等信息渲染成最终字符串的组件。我的标准格式串长这样%(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s渲染出来的样子2025-03-12 14:30:21,567 | INFO | app.services.task | task.py:42 | 用户 1001 开始下载任务这个模板里时间、级别、Logger名、文件行号、消息都齐了可以作为工作流的基础模板。-8s表示左对齐并占8个字符宽度出发点是为了让不同级别的日志在视觉上对齐扫一眼就能看出哪些行是ERROR。还可以在Formatter里带上下文信息比如进程号、线程号%(asctime)s | %(levelname)-8s | %(threadName)s | %(name)s | %(filename)s:%(lineno)d | %(message)s在多线程服务里带线程名能快速分辨并发日志到底是谁打的。2.4 Filter关卡只放行要的日志顺便给记录“加字段”很多人不知道Filter的存在因为80%的场景靠级别就能搞定。但Filter能做级别做不到的事基于任意属性决定要不要放行或者在日志记录上附加自定义字段。比如某个业务里只关注用户ID以A开头的请求或者只想要特定路径下的API日志写一个Filterclass UserPrefixFilter(logging.Filter): def filter(self, record: logging.LogRecord) - bool: return getattr(record, user_id, ).startswith(A)filter方法返回True就放行返回False就丢弃。这比写一堆if语句把日志包起来要干净得多。Filter还可以给LogRecord动态添加属性配合Formatter里的字段输出就能让所有通过该Filter的日志自动带上额外字段。这在后面讲trace_id注入时会更具体地展开。2.5 一条日志从产生到落盘的完整链路把上面几个概念串起来一条日志的完整旅程是这样的调用logger.info(xxx)Logger先检查自身级别是否允许INFO事件通过不允许就直接返回。允许后LogRecord对象被创建带着消息、时间、调用位置等信息。Logger把LogRecord交给自己的Filter链有Filter拦截就丢弃。对每个挂着的HandlerHandler先检查自己的级别再检查自己的Filter通过的进入Handler。Handler用Formatter把LogRecord渲染成字符串写入目标文件、控制台、网络。Handler处理完后如果propagate为TrueLogRecord还会继续向父Logger传递重复3到5步。理解这条链路非常关键因为大部分日志问题——打不出东西、打了两份、漏了东西——本质上都是链路某个环节断了或重了。3. 生产级日志配置的实战拆解3.1 配置方式basicConfig还是dictConfig学习阶段用logging.basicConfig最简单logging.basicConfig(levellogging.INFO, format%(asctime)s | %(levelname)s | %(message)s)但basicConfig有个限制只能粗略配置一个全局Handler没法精细管理多个Logger、多个Handler的喷发关系。生产项目里模块一多、环境要求一复杂这个配置会很快不够用只能到处打补丁。我推荐从项目一开始就使用dictConfig。核心思路是把日志配置写成纯数据结构的字典再交给logging.config.dictConfig统一加载。好处有三点整份配置可视化、模块化换环境时只需要换配置字典不碰代码字典可以直接放在YAML、JSON配置文件里运维同学也能改。一个常见的配置写法LOGGING_CONFIG { version: 1, disable_existing_loggers: False, formatters: { standard: { format: %(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s }, verbose: { format: %(asctime)s | %(levelname)-8s | %(threadName)s | %(name)s | %(filename)s:%(lineno)d | %(message)s } }, handlers: { console: { class: logging.StreamHandler, formatter: standard, stream: ext://sys.stdout }, file_rotating: { class: logging.handlers.RotatingFileHandler, filename: logs/app.log, maxBytes: 10485760, backupCount: 10, encoding: utf-8, formatter: verbose } }, root: { level: INFO, handlers: [console, file_rotating] }, loggers: { app: { level: DEBUG, handlers: [console, file_rotating], propagate: False } } }注意几个关键点。disable_existing_loggers这个配置一定设为False否则在应用启动前创建的Logger会被静默禁用日志打不出来而且几乎没有报错提示。ext://sys.stdout的写法是从字符串解析出sys.stdout这个对象比在代码里手动赋值干净。3.2 一套可直接Copy的生产配置模板上面那份配置适合大部分中小项目但生产环境通常还需要考虑日志滚动策略、编码和JSON输出我再给一套更完整的模板。import logging 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 }, json: { (): app.log_utils.JSONFormatter } }, handlers: { console: { class: logging.StreamHandler, formatter: standard, stream: ext://sys.stdout, level: WARNING }, file_app: { class: logging.handlers.RotatingFileHandler, filename: logs/app.log, maxBytes: 20 * 1024 * 1024, backupCount: 15, encoding: utf-8, formatter: standard }, file_json: { class: logging.handlers.TimedRotatingFileHandler, filename: logs/app.jsonl, when: midnight, interval: 1, backupCount: 30, encoding: utf-8, formatter: json } }, root: { level: INFO, handlers: [console, file_app, file_json] }, loggers: { app: { level: DEBUG, propagate: False }, urllib3: { level: WARNING, propagate: False } } } logging.config.dictConfig(LOGGING_CONFIG)console只输出WARNING及更高级别的日志避免生产环境控制台被刷爆文件里保存完整、持久化的信息。file_app按大小滚动一个20MB、保留15份file_json按天滚动、保留30天供日志平台采集分析。第三方库urllib3、requests、docker之类的日志单独压成WARNING级别避免无关噪音混进业务日志。3.3 实现一个JSONFormatter日志结构化才有出路如果你准备接ELK、Loki、Splunk这类日志平台或者只是希望后续能用日志查询语法快速检索字段那结构化输出几乎是必须的。结构化日志本质是做“给机器看”的格式它把级别的值、来源模块、业务字段拆成分离字段而不是拼在自然语言里。第三方库python-json-logger很成熟一个class就能让日志直接变JSON。如果不方便引依赖自己写一个也很快import json import logging class JSONFormatter(logging.Formatter): def format(self, record: logging.LogRecord) - str: data { time: self.formatTime(record, self.datefmt), level: record.levelname, logger: record.name, message: record.getMessage(), filename: record.filename, line: record.lineno, } if record.exc_info: data[exception] self.formatException(record.exc_info) extras getattr(record, extra_info, None) if extras: data.update(extras) return json.dumps(data, ensure_asciiFalse)这样记录里如果有extra_info字段也会被合并进JSON。结合trace_id的注入就能做到“按订单号一次性捞出整条请求链路的所有日志”。3.4 日志轮转策略不能任由日志文件无限“膨胀”日志若不设置轮转跑上一个月轻松占满磁盘这是生产环境很常见的事故。RotatingFileHandler按文件大小切在单反容量有限、切分粒度小的场景里适合TimedRotatingFileHandler按时间切运维上更直观每天一个文件、按天归档也方便按日期检索。给条实际建议日志切分粒度按业务量来定。业务量小按天切很合适保留30到90天业务量大、一天几个GB可以考虑按小时切或者直接交给Loki这类平台收集本地只留fallback。滚动策略没有统一标准核心是“磁盘不炸、检索够用、留存合规”。另外一定要设置backupCount也就是保留多少份旧日志自动清理过期文件。不设的话跟不轮转没有区别早晚满盘。4. 日志级别与内容设计记什么、不记什么4.1 级别别乱用从DEBUG到CRITICAL的使用边界日志级别是logging的门槛机制也是最容易被用错的机制之一。我见过一个团队把什么信息都打成INFO导致出问题时一屏全是有用的等于全没用也见过有人把“业务进入分支”这种细节打成ERROR结果ERROR告警全天响真正的故障反而被淹没。我建议级别按以下标准来定级别使用场景举例DEBUG记录程序运行过程中的详细中间状态调试用生产环境一般关闭每轮循环的变量值、分支进入情况INFO记录关键业务操作的结果能还原用户做了什么、系统做了什么请求开始、请求结束、任务完成、缓存命中WARNING程序仍在正常运行但出现了异常情况需要关注但不影响用户重试次数超过阈值、进率过低、接口时延劣化ERROR某功能或操作失败但程序还能继续运行下游接口报错、业务处理失败、订单状态异常CRITICAL程序完全无法继续运行的情况数据库连接彻底断开、启动时配置缺失有一条经验很管用INFO给业务运营看DEBUG给开发人员看ERROR给值班告警看。你要问自己某条日志如果打了INFO运营同学能从中推断出业务正常吗如果打个ERROR值班同学收到告警知道该看哪里吗想清楚之后再定级别就不太会乱。4.2 异常记录别漏掉堆栈日志里最不该省的就是堆栈。两个常见反例# 反例1只记录error字符串丢了堆栈 logger.error(f调用订单服务失败{e}) # 反例2丢失原始异常错误上下文全没了 logger.error(f调用订单服务失败{e.message})正确做法是在except块里使用logger.exception它会在当前堆栈里自动记录完整的tracebacktry: resp requests.post(ORDER_SERVICE_URL, jsonpayload, timeout5) except requests.Timeout: logger.exception(调用订单服务超时%s, ORDER_SERVICE_URL)注意两点exception只能在except块里用效果相当于error(msg, exc_infoTrue)另外消息里不要拼f-string来塞上下文用逗号或占位符传参把变量作为参数传给logging让它自己格式化。4.3 不记什么敏感信息必须严格排除日志是长期留存的考虑登录、银行卡号、身份证号、访问token、数据库密码这类敏感信息一旦写进日志就等于把密钥和隐私交到了每一个能读日志的人手里。即使日志文件权限控制得很严一旦漏到ELK里再同步给第三方查询风险瞬间放大。在没有明确清理的情况下日志默认不能记录以下内容密码、二次验证码、密钥、证书内容Token、Session ID、Cookie的完整值身份证、银行卡、手机号等个人敏感信息数据库连接串里面有用户名密码内部API的完整请求体如果确实需要记录报文建议在Formater或过滤层做脱敏def mask_sensitive(value: str) - str: if not value or len(value) 8: return *** return value[:2] **** value[-4:]在filter里对record的字段统一处理不要散落在业务代码里到处判断容易漏。4.4 多线程与异步环境下的日志顺序不是你想的那样很多同学以为logging模块线程安全就代表多线程下日志顺序不乱。实际上线程安全的含义是“写文件不会串内容”但多条日志之间的先后顺序是调度器决定的不等于业务逻辑的执行顺序。想完全还原顺序需要自己在线程入口处传入一个有序号或请求ID。另外如果你用asyncio跑协程标准的logging实现里“同一个线程里写日志”也不会乱但协程切换顺序未必跟业务顺序一致。在异步框架里更重要的是一致地传递上下文比如FastAPI的每个请求里带上request_id让同一请求的所有协程日志都能通过request_id过滤出来。5. 我踩过的坑和排查经验实录5.1 日志重复打印最经典的问题日志打两遍是logging上手阶段最常见的诡异现象。第一次遇到时我的第一反应是找是不是有多个Handler在输出其实是传播机制搞的鬼子Logger和root Logger都挂了handler子Logger自己输出一遍又通过propagate传给root再输出一遍。复现方式很简单logger logging.getLogger(app) logger.addHandler(file_handler) # root上也挂了handler导致一条日志同时进两个handler logger.info(这条会打两遍)所以解决办法二选一业务模块的logger设置propagateFalse阻断向root传播同时自己配置Handler全项目只把Handler挂在root上子Logger只负责产生事件让root统一输出。第二种方式更规范但要求所有库的Logger别挂自己的Handler。混合使用的话最安全的策略是自己的应用Logger都挂到root兜底只有需要特殊行为输出JSON、单独文件的模块才单独挂Handler并关掉propagate。5.2 Windows下日志文件被占用的坑在Windows上跑程序时RotatingFileHandler滚动到一半报PermissionError这是个很经典的坑。原因是Windows的文件锁机制跟Linux不一样文件被进程打开时不能被重命名。Linux的handler尝试把旧文件改名为.log.1Windows大概率直接抛错。我实际中的处理方式有这么几种改用TimedRotatingFileHandler并在午夜滚动时尽量错开文件读写高峰把输出路径指到日志目录由外部程序负责切割归档用第三方库concurrent-log-handler它可以在多进程、Windows下规避部分类似问题实在不行就只按大小滚动少用rename。如果只是“程序重启时日志文件被占用”那通常在服务退出、日志handler没被关闭。别忘了在程序退出处显式调用shutdown。5.3 编码与时区中文乱码、时间偏移第二个常见坑是编码。在高版本Python里FileHandler默认UTF-8但在Windows环境或者老项目里很容易出现中文乱码。所以日志配置文件里一定要显式加encodingutf-8。第三个坑是时间。asctime默认用本地时间但很多服务器时区没有配好。容器环境更是重灾区。生产服务器上我建议在配置阶段就统一UTC或统一某时区Formatter里固定一下时间格式并考虑使用zoneinfo生成前缀。另外TimedRotatingFileHandler的“whenmidnight”依赖本机时区。如果容器时区是UTC但你想按北京时间切日志文件需要先确保进程时区设置正确否则“每天一条日志”这个预期很容易错位。5.4 日志拖慢业务跨进程IO不是免费的当你的接口每次请求打七八条INFO日志每条都要写入文件日志就真的成了性能瓶颈。单个进程磁盘IO很快但并发一大就有排队。我碰到过最极端的情况是日志驱动器负载过高CPU被sys占用拉高业务接口整体慢了一倍。建议的解法是用异步日志。把日志放进内存队列由后台线程统一批量写入import logging import queue from logging.handlers import QueueHandler, QueueListener log_queue queue.Queue(-1) queue_handler QueueHandler(log_queue) console_handler logging.StreamHandler() file_handler logging.FileHandler(logs/app.log) listener QueueListener(log_queue, console_handler, file_handler, respect_handler_levelTrue) listener.start() root logging.getLogger() root.addHandler(queue_handler) root.setLevel(logging.DEBUG)这相当于在生产日志和磁盘写之间加了一个缓冲带业务线程只需要把日志放进内存队列不会阻塞在磁盘同步上。程序退出前记得listener.stop()否则队列里的日志会丢失。5.5 借助trace_id打通分布式链路日志在微服务或调用链比较长的系统里一条请求经过好几个服务怎么把属于同一请求的日志过滤出来答案是给请求设置一个唯一的trace_id并在所有相关日志里带上它。我用contextvars加Filter实现逻辑很轻import contextvars import uuid trace_id_var contextvars.ContextVar(trace_id, default-) class TraceIDFilter(logging.Filter): def filter(self, record: logging.LogRecord) - bool: record.trace_id trace_id_var.get() return True在FastAPI入口中间件里生成并设置app.middleware(http) async def set_trace_id(request, call_next): trace_id_var.set(request.headers.get(x-trace-id, uuid.uuid4().hex)) response await call_next(request) response.headers[X-Trace-ID] trace_id_var.get() return response把TraceIDFilter挂到app的logger上Formatter模板加上(trace_id)s此后同一请求里的所有日志都会带同一个trace_id。查询日志时按trace_id一过滤整条链路的快照就出来了。这是我从纸上谈兵阶段之后最受益的一个实践。6. 一套自查清单日志配置上线前过一遍最后分享一些实战中琢磨出来的检查点。我的习惯是每次给项目接入logging之后都会拿着这个清单逐项核对配置里disable_existing_loggers是不是False业务模块Logger是否误设了propagateTrue导致重复打印是否有Handler在生产里漏加了level限制DEBUG日志刷爆磁盘日志文件路径是否设置了可写没有该目录时是否能自动创建是否显式配置encodingutf-8中文日志乱不乱滚动策略是否设置了backupCount磁盘撑爆前能扛多久是否记录了完整的异常堆栈而不是只有错误消息日志里有没有可能泄敏感信息的字段生产环境console的日志级别够不够高不至于一排日志刷到不可用程序退出时有没有关闭Handler、停止Listener避免丢日志这份清单每一条背后都对应着一个实际翻车场景。我陆续在几个服务里吃过这些亏后面就养成了每次配置完日志先过一遍清单的习惯踩坑率明显下降。对大多数项目来说标准库logging配上dictConfig、滚动文件、JSON格式化已经能覆盖90%的需求。不要一上来就追求Kafka、elk、OpenTelemetry那套重型方案先把最基础的链路弄通——哪条日志进了哪个文件、按什么结构存下来、出了故障能不能捞回来做到这三件事再考虑更复杂的平台化建设。日志系统是随着业务一起生长的它应该像排水管道一样一开始就存在然后根据流量一点一点加粗、加分支、加监测点。
Python日志记录最佳实践：从print到logging的工程化改造
干过几年Python开发的人迟早会遇到这样一件事代码里到处是print线上环境一出问题第一反应是打开终端盯着输出看。等真正把Python日志记录Logging捋清楚之后我才发现print和logging之间差的不是几行代码而是一整套事件收集思维。这篇日志最佳实践不是API照抄指南而是从核心概念讲到生产级配置外加我踩过的一堆坑把logging的使用边界和正确姿势一次说清。logging是Python标准库自带的模块不用装任何第三方包就能用。它解决的核心问题是让运行中的程序把关键事件按照统一的结构记录下来并且这些记录可以被检索、被追溯、被留作证据。它适合所有用Python写程序的场景——从跑一次就结束的脚本到需要长期运行的Web服务、数据处理任务、爬虫都会从中受益。如果你写的是会被别人接手、需要长期维护的代码那日志设计得怎么样基本决定了将来排查故障要花半天还是一分钟。1. 为什么你的项目需要一个正经的日志系统1.1 先聊一个现实问题print大法为什么撑不到生产环境很多新手写代码调试全靠print。print确实简单脚本阶段用起来相当顺手但到了生产环境至少五个问题会冒出来。第一print没有级别。输出的内容混在一起DEBUG信息、业务信息、错误信息全是一行行裸文本根本没法快速筛选出错误。第二print没有时间戳。出了事你看到一行网络请求失败的输出但根本不知道发生在哪天几点几分排查全靠猜。第三print没有来源信息。程序里几百个print输出后只能靠肉眼认是哪一行的内容大型项目里这几乎是灾难。第四print无法分流。日志通常要被同时写到文件、控制台、日志收集平台print只能往一个stdout里打想拆都拆不开。第五print是不可控的。它不认配置文件没有“调试模式下才输出、正式环境只记重要事件”这种开关写进代码里就很难在不改代码的前提下调整。这些问题单独看都不致命堆叠在一起就是“线上日志失灵”的典型症状。我见过不少人把这结论归为“Python不适合做大型项目”其实不是工具的错是用工具的方式有边界。print的职责是“给正在写代码的人看”logging的职责是“给维护这个系统的人看”两者定位完全不同。1.2 logging不是“更好用的print”它是统一的事件收集通道logging模块的底层设计是把日志当成事件流来处理。整个系统分成四类角色Logger负责“产生事件”Handler负责“把事件送到哪里去”Formatter负责“事件长什么样”Filter负责“哪些事件值得送”。这种分工看起来多绕了一层但实际使用中会发现非常灵活。同一个Logger可以同时挂一个写控制台的Handler、一个写文件的Handler、一个发到远端日志平台的Handler各自拥有独立的级别和格式。线上环境想调高Console的级别、保留文件里的完整DEBUG记录只需要改一行配置代码不用动。另外要注意logging在Python 3里已经是线程安全的多线程环境下日志不会串行写坏。这是很多自造日志方案的硬伤也是我始终推荐直接用标准库的原因——别急着造轮子标准库能覆盖绝大多数需求。1.3 这篇文章能让你拿走什么跟随这篇内容你会把logging模块的核心概念彻底过一遍搞清楚Logger、Handler、Formatter、Filter之间的协作关系然后拿到一套可以直接搬进生产项目的dictConfig配置模板包含按大小滚动、按天滚动、JSON结构化输出最后是一些我亲测踩过的坑——日志重复打印、Windows句柄被占、编码乱码、异步写日志的性能陷阱。这些都是网上文档很少告诉你、但实际项目里一定会碰到的东西。2. 吃透logging模块的五个核心概念2.1 Logger有名字的事件源而不是一个全局单例先纠正一个常见误解logging.getLogger()不是取一个“全局的东西”而是通过名字获取一个Logger对象。名字是有层级关系的用点号分隔。比如你调用了logging.getLogger(app.api)它会自动把app当作自己的父Loggerapi是子Logger再往上是root。层级关系带来一个很重要的行为——传播propagate。子Logger记录的一条日志默认会向上传给父Logger由父Logger的Handler再输出一次。这意味着如果你在模块里只创建Logger、不添加Handler日志也照样能输出因为root上大概率挂了Handler。这很方便但也是“日志重复打印”的头号原因后面踩坑部分会细说。实践中怎么用呢推荐每个模块都用自己的模块名loggerlogger logging.getLogger(__name__)__name__就是当前模块的完整路径比如app.services.task这样日志里自带模块名排查时一眼就能定位到代码位置。注意Logger的级别判断是在事件产生时独立生效的它决定“这条日志要不要被收集起来”收集之后再交给HandlerHandler那边还会再做一次级别过滤。2.2 Handler决定日志流向哪里的出口Handler负责真正把日志写出去。标准库提供了很多种我实际用得最多的是这几个StreamHandler写往控制台或任何类似流对象默认是stderr。开发调试、容器环境里很常用。FileHandler写往文件最简单的持久化方案。RotatingFileHandler按文件大小滚动文件写满maxBytes之后自动重命名新建一个文件继续写。TimedRotatingFileHandler按时间滚动可以按分钟、小时、天、周切换新文件。生产环境最常用的是每天滚动一次。一个Logger可以挂多个Handler这也是logging最灵活的地方。开发环境我要的是“控制台即时看到全量日志”生产环境我要的是“文件记录全量日志 控制台只出错误摘要”这就是同一个Logger挂两个不同Handler的典型场景。2.3 Formatter决定日志最后长什么样的模板Formatter就是把LogRecord对象一条日志事件的完整载体包含Message、时间、级别、Logger名、行号、进程号、线程号等信息渲染成最终字符串的组件。我的标准格式串长这样%(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s渲染出来的样子2025-03-12 14:30:21,567 | INFO | app.services.task | task.py:42 | 用户 1001 开始下载任务这个模板里时间、级别、Logger名、文件行号、消息都齐了可以作为工作流的基础模板。-8s表示左对齐并占8个字符宽度出发点是为了让不同级别的日志在视觉上对齐扫一眼就能看出哪些行是ERROR。还可以在Formatter里带上下文信息比如进程号、线程号%(asctime)s | %(levelname)-8s | %(threadName)s | %(name)s | %(filename)s:%(lineno)d | %(message)s在多线程服务里带线程名能快速分辨并发日志到底是谁打的。2.4 Filter关卡只放行要的日志顺便给记录“加字段”很多人不知道Filter的存在因为80%的场景靠级别就能搞定。但Filter能做级别做不到的事基于任意属性决定要不要放行或者在日志记录上附加自定义字段。比如某个业务里只关注用户ID以A开头的请求或者只想要特定路径下的API日志写一个Filterclass UserPrefixFilter(logging.Filter): def filter(self, record: logging.LogRecord) - bool: return getattr(record, user_id, ).startswith(A)filter方法返回True就放行返回False就丢弃。这比写一堆if语句把日志包起来要干净得多。Filter还可以给LogRecord动态添加属性配合Formatter里的字段输出就能让所有通过该Filter的日志自动带上额外字段。这在后面讲trace_id注入时会更具体地展开。2.5 一条日志从产生到落盘的完整链路把上面几个概念串起来一条日志的完整旅程是这样的调用logger.info(xxx)Logger先检查自身级别是否允许INFO事件通过不允许就直接返回。允许后LogRecord对象被创建带着消息、时间、调用位置等信息。Logger把LogRecord交给自己的Filter链有Filter拦截就丢弃。对每个挂着的HandlerHandler先检查自己的级别再检查自己的Filter通过的进入Handler。Handler用Formatter把LogRecord渲染成字符串写入目标文件、控制台、网络。Handler处理完后如果propagate为TrueLogRecord还会继续向父Logger传递重复3到5步。理解这条链路非常关键因为大部分日志问题——打不出东西、打了两份、漏了东西——本质上都是链路某个环节断了或重了。3. 生产级日志配置的实战拆解3.1 配置方式basicConfig还是dictConfig学习阶段用logging.basicConfig最简单logging.basicConfig(levellogging.INFO, format%(asctime)s | %(levelname)s | %(message)s)但basicConfig有个限制只能粗略配置一个全局Handler没法精细管理多个Logger、多个Handler的喷发关系。生产项目里模块一多、环境要求一复杂这个配置会很快不够用只能到处打补丁。我推荐从项目一开始就使用dictConfig。核心思路是把日志配置写成纯数据结构的字典再交给logging.config.dictConfig统一加载。好处有三点整份配置可视化、模块化换环境时只需要换配置字典不碰代码字典可以直接放在YAML、JSON配置文件里运维同学也能改。一个常见的配置写法LOGGING_CONFIG { version: 1, disable_existing_loggers: False, formatters: { standard: { format: %(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s }, verbose: { format: %(asctime)s | %(levelname)-8s | %(threadName)s | %(name)s | %(filename)s:%(lineno)d | %(message)s } }, handlers: { console: { class: logging.StreamHandler, formatter: standard, stream: ext://sys.stdout }, file_rotating: { class: logging.handlers.RotatingFileHandler, filename: logs/app.log, maxBytes: 10485760, backupCount: 10, encoding: utf-8, formatter: verbose } }, root: { level: INFO, handlers: [console, file_rotating] }, loggers: { app: { level: DEBUG, handlers: [console, file_rotating], propagate: False } } }注意几个关键点。disable_existing_loggers这个配置一定设为False否则在应用启动前创建的Logger会被静默禁用日志打不出来而且几乎没有报错提示。ext://sys.stdout的写法是从字符串解析出sys.stdout这个对象比在代码里手动赋值干净。3.2 一套可直接Copy的生产配置模板上面那份配置适合大部分中小项目但生产环境通常还需要考虑日志滚动策略、编码和JSON输出我再给一套更完整的模板。import logging 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 }, json: { (): app.log_utils.JSONFormatter } }, handlers: { console: { class: logging.StreamHandler, formatter: standard, stream: ext://sys.stdout, level: WARNING }, file_app: { class: logging.handlers.RotatingFileHandler, filename: logs/app.log, maxBytes: 20 * 1024 * 1024, backupCount: 15, encoding: utf-8, formatter: standard }, file_json: { class: logging.handlers.TimedRotatingFileHandler, filename: logs/app.jsonl, when: midnight, interval: 1, backupCount: 30, encoding: utf-8, formatter: json } }, root: { level: INFO, handlers: [console, file_app, file_json] }, loggers: { app: { level: DEBUG, propagate: False }, urllib3: { level: WARNING, propagate: False } } } logging.config.dictConfig(LOGGING_CONFIG)console只输出WARNING及更高级别的日志避免生产环境控制台被刷爆文件里保存完整、持久化的信息。file_app按大小滚动一个20MB、保留15份file_json按天滚动、保留30天供日志平台采集分析。第三方库urllib3、requests、docker之类的日志单独压成WARNING级别避免无关噪音混进业务日志。3.3 实现一个JSONFormatter日志结构化才有出路如果你准备接ELK、Loki、Splunk这类日志平台或者只是希望后续能用日志查询语法快速检索字段那结构化输出几乎是必须的。结构化日志本质是做“给机器看”的格式它把级别的值、来源模块、业务字段拆成分离字段而不是拼在自然语言里。第三方库python-json-logger很成熟一个class就能让日志直接变JSON。如果不方便引依赖自己写一个也很快import json import logging class JSONFormatter(logging.Formatter): def format(self, record: logging.LogRecord) - str: data { time: self.formatTime(record, self.datefmt), level: record.levelname, logger: record.name, message: record.getMessage(), filename: record.filename, line: record.lineno, } if record.exc_info: data[exception] self.formatException(record.exc_info) extras getattr(record, extra_info, None) if extras: data.update(extras) return json.dumps(data, ensure_asciiFalse)这样记录里如果有extra_info字段也会被合并进JSON。结合trace_id的注入就能做到“按订单号一次性捞出整条请求链路的所有日志”。3.4 日志轮转策略不能任由日志文件无限“膨胀”日志若不设置轮转跑上一个月轻松占满磁盘这是生产环境很常见的事故。RotatingFileHandler按文件大小切在单反容量有限、切分粒度小的场景里适合TimedRotatingFileHandler按时间切运维上更直观每天一个文件、按天归档也方便按日期检索。给条实际建议日志切分粒度按业务量来定。业务量小按天切很合适保留30到90天业务量大、一天几个GB可以考虑按小时切或者直接交给Loki这类平台收集本地只留fallback。滚动策略没有统一标准核心是“磁盘不炸、检索够用、留存合规”。另外一定要设置backupCount也就是保留多少份旧日志自动清理过期文件。不设的话跟不轮转没有区别早晚满盘。4. 日志级别与内容设计记什么、不记什么4.1 级别别乱用从DEBUG到CRITICAL的使用边界日志级别是logging的门槛机制也是最容易被用错的机制之一。我见过一个团队把什么信息都打成INFO导致出问题时一屏全是有用的等于全没用也见过有人把“业务进入分支”这种细节打成ERROR结果ERROR告警全天响真正的故障反而被淹没。我建议级别按以下标准来定级别使用场景举例DEBUG记录程序运行过程中的详细中间状态调试用生产环境一般关闭每轮循环的变量值、分支进入情况INFO记录关键业务操作的结果能还原用户做了什么、系统做了什么请求开始、请求结束、任务完成、缓存命中WARNING程序仍在正常运行但出现了异常情况需要关注但不影响用户重试次数超过阈值、进率过低、接口时延劣化ERROR某功能或操作失败但程序还能继续运行下游接口报错、业务处理失败、订单状态异常CRITICAL程序完全无法继续运行的情况数据库连接彻底断开、启动时配置缺失有一条经验很管用INFO给业务运营看DEBUG给开发人员看ERROR给值班告警看。你要问自己某条日志如果打了INFO运营同学能从中推断出业务正常吗如果打个ERROR值班同学收到告警知道该看哪里吗想清楚之后再定级别就不太会乱。4.2 异常记录别漏掉堆栈日志里最不该省的就是堆栈。两个常见反例# 反例1只记录error字符串丢了堆栈 logger.error(f调用订单服务失败{e}) # 反例2丢失原始异常错误上下文全没了 logger.error(f调用订单服务失败{e.message})正确做法是在except块里使用logger.exception它会在当前堆栈里自动记录完整的tracebacktry: resp requests.post(ORDER_SERVICE_URL, jsonpayload, timeout5) except requests.Timeout: logger.exception(调用订单服务超时%s, ORDER_SERVICE_URL)注意两点exception只能在except块里用效果相当于error(msg, exc_infoTrue)另外消息里不要拼f-string来塞上下文用逗号或占位符传参把变量作为参数传给logging让它自己格式化。4.3 不记什么敏感信息必须严格排除日志是长期留存的考虑登录、银行卡号、身份证号、访问token、数据库密码这类敏感信息一旦写进日志就等于把密钥和隐私交到了每一个能读日志的人手里。即使日志文件权限控制得很严一旦漏到ELK里再同步给第三方查询风险瞬间放大。在没有明确清理的情况下日志默认不能记录以下内容密码、二次验证码、密钥、证书内容Token、Session ID、Cookie的完整值身份证、银行卡、手机号等个人敏感信息数据库连接串里面有用户名密码内部API的完整请求体如果确实需要记录报文建议在Formater或过滤层做脱敏def mask_sensitive(value: str) - str: if not value or len(value) 8: return *** return value[:2] **** value[-4:]在filter里对record的字段统一处理不要散落在业务代码里到处判断容易漏。4.4 多线程与异步环境下的日志顺序不是你想的那样很多同学以为logging模块线程安全就代表多线程下日志顺序不乱。实际上线程安全的含义是“写文件不会串内容”但多条日志之间的先后顺序是调度器决定的不等于业务逻辑的执行顺序。想完全还原顺序需要自己在线程入口处传入一个有序号或请求ID。另外如果你用asyncio跑协程标准的logging实现里“同一个线程里写日志”也不会乱但协程切换顺序未必跟业务顺序一致。在异步框架里更重要的是一致地传递上下文比如FastAPI的每个请求里带上request_id让同一请求的所有协程日志都能通过request_id过滤出来。5. 我踩过的坑和排查经验实录5.1 日志重复打印最经典的问题日志打两遍是logging上手阶段最常见的诡异现象。第一次遇到时我的第一反应是找是不是有多个Handler在输出其实是传播机制搞的鬼子Logger和root Logger都挂了handler子Logger自己输出一遍又通过propagate传给root再输出一遍。复现方式很简单logger logging.getLogger(app) logger.addHandler(file_handler) # root上也挂了handler导致一条日志同时进两个handler logger.info(这条会打两遍)所以解决办法二选一业务模块的logger设置propagateFalse阻断向root传播同时自己配置Handler全项目只把Handler挂在root上子Logger只负责产生事件让root统一输出。第二种方式更规范但要求所有库的Logger别挂自己的Handler。混合使用的话最安全的策略是自己的应用Logger都挂到root兜底只有需要特殊行为输出JSON、单独文件的模块才单独挂Handler并关掉propagate。5.2 Windows下日志文件被占用的坑在Windows上跑程序时RotatingFileHandler滚动到一半报PermissionError这是个很经典的坑。原因是Windows的文件锁机制跟Linux不一样文件被进程打开时不能被重命名。Linux的handler尝试把旧文件改名为.log.1Windows大概率直接抛错。我实际中的处理方式有这么几种改用TimedRotatingFileHandler并在午夜滚动时尽量错开文件读写高峰把输出路径指到日志目录由外部程序负责切割归档用第三方库concurrent-log-handler它可以在多进程、Windows下规避部分类似问题实在不行就只按大小滚动少用rename。如果只是“程序重启时日志文件被占用”那通常在服务退出、日志handler没被关闭。别忘了在程序退出处显式调用shutdown。5.3 编码与时区中文乱码、时间偏移第二个常见坑是编码。在高版本Python里FileHandler默认UTF-8但在Windows环境或者老项目里很容易出现中文乱码。所以日志配置文件里一定要显式加encodingutf-8。第三个坑是时间。asctime默认用本地时间但很多服务器时区没有配好。容器环境更是重灾区。生产服务器上我建议在配置阶段就统一UTC或统一某时区Formatter里固定一下时间格式并考虑使用zoneinfo生成前缀。另外TimedRotatingFileHandler的“whenmidnight”依赖本机时区。如果容器时区是UTC但你想按北京时间切日志文件需要先确保进程时区设置正确否则“每天一条日志”这个预期很容易错位。5.4 日志拖慢业务跨进程IO不是免费的当你的接口每次请求打七八条INFO日志每条都要写入文件日志就真的成了性能瓶颈。单个进程磁盘IO很快但并发一大就有排队。我碰到过最极端的情况是日志驱动器负载过高CPU被sys占用拉高业务接口整体慢了一倍。建议的解法是用异步日志。把日志放进内存队列由后台线程统一批量写入import logging import queue from logging.handlers import QueueHandler, QueueListener log_queue queue.Queue(-1) queue_handler QueueHandler(log_queue) console_handler logging.StreamHandler() file_handler logging.FileHandler(logs/app.log) listener QueueListener(log_queue, console_handler, file_handler, respect_handler_levelTrue) listener.start() root logging.getLogger() root.addHandler(queue_handler) root.setLevel(logging.DEBUG)这相当于在生产日志和磁盘写之间加了一个缓冲带业务线程只需要把日志放进内存队列不会阻塞在磁盘同步上。程序退出前记得listener.stop()否则队列里的日志会丢失。5.5 借助trace_id打通分布式链路日志在微服务或调用链比较长的系统里一条请求经过好几个服务怎么把属于同一请求的日志过滤出来答案是给请求设置一个唯一的trace_id并在所有相关日志里带上它。我用contextvars加Filter实现逻辑很轻import contextvars import uuid trace_id_var contextvars.ContextVar(trace_id, default-) class TraceIDFilter(logging.Filter): def filter(self, record: logging.LogRecord) - bool: record.trace_id trace_id_var.get() return True在FastAPI入口中间件里生成并设置app.middleware(http) async def set_trace_id(request, call_next): trace_id_var.set(request.headers.get(x-trace-id, uuid.uuid4().hex)) response await call_next(request) response.headers[X-Trace-ID] trace_id_var.get() return response把TraceIDFilter挂到app的logger上Formatter模板加上(trace_id)s此后同一请求里的所有日志都会带同一个trace_id。查询日志时按trace_id一过滤整条链路的快照就出来了。这是我从纸上谈兵阶段之后最受益的一个实践。6. 一套自查清单日志配置上线前过一遍最后分享一些实战中琢磨出来的检查点。我的习惯是每次给项目接入logging之后都会拿着这个清单逐项核对配置里disable_existing_loggers是不是False业务模块Logger是否误设了propagateTrue导致重复打印是否有Handler在生产里漏加了level限制DEBUG日志刷爆磁盘日志文件路径是否设置了可写没有该目录时是否能自动创建是否显式配置encodingutf-8中文日志乱不乱滚动策略是否设置了backupCount磁盘撑爆前能扛多久是否记录了完整的异常堆栈而不是只有错误消息日志里有没有可能泄敏感信息的字段生产环境console的日志级别够不够高不至于一排日志刷到不可用程序退出时有没有关闭Handler、停止Listener避免丢日志这份清单每一条背后都对应着一个实际翻车场景。我陆续在几个服务里吃过这些亏后面就养成了每次配置完日志先过一遍清单的习惯踩坑率明显下降。对大多数项目来说标准库logging配上dictConfig、滚动文件、JSON格式化已经能覆盖90%的需求。不要一上来就追求Kafka、elk、OpenTelemetry那套重型方案先把最基础的链路弄通——哪条日志进了哪个文件、按什么结构存下来、出了故障能不能捞回来做到这三件事再考虑更复杂的平台化建设。日志系统是随着业务一起生长的它应该像排水管道一样一开始就存在然后根据流量一点一点加粗、加分支、加监测点。
