1. 为什么你的项目需要一个正经的日志系统刚入行那会儿我排查线上问题全靠print。代码里到处散落着print(到这里了)、print(值为, x)上线前再手忙脚乱地注释掉。结果真出问题时日志文件里干干净净只能靠猜。后来接手一个稍微复杂点的服务模块之间互相调用一个请求链路跨了七八个文件print出来的东西混在一起根本分不清哪条是哪个请求打的。那次事故排查花了整整一个通宵从那以后我就老老实实把logging模块啃了一遍。logging是 Python 标准库自带的日志记录模块不用装任何第三方包开箱即用。它能干的事情比print多得多可以按级别过滤信息、可以把日志同时输出到控制台和文件、可以按时间自动切割日志文件、可以自定义格式带上时间戳和模块名、还能通过配置文件统一管理。说白了print是给开发者自己看的临时输出而logging是给整个项目用的基础设施。这篇文章适合谁看如果你还在用print调试代码或者虽然用了logging但只是logging.info(xxx)一把梭那这篇内容应该能帮你少走不少弯路。我会从设计思路讲到实操配置再到踩过的坑尽量把每个决策背后的原因说清楚。全文基于我这些年做后端服务和数据处理项目的实际经验代码可以直接抄作业。2. 日志系统的整体设计思路拆解2.1 为什么不用 print 而用 logging很多人觉得print挺方便的为什么要多此一举我举个例子你就明白了。假设你写了一个数据处理脚本跑一次要两个小时。你在关键节点打了print结果跑到一半报错了。这时候你想看看到底是哪一步出的问题但print的输出全在终端里终端缓存有限前面的信息可能已经被冲掉了。而且你没法控制哪些信息该显示、哪些不该显示调试信息和生产信息混在一起。logging解决的核心问题是分级管理和多目标输出。它把日志分成五个级别DEBUG、INFO、WARNING、ERROR、CRITICAL。你可以设置一个阈值比如生产环境只记录 WARNING 以上的开发环境记录 DEBUG 以上的。这样同一套代码在不同环境下自动调整输出粒度不用改代码。同时日志可以同时往控制台、文件、甚至远程服务器发一份日志多处消费。还有一个容易被忽略的点logging是线程安全的。多线程环境下用print可能会出现输出交错的情况而logging内部有锁机制保证每条日志完整输出。这个在做并发任务的时候特别重要。2.2 四个核心组件的关系logging模块的设计遵循了一个经典的责任链模式核心就四个东西Logger、Handler、Formatter、Filter。理解它们之间的关系后面配置起来就不会晕。Logger 是你要调用的入口比如logging.getLogger(__name__)。它负责接收日志记录然后决定要不要往下传。每个 Logger 有一个级别低于这个级别的日志直接被丢弃。Logger 还可以有父子关系子 Logger 的日志会向上传递给父 Logger 的 Handler 处理。Handler 决定日志往哪里去。一个 Logger 可以挂多个 Handler比如一个往控制台输出一个往文件写。每个 Handler 也有自己的级别可以实现“控制台只看 ERROR文件里记全部”这种效果。Formatter 决定日志长什么样。你可以定义时间格式、是否显示模块名、是否显示行号等等。同一个 Handler 只能绑一个 Formatter但不同 Handler 可以用不同的 Formatter。Filter 是一个更细粒度的过滤器可以基于日志内容做过滤比如只记录某个用户 ID 的日志。这个用得相对少一些但在复杂系统里很有用。提示Logger 的级别和 Handler 的级别是两回事。Logger 级别决定“要不要处理这条日志”Handler 级别决定“处理到什么程度”。实际生效的是两者中更严格的那个。2.3 日志级别怎么选才合理我见过很多项目日志级别用得乱七八糟。DEBUG 和 INFO 混着用WARNING 当 ERROR 打。这里说一下我的习惯不一定标准但实践中比较好用。DEBUG 是给开发阶段用的记录变量值、函数进出、循环次数这类信息。生产环境一般关掉因为量太大。INFO 记录正常的业务流程节点比如“用户登录成功”、“订单创建完成”、“任务开始执行”。这些信息在生产环境是要保留的用来追踪业务流转。WARNING 表示出现了预期之外但不影响主流程的情况比如“缓存未命中回源查询”、“配置文件缺少某项使用默认值”。ERROR 表示功能受损比如“数据库连接失败”、“第三方接口返回异常”。CRITICAL 表示整个服务不可用比如“磁盘写满”、“核心依赖全部超时”。一个常见的误区是把所有异常都打成 ERROR。其实像用户输入格式不对这种打 WARNING 就够了因为这是预期内的情况。真正的 ERROR 应该是需要人工介入的问题。3. 核心配置细节与实操要点3.1 最简可用的配置模板先给一个我平时最常用的配置模板直接复制就能跑。这个模板同时输出到控制台和文件文件按天切割保留 30 天。import logging from logging.handlers import TimedRotatingFileHandler import os def setup_logger(name, log_dirlogs, levellogging.INFO): os.makedirs(log_dir, exist_okTrue) logger logging.getLogger(name) logger.setLevel(level) if logger.handlers: return logger fmt logging.Formatter( %(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s, datefmt%Y-%m-%d %H:%M:%S ) console_handler logging.StreamHandler() console_handler.setLevel(logging.INFO) console_handler.setFormatter(fmt) file_handler TimedRotatingFileHandler( os.path.join(log_dir, f{name}.log), whenmidnight, interval1, backupCount30, encodingutf-8 ) file_handler.setLevel(logging.DEBUG) file_handler.setFormatter(fmt) logger.addHandler(console_handler) logger.addHandler(file_handler) return logger用的时候这样调logger setup_logger(myapp) logger.info(服务启动完成) logger.error(数据库连接失败)这个模板有几个设计考虑。if logger.handlers: return logger这行是为了防止重复添加 Handler。如果你在多个模块里调用setup_logger不加这个判断会导致日志重复输出。TimedRotatingFileHandler的whenmidnight表示每天零点切割backupCount30表示保留最近 30 个文件。encodingutf-8一定要加不然中文日志在 Windows 上会乱码。3.2 日志格式里该放什么信息格式字符串里的字段决定了你排查问题时能拿到多少线索。我建议至少包含这几个时间戳、级别、Logger 名称、文件名和行号、消息内容。%(asctime)s是时间%(levelname)s是级别%(name)s是 Logger 名称通常用__name__传入就是模块路径%(filename)s和%(lineno)d是出日志的文件和行号。有了行号定位问题快很多不用全局搜索日志内容。%(levelname)-8s里的-8表示左对齐占 8 个字符宽度这样不同级别的日志对齐好看。%(message)s是日志正文。还有一个字段%(process)d和%(thread)d在多进程或多线程环境里很有用能区分日志来源。但如果你用的是异步框架线程 ID 可能不太准这个要注意。注意%(lineno)d在有些情况下会显示成 0 或者不准确比如日志调用被包装在装饰器里的时候。这是 Python 的已知行为不是配置问题。3.3 按时间切割还是按大小切割TimedRotatingFileHandler按时间切割RotatingFileHandler按文件大小切割。怎么选如果你的服务流量比较稳定每天日志量差不多用按时间切割。好处是找日志方便直接按日期定位文件。如果流量波动大某天突然爆量按时间切割可能导致单个文件巨大打开都费劲。这时候用按大小切割更合适比如每个文件 100MB写满就换下一个。我一般用按时间切割因为排查问题时通常知道大概的时间范围按日期找文件最直观。但如果你的服务是突发性的批处理任务建议用按大小切割避免一个任务产生一个超大文件。TimedRotatingFileHandler的when参数支持S秒、M分、H小时、D天、midnight每天零点。interval是间隔数比如whenH, interval6就是每 6 小时切割一次。3.4 用 dictConfig 统一管理配置当项目变大代码里到处addHandler会很难维护。这时候用logging.config.dictConfig把配置抽出来放在一个字典或者 YAML 文件里。import logging.config LOGGING_CONFIG { version: 1, disable_existing_loggers: False, formatters: { standard: { format: %(asctime)s | %(levelname)-8s | %(name)s | %(message)s, datefmt: %Y-%m-%d %H:%M:%S }, detailed: { format: %(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s } }, handlers: { console: { class: logging.StreamHandler, level: INFO, formatter: standard, stream: ext://sys.stdout }, file: { class: logging.handlers.TimedRotatingFileHandler, level: DEBUG, formatter: detailed, filename: logs/app.log, when: midnight, backupCount: 30, encoding: utf-8 } }, loggers: { myapp: { level: DEBUG, handlers: [console, file], propagate: False } }, root: { level: WARNING, handlers: [console] } } logging.config.dictConfig(LOGGING_CONFIG) logger logging.getLogger(myapp)disable_existing_loggers: False这个很重要。默认情况下dictConfig会禁用所有已存在的 Logger这可能导致第三方库的日志丢失。设成 False 就保留它们。propagate: False表示这个 Logger 的日志不再向上传递给父 Logger。如果你不设这个日志可能会被 root Logger 的 Handler 再处理一遍导致重复输出。4. 完整实操流程与关键环节实现4.1 从零搭建一个带日志的项目骨架假设你要写一个数据处理服务目录结构大概是这样myproject/ ├── config/ │ └── logging.yaml ├── src/ │ ├── __init__.py │ ├── main.py │ ├── processor.py │ └── utils.py └── logs/第一步写logging.yamlversion: 1 disable_existing_loggers: false formatters: standard: format: %(asctime)s | %(levelname)-8s | %(name)s | %(message)s datefmt: %Y-%m-%d %H:%M:%S detailed: format: %(asctime)s | %(levelname)-8s | %(name)s | %(filename)s:%(lineno)d | %(message)s handlers: console: class: logging.StreamHandler level: INFO formatter: standard stream: ext://sys.stdout file: class: logging.handlers.TimedRotatingFileHandler level: DEBUG formatter: detailed filename: logs/app.log when: midnight backupCount: 30 encoding: utf-8 loggers: myproject: level: DEBUG handlers: [console, file] propagate: false root: level: WARNING handlers: [console]第二步在main.py里加载配置import logging.config import yaml import os def init_logging(): os.makedirs(logs, exist_okTrue) with open(config/logging.yaml, r, encodingutf-8) as f: config yaml.safe_load(f) logging.config.dictConfig(config) if __name__ __main__: init_logging() logger logging.getLogger(myproject) logger.info(项目启动)第三步在其他模块里直接用logging.getLogger(__name__)获取 Logger。因为__name__会带上模块路径比如myproject.processor它会自动继承myproject这个 Logger 的配置。import logging logger logging.getLogger(__name__) def process_data(data): logger.debug(开始处理数据长度%d, len(data)) try: result [x * 2 for x in data] logger.info(数据处理完成结果长度%d, len(result)) return result except Exception as e: logger.exception(数据处理失败) raiselogger.exception会自动把异常堆栈打出来比logger.error多一个 traceback。这个在排查异常时特别有用。4.2 日志切割的验证方法配置好切割之后怎么验证它真的在工作你不可能等一天。可以把when改成Sinterval改成 5然后写个循环快速打日志观察文件是否按预期生成。import logging import logging.config import time logging.config.dictConfig({ version: 1, handlers: { file: { class: logging.handlers.TimedRotatingFileHandler, filename: logs/test.log, when: S, interval: 2, backupCount: 5, encoding: utf-8 } }, root: {level: INFO, handlers: [file]} }) logger logging.getLogger() for i in range(20): logger.info(测试日志 %d, i) time.sleep(0.5)跑完之后看logs/目录应该能看到test.log和test.log.2024-01-01_12-00-00这样的文件。确认没问题再把参数改回生产配置。提示TimedRotatingFileHandler的切割是在写入时触发的不是定时器触发的。也就是说如果两小时内没有日志写入切割不会发生直到下一条日志进来才判断是否需要切割。这个行为在排查“为什么文件没切割”时经常被忽略。4.3 多进程环境下的日志处理多进程写同一个日志文件是个经典难题。logging的 Handler 不是进程安全的多个进程同时写一个文件可能导致日志丢失或交错。解决方案有几个。最简单的是每个进程写自己的文件文件名带上进程 IDimport os import logging from logging.handlers import TimedRotatingFileHandler def setup_multiprocess_logger(name): logger logging.getLogger(name) logger.setLevel(logging.DEBUG) if logger.handlers: return logger pid os.getpid() handler TimedRotatingFileHandler( flogs/{name}_{pid}.log, whenmidnight, backupCount7, encodingutf-8 ) handler.setFormatter(logging.Formatter( %(asctime)s | %(levelname)s | %(process)d | %(message)s )) logger.addHandler(handler) return logger另一个方案是用QueueHandler和QueueListener把日志先写到一个队列里由一个单独的进程负责写文件。这个方案更优雅但配置复杂一些。如果你的项目用multiprocessing可以考虑这个方案。import logging import logging.handlers import multiprocessing def listener_process(queue): handler logging.FileHandler(logs/app.log, encodingutf-8) handler.setFormatter(logging.Formatter( %(asctime)s | %(levelname)s | %(message)s )) listener logging.handlers.QueueListener(queue, handler) listener.start() try: while True: pass except KeyboardInterrupt: listener.stop() if __name__ __main__: queue multiprocessing.Queue() listener multiprocessing.Process(targetlistener_process, args(queue,)) listener.start() handler logging.handlers.QueueHandler(queue) root logging.getLogger() root.addHandler(handler) root.setLevel(logging.INFO) logger logging.getLogger(myapp) logger.info(来自主进程的日志)这个方案的核心思想是“写日志的进程不直接碰文件只往队列里丢”。队列本身是进程安全的所以不会出现写冲突。4.4 日志性能优化的几个手段日志本身是有开销的尤其是 DEBUG 级别。如果代码里有大量logger.debug(fxxx {var})即使生产环境关了 DEBUG字符串格式化还是会执行白白浪费 CPU。正确的做法是用惰性格式化logger.debug(处理数据%s, data)而不是logger.debug(f处理数据{data})前者只有在日志真正要输出时才会做字符串拼接后者无论日志级别如何都会先拼好字符串。这个差别在高频日志场景下非常明显。另一个优化手段是调整 Logger 级别。生产环境把级别设成 INFO 或 WARNINGDEBUG 日志直接不处理。还可以用logging.disable(logging.DEBUG)全局禁用某个级别。如果日志量特别大可以考虑异步写日志。QueueHandler本身就是一种异步方案写日志的线程只负责往队列丢不等待磁盘 IO。对于 IO 密集型的服务这个提升很明显。5. 常见问题与排查技巧实录5.1 日志重复输出的原因和解决这是新手最常遇到的问题明明只调了一次logger.info控制台却打了两遍。原因通常是 Logger 的propagate属性没关或者重复添加了 Handler。如果你用logging.getLogger(myapp)获取 Logger然后给它加了 Handler同时 root Logger 也有 Handler那么日志会先在myapp的 Handler 处理一遍再向上传递给 root 的 Handler 处理一遍。解决办法有两个一是设置logger.propagate False二是不要给子 Logger 加 Handler统一用 root Logger 的 Handler。我一般用第一种因为更灵活。还有一种情况是模块被重复导入导致setup_logger被调用多次。这时候if logger.handlers: return logger这个判断就派上用场了。5.2 日志文件不切割的排查思路配置了TimedRotatingFileHandler但文件一直不切割先检查这几个点。第一确认when和interval设置正确。whenmidnight是每天零点切割如果你在零点之后启动服务第一次切割要等到第二天零点。第二确认有日志写入。前面说过切割是写入触发的没有写入就不会切割。第三检查文件权限。如果日志目录没有写权限切割会失败但可能不报错。第四看backupCount设置。如果设成 0旧文件会被立即删除看起来就像没切割。还有一个坑TimedRotatingFileHandler在计算切割时间时用的是本地时间如果你的服务器时区设置不对切割时间会偏移。5.3 中文日志乱码的处理中文乱码通常是因为文件编码没设对。FileHandler和TimedRotatingFileHandler都有encoding参数一定要设成utf-8。如果不设Python 会用系统默认编码在 Windows 上就是 GBK在 Linux 上可能是 ASCII都会导致中文乱码。handler logging.FileHandler(logs/app.log, encodingutf-8)控制台输出乱码的话检查终端的编码设置。Windows 的 cmd 默认是 GBK可以用chcp 65001切换到 UTF-8。或者用 Windows Terminal默认就是 UTF-8。5.4 日志级别不生效的几种情况设了logger.setLevel(logging.DEBUG)但 DEBUG 日志还是不出来检查这几个地方。首先Handler 的级别。如果 Handler 级别是 INFO即使 Logger 级别是 DEBUGDEBUG 日志也会被 Handler 过滤掉。其次root Logger 的级别。如果你用的是子 Logger但没设propagateFalse日志会传给 rootroot 的级别也会影响。第三第三方库可能修改了全局的 logging 配置。有些库在导入时会调用logging.basicConfig()这会覆盖你的配置。解决办法是在导入第三方库之前先初始化自己的日志配置。5.5 常见问题速查表问题现象可能原因解决方法日志重复输出propagate 未关闭或 Handler 重复添加设 propagateFalse加 Handler 前判断文件不切割无日志写入或参数错误检查 when/interval确认有日志产生中文乱码编码未设置Handler 加 encodingutf-8DEBUG 不输出Handler 或 root 级别限制检查所有层级的 level 设置日志丢失多进程写同一文件每进程独立文件或用 QueueHandler性能差用了 f-string 格式化改用惰性格式化 %s行号显示 0日志调用被装饰器包装用 stacklevel 参数调整提示logger.info(msg, stacklevel2)可以让行号指向调用者的位置而不是日志封装函数的位置。这个在写日志工具函数时很有用。5.6 几个我踩过的坑第一个坑在__init__.py里调用logging.basicConfig()。这会导致所有模块的日志都走 root Logger 的配置子 Logger 的配置全部失效。而且basicConfig只能生效一次第二次调用会被忽略。我现在的习惯是永远不用basicConfig全部用dictConfig。第二个坑日志文件路径用了相对路径。在开发环境没问题部署到服务器上用 systemd 启动时工作目录变了日志文件就跑到别的地方去了。解决办法是用绝对路径或者基于__file__计算路径。import os BASE_DIR os.path.dirname(os.path.abspath(__file__)) LOG_DIR os.path.join(BASE_DIR, logs)第三个坑忘了给日志目录建文件夹。FileHandler不会自动创建目录如果logs/不存在会直接报FileNotFoundError。所以初始化日志之前先os.makedirs(log_dir, exist_okTrue)。第四个坑在日志里打了敏感信息。比如用户密码、token、身份证号。这些一旦写进日志文件就很难清理。建议在日志工具里加一层脱敏处理或者至少在上线前全局搜索一下日志调用确认没有敏感字段。5.7 日志监控与告警的衔接日志写出来只是第一步更重要的是怎么用。生产环境一般会把日志收集到集中式平台比如用 Filebeat 采集文件发到 Elasticsearch再用 Kibana 做可视化。这时候日志格式的规范性就很重要了最好是 JSON 格式方便解析。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)用 JSON 格式之后可以直接在日志平台里按字段搜索和聚合。比如统计某个时间段内 ERROR 日志的数量或者按模块分组看日志分布。这些在排查系统性问题时非常有用。告警方面可以设置规则比如 5 分钟内 ERROR 日志超过 10 条就发通知。这个一般在日志平台侧配置不需要在代码里做。但代码里要保证 ERROR 日志打得准确不要滥用。6. 一些进阶用法和个人体会6.1 用 LoggerAdapter 注入上下文信息在 Web 服务里经常需要在每条日志里带上请求 ID方便追踪一个请求的完整链路。用LoggerAdapter可以优雅地实现这个需求。import logging import uuid class RequestAdapter(logging.LoggerAdapter): def process(self, msg, kwargs): return f[{self.extra[request_id]}] {msg}, kwargs def handle_request(): request_id str(uuid.uuid4())[:8] logger RequestAdapter(logging.getLogger(myapp), {request_id: request_id}) logger.info(开始处理请求) logger.info(请求处理完成)这样每条日志都会带上请求 ID排查问题时直接搜 ID 就能看到完整链路。比在每个日志调用里手动拼 ID 优雅多了。6.2 捕获 warnings 模块的输出Python 的warnings模块和logging是两套体系。有些第三方库用warnings.warn发警告这些警告默认输出到 stderr不会进你的日志文件。可以用logging.captureWarnings(True)把它们重定向到 logging。import logging logging.captureWarnings(True)开启之后warnings.warn的输出会以 WARNING 级别进入 logging 系统统一管理。6.3 我个人的一些使用习惯我一般会在项目里建一个logger.py或者log_config.py把日志初始化封装成一个函数在程序入口调用一次。其他模块只负责logging.getLogger(__name__)不碰任何配置。这样职责清晰改配置只需要改一个地方。日志级别方面开发环境用 DEBUG测试环境用 INFO生产环境用 INFO 或 WARNING。具体看业务如果业务对排查要求高生产也用 INFO。但 DEBUG 一定要关不然日志量会爆炸。文件保留时间方面我一般设 30 天。太短了不够排查历史问题太长了占磁盘。如果合规要求更长时间可以设 90 天或 180 天但要配合磁盘监控。最后说一个容易被忽略的点日志本身也是代码的一部分需要 review。我见过太多项目日志打得随意关键路径没日志不重要的地方刷屏。建议在 code review 的时候把日志也过一遍确认关键节点有 INFO异常分支有 ERROR调试信息用 DEBUG。这个内容后续还可以这样扩展结合 OpenTelemetry 做分布式追踪把日志、指标、链路三者关联起来或者用结构化日志配合日志分析平台做实时告警。不过那是另一个话题了先把基础的 logging 用扎实后面再往上叠。