MongoDB: Database Profiler

文章来源：http://www.mongodb.org/display/DOCS/Database+Profiler

 

 

刚接触mongodb的时候，曾经用过profile，但是没有这么详细的阅读这篇文档，可能是自己的系统的访问规模还不够大吧，如果访问量大的时候必然会让我们查看一些性能方面的问题，这个时候我们就要考虑一下mongodb profile了，下面开始详细的分析：

• 什么是Database Profiler？

它是mongodb提供的一个用来分析mongodb性能的，比如有哪些操作的执行时间超过了期望的阀值，我们就可以在enable profiler的情况下从system.profile查看到你想要的一些信息。

 

• mongodb不同版本的支持情况？

v1.9之前的版本只能够在primary上节点使用，v1.9+将会在secondaries也得到支持

 

• profiling支持哪几个level?

目前有三个level: 0, 1, 2

 

0 - off1 - log slow operations (by default, >100ms is considered slow)2 - log all operations 

 

• 如果enable profiling和 check profiling状态?

默认情况是profiling是disable的，你可以通过下面的命令行enable:

 

> db.setProfilingLevel(1,20) // log slow operations, slow threshold=20ms> db.getProfilingStatus() // new shell helper method as of v1.7+{ "was" : 1, "slowms" : 20 } 

 

setProfilingLevel就是用来设置profiling级别的，0代表关闭； 1代表监控哪些慢的操作，至于慢的标准可以通过第二个参数来设定，比如我认为超过了20ms的操作就是慢的操作了；2则会记录所有的操作。

 

getProfilingStatus则是用来查看prifiling的，was代表设定的级别；slowms则表示一个时间阀值。

 

当然你也可以在启动mongodb的时候，通过下面两个参数来设定：

 

$ mongo --profile=1 --slowms=15 

 

• profiling信息存储在哪里？如何查看？

profiling是针对数据库设置是否enable的，Profiling data会记录在数据库的system.profile这个collection里面，我们可以使用find来查看里面的内容，所以find使用一些查询限定符可以帮助我们查看我们关注的record:

 

随便看一下：

 

> 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 <br>query: { profile: 2 } nreturned:1 bytes:50" , "millis" : 0} 

 

想看一下没有 $cmd的记录：

 

> 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 <br>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 <br>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} 

 

想看一下执行时间超过了5ms的记录：

 

> 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} 

 

想看一下最近的一些记录：

 

db.system.profile.find().sort({$natural:-1}) 

 

所以find的限定符能够给我们带来很大的帮助，让我们快速的定位到指定位置。

 

• system.profile里面的每条记录都代表什么意思呢？

ts: 这条记录的产生时间；

millis: 操作的执行多少ms，这个时间不包括获取锁和网络传输消耗的时间，仅仅是mongodb进程处理它的时间；

info: 对操作的详细描述了：

 

1） query

query开头，表示这条记录是条查询语句，它后面会跟着四个参数信息，ntoreturn表示客户端的查询请求要返回的object个数，比如findOne操作，这里则会显示1，limit操作则显示limit的个数，0则表示没有限制，有多少返回多少了；query表示具体的查询时时使用的限定符，如{$gte: {x : 2}}；nscanned表示为了找到符合查询条件的documents， mongodb查看了多少个documents；reslen表示查询返回的结果有多少bytes；nreturned表示这次查询操作返回多少个documents。

 

2) update

update开头，表示这条记录是更新或者插入语句，后面会跟着五个参数信息，fastmode表示该操作不需要等待执行完毕就可以返回了；fastmodinsert表示该操作是insert操作，而且无需等待执行完毕就可以返回，可以认为是异步；upsert说明我们调用update时候设定了upsert为true，它表示如果查找不到指定条件的记录就插入这条记录，否则更新查找到记录；moved表示更新object的时候需要移动磁盘空间位置，update本来是in-place update的，但是因为object变大了，原来的空间大小已经放不下了，所以不得不搬家，这种会降低更新速度；key updates表示这次更新影响了多少个index上的更改。

 

3) insert

insert开头，表示这条记录是插入语句

 

4) getmore

 

getmore开头，表示客户端是接着上面的find来获取更多的documents，一般一个find只会先返回一部分document给客户端，后面的document借助cursor的next方法向mongodb发送请求，这个时候我们就能在system profile中看到getmore记录了。

 

• 开启profile有什么影响没？

开启的时候会对mongodb速度有一定影响，尽管不会很严重，Profile data是保存在collection system profile中的，而这个collection是capped collection, 所以默认的情况下这个collection不是很大，所以这里面通常保存的最近的一些操作的记录。

 

• 如何优化查询性能呢？

1) 当nscanned的大小远远大于nreturned的时候，说明数据库在从大量的documents中查找我们想要的documents，这个时间要对查询的条件建索引了。

 

2) 当reslen的值很大的时候，表示mongodb返回了大量的数据给client， 比如1M，这个时候我们时候可以给find第二个参数，让查询操作只返回我们关心的那些fields，而不是盲目的全部返回给client。

 

• 如何优化更新性能呢？

1）同上1

 

2) 使用fast modify

 

 

上面的内容全部来自mongodb自己的offical文档，有兴趣自己可以读读英文文档并亲自动手操作一下mongodb profile，看看实际效果。