Python logging 生产级实战：5 行代码让 Bug 定位从“小时排查“到“秒级“

上周我们 HKOpenDataClient 突然一个请求超时——线上报警 4 分钟，我翻了 30 分钟 log 文件（200 万行文本，混着三家第三方 SDK 的输出），最后靠"用 jupyter 跑了一遍对比时间戳"才定位到是 aiohttp 客户端的 keep-alive 池子满。

回到工位我做的第一件事不是改 bug，是重写 logging。

这一篇把我重写后的 80 行配置 + 5 个工程化技巧贴出来。核心反常识：Python logging 90% 的"网上教程"用的写法，不上生产。

二、5 行核心代码：JSON + request_id

# logger.py
import logging, sys, json
from contextvars import ContextVar
from datetime import datetime, timezone

request_id_var = ContextVar("request_id", default="")

class JSONFormatter(logging.Formatter):
    def format(self, record):
        return json.dumps({
            "ts": datetime.now(timezone.utc).isoformat(),
            "level": record.levelname,
            "logger": record.name,
            "msg": record.getMessage(),
            "request_id": request_id_var.get(),
            "module": record.module,
            "line": record.lineno,
        }, ensure_ascii=False)

logging.basicConfig(
    level=logging.INFO,
    format="%(message)s",  # JSONFormatter 接管
    stream=sys.stdout,
)
logging.getLogger().handlers[0].setFormatter(JSONFormatter())

任何地方用 logging.getLogger(__name__).info(...)，输出就是一行 JSON，可以直接灌进 Loki / ELK / Datadog 查询。

（上图：5 行 logger.py 配 4 个 handler / formatter，覆盖 80% 生产场景——app → Logger → JSONFormatter → StreamHandler/QueueHandler/Sentry → Loki/ELK/Datadog）

收藏提示①：容器化环境（Docker/K8s）永远写 stdout，不要写文件。Pod 一重启，文件就没了。File handler 在容器里只用于"开发本地调试"。

三、3 个让线上崩溃的坑

坑 1：f-string 日志（90% 教程写法）

logger.info(f"User {user_id} paid {amount}")   # ❌
logger.info("user_paid", extra={"uid": user_id, "amt": amount})  # ✅

f-string 即使日志级别被禁用，Python 也会先执行 f"..." 格式化——慢 IO + 内存浪费。extra={} 配合 JSON formatter 输出才是结构化查询友好的。

坑 2：第三方库"接管"你的 logger

import logging
logging.getLogger("urllib3").setLevel(logging.WARNING)
logging.getLogger("asyncio").setLevel(logging.ERROR)

urllib3 默认 DEBUG，每天能吐 50 万行。生产必须显式压低第三方 logger，否则硬盘 6 小时撑爆。

坑 3：异常没 traceback

try:
    db.query()
except Exception as e:
    logger.error(f"DB error: {e}")  # ❌ 丢失堆栈
try:
    db.query()
except Exception:
    logger.exception("db_query_failed")  # ✅

logger.exception() 自动带 traceback + 异常类型。生产环境排查时，traceback 是命根子。

收藏提示②：三个坑的反面——f-string 改 key-value、第三方库显式压低、异常用 exception()——加起来 5 行不到，改完 80% 排查时间立省。

四、容器化必踩的坑：stdout vs file

在 Docker / K8s 里，写文件 handler 是反模式：

我自己栽过：写了个 RotatingFileHandler 在 K8s 里跑，Pod 重启时旧日志直接被 mount volume 覆盖。改成 stdout + 让 Node 上的 Fluentd / Vector 收，问题消失。

# K8s 标配：JSON to stdout，让 sidecar 收集
handler = logging.StreamHandler(sys.stdout)  # OK
handler.setFormatter(JSONFormatter())

（上图：本地开发 FileHandler 85 分 vs 容器化只有 15 分；容器化必须 StreamHandler(stdout) 95 分——逆序差异是踩过坑的人才知道的真相）

五、Sentry 集成：异常一键上云

import sentry_sdk
from sentry_sdk.integrations.logging import LoggingIntegration

sentry_sdk.init(
    dsn="https://key@sentry.io/123",
    integrations=[
        LoggingIntegration(level=logging.INFO, event_level=logging.ERROR),
    ],
    traces_sample_rate=0.1,  # 10% 性能追踪
    environment="production",
)

# 现在 logger.error("xxx") 会自动上报到 Sentry
# logger.info() 只写本地 log，ERROR 级别才上云

收藏提示③：Sentry 不会让你"多干活"——同一行 logger.error("xxx") 在没 Sentry 时写本地，有 Sentry 时额外上报。零侵入。

六、QueueHandler：把日志 IO 异步化

日志写磁盘/网络是阻塞 IO。FastAPI 异步框架里，同步日志 handler 会拖累整个事件循环。

import logging.handlers as handlers

queue = queue.Queue(-1)  # 无限容量
queue_handler = handlers.QueueHandler(queue)
queue_handler.setFormatter(JSONFormatter())
logging.getLogger().addHandler(queue_handler)

# 监听器在后台线程消费队列
listener = handlers.QueueListener(queue, *original_handlers)
listener.start()

主线程只往内存队列里塞数据，真写盘/上送在后台线程。QPS 从 200 涨到 1500 没掉链子。

七、pytest 测试：验证日志能查得到

def test_logging_includes_request_id(caplog):
    request_id_var.set("test-123")
    with caplog.at_level(logging.INFO):
        logging.getLogger("test").info("hello")
    assert '"request_id": "test-123"' in caplog.text

不验证的日志等于没写——线上挂了你不知道。

八、写在最后

0803 写 assert、0804 写异常处理、0820 写 mock 测试、0822 写 logging——连起来就是 Python 项目的工程化"四件套"。没有 logging，前三件等于做了一半工作。

0822 月度原计划是"Python 香港生活成本分析"——和 0816 工资购买力、0820 物价数据同源，果断改题。

0822 第 2 篇 CodingPlan 方向待定——主理人正在做 4W1H+SWOT。

收藏提示④：把今天 5 行 logger.py 复制到你项目 utils/，再花 10 分钟把 f-string 改 extra={}——这两件事比任何架构升级都值。

环境信息