一个MongoDB索引走偏的案例及探究分析

程序员文章站 2022-04-29 08:25:30

接业务需求，有一个MongoDB的简单查询，太耗时了，执行了 70S 左右，严重影响用户的体验。。查询代码主要如下：此集合在字段OPTime上有索引idx_OPTime；在"Tags"数组中的内嵌字段"SN"有索引idx_TSN；两者都是独立的索引。此集合存放的是执行Log，相对Size较大。 ......

接业务需求，有一个mongodb的简单查询，太耗时了，执行了 70s 左右，严重影响用户的体验。。

查询代码主要如下：

db.duoduologmodel.find({"tags.sn": "qz435698245"})
 .projection({})
 .sort({optime: -1})
 .limit(20)

此集合在字段optime上有索引idx_optime；在"tags"数组中的内嵌字段"sn"有索引idx_tsn；两者都是独立的索引。此集合存放的是执行log，相对size较大。

查看此查询对应的慢查询日志，如下：

2019-08-13t15:07:16.767+0800 i command [conn536359] command shqq_zp.duoduologmodel command: find { find: "duoduologmodel", filter: { tags.sn: "qz435698245" }, sort: { optime: -1 }, projection: {}, limit: 20, $db: "shqq_zp", $clustertime: { clustertime: timestamp(1565679737, 71), signature: { hash: bindata(0, e7b0a887e83bad0aa0a72016a39c677b53abdbe2), keyid: 6658116868433248258 } }, lsid: { id: uuid("0f22409b-f122-41e9-a094-46ccf04e44c7") } } plansummary: ixscan { optime: 1 } cursorid:61603998663 keysexamined:12145431 docsexamined:12145431 frommultiplanner:1 replanned:1 numyields:97720 nreturned:14 reslen:16772198 locks:{ global: { acquirecount: { r: 97721 } }, database: { acquirecount: { r: 97721 } }, collection: { acquirecount: { r: 97721 } } }  protocol:op_msg 692537ms

查看此查询的执行计划，执行代码

db.duoduologmodel.find({"tags.sn": "qz435698245"})
   .projection({})
   .sort({optime: -1})
   .explain()

主要反馈信息

    "queryplanner" : {
        "plannerversion" : 1,
        "namespace" : "shqq_zp.duoduologmodel",
        "indexfilterset" : false,
        "parsedquery" : {
            "tags.sn" : {
                "$eq" : "qz435698245"
            }
        },
        "winningplan" : {
            "stage" : "sort",
            "sortpattern" : {
                "optime" : -1
            },
            "inputstage" : {
                "stage" : "sort_key_generator",
                "inputstage" : {
                    "stage" : "fetch",
                    "inputstage" : {
                        "stage" : "ixscan",
                        "keypattern" : {
                            "tags.sn" : 1
                        },
                        "indexname" : "idx_tsn",
                        "ismultikey" : true,
                        "multikeypaths" : {
                            "tags.sn" : [
                                "tags"
                            ]
                        },
                        "isunique" : false,
                        "issparse" : true,
                        "ispartial" : false,
                        "indexversion" : 2,
                        "direction" : "forward",
                        "indexbounds" : {
                            "tags.sn" : [
                                "[\"qz435698245\", \"qz435698245\"]"
                            ]
                        }
                    }
                }
            }
        },
        "rejectedplans" : [
            {
                "stage" : "fetch",
                "filter" : {
                    "tags.sn" : {
                        "$eq" : "qz435698245"
                    }
                },
                "inputstage" : {
                    "stage" : "ixscan",
                    "keypattern" : {
                        "optime" : 1
                    },
                    "indexname" : "idx_optime",
                    "ismultikey" : false,
                    "multikeypaths" : {
                        "optime" : [ ]
                    },
                    "isunique" : false,
                    "issparse" : false,
                    "ispartial" : false,
                    "indexversion" : 2,
                    "direction" : "backward",
                    "indexbounds" : {
                        "optime" : [
                            "[maxkey, minkey]"
                        ]
                    }
                }
            }
        ]
    }

假如不用排序，删除 .sort({operationtime: -1})，其执行计划

"queryplanner" : {
        "plannerversion" : 1,
        "namespace" : "shqq_zp.duoduologmodel",
        "indexfilterset" : false,
        "parsedquery" : {
            "tags.sn" : {
                "$eq" : "qz435698245"
            }
        },
        "winningplan" : {
            "stage" : "fetch",
            "inputstage" : {
                "stage" : "ixscan",
                "keypattern" : {
                    "tags.sn" : 1
                },
                "indexname" : "idx_tsn",
                "ismultikey" : true,
                "multikeypaths" : {
                    "tags.sn" : [
                        "tags"
                    ]
                },
                "isunique" : false,
                "issparse" : true,
                "ispartial" : false,
                "indexversion" : 2,
                "direction" : "forward",
                "indexbounds" : {
                    "tags.sn" : [
                        "[\"qz435698245\", \"qz435698245\"]"
                    ]
                }
            }
        },
        "rejectedplans" : [ ]
    }

此时，执行查询确实变快了很多，在2s以内执行完毕。

删除optime字段索引后的执行计划

    "queryplanner" : {
        "plannerversion" : 1,
        "namespace" : "shqq_zp.duoduologmodel",
        "indexfilterset" : false,
        "parsedquery" : {
            "tags.sn" : {
                "$eq" : "qz435698245"
            }
        },
        "winningplan" : {
            "stage" : "sort",
            "sortpattern" : {
                "optime" : -1
            },
            "inputstage" : {
                "stage" : "sort_key_generator",
                "inputstage" : {
                    "stage" : "fetch",
                    "inputstage" : {
                        "stage" : "ixscan",
                        "keypattern" : {
                            "tags.sn" : 1
                        },
                        "indexname" : "idx_tsn",
                        "ismultikey" : true,
                        "multikeypaths" : {
                            "tags.sn" : [
                                "tags"
                            ]
                        },
                        "isunique" : false,
                        "issparse" : true,
                        "ispartial" : false,
                        "indexversion" : 2,
                        "direction" : "forward",
                        "indexbounds" : {
                            "tags.sn" : [
                                "[\"qz435698245\", \"qz435698245\"]"
                            ]
                        }
                    }
                }
            }
        },
        "rejectedplans" : [ ]
    }

删除这个索引后，查看报错

 {
    "message" : "executor error during find command :: caused by :: sort operation used more than the maximum 33554432 bytes of ram. add an index, or specify a smaller limit.",
    "optime" : "timestamp(1565681389, 1)",
    "ok" : 0,
    "code" : 96,
    "codename" : "operationfailed",
    "$clustertime" : {
        "clustertime" : "timestamp(1565681389, 1)",
        "signature" : {
            "hash" : "vodwe0bczyihrrvm08wpsfimvo0=",
            "keyid" : "6658116868433248258"
        }
    },
    "name" : "mongoerror"
}

原因比较明确：sort operation used more than the maximum 33554432 bytes of ram.，33554432 bytes算下来正好是32mb，而mongodb的sort操作是把数据拿到内存中再进行排序的，为了节约内存，默认给sort操作限制了最大内存为32mb，当数据量越来越大直到超过32mb的时候就自然抛出异常了！

因这个查看功能执行不多，并发不高。将系统排序内存由默认的32m调整到64m。

（此操作需谨慎，一般不建议修改，需要结合业务的使用情况，比如并发，数据量的大小；应优先考虑通过调整索引或集合的设计、甚至前端的设计来实现优化。）

db.admincommand({setparameter:1, internalqueryexecmaxblockingsortbytes:64554432})

（注意;这个设置在重启mongodb服务就会失效，重新变成默认的32m了）。

再次执行查询查看，不再报错。并且快速返回结果（2s）

因为还有其他需求，会根据optime字段查看，重新添加这个索引。

再次执行，也可以比较迅速的返回结果（2s）。

从以上分析我们可以推断;

（1）explain()查看的执行计划，有时候还是有偏差的。

（2）sort排序情况会影响索引的选择。即当internalqueryexecmaxblockingsortbytes不足以支持先查询（by tag.sn）后排序(by optime)时，系统自动选择了一个已排序好的索引（by optime），进行查看。

知识补充：

queryplanner.namespace:该值返回的是该query所查询的表；

queryplanner.indexfilterset:针对该query是否有indexfilter；

queryplanner.winningplan:查询优化器针对该query所返回的最优执行计划的详细内容；

queryplanner.rejectedplans：其他执行计划（非最优而被查询优化器reject的）的详细返回。

本文版权归作者所有，未经作者同意不得转载,谢谢配合！！！

上一篇：详解js几个绕不开的事件兼容写法

下一篇： jQuery实现base64前台加密解密功能详解