MongoDB 慢日志分析

本文主要是介绍MongoDB 慢日志分析，对大家解决编程问题具有一定的参考价值，需要的程序猿们随着小编来一起学习吧！

##查看慢日志
#设置mongo慢查询日志等级和记录时间门槛,单位ms毫秒
db.setProfilingLevel(1,3000)
#查看当前mongo慢查询级别状态,有0,1,2三个级别,0:关闭,不收集任何数据.1:收集慢查询数据,默认是100毫秒.2:收集所有数据
db.getProfilingStatus()
#查看当前mongo慢查询的记录,注意:要查看那个库的慢日志,就要登进去那个库,不然无法显示相应的慢日志
use apptest
db.system.profile.find()
#查看当前mongo慢查询的记录并排序显示最新,只显示10条
use apptest
db.system.profile.find().sort({$natural:-1}).limit(10)
#如果慢查询等级设成了2,可能会记录非常多的日志,就需要按条件过滤了,例如下面:列出执行时间长于某一限度(5ms)的记录
use apptest
db.system.profile.find({millis:{$gt:5}})
#慢日志信息关键项说明
"op" : "query",            # 操作类型,查询query,更改update
"ns" : "test.report",    # 操作的数据库和集合
"command" : {            # 执行命令信息
"find" : "report",        # 操作的集合
"filter" : { "a" : { "$lte" : 500 } },    # 查询条件
"docsExamined" : 101,    # MongoDB为了执行操作而扫描的集合中的文档数.
keysExamined            #索引是否命中
"numYield" : 2,            # 让步次数,操作时让其他的操作完成的次数.
nscanned                #扫描的记录数,如果远大于nreturned,需要考虑加索引
"nreturned" : 101,        # 操作返回的文档数
"locks" : {                # 操作期间的锁和所的类型
"Global" : {            #表示全局锁定
"acquireCount" : {        #锁定的次数
"r" : NumberLong(3)        # 表示共享锁
"Database" : {            # 数据库锁
"Collection" : {        # 集合锁
"responseLength" : 1305014,    # 操作返回结果的文档长度,单位为字节
"protocol" : "op_msg",    # 消息的协议
"millis" : 69132,        # 从 MongoDB 操作开始到结束耗费的时间
"planSummary" : "IXSCAN { a: 1, _id: -1 }",  #执行计划摘要,不同信息代表不同操作方式
"execStats" : {            # 操作执行过程中的详细信息
"stage" : "FETCH",        # 操作形式 ,COLLSCAN代表全集合扫描,IXSCAN代表扫描索引键,FETCH代表根据索引检索文档
"nReturned" : 101,        # 返回的文档数量
"ts" : ISODate("2019-01-14T16:57:33.450Z"),    #操作的时间戳
"client" : "127.0.0.1",    # 客户端的ip
"user" : "someuser",    # 用户
"db" : "admin"            # 验证的数据库
"user" : "someuser@admin"    # 经过验证的用户
#通过mongoexport导出慢日志,并生成csv文档,方便查看,参考信息解析如上
mongoexport -h 127.0.0.1 --port 40006 --authenticationDatabase admin -u root -p "****" -d jst_order_service_prod -c system.profile -f op,ns,query,docsExamined,numYield,nreturned,locks,responseLength,protocol,millis,planSummary,execStats,ts,client --type csv  --out=/opt/slow20200706.csv

#mongodb慢查询日志的记录空间默认是只有1MB的固定集合,不利于收集历史信息,但是可以手动设置更大
#先关闭慢查询功能
db.setProfilingLevel(0)
#把旧的固定集合删除
db.system.profile.drop()
#创建一个新的而且空间更大的固定集合空间,这里设置成1GB
db.createCollection("system.profile",{capped:true,size:1073741824})
#重新开启慢查询日志,就更改完成了
db.setProfilingLevel(1)

##通过mongodb日志记录查看慢查询日志记录
#有时候mongodb系统自带的system.profile会变得有些鸡肋,看不到慢日志,但是还好,mongodb会主动把慢日志记录到mongodb的日志里面去,这个时候只要我们过滤一下就能看到了
tail -1000000 mongodb_data.log |grep -Ev "NETWORK|ACCESS|connection|COMMAND|ASIO|SHARDING|Error|REPL|background|CONTROL|INDEX">/opt/20210524_43.20.log
2019-11-29T16:11:38.234+0800 I WRITE    [conn2443] update jst_order_service_prod.order query: { _id: "3564-102656377733-5" } exception: [jst_order_service_prod.order] shard version not ok: migration commit in progress for jst_order_service_prod.order ( ns : jst_order_service_prod.order, received : 323|1||5dc1836cdf86ba1d5a9a680e, wanted : 323|1||5dc1836cdf86ba1d5a9a680e, send ) code:13388 numYields:0 locks:{ Global: { acquireCount: { r: 3, w: 1 } }, Database: { acquireCount: { r: 1, w: 1 } }, Collection: { acquireCount: { r: 1, w: 1 } } } 894ms

##执行计划

和mysql差不多意思,查询分析可以确保我们建议的索引是否有效,是查询语句性能分析的重要工具,MongoDB 查询分析常用函数有:explain() 和 hint().
#db.collection.explain().<method(...)>
有三个参数选择:queryPlanner,executionStats,allPlansExecution
示例:
    db.users.find({gender:"M"},{user_name:1,_id:0}).explain(executionStats)
这个结果集的字段解析:
winningPlan:            当前步骤最优的执行计划,由系统判断,除非是设置了hint和索引过滤
stage:                    所属步骤的操作类型,有很多种,下面列举
filter:                    查询的过滤条件
inputStage:                所属分支步骤的stage
indexFilterSet:            索引过滤器,如果为true,则说明有相关规则,执行计划只会用这个索引来查询,不管是不是最优计划
namespace:                所属集合的命名空间,也说明了该步骤操作了什么集合
parsedQuery:            每一步骤的详细操作信息
keyPattern:                扫描的index内容
indexName:                使用到索引的索引名称
isMultiKey:                是否是Multikey,即数组类型多key索引
isUnique:                是否唯一索引
isSparse:                是否稀疏索引
isPartial:                是否部分索引
direction:                索引扫描顺序,默认是顺序forward,倒序则是显示backward(即-1)
indexBounds:            扫描索引的边界范围,如果没有指定范围就是[MaxKey, MinKey]
rejectedPlans:            其他执行计划(非最优而被查询优化器reject的)的详细返回
executionStats:            执行状态统计信息
executionSuccess:        是否执行成功
executionTimeMillis:    这个步骤的执行时间,这个值当然是希望越少越好,单位毫秒.
nReturned:                这个步骤返回的结果统计条目数
nCounted:                当stage为COUNT时显示的统计条目数
totalKeysExamined:        这个步骤索引扫描条目数
totalDocsExamined:        这个步骤文档扫描条目数
executionSuccess:        是否执行成功
works:                    查询执行阶段执行的"工作单元"的数量,通常来说一个处理步骤就有一个"工作单元"
advanced:                往下一阶段传递结果的次数,通常和nCounted或nReturned的值相等
needTime:                预估需要更多一些时间才能产生结果并交给下一阶段的数值
needYield:                遇到写冲突在引擎层主动进行等待的次数
saveState:                查询阶段暂停处理并保存其当前执行状态的次数
restoreState:            查询阶段恢复已保存的执行状态的次数
isEOF:                    是否扫描完毕所有的数据
invalidates:            查询过程中发现记录被删除或修改的次数(因为不支持事务)
docsExamined:            在集合里扫描的文档数
alreadyHasObj:            fetch数据中检查发现数据已被获取(数据可能失效或者磁盘位置改变)
seeks:                    为完成索引扫描,必须将索引游标定位到新位置的次数
dupsTested:                在使用数组索引中出现,检测是否有重复文档
dupsDropped:            处理重复扫描记录的次数
seenInvalidated:        再次看到并处理之前扫描过的记录的次数

stage详细信息列举:
    AND_HASH:    hash索引交集
    AND_SORTED:    普通索引交集
    CACHED_PLAN:缓存查询计划
    SCAN:        用了索引的去重查询
    COLLSCAN:    全集合扫描,最糟糕的方法
    IXSCAN:        索引扫描,较优方案
    FETCH:        根据索引获取到相关文档
    SHARD_MERGE:将各个分片返回数据进行merge
    SORT:        表明在内存中进行了排序
    LIMIT:        使用limit限制返回文档
    SKIP:        使用skip进行跳过文档
    IDHACK:        针对_id进行的查询,速度最快
    SHARDING_FILTER:    通过mongos对分片数据进行查询
    COUNT:        利用db.coll.explain().count()之类进行count运算或者是直接count的计数查询
    COUNTSCAN:    count不使用Index进行count时的stage返回
    COUNT_SCAN:    通过索引计数的count,不返回索引值
    TEXT:        使用全文索引进行查询时候的stage返回
    PROJECTION:    限定返回字段的查询
    DELETE:        数据删除
    UPDATE:        数据更改
    MULTI_PLAN:    并行的扫描计划
    OR:            or的查询
    SORT_KEY_GENERATOR:    生成排序用的key
    SUBPLAN:    子查询计划,最好用OR,不用子查询
    
    
#hint()
和mysql一样,虽然MongoDB查询优化器一般工作的很不错,但是某种方法在某些情形下用另外一些索引或字段来做条件会提升性能,那我们就可以使用 hint 来强制 MongoDB 使用一个指定的索引.
    db.users.find({gender:"M"},{user_name:1,_id:0}).hint({gender:1,user_name:1})
    
索引过滤器
指定查询指纹选择对应的索引,如果某个特定查询指纹存在索引过滤器,则优化器只会选择索引过滤器指定的索引,并自动忽略hint()和其他执行计划.
db.runCommand({
planCacheSetFilter:<集合名>,
query:<语句>,
sort:<排序>,
projection:<限制返回条件>,
indexes:[<索引1>,<索引2>,...]
})
其中:
    query:        就是查询语句本身
    sort:        排序子句,没有也可以不指定
    projection:    相当于mysql的where子句,没有也可以不指定
    indexes:    就是指定用的索引    
    
##日志分析工具mtools
mtools 是由MongoDB 官方工程师实现的一套工具集,可以很快速的日志查询分析.统计功能,此外还支持本地集群部署管理,非常便于新手学习.
现在我们只针对他的日志分析功能,因为他不需要结合实时业务,可以安装在任何机器上,只分析mongodb日志文件.所以把mongodb日志下载下来用它分析就可以,但是必须在python3下执行.
#安装:因为不需要关心装在那台机上,直接先安装pip3,再通过pip安装,简单便捷,还有相关依赖包
    apt-get install -y pip3
    apt-get install -y python3-tk
#安装mtools的py包
    pip3 install mtools
#安装2D图表渲染模块,图形生成工具包matplotlib,安装后可以生成图表样式,非常方便
    pip3 install matplotlib
#其他依赖包,通常这些包会被当依赖包一早装上
    #用于管理进程的工具
    pip3 install psutil
    #mongodb python驱动
    pip3 install pymongo
    #支持科学计算的工具
    pip3 install numpy

#命令汇总
mlaunch:支持快速搭建本地测试环境,可以是单机.副本集.分片集群.
mlogfilter:日志过滤组件,支持按时间检索慢查询.全表扫描操作,支持通过多个属性进行信息过滤,支持输出为JSON格式.
mplotqueries:支持将日志分析结果转换为图表形式,依赖于tkinter(python图形模块).和matplotlib模块.
mlogvis:支持将日志分析结果转换为一个独立的HTML页面,实现与mplotqueries同样的功能.
mloginfo:用于做日志信息统计的工具

#示例
mloginfo:
日志的起止时间范围.主机端口.版本.数据库引擎等概要信息
mloginfo mongo.log
检查客户端的连接数情况
mloginfo mongo.log --connections
望统计出当前某些事件的发生频次
mloginfo mongo.log --distinct
分析慢查询
mloginfo mongo.log --queries --sort count
重启信息
mloginfo mongo.log --restart
副本集切换
mloginfo mongo.log --rsstate

mlogfilter:
查看超过10s的慢操作
mlogfilter mongo.log --slow 10000 --shorten 200
查看慢扫描操作
mlogfilter mongo.log --scan --shorten 200
根据名称空间过滤
mlogfilter mongo.log --namespace dmspace.DeviceInfo
根据操作类型过滤
mlogfilter mongo.log --operation update
获取某时间点之后1小时的日志
mlogfilter mongo.log --from Apr 6 0:00 --to "+1h" | tail -n3
时区转换
mlogfilter mongo.log --tiemzone 8 > mongo-correct.log

mplotqueries:将日志中扁平的文字信息转换为图表形式
按操作分组输出的散点图
mplotqueries mongo.log --group operations --output-file operations.png
按名称空间进行分组(限显示20个),y轴为nscanned值,即扫描记录数量
mplotqueries mongo.log --group namespace --group-limit 20 --type scatter --yaxis nscanned --output-file namespace_nscan.png
每小时,每个集合的操作比例分布,此时可以采用直方图
mplotqueries mongo.log --group namespace --bucketsize 3600 --group-limit 10 --type histogram --output-file namespaces_perhour.png
连接变更统计类型
mplotqueries mongo.log --type connchurn --bucketsize 3600 --output-file connchurn_perhour.png
扫描数/返回数
mplotqueries mongo.log --type nscanned/n --group-limit 20 --output-file nscan.png
    
mlogvis:直接生成html页面,内置强大的脚本,基本上覆盖了mplotqueries的绝大多数图表功能.
mlogvis mongo.log
    

这篇关于MongoDB 慢日志分析的文章就介绍到这儿，希望我们推荐的文章对大家有所帮助，也希望大家多多支持为之网！