一、问题背景

事情是这样的。我们有个商品详情接口 GET /api/v1/products/{id},返回商品基础信息 + 规格 + 库存 + 若干张图片。业务上这个接口被App首页、详情页、购物车多处调用,日均请求量大概200万,峰值QPS在800左右。

上线初期没太在意,直到监控告警开始频繁响:P99延迟1.8s,P50也有400ms,4核8G的容器CPU使用率长期在90%以上,GC日志里能看到明显的停顿。运维那边已经开始问要不要扩容了,但我知道这接口逻辑不复杂,扩容只是掩盖问题,得先搞清楚时间到底花在哪。

技术栈是 FastAPI 0.110.0 + SQLAlchemy 2.0.29 + PostgreSQL 15.6 + Redis 7.2,部署在 uvicorn 上,4个worker。

二、环境与版本

先把关键版本列清楚,后面所有数据都基于这套环境:

  • Python 3.11.8
  • FastAPI 0.110.0
  • uvicorn 0.29.0(4 workers,--workers 4)
  • SQLAlchemy 2.0.29(async engine,asyncpg 0.29.0 驱动)
  • PostgreSQL 15.6,商品表约1200万行
  • Redis 7.2.4,单实例
  • 压测工具:wrk 4.2.0,压测机 8核16G,与被压测服务同内网

三、定位瓶颈:profiling 三板斧

3.1 第一板斧:py-spy 抓火焰图

线上服务不能随便改代码,先用 py-spy 做无侵入采样:

# 找到 uvicorn worker 进程
ps -ef | grep uvicorn

# 对一个 worker 采样 30 秒,生成火焰图
py-spy record -o profile.svg --pid 12345 --duration 30 --rate 200

火焰图出来的结果很直观:超过60%的采样落在 asyncpg 的 fetch 等待上,另有约20%在 pydantic 的序列化路径里。也就是说,瓶颈大概率在数据库查询,而不是Python业务逻辑。

3.2 第二板斧:中间件记录慢请求明细

光看火焰图不够,得知道具体是哪个查询慢。加一个轻量中间件,把单次请求里执行的SQL条数和耗时打出来(这里用 SQLAlchemy 的 event 钩子统计):

import time
import logging
from fastapi import Request
from sqlalchemy import event
from sqlalchemy.engine import Engine

logger = logging.getLogger("api.perf")

@event.listens_for(Engine, "before_cursor_execute")
def before_cursor_execute(conn, cursor, statement, parameters, context, executemany):
    conn.info.setdefault("query_start", []).append(time.perf_counter())

@event.listens_for(Engine, "after_cursor_execute")
def after_cursor_execute(conn, cursor, statement, parameters, context, executemany):
    start = conn.info["query_start"].pop()
    elapsed = (time.perf_counter() - start) * 1000
    if elapsed > 50:  # 只记录超过50ms的
        logger.warning("SLOW SQL %.1fms: %s", elapsed, statement[:200])

async def perf_middleware(request: Request, call_next):
    t0 = time.perf_counter()
    response = await call_next(request)
    cost = (time.perf_counter() - t0) * 1000
    response.headers["X-Resp-Time"] = f"{cost:.1f}ms"
    if cost > 500:
        logger.warning("%s %s cost %.1fms", request.method, request.url.path, cost)
    return response

跑了一天,日志里慢请求的典型形态是:单个请求触发了 7 条SQL,其中商品主表1条、规格1条、库存1条、图片4条(每个SKU一张图,典型N+1)。每条查询单独看都不慢,20~40ms,但7条串行加起来就是200ms+,再加上连接池排队和序列化,P99冲到1.8s就说得通了。

3.3 第三板斧:压测复现

本地用wrk复现,确认基线:

wrk -t8 -c200 -d60s --latency \
  "http://127.0.0.1:8000/api/v1/products/123456"

基线数据:QPS 320,P50 380ms,P99 1820ms,CPU 92%。

问题定位清楚了:N+1查询 + 无缓存 + 序列化开销。下面逐个解决。

四、方案设计与核心实现

4.1 数据库查询优化:干掉N+1

原来的写法是典型的懒加载陷阱(SQLAlchemy 2.0 异步模式下懒加载会直接报错或触发大量额外查询):

# 优化前:每个关联对象都触发一次查询
stmt = select(Product).where(Product.id == product_id)
product = (await session.execute(stmt)).scalar_one()
# 访问 product.skus 时又查一次,product.images 再查一次...

改成用 selectinload 一次性把关联数据拉回来,SQL条数从7条降到3条(主表+两个IN查询):

from sqlalchemy.orm import selectinload
from sqlalchemy import select

async def get_product_detail(session, product_id: int):
    stmt = (
        select(Product)
        .where(Product.id == product_id)
        .options(
            selectinload(Product.skus).selectinload(Sku.images),
            selectinload(Product.inventory),
        )
    )
    result = await session.execute(stmt)
    return result.scalar_one_or_none()

同时在商品表的 id(主键,已有)、sku.product_id、sku_image.sku_id 上确认索引存在。检查时发现 sku_image.sku_id 居然没索引,1200万行数据下每次都是全表扫,加上索引后单条查询从平均35ms降到3ms。

另外把连接池参数调整了:pool_size=20, max_overflow=10, pool_pre_ping=True。原来默认pool_size=5,4个worker就是20个连接,峰值时排队明显。

4.2 缓存策略:两级缓存 + 防击穿

商品详情是典型的读多写少,天然适合缓存。设计上做了两级:本地内存缓存(进程内,TTL 5秒,抗热点) + Redis(TTL 300秒)。本地缓存用 cachetools.TTLCache,主要是为了削峰,避免同一个热点key把Redis打穿。

缓存装饰器实现(含简单的防击穿和空值缓存):

import json
import asyncio
import hashlib
from functools import wraps
from cachetools import TTLCache
import redis.asyncio as aioredis

local_cache = TTLCache(maxsize=2048, ttl=5)
redis_client = aioredis.from_url("redis://127.0.0.1:6379/0", decode_responses=True)
_locks: dict[str, asyncio.Lock] = {}

def cached(prefix: str, ttl: int = 300):
    def decorator(func):
        @wraps(func)
        async def wrapper(*args, **kwargs):
            raw_key = f"{prefix}:{args}:{sorted(kwargs.items())}"
            key = hashlib.md5(raw_key.encode()).hexdigest()

            # L1 本地缓存
            if key in local_cache:
                return local_cache[key]

            # L2 Redis
            cached_val = await redis_client.get(f"{prefix}:{key}")
            if cached_val is not None:
                data = json.loads(cached_val)
                local_cache[key] = data
                return data

            # 防击穿:同key只放一个请求回源
            lock = _locks.setdefault(key, asyncio.Lock())
            async with lock:
                cached_val = await redis_client.get(f"{prefix}:{key}")
                if cached_val is not None:
                    data = json.loads(cached_val)
                    local_cache[key] = data
                    return data

                data = await func(*args, **kwargs)
                # 空值也缓存,防穿透(TTL短一点)
                payload = json.dumps(data, default=str)
                await redis_client.setex(
                    f"{prefix}:{key}",
                    30 if data is None else ttl,
                    payload,
                )
                local_cache[key] = data
                return data
        return wrapper
    return decorator

用在接口层:

@app.get("/api/v1/products/{product_id}")
async def product_detail(product_id: int):
    data = await _load_product(product_id)
    if data is None:
        raise HTTPException(status_code=404, detail="product not found")
    return data

@cached(prefix="product:detail", ttl=300)
async def _load_product(product_id: int):
    async with async_session() as session:
        product = await get_product_detail(session, product_id)
        if product is None:
            return None
        # 关键:在会话内完成序列化,避免懒加载在会话外触发
        return ProductSchema.model_validate(product).model_dump()

这里有个坑后面会讲:序列化必须在session内完成,否则对象detach后访问关联属性会报错。

4.3 uvicorn worker 调整

原配置是 --workers 4,机器4核,看起来合理。但压测时发现CPU并没有完全打满在业务上,大量时间在上下文切换。改成 --workers 8(2倍核数,因为大部分时间在等IO)后,QPS提升约15%。这个不是银弹,得实测,我们环境测出来8最优,16反而因为内存和切换开销下降。

五、踩坑与优化

坑1:缓存反序列化后时间字段丢失。 json.dumps(default=str) 把 datetime 转成了字符串,Pydantic 校验时又正常解析,但前端拿到的是字符串格式,和原来不一致。后来统一在 schema 层用 model_dump(mode="json") 输出,保证缓存前后格式一致。

坑2:防击穿锁的内存泄漏。 _locks 字典只增不减,key多了内存会涨。改成用 WeakValueDictionary,或者简单点,加个定期清理。我们直接换了 cachetools 的思路,锁只对热点key生效,设置上限。

坑3:缓存更新延迟导致库存显示错误。 TTL 300秒对于库存来说太长了。解法是把库存从详情接口的缓存里拆出来,单独一个 /inventory 接口,TTL 10秒,且写操作时主动 delete 缓存。商品基础信息可以缓存久一点。

坑4:selectinload 嵌套层级过深。 一开始把 skus.images 和 inventory 都塞进去,SQL变成3条但单条返回数据量很大(一个商品最多50个SKU × 4张图)。后来对图片做了裁剪,只取前2张主图,返回体从平均 85KB 降到 12KB,序列化耗时从 90ms 降到 15ms。这个对P99影响很大,很多人只关注SQL,忽略了响应体大小。

六、效果数据

所有优化做完后,同样命令压测(4核8G,wrk 8线程200连接60秒):

指标 优化前 优化后 变化
QPS 320 2100 +556%
P50 380ms 28ms -93%
P99 1820ms 120ms -93%
单请求SQL条数 7 3(未命中缓存)/ 0(命中) -
缓存命中率 0 96.3%(Redis)/ 41%(本地) -
CPU使用率 92% 38% -
平均响应体 85KB 12KB -86%

线上灰度后,P99稳定在120~150ms区间,CPU降到40%以下,扩容计划直接取消了。

七、总结

回头看,这个接口的问题一点都不高级:N+1查询、缺索引、无缓存、响应体过大。但定位过程必须靠数据说话,py-spy + SQL耗时日志 + wrk 基线,三步就能把"感觉慢"变成"知道慢在哪一行"。

几个可以复用的经验:

  1. 先profiling再动手,别凭直觉加缓存,我们一开始差点直接上Redis,但根因是N+1,缓存只是掩盖。
  2. SQL条数比单条SQL耗时更值得关注,7条30ms的查询比1条200ms的查询更隐蔽。
  3. 序列化和响应体大小常被忽略,85KB的JSON在P99上贡献了接近100ms。
  4. 缓存要分层,且想清楚哪些字段不能长缓存(库存这类强一致需求单独处理)。
  5. 压测数据要在优化前后用同样的命令、同样的机器跑,否则数字没意义。

代码都在上面了,selectinload 和那个 cached 装饰器可以直接拿去用,但记得把 Redis 连接和锁的实现按你们的基础设施调整一下。