线上某业务,频繁出现IOPS 使用率100%的(每秒4000IOPS)现象,每次持续接近1个小时,从慢请求的日志发现是一个 getMore 请求耗时1个小时,导致IOPS高;深入调查之后,最终发现竟是一个索引选择的问题。
2017-11-01T15:04:17.498+0800 I COMMAND [conn5735095] command db.mycoll command: getMore { getMore: 215174255789, collection: "mycoll" } cursorid:215174255789 keyUpdates:0 writeConflicts:0 numYields:161127 nreturned:8419 reslen:4194961 locks:{ Global: { acquireCount: { r: 322256 } }, Database: { acquireCount: { r: 161128 } }, Collection: { acquireCount: { r: 161128 } } } protocol:op_command 3651743ms
问题背景
业务每个整点开始,会把过去1小时的数据同步到另一个数据源,查询时会按 _id 排序,2个主要查询条件如下,先执行find命令,然后遍历cursor,读取所有满足条件的文档。
* created_at: { $gte: "2017-11-01 13:00:00", $lte: "2017-11-01 13:59:59" }
* sort: {_id: 1}
业务数据的特性
- 每条数据插入时都带上 created_at 字段,时间为当前时间戳,并建立了 {created_at: -1} 的索引
- _id 字段为用户自定义(并非mongodb默认的ObjectId),取值较随机,无规律
- 整个集合非常大,总文档数超过1亿条
MongoDB的find、getMore特性
- find命令,会返回第一批满足条件的batch(默认101条记录)以及一个cursor
- getMore 根据find返回的cursor继续遍历,每次遍历默认返回不超过4MB的数据
索引的选择
方案1:使用 created_at 索引
整个执行路径为
- 通过 created_at 索引,快速定位到符合条件的文档
- 读出所有的满足 created_at 查询条件的文档
- 对所有的文档根据 _id 字段进行排序
如下是走这个索引的2条典型日志,可以看出
- 符合 created_at 条件的文档大概有7w+,全部排序后,返回前101条,总共耗时约600ms;
- 接下来 getMore,因为结果要按_id排序,getMore 还是得继续把所有符合条件的读出来排序,并跳过第一次的101条,返回下一批给客户端。
2017-11-01T14:02:31.861+0800 I COMMAND [conn5737355] command db.mycoll command: find { find: "mycoll", filter: { created_at: { $gte: "2017-11-01 13:00:00", $lte: "2017-11-01 13:59:59" } }, projection: { $sortKey: { $meta: "sortKey" } }, sort: { _id: 1 }, limit: 104000, shardVersion: [ Timestamp 5139000|7, ObjectId('590d9048c628ebe143f76863') ] } planSummary: IXSCAN { created_at: -1.0 } cursorid:215494987197 keysExamined:71017 docsExamined:71017 hasSortStage:1 keyUpdates:0 writeConflicts:0 numYields:557 nreturned:101 reslen:48458 locks:{ Global: { acquireCount: { r: 1116 } }, Database: { acquireCount: { r: 558 } }, Collection: { acquireCount: { r: 558 } } } protocol:op_command 598ms 2017-11-01T14:02:32.036+0800 I COMMAND [conn5737355] command db.mycoll command: getMore { getMore: 215494987197, collection: "mycoll" } cursorid:215494987197 keyUpdates:0 writeConflicts:0 numYields:66 nreturned:8510 reslen:4194703 locks:{ Global: { acquireCount: { r: 134 } }, Database: { acquireCount: { r: 67 } }, Collection: { acquireCount: { r: 67 } } } protocol:op_command 120ms
方案2:使用 _id 索引
整个执行路径为
- 根据 _id 索引,扫描所有的记录 (按_id索引的顺序扫描,对应的文档的created_at是随机的,无规律)
- 把满足 created_at 条件的文档返回,第一次find,要找到101个符合条件的文档返回
如下是走这个索引的2条典型日志,可以看出
- 第一次扫描了17w,才找到101条符合条件的记录,耗时46s
- 第二次要累计近4MB符合条件的文档(8419条)才返回,需要全表扫描更多的文档,最终耗时1个小时,由于全表扫描对cache非常不友好,所以一直是要从磁盘读取,所以导致大量的IO。
2017-11-01T14:03:25.648+0800 I COMMAND [conn5735095] command db.mycoll command: find { find: "mycoll", filter: { created_at: { $gte: "2017-11-01 13:00:00", $lte: "2017-11-01 13:59:59" } }, projection: { $sortKey: { $meta: "sortKey" } }, sort: { _id: 1 }, limit: 75000, shardVersion: [ Timestamp 5139000|7, ObjectId('590d9048c628ebe143f76863') ] } planSummary: IXSCAN { _id: 1 } cursorid:215174255789 keysExamined:173483 docsExamined:173483 fromMultiPlanner:1 replanned:1 keyUpdates:0 writeConflicts:0 numYields:2942 nreturned:101 reslen:50467 locks:{ Global: { acquireCount: { r: 5886 } }, Database: { acquireCount: { r: 2943 } }, Collection: { acquireCount: { r: 2943 } } } protocol:op_command 46232ms 2017-11-01T15:04:17.498+0800 I COMMAND [conn5735095] command db.mycoll command: getMore { getMore: 215174255789, collection: "mycoll" } cursorid:215174255789 keyUpdates:0 writeConflicts:0 numYields:161127 nreturned:8419 reslen:4194961 locks:{ Global: { acquireCount: { r: 322256 } }, Database: { acquireCount: { r: 161128 } }, Collection: { acquireCount: { r: 161128 } } } protocol:op_command 3651743ms
总结
IOPS高是因为选择的索引不是最优,那为什么MongoDB没有选择最优的索引来执行这个任务呢?
- 从日志可以看出,绝大部分情况,MongoDB 都是走的 created_at 索引
- 上述case,那个索引更优,其实是跟数据的分布情况相关的
- 如果满足 created_at 查询条件的文档特别多,那么对大量的文档排序的开销也是很大的
- 如果 created_at 字段分布非常离散(如本案例中的数据),则全表扫描找出符合条件的文档开销更大
- MongoDB 的索引是基于采样代价模型,一个索引对采样的数据集更优,并不意味着其对整个数据集也最优
- MongoDB 一个查询第一次执行时,如果有多个执行计划,会根据模型选出最优的,并缓存起来,以提升效率
- 当 MongoDB 发生集合创建/删除索引时,会将缓存的执行计划清空掉,并重新选择
- MongoDB 在执行的过程中,也会根据执行计划的表现,比如一个执行计划,很多次迭代都没遇到符合条件的文档,就会考虑这个执行计划是否最优了,会触发重新构建执行计划的逻辑(具体触发的策略还没有详细研究,后续再分享),比如方案2里的find查询,执行计划里包含了
{replanned: 1}
说明是重新构建了执行计划;当它发现这个执行计划实际执行起来效果更差时,最终还是会会到更优的执行计划上。
- 最懂数据的还是业务自身,对于查询优化器搞不定的case,可以通过在查询时加 hint,自己指定的索引来构建执行计划。
你好 我想跟你请教一个mongodb查询忽快忽慢的问题,从几号秒到几千毫秒
如果_id是bson.ObjectID的话,_id的前4位是unix时间戳,直接按照_id索引可能会快一些吧。