3. 慢查询日志与Profiler深度分析

慢查询日志和数据库分析器（Database Profiler）是 MongoDB 性能诊断的两把“手术刀”。慢查询日志负责“事后取证”，它按阈值记录执行时间超标的操作；Profiler 则负责“全程录像”，可以按需采集更细粒度的执行统计。两者结合，才能从“哪条语句慢”深入到“为什么慢、慢在哪个阶段、缺什么索引、查询模式是否异常”。

一、先让证据可采集：慢日志与 Profiler 的开启方式

慢查询日志由 operationProfiling.slowOpThresholdMs 控制，默认 100ms。生产环境通常不建议直接调到 0，而是先设一个合理阈值，例如 200ms，避免日志量过大。动态调整可用：

db.setProfilingLevel(1, { slowms: 200 })
db.getProfilingStatus()
// { was: 1, slowms: 200, sampleRate: 1.0 }

Profiler 有三个级别：0 关闭、1 只记录慢操作、2 记录所有操作。级别 2 仅适合短时间排障，长期开启会显著增加 I/O 与存储压力。Profiler 数据写入 system.profile 集合，可通过查询它来定位问题：

db.system.profile.find(
  { millis: { $gt: 200 }, ns: { $ne: "test.system.profile" } }
).sort({ ts: -1 }).limit(10)

关键字段包括：op（操作类型）、ns（命名空间）、millis（耗时）、planSummary（执行计划摘要）、keysExamined（索引扫描键数）、docsExamined（文档扫描数）、nreturned（返回数）、command（原始命令）。这四个数字的比值，是判断索引缺失与查询模式异常的核心依据。

二、从一条慢日志还原瓶颈：四个数字的判读

假设某电商系统在高峰期出现如下慢日志片段（示例数据，用于说明判读方法）：

{
  op: "query",
  ns: "shop.orders",
  millis: 842,
  planSummary: "COLLSCAN",
  keysExamined: 0,
  docsExamined: 1284300,
  nreturned: 12,
  command: {
    find: "orders",
    filter: { status: "PAID", userId: 88231 },
    sort: { createdAt: -1 }
  }
}

这条记录几乎把问题写在了脸上：planSummary 是 COLLSCAN，说明没有走索引；docsExamined 高达 128 万，而 nreturned 只有 12，扫描/返回比超过 10 万倍。这意味着数据库为了找 12 条订单，把整张订单表翻了一遍。修复方向是建立复合索引，且字段顺序要匹配“等值 + 排序”模式：

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

更通用的判读规则是：keysExamined 与 docsExamined 应尽量接近 nreturned。若 docsExamined / nreturned 大于 100，通常说明索引选择性差或缺失；若 keysExamined 远大于 nreturned，则可能是索引前缀被低选择性字段占用，或排序无法被索引覆盖。

三、聚合管道瓶颈：慢在“入口”还是“出口”

聚合管道的慢，往往不是单一阶段的问题，而是阶段顺序不合理。Profiler 中聚合操作的 command.pipeline 会保留完整管道，配合 planSummary 可以判断瓶颈阶段。常见反模式是：先 $match 少量条件，再 $lookup 关联大表，最后才 $match 过滤——这会让关联阶段处理海量中间结果。

正确做法是把过滤尽量前移，让 $match 和 $limit 尽早缩小数据集，再执行 $lookup、$group 等重操作。若 $lookup 的外键字段没有索引，每次关联都会触发一次集合扫描，性能会随文档数线性恶化。可用 explain("executionStats") 查看每个阶段的 totalDocsExamined 与 totalKeysExamined，定位到具体阶段。

四、查询模式异常：比单条慢语句更危险

单条慢查询可以靠索引解决，但“查询模式异常”往往意味着应用层设计问题。典型表现有三类：

• 高频小查询风暴：Profiler 中同一 ns 在短时间内出现大量 millis 不高但 nreturned=1 的查询，累计消耗大量 CPU。这通常是应用层循环调用数据库，应改为批量查询或 $in。
• 无界查询：nreturned 极大且没有 limit，例如全表导出、无分页列表。应强制分页并加 limit。
• 排序与索引方向不一致：planSummary 出现 SORT 或 SORT_KEY_GENERATOR，说明排序在内存中完成。当排序数据超过 32MB 会直接报错，应让索引顺序与 sort 方向一致。

识别查询模式异常，不能只看单条记录，而要做聚合统计。例如按命名空间和命令指纹分组，找出“总耗时最高”的操作：

db.system.profile.aggregate([
  { $match: { millis: { $gt: 100 } } },
  { $group: {
      _id: { ns: "$ns", op: "$op" },
      count: { $sum: 1 },
      totalMs: { $sum: "$millis" },
      avgMs: { $avg: "$millis" },
      maxMs: { $max: "$millis" }
  }},
  { $sort: { totalMs: -1 } },
  { $limit: 10 }
])

这条聚合能快速暴露“单条不慢但总量惊人”的操作，是发现查询模式异常的有效手段。

五、一份可直接使用的慢查询分析检查表

下面这份检查表按“采集—判读—定位—验证”组织，可在实际排障时逐项核对。字段和阈值均为经验参考，需结合业务数据量调整。

慢查询日志与 Profiler 的价值，不在于记录了多少条慢语句，而在于能否从 planSummary、keysExamined、docsExamined、nreturned 这组数字中读出执行计划的真实行为。索引缺失看扫描比，聚合瓶颈看阶段顺序，查询模式异常看聚合统计。三者结合，才能把“慢”从一个现象，还原成可修复的具体原因。