1. 组件协作机制与整体设计思路logging 模块机构庞大许多同学学到这都会卡在一个坎上明明按网上的代码配了日志还是一头雾水日志要么不显示要么重复显示要么格式不对。这里根本问题不是代码不对而是没搞懂 logging 的架构——它其实由四个独立但又互相协作的组件组成Logger日志记录器、Handler处理器、Formatter格式化器、Filter过滤器。搞清楚这四者之间的关系就能写出好用且可控的日志系统。为了把组件之间的协作关系讲明白我先用一个生活类比做个铺垫。你在公司前台拿快递前台是会根据快递单上的信息把包裹分类放到不同的货架上然后通知你来取。这个过程里你填写的快递单就是 Logger 产生的 LogRecord 日志事件前台的分类规则就是 Logger 和 Handler 上的 Level 级别设定不同货架就是不同的 Handler比如控制台、文件、远程服务货架上的标签就是 Formatter 格式化器而那个负责拦住某些包裹不让上架的人就是 Filter 过滤器。在 logging 源码里日志的流转顺序是这样Logger 调用某个方法生成一条 LogRecord然后依次经过 Logger 的 Filter 检查、级别判断接着交给当前 Logger 以及它的各个祖先 Logger 上挂载的 Handler 去处理。每个 Handler 又会再做一次自己的级别判断和 Filter 检查最后用 Formatter 把记录变成文本。这个顺序非常重要因为很多同学只注意了 Logger 上的级别却忽略了 Handler 上还有一道独立的级别闸门。两者是串联关系——日志只有同时通过这两道闸门才会真正被输出。五大核心组件实际做的是Logger 负责承接调用、决定这条日志要不要给后面的处理器Handler 负责把记录送到不同的目的地Formatter 负责把 LogRecord 的属性拼成一行可读文本Filter 负责在 Logger 和 Handler 两个位置做自定义拦截再加上 Level 在各个关卡上的粗细分级。五者各管一摊配合起来就可以组成一套灵活的企业级日志方案。现在对 logging 初始化方式的常见误区做个纠正。官方文档里推荐的 best practice是每个模块里用 logging.getLogger() 获取一个模块级 logger模块内部只管打日志不需要也不应该自己配置 Handler。配置统一放在程序入口处集中完成。很多同学反着来每个模块都配一次 basicConfig结果重复打印或者互相覆盖格式。这不是 logging 的问题是用法不对。logger 之间的继承关系也是设计难点值得展开说。如果用 getLogger(name)模块的包路径形成天然的父子层级子 logger 没有设置 Handler 时日志会根据 propagate 向上传递到最近的祖先 logger 上去。这个机制是双刃剑用得好可以高效地在根 logger 上统一配置各子模块自动继承用不好你会发现一个日志被打印了 N 遍或者想关闭某个子模块的日志却关不掉。我见过的最典型错误配置是这样的在封装模块里创建了一个名为myapp的 logger并且给它 setLevel 和加了 StreamHandler然后又在外层入口调用了 basicConfig。结果 basicConfig 创建了一个名为 root 的 root logger两条链路同时处理同一条日志屏幕上就会出现两行一模一样的输出。要解决这个必须记住一个核心原则——同一个 logger 命名空间里Handler 只挂一次。2. 五大核心组件逐个拆解2.1 Logger 记录器日志入口与级别闸门Logger 是整个体系的入口实际情况下你接触到的几乎所有日志操作都是直接面对它。Logger 的实例不是用构造函数生成的而是统一通过 logging.getLogger(name) 获得这一步保证了同名的 logger 在任何模块里拿到的都是同一个实例。Logger 的 name 参数有个小细节传空字符串或者不传拿到的就是 root 根 logger。根 logger 是默认的兜底目标所有没有显式配置 logger 的模块日志最终都会汇聚到它这里。basConfig 这个快捷函数本质上就是给根 logger 挂上了一个默认的 StreamHandler。Logger 上的 setLevel 决定的是“这个 logger 愿意记录的最低级别”。比如 logger.setLevel(logging.DEBUG)那么 DEBUG 和更高级别都会进到后续流程如果设置成 WARNING那么 DEBUG 和 INFO 在源头就被丢弃了根本不会传给 Handler。这里要特别提一句Handler 上也有自己的 setLevel那是第二道闸门。一道在源头一道在出口两者都要满足这条日志才能最终被送达。Logger 还提供了一系列语义化方法debug、info、warning、error、critical以及一个通用的 log(level, msg) 方法。还有一个不太常用但很实用的 exception(msg)它在 error 基础上自动附带了当前异常的堆栈信息只能在 except 块里调用才有效。在设计上Logger 不直接输出“文本”。它内部创建一个 LogRecord 对象把时间、模块名、函数名、行号、消息内容、异常信息等打包成一个整体然后交给后面的流水线。这套设计的好处是后续任何 Handler 和 Formatter 都能拿到完整的结构化信息而不仅仅是字符串。2.2 Handler 处理器日志的三路分发Handler 决定日志去哪儿。logging 内置了几种常见 Handler我工作中最常用的四个在表格里整理如下Handler 名称目标输出典型使用场景关键参数StreamHandler任意流对象默认 stderr控制台输出stream, level, formatterFileHandler单个文件本地文件记录filename, mode, encodingRotatingFileHandler按大小轮转的文件文件可能变大的场景maxBytes, backupCountTimedRotatingFileHandler按时间轮转的文件按天/小时切割日志when, interval, backupCount单个 logger 可以挂多个 Handler比如同时挂控制台 Handler 和文件 Handler这样开发时在控制台看实时输出线上把完整日志落到文件中。这个多路分发能力正是五大组件协作体系的价值所在。关于 Handler 的格式设置有说道。每个 Handler 可以单独设置自己的 Formatter这意味着同一个日志事件在终端里输出时可以带颜色、精简内容在文件里却可以记录完整上下文。我常用的做法是控制台 Formatter 只显示时间、级别和消息文件 Formatter 显示时间、模块、函数、行号、级别、消息、异常堆栈全套信息。Handler 的级别是独立于 Logger 的。为了防止把 DEBUG 刷进文件引起磁盘暴涨可以在 Handler 上设成 INFO同时在 Logger 上保留 DEBUG。这样在开发调试阶段临时把 Handler 级别调成 DEBUG 就能看到详细信息改配置不影响业务代码。有一个 Handler 内部的 mechanism 很多人不知道Formatter 是一层一层向下传递的。如果你创建了一个 FileHandler 并给它设置了 Formatter其他 Handler 没有配置 Formatter那么日志在输出时会用默认的%(message)s格式只显示消息文本而不会带上时间级别。所以每个 Handler 都要显式设置 Formatter除非你明确知道自己在做什么。2.3 Formatter 格式化器日志字段的排版规则Formatter 的工作是把 LogRecord 对象的各个属性拼接成最终输出的字符串。logging 保留了类似 printf 的%占位风格{% raw %}常见的格式包括%(asctime)s时间、%(levelname)s级别名、%(name)slogger 名、%(message)s日志消息{% endraw %}。一个完整的、适合文件输出的格式示例import logging file_fmt logging.Formatter( %(asctime)s | %(levelname)-8s | %(name)s | %(funcName)s:%(lineno)d | %(message)s, datefmt%Y-%m-%d %H:%M:%S ){% raw %}-8s表示左对齐并占满 8 个字符宽度这样日志级别在视觉上会整齐对齐可读性大幅提高{% endraw %}。这个简单的排版习惯能让多级混杂的日志清晰很多。Formatter 还有一个容易被忽视的用法它可以拿到异常的堆栈信息。在 except 块里调用logger.exception(...)LogRecord 会带上 exc_infoFormatter 在渲染时只要消息里包含换行堆栈信息会自动拼在消息后面不需要额外操作。自定义 Formatter 也很简单继承 logging.Formatter重写 format 方法就能实现扩展。一个常见的需求是在日志行里附带当前进程 ID 和线程名这在排查并发问题时非常有用import logging import os import threading class ThreadFormatter(logging.Formatter): def format(self, record): record.process_id os.getpid() record.thread_name threading.current_thread().name return super().format(record)关键在于在调用 super().format() 之前给 record 动态添加属性后续在格式字符串里直接引用 {% raw %}%(thread_name)s{% endraw %} 就能输出。2.4 Filter 过滤器精准的日志筛选逻辑Filter 是五大组件里最容易被低估的一个。它的核心用途不是按级别过滤——级别过滤交给 Level 更合适——而是按业务维度做精确筛选。比如只想记录某个特定模块的日志或者只想记录包含某个关键词的事务日志。Filter 的行为是典型的“白名单机制”一个 filter 对象需要实现 filter(record) 方法返回 True 表示放行返回 False 表示丢弃。logging 内置的 Filter 类可以直接使用构造时传一个 logger name 字符串它就会只放行“该 logger 自身及其子 logger”产生的日志。自定义 Filter 的场景我举一个真实例子。某公司的订单系统里我只想追踪一个特定订单号的完整调用链那么可以这样写import logging class OrderIDFilter(logging.Filter): def __init__(self, target_order_id): super().__init__() self.target target_order_id def filter(self, record): msg record.getMessage() return forder{self.target} in msg or self.target in msg logger logging.getLogger(order_system) logger.addFilter(OrderIDFilter(#2025A001))这个 Filter 会检查每一条经过它的日志消息里是否包含目标订单号不包含的直接丢弃。开发调试的效率提升非常显著尤其是在一天几十万条日志压下来的时候。需要特别强调的是Filter 在 Logger 和 Handler 上都可以添加。挂在 Logger 上影响的是该 logger 自身及经过它的所有日志挂在 Handler 上则只影响这一个输出通道。两者的使用时机不同如果日志要同时发往文件和控制台但你想只在文件里过滤掉一类记录那 Filter 应该挂到文件 Handler 上而不是 Logger 上。2.5 Level 级别贯穿全流程的刻度线Level 表面上是数字常量实际是系统里最基础的分级标尺。级别从低到高分别是 DEBUG10、INFO20、WARNING30、ERROR40、CRITICAL50。这种数值设计方便进行大小比较logger 和 handler 上维护两个阈值数字每条日志的级别数值只要小于阈值就被拦截。除了内置的五个级别logging 支持自定义级别。比如业务上有特殊的审计需求想插入一个介于 INFO 和 WARNING 之间的级别做法是import logging AUDIT_LEVEL 25 logging.addLevelName(AUDIT_LEVEL, AUDIT) def audit(self, msg, *args, **kwargs): if self.isEnabledFor(AUDIT_LEVEL): self._log(AUDIT_LEVEL, msg, args, **kwargs) logging.Logger.audit audit logger logging.getLogger(business) logger.audit(用户执行了关键操作操作类型: %s, transfer)这里有两个坑要提前说明。一是 addLevelName 不会自动让这个级别生效logger 必须显式调用 isEnabledFor 和 _log 才能记录下来二是级别数字的选择要与已有级别空开防止比较运算时出现歧义。Level 的比较运算不仅用于 logger 上的关卡也用于 handler 上的关卡。实际调试时遇到日志“莫名丢了”第一件事不是怀疑代码逻辑而是交叉检查 Logger 和 Handler 的 Level 配置。再补充一个重要的知识点当 Logger 没有明确设置 Level 时effective level 规则触发——它会沿着 logger 的父子链一路向上找找到第一个设置了级别的祖先 logger 作为当前生效级别。如果在根 logger 上设了级别所有子 logger 在没有显式设置的情况下都会沿用这个级别。了解这个机制之后很多“为什么这个模块的日志不见了”的问题都能迎刃而解。3. 完整实操从零搭建一套可复用的日志配置理论环节到此打住现在我用一个真实项目场景带你实操一遍。假设某公司的一个 Web 服务需要同时满足三个需求开发时在控制台看到 DEBUG 级别日志、生产时把 INFO 及以上日志写到按天轮转的文件、隔离某个特殊模块的日志到单独文件。全部基于五大组件搭建。3.1 配置代码模块化日志工厂我先写一个 log_factory.py负责配置 Logger 的实例。按照推荐做法业务模块不配置 Handler只在统一入口处初始化import logging import logging.handlers import os import sys LOG_DIR logs os.makedirs(LOG_DIR, exist_okTrue) def build_logger(namemyapp, console_levellogging.INFO, file_levellogging.DEBUG, dailyTrue): logger logging.getLogger(name) logger.setLevel(logging.DEBUG) fmt_console logging.Formatter( %(asctime)s %(levelname)-8s %(message)s, datefmt%H:%M:%S ) fmt_file logging.Formatter( %(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(funcName)s | %(message)s ) # 控制台 Handler console_handler logging.StreamHandler(sys.stderr) console_handler.setLevel(console_level) console_handler.setFormatter(fmt_console) logger.addHandler(console_handler) # 按时间轮转的文件 Handler if daily: file_handler logging.handlers.TimedRotatingFileHandler( os.path.join(LOG_DIR, app.log), whenmidnight, backupCount30, encodingutf-8 ) else: file_handler logging.handlers.RotatingFileHandler( os.path.join(LOG_DIR, app.log), maxBytes10 * 1024 * 1024, backupCount5, encodingutf-8 ) file_handler.setLevel(file_level) file_handler.setFormatter(fmt_file) logger.addHandler(file_handler) return logger这里几个关键点逐一说Logger 上的 setLevel 设成 DEBUG是为了保证所有级别的日志都有机会流向下游最终的“该不该记”决策交给 Handler 去判断。这给了你很大的灵活性——临时调整某个 Handler 的级别就能在开发和线上之间无缝切换。TimedRotatingFileHandler 的 whenmidnight 表示每天零点切割日志。backupCount30 表示只保留最近 30 个日志文件超出的自动清理磁盘不会无限膨胀。encodingutf-8 一定要显式指定尤其是 Windows 环境下否则中文日志会变成乱码。3.2 业务模块中正确使用 logger业务代码里不需要任何配置直接获取 logger 并打日志# order_service.py import logging logger logging.getLogger(myapp.order) def create_order(order_id, user_id, amount): logger.info(开始创建订单, order_id%s, user_id%s, amount%.2f, order_id, user_id, amount) try: # 模拟下单逻辑 if amount 0: raise ValueError(订单金额必须大于0) logger.debug(订单金额校验通过, amount%.2f, amount) return True except Exception: logger.exception(创建订单失败, order_id%s, order_id) return False这段代码里有几个值得展开的知识点。一是级别语义化的用法——业务节点用 INFO内部检查细节用 DEBUG出错用 exception。二是logger.info(...%s..., order_id)这种惰性格式化的用法它比logger.info(f...{order_id})性能好因为当级别不满足时f-string 仍然会执行格式化而惰性格式化完全跳过了参数拼接。再看 getLogger 的 name 参数我传的是myapp.order。这个名称和顶层myapp形成了父子关系order 这个 logger 没有显式添加 Handler它的日志会自动向上传播到myapplogger 的两个 Handler 上处理。这就是前面说的继承模型的灵活之处。想单独隔离某个特殊模块比如操作审计日志可以把这个模块的 logger 名改成独立的命名空间再单独配置# audit_logger.py import logging audit_logger logging.getLogger(audit) audit_handler logging.FileHandler(audit.log, encodingutf-8) audit_handler.setLevel(logging.INFO) audit_fmt logging.Formatter( %(asctime)s | %(message)s, datefmt%Y-%m-%d %H:%M:%S ) audit_handler.setFormatter(audit_fmt) audit_logger.addHandler(audit_handler) audit_logger.propagate Falsepropagate False 这一步极其关键。如果忘了设置审计日志会同时往 audit.log 和主日志文件里写。业务可能不介意但审计场景对“单一路径写入”有严格要求重复写入会破坏审计记录的严肃性。3.3 配置初始化入口按环境激活程序启动时需要根据运行环境选择不同的初始化方式# main.py import os import logging from log_factory import build_logger env os.getenv(APP_ENV, dev) if env prod: logger build_logger(myapp, console_levellogging.WARNING, file_levellogging.DEBUG) else: logger build_logger(myapp, console_levellogging.DEBUG, file_levellogging.DEBUG)生产环境终端不再刷 INFO 日志控制台只保留 WARNING 以上但文件里仍然保留了 DEBUG方便出问题时查上下文。这种“控制台简洁、文件完整”的模式我会在很长一段时间内继续用下去信息密度高又不怕刷屏。3.4 利用 dictConfig 实现配置与代码分离对于更大的项目推荐更进一步把配置全部放进字典或 YAML 里用 logging.config.dictConfig 加载。这样日志的调整不需要改动业务代码运维同学也能安全地改配置。一个标准的配置字典示例import logging.config LOGGING_CONFIG { version: 1, formatters: { brief: { format: %(asctime)s %(levelname)-8s %(message)s, datefmt: %H:%M:%S }, full: { format: %(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s }, }, handlers: { console: { class: logging.StreamHandler, level: DEBUG, formatter: brief, stream: ext://sys.stderr }, app_file: { class: logging.handlers.TimedRotatingFileHandler, level: INFO, formatter: full, filename: logs/app.log, when: midnight, backupCount: 30, encoding: utf-8 }, }, loggers: { myapp: { handlers: [console, app_file], level: DEBUG, propagate: False }, audit: { handlers: [app_file], level: INFO, propagate: False } } } logging.config.dictConfig(LOGGING_CONFIG)dictConfig 的好处是结构清晰formatters、handlers、loggers 三张表一目了然并且支持用ext://前缀引用外部对象比如 sys.stderr。对于要把它做成配置中心的团队来说这个方案更利于后续的集中管理和动态下发。4. 实战踩坑常见问题与排查技巧日志配置写过几年该踩的坑基本都踩过。我把印象最深的几个整理出来解决一个就可能省下好几个小时的排查时间。4.1 日志重复打印查了半天才发现是 Handler 重复挂载这个坑的出现概率极高。现象是控制台每行日志出现两遍排查思路如下先看代码里是否多次调用了 addHandler。比如某个函数里每次调用都新建一个 StreamHandler add 到 logger 上日志第一次输出时挂了一个第二次输出时挂了两个。Handler 一旦挂上不会自动移除除非显式调用 removeHandler所以重复调用初始化函数就会产生重复输出。解决方式有两种。推荐在 addHandler 之前先检查if not logger.handlers: handler logging.StreamHandler() logger.addHandler(handler)或者干脆用清空再添加的方式logger.handlers.clear() logger.addHandler(handler)第二种更稳妥在重新加载配置时会安全重置。注意logger.handlers是列表直接在末尾 append 也不推荐因为可能绕过 logging 内部的某些管理逻辑。4.2 日志级别设置了为什么还是看不到 DEBUG 信息这种问题十有八九是 Handler 级别没有同步修改。很多人只配置了 logger.setLevel(logging.DEBUG)却忘了控制台 Handler 默认级别是 WARNINGStreamHandler 默认无 Level但 root logger 默认级别是 WARNING等效于被限制。于是 logger 把 DEBUG 级别的事件生产出来了Handler 又给丢了。排查方法很直接print 出 logger 和它的每个 handler 的 levelprint(logger.level) for h in logger.handlers: print(h.level)看到数字就等于明白了。某个 Handler 的 level 是 30DEBUG 是 10肯定过不去。4.3 日志文件中文乱码编码参数被遗忘Windows 下最常见的日志问题。FileHandler 默认打开文件时用系统默认编码中文系统里通常是 GBK如果代码里没有传 encodingutf-8文件里的中文会变成乱码。这个问题在 Linux 上可能看不出来但交付给客户一旦跑在 Windows 环境就立刻暴露。配置时统一给所有文件类 Handler 加上 encodingutf-8 即可。4.4 Filter 挂在 Logger 上没有生效原因在于传播链前面提到过 Filter 的挂载位置会对行为产生显著影响。有个同学把 Filter 挂到了子 logger 上以为能拦截所有从它这里发起的日志结果日志在下层 handler 还是输出了。原因就在于 propagate 传播机制子 logger 处理完后日志事件还会继续向上层 logger 传递而上层 logger 上的 Handler 不受子 logger 上 Filter 的约束。想让某个 Key 只在某一个输出通道被过滤正确的做法是把 Filter 挂到对应的 Handler 上这和前面审计 Handler 的隔离思路是一对镜像设计。4.5 日志格式里没有打印文件行号排查时根本定位不到位置默认的 Formatter 如果不显式加%(lineno)d日志行里不会显示代码行号。排查线上问题时没有行号就像拿着地图没有坐标。我的习惯是文件 Handler 的 format 里永远包含%(filename)s:%(lineno)d和%(funcName)s。4.6 日志文件打不开文件句柄被占用Windows 环境下若 FileHandler 打开的日志文件正在被另一个进程占用比如你手动用记事本打开了它Python 会抛 PermissionError。用 TimedRotatingFileHandler 也有这个问题——切分文件时如果目标文件被占用切分失败。规避方法生产环境给日志目录设置好日志轮转的专门清理策略尽量避免人为直接打开正在写入的文件。4.7 使用 logging.getLogger(name) 时的时间陷阱__name__在模块被不同方式导入时显示的样子不同。比如直接运行时__name__等于__main__作为模块导入时是完整包名。如果只在入口处用__main__做 logger 名子模块里会有多个独立的 logger 命名空间同时存在配置就会乱套。统一在配置里指定一个项目根名各模块用相对 name 的子 logger才是可持续的路径。5. 五大组件的配合思路与实际项目参考把五大组件当作一条完整链路来看很多日志设计问题都能找到标准答案。核心路线是业务代码只发日志到 LoggerLogger 不决定任何输出目的地所有 Handler 挂在 logger 上每个 Handler 的格式和等级独立Filter 是链路中的自定义裁量点Level 在每一段都参与判断。举一个典型的 Web 服务日志实践Logger 层每个业务模块建app.modulelogger统一 DEBUG 级别。Handler 层控制台 HandlerINFO主文件 RotatingFileHandlerINFO错误文件 FileHandlerERROR三个 Handler 各就各位。Formatter 层控制台简版格式主文件和错误文件全量格式。Filter 层错误文件的 Handler 挂 Filter 检查 record.exc_info只保留真正带有异常堆栈的记录。这个方案在采集端表现很干净。错误文件专门供sentry或ELK采集不会每天被DEBUG刷爆主文件保留完整业务链路控制台面向开发人员实时输出。层次分明信息不冗余。另外生产上如果日志量极大需要考虑日志丢弃策略。比如主文件 Handler 设置内存 buffer 大小或者采用 memory handler 批量写入。这一步属于性能调优范畴但它的出发点仍然建立在五个组件的架构之上——换一条输出通道只需要换一个 Handler业务代码一行都不用改。我个人的体会是logging 这套框架越用越觉得它像项目的“信息中枢”——把各种日志流妥善有序地编排到各自的位置不只是调试工具更是观察系统运行状态的最佳入口。掌握五大组件的互动逻辑之后后续再接触 loguru、structlog 这类第三方库也能很快在对比中找到差异点知其然更知其所以然。