MongoDB 响应慢如何排查？

2022-04-15 00:00:00 查询内存情况执行时间排查

在工作中，我们可能会遇到 MongoDB 响应慢的情况，这一节内容，来聊聊当出现这种情况时，应该怎样去排查？

1 MongoDB 慢查询

MongoDB 响应慢，可能大部分原因是慢查询导致的，这里通过一个实验来聊聊 MongoDB 慢查询。

开启慢查询：

db.setProfilingLevel(1,100)

表示记录执行时间超过 100ms 的语句。

导入数据并制造慢查询（这里是为了我们这次实验能看到慢查询，如果是线上环境排查问题，这一步忽略）：

for (var i=1; i<=300000; i++ ) db.userinfo.save({userid:i,username:'a'});db.userinfo.find({"userid" : 29998}).explain()

可以在日志文件中查看到执行时间超过 100ms 的慢查询日志：

2022-04-15T13:44:13.418+0800 I COMMAND [conn4] command martin.userinfo appName: "MongoDB Shell" command: find { find: "userinfo", filter: { userid: 29998.0 }, lsid: { id: UUID("7529eb75-cffa-4164-a8d4-e4730d735c2b") }, $db: "martin" } planSummary: COLLSCAN keysExamined: docsExamined:300000 cursorExhausted:1 numYields:2343 nreturned:1 queryHash:37A12FC3 planCacheKey:37A12FC3 reslen:161 locks:{ ReplicationStateTransition: { acquireCount: { w: 2344 } }, Global: { acquireCount: { r: 2344 } }, Database: { acquireCount: { r: 2344 } }, Collection: { acquireCount: { r: 2344 } }, Mutex: { acquireCount: { r: 1 } } } storage:{} protocol:op_msg 142ms

其中：

command 表示使用的命令；
planSummary 表示执行计划；
COLLSCAN 表示全表扫描；
COLLSCAN 中的 keysExamined 表示是否走索引；
COLLSCAN 中的 docsExamined 表示扫描文档数（类似MySQL的扫描行数）；
locks 锁相关信息；
locks 中的 Database 表示库级别的锁情况；
locks 中的 Collection 表示表级别的锁情况；
protocol:op_msg 142ms 表示执行时间 142 毫秒。

有时，我们要统计某一类慢查询执行的总数，这时，可以采用 mtools 中的 mloginfo 来分析 MongoDB 慢查询。

开源工具 mtools 可用来解析、过滤和可视化 MongoDB 日志。Github地址：https://github.com/rueckstiess/mtools。

安装 mtools：

pip3 install mtools

使用 mloginfo 来分析慢查询日志：

/usr/local/python3/bin/mloginfo --queries /data/mongo4/logs/mongod.log

可以看到不同类型的慢查询总体的统计结果。

2 mongostat 排查

另外可以考虑使用 mongostat 进行排查，它的输出结果如下：


mongostat --host  192.168.150.232:27001

其中：

insert、query、update、delete、getmore、command 表示近1秒这类操作的次数，观察这几个字段的值是否比平时高很多；
dirty 表示脏数据（未刷盘的数据）占总内存数据的比例，仅针对 WiredTiger 存储引擎，如果该值过高，可能会阻塞新请求；
used WiredTiger 存储引擎内存使用率，如果内存使用率过高，需要判断是否需要增加内存；
flushes 表示近1秒数据刷新到磁盘的次数，仅针对 WiredTiger 存储引擎；
vsize 表示使用了多少虚拟内存；
res 表示实际使用的内存大小，如果内存使用的比较大，需要确定是否需要增加内存；
qrw 表示读写等待的队列长度；
arw 执行读写操作的活跃客户端数，看是否是短时间活跃连接数突增导致的响应变慢；
net_in、net_out 进出流量，通过进出流量同样可以判断是否有访问量突增的情况；
conn 连接数；
set 副本集的名称；
repl 复制的状态；
time 当前时间。

3 mongotop 排查

mongotop 可以查看每个操作上所花费的时间。


mongotop --host 192.168.150.232:27001

其中：

ns 表示数据库命名空间；
total、read、write 具体操作花费的时间。

来自：公众号-悦专栏

相关文章