MongoDB慢日志文件分析工具-mtools
原创MongoDB慢日志文件分析工具-mtools
原创
Power
发布于 2025-03-02 00:29:01
发布于 2025-03-02 00:29:01
代码可运行
运行总次数：0
代码可运行
一、mtools工具集介绍
1.1 mtools工具集是什么？
开源地址介绍：https://github.com/rueckstiess/mtools
mtools是一组工具集脚本，用于解析、过滤和可视化 MongoDB 日志文件 ( mongod, mongos)。mtools也包含mlaunch工具，该工具可以快速搭建本地测试环境。mtransfer工具可以用于数据库之间数据传输。
1.2 mtools工具组件介绍
- mlogfilter：日志过滤组件，支持按时间切割、合并、过滤慢查询、查找全表扫描操作，支持通过多个属性进行信息过滤，支持输出为JSON格式。
- mloginfo：返回有关日志文件的信息，例如：开始和结束时间、版本、二进制文件、重新启动、连接、不同视图等特殊部分
- mplotqueries：支持将日志分析结果转换为图表形式，依赖于tkinter(python图形模块)和matplotlib模块。
- mlaunch：支持快速部署本地测试环境，可以是单机、副本集、分片集群。（依赖pymongo）
- mtransfer：通过复制 WiredTiger 数据文件在 MongoDB 实例之间传输数据库的实验脚本。（需要
pymongo和wiredtiger）
二、mtools工具的使用
#（1）安装mtools工具及依赖
pip3 install mtools
yum install python-tools
pip3 install psutil
pip3 install pymongo
pip3 install matplotlib
pip3 install numpy
#（2）安装Python环境
wget https://www.python.org/ftp/python/3.6.8/Python-3.6.8.tar.xz
xz -d Python-3.6.8.tar.xz
tar -xvf Python-3.6.8.tar
cd Python-3.6.8/
./configure --with-ssl # 带上ssl不然pip会出现错误
make
make install2.1 mloginfo日志统计
（1）日志总体信息，比如：日志的起止时间范围、主机端口、版本、数据库引擎等概要信息。
[root@10-23-85-17 ~]# mloginfo mongodb.log
source: mongodb.log
host: 84b511baa949:27017
start: 2022 May 27 00:00:05.941
end: 2022 May 28 00:00:06.954
date format: iso8601-local
timezone: UTC +0800
length: 1437359
binary: mongod
version: 3.2.7
storage: wiredTiger（2）连接数
[root@10-23-85-17 ~]# mloginfo mongodb.log --connections
source: mongodb.log
host: 84b511baa949:27017
start: 2022 May 27 00:00:05.941
end: 2022 May 28 00:00:06.954
date format: iso8601-local
timezone: UTC +0800
length: 1437359
binary: mongod
version: 3.2.7
storage: wiredTiger
CONNECTIONS
total opened: 14282
total closed: 14358
no unique IPs: 4
socket exceptions: 0
127.0.0.1 opened: 12886 closed: 12889
172.21.0.10 opened: 658 closed: 716
172.21.0.20 opened: 461 closed: 490
172.21.0.30 opened: 277 closed: 263（3）事件统计，即统计出当前某些事件的发生频次
[root@10-23-85-17 ~]# mloginfo mongodb.log --distinct
source: mongodb.log
host: 84b511baa949:27017
start: 2022 May 27 00:00:05.941
end: 2022 May 28 00:00:06.954
date format: iso8601-local
timezone: UTC +0800
length: 1437359
binary: mongod
version: 3.2.7
storage: wiredTiger
DISTINCT
25460 SocketException handling request, closing client connection:
19504 assertion ... ns: ... query:
18464 exception: ... on:
5075 going to kill op:
660 Index ... :
400 Error in heartbeat request to ... ;
312 build index on: ... properties:
312 building index using bulk method
300 Placing a marker at optime
59 Successfully connected to
44 Member ... is now in state
28 DBClientCursor::init call() failed
27 Socket recv() timeout
27 SocketException: remote: ... error:
23 Plan executor error during find: ... , stats:
18 transition to（4）慢查询：显示所有慢查询，并按出现次数排序
[root@10-23-85-17 ~]# mloginfo mongodb.log --queries --sort count
source: mongodb.log
host: 84b511baa949:27017
start: 2022 May 27 00:00:05.941
end: 2022 May 28 00:00:06.954
date format: iso8601-local
timezone: UTC +0800
length: 1437359
binary: mongod
version: 3.2.7
storage: wiredTiger
QUERIES
namespace operation pattern count min (ms) max (ms) 95%-ile (ms) sum (ms) mean (ms) allowDiskUse
doyo.news count {"$or": [{"n_cate": 1}, {"n_prop": 1}], "bigcate": 1, "status": 1} 188339 587 492592 45736.2 1247160002 6621.9 None
doyo.resource query {"cate": 1, "status": 1} 173569 101 429614 1792.0 78818078 454.1 None
doyo.news query {"nid": 1, "status": 1} 120989 101 1159648 760531.2 12485218384（5）重启信息
[root@10-23-85-17 ~]# mloginfo mongodb.log --restart
source: mongodb.log
host: 84b511baa949:27017
start: 2022 May 27 00:00:05.941
end: 2022 May 28 00:00:06.954
date format: iso8601-local
timezone: UTC +0800
length: 1437359
binary: mongod
version: 3.2.7
storage: wiredTiger
RESTARTS
May 27 08:44:55 version 3.2.7
May 27 08:59:23 version 3.2.7
May 27 11:25:00 version 3.2.7（6）副本切换情况
[root@10-23-85-17 ~]# mloginfo mongodb.log --rsstate
source: mongodb.log
host: 84b511baa949:27017
start: 2022 May 27 00:00:05.941
end: 2022 May 28 00:00:06.954
date format: iso8601-local
timezone: UTC +0800
length: 1437359
binary: mongod
version: 3.2.7
storage: wiredTiger
RSSTATE
date host state/message
May 27 08:44:58 10.23.1.242:27017 ARBITER
May 27 08:44:58 10.23.1.26:27017 PRIMARY
May 27 08:54:42 10.23.1.26:27017 SECONDARY
May 27 08:59:25 10.23.1.242:27017 ARBITER
May 27 08:59:25 10.23.1.26:27017 SECONDARY
May 27 08:59:30 10.23.1.26:27017 PRIMARY
May 27 08:59:42 10.23.1.26:27017 SECONDARY2.2 日志过滤
（1）查询超过10s的慢查询
[root@10-23-85-17 ~]# mlogfilter mongodb.log --slow 10000 --shorten 200
2022-05-27T08:27:25.862+0800 I COMMAND [conn84751] query doyo.news query: { $query: { nid: { $gt: ...0 } }, Database: { acquireCount: { r: 3795 } }, Collection: { acquireCount: { r: 3795 } } } 10510ms
2022-05-27T08:27:28.254+0800 I COMMAND [conn84689] command doyo.news command: count { count: "news... acquireCount: { r: 3788 } }, Collection: { acquireCount: { r: 3788 } } } protocol:op_query 10247ms（2）查询慢扫描操作
- 慢扫描是指该操作需要扫描过多的记录(超过1w行)，且返回数量不足扫描数量的1/100，这样的操作通常对CPU消耗很高，也比较低效
[root@10-23-85-17 ~]# mlogfilter mongodb.log --scan --shorten 200
2022-05-27T12:10:51.816+0800 I COMMAND [conn581] query doyo.news query: { $query: { bigcate: "2", ...0 } }, Database: { acquireCount: { r: 1470 } }, Collection: { acquireCount: { r: 1470 } } } 11869ms
2022-05-27T12:10:53.739+0800 I COMMAND [conn578] query doyo.news query: { $query: { bigcate: "1", ...6 } }, Database: { acquireCount: { r: 3183 } }, Collection: { acquireCount: { r: 3183 } } } 14412ms（3）获取某时间点之后1小时的日志
[root@10-23-85-17 ~]# mlogfilter mongodb.log --from May 27 0:00 --to "+1h" | tail -n3
2022-05-27T00:00:05.941+0800 I CONTROL [conn80893] distarch: x86_64
2022-05-27T00:00:05.941+0800 I CONTROL [conn80893] target_arch: x86_64原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。
如有侵权，请联系 cloudcommunity@tencent.com 删除。
原创声明：本文系作者授权腾讯云开发者社区发表，未经许可，不得转载。
如有侵权，请联系 cloudcommunity@tencent.com 删除。
评论
登录后参与评论
推荐阅读
腾讯云开发者
