MongoDB慢日志查詢

MongoDB system.profile

前言

Part1:寫在最前

    說到MongoDB的慢日志分析，就不得不提到profile分析器，profile分析器將記錄的慢日志寫到system.profile集合下，這個集合是一個固定集合。我們可以通過對這個集合的查詢，來了解當前的慢日志，進而對數據庫進行優化。

Part2:整體環境

MongoDB 3.2.5

實戰

Part1:輸出示范

在查詢system.profile的時候，我們能夠觀察到所有的操作，包括remove,update,find等等都會被記錄到system.profile集合中，該集合中包含了諸多信息，如：

{
   "op" : "query",
   "ns" : "test.c",
   "query" : {
      "find" : "c",
      "filter" : {
         "a" : 1
      }
   },
   "keysExamined" : 2,
   "docsExamined" : 2,
   "cursorExhausted" : true,
   "keyUpdates" : 0,
   "writeConflicts" : 0,
   "numYield" : 0,
   "locks" : {
      "Global" : {
         "acquireCount" : {
            "r" : NumberLong(2)
         }
      },
      "Database" : {
         "acquireCount" : {
            "r" : NumberLong(1)
         }
      },
      "Collection" : {
         "acquireCount" : {
            "r" : NumberLong(1)
         }
      }
   },
   "nreturned" : 2,
   "responseLength" : 108,
   "millis" : 0,
   "execStats" : {
      "stage" : "FETCH",
      "nReturned" : 2,
      "executionTimeMillisEstimate" : 0,
      "works" : 3,
      "advanced" : 2,
      "needTime" : 0,
      "needYield" : 0,
      "saveState" : 0,
      "restoreState" : 0,
      "isEOF" : 1,
      "invalidates" : 0,
      "docsExamined" : 2,
      "alreadyHasObj" : 0,
      "inputStage" : {
         "stage" : "IXSCAN",
         "nReturned" : 2,
         "executionTimeMillisEstimate" : 0,
         "works" : 3,
         "advanced" : 2,
         "needTime" : 0,
         "needYield" : 0,
         "saveState" : 0,
         "restoreState" : 0,
         "isEOF" : 1,
         "invalidates" : 0,
         "keyPattern" : {
            "a" : 1
         },
         "indexName" : "a_1",
         "isMultiKey" : false,
         "isUnique" : false,
         "isSparse" : false,
         "isPartial" : false,
         "indexVersion" : 1,
         "direction" : "forward",
         "indexBounds" : {
            "a" : [
               "[1.0, 1.0]"
            ]
         },
         "keysExamined" : 2,
         "dupsTested" : 0,
         "dupsDropped" : 0,
         "seenInvalidated" : 0
      }
   },
   "ts" : ISODate("2015-09-03T15:26:14.948Z"),
   "client" : "127.0.0.1",
   "allUsers" : [ ],
   "user" : ""}

Part2:輸出解讀

system.profile.op

這一項主要包含如下幾類

• insert

• query

• update

• remove

• getmore

• command

代表了該慢日志的種類是什么，是查詢、插入、更新、刪除還是其他。

system.profile.ns

該項表明該慢日志是哪個庫下的哪個集合所對應的慢日志。

system.profile.query

該項詳細輸出了慢日志的具體語句和行為

system.profile.keysExamined

該項表明為了找出最終結果MongoDB搜索了多少個key

system.profile.docsExamined

該項表明為了找出最終結果MongoDB搜索了多少個文檔

system.profile.keyUpdates

該項表名有多少個index key在該操作中被更改，更改索引鍵也會有少量的性能消耗，因為數據庫不單單要刪除舊Key，還要插入新的Key到B-Tree索引中

system.profile.writeConflicts

寫沖突發生的數量，例如update一個正在被別的update操作的文檔

system.profile.numYield

為了讓別的操作完成而屈服的次數，一般發生在需要訪問的數據尚未被完全讀取到內存中，MongoDB會優先完成在內存中的操作

system.profile.locks

在操作中產生的鎖，鎖的種類有多種，如下：

鎖的模式也有多種，如下：

system.profile.locks.acquireCoun

在各種不用的種類下，請求鎖的次數

system.profile.nreturned

該操作最終返回文檔的數量

system.profile.responseLength

結果返回的大小，單位為bytes，該值如果過大，則需考慮limit()等方式減少輸出結果

system.profile.millis

該操作從開始到結束耗時多少，單位為毫秒

system.profile.execStats

包含了一些該操作的統計信息，只有query類型的才會顯示

system.profile.execStats.stage

包含了該操作的詳細信息，例如是否用到索引

system.profile.ts

該操作執行時的時間

system.profile.client

哪個客戶端發起的該操作，并顯示出該客戶端的ip或hostname

system.profile.allUsers

哪個認證用戶執行的該操作

system.profile.user

是否認證用戶執行該操作，如認證后使用其他用戶操作，該項為空

——總結——

system.profile集合是定位慢SQL的手段之一，了解每一個輸出項的含義有助于我們更快的定位問題。由于筆者的水平有限，編寫時間也很倉促，文中難免會出現一些錯誤或者不準確的地方，不妥之處懇請讀者批評指正。