Python日志记录实战：从入门到生产级配置体系

我干了这么多年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(level=logging.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", encoding="utf-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按文件大小轮转。我设置maxBytes=10485760（10MB），backupCount=5，那么当日志文件写到10MB时，就会自动把当前文件重命名为app.log.1，然后新建一个app.log继续写。依次类推，app.log.1变成app.log.2，最老的app.log.5被删掉。这样磁盘上始终保持最多6个日志文件，总量不超过60MB。

TimedRotatingFileHandler按时间轮转。比如when="midnight"表示每天零点轮转一次，backupCount=7表示保留7天的日志。这种方式适合日志大小波动比较大的场景，比如某天流量爆发，一天写了50MB，另一天只写了5MB，按时间轮转可以保证保留足够长的历史周期。

实际项目中我经常把两种方案结合来考虑：大流量、日志量稳定的服务用大小轮转，因为可以精确控制磁盘占用；日志量波动大、需要按天分析历史的服务用时间轮转。不过需要注意一点，轮转不是没有代价的——轮转发生时文件要重命名、新文件要创建，这期间如果大量日志写入，可能会有短暂的性能抖动。所以轮转操作最好放在业务低谷期，或者采用定时轮转尽量减小影响。

3.2 日志格式：哪些字段值得记录，背后有什么考量

日志格式这件事，看着简单，其实讲究不少。好的日志格式是“一行日志就是一个完整的事件记录”，任何一行拿出来，你都能判断出时间、来源、级别、大致业务。我用过的日志格式里，最推荐的信息组合是：

字段	作用	示例
时间戳	定位问题发生的时间点	2025-01-15 14:03:22,185
日志级别	判断严重程度	INFO / ERROR
Logger名称	定位来源模块	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}")，如果当前日志级别是INFO，DEBUG根本不会输出，但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时设置propagate=False。这个属性控制日志事件是否向上级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_info=True：

logger.error("计算出错", exc_info=True)

效果是一样的。这个细节能帮你少走很多弯路，遇到异常第一时间拿到完整堆栈，比什么都强。

4.3 多线程环境下的日志线程安全问题

Python的logging模块自带线程锁，同一个Logger实例被多个线程同时调用时，日志消息不会交错乱掉。每一条完整的日志消息是原子的，不会出现“A线程写了一半，被B线程插进来”的情况。

但这里有个容易被忽略的坑：线程锁保证的是单行日志的完整性，不保证多行日志的顺序。比如用户下单这个操作，可能跨多个模块、多次调用logger，这几条日志虽然是同一个用户的操作，但如果A线程和B线程同时在下单，日志输出顺序可能会交错成A1、B1、A2、B2，而不是A1、A2、B1、B2。排查问题时，这种交错会让“还原单个请求的完整流程”变得很难受。

解决办法有两个思路：

• 一是引入请求ID（trace_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(name="app", log_file="app.log", level=logging.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, datefmt=datefmt)) # 文件Handler，大小轮转 file_handler = RotatingFileHandler( log_file, maxBytes=10 * 1024 * 1024, backupCount=5, encoding="utf-8" ) file_handler.setLevel(logging.DEBUG) file_handler.setFormatter(logging.Formatter(fmt, datefmt=datefmt)) 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模块看着简单，真正用好它，靠的是对业务的理解、对排查需求的预判，以及对细节的打磨。希望这篇文章能帮你把日志从“会打”提升到“打得规范、打得有用”的水平。