做 MongoDB 性能排查最烦的往往不是某个操作本身写错了而是线上时不时冒出一条慢查询接口超时报警、CPU 飙到 90%重启也压不下去日志里只剩一句冷冰冰的 operation exceeded time limit。很多人第一反应是去翻 MongoDB 的日志文件但纯文本日志在这种时候基本没用——几百个分片、几千条语句堆在一起根本筛不出规律。我自己的习惯是直接打开 profiling让 MongoDB 在内部记录下超过阈值的操作把记录写进一组叫 system.profile 的集合里然后对着这些结构化数据做聚合、排序、对比一点点把性能瓶颈从“感觉”变成“证据”。这篇文章就从 profile 集合的原理讲起把它涉及到的三种级别、关键参数、核心字段、常见误区和实操流程全部拆开讲一遍。适合正在被线上慢查询折磨的 DBA、后端开发和运维同学也适合刚接触 MongoDB 优化、想系统了解 profiling 机制的人。读完你会发现慢查询排查没有想象中那么玄学关键在于你手上有没有一份“案发录像”。1. 为什么要用 profile 集合做慢查询分析它到底能查到什么1.1 慢查询排查的常见困境先聊一个非常典型的场景某天业务方反馈“列表页越来越慢”你去查监控发现某个 MongoDB 实例的 CPU 在下午两点到三点之间突然拉高连接数也涨了一倍。进一步看 mongostat发现 query 的操作数并没有爆炸式增长但每个操作的平均耗时抬升很明显。这时候你会面临一个问题只知道“哪个时段出问题”和“哪个集合被大量访问”是不够的你还得知道具体是哪些语句在拖后腿。传统做法是开 MongoDB 的 slowOp 日志然后在日志文件里 grep。可一旦业务量大日志文件动辄几个 GBgrep 出来的是几十条格式相近、看不出业务含义的语句而且日志只打印了命中的慢操作文本没有结构化的执行计划数据你想按“扫描了多少文档”“是否发生了排序”“来自哪个客户端”去分类统计基本无能为力。另一个更隐蔽的问题是慢查询本身是结果不是原因光知道“这条语句慢”并不能告诉你“它为什么慢”。如果连执行计划、扫描行数、内存排序这些信息都拿不到你后续的优化动作只能是猜。1.2 profile 集合是什么一个内置的“行车记录仪”MongoDB 自带了一套完整的操作采样机制叫 Database Profiling。开启之后符合条件的操作会被记录到 system.profile 这个集合里。我习惯把它类比成行车记录仪平时不打扰正常行驶一旦发生“超速”或者“事故”它就把当时的画面完整保存下来事后你可以一帧一帧回放。这里有个容易混淆的点system.profile 不是普通业务集合它是一个 capped collection也就是有固定大小、会自动淘汰旧数据的环形队列集合。默认情况下这个集合的大小只有 1MB记录满了之后新的记录会覆盖最老的记录。所以它天然适合做“近一段时间内慢查询的采样存储”但不适合用来积累全量历史数据。profiling 能够记录的是一类非常完整的操作现场执行的是 find、insert、update、remove 还是 aggregate命令参数是什么执行耗时多少毫秒扫描了多少个索引键和文档返回了多少条是否发生了内存排序来自哪个客户端 IP甚至在执行期间有没有产生锁等待和让出yield。这些信息对定位性能瓶颈来说比任何日志文本都直接。1.3 和 mongostat、mongotop、普通日志怎么配合很多同学容易把 profiling 和 mongostat、mongotop 搞混其实三者的定位完全不同。mongostat 是秒级采样看的是整个实例的全局指标比如 CPU 占用、内存使用、每秒读写次数、排队请求数适合回答“系统什么时候出了问题”mongotop 是看每个集合的读写耗时排名适合回答“哪个集合出了问题”而 profile 集合记录的是每一个被采样操作的详情适合回答“具体哪条语句、哪段执行计划出了问题”。我一般排查流程是这样的先通过 mongostat 找到异常时间窗再通过 mongotop 把范围缩小到某个业务集合然后开启或者查看已有的 profile 记录把该集合下的慢查询全部捞出来按耗时、扫描量、客户端做统计。如果还需要更细的执行计划验证就配合 explain 做单条语句分析。四者组合在一起才能构成一条完整的“发现-定位-验证-优化”链路缺了 profile 这一环前面两步只能让你知道病在哪里不知道病因。2. profiling 级别与参数设置全解析2.1 三种 profiling 级别怎么选MongoDB 的 profiling 一共有三个级别中文文档里经常翻译成关闭、慢查询、全部记录对应的英文是 off、slowOp、all。理解它们的最好方式是看下表里“写入条件”那一列级别含义写入条件适用场景注意事项0关闭 profiling不写入任何记录常规生产环境默认级别性能开销为零1只记录慢操作执行时间超过 slowms 阈值的操作生产环境排查慢查询最推荐注意设置合理阈值2记录所有操作所有读写和管理操作都会记录开发调试、短时间全量采样生产环境慎用会显著放大写入放大注意一个细节level 2 并非“理论上会拖慢”而是“几乎一定会拖慢”。因为每条操作执行完之后MongoDB 还要额外把这次操作的详细信息写入 system.profile 集合这本身又是一次文档写入。在高写入压力的实例上开 level 2相当于给每个写操作又挂了一笔额外开销轻则延迟变高重则直接把实例拖垮。所以我始终强调生产环境默认只用 level 1level 2 只在测试环境或者极短时间的全量采样里使用。2.2 临时开启与永久生效的配置方法如果只是临时排查用 mongo shell 执行下面的命令就够了// 设置 profiling 级别为 1慢查询阈值为 200ms db.setProfilingLevel(1, 200) // 查看当前 profiling 状态 db.getProfilingStatus()执行完之后再开启一个查询窗口用下面的命令验证一下是否真的生效db.getProfilingStatus()返回结果里会出现 was 和 slowms 两个字段was 为 1 说明级别设置成功slowms 为 200 说明阈值也写进去了。注意这种方式是动态生效的不需要重启 mongod但它只会对当前连接的 mongod 实例生效不会持久化到配置文件里。如果 mongod 进程重启profiling 状态会回到默认值。对于需要长期开启 profiling 的实例更可靠的做法是写到 mongod.conf 的 operationProfiling 段operationProfiling: mode: slowOp slowOpThresholdMs: 200其中 mode 对应的就是上面提到的三种级别off 对应 0slowOp 对应 1all 对应 2。这样配置之后mongod 启动时会自动应用不需要每次手动 setProfilingLevel。还有一个细节在副本集架构下如果你希望主从节点都有慢查询记录必须在每个节点的配置里都加上这段内容不能只在主节点上设置。2.3 slowms 阈值怎么定才合理slowms 这个参数直接决定哪些操作会被写进 system.profile阈值设得不好后面全白搭。设得太低比如 1ms你会看到几乎所有读请求都被记录profile 集合瞬间被刷满大量低价值的操作会把真正需要关注的慢查询淹没掉设得太高比如 10 秒很多初期的性能劣化信号在你还没发现时就已经被过滤掉了。我的经验是先看业务接口的延迟分布再反推一个合适的阈值。一般读多写少的 Web 业务慢查询阈值设在 100ms 到 200ms 之间比较合理如果是核心支付类接口可以收紧到 50ms如果是后台批量任务500ms 甚至 1s 都可以。打开之后不要急着下结论先观察一天如果 profile 集合里的记录寥寥无几再把阈值调低如果记录多到看不过来再往高调。理想状态应该是每天积累几百条到几千条慢查询记录既不会刷爆集合又能保证有足够的样本来做统计。3. system.profile 字段拆解一条慢查询记录里藏着哪些关键线索3.1 关键字段速查表真正打开一条 system.profile 记录你会看到一大串字段很多初学者容易迷失在里面。其实对性能分析有用的核心字段就十几个把它们读懂80% 的问题都能定位。字段含义怎么看op操作类型query、insert、update、remove、command 等ns操作所在命名空间格式为 数据库.集合锁定目标集合的关键command具体命令内容包含 find、filter、sort、skip、limit、aggregate 等业务条件planSummary执行计划摘要直接显示 COLLSCAN 全表扫描还是 IXSCAN 索引扫描keysExamined扫描的索引键数量远大于 nreturned 时说明索引选择或范围条件不合理docsExamined扫描的文档数量全表扫描时等于集合总文档数是低效查询最直接的证据nreturned实际返回的文档数和 docsExamined 对比能算出“无效扫描比例”millis操作总耗时慢查询的直接指标hasSortStage是否发生了排序阶段true 表示结果需要内存排序通常是缺少排序索引numYield操作执行中让出锁的次数数值高说明执行期间不断让路给其他操作往往和内存压力相关responseLength返回结果字节数异常大时说明查询返回过多字段需要加 projectionclient客户端 IP 和端口定位慢查询是从哪个应用服务器发起的locks锁等待信息包含了 Global、Database、Collection 级别的等待时间ts操作发生时间注意这是 UTC 时间和本地时区差 8 小时3.2 一条真实慢查询的执行记录解读光说字段太抽象我们直接看一条典型的生产慢查询记录。假设业务里有一个订单集合 shop.orders某一天列表查询突然变慢你从 profile 集合里捞出了这样一条数据{ op: query, ns: shop.orders, command: { find: orders, filter: {userId: 12345}, sort: {createdAt: -1}, skip: 10000, limit: 20 }, planSummary: COLLSCAN, keysExamined: 0, docsExamined: 100000, nreturned: 20, millis: 850, hasSortStage: true, numYield: 42, client: 10.0.0.12:53210, ts: ISODate(2024-01-15T14:30:12.100Z) }别急着改代码先从字段里提取信息。planSummary 是 COLLSCAN说明这条查询走的是全表扫描根本没用到索引docsExamined 是 100000说明它把整个集合扫了一遍nreturned 只有 20意味着它为了返回 20 条数据翻了 100000 条文档无效扫描比例高达 5000 倍hasSortStage 为 true说明按 createdAt 排序也是扫描完之后在内存里完成的。再看 skip 10000这个是分页参数MongoDB 实现 skip 时会把前面 10000 条记录也逐个扫描一遍算是全表扫描之外又一个放大点。这种记录看起来吓人但解决办法非常明确给 userId 和 createdAt 建一个复合索引即可。3.3 文档扫描与索引命中的判别规则有了上面的基础我们可以总结出几条非常实用的判别规则。第一当 docsExamined 远大于 nreturned 时基本可以判定没有可用的有效索引或者索引选择性太差这是最典型的低效查询信号。第二当 keysExamined 很大而 docsExamined 很小、nreturned 很少时说明虽然用了索引但索引的字段顺序或者范围条件设计不合理导致扫描了大量索引项。第三当 hasSortStage 为 true 时说明排序字段没有和过滤字段组成复合索引MongoDB 只能把所有匹配文档加载到内存里排序文档量一大就会触发内存排序上限。需要特别提醒的是文档扫描量大并不一定等于执行耗时高但它是性能隐患的前置信号。我遇到过一个 case一张表才 5 万条数据全表扫描 50ms 就完成了当时大家都觉得无所谓。结果半年后这张表涨到 5000 万条全表扫描直接变成 3 秒接口全部超时。如果在数据量很小的时候就能通过 profile 识别到 COLLSCAN提前把索引建好后面完全不会踩这个雷。4. 实操流程从采集慢查询到完成索引设计4.1 生产环境开启 profiling 的正确姿势生产环境开 profiling我建议不要一上来就全天开而是先做一次有计划的短时采样。典型的做法是挑业务高峰期的 30 分钟动态打开 level 1 并设置合理的 slowms等窗口结束之后立刻关闭。这样做既不会长时间放大实例的开销又能抓到最有代表性的慢查询样本。具体操作流程如下// 第一步开启慢查询记录阈值设为 200ms db.setProfilingLevel(1, 200) // 第二步等待 30 分钟采样窗口期间业务保持正常 // 第三步采样结束后关闭 profiling db.setProfilingLevel(0) // 第四步查看采到了哪些记录 db.system.profile.find().sort({ts: -1}).limit(50)如果只想针对某个集合采样可以在新版 MongoDB 中使用 filter 参数。这个参数允许你指定一个查询条件只有满足条件的操作才会被记录比如只关注某个核心业务库db.setProfilingLevel(1, { slowms: 100, filter: { ns: shop.orders } })注意filter 字段的匹配逻辑和普通 find 查询一致支持 $regex、$in 等操作符但不要把它写得过于复杂否则 profiling 本身也会占用不必要的计算资源。4.2 用聚合分析找出 Top 慢操作采集到慢查询记录之后最忌讳的就是一条一条肉眼看几万条记录根本看不过来。正确做法是先做一次粗粒度的聚合找出最值得深入分析的集合和命令类型。我个人最常用的聚合是这样db.system.profile.aggregate([ { $match: { millis: { $gte: 100 }, ts: { $gte: ISODate(2024-01-15T14:00:00Z) } } }, { $group: { _id: $ns, count: { $sum: 1 }, avgMillis: { $avg: $millis }, maxMillis: { $max: $millis }, totalMillis: { $sum: $millis } } }, { $sort: { totalMillis: -1 } }, { $limit: 20 } ])这段聚合做的事情是过滤出执行耗时超过 100ms 的所有记录然后按命名空间分组统计每个集合的慢查询次数、平均耗时、最大耗时的累计耗时。输出结果里排在前面的集合就是最需要优先处理的瓶颈所在。totalMillis 累计耗时这个指标尤其重要一次 2 秒的超慢查询和一万次 200ms 的普通慢查询前者更刺眼但后者对业务体感的影响可能更大totalMillis 能帮你平衡这两个维度。做完集合级聚合之后再针对具体集合拉出明细。还是以 shop.orders 为例查看它最慢的 20 条记录db.system.profile.find({ ns: shop.orders, millis: { $gte: 100 } }).sort({ millis: -1 }).limit(20)看到具体命令之后再去看每条的 planSummary、docsExamined、hasSortStage 这些字段就能判断问题是出在索引缺失、索引设计不合理、查询条件写错还是返回字段过多。4.3 用 explain 验证执行计划并设计索引当 profile 记录已经指出了某个查询的低效模式下一步就是针对单条查询做 explain 验证。explain 相当于让 MongoDB 告诉你“如果我执行这条查询我会怎么查”。继续用上面那条带 skip 的订单查询举例db.orders.find( { userId: 12345 } ).sort( { createdAt: -1 } ).skip( 10000 ).limit( 20 ).explain(executionStats)explain 输出里重点看几个地方。executionStats.executionStages.stage 如果是 COLLSCAN说明全表扫描如果创建索引之后变成 IXSCAN说明查询走的是索引扫描节点数已经大幅缩小。totalDocsExamined 直接显示扫描文档总数优化前是 100000优化后应该降到和返回数据量差不多的量级。winningPlan 里如果出现 SORT 节点表示排序没有走索引需要在索引设计里补齐排序字段。对应的索引创建命令如下db.orders.createIndex({ userId: 1, createdAt: -1 })这里有一个很核心的索引设计原则等值条件字段放前面排序字段放后面。为什么因为 userId 是等值查询放在索引前缀可以有效缩小扫描范围createdAt 紧随其后刚好可以服务 sort 排序使得 MongoDB 在读索引时就能按 createdAt 逆序拿到数据不再需要额外的排序阶段。如果你把顺序反过来建 createdAt 在前、userId 在后等值查询虽然也能定位某个用户的数据但会出现多段连续索引区间扫描效率反而更差。4.4 优化效果验证与回归索引建完之后不要直接宣布问题解决一定要做前后对比。还是使用 explain优化前后的数据应该呈现出明显的差异指标优化前优化后执行计划COLLSCAN 全表扫描IXSCAN 索引扫描docsExamined10000020是否有 SORT 节点是否执行耗时850ms2ms除了单条语句的执行计划对比还要回到 profile 集合看整体效果。重新开一段短时采样窗口观察 shop.orders 集合下是否还有新的慢查询记录。如果原来的慢查询彻底消失说明索引命中成功如果还有零星记录再继续看具体字段可能是新索引没被选上也可能是又出现了新的查询模式。这里我要特别提醒一个容易犯的错加索引不是免费的。每个索引都会增加写入操作的维护成本索引过多还会吃掉大量内存。所以在优化慢查询时不能只盯着“这条查询变快了”还要评估“新增索引对写入、存储、内存的影响”。一般情况下单集合索引数量控制在 5 个以内比较稳妥多了反而容易引发写入性能问题。5. 常见问题与排查技巧实录5.1 profiling 会造成性能损耗吗很多第一次开 profiling 的同学都有这个担心记录慢查询是不是会让本身正常的数据库变慢答案是会但要看级别。level 1 对绝大多数生产实例来说额外的写入量很小因为只有超过阈值的操作才会被记录系统性能可以接受。level 2 就完全不一样了所有操作都会写入每条写入都要经过一次额外的文档写入流程在高写入场景下会让整体吞吐明显下降。如果业务实在敏感不想在主实例上开 profiling可以在从库Secondary节点上开启。从库一样会复制主库的操作并把慢查询记录写到自己的 system.profile 里通过分析从库的 profile 既能判断主库的查询模式又不会影响主库的性能。缺点是数据可能略有滞后但对慢查询分析来说足够用。5.2 system.profile 集合被写满怎么办默认的 system.profile 集合只有 1MB不管 profile 记录有多少超过之后最老的记录就会被自动覆盖。对于慢查询很多的业务一小时就能把集合写满导致你还没来得及分析重要记录已经被冲掉了。针对这个问题我一般用两个办法解决。第一种是调整 system.profile 集合的容量但 capped collection 的大小在创建时就已经固定不能直接 modify只能 drop 后重建。操作方法是先把 profiling 级别设为 0然后执行db.setProfilingLevel(0) db.system.profile.drop() db.createCollection(system.profile, { capped: true, size: 16 * 1024 * 1024 })这样重建出一个 16MB 的新的 capped 集合有足够空间容纳更多慢查询记录。第二种办法是定期把 profile 记录导出到普通集合比如每天凌晨把 system.profile 里的数据迁移到 profile_history 集合然后清理原集合既保证 system.profile 不会被写满又给后续分析留下了历史数据。5.3 开了 profiling 却查不到慢查询的几种情况我见过不少同学信誓旦旦说“我明明开了 profile”结果查询 system.profile 时却一片空白这种情况百分之八九十是下面几个原因之一。第一是权限问题。执行 setProfilingLevel 需要 dbAdmin 或 clusterAdmin 相关权限普通读写用户虽然能执行命令但不一定会报错只是操作没有真正生效。第二是分片集群问题。mongos 本身没有自己的 system.profileprofile 是记录在各分片节点的 mongod 里的通过 mongos 去查 profile 往往会得到空结果必须分别连到各个分片节点查看。第三是设置之后没有真正执行到慢查询。这时候需要检查 getProfilingStatus 返回的 slowms 是否合理以及 filter 是否设置得过于严格。第四是采样窗口太短恰好没有慢查询发生可以先人为执行一个 sleep 类操作或者复杂的聚合测试验证 profiling 是否工作。排查顺序建议是先 getProfilingStatus 看状态再查权限再确认连接的是 mongod 还是 mongos最后放大采样范围重试。5.4 慢查询原因速查表为了让大家排查时能快速对号入座我把最常见的 profile 字段组合和对应原因整理成一张速查表profile 字段表现根因方向下一步动作docsExamined 高nreturned 很低缺少索引或索引选择性差创建合适的复合索引planSummary 显示 COLLSCAN没有可用索引先分析查询条件再看执行计划确认索引是否存在hasSortStage 为 true排序字段没有走索引在复合索引中补充排序字段keysExamined 很高docsExamined 低索引范围扫描过大调整索引字段顺序或缩小范围条件numYield 很高内存压力大或长查询频繁让出锁优化查询数据量、检查内存占用responseLength 异常大返回字段过多增加 projection 只返回必要字段locks 中 Collection 等待时间高存在长事务或慢写操作分析写入模式优化批量写操作skip 值非常大深分页问题改成基于游标的时间范围分页这张表不是万能药但它能帮助你把抽象的字段值对应到具体的优化动作上省掉很多无效摸索。5.5 我踩过的几个隐蔽的坑最后分享几个我在实际排查中踩过、且不太容易在文档里看到的坑。第一个坑最耗时的慢查询不一定是真正的根因。有一次我发现某条聚合查询耗时 5 秒排在所有慢查询的第一位但深入看 locks 字段才发现它主要时间都花在等锁上真正的问题源是它前面一批长时间未提交的写事务。如果只盯着耗时最大的查询加索引问题永远解决不了。第二个坑从库的 profile 和主库差异很大。主从复制模式下从库的查询压力往往比主库低慢查询样本也不一样用从库采样结果去衡量主库性能很可能得出错误结论。所以做慢查询分析时不要混用主从数据。第三个坑排查完忘了关闭 profiling。开过一次 level 1 后来忘记关加上慢查询较多system.profile 集合里的记录持续被写入虽然影响不大但会造成不必要的 I/O。我现在有一个习惯任何临时开启的 profiling都会在 shell 命令前面备注关闭时间和恢复阈值避免给后续运维留下隐患。我个人做 MongoDB 性能排查做得久了越来越觉得慢查询分析的核心目标不是“消灭所有慢查询”而是“让慢查询变得可解释”。每一条慢查询记录背后都有它发生的原因可能是索引问题可能是数据量膨胀可能是锁争用也可能是业务特性本来就不适合这个查询模式。profile 集合最大的价值就是把原本模糊的“系统变慢”硬生生拆解成一条条可以阅读的现场记录。在这里也分享一个我能坚持到现在的小习惯每周找一天低峰期开 10 分钟 profiling把这周出现的慢查询按集合、客户端、耗时统计起来做成一张简单的巡检表。这样做不会消耗太多资源却能在业务真正出问题之前帮你提前发现那些缓慢恶化的查询模式。毕竟性能优化这件事越早发现处理成本越低。