在mongodb中，如果发生了慢查询，我们如何得到这些慢查询的语句，并优化呢？今天来看这块儿的一些心得。
01 如何收集慢查询？
在mongodb中，通常可以开启profile来收集慢日志，查看当前profile状态的语句如下：
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 |
test1: primary > db.getprofilingstatus() { "was" : 2, "slowms" : 0, "samplerate" : 1, "$glestats" : { "lastoptime" : timestamp (0, 0), "electionid" : objectid( "7fffffff0000000000000005" ) }, "lastcommittedoptime" : timestamp (1619186976, 2), "$configserverstate" : { "optime" : { "ts" : timestamp (1619186976, 1), "t" : numberlong(2) } }, "$clustertime" : { "clustertime" : timestamp (1619186976, 2), "signature" : { "hash" : bindata(0, "zvwfpgc0kfxiempj7mbpdrononi=" ), "keyid" : numberlong( "6904838687771590657" ) } }, "operationtime" : timestamp (1619186976, 2) } |
这里我们可以看到2个关键参数，分别是was和slowms，其中：
was=0,代表不记录任何的语句；
was=1,代表记录执行时间超过slowms的语句
was=2,代表记录所有的语句
slowms代表语句的阈值，单位是ms
上图中的结果代表我们的实例会收集所有的查询语句。profile收集的查询语句结果存放在admin数据库中的system.profile集合中，可以通过下面的方法进行访问：
|
1 2 3 4 5 6 7 8 9 10 11 12 13 |
test1: primary > use admin switched to db admin
test1: primary > db.system.profile.find({ 'op' : 'query' },{ 'op' :1, 'ns' :1, 'millis' :1, 'ts' :1}) { "op" : "query" , "ns" : "admin.system.users" , "millis" : 0, "ts" : isodate( "2020-08-27t07:22:14.815z" ) } { "op" : "query" , "ns" : "admin.system.users" , "millis" : 0, "ts" : isodate( "2020-08-27t07:22:15.139z" ) } { "op" : "query" , "ns" : "admin.system.users" , "millis" : 0, "ts" : isodate( "2020-08-27t07:22:15.141z" ) } { "op" : "query" , "ns" : "admin.system.users" , "millis" : 0, "ts" : isodate( "2020-08-27t07:22:15.239z" ) } { "op" : "query" , "ns" : "admin.system.version" , "millis" : 0, "ts" : isodate( "2020-08-27t07:22:16.155z" ) } { "op" : "query" , "ns" : "admin.system.version" , "millis" : 0, "ts" : isodate( "2020-08-27t07:22:16.192z" ) } { "op" : "query" , "ns" : "admin.system.users" , "millis" : 0, "ts" : isodate( "2020-08-27t07:22:16.225z" ) } { "op" : "query" , "ns" : "admin.system.users" , "millis" : 0, "ts" : isodate( "2020-08-27t07:22:16.273z" ) } { "op" : "query" , "ns" : "admin.system.version" , "millis" : 0, "ts" : isodate( "2020-08-27t07:22:16.276z" ) } |
02 system.profile慢查询集合分析
admin数据库中的system.profile是一个固定集合，保存着超过设置的慢查询的结果。我们来看里面的一条慢查询。
利用下面的方法，来拿到一条数据，并对其中的关键字段进行注释说明：
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 |
test1: primary > db.system.profile.findone({ 'op' : 'query' }) { "op" : "query" , # 操作类型 "ns" : "admin.system.users" , # 命名空间 "command" : { "find" : "system.users" , "filter" : { "_id" : "admin.root" # 过滤的字段 }, "limit" : 1, "singlebatch" : true , "lsid" : { "id" : uuid( "a6034f5e-77c1-4b19-9669-60e1253edf4b" ) }, "$readpreference" : { "mode" : "secondarypreferred" }, "$db" : "admin" }, "keysexamined" : 1, # 扫描的索引数 "docsexamined" : 1, # 扫描的行数 "cursorexhausted" : true , "numyield" : 0, "nreturned" : 1, # 返回的值的行数 "locks" : { xxxx # 锁信息 }, "flowcontrol" : {
}, "storage" : { }, "responselength" : 647, "protocol" : "op_query" , "millis" : 0, # 这个查询的执行时间，因为我们设置的profilestatus是0，因此所有操作都被记录了。 "plansummary" : "idhack" , # 针对_id进行查询 "execstats" : { # 查询执行状态 "stage" : "idhack" , "nreturned" : 1, "executiontimemillisestimate" : 0, "works" : 2, "advanced" : 1, "needtime" : 0, "needyield" : 0, "savestate" : 0, "restorestate" : 0, "iseof" : 1, "keysexamined" : 1, "docsexamined" : 1 }, "ts" : isodate( "2020-08-27t07:22:14.815z" ), "client" : "xx.xx.xx.xx" , # 查询的客户端ip地址 "allusers" : [ # 所有的用户信息 { "user" : "root" , "db" : "admin" } ], "user" : "root@admin" # 使用的用户信息 } |
03 慢查询分析利器---explain
通常情况下，我们可以使用mongodb的explain语法来分析一个语句的查询性能，包含是否用到索引、扫描行数等信息，explain语法的基本用法:
|
1 2 3 4 |
后置写法 db.system.profile.find({ 'op' : 'query' }).explain() 前置写法 db.system.profile.explain().find({ 'op' : 'query' }) |
其中，explain可以放在查询语句的后面或者前面，当然find语法也可以是update、remove、insert
explain语法的输出分为3种不同的详细程度，分别如下：
三种清晰度模式，清晰度越高，则输出的信息越全，默认情况下是queryplanner：
1、queryplanner模式(默认)
db.products.explain().count( { quantity: { $gt: 50 } } )
2、executionstats模式
db.products.explain("executionstats").count( { quantity: { $gt: 50 } } )
3、allplansexecution模式
db.products.explain("allplansexecution").count( { quantity: { $gt: 50 } } )
其中，allplansexecution模式输出的信息最多。
下面是一个explain语法的输出内容，查询的sql如下：
|
1 2 3 4 5 |
db.getcollection( 'files' ).find( { "ctime" :{ "$gte" :isodate( "2021-04-18" ), "$lt" :isodate( "2021-04-19" ) }}).limit(1000).explain( "allplansexecution" ) |
输出的结果如下：
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 |
{ "queryplanner" : { # 代表查询的执行计划 "plannerversion" : 1, # 版本号 "namespace" : "fs.files" , # 查询的命名空间，也就是集合名称 "indexfilterset" : false , # 是否使用了索引过滤，注意，它并不能判定是否使用了索引 "parsedquery" : { # 查询语法解析树 "$and" : [ { "ctime" : { "$lt" : isodate( "2021-04-19t0z" ) } }, { "ctime" : { "$gte" : isodate( "2021-04-18t0z" ) } } ] }, "winningplan" : { # 最终选择的查询计划 "stage" : "limit" , # 查询的阶段，很重要，下面详细介绍 "limitamount" : 1000, # 查询结果的limit值 "inputstage" : { "stage" : "fetch" , "inputstage" : { "stage" : "ixscan" , # 代表索引扫描 "keypattern" : { "ctime" : 1 }, "indexname" : "ctime_1" , # 索引名称 "ismultikey" : false , # 下面4个字段都是索引类型分析 "isunique" : false , "issparse" : false , "ispartial" : false , "indexversion" : 1, "direction" : "forward" , "indexbounds" : { "ctime" : [ "[new date(1618704000000), new date(1618790400000))" ] } } } }, "rejectedplans" : [ ] # 候选的没被选中的查询计划 }, "serverinfo" : { "host" : "xxxx" , "port" : 24999, "version" : "3.2.8" , "gitversion" : "ed70e33130c977bda0024c125b56d159573dbaf0" }, "ok" : 1 } |
首先解释下stage的几个阶段：
collscan---全表扫描 ixscan---索引扫描 fetch---根据索引去检索文档 shard_merge---合并分片结果 idhack---针对id进行查询 limit---执行limit了解了这些stage的阶段之后，我们可以看到，一个查询的过程是一层一层解析的，所以可以看到，stage这个字段有嵌套的情况。winningplan中的执行计划也是按照一层一层的顺序去执行：
1、先执行最内层的索引扫描(ixscan)；
2、再执行外面的fetch，根据索引去拿文档
3、执行最后一步的limit，取指定数目个结果返回给客户端
以上就是mongodb profile分析慢查询的示例的详细内容，更多关于mongodb profile分析慢查询的资料请关注服务器之家其它相关文章！
查看更多关于MongoDB使用profile分析慢查询的步骤的详细内容...