Mongo篇之排错之慢SQL查询

一、前言
在数据库中&＃xff0c;慢查询日志通常是用来进行优化数据库&＃xff0c;MySQL中存在慢查询&＃xff0c;Mongodb中也是如此。
在Mongo中的慢查询属于Mongo Database Profiler&＃xff0c;而且其信息详细。

接下来介绍下Mongo慢查询
二、开启 Profiling 功能
开启并控制Profiling 的方式有两种&＃xff0c;
第一种&＃xff0c;是直接在启动参数里直接进行设置&＃xff0c;启动MongoDB时加上–profile&＃61;级别 即可。
第二种是在客户端进行调用。
调用db.setProfilingLevel(级别) 命令来实时配置。
可以通过db.getProfilingLevel()命令来获取当前的Profile级别。

> db.setProfilingLevel(2);
{"was" : 0 , "ok" : 1}
> db.getProfilingLevel()


上面的级别可以取0&＃xff0c;1&＃xff0c;2 三个值&＃xff0c;他们表示的意义如下&＃xff1a;
　0 – 不开启
　1 – 记录慢命令 (默认为>100ms)
　2 – 记录所有命令
Profile 记录在级别1时会记录慢命令&＃xff0c;默认为100ms&＃xff0c;当然有默认就有设置&＃xff0c;其设置方法和级别一样有两种&＃xff0c;一种是通过添加–slowms启动参数配置。第二种是调用db.setProfilingLevel时加上第二个参数&＃xff1a;

db.setProfilingLevel( level , slowms )
db.setProfilingLevel( 1 , 10 );


1、查询 Profiling 记录

与MySQL的慢查询日志不同&＃xff0c;Mongo Profile 记录是直接存在系统db里的&＃xff0c;记录位置 system.profile &＃xff0c;所以&＃xff0c;我们只要查询这个Collection的记录就可以获取到我们的 Profile 记录了。

> db.system.profile.find()
{"ts" : "Thu Jan 29 2009 15:19:32 GMT-0500 (EST)" , "info" : "query test.$cmd ntoreturn:1 reslen:66 nscanned:0
query: { profile: 2 } nreturned:1 bytes:50" , "millis" : 0}
db.system.profile.find( { info: /test.foo/ } )
{"ts" : "Thu Jan 29 2009 15:19:40 GMT-0500 (EST)" , "info" : "insert test.foo" , "millis" : 0}
{"ts" : "Thu Jan 29 2009 15:19:42 GMT-0500 (EST)" , "info" : "insert test.foo" , "millis" : 0}
{"ts" : "Thu Jan 29 2009 15:19:45 GMT-0500 (EST)" , "info" : "query test.foo ntoreturn:0 reslen:102 nscanned:2
query: {} nreturned:2 bytes:86" , "millis" : 0}
{"ts" : "Thu Jan 29 2009 15:21:17 GMT-0500 (EST)" , "info" : "query test.foo ntoreturn:0 reslen:36 nscanned:2
query: { $not: { x: 2 } } nreturned:0 bytes:20" , "millis" : 0}
{"ts" : "Thu Jan 29 2009 15:21:27 GMT-0500 (EST)" , "info" : "query test.foo ntoreturn:0 exception bytes:53" , "millis" : 88}1、列出执行时间长于某一限度(5ms)的 Profile 记录&＃xff1a;
> db.system.profile.find( { millis : { $gt : 5 } } )
{"ts" : "Thu Jan 29 2009 15:21:27 GMT-0500 (EST)" , "info" : "query test.foo ntoreturn:0 exception bytes:53" , "millis" : 88}2、查看最新的 Profile 记录&＃xff1a;
db.system.profile.find().sort({$natural:-1})

Mongo Shell 还提供了一个比较简洁的命令show profile&＃xff0c;可列出最近5条执行时间超过1ms的 Profile 记录。

2、开启慢日志

1.查看mongodb慢日志是否开起use BJ_Rack;
db.getProfilingStatus();发现没有开户慢日志
2.开启慢日志&＃xff0c;设置超过100毫秒的操作为慢操作db.setProfilingLevel(1,100);
3.查看慢日志内容db.system.profile.find().sort({$natural:-1})
得到50个比较慢的操作日志.


3、查看当前操作

db.currentOp(true);
主要有以下信息&＃xff1a;client – 请求是由哪个客户端发起的
opid – 操作的opid&＃xff0c;有需要的话&＃xff0c;可以通过 db.killOp(opid) 杀死操作
secs_running/microsecs_running – 请求运行的时间&＃xff0c;如果这个值特别大就非常值得注意
query/ns: 对集合进行的具体操作
lock*&＃xff1a;锁相关参数


4、慢请求分析 – 全表扫描 COLLSCAN
如果在日志中看到关键字 COLLSCAN&＃xff0c;说明该查询在进行全表扫描&＃xff0c;通常这就是 CPU 异常飙高的主要原因。

4.1. 查看扫描文档数
system.profile 里 docsExamined 的值显示了本次查询的扫描文档数。

4.2. 解决办法 – 添加索引
最好针对查询语句建立索引&＃xff1a;

db.col.createIndex({“title”:1})
1
我们也可以在添加索引时增加传入可选参数&＃xff0c;例如&＃xff0c;在生产环境我们通常不希望索引添加的操作阻塞其他数据库操作&＃xff0c;这时就需要务必添加 background 参数&＃xff1a;

db.col.createIndex({“title”:1}, {‘background’, true})
1