日志要能追：结构化日志直觉

本文目录

线上报错时用户只给订单号，你在 Kibana 里搜 ERROR 跳出上万行——同名函数、不同请求缠在一起，根本对不上是哪次 HTTP 调用。日志的价值不在「多打几行 print」，而在**事后能追踪**：同一请求从进 middleware 到 Service 到 SQL，共享同一 request_id；字段机器可读，才方便按用户、路径、耗时过滤。这就是 结构化 logging 要解决的，与换不换 loguru 无关，核心是字段设计。

好的日志像飞行黑匣子：平时不显山露水，出事时能还原时间线。FastAPI 项目请求短、并发高，更需要约定字段，而不是依赖开发者临场发挥写 f-string。

非结构化 vs 结构化

python

logger.info(f"created order {order_id} for user {user_id}")

人眼能读，机器难稳定解析：user= 还是 user_id:？结构化 用固定键：

python

logger.info(
    "order_created",
    extra={"order_id": order_id, "user_id": user_id, "amount": total},
)

若 formatter 输出 JSON，一行即一条记录，ELK、Loki、CloudWatch 都能按 order_id 精确查。追踪依赖这些键，而不是 grep 子字符串。

消息与字段分离

结构化 实践里，message 宜短且稳定（如 order_created），变量放 extra 字段。这样在仪表盘里按 message 聚合不会 explosion；按 order_id 过滤仍精确。中文描述可以放在 detail 字段，但键名保持英文 snake_case，方便跨团队脚本。

标准库 logging 足够起步

不必一上来引入 heavy 依赖。在 lifespan 启动时配置 root logging：

python

import json
import logging
from datetime import UTC, datetime


class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> dict[str, object]:
        payload: dict[str, object] = {
            "ts": datetime.now(UTC).isoformat(),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        if hasattr(record, "request_id"):
            payload["request_id"] = record.request_id
        for key in ("user_id", "path", "duration_ms"):
            if hasattr(record, key):
                payload[key] = getattr(record, key)
        return json.dumps(payload, ensure_ascii=False)


def setup_logging(level: str = "INFO") -> None:
    handler = logging.StreamHandler()
    handler.setFormatter(JsonFormatter())
    root = logging.getLogger()
    root.handlers.clear()
    root.addHandler(handler)
    root.setLevel(level)

业务模块：

python

logger = logging.getLogger(__name__)

第三方库默认 logger 名通常是包名；你可以把 uvicorn.access 的 handler 也挂到同一 JsonFormatter，避免 access 行与应用行格式分裂。loguru 等库若团队已统一，也可输出 JSON 行，原则相同：启动时一次配置，业务只打字段。

request_id：串起一次请求

中间件（或纯 ASGI 中间件）在入口生成 UUID，写入 contextvars 与响应 Header：

python

import contextvars
import uuid
from collections.abc import Callable

from starlette.middleware.base import BaseHTTPMiddleware
from starlette.requests import Request
from starlette.responses import Response

request_id_ctx: contextvars.ContextVar[str] = contextvars.ContextVar("request_id", default="")


class RequestIdMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request: Request, call_next: Callable) -> Response:
        rid = request.headers.get("X-Request-Id") or str(uuid.uuid4())
        token = request_id_ctx.set(rid)
        try:
            response = await call_next(request)
            response.headers["X-Request-Id"] = rid
            return response
        finally:
            request_id_ctx.reset(token)


def log_extra(**fields: object) -> dict[str, object]:
    extra: dict[str, object] = {"request_id": request_id_ctx.get()}
    extra.update(fields)
    return extra

Service 里：

python

logger.info("inventory_reserved", extra=log_extra(sku=sku, qty=qty))

同一 HTTP 请求内所有日志带相同 request_id，排障时按 id 拉全链。追踪再上一级可对接 OpenTelemetry trace_id，与 request_id 互填字段即可。

在中间件里记录 access 摘要

除业务日志外，可在 middleware 出口打一行 access 摘要：method、path、status_code、duration_ms，同样带 request_id。用户报「刚才下单失败」时，用 request_id（响应 Header 可回传）串起 access 行与 Service 内 order_created / domain_error 行，比只看 Uvicorn 默认 access 更齐。

contextvars 与 async

contextvars 在 async def 路由里随 Task 传播，子 Task 默认继承 request_id。若用 asyncio.create_task fire-and-forget 后台作业，应显式传入 request_id 或在任务开头 request_id_ctx.set(...)，否则后台日志会丢链。

记什么、不记什么

建议记录	避免
请求 method、path、status、duration_ms	完整 Authorization Header
业务 id：order_id、payment_ref	密码、完整 PAN
异常类型与 message（非完整堆栈到 INFO）	巨型 body

logging 级别：生产默认 INFO；DEBUG 仅短期开。Uvicorn access 日志可与应用日志同一 JSON 格式，避免两套解析规则。

采样与体量

高 QPS 下全量 DEBUG 会拖垮磁盘与采集成本。可以对健康检查路径降级或不打 body；对重复成功的读接口只打 access 一行。ERROR 与 WARNING 尽量全量保留，并带 request_id 与关键业务 id。

与异常处理配合

统一异常处理器里打 结构化 错误日志，再返回统一 JSON 体：

python

@app.exception_handler(DomainError)
async def domain_error_handler(request: Request, exc: DomainError) -> JSONResponse:
    logger.warning(
        "domain_error",
        extra=log_extra(code=exc.code, detail=str(exc), path=request.url.path),
    )
    return JSONResponse(status_code=400, content={"code": exc.code, "detail": str(exc)})

客户端只看到 detail；你在后台用 request_id 关联 warning 行与 access 日志。

未捕获的 500 在全局 handler 里 logger.exception(...)，自动带 stack trace；返回给客户端的 body 仍应脱敏，不把内部路径或 SQL 透出。追踪靠服务端日志字段，不靠把堆栈塞进 JSON 响应。

开发环境可读性

本地可把 JsonFormatter 换成彩色 console format；通过 Settings.debug 切换。原则不变：字段键名与生产一致，避免「本地能搜、上线不能搜」。

也可以在开发环境 human-readable、生产 JSON，但 extra 键集合保持一致。新人本地读彩色行，上线后用同一套键名写查询，迁移成本更低。

常见误解

误解 1：print 调试够用了。无级别、无 request_id、无集中采集，多进程下 stdout 交错更难追踪。

误解 2：每条日志打完整 stack。ERROR 带 traceback 合理；INFO 应短。堆栈交给 logger.exception 在 except 块用。

误解 3：日志在 import 时配置。应在 lifespan 启动调 setup_logging()，并读 Settings 的 log_level，与配置篇一致。

排障故事：三键定位

假设用户反馈「支付后订单仍 pending」。你手里有支付时间与大略路径 /orders/123/pay。操作顺序可以是：

在日志系统按 path:/orders/123/pay 与时间窗筛 access 行，取出 request_id。
用同一 request_id 搜 domain_error、payment_callback、order_status_changed 等 结构化 message。
若缺上下文，再按 order_id:123 跨 request_id 关联回调与首次下单。

若没有 request_id 与固定 message 键，同一订单的多步操作会散在几十万行里，追踪变成人工猜。日志设计要在写代码时就想好「出事按什么键搜」。

中间件记录的 duration_ms 还能区分慢在外部支付还是慢在 SQL——配合事务篇看连接持有，常能发现边界画错导致的隐性长事务。

与中间件、异常处理的字段一致

访问日志的 path、method 应与异常 handler 里 log_extra(path=...) 使用同一键名。Service 层打业务日志时优先带 order_id、user_id 等业务主键，而不是只打中文句子——中文留给 detail 字段 optional。这样追踪链路从 edge 到 core 字段可对齐，仪表盘一条 JSON 解析规则吃全站。

loguru 与标准库并存

团队若已用 loguru，可用 logger.bind(request_id=...).info("event", key=value) 达到同类 结构化 效果；关键是启动时统一 sink 到 stdout JSON，而不是默认彩色 human format 上线。logging 标准库与 loguru 选型不冲突，冲突的是「有无固定字段、有无 request_id」——先统一字段契约，再谈库。

性能：异步路径少打

async def 路由里同步写盘日志会阻塞 event loop；高 QPS 时日志 handler 应是非阻塞或批量 flush。开发环境同步 stdout 足够；生产 JSON 行到 stdout 由采集 agent 负责，应用侧避免在 hot path 打 DEBUG 字符串拼接。

关联 request_id 与用户

在认证通过后，middleware 或 get_current_user 下游可把 user_id bind 进日志 context（与 request_id 并列）。排障「某用户连续失败」时可按 user_id 聚合，而不只靠 request_id 单条链。注意隐私合规：日志保留周期与脱敏策略由公司政策定，技术上是字段设计问题。

采样 trace 与 DEBUG

短期排查可在 Settings 里对特定用户或路径开 DEBUG，仍走 结构化 输出。全站长期 DEBUG 不可持续；与配置篇联动，用 feature flag 控制 verbose 日志，避免改代码重启。

correlation 与下游调用

Service 调外部 HTTP 时，把 request_id 放进 outbound Header（如 X-Request-Id），下游服务日志可对齐全链路。这是追踪的延伸，不依赖特定 APM 厂商；与导购调外部服务的场景直接相关。

写日志时养成习惯：message 用英文 snake_case 事件名，业务 id 放 extra，一条一行 JSON。几个月后你会感谢现在的自己——结构化 logging 是运维友好的最低成本投资。

access 中间件一行、业务事件一行、异常 handler 一行——同一 request_id 三条记录，足以还原绝大多数请求故事。先把这三处打通，再考虑引入 trace 系统也不迟。

日志级别约定：生产 INFO 起；WARN 表业务可恢复异常；ERROR 表需人介入。统一语义后，告警规则才好配。

middleware 里记录的 status_code 与异常 handler 的 level 应对齐：用户输入错误多用 WARN，未捕获异常用 ERROR 并 logger.exception。

上线前用一次 staging 故障注入（故意抛 DomainError 与 500），确认日志系统能按 request_id 拉齐 access 与业务行——比写多少条规范更有说服力。日志是运行时可观测性的地基，值得在启动时优先配置，再打开数据库连接池，避免两套日志格式并存。Uvicorn 与应用共用 formatter 即可，运维只解析一种 JSON 行。

小结

日志要服务排障：结构化 字段（JSON 行）+ request_id 追踪一次调用；logging 在启动时统一配置，业务层用 extra= 传键值。能按订单号、用户 id、request_id 三键定位，日志才算「能追」。

非结构化 vs 结构化 ​

消息与字段分离 ​

标准库 logging 足够起步 ​

request_id：串起一次请求 ​

在中间件里记录 access 摘要 ​

contextvars 与 async ​

记什么、不记什么 ​

采样与体量 ​

与异常处理配合 ​

开发环境可读性 ​

常见误解 ​

排障故事：三键定位 ​

与中间件、异常处理的字段一致 ​

loguru 与标准库并存 ​

性能：异步路径少打 ​

关联 request_id 与 用户 ​

采样 trace 与 DEBUG ​

correlation 与下游调用 ​

小结 ​

非结构化 vs 结构化

消息与字段分离

标准库 logging 足够起步

request_id：串起一次请求

在中间件里记录 access 摘要

contextvars 与 async

记什么、不记什么

采样与体量

与异常处理配合

开发环境可读性

常见误解

排障故事：三键定位

与中间件、异常处理的字段一致

loguru 与标准库并存

性能：异步路径少打

关联 request_id 与用户

采样 trace 与 DEBUG

correlation 与下游调用

小结