MongoDB慢日誌分析

在 MySQL中，慢查詢日誌是經常作為我們最佳化資料庫的依據，那在MongoDB中是否有類似的功能呢?答案是肯定的，那就是Mongo Database Profiler.不僅有，而且還有一些比MySQL的Slow Query Log更詳細的資訊。它就是我們這篇文章的主題。

　　開啟 Profiling 功能

　　有兩種方式可以控制 Profiling 的開關和層級，第一種是直接在啟動參數裡直接進行設定。

　　啟動MongoDB時加上–profile=層級 即可。

　　也可以在用戶端調用db.setProfilingLevel(層級) 命令來即時配置。可以通過db.getProfilingLevel()命令來擷取當前的Profile層級。

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

　　上面斜體的層級可以取0，1，2 三個值，他們表示的意義如下：

　　0 – 不開啟

　　1 – 記錄慢命令 (預設為>100ms)

　　2 – 記錄所有命令

　　Profile 記錄在層級1時會記錄慢命令，那麼這個慢的定義是什麼?上面我們說到其預設為100ms，當然有預設就有設定，其設定方法和層級一樣有兩種，一種是通過添加–slowms啟動參數配置。第二種是調用db.setProfilingLevel時加上第二個參數：

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

　　查詢 Profiling 記錄

　　與MySQL的慢查詢日誌不同，Mongo Profile 記錄是直接存在系統db裡的，記錄位置 system.profile ，所以，我們只要查詢這個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}

　　列出執行時間長於某一限度(5ms)的 Profile 記錄：

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

　　查看最新的 Profile 記錄：

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

　　Mongo Shell 還提供了一個比較簡潔的命令show profile，可列出最近5條執行時間超過1ms的 Profile 記錄。

　　Profile 資訊內容詳解：

　　ts-該命令在何時執行.

　　millis Time-該命令執行耗時，以毫秒記.

　　info-本命令的詳細資料.

　　query-表明這是一個query查詢操作.

　　ntoreturn-本次查詢用戶端要求返回的記錄數.比如, findOne()命令執行時 ntoreturn 為 1.有limit(n) 條件時ntoreturn為n.

　　query-具體的查詢條件(如x>3).

　　nscanned-本次查詢掃描的記錄數.

　　reslen-返回結果集的大小.

　　nreturned-本次查詢實際返回的結果集.

　　update-表明這是一個update更新操作.

　　fastmod-Indicates a fast modify operation. See Updates. These operations are normally quite fast.

　　fastmodinsert – indicates a fast modify operation that performed an upsert.

　　upsert-表明update的upsert參數為true.此參數的功能是如果update的記錄不存在，則用update的條件insert一條記錄.

　　moved-表明本次update是否移動了硬碟上的資料，如果新記錄比原記錄短，通常不會移動目前記錄，如果新記錄比原記錄長，那麼可能會移動記錄到其它位置，這時候會導致相關索引的更新.磁碟操作更多，加上索引更新，會使得這樣的操作比較慢.

　　insert-這是一個insert插入操作.

　　getmore-這是一個getmore 操作，getmore通常發生在結果集比較大的查詢時，第一個query返回了部分結果，後續的結果是通過getmore來擷取的。

　　MongoDB 查詢最佳化

　　如果nscanned(掃描的記錄數)遠大於nreturned(返回結果的記錄數)的話，那麼我們就要考慮通過加索引來最佳化記錄定位了。

　　reslen 如果過大，那麼說明我們返回的結果集太大了，這時請查看find函數的第二個參數是否唯寫上了你需要的屬性名稱。(類似 於MySQL中不要總是select *)

　　對於建立索引的建議是：如果很少讀，那麼盡量不要添加索引，因為索引越多，寫操作會越慢。如果讀量很大，那麼建立索引還是比較划算的。(和RDBMS一樣，貌似是廢話 -_-!!)

　　MongoDB 更新最佳化

　　如果寫查詢量或者update量過大的話，多加索引是會有好處的。以及～～～～(省略N字，和RDBMS差不多的道理)

　　Use fast modify operations when possible (and usually with these, an index). See Updates.

　　Profiler 的效率

　　Profiling 功能肯定是會影響效率的，但是不太嚴重，原因是他使用的是system.profile 來記錄，而system.profile 是一個capped collection 這種collection 在操作上有一些限制和特點，但是效率更高。

轉http://blog.zol.com.cn/3044/article_3043984.html