MongoDB如何使用profile分析慢查询的步骤

故里桃花落无踪,小楼轩窗山影重。若见瘦湖病西子,凋零秋风映山红。正是荷花成熟的季节,一朵朵荷花含苞怒放,满田野里的荷田闪烁着金光,一簇簇的荷花有的带着水珠乍开,有的含苞吐蕾,有的像个含羞的少女似开非开。

在MongoDB中,如果发生了慢查询,我们如何得到这些慢查询的语句,并优化呢?今天来看这块儿的一些心得。

01 如何收集慢查询?

在MongoDB中,通常可以开启profile来收集慢日志,查看当前profile状态的语句如下:

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集合中,可以通过下面的方法进行访问:

test1:PRIMARY>useadmin
switchedtodbadmin

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是一个固定集合,保存着超过设置的慢查询的结果。我们来看里面的一条慢查询。

利用下面的方法,来拿到一条数据,并对其中的关键字段进行注释说明:

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语法的基本用法:

后置写法
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如下:

db.getCollection('files').find(
{"cTime":{
"$gte":ISODate("2021-04-18"),
"$lt":ISODate("2021-04-19")
}}).limit(1000).explain("allPlansExecution")

输出的结果如下:

{
"queryPlanner":{  # 代表查询的执行计划
"plannerVersion":1,  # 版本号
"namespace":"fs.files",  # 查询的命名空间,也就是集合名称
"indexFilterSet":false,  # 是否使用了索引过滤,注意,它并不能判定是否使用了索引
"parsedQuery":{  # 查询语法解析树
"$and":[
{
"cTime":{
"$lt":ISODate("2021-04-19T00:00:00Z")
}
},
{
"cTime":{
"$gte":ISODate("2021-04-18T00:00:00Z")
}
}
]
},
"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":[
"[newDate(1618704000000),newDate(1618790400000))"
]
}
}
}
},
"rejectedPlans":[] # 候选的没被选中的查询计划
},
"serverInfo":{
"host":"xxxx",
"port":24999,
"version":"3.2.8",
"gitVersion":"ed70e33130c977bda0024c125b56d159573dbaf0"
},
"ok":1
}

首先解释下stage的几个阶段:

  1. COLLSCAN---全表扫描
  2. IXSCAN---索引扫描
  3. FETCH---根据索引去检索文档
  4. SHARD_MERGE---合并分片结果
  5. IDHACK---针对id进行查询
  6. LIMIT---执行limit

了解了这些stage的阶段之后,我们可以看到,一个查询的过程是一层一层解析的,所以可以看到,stage这个字段有嵌套的情况。winningPlan中的执行计划也是按照一层一层的顺序去执行:

1、先执行最内层的索引扫描(IXSCAN);

2、再执行外面的FETCH,根据索引去拿文档

3、执行最后一步的limit,取指定数目个结果返回给客户端

以上就是MongoDB profile分析慢查询的示例的详细内容,更多关于MongoDB profile分析慢查询的资料请关注其它相关文章!