民工哥 MongoDB 教程：MD 日志分析工具

2023-06-0515:54:40数据库教程Comments938 views字数 8847阅读模式

需求背景

MongoDB 数据库的强大的文档模型使其成为处理数据的最佳方式。文档适用于广泛的流行数据模型，支持各种各样的场景。文档模型可以包含键值、关系数据集和图形数据集，当然，还可以包含父子关系、列表/数组以及其他层次关系，它们比传统的关系型数据库技术（表格）具有更大的灵活性。由于文档模型与主流面向对象编程语言中的对象直接对应，因此开发人员可以根据现实世界中实体之间的自然关系存储和组织数据，从而将重点放在以最有意义的方式构建应用程序上，而不是围绕其数据库的局限性开展工作。因此，使用文档模型显著提高了开发人员的生产效率，使组织机构能够更快地进行创新。MongoDB CEO 兼总裁 Dev Ittycheria称之为：文档即未来。文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

但是 MongoDB 通用的监控工具有限，其中又有一部分还是要收费的,通过工具 Percona Monitoring and Management 进行监控，是个不错的选择。但在慢查询收集方面，需要开启Profiling，对性能方面会有一些侵害，另外，更细粒度的监控项维护起来也不容易。如果不想不开启Profiling，我们还可以通过收集分析mongodb的运行log来来进行性能监控，并且通过运行日志还可以获取更多的运行状态相关的信息。文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

今天介绍的就是一款专门用来读取、分析 MongoDB 运行日志的工具--Mtools。文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

mtools工具集介绍

mtools 工具集是什么？

开源地址介绍：https://github.com/rueckstiess/mtools文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

mtools 是一组工具集脚本，用于解析、过滤和可视化 MongoDB 日志文件 ( mongod, mongos)。mtools也包含mlaunch工具，该工具可以快速搭建本地测试环境。mtransfer工具可以用于数据库之间数据传输。文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

mtools工具组件介绍

  • mlogfilter：日志过滤组件，支持按时间切割、合并、过滤慢查询、查找全表扫描操作，支持通过多个属性进行信息过滤，支持输出为JSON格式。
  • mloginfo：返回有关日志文件的信息，例如：开始和结束时间、版本、二进制文件、重新启动、连接、不同视图等特殊部分
  • mplotqueries：支持将日志分析结果转换为图表形式，依赖于tkinter(python图形模块)和matplotlib模块。
  • mlaunch：支持快速部署本地测试环境，可以是单机、副本集、分片集群。（依赖pymongo）
  • mtransfer：通过复制 WiredTiger 数据文件在 MongoDB 实例之间传输数据库的实验脚本。（需要pymongo和wiredtiger）

mtools工具的使用

#安装mtools工具及依赖
pip3 install mtools
yum install python-tools
pip3 install psutil
pip3 install pymongo
pip3 install matplotlib
pip3 install numpy

#安装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 install

mloginfo日志统计

日志总体信息，比如：日志的起止时间范围、主机端口、版本、数据库引擎等概要信息。文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

[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
连接数
[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
事件统计

即统计出当前某些事件的发生频次文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

[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
慢查询

显示所有慢查询，并按出现次数排序文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

[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
重启信息
[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
副本切换情况
[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     SECONDARY

日志过滤

mlogfilter是一个强大的日志过滤模块，相比linux 的grep/egrep的文本过滤，该组件可以对日志内容进行解析，并按我们想要的结果进行过滤。文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

查询超过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
查询慢扫描操作

慢扫描是指该操作需要扫描过多的记录(超过1w行)，且返回数量不足扫描数量的1/100，这样的操作通常对CPU消耗很高，也比较低效文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html

[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
获取某时间点之后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
根据名称空间过滤
# mlogfilter mongo.log --namespace dmspace.DeviceInfo
2018-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 2963ms
2018-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 936ms
2018-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 745ms
2018-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 update
2018-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 } } } 2630ms
2018-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 } } } 1264ms
2018-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 } } } 2643ms
2018-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 } } } 868ms
2018-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
链接：https://www.starcto.com/mongodb/295.html
文章源自菜鸟学院-https://www.cainiaoxueyuan.com/sjk/44846.html
  • 本站内容整理自互联网，仅提供信息存储空间服务，以方便学习之用。如对文章、图片、字体等版权有疑问，请在下方留言，管理员看到后，将第一时间进行处理。
  • 转载请务必保留本文链接：https://www.cainiaoxueyuan.com/sjk/44846.html

Comment

匿名网友 填写信息

:?: :razz: :sad: :evil: :!: :smile: :oops: :grin: :eek: :shock: :???: :cool: :lol: :mad: :twisted: :roll: :wink: :idea: :arrow: :neutral: :cry: :mrgreen:

确定