MongoDB的慢查询问题解决思路
慢查询工具帮助我们定位问题sql语句,该工具在运行的实例上收集有关MongoDB的写操作,游标,数据库命令等,可以在数据库级别开启该工具,也可以在实例级别开启(即单独某个集合上开启)。该工具会把收集到的所有都写入到system.profile集合中,该集合是一个capped
collection。(即是一个容量固定的集合),更多信息见https://docs.mongodb.com/manual/tutorial/manage-the-database-profiler/
慢查询分析流程
慢查询日志一般作为优化步骤里的第一步。通过慢查询日志,定位每一条语句的查询时间。比如超过了200ms,那么查询超过200ms的语句需要优化。然后它通过.explain()
解析影响行数是不是过大,所以导致查询语句超过200ms。
所以优化步骤一般就是:
1.用慢查询日志(system.profile)找到超过200ms的语句
2.然后再通过.explain()解析影响行数,分析为什么超过200ms
3.决定是不是需要添加索引
慢查询参数设置
Profiling级别说明
0:关闭,不收集任何数据。
1:收集慢查询数据,默认是100毫秒。
2:收集所有数据 (可能对性能产生影响)
开启profiling的方式
通过mongo shell(cmd中输入命令)
#查看状态:级别和时间
PRIMARY> db.getProfilingStatus()
{ "was" : 1, "slowms" : 200 }
#查看级别
PRIMARY> db.getProfilingLevel()
1
#设置级别
PRIMARY> db.setProfilingLevel(2)
{ "was" : 1, "slowms" : 100, "ok" : 1 }
#设置级别和时间
PRIMARY> db.setProfilingLevel(1,200)
{ "was" : 2, "slowms" : 100, "ok" : 1 }
注意:
1
以上要操作要是在test集合下面的话,只对该集合里的操作有效,要是需要对整个实例有效,则需要在所有的集合下设置或则在开启的时候开启参数
2 每次设置之后返回给你的结果是修改之前的状态(包括级别、时间参数)。
备注:需要在shell中认证用户权限 ####不通过mongo shell:
1.在mongoDB启动的时候 mongod –profile=1 –slowms=200
2.或者当Mongodb以windows服务启动的时候,先停止服务,在配置在配置文件里(mongodb.conf)尾部添加下列文字,重启服务
operationProfiling:
slowOpThresholdMs: <int>
mode: off | slowOp | all
如果我们想记录查找耗时在1000ms的语句,如下:
operationProfiling:
slowOpThresholdMs: 1000
mode: 1
两者对比:通过shell可以做到不重启Mongodb,但需要用户认证;不通过shell开启慢查询,则需要重启Mongodb
关闭Profiling
\> db.setProfilingLevel(0) { "was" : 1, "slowms" : 200,
"ok" : 1 } \#\#\#修改慢查询日志的大小
开启profile功能后,会将记录日志插入到system.profile集合
#关闭Profiling
> db.setProfilingLevel(0)
{ "was" : 0, "slowms" : 200, "ok" : 1 }
#删除system.profile集合
drug:PRIMARY> db.system.profile.drop()
true
#创建一个新的system.profile集合
drug:PRIMARY> db.createCollection( "system.profile", { capped: true, size:4000000 } )
{ "ok" : 1 }
#重新开启Profiling
drug:PRIMARY> db.setProfilingLevel(1)
{ "was" : 0, "slowms" : 200, "ok" : 1 }
慢查询参数说明
- 首先通过 db.system.profile.find()
查看当前所有的慢查询日志,下面的例子说明各个参数的含义,更多信息见:http://docs.mongodb.org/manual/reference
/database-profiler/
可以任意挑选一条来观察,例子如下
{
“op” : “query”,
#操作类型,有insert、query、update、remove、getmore、command“ns” : “HTCDR.HT_PATIENT_MEDICAL_RECORD”, #查询表名
“query” : {
“find” : “HT_PATIENT_MEDICAL_RECORD”,
“filter” : {
“sfzh” : “33022519340217861X”,
“jzrq” : {
“$gt” : “20170528160252”,
“$lt” : “20180528160252”
}
},
“sort” : {
“jzrq” : 1
},
“projection” : {
“jzlsh” : 1,
“mzzybz” : 1,
“cyrq” : 1,
“tjlbdm” : 1,
“yljgmc” : 1,
“yljgdm” : 1,
“_id” : 0,
“jzksmc” : 1,
“zyzdmc” : 1,
“zzysxm” : 1,
“jzrq” : 1
},
“limit” : 100
},
“keysExamined” : 0,
“docsExamined” : 2256829, #查询过的文档数目
“hasSortStage” : true,
#当查询请求里包含排序的时候,如果排序无法通过索引满足,MongoDB
会在内存李结果进行排序,要么不出现,出现只能为true,代表不能用索引获取排序信息
“cursorExhausted” : true,
“numYield” : 17632, #该查询为其他查询让出锁的次数
“locks” : {
#锁信息,R:全局读锁;W:全局写锁;r:特定数据库的读锁;w:特定数据库的写锁
“Global” : {
“acquireCount” : {
“r” : NumberLong(35266)
}
},
“Database” : { #数据库锁等待
“acquireCount” : {
“r” : NumberLong(17633)
}
},
“Collection” : { #集合锁等待
“acquireCount” : {
“r” : NumberLong(17633)
}
}
},
“nreturned” : 6, #返回文档数目
“responseLength” : 1401,
#返回文档的总大小,如该值过大,考虑只取需要的字段
“protocol” : “op_query”,
“millis” : 5641, #插叙操作耗时
“planSummary” : “COLLSCAN”, #查询计划类型
“execStats” : { #具体的执行细节
“stage” : “PROJECTION”,
“nReturned” : 6,
“executionTimeMillisEstimate” : 5362,
“works” : 2256839,
“advanced” : 6,
“needTime” : 2256832,
“needYield” : 0,
“saveState” : 17632,
“restoreState” : 17632,
“isEOF” : 1,
“invalidates” : 0,
“transformBy” : {
“jzlsh” : 1,
“mzzybz” : 1,
“cyrq” : 1,
“tjlbdm” : 1,
“yljgmc” : 1,
“yljgdm” : 1,
“_id” : 0,
“jzksmc” : 1,
“zyzdmc” : 1,
“zzysxm” : 1,
“jzrq” : 1
},
“inputStage” : {
“stage” : “SORT”,
“nReturned” : 6,
“executionTimeMillisEstimate” : 5212,
“works” : 2256839,
“advanced” : 6,
“needTime” : 2256832,
“needYield” : 0,
“saveState” : 17632,
“restoreState” : 17632,
“isEOF” : 1,
“invalidates” : 0,
“sortPattern” : {
“jzrq” : 1
},
“memUsage” : 3193,
“memLimit” : 33554432,
“limitAmount” : 100,
“inputStage” : {
“stage” : “SORT_KEY_GENERATOR”,
“nReturned” : 6,
“executionTimeMillisEstimate” : 5122,
“works” : 2256832,
“advanced” : 6,
“needTime” : 2256825,
“needYield” : 0,
“saveState” : 17632,
“restoreState” : 17632,
“isEOF” : 1,
“invalidates” : 0,
“inputStage” : {
“stage” : “COLLSCAN”,
“filter” : {
“$and” : [{
“sfzh” : {
“$eq” : “33022519340217861X”
}
}, {
“jzrq” : {
“$lt” : “20180528160252”
}
}, {
“jzrq” : {
“$gt” : “20170528160252”
}
}]
},
“nReturned” : 6,
“executionTimeMillisEstimate” : 4982,
“works” : 2256831,
“advanced” : 6,
“needTime” : 2256824,
“needYield” : 0,
“saveState” : 17632,
“restoreState” : 17632,
“isEOF” : 1,
“invalidates” : 0,
“direction” : “forward”,
“docsExamined” : 2256829
}
}
}
},
“ts” : ISODate(“2018-05-28T08:02:58.139Z”),
“client” : “172.16.10.202”,
“allUsers” : [{
“user” : “htcdr”,
“db” : “HTCDR”
}],
“user” : “htcdr\@HTCDR”
}通过上面的例子我们可以看到这个时光轴查询花了大概
5秒(mills字段),出现了COLLSCAN意味着全表扫描,扫描了 2256829文档( docsExamined),所以效率低下,我们可以重建索引,即
sfzh_1_jzrq_-1,再次查询发现system.profile集合中没有新增文档,说明查询时间在1000ms以内,达到优化目的
如果发现 millis 值比较大,那么就需要作优化。
如果docsExamined数很大,或者接近记录总数(文档数),那么可能没有用到索引查询,而是全表扫描。
如果 docsExamined 值高于 nreturned
的值,说明数据库为了找到目标文档扫描了很多文档。这时可以考虑创建索引来提高效率。
system.profile补充
system.profile.execStats.stage的几个典型值, COLLSCAN for 全表扫描(尽量避免)
IXSCAN for 索引扫描 FETCH for 利用索引去数据库去取数据
常用慢日志操作
返回最近的10条记录
db.system.profile.find().limit(10).sort({ ts : -1 }).pretty()
返回所有的操作,除command类型的
db.system.profile.find( { op: { $ne : 'command' } } ).pretty()
返回特定集合
db.system.profile.find( { ns : 'mydb.test' } ).pretty()
返回大于5毫秒慢的操作
db.system.profile.find( { millis : { $gt : 5 } } ).pretty()
从一个特定的时间范围内返回信息
db.system.profile.find(
{
ts : {
$gt : new ISODate("2012-12-09T03:00:00Z") ,
$lt : new ISODate("2012-12-09T03:40:00Z")
}
}
).pretty()
特定时间,限制用户,按照消耗时间排序
db.system.profile.find(
{
ts : {
$gt : new ISODate("2011-07-12T03:00:00Z") ,
$lt : new ISODate("2011-07-12T03:40:00Z")
}
},
{ user : 0 }
).sort( { millis : -1 } )
参考文章
MongoDB干货系列2-MongoDB执行计划分析详解
http://www.mongoing.com/eshu_explain1
http://www.mongoing.com/eshu_explain2
http://www.mongoing.com/eshu_explain3
mongodb之慢查询分析
http://blog.51cto.com/yucanghai/1705195