检索MongoDB的日志为何存在大量的查询报错

发布时间:2020-05-09 浏览次数:131

一、背景

某次在客户现场处理一起APP业务中页面访问异常的问题,该页面直接是返回一行行硕大的报错代码,错误大概如下所示:

MongoDB.Driver.MongoQueryException: QueryFailure flag was Executor error: OperationFailed: Sort operation used more than the maximum 33554432 bytes of RAM. Add an index, or specify a smaller limit

报错页面很明显告知了问题排查的方向:

  • Sort operation 该页面涉及的MongoDB查询语句使用了排序。

  • more than the maximum 33554432 排序操作超过了MongoDB单个Session排序可使用的最大内存限制。

检索MongoDB的日志确实存在大量的查询报错,跟APP页面报错能够对应上;并且日志中排序使用的字段为 DT 和 _id ,升序排序。

涉及业务敏感字,全文会略过、改写或使用'xxx'代替2019-XX-XXTXX:XX:XX.XXX+0800 E QUERY    [conn3644666] Plan executor error during find: FAILURE, ·········· sortPattern: {DT: 1, _id: 1 }, memUsage: 33555513, memLimit: 33554432, ·············· }2019-XX-XXTXX:XX:XX.XXX+0800 I QUERY    [conn3644666] assertion 17144 Executor error: OperationFailed: Sort operation used more than the maximum 33554432 bytes of RAM. Add an index, or specify a smaller limit. ns:XXXXX query:{ $query:········  $orderby: { DT: 1, _id: 1 }, $hint: { CID: 1, CVX: 1 } }


1. 配置参数检查

MongoDB Server中确认了对于Sort排序能够支持的最大内存限制为32M。

> use adminswitched to db admin> db.runCommand({ getParameter : 1, "internalQueryExecMaxBlockingSortBytes" : 1 } ){ "internalQueryExecMaxBlockingSortBytes" : 33554432, "ok" : 1 }


2. 排序字段是否存在索引

根据报错信息的建议,查看官方文档的解释:

In MongoDB, sort operations can obtain the sort order by retrieving documents based on the ordering in an index. If the query planner cannot obtain the sort order from an index, it will sort the results in memory. Sort operations that use an index often have better performance than those that do not use an index. In addition, sort operations that do not use an index will abort when they use 32 megabytes of memory.

文档中意思大概是:在排序字段未利用到索引的情况下,若超过32M内存则会被Abort,语句直接返回报错。

那么现在方向基本可以锁定在排序操作是否使用到索引了;查看该集合状态,排序字段 DT 和 _id确实存在索引 _id_、 DT_1 、 DT_1_CID_1_id_1 ,为啥还会报错?带着疑问我们下文在测试环境进行模拟。

> db.xxx.getIndexes()[·········    {        "v" : 1,        "key" : {            "_id" : 1        },        "name" : "_id_",        "ns" : "xxx.xxx"    },    {        "v" : 1,        "key" : {            "DT" : 1        },        "name" : "DT_1",        "ns" : "xxx.xxx"    },    {        "v" : 1,        "key" : {            "DT" : 1,            "CID" : 1,            "_id" : 1        },        "name" : "DT_1_CID_1_id_1",        "ns" : "xxx.xxx"    }···········


二、测试环境模拟索引对排序的影响

1.测试环境信息

MongoDB版本4.0.10MongoDB 存储引擎wiredTiger数据量1000000测试集合名data_test

集合数据存储格式

> db.data_test.findOne(){    "_id" : ObjectId("5d0872dc5f13ad3173457186"),    "Name" : "Edison",    "Num" : 195930,    "loc" : {        "type" : "Point",        "coordinates" : [            118.0222094243601,            36.610739264097646        ]    }}

集合索引信息

> db.data_test.getIndexes()[    {        "v" : 2,        "key" : {            "_id" : 1        },        "name" : "_id_",        "ns" : "mongobench.data_test"    },    {        "v" : 2,        "key" : {            "Name" : 1        },        "name" : "Name_1",        "ns" : "mongobench.data_test"    },    {        "v" : 2,        "key" : {            "Num" : 1        },        "name" : "Num_1",        "ns" : "mongobench.data_test"    },    {        "v" : 2,        "key" : {            "Num" : 1,            "Name" : 1,            "_id" : 1        },        "name" : "Num_1_Name_1__id_1",        "ns" : "mongobench.data_test"    }]

查询语句

为测试方便,将业务中报错的聚合查询按同样查询逻辑修改为 Mongo Shell 中的普通 find() 查询


2. 报错语句的执行计划解释

测试查询报错的语句,尝试查看其查询计划如下:

> db.data_test.find({'Num':{"$gt":500000}}).sort({"Num":1,"_id":1}).explain()2019-06-19T18:21:14.745+0800 E QUERY    [js] Error: explain failed: {    "ok" : 0,    "errmsg" : "Sort operation used more than the maximum 33554432 bytes of RAM. Add an index, or specify a smaller limit.",    "code" : 96,    "codeName" : "OperationFailed"}

直接报错,这里有个疑问为啥连执行计划都看不了?先不急,我们先删除对于排序字段的组合索引 Num_1_Name_1_id_1 后,再查看执行计划:

> db.data_test.dropIndex('Num_1_Name_1__id_1'){ "nIndexesWas" : 4, "ok" : 1 }db.data_test.find({'Num':{"$gt":500000}}).sort({"Num":1,"_id":1}).explain('executionStats'){    "queryPlanner" : {        "plannerVersion" : 1,        "namespace" : "mongobench.data_test",        "indexFilterSet" : false,        "parsedQuery" : {            "Num" : {                "$gt" : 500000            }        },        "winningPlan" : {            "stage" : "SORT",            "sortPattern" : {                "Num" : 1,                "_id" : 1            },            "inputStage" : {                "stage" : "SORT_KEY_GENERATOR",·······        "rejectedPlans" : [ ]    },    "executionStats" : {        "executionSuccess" : false,        "errorMessage" : "Exec error resulting in state FAILURE :: caused by :: Sort operation used more than the maximum 33554432 bytes of RAM. Add an index, or specify a smaller limit.",        "errorCode" : 96,        "nReturned" : 0,        "executionTimeMillis" : 1504,        "totalKeysExamined" : 275037,        "totalDocsExamined" : 275037,        "executionStages" : {            "stage" : "SORT",            "nReturned" : 0,            "executionTimeMillisEstimate" : 188,····            "memUsage" : 33554514,            "memLimit" : 33554432,            "inputStage" : {                "stage" : "SORT_KEY_GENERATOR",                "nReturned" : 275037,·····

查询计划中关键参数的解释:

1. queryPlanner:explain中三种模式之一,默认模式。表示不会执行查询语句而是选出最优的查询计划即winning plan,剩余两种模式分别是 executionStats 和 allPlansExecution

  • winningPlan:MongoDB优化器选择的最优执行计划

[1]stage:包括COLLSCAN 全表扫描、IXSCAN 索引扫描、FETCH 根据索引去检索指定文档、SORT 在内存中进行排序(未使用索引)

[2]sortPattern:需排序的字段

[3]inputStage:winningPlan.stage的子阶段

  • rejectedPlans:优化器弃用的执行计划

2. executionStats:返回执行结果的状态,如语句成功或失败等

  • executionSuccess:语句执行是否成功

  • errorMessage:错误信息

  • nReturned:返回的记录数

  • totalKeysExamined:索引扫描总行数

  • totalDocsExamined:文档扫描总行数

  • memUsage:Sort 使用内存排序操作使用的内存大小

  • memLimit:MongoDB 内部限制Sort操作的最大内存

上述执行计划表明查询语句在未使用索引排序的情况下如果排序使用的内存超过32M必定会报错,那么为什么没有使用到索引排序,是不是跟组合索引的顺序有关?


3. 建立新的组合索引进行测试

直接创建 Num 和 _id 列都为升序的组合索引,再次查看执行计划:

> db.data_test.ensureIndex({Num:1,_id:1}){    "createdCollectionAutomatically" : false,    "numIndexesBefore" : 3,    "numIndexesAfter" : 4,    "ok" : 1}> db.data_test.find({'Num':{"$gt":500000}}).sort({"Num":1,"_id":1}).explain('executionStats'){    "queryPlanner" : {        "plannerVersion" : 1,        "namespace" : "mongobench.data_test",        "indexFilterSet" : false,        "parsedQuery" : {            "Num" : {                "$gt" : 500000            }        },        "winningPlan" : {            "stage" : "FETCH",            "inputStage" : {                "stage" : "IXSCAN",                "keyPattern" : {                    "Num" : 1,                    "_id" : 1                },                "indexName" : "Num_1__id_1",·········        "rejectedPlans" : [            {                "stage" : "SORT",                "sortPattern" : {                    "Num" : 1,                    "_id" : 1                },                "inputStage" : {                    "stage" : "SORT_KEY_GENERATOR",·········    "executionStats" : {        "executionSuccess" : true,        "nReturned" : 499167,        "executionTimeMillis" : 1355,        "totalKeysExamined" : 499167,        "totalDocsExamined" : 499167,        "executionStages" : {            "stage" : "FETCH",            "nReturned" : 499167,            "executionTimeMillisEstimate" : 102,            "works" : 499168,            "advanced" : 499167,            "needTime" : 0,            "needYield" : 0,            "saveState" : 3901,            "restoreState" : 3901,            "isEOF" : 1,            "invalidates" : 0,            "docsExamined" : 499167,            "alreadyHasObj" : 0,            "inputStage" : {                "stage" : "IXSCAN",                "nReturned" : 499167,                "executionTimeMillisEstimate" : 14,                "works" : 499168,·······

上述执行计划说明:

  • winningPlan.stage:优化器选择了FETCH+IXSCAN的Stage,而不是之前的Sort;这是最优的方式之一,也就是通过索引检索指定的文档数据,并在索引中完成排序 ("keyPattern" : {"Num" : 1,"_id" : 1}) ,效率最高

  • rejectedPlans:Sort 使用内存排序的方式被优化器弃用

  • executionSuccess:语句执行成功

  • nReturned:语句返回结果数为499167


三、引申的组合索引问题

上文中查询语句explain()直接报错,是因为组合索引为{Num_1_Name_1_id_1},而查询语句为sort({"Num":1,"_id":1}),未遵循最左原则,索引无法被使用到而后优化器选择Sort Stage触发了内存限制并Abort。

至于为啥MongoDB连执行计划都不返回给你,可以后续再讨论,欢迎评论

创建合适的组合索引后,查询语句成功执行;那么如果不按照索引的升降顺序执行语句会怎样?


1.查询语句中,排序字段 _id 使用降序

当前的组合索引为{"key" : {"Num" : 1, "_id" : 1} },也就是都为升序,而我们将查询语句中排序字段 _id 使用降序排序时,查询语句直接报错,说明该语句也未使用到索引排序,而是使用的Sort Stage。

> db.data_test.find({'Num':{"$gt":500000}}).sort({"Num":1,"_id":-1}).explain('executionStats')2019-06-19T19:32:30.939+0800 E QUERY    [js] Error: explain failed: {    "ok" : 0,    "errmsg" : "Sort operation used more than the maximum 33554432 bytes of RAM. Add an index, or specify a smaller limit.",    "code" : 96,    "codeName" : "OperationFailed"}

2.查询语句中,排序字段 Num 和 _id 全部使用降序

我们现在将查询语句的排序字段全部使用降序,与组合索引全部相反再测试,执行成功。

> db.data_test.find({'Num':{"$gt":500000}}).sort({"Num":-1,"_id":-1}).explain('executionStats'){    "queryPlanner" : {······        "winningPlan" : {            "stage" : "FETCH",            "inputStage" : {                "stage" : "IXSCAN",                "keyPattern" : {                    "Num" : 1,                    "_id" : 1                },                "indexName" : "Num_1__id_1",·······        "rejectedPlans" : [            {                "stage" : "SORT",·······    "executionStats" : {        "executionSuccess" : true,·······            "inputStage" : {                "stage" : "IXSCAN",·······                "indexName" : "Num_1__id_1",······    "ok" : 1}

再次做其他查询组合测试 sort({"Num":-1,"_id":1}),执行依然失败;说明只有在排序列的升降序只有和组合索引中的 方向 保持 全部相同  全部相反,语句执行才能成功。


四、引申的聚合查询问题

上文中的查询测试语句是在 MongoDB Shell 执行的 find() 查询方法,但是业务程序中查询一般都是使用聚合查询方法 aggregate(),对于聚合查询中的Sort Stage,官方文档说明了使用内存排序能使用最大的内存为 100M,若需要避免报错则需要添加 {allowDiskUse : true} 参数。

The $sort stage has a limit of 100 megabytes of RAM. By default, if the stage exceeds this limit, $sort will produce an error. To allow for the handling of large datasets, set the allowDiskUse option to true to enable $sort operations to write to temporary files. See the allowDiskUse option in db.collection.aggregate() method and the aggregate command for details.

1.Sort stage 使用内存排序

将普通的 find() 方法转为 aggregate() 聚合方法,语义不变,特意将排序字段 _id 修改为 降序 -1,那么查询计划将无法使用到组合索引只能使用Sort stage。下文中查询依然报错,Sort stage操作使用的内存超过100M

> db.data_test.explain('executionStats').aggregate([{ $match : { Num : { $gt : 500000} } },{ $sort : { "Num" : 1, _id: -1 } }])2019-06-19T20:28:43.859+0800 E QUERY    [js] Error: explain failed: {    "ok" : 0,    "errmsg" : "Sort exceeded memory limit of 104857600 bytes, but did not opt in to external sorting. Aborting operation. Pass allowDiskUse:true to opt in.",    "code" : 16819,    "codeName" : "Location16819"} :_getErrorWithCode@src/mongo/shell/utils.js:25:13throwOrReturn@src/mongo/shell/explainable.js:31:1constructor/this.aggregate@src/mongo/shell/explainable.js:121:1@(shell):1:1

添加 {allowDiskUse: true} 参数,可以使Sort stage操作绕过内存限制而使用磁盘,查询语句可以执行成功:

> db.data_test.explain('executionStats').aggregate([{ $match : { Num : { $gt : 500000} } },{ $sort : { "Num" : 1, _id: -1 } }],{allowDiskUse: true}){    "stages" : [······                "executionStats" : {                    "executionSuccess" : true,                    "nReturned" : 499167,                    "executionTimeMillis" : 4128,                    "totalKeysExamined" : 499167,                    "totalDocsExamined" : 499167,······        {            "$sort" : {                "sortKey" : {                    "Num" : 1,                    "_id" : -1                }            }        }    ],    "ok" : 1}


五、结论

1.排序内存限制的问题

MongoDB使用内存进行排序的场景只有是Sort stage,官方文档有说明:

If MongoDB can use an index scan to obtain the requested sort order, the result will not include a SORT stage. Otherwise, if MongoDB cannot use the index to sort, the explain result will include a SORT stage.

意思大概是如果MongoDB可以使用索引扫描来进行排序,那么结果将不包括SORT stage。否则如果MongoDB无法使用索引进行排序,那么查询计划将包括SORT stage。

使用索引扫描的效率是远大于直接将结果集放在内存排序的,所以MongoDB为了使查询语句更有效率的执行,限制了 排序内存的使用,因而规定了只能使用 32M,该种考虑是非常合理的。

但也可通过手工调整参数进行修改(不建议):

# 比如调大到 128M## 在线调整> db.adminCommand({setParameter:1, internalQueryExecMaxBlockingSortBytes:134217728})## 持久到配置文件setParameter:internalQueryExecMaxBlockingSortBytes: 134217728

2.使排序操作使用到索引

1)为查询语句创建合适的索引如果查询中排序是单列排序,如sort({"Num":1}),那么只需添加为Num 列添加索引即可,排序的顺序无影响

## 例如索引为 {'Num':1},查询不管升/降序都可使用到索引排序db.data_test.find().sort({Num:1})  db.data_test.find().sort({Num:-1})

如果查询中排序是使用组合排序,如sort({"Num":1,"id":1}),那么需要建立对应的组合索引,如{"key" : {"Num" : 1, "_id" : 1} 或者 {"key" : {"Num" : -1, "_id" : -1}

## 例如索引为{"Num" : 1, "_id" : 1},可以用到索引排序的场景为db.data_test.find().sort({Num:1,_id:1})db.data_test.find().sort({Num:-1,_id:-1})

注意保持查询中组合排序的升降序和组合索引中的 方向 保持 全部相同 或 全部相反


2)注意前缀索引的使用

上文查询报错的案例分析已说明了组合索引每一个键的顺序非常重要,这将决定该组合索引在查询过程中能否被使用到,也将是MongoDB的索引及排序同样需遵循最左前缀原则。


3. 聚合查询添加allowDiskUse选项

尽可能的保证查询语句的排序能够使用索引排序,但如果业务需要规避排序内存限制报错的问题,那么需要在代码中添加 {allowDiskUse : true} 参数。

上一篇: 数据库中Redis和Memcached的区别

下一篇: MySQL的delete大表slave回放巨慢的问题分析

咨询客服 在线咨询
400-820-6580 免费电话