mongodb oplog日志详解和格式分析

爱护朋友 發表於 2021-7-17 22:22:00

<h1>1. 基本概念</h1>
    oplog使用固定大小集合记录了数据库中所有修改操作的操作日志(新增、修改和删除，无查询)，其记录每条记录被修改后的数据，等同于MYSQL中ROW类型的binlog。mongodb收到修改请求后，先在主节点（Primary）执行请求，再把操作日志保存到oplog表中，其他从节点（Secondary）到主节点拉取oplog并在异步进程中应用这些操作，从而达到主从数据的一致性。复制组内的所有节点都会保存一份oplog(集合名local.oplog.rs)，这让他们可以保持同样的数据库状态。
     为了提高同步效率，所有复制组成员都会向其他成员发送保活报文(pings)，任意从节点可以从其他成员节点同步oplog（即可以从主节点同步，也可以从从节点同步）。oplog中的操作都是幂等的，即oplog中的某个操作日志在目标数据库中应用一次或者多次，其结果都是一样的。
     主从同步示意图如下(客户端写数据到主节点，从节点从主节点同步oplog并应用到本节点)：
<img src="https://img2020.cnblogs.com/blog/319908/202107/319908-20210712172942439-316895130.svg" alt="" width="456" height="373" loading="lazy">
 
<h1>2. Oplog 的默认储存大小</h1>
 当你首次启动复制组节点时，在你未指定oplog大小时，mongodb会使用默认大小来创建oplog。
对于Unix和Windows系统来说，默认大小和存储引擎的对应关系如下：
<table border="0" align="left">
<tbody>
<tr>
<td>存储引擎类型</td>
<td>oplog大小</td>
<td>下限</td>
<td>上限</td>

</tr>
<tr>
<td>内存</td>
<td>物理内存的5%</td>
<td>50MB</td>
<td>50GB</td>

</tr>
<tr>
<td>WiredTiger</td>
<td>空闲磁盘的5%</td>
<td>990MB</td>
<td>50GB　</td>

</tr>

</tbody>

</table>
 (注意，最新4.4版本的mongodb移除了MMAP类型存储引擎的支持。)
对于64位maxOS系统来说，参照使用的存储引擎类型，该默认大小是192MB（物理内存或者磁盘空间），如下：
<table border="0" align="left">
<tbody>
<tr>
<td>存储引擎类型</td>
<td>oplog大小</td>

</tr>
<tr>
<td>内存</td>
<td>192MB物理内存</td>

</tr>
<tr>
<td>WiredTiger</td>
<td>192MB的磁盘空间</td>

</tr>

</tbody>

</table>
 大部分情况下，oplog的默认大小是足够的。举个例子，如果5%的磁盘空间存储了最近24小时的操作日志，此时如果某个从节点的日志同步时间差超过24小时时，从节点将停止同步oplog，并将自身的状态从“Secondery”切换到“STALE”。当然，在实际的运行环境中，大部分复制组成员的负载会低一些，他们的oplog中也会持有更长时间段的日志。
<h1>3. 可能需要更大oplog的工作负载</h1>
如果你预测到你的复制组的工作负载属于以下的模式，你需要创建比默认值更大一些的oplog。相反的，如果你的应用大部分情况下是读操作，只有小部分的写操作，那么更小一些的oplog也是满足需要的。
下面的工作负载可能需要更大一些的oplog
<h2>单次操作会更新多条记录</h2>
为了满足oplog的幂等性，单次操作更新多条记录时，mongodb会记录多条操作日志到oplog中，这种场景就需要使用大量的oplog的空间，虽然此时数据大小或者磁盘大小并没有相应的增加那么多。
<h2>删除操作和插入操作一样多时</h2>
 如果你的删除操作请求量和插入操作的请求量大致相当时，数据库在磁盘空间消耗方面不会有明显增长，但是操作日志的大小会非常巨大。
<h2>显著数量的原文档更新</h2>
如果工作负载的大部分操作都是原文档更新，此时虽然不会增加数据库中文档的数量，但是数据库需要记录大量的操作日志。
<h1>4. Oplog状态</h1>
如果要查看oplog的状态，包含记录条数和时间范围，可以使用"rs.printReplicationInfo() "命令，如下：
<div class="cnblogs_code">
<pre>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</pre>
</div>
 
<h1>5. Oplog格式</h1>
从前面知道oplog是存储在数据库local中，表名为“oplog.rs”，通过查询命令看一下oplog的数据格式：
<div class="cnblogs_code">
<pre>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"
}
}</pre>
</div>
 
<h1>6. CUD操作和Oplog的对应关系</h1>
前面分析oplog日志格式的时候，查看了一条insert操作对应的日志，就不再赘述，下面再看下delete和update对应的日志格式(find不会产生oplog)。
<h2>delete操作</h2>
首先插入三条记录：
<div class="cnblogs_code">
<pre>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" : "男" }</pre>
</div>
执行delete操作，匹配条件是{"sex":"男"}，即删除所有性别为男的记录：
<div class="cnblogs_code">
<pre>MongoDB Enterprise repa:PRIMARY> db.users.remove({"sex":"男"})
WriteResult({ "nRemoved" : 3 })
MongoDB Enterprise repa:PRIMARY> db.users.find() MongoDB Enterprise repa:PRIMARY></pre>
</div>
可以看到，一条删除命令删除了三条记录，对应的oplog是什么呢，来，查一下：
<div class="cnblogs_code">
<pre>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></pre>
</div>
从上可以看到，一条删除命令，在oplog中记录了三条日志，下面分析其中的一条：
<div class="cnblogs_code">
<pre>{
"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")
}
}</pre>
</div>
从上面日志分析可以得到结论：
用户的一次删除请求，如果删除了N条记录，那么oplog中将记录N条日志，日志中会记录待删除记录的“_id”字段，与用户的删除请求的参数无关。
<h2>update操作</h2>
下面再看下更新操作对应的oplog的日志数量和格式。
首先插入三条记录：
<div class="cnblogs_code">
<pre>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" : "男" }</pre>
</div>
再执行更新操作：
<div class="cnblogs_code">
<pre>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" : "男" }</pre>
</div>
从返回结果可以看到，更新操作执行成功，并更新了三条记录，下面看下oplog的日志：
<div class="cnblogs_code">
<pre>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 } } }</pre>
</div>
和delete类似，update操作也是产生了三条日志，选第一条分析：
<div class="cnblogs_code">
<pre>{
"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
 }
}
}</pre>
</div>
从上面日志分析可以得到结论：
用户的一次更新请求，如果更新了N条记录，那么oplog中将记录N条日志，日志中记录待更新记录的“_id”字段为查询条件，更新操作使用的是set操作符，并不是用户的更新操作符。
<h2>小结</h2>
从上面的delete和update操作对应的oplog日志分析可以看出，oplog记录的不是用户的原始命令，而是对应的逻辑命令，通过这种方式可以满足oplog的幂等性，但是也会衍生出可能产生大量oplog记录的问题，需要用户根据业务模型的需要，来选择合适的oplog大小。

</div>
<div id="MySignature" role="contentinfo">
https://github.com/tomliugen 
来源：https://www.cnblogs.com/xinghebuluo/p/15003040.html

頁: [1]

琼殿技术论坛's Archiver

mongodb oplog日志详解和格式分析