mongodb oplog日志详解和格式分析

1. 基本概念

oplog使用固定大小集合记录了数据库中所有修改操作的操作日志(新增、修改和删除，无查询)，其记录每条记录被修改后的数据，等同于MYSQL中ROW类型的binlog。mongodb收到修改请求后，先在主节点（Primary）执行请求，再把操作日志保存到oplog表中，其他从节点（Secondary）到主节点拉取oplog并在异步进程中应用这些操作，从而达到主从数据的一致性。复制组内的所有节点都会保存一份oplog(集合名local.oplog.rs)，这让他们可以保持同样的数据库状态。

为了提高同步效率，所有复制组成员都会向其他成员发送保活报文(pings)，任意从节点可以从其他成员节点同步oplog（即可以从主节点同步，也可以从从节点同步）。oplog中的操作都是幂等的，即oplog中的某个操作日志在目标数据库中应用一次或者多次，其结果都是一样的。

主从同步示意图如下(客户端写数据到主节点，从节点从主节点同步oplog并应用到本节点)：

2. Oplog 的默认储存大小

当你首次启动复制组节点时，在你未指定oplog大小时，mongodb会使用默认大小来创建oplog。

对于Unix和Windows系统来说，默认大小和存储引擎的对应关系如下：

存储引擎类型	oplog大小	下限	上限
内存	物理内存的5%	50MB	50GB
WiredTiger	空闲磁盘的5%	990MB	50GB

(注意，最新4.4版本的mongodb移除了MMAP类型存储引擎的支持。)

对于64位maxOS系统来说，参照使用的存储引擎类型，该默认大小是192MB（物理内存或者磁盘空间），如下：

存储引擎类型	oplog大小
内存	192MB物理内存
WiredTiger	192MB的磁盘空间

大部分情况下，oplog的默认大小是足够的。举个例子，如果5%的磁盘空间存储了最近24小时的操作日志，此时如果某个从节点的日志同步时间差超过24小时时，从节点将停止同步oplog，并将自身的状态从“Secondery”切换到“STALE”。当然，在实际的运行环境中，大部分复制组成员的负载会低一些，他们的oplog中也会持有更长时间段的日志。

3. 可能需要更大oplog的工作负载

如果你预测到你的复制组的工作负载属于以下的模式，你需要创建比默认值更大一些的oplog。相反的，如果你的应用大部分情况下是读操作，只有小部分的写操作，那么更小一些的oplog也是满足需要的。

下面的工作负载可能需要更大一些的oplog

单次操作会更新多条记录

为了满足oplog的幂等性，单次操作更新多条记录时，mongodb会记录多条操作日志到oplog中，这种场景就需要使用大量的oplog的空间，虽然此时数据大小或者磁盘大小并没有相应的增加那么多。

删除操作和插入操作一样多时

如果你的删除操作请求量和插入操作的请求量大致相当时，数据库在磁盘空间消耗方面不会有明显增长，但是操作日志的大小会非常巨大。

显著数量的原文档更新

如果工作负载的大部分操作都是原文档更新，此时虽然不会增加数据库中文档的数量，但是数据库需要记录大量的操作日志。

4. Oplog状态

如果要查看oplog的状态，包含记录条数和时间范围，可以使用"rs.printReplicationInfo() "命令，如下：

MongoDB Enterprise repa:PRIMARY> rs.printReplicationInfo()
configured oplog size:   1024MB  // oplog大小是1024MB
log length start to end: 867353secs (240.93hrs)  // 第一条和最后一条日志的时间差是240.93小时
oplog first event time:  Wed Jul 07 2021 20:24:57 GMT+0800
oplog last event time:   Sat Jul 17 2021 21:20:50 GMT+0800
now:                     Sat Jul 17 2021 21:20:56 GMT+0800

5. Oplog格式

从前面知道oplog是存储在数据库local中，表名为“oplog.rs”，通过查询命令看一下oplog的数据格式：

db.oplog.rs.find({"ns":"test.users"}).limit(1)   // ns字段指明查询对数据库test中users表的操作日志
{
    "ts": Timestamp(1625660877, 2),     // 日志的操作时间戳，第一个数字是时间戳，单位秒，第二个数字是当前秒的第2个操作
    "t": NumberLong(2),
    "h": NumberLong("5521980394145765083"),
    "v": 2,
    "op": "i",            // i表示insert，u表示update,d表示delete，c 表示的是数据库的命令，比如建表,n表示noop,即空操作
    "ns": "test.users",   // 命名空间，即数据库和集合名称
    "ui": UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), // 连接到mongodb的客户端会话id
    "wall": ISODate("2021-07-07T12:27:57.689Z"),  // 操作执行时间，utc时间
    "o": {        // 操作的内容，对于不同的op类型，其格式不尽相同
        "_id": ObjectId("60e59dcd46db1fb4605f8b18"),
        "name": "1"
    }
}

6. CUD操作和Oplog的对应关系

前面分析oplog日志格式的时候，查看了一条insert操作对应的日志，就不再赘述，下面再看下delete和update对应的日志格式(find不会产生oplog)。

delete操作

首先插入三条记录：

MongoDB Enterprise repa:PRIMARY> use test
switched to db test
MongoDB Enterprise repa:PRIMARY> db.users.insert({"name":"张三","age":NumberInt(10),"sex":"男"})
WriteResult({ "nInserted" : 1 })
MongoDB Enterprise repa:PRIMARY> db.users.insert({"name":"李四","age":NumberInt(11),"sex":"男"})
WriteResult({ "nInserted" : 1 })
MongoDB Enterprise repa:PRIMARY> db.users.insert({"name":"王五","age":NumberInt(12),"sex":"男"})
WriteResult({ "nInserted" : 1 })
MongoDB Enterprise repa:PRIMARY> db.users.find()
{ "_id" : ObjectId("60f2e11b0d98dc3b374199de"), "name" : "张三", "age" : 10, "sex" : "男" }
{ "_id" : ObjectId("60f2e11e0d98dc3b374199df"), "name" : "李四", "age" : 11, "sex" : "男" }
{ "_id" : ObjectId("60f2e11e0d98dc3b374199e0"), "name" : "王五", "age" : 12, "sex" : "男" }

执行delete操作，匹配条件是{"sex":"男"}，即删除所有性别为男的记录：

MongoDB Enterprise repa:PRIMARY> db.users.remove({"sex":"男"})
WriteResult({ "nRemoved" : 3 })
MongoDB Enterprise repa:PRIMARY> db.users.find()
MongoDB Enterprise repa:PRIMARY>

可以看到，一条删除命令删除了三条记录，对应的oplog是什么呢，来，查一下：

MongoDB Enterprise repa:PRIMARY> use local
switched to db local
MongoDB Enterprise repa:PRIMARY> db.oplog.rs.find({"ns":"test.users","op":"d","wall":{"$gt":ISODate("2021-07-17T13:50:57.689Z")}})
{ "ts" : Timestamp(1626530154, 1), "t" : NumberLong(2), "h" : NumberLong("5834731856459959506"), "v" : 2, "op" : "d", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "wall" : ISODate("2021-07-17T13:55:54.424Z"), "o" : { "_id" : ObjectId("60f2e11b0d98dc3b374199de") } }
{ "ts" : Timestamp(1626530154, 2), "t" : NumberLong(2), "h" : NumberLong("-2164276082472824844"), "v" : 2, "op" : "d", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "wall" : ISODate("2021-07-17T13:55:54.424Z"), "o" : { "_id" : ObjectId("60f2e11e0d98dc3b374199df") } }
{ "ts" : Timestamp(1626530154, 3), "t" : NumberLong(2), "h" : NumberLong("3834858247238363179"), "v" : 2, "op" : "d", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "wall" : ISODate("2021-07-17T13:55:54.424Z"), "o" : { "_id" : ObjectId("60f2e11e0d98dc3b374199e0") } }
MongoDB Enterprise repa:PRIMARY>

从上可以看到，一条删除命令，在oplog中记录了三条日志，下面分析其中的一条：

{
    "ts": Timestamp(1626530154, 1),
    "t": NumberLong(2),
    "h": NumberLong("5834731856459959506"),
    "v": 2,
    "op": "d",   // 删除操作
    "ns": "test.users",  // 数据库是test，集合是users
    "ui": UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"),
    "wall": ISODate("2021-07-17T13:55:54.424Z"),
    "o": {     // 待删除记录的_id
        "_id": ObjectId("60f2e11b0d98dc3b374199de")
    }
}

从上面日志分析可以得到结论：

用户的一次删除请求，如果删除了N条记录，那么oplog中将记录N条日志，日志中会记录待删除记录的“_id”字段，与用户的删除请求的参数无关。

update操作

下面再看下更新操作对应的oplog的日志数量和格式。

首先插入三条记录：

MongoDB Enterprise repa:PRIMARY> use test
switched to db test
MongoDB Enterprise repa:PRIMARY>
MongoDB Enterprise repa:PRIMARY> db.users.insert({"name":"张三","age":NumberInt(10),"sex":"男"})
WriteResult({ "nInserted" : 1 })
MongoDB Enterprise repa:PRIMARY> db.users.insert({"name":"李四","age":NumberInt(11),"sex":"男"})
WriteResult({ "nInserted" : 1 })
MongoDB Enterprise repa:PRIMARY> db.users.insert({"name":"王五","age":NumberInt(12),"sex":"男"})
WriteResult({ "nInserted" : 1 })
MongoDB Enterprise repa:PRIMARY> db.users.find()
{ "_id" : ObjectId("60f2e2db0d98dc3b374199e1"), "name" : "张三", "age" : 10, "sex" : "男" }
{ "_id" : ObjectId("60f2e2db0d98dc3b374199e2"), "name" : "李四", "age" : 11, "sex" : "男" }
{ "_id" : ObjectId("60f2e2dc0d98dc3b374199e3"), "name" : "王五", "age" : 12, "sex" : "男" }

再执行更新操作：

MongoDB Enterprise repa:PRIMARY> db.users.update({"sex":"男"},  {"$inc":{"age":NumberInt(1)}}, false, true)
WriteResult({ "nMatched" : 3, "nUpserted" : 0, "nModified" : 3 })
MongoDB Enterprise repa:PRIMARY> db.users.find()                                                          
{ "_id" : ObjectId("60f2e2db0d98dc3b374199e1"), "name" : "张三", "age" : 11, "sex" : "男" }
{ "_id" : ObjectId("60f2e2db0d98dc3b374199e2"), "name" : "李四", "age" : 12, "sex" : "男" }
{ "_id" : ObjectId("60f2e2dc0d98dc3b374199e3"), "name" : "王五", "age" : 13, "sex" : "男" }

从返回结果可以看到，更新操作执行成功，并更新了三条记录，下面看下oplog的日志：

MongoDB Enterprise repa:PRIMARY> use local
switched to db local
MongoDB Enterprise repa:PRIMARY> db.oplog.rs.find({"ns":"test.users","op":"u","wall":{"$gt":ISODate("2021-07-17T13:50:57.689Z")}})
{ "ts" : Timestamp(1626530575, 1), "t" : NumberLong(2), "h" : NumberLong("-6359278368726841648"), "v" : 2, "op" : "u", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "o2" : { "_id" : ObjectId("60f2e2db0d98dc3b374199e1") }, "wall" : ISODate("2021-07-17T14:02:55.319Z"), "o" : { "$v" : 1, "$set" : { "age" : 11 } } }
{ "ts" : Timestamp(1626530575, 2), "t" : NumberLong(2), "h" : NumberLong("-4351658862590633053"), "v" : 2, "op" : "u", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "o2" : { "_id" : ObjectId("60f2e2db0d98dc3b374199e2") }, "wall" : ISODate("2021-07-17T14:02:55.319Z"), "o" : { "$v" : 1, "$set" : { "age" : 12 } } }
{ "ts" : Timestamp(1626530575, 3), "t" : NumberLong(2), "h" : NumberLong("5911110003695351597"), "v" : 2, "op" : "u", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "o2" : { "_id" : ObjectId("60f2e2dc0d98dc3b374199e3") }, "wall" : ISODate("2021-07-17T14:02:55.319Z"), "o" : { "$v" : 1, "$set" : { "age" : 13 } } }

和delete类似，update操作也是产生了三条日志，选第一条分析：

{
    "ts": Timestamp(1626530575, 1),
    "t": NumberLong(2),
    "h": NumberLong("-6359278368726841648"),
    "v": 2,
    "op": "u",   // 更新操作
    "ns": "test.users",  // 数据库test，集合是users
    "ui": UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"),
    "o2": {  // 更新操作的查询条件，使用的记录的_id
        "_id": ObjectId("60f2e2db0d98dc3b374199e1")
    },
    "wall": ISODate("2021-07-17T14:02:55.319Z"),
    "o": {  // 更新操作的更新内容，原始的inc操作符转变为set操作符，可以满足幂等性
        "$v": 1,
        "$set": {
            "age": 11
        }
    }
}