mtools-你可能沒用過的mongodb神器

標籤：post   業務   獨立   shel   非官方   叢集管理   orm   har   3.5   

前言

接觸 mongodb 已經有一段時間了，從一開始的不瞭解，到現在已慢慢適應這個nosql領域的佼佼者，還是經曆了不少波折。
在進行資料庫選型的時候，許多人總是喜歡拿 mongodb和mysql、oracle做比較，並總結出一套非常詳盡的分析結果。
但是這種分析往往改變不了管理者(或是架構師)的決策。因為往往在決定使用某種技術之前，管理者可能已經有了答案，而分析對比則是為了讓決策更加篤定，更有依據。
儘管這個說法有些令人沮喪，但現實中確實如此。

眾所周知的是，mongodb不是關係型資料庫，不遵循經典的"三個範式"，也沒有表關聯、事務(直到最新的4.0版本才實現)等傳統資料庫的特性。
然而mongodb內建的無schema、複本集、自動分區等能力獲得了大量的青睞，而更值得一提的是資料庫本身提供了大量的監控、分析工具命令，對營運管理提供了很大的便利性。

既然談到了工具，本文要介紹的是一款叫mtools的工具。在此段期間，筆者一直在組織線上資料庫日誌的收集分析，由於沒有較好的工具支撐，每次的分析工作總需要投入大量的人力。
在這種情況下，mtools 便可以協助於大幅度提升效率，下面的篇幅開始介紹這個工具。

mtools是什麼

mtools 是由MongoDB 官方工程師實現的一套工具集，可以很快速的日誌查詢分析、統計功能，此外還支援本地叢集部署管理，非常便於新手學習。
github地址，該套工具非官方公司維護，僅由作者做開源維護，目前項目的更新頻度並不高，但已經有大量的使用者。

mtools使用python編寫完成，可通過pipy網站 擷取；
該工具包含了以下幾個關鍵組件

mlaunch
支援快速搭建本地測試環境，可以是單機、複本集、分區叢集。
mlogfilter
日誌過濾組件，支援按時間檢索慢查詢、全表掃描操作，支援通過多個屬性進行資訊過濾，支援輸出為JSON格式。
mplotqueries
支援將日誌分析結果轉換為圖表形式，依賴於tkinter(python圖形模組)、和matplotlib模組。
mlogvis
支援將日誌分析結果轉換為一個獨立的HTML頁面，實現與mplotqueries同樣的功能。

網上關於mtools的資料已經不少，包括其官方文檔的說明都比較詳細，這裡僅對工具的使用情境做簡單介紹

可以做什麼1. 簡易叢集管理

執行以下命令，可以啟動一個單節點的mongod進程。

# mlaunch init --singlelaunching: "mongod" on port 27017

可對比單節點手工搭建

再執行另外一個稍複雜點的命令：

# mlaunch init --sharded 2 --replicaset --nodes 3 --config 3 --csrs --mongos 3 --port 27050 --auth --username admin --password [email protected] --auth-db admin launching: "mongod" on port 27053launching: "mongod" on port 27054launching: "mongod" on port 27055launching: "mongod" on port 27056launching: "mongod" on port 27057launching: "mongod" on port 27058launching: config server on port 27059launching: config server on port 27060launching: config server on port 27061replica set 'configRepl' initialized.replica set 'shard01' initialized.replica set 'shard02' initialized.launching: mongos on port 27050launching: mongos on port 27051launching: mongos on port 27052adding shards. can take up to 30 seconds...Username "admin", password "[email protected]"

什嗎？已經完成了一個雙複本集分區叢集的搭建！27050是開始端點口，--sharded 2 表示有兩個分區，--replicaset 表示啟用複本集，
--config 3 --csrs 表示config 使用CSRS結構的3節點複本集，--auth 表示啟用鑒權， --username --password 為初始化的使用者，預設該使用者將擁有所有庫的系統管理權限。
整個叢集的架構如所示：

可以通過以下命令進行管理

]# mlaunch listPROCESS PORT STATUS PID()mongos 27050 running 13017mongos 27051 running 13059mongos 27052 running 13093()config server 27059 running 12134config server 27060 running 12217config server 27061 running 12261()shard01    primary 27053 running 12404    secondary 27055 running 12559    mongod 27054 running 12509()shard02    secondary 27057 running 12793    secondary 27058 running 12845    mongod 27056 running 12697()() auth: "admin:[email protected]"

啟動停止

# mlaunch stopsent signal 15 to 12 processes.# mlaunch startlaunching: config server on port 27059...

這是相當方便的，可以對比分布式叢集搭建手記 這篇文章所描述的流程，相比手工搭建，該工具可縮減幾十倍時間。

2. 日誌統計

mloginfo 是一個用於做日誌資訊統計的工具，輸入以下命令：

# mloginfo mongo.log     source: mongo.log       host: MongoDB_1:10001        start: 2018 May 18 16:33:11.692        end: 2018 May 19 01:13:08.290date format: iso8601-local     length: 144480     binary: mongod    version: 3.4.10    storage: wiredTiger

可以看到日誌的起止時間範圍、主機連接埠、版本、資料庫引擎等概要資訊。

串連數
當我們希望檢查用戶端的串連數情況時，可以執行以下命令：

# mloginfo mongo.log --connectionsCONNECTIONS     total opened: 14282     total closed: 14358    no unique IPs: 4socket exceptions: 0127.0.0.1 opened: 12886 closed: 12889172.21.0.29 opened: 658 closed: 716172.21.0.28 opened: 461 closed: 490172.21.0.27 opened: 277 closed: 263

通過這樣的資訊，進一步判斷是否存在串連過載等異常情況。

事件統計
又或者，你希望統計出當前某些事件的發生頻次。

# mloginfo mongo.log --distinctDISTINCT   14358 end connection ... ( ... now open)   14281 connection accepted from ... # ... ( ... now open)   13075 received client metadata from ... :    5340 Successfully authenticated as principal ... on    1194 Use of the aggregate command without the 'cursor'     338 build index on: ... properties:     244 building index using bulk method; build may temporarily use up to ... megabytes of RAM     234 ns: ... key: ... name:     219 Refreshing chunks for collection ... based on version     218 Refresh for collection ... took ... ms and found version     179 Index ... :

慢查詢
在業務問題分析中，慢查詢是最常見的問題。

# mloginfo mongo.log --queries --sort countQUERIESnamespace                  operation      pattern                              count      min (ms)    max (ms)  mean (ms)    95%-ile (ms) sum (ms)nsspace.StatisticsHour   find             {"$and": [{"recordTime": 1}]..}     22331      276       747          345          414.0            7720736nsspace.StatisticsHour   getmore       {"aggregate": 1, "cursor": ...}]}    231          200      304          227          272.0             52587dmspace.DeviceInfo      remove          {"_id": 1}                              109        205      1786          420          771.0            45860cmspace.DeviceData     update          {"appId": 1, "deviceId": 1}          95          201      1802          431          824.5            40966dmspace.TaskHistory    update          {"_id": 1}                                54          268      2643          692          2019.0          37413nsspace.StatisticsDay     find              {"$and": [{"recordTime": 1}], ..}   31          201      348            241          345.0            7472

如上面的命令，將顯示所有慢查詢，並按出現次數排序。

重啟資訊

# mloginfo mongo.log --restartRESTARTS   May 18 21:37:51 version 3.4.10   May 18 21:48:33 version 3.4.10

通過檢測重啟資訊，對系統潛在的故障進行評估分析。

複本集切換
同樣，主備切換可能導致一定的業務失敗，需要定期監測。

# mloginfo mongo.log --rsstateRSSTATEdate host state/message()May 18 21:48:53 172.21.0.29:10001 ARBITERMay 18 21:49:26 172.21.0.28:10001 SECONDARY

3. 日誌過濾

mlogfilter是一個強大的日誌過濾模組，相比linux 的grep/egrep的文本過濾，該組件可以對日誌內容進行解析，並按我們想要的結果進行過濾。

查看超過10s的慢操作

# mlogfilter mongo.log --slow 10000 --shorten 2002018-05-18T21:49:04.069+0800 I REPL [ReplicationExecutor] Starting an election, since we've seen no PRIMARY in the past 10000ms2018-05-18T21:50:22.988+0800 I COMMAND [conn31] command dmspace.fs.chunks appName: "Mong...quireCount: { w: 46 } }, oplog: { acquireCount: { w: 46 } } } protocol:op_command 10804ms2018-05-18T21:50:22.988+0800 I COMMAND [conn44] command dmspace.DeviceInfo command: inse...quireCount: { w: 16 } }, oplog: { acquireCount: { w: 16 } } } protocol:op_command 10931ms2018-05-18T21:50:22.988+0800 I COMMAND [conn157] command dmspace.Lwm2mDevice command...quireCount: { w: 16 } }, oplog: { acquireCount: { w: 16 } } } protocol:op_command 10762ms2018-05-18T21:50:22.988+0800 I COMMAND [conn156] command dmspace.TaskHistory command: in...quireCount: { w: 16 } }, oplog: { acquireCount: { w: 16 } } } protocol:op_command 10927ms2018-05-18T21:50:50.104+0800 I COMMAND [conn31] command dmspace.DeviceInfo appName: "Mon...quireCount: { w: 16 } }, oplog: { acquireCount: { w: 16 } } } protocol:op_command 10020ms2018-05-18T21:50:51.203+0800 I COMMAND [conn156] command dmspace.fs.chunks command: inse...quireCount: { w: 51 } }, oplog: { acquireCount: { w: 51 } } } protocol:op_command 10823ms

查看慢掃描操作
慢掃描是指該操作需要掃描過多的記錄(超過1w行)，且返回數量不足掃描數量的1/100，這樣的操作通常對CPU消耗很高，也比較低效，

# mlogfilter mongo.log --scan --shorten 2002018-05-18T21:57:09.123+0800 I COMMAND [conn683] command cmspace.USER_LOGIN_HISTORY command: find ...e: { acquireCount: { r: 95 } }, Collection: { acquireCount: { r: 95 } } } protocol:op_command 556ms2018-05-18T21:57:17.381+0800 I COMMAND [conn784] getmore nsspace.StatisticsDay query: { aggre...nt: { r: 10 }, timeAcquiringMicros: { r: 1667 } }, Collection: { acquireCount: { r: 890 } } } 214ms2018-05-18T22:06:16.148+0800 I COMMAND [conn764] getmore nsspace.StatisticsHour query: { aggr...} }, Database: { acquireCount: { r: 69128 } }, Collection: { acquireCount: { r: 69128 } } } 12053ms2018-05-18T22:06:24.962+0800 I COMMAND [conn764] getmore nsspace.StatisticsHour query: { aggr... } }, Database: { acquireCount: { r: 69106 } }, Collection: { acquireCount: { r: 69106 } } } 8782ms2018-05-18T22:06:33.787+0800 I COMMAND [conn764] getmore nsspace.StatisticsHour query: { aggr... } }, Database: { acquireCount: { r: 69111 } }, Collection: { acquireCount: { r: 69111 } } } 8822ms

根據名稱空間過濾

# mlogfilter mongo.log --namespace dmspace.DeviceInfo2018-05-18T21:50:58.105+0800 I COMMAND [conn31] command dmspace.DeviceInfo appName: "MongoDB Shell...adata: { acquireCount: { w: 16 } }, oplog: { acquireCount: { w: 16 } } } protocol:op_command 2963ms2018-05-18T21:50:59.195+0800 I COMMAND [conn31] command dmspace.DeviceInfo appName: "MongoDB Shell...tadata: { acquireCount: { w: 16 } }, oplog: { acquireCount: { w: 16 } } } protocol:op_command 936ms2018-05-18T21:51:00.173+0800 I COMMAND [conn44] command dmspace.DeviceInfo command: insert { inser...tadata: { acquireCount: { w: 16 } }, oplog: { acquireCount: { w: 16 } } } protocol:op_command 745ms2018-05-18T21:51:00.433+0800 I COMMAND [conn44] command dmspace.DeviceInfo command: insert { inser...tadata: { acquireCount: { w: 16 } }, oplog: { acquireCount: { w: 16 } } } protocol:op_command 252ms

根據操作類型過濾

# mlogfilter mongo.log --operation update2018-05-18T21:56:25.114+0800 I WRITE [conn156] update dmspace.PolicyTask query: { _id: "###" } pla...Count: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 2630ms2018-05-18T21:56:25.114+0800 I WRITE [conn92] update nsspace.TimerTask query: { _id: "###" } planS...Count: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 1264ms2018-05-18T21:56:25.125+0800 I WRITE [conn43] update dmspace.TaskHistory query: { _id: "###" } pla...Count: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 2643ms2018-05-18T21:56:30.027+0800 I WRITE [conn532] update dmspace.TaskHistory query: { _id: "###" } pl...eCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 868ms2018-05-18T21:56:32.115+0800 I WRITE [conn517] update dmspace.TaskHistory query: { _id: "###" } pl...eCount: { w: 2 } }, Metadata: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 497ms

擷取某時間點之後1小時的日誌

# mlogfilter mongo.log --from Apr 6 0:00 --to "+1h" | tail -n32018-05-19T00:59:59.876+0800 I COMMAND [conn16386] command nsspace.StatisticsHour command: find { find: "###", filter: { user: "###", region: "###", appKey: "###", recordTime: { $lte: "###" }, $and: [ { recordTime: { $gte: "###" } } ] }, shardVersion: [ "###", "###" ] } planSummary: ### keysExamined:249767 docsExamined:249767 cursorExhausted:1 numYields:1952 nreturned:84 reslen:29748 locks:{ Global: { acquireCount: { r: 3906 } }, Database: { acquireCount: { r: 1953 } }, Collection: { acquireCount: { r: 1953 } } } protocol:op_command 319ms2018-05-19T00:59:59.879+0800 I COMMAND [conn15998] command nsspace.StatisticsHour command: find { find: "###", filter: { user: "###", region: "###", appKey: "###", recordTime: { $lte: "###" }, $and: [ { recordTime: { $gte: "###" } } ] }, shardVersion: [ "###", "###" ] } planSummary: ### keysExamined:249767 docsExamined:249767 cursorExhausted:1 numYields:1954 nreturned:84 reslen:29833 locks:{ Global: { acquireCount: { r: 3910 } }, Database: { acquireCount: { r: 1955 } }, Collection: { acquireCount: { r: 1955 } } } protocol:op_command 321ms

mlogfilter提供了非常靈活的日期條件設定，除了可以指定起始、結束時間之外，還能通過位移量劃分範圍。

時區轉換

# mlogfilter mongo.log --tiemzone 2 > mongo-correct.log

以上命令將日期調大2個時區，輸出到mongo-correct.log，這在處理國際化系統的情境中非常有用。

更多詳情戳這裡

4. 圖表呈現

mplotqueries 是基於tkinter實現的圖表組件，可以將日誌中扁平的文字資訊轉換為圖表形式。
輸入以下命令：

mplotqueries mongo.log --group operations --output-file operations.png

你可以得到一個按操作分組輸出的散佈圖，如：

左側的Y軸是duration，即操作的執行時間長度，下邊的X軸是時間。每個操作在圖中都會有一個描點，因此散佈圖會存在許多重疊。
當然，你也可以通過集合名稱進行分組輸出，如下面的命令：

mplotqueries mongo.log --group namespace --group-limit 20 --type scatter --yaxis nscanned --output-file namespace_nscan.png

輸出的圖表將按名稱空間進行分組(限顯示20個)，y軸為nscanned值，即掃描記錄數量。

預設情況下，y軸的呈現為時間長度(during)，可指定為其他指標：

指標名稱	說明
nscanned	掃描數
nupdated	更新數
ninserted	插入數
ntoreturn	返回數
numYields	讓步次數
r	讀鎖
w	寫鎖

有時候你並不關係具體的某個操作，而是希望看到某個時間段，某類操作或某個集合的操作佔比。
比如每小時，每個集合的操作比例分布，此時可以採用長條圖

mplotqueries mongo.log --group namespace --bucketsize 3600 --group-limit 10 --type histogram --output-file namespaces_perhour.png

在前面已經講過，串連數的監測工作非常重要，mplotqueries也提供了串連變更統計類型

mplotqueries mongo.log --type connchurn --bucketsize 3600 --output-file connchurn_perhour.png

在大部分情況下，低效的操作往往來自大量的scan掃描，尤其當return數遠小於scan時會更加低效。
可以通過指定 nscanned/n 參數輸出該維度圖表，即掃描數/返回數

mplotqueries mongo.log --type nscanned/n --group-limit 20 --output-file nscan.png

輸出事件持續圖
往往在跟蹤某一類耗時操作或事件時需要用到，比如oplog的同步、建立索引等，我們希望看到事件的執行時段。
同時還需要伴隨一些操作統計，用於配合做資源監控分析。具體一點就是，你執行了一個耗時操作，在某些情況下對業務訪問可能
產生了影響，如業務訪問逾時並伴隨DB伺服器資源的警示，如CPU飆高，在後續的分析中希望通過耗時操作、以及同時段業務訪問的分布進行綜合分析。

以下的命令展示了一個典型用法

# 建立一個overlaygrep "index" mongo.log | mplotqueries --type durline --overlay# 疊加overlay輸出圖表mplotqueries mongo.log --group operation --output-file duration.png

By the way，如果不希望產生那麼多的圖表，mtools還提供了一個偷懶的工具 mlogvis。可以直接產生html頁面，內建強大的指令碼
基本上覆蓋了mplotqueries的絕大多數圖表功能。

# mlogvis mongo.log

查看更多用法

希望你已經開始喜歡mtools，並已經躍躍欲試。下面提供了簡單的安裝方法

如何安裝

由於篇幅所限，這裡僅提供Centos下的安裝方式

• 準備Python的環境(2.7或3.5)，目前大多數發行版本的linux都包含了python。
  如果沒有Python，執行yum install python python-devel 完成安裝
  確保pip已經安裝，執行pip進行檢測，如果沒有安裝可參考官方說明進行安裝。

• 安裝python-tk
  執行命令如下：

  yum install python-tools

  其他linux系統(如ubuntu/opensuse)則需要安裝python-tk軟體包

• 安裝相依模組

  pip install psutilpip install pymongopip install matplotlibpip install numpy

  說明
  每個模組的作用可以參考下表：

模組名稱	作用
psutil	用於管理進程的工具
pymongo	mongodb python驅動
matplotlib	python的2D圖表渲染模組
numpy	支援科學計算的工具

• 安裝mtools

  pip install mtools

  至此，你應該獲得了一個已安裝好的mtools環境，如果希望安裝最新的非穩定版本，可以通過源碼安裝

參考文檔

Mongodb乾貨系列-定期巡檢之Mtools
關於mtools的介紹
mtools安裝指導

mtools-你可能沒用過的mongodb神器