MongoDB 查询从 80ms 变 900ms：working set 算错、ESR 索引写反，我的排查流水账
2024 年 3 月接手一个跑了两年半的订单库，三节点副本集，主库 32GB 内存 8 核，MongoDB 6.0.4，4300 万文档。db.orders.stats() 打出来 avgObjSize 1180 字节，dataSize 21GB，indexSize 9.4GB，storageSize 只有 6.8GB，WiredTiger 默认的 snappy 压过一遍就是这个效果。监控上 P99 稳在 80ms 附近快一年了，直到某个周一早上九点半，P99 顶到 900ms，QPS 从 1200 掉到 400，前端超时告警刷了满屏。那天我做的第一件事是 db.setProfilingLevel(1, {slowms: 100})，开了二十分钟抓慢查询，抓完一看整个人都不太好。
profiler 出来 3800 条记录，几乎全是同一个查询：{status: 'PENDING', updatedAt: {$gte: 某时间}} 加 .sort({updatedAt: -1}).limit(20)。explain('executionStats') 一看，totalKeysExamined 120 万，totalDocsExamined 380 万，nReturned 20。这三个数的关系很说明问题，理想情况三个数差不多大，它这儿是六万倍的放大。我第一反应是索引丢了，getIndexes() 一看索引好好的，{status:1, createdAt:1, updatedAt:1}，三个字段都在，一个都没少。
问题就出在这个索引上。MongoDB 的复合索引有个老生常谈的 ESR 规则，等值、排序、范围，这个顺序不能乱。我这条查询是 status 等值、updatedAt 范围、updatedAt 排序，索引却是 status 到 createdAt 再到 updatedAt。createdAt 夹在中间，直接把后面的 updatedAt 排序给废了，优化器只能把 status 命中的所有文档捞出来在内存里 sort，380 万次 docExamined 就是这么来的。改成 {status:1, updatedAt:-1} 之后，totalKeysExamined 掉到 21，totalDocsExamined 掉到 20，nReturned 20，P99 回到 85ms。顺带说一句 {status:1, updatedAt:-1, createdAt:1} 可能更好，因为查询里如果还有 createdAt 的等值条件，它能被索引覆盖，但排序键必须紧跟在等值键后面，中间不能插范围键，插了就废。
索引改完我以为完事了，结果第二天早上同样的时间点又慢了，这次慢的不只是那一个查询，是一大片。这时候才轮到真正的主角：WiredTiger 的缓存。db.serverStatus().wiredTiger.cache 里几个关键数，maximum bytes configured 是 14.4GiB，bytes currently in the cache 涨到了 14.3GiB，pages evicted because they exceeded the in-memory maximum 这个计数器一直在往上爬。WiredTiger 的默认缓存是 max(0.5 × (总内存 - 1GB), 256MB)，32GB 的机器算下来就是 15.5GB，看着挺多，但缓存里要同时装数据和索引的热点页。
这里有个很多人算错的地方：working set 不等于总数据量，也不等于热数据量，它是「一段时间内真正被频繁访问的数据页，加上这些页对应的索引页」。我把订单表按 updatedAt 分了一下，最近 90 天的订单大概 1100 万条、13GB 左右，再加上 status 和 updatedAt 那几个索引的热点部分大概 3GB，总共 16GB 出头，稳稳超过 14.4GiB 的缓存上限。超出之后 WiredTiger 就开始疯狂 evict，被赶出去的页下次又要从磁盘读回来，磁盘 IOPS 从 800 飙到 12000，pages read into cache 一分钟涨了 40 万。缓存命中率我用 1 - pages read into cache / pages requested from the cache 算了一下，从 99.2% 掉到 91.7%，看着还行，但落到 1200 QPS 上就是每秒上百次磁盘随机读。后来把主机内存从 32GB 升到 64GB，缓存上限变成 30GB，16GB 的 working set 才装得下。也有人会把 cacheSizeGB 调大超过默认值，我不太建议，留 1GB 给系统和连接开销是官方建议，踩过内存 OOM 被系统 kill 的都懂那不是开玩笑。
除了这两个，还有一个坑是 $lookup。同一个库里有个 order_items 集合，4000 万文档，订单表用 {_id: 1} 关联它。老代码用的是 3.2 时代的 localField / foreignField 写法，这种写法如果 foreignField 上有索引是没问题的，我们当时外键字段建的是 {orderId: 1, skuId: 1} 的复合索引，orderId 是前缀，理论上能用。explain 里能看到 lookup 阶段确实走了 IXSCAN，但 nReturned 里有个别订单挂了几千条明细，整个聚合跑了 4.7 秒。后来我把 $lookup 改成 3.6 之后的 pipeline 写法，在第一个 $match 里用 $expr 做等值匹配，再加 $limit 控制返回条数，同一个聚合掉到 620ms。
最后一个我想说的是分片键，这个库还没分片，但我在上一个项目里栽过。当时用了 {createdAt: 1} 做范围分片键，写入全部集中在最后一个 chunk 上，MongoDB 6.0 的 chunk 默认是 128MB，每秒 3000 次插入的情况下，均衡器刚 split 完那边又写满了，整个集群的写入压力全压在一个 shard 上，另外两个 shard 的 CPU 长期 15%。后来改成 {tenantId: 1, createdAt: 1} 的组合键，写入才均匀开。经验就是如果你的查询几乎都带 tenantId 或者 userId 这种高基数的等值条件，把它放前面做复合分片键，比 hashed 分片键更划算，hashed 虽然写入均匀，但范围查询要打穿所有分片，那个代价你未必愿意付。
一些我常用的命令，直接抄：db.orders.aggregate([{$indexStats:{}}]) 看每个索引被用了多少次（accesses.ops），零次的基本可以删；db.currentOp({secs_running: {$gte: 3}}) 看当前跑超过 3 秒的操作；db.serverStatus().wiredTiger.cache 看缓存；db.orders.find(...).explain('executionStats') 看 totalKeysExamined 和 nReturned 的比值，超过 100 就该回去翻索引了。这些数不一定会直接告诉你答案，但至少能让你少熬两个通宵。