MongoDB日志浅析-阿里云开发者社区

开发者社区> 数据库> 正文

MongoDB日志浅析

简介: MongoDB 日志

  MongoDB中主要有四种日志。分别是系统日志、Journal日志、oplog主从日志、慢查询日志。这些日志记录着MongoDB数据库不同的信息。下面分别介绍这四种日志:

一、系统日志

  系统日志在MongoDB中十分重要,它记录MongoDB启动和停止的操作,以及服务器在运行过程中发生的任何异常信息;配置系统日志非常简单,在运行mongod时候增加额外参数或者写入配置文件即可:

#在启动mongoDB时使用-logpath指定日志的路径,-logappend表示使用追加的方式写日志
mongod -logpath='/usr/local/mongodb/log/rs1.log' -logappend
#也可以在配置文件中指定参数进行配置:
logpath=/usr/local/mongodb/log/rs1.log #日志文件路径
logappend=true #表示使用追加的方式写日志
verbose=true #表示会打印debug信息
vv=true #表示debug级别,有vv-vvvvv,v越多则记录的日志信息越详细。
#quiet=true #quiet=true,表示安静地输出,不会再有debug信息,日志中只会打印一些关键的信息,比如自动故障切换,系统错误等信息,相当于error log。这时需要注释掉verbose参数。

_

二、Journal日志

  不开启journal日志,写入wiredtiger的数据,并不会立即持久化存储;而是每分钟会做一次全量的checkpoint,将所有的数据持久化。
  开启journal日志后,数据的更新就先写入Journal日志(其中包含了此次写入操作具体更改的磁盘地址和字节),定期集中提交,然后在正式数据执行更改。这样即使出现宕机,启动时Wiredtiger会先将数据恢复到最近的一次checkpoint的点,然后重放后续的journal操作日志来恢复数据。
  由于MongoDB使用的journal文件大小限制为100MB,因此WiredTiger大约每100MB数据创建一个新的日志文件。
  向MongoDB中写入数据是先写入内存,然后每隔60s在刷盘,同样写入journal,也是先写入对应的buffer,然后每隔50ms在刷盘到磁盘的journal文件。
  需要注意的是如果客户端的写入速度超过了日志的刷新速度,mongod则会限制写入操作,直到日志完成磁盘的写入。这是mongod会限制写入的唯一情况。
  Jouranl日志就是预写入的redo日志,是用于数据故障恢复和持久化数据的,为mongodb增加了额外的可靠性保障。journal除了故障恢复的作用之外,还可以提高写入的性能,批量提交。在这个过程中,所有的写入都可以一次提交,是单事务的,全部成功或者全部失败。启动数据库的Journal功能非常简单,只需写入配置文件即可:

#在启动时指定--journal代表启动journal日志。
mongod --journal
journal=true #启用journal日志
journalCommitInterval=100 #刷写提交机制。可修改范围是2~300,值越低,刷新输出频率越高,数据安全度也就越高,但磁盘性能上的开销也更高。

_

三、oplog主从日志与慢查询日志

3.1 固定集合

  在讲下面两种日志之前先来认识下固定集合。MongoDB中的普通集合是动态创建的,而且可以自动增长以容纳更多的数据。MongoDB中还有另一种不同类型的集合,叫做固定集合。固定集合需要先创建好,而且它的大小是固定的。固定集合的行为类型与循环队列一样。如果没有空间了,最老的文档会被删除以释放空间,新插入的文档会占据这块空间。
  固定集合创建之后就不能改变,无法将固定集合转换为非固定集合,但是可以将常规集合转换为固定集合。
  固定集合可以进行一种特殊的排序,称为自然排序,自然排序返回结果集中文档的顺序就是文档在磁盘的顺序。自然顺序就是文档的插入顺序,因此自然排序得到的文档是从旧到新排列的。

3.2 oplog主从日志

  MongoDB的高可用复制策略有一个叫做副本集。副本集的复制过程中有一个服务器充当主服务器,而一个或多个充当从服务器,主服务器将更新写入oplog,oplog记录着发生在主服务器的更新操作,oplog是主节点的local数据库中的固定集合(oplog.rs)中,并将这些操作分发到从服务器上。
  每个备份节点都维护着自己的oplog,记录着每一次从主节点复制数据的操作。这样,每个成员都可以作为同步源给其他成员使用。
  备份节点从当前使用的同步源中获取需要执行的操作,然后在自己的数据集上执行这些操作,最后再将这些操作写入自己的oplog,如果遇到某个操作失败的情况(只有当同步源的数据损坏或者数据与主节点不一致时才可能发生),那么备份节点就会停止从当前的同步源复制数据。
  oplog中按顺序保存着所有执行过的写操作,副本集中每个成员都维护着一份自己的oplog,每个成员的oplog都应该跟主节点的oplog完全一致。
  如果某个备份节点由于某些原因挂了,但它重新启动后,就会自动从oplog中最后一个操作开始进行同步。由于复制操作的过程是复制数据再写入oplog,所以备份节点可能会在已经同步过的数据上再次执行复制操作。MongoDB在设计之初就考虑到了这种情况:将oplog中的同一个操作执行多次,与只执行一次的效果是一样的。
  oplog是固定集合,MongoDB默认将其大小设置为可用disk空间的5%(默认最小为1G,最大为50G),也可以在MongoDB复制集实例初始化之前将mongo.conf中oplogSize设置为我们需要的值。它只能保持特定数量的操作日志,并且如果执行大量的批量操作,oplog很快就会被填满。
_

#oplog各字段详解
ts: 8字节的时间戳,由4字节unix timestamp + 4字节自增计数表示。这个值很重要,在选举(如master宕机时)新primary时,会选择ts最大的那个secondary作为新primary
op:1字节的操作类型
"i": insert
"u": update
"d": delete
"c": db cmd
"db":声明当前数据库 (其中ns 被设置成为=>数据库名称+ '.')
"n": no op,即空操作,其会定期执行以确保时效性
ns:操作所在的namespace
o:操作所对应的document,即当前操作的内容(比如更新操作时要更新的的字段和值)
o2: 在执行更新操作时的where条件,仅限于update时才有该属性

  通过"db.printReplicationInfo()"命令可以查看oplog的信息:
_
  通过"db.printSlaveReplicationInfo()"可以查看slave的同步状态:
_

3.3 慢查询日志

  说到MongoDB的慢查询日志,就不得不提到profile分析器,profile分析器将记录的慢日志写到当前库下的system.profile集合下,这个集合是一个固定集合,使用db.system.profile.find()进行查询,慢日志可以在启动时或者在配置文件中进行指定。

#在启动mongoDB时使用--profile=1启动慢日志,--slowms表示慢日志阈值时间
mongod --profile=1 --slowms=5 
#也可以在配置文件中指定参数
slowms=100 #单位是毫秒
profile = 1#0:关闭,不收集任何数据。1:收集慢查询数据,默认是100毫秒。2:收集所有数据
#慢日志内容格式详解
{
    "op" : "query",  #操作类型,有insert、query、update、remove、getmore、command   
    "ns" : "test.test", #操作的集合
    "query" : {
        "$query" : {
            "user_id" : 314436841,
            "data_time" : {
                "$gte" : 1436198400
            }
        },
        "$orderby" : {
            "data_time" : 1
        }
    },
    "ntoskip" : 0, #指定跳过skip()方法的文档的数量。
    "nscanned" : 2, #为了执行该操作,MongoDB在index中浏览的文档数。一般来说,如果nscanned值高于nreturned 的值,说明数据库为了找到目标文档扫描了很多文档。这时可以考虑创建索引来提高效率。
    "nscannedObjects" : 1, #为了执行该操作,MongoDB在collection中浏览的文档数。
    "keyUpdates" : 0, #索引更新的数量,改变一个索引键带有一个小的性能开销,因为数据库必须删除旧的key,并插入一个新的key到B-树索引
    "numYield" : 1,  #该操作为了使其他操作完成而放弃的次数。通常来说,当他们需要访问还没有完全读入内存中的数据时,操作将放弃。这使得在MongoDB为了放弃操作进行数据读取的同时,还有数据在内存中的其他操作可以完成
    "lockStats" : {#锁信息,R:全局读锁;W:全局写锁;r:特定数据库的读锁;w:特定数据库的写锁
        "timeLockedMicros" : {  #该操作获取一个级锁花费的时间。对于请求多个锁的操作,比如对local数据库锁来更新oplog,该值比该操作的总长要长(即millis )
            "r" : NumberLong(1089485),
            "w" : NumberLong(0)
        },
        "timeAcquiringMicros" : {  #该操作等待获取一个级锁花费的时间。
            "r" : NumberLong(102),
            "w" : NumberLong(2)
        }
    },
    "nreturned" : 1,  // 返回的文档数量
    "responseLength" : 1669, // 返回字节长度,如果这个数字很大,考虑值返回所需字段
    "millis" : 544, #消耗的时间(毫秒)
    "execStats" : {  #一个文档,其中包含执行 查询 的操作,对于其他操作,这个值是一个空文件, system.profile.execStats 显示了就像树一样的统计结构,每个节点提供了在执行阶段的查询操作情况。
        "type" : "LIMIT", ##使用limit限制返回数  
        "works" : 2,
        "yields" : 1,
        "unyields" : 1,
        "invalidates" : 0,
        "advanced" : 1,
        "needTime" : 0,
        "needFetch" : 0,
        "isEOF" : 1,  #是否为文件结束符
        "children" : [
            {
                "type" : "FETCH",  #根据索引去检索指定document
                "works" : 1,
                "yields" : 1,
                "unyields" : 1,
                "invalidates" : 0,
                "advanced" : 1,
                "needTime" : 0,
                "needFetch" : 0,
                "isEOF" : 0,
                "alreadyHasObj" : 0,
                "forcedFetches" : 0,
                "matchTested" : 0,
                "children" : [
                    {
                        "type" : "IXSCAN", #扫描索引键
                        "works" : 1,
                        "yields" : 1,
                        "unyields" : 1,
                        "invalidates" : 0,
                        "advanced" : 1,
                        "needTime" : 0,
                        "needFetch" : 0,
                        "isEOF" : 0,
                        "keyPattern" : "{ user_id: 1.0, data_time: -1.0 }",
                        "boundsVerbose" : "field #0['user_id']: [314436841, 314436841], field #1['data_time']: [1436198400, inf.0]",
                        "isMultiKey" : 0,
                        "yieldMovedCursor" : 0,
                        "dupsTested" : 0,
                        "dupsDropped" : 0,
                        "seenInvalidated" : 0,
                        "matchTested" : 0,
                        "keysExamined" : 2,
                        "children" : [ ]
                    }
                ]
            }
        ]
    },
    "ts": ISODate("2019-08-31T10:05:21.401Z"), #登陆时间
    "client": "127.0.0.1", #登陆IP或地址
    "appName": "MongoDB Shell",
    "allUsers": [],
    "user": ""
}

_

四、总结

  总体来说,MongoDB有以上四种日志,其中系统日志和journal日志是物理文件日志,而oplog主从日志和慢查询日志其实是MongoDB中的固定集合。oplog主从日志被放在local库下的oplog.rs集合中;慢查询日志被放在当前库下system.profile集合中。
  因为MongoDB中的journal日志类似于MySQL的redo日志,oplog日志类似于MySQL的binlog;所以可能有人会问journal日志和oplog主从日志的顺序。其实我们仔细思考可以明白:oplog是MongoDB的一个固定集合,与其他的集合没有其他区别;所以是先写入journal日志的。

版权声明:本文内容由阿里云实名注册用户自发贡献,版权归原作者所有,阿里云开发者社区不拥有其著作权,亦不承担相应法律责任。具体规则请查看《阿里云开发者社区用户服务协议》和《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容,填写侵权投诉表单进行举报,一经查实,本社区将立刻删除涉嫌侵权内容。

分享:
数据库
使用钉钉扫一扫加入圈子
+ 订阅

分享数据库前沿,解构实战干货,推动数据库技术变革

其他文章