企业官网建设流程全解析

先说一个发生在我这边的真实故事。有段时间公司管理后台的订单导出功能隔三差五就卡死，用户点一次导出，浏览器转圈半分钟，数据库的 CPU 直接冲到 90% 以上。我排查了一圈，最后在 MongoDB 的 system.profile 集合里抓到一条执行了 3000 多毫秒的查询，扫描了 35 万条文档，最后只返回 20 条结果，典型的全表扫描。随手加了一个复合索引，执行时间直接掉到 3 毫秒。那次排障之后，我彻底体会到：MongoDB 慢查询分析这件事，profile 集合用好了，性能瓶颈定位就是几分钟的事。

这篇文章打算把这套方法完整讲一遍：怎么开启 profile、怎么从 system.profile 里把慢查询捞出来、怎么解读关键字段、怎么结合 explain 做优化验证，以及我在生产环境里踩过的坑。适合刚接手 MongoDB 的后端同学，也适合已经会用 explain 但想系统化做性能巡检的 DBA。看完之后，你至少能把“数据库怎么这么慢”这种模糊描述，变成一条条可以直接执行的优化动作。

1. 先把 profile 机制吃透：它记录了什么、为什么用它

1.1 profiling 的三档级别和 system.profile 的存储特性

MongoDB 把记录慢查询的能力叫做 database profiling，开启之后，符合条件的操作会被写入 system.profile。system.profile 是一个 capped collection，容量固定，满了就自动覆盖最旧的记录。这就像行车记录仪，只存最近一段时间的画面，不会无限占磁盘。

系统默认有三个级别：

• level 0：关闭，不记录任何操作，这是默认状态。
• level 1：只记录执行时间超过阈值的操作，阈值由 slowms 指定，默认是 100ms。
• level 2：记录所有操作，不管快慢。

level 2 我基本不建议在生产环境开。所有操作都记录，包括读、写、管理命令，很快会把集合写满并反复覆盖，而且写日志本身就有开销。之前有一次在压测环境里开过 level 2，TPS 高的时候 profile 集合每秒要写几千条记录，写入造成的负载比慢查询本身还严重。生产环境只开 level 1，配合合理阈值，就够了。

这里牵扯出一个很现实的问题：system.profile 默认创建时分配的容量不一定够用。高流量业务下，一个小容量的 capped 集合可能只保留几分钟的记录，等你发现问题想回溯时，数据早被覆盖了。建议在部署初期就评估一下，用 db.system.profile.stats() 查看当前容量，如果不够，就要手动重建一个更大容量或合适出入的 profile 集合，别等到排查时发现历史记录都没了。

1.2 一条请求从“正常”到“被记录”发生了什么

当你开启了 profiling，MongoDB 会把执行时间超过 slowms 阈值的操作包装成一条 profile 文档，写入 system.profile。这条文档里保存了操作类型 op、命名空间 ns、完整查询条件 query、执行耗时 millis、扫描文档数 docsExamined、扫描索引键数 keysExamined、返回行数 nreturned，以及执行计划摘要 planSummary 等字段。这些字段就是我们判断性能瓶颈的核心依据。

需要提醒的是，每条 profile 记录本质上就是一个普通 JSON 文档，你可以像查普通集合一样去查它。因为它是 capped 集合，所以不需要担心日志无限膨胀，它会自转覆盖。

另外有个容易忽略的点：MongoDB 的日志文件里也会输出 Slow query 信息，和 system.profile 共用同一个 slowms 阈值，但两者是独立的记录机制。我一般是两个都开。日志方便实时感知，profile 方便做结构化统计和趋势分析。光靠人肉刷日志，在高并发日志量下很难看到全貌。

2. 实操：开启 profile 并把配置固定下来

2.1 三行命令快速开启和验证

最快的方式是连接 MongoDB 后直接执行：

use admin db.setProfilingLevel(1, { slowms: 100 })

执行后返回类似{ "was" : 0, "slowms" : 100, "ok" : 1 }的文档，表示之前是 level 0，现在已成功设为 level 1，慢查询阈值是 100ms。查看当前状态用：

db.getProfilingStatus()

返回结果里能看到当前级别和阈值。想确认 system.profile 实际大小，执行：

db.system.profile.stats()

这里要注意一个原则：profiling level 是全局生效的，不是“只记录某个库”。无论你在哪个库执行 setProfilingLevel，最终都影响整个实例。因为 system.profile 存放在 admin 库，记录范围覆盖所有数据库。有些人想只监控某个核心业务库，结果发现所有库的慢查询都进来了，反而被无关日志干扰。遇到这种情况，后续分析时用 ns 字段过滤就好。

等业务跑一段时间后，看看有没有记录：

db.system.profile.find().sort({ ts: -1 }).limit(5).pretty()

如果没有任何记录，可能是业务里确实没有超过阈值的操作，也可能是你选的阈值偏高。这时候不要急着调低，继续往下分析。

2.2 重启失效问题：最终还是要写配置文件

命令行设置的 profiling 是内存态，MongoDB 重启后会恢复默认关闭状态。所以如果要做长期监控，必须把配置写进 mongod 的配置文件。以常规 YAML 配置为例：

operationProfiling: mode: slowOp slowOpThresholdMs: 100

mode 有三个可选值：off 对应 level 0，slowOp 对应 level 1，all 对应 level 2。改完配置后重启 mongod，再执行 db.getProfilingStatus() 验证是否生效。

修改配置重启这件事，要放在低峰期做，尤其是副本集环境，建议逐个节点滚动重启，别直接把所有节点同时重启，以免影响线上读写。这是生产环境最基本的操作纪律，很多人都忽略了。

关于 slowms 阈值的选择，默认 100ms 看起来合理，但也要看业务场景。如果业务查询本来就简单，绝大多数操作都在 5ms 内完成，那 100ms 阈值可能漏掉一些初期波动；如果数据库本身压力大、慢查询很多，一开始就把阈值设置成 10ms，profile 集合里会被“正常慢”操作淹没，真正需要关注的问题反而不明显。我习惯的做法是：先按 100ms 跑一天，用聚合统计看整体耗时分布，再根据 Top10 的实际情况收紧到 50ms 或放宽到 200ms。这比拍脑袋定阈值靠谱得多。

3. 从 system.profile 里把慢查询“挖”出来

3.1 最常用的三种分析查询

拿到 system.profile 里的记录后，关键是怎么高效查询。我日常最常用的是下面几个。

第一种，直接看最近最慢的 20 条：

db.system.profile.find({ ns: { $ne: 'admin.system.profile' }, millis: { $gt: 200 } }).sort({ ts: -1 }).limit(20).pretty()

这里过滤掉了 ns 为 admin.system.profile 自身的写记录，否则你查 profile 这个动作本身也会被记录下来，干扰分析结果。

第二种，按集合维度做耗时汇总，看哪张表消耗最高：

db.system.profile.aggregate([ { $match: { ns: { $ne: 'admin.system.profile' }, millis: { $gt: 0 } } }, { $group: { _id: '$ns', count: { $sum: 1 }, totalMillis: { $sum: '$millis' }, avgMillis: { $avg: '$millis' }, maxMillis: { $max: '$millis' } }}, { $sort: { totalMillis: -1 } }, { $limit: 10 } ])

这个统计的价值在于：在一段观察窗口里，哪个集合的累积耗时最高，哪个集合大概率就是拖垮整体响应速度的元凶。比如报表接口慢，汇总后看到 report.orders 的 totalMillis 占了 80%，那就顺着这个集合继续深挖。

第三种，按执行计划和集合组合统计，快速定位哪些查询正在全表扫描：

db.system.profile.aggregate([ { $match: { ns: { $ne: 'admin.system.profile' }, millis: { $gt: 100 } } }, { $group: { _id: { ns: '$ns', planSummary: '$planSummary' }, count: { $sum: 1 } }}, { $sort: { count: -1 } }, { $limit: 20 } ])

这一步可以快速把“大量 COLLSCAN 操作”识别出来。不同 MongoDB 版本的 profile 文档结构略有差异，有的版本里 planSummary 字段不一定叫这个名字，建议先在 collection 里 findOne 一条记录看看结构再写统计脚本，不要拿着旧脚本直接跑。

3.2 核心字段解读：不要只会看 millis

很多同学看慢查询只盯一个 millis 字段，看到执行时间几千毫秒就兴奋，马上跑到 explain 里看有没有索引。但如果能静下心读一下 profile 里的其它字段，往往能绕过不少弯路。

举个例子，如果一条查询的 docsExamined 是 30 万，nreturned 只有 20，说明数据库扫描了 30 万条文档才过滤出 20 条结果，问题大概率出在索引缺失或者索引选择错误。如果 keysExamined 也很大，但 nreturned 很小，那往往不是没建索引，而是复合索引字段顺序和查询条件不匹配，导致索引大量无效扫描。这两种情况的优化方向完全不一样，一个是建索引，一个是调整索引顺序。所以只凭一条毫秒数，根本没法精准定位问题。

4. 从慢查询到优化：用 explain 把执行计划看清楚

4.1 用 explain('executionStats') 还原执行计划

从 system.profile 里拿到具体的慢查询语句后，下一步是把这条语句原样复制出来，在 shell 里手动加 explain 执行，确认执行计划到底长什么样。命令长这样：

db.orders.find({ status: 'pending', userId: 'u123' }) .sort({ createdAt: -1 }) .limit(20) .explain('executionStats')

输出内容很多，但只看几个关键指标就够了：

• executionStats.executionTimeMillis：实际执行时间
• executionStats.totalDocsExamined：扫描文档数
• executionStats.totalKeysExamined：扫描索引键数
• executionStats.nReturned：返回条数
• queryPlanner.winningPlan.stage：执行阶段，COLLSCAN、IXSCAN、FETCH、SORT 等

如果看到stage: "COLLSCAN"，说明查询没有使用任何索引，这是最需要优先解决的一类问题。如果看到IXSCAN -> FETCH -> SORT，说明已经用了索引，但后面还是出现了 SORT 阶段。SORT 在某些情况下不一定是坏事，但如果需要排序的数据量特别大，SORT 的内存消耗和耗时都会很夸张，这时要考虑是不是索引字段顺序可以覆盖排序条件。

建议始终使用 explain('executionStats') 而不要用默认的 explain()，因为默认模式下拿不到 totalDocsExamined 和 executionTimeMillis，分析价值大打折扣。

4.2 典型瓶颈：从 profile 字段反推优化动作

根据我观察到的常见情况，慢查询基本可以归成几类。

第一类：COLLSCAN + docsExamined 巨大。这是最典型、最容易解决的。解决方案就是创建合适的索引。比如上面那个查询，条件是 status 精确匹配再加 createdAt 排序，就创建复合索引：

db.orders.createIndex({ status: 1, createdAt: -1 })

这里要注意复合索引字段顺序。原则是精确等值字段放前面，排序字段放后面。如果索引建反了，比如建了{ createdAt: -1, status: 1 }，查询时 status 条件无法精确定位，还是可能发生大量无效扫描，keysExamined 会居高不下。

第二类：keysExamined 远大于 nreturned，但 planSummary 显示已经走了 IXSCAN。这种情况经常不是“没有索引”，而是索引没吃对。你可能会发现同一个集合上有好几个索引，MongoDB 明明选了其中一个，可扫描的键数量依然巨大。这时候要用 explain 看清楚获胜执行计划用的哪个索引，再检查索引字段和查询条件是否匹配。也可以在查询语句里用 hint 手动指定索引做测试：

db.orders.find({ status: 'pending' }) .hint({ status: 1, createdAt: -1 }) .explain('executionStats')

第三类：responseLength 超大。有些慢查询本身执行时间并不长，但返回的响应体非常大，导致网络传输和应用程序解析耗时上升，用户体感依然是“卡”。这种情况在 profile 里的特征是 millis 可能只有几十毫秒，但 responseLength 动辄几 MB。原因是 find 没有加 projection，把文档里的大数组、大文本字段全返回了。优化方式很简单，加一个字段白名单：

db.orders.find({ status: 'pending' }, { _id: 1, orderNo: 1, totalAmount: 1 })

第四类：慢的是 update 或 remove 等写操作。写操作慢的原因和读不同，经常跟锁竞争、批量更新范围过大有关。通过 profile 里 op:'update' 的记录，配合 observed locks 字段，可以看到是否长时间等待写锁。解决思路通常是：把大事务拆成小批量，一次不要处理几万条数据，特别是业务高峰期，尽量打散更新，减少锁持有时间。

第五类：聚合命令触发内存限制或中间结果膨胀。MongoDB 的聚合框架里，$group、$sort 等阶段默认最多使用 100MB 内存，超过会报错。而且 $lookup、$unwind 这类操作会把中间结果放大很多倍。优化方向是尽量把 $match 前移，先过滤数据再关联；实在无法避免大数据量聚合时，可以给 aggregate 加上{ allowDiskUse: true }，但这只是缓解，治标不治本。根本上还是减少进入聚合的文档量。

5. 一次真实故障复盘和避坑清单

5.1 完整复盘案例

我印象很深的一次故障，是某个报表接口每到下午两三点就开始变慢，从原来的几百毫秒涨到四五秒。一开始排查网络和服务器负载都没问题，后来在备节点上查了 system.profile，发现report.orders集合里连续出现多条聚合命令，millis 都在 2000ms 以上：

db.system.profile.find({ ns: 'report.orders', millis: { $gt: 500 } }).sort({ ts: -1 }).limit(5).pretty()

我把其中一条 command 字段拿出来看，发现里面有 $unwind 和 $lookup。这条聚合先把订单的 items 数组展开，每个订单因此变成多行，然后再用items.goodsId去关联商品表。一个订单如果有 30 个商品，展开后就是 30 条中间结果，再关联一次商品库，数据量被放大了几十倍，总耗时自然爆炸。

我用 explain('executionStats') 验证后，做了三个改动：

1. 把 $match 前移，先把 orders 集合限定在当天的时间范围内。
2. 把 $lookup 的关联条件在关联前先过滤一遍，减少关联目标集合的数据扇出。
3. 去掉不必要的 $unwind，改用 $reduce 或 $size 处理数组汇总。

同时给商品表的关联字段建了索引。优化后同一条聚合的 millis 从 2000 多毫秒降到 40 毫秒，totalDocsExamined 从几十万降到几千。这个案例说明，慢查询分析不能只看表面语句，要顺着执行计划追到数据模型是否合理，有时候问题根本不在一张表，而是聚合阶段的中间结果失控。

5.2 常见问题速查表：从踩坑中总结

我再特别提醒一个很少有人说的坑：临时开启 level 2 后，干完活一定要记得改回来。之前有同学在测试环境开 level 2 跑压测，结束后忘关，第二天所有接口都变慢，查了半天才发现是 profile 集合每秒写入几百条记录，在入口处就增加了不必要的开销。这种问题非常隐蔽，它不会报错，只会让你觉得数据库“好像哪里怪怪的”。所以每次临时开启 profiling，都应该在心里过一遍：这个级别要开多久，什么时候恢复 level 1。

如果让我说这几年来在 MongoDB 性能排查上的最大体会，那就是：不要等线上变慢了才去开 profile。慢查询分析应该成为日常巡检的一部分。我现在每个周一早上都会在备节点上查一次 admin 库的 system.profile，把累计耗时 Top10 的查询导出来，连同执行计划的指标一起存到独立的性能趋势集合里。这样能看到一个查询是不是在持续变慢，而不是等它某天突然爆发。另一个小技巧是：改动索引后，不要只看优化当天的执行时间，应该把同一查询在改动前后的 docsExamined 和 keysExamined 拉出来对比。这两个指标最能说明索引是否真正被用对了——哪怕 millis 受到机器负载影响会波动，扫描行数不会说谎。