3.MongoDB恢復探究：為什麼oplogReplay引數只設置了日誌應用結束時間oplogLimit，而沒有設定開始時間？
（一）我的疑問
在使用MySQL資料庫binlog日誌基於時間點恢復資料庫時，我們必須要指定binlog的開始位置和結束位置，而在MongoDB裡面，如果使用oplog進行恢復，只有oplogLimit引數，該引數資訊如下
--oplogLimit=<seconds>[:ordinal] only include oplog entries before the provided Timestamp
oplogLimit引數定義了資料庫恢復到該時間點。也就是說，MongoDB只是設定了oplog的結束位置，沒有指定oplog的開始位置。那麼就存在問題了，以下圖為例，我在T3時刻執行了全備份，在T4時刻資料庫發生了誤操作，當我執行恢復的時候，分為2個步驟：
- 階段1：使用完全備份，將資料庫恢復到T3時刻；
- 階段2：使用oplog日誌，將資料庫恢復到T4故障之前。T4故障之前的時間點由引數oplogLimit控制，但是：oplog的開始時間不是從T3時刻，而是T2時刻，這裡T2是oplog記錄的最早時間，該時間並不受我們控制。
補充：這裡的“不受我們控制”是指在使用mongorestore重做oplog的時候，我們沒辦法指定開始時間。但是如果想要把oplog的開始時間控制在T3時刻，還是有辦法的：使用bsondump分析全備的最後一筆資料，在備份oplog的時候，用query選項過濾掉之前的資料即可。然而，這並不是我們關心的，我所關心的，是為什麼mongorestore不給出恢復操作的開始時間引數。
說了那麼多，把問題明確一下：
mongorestore在恢復oplog的時候，只限定了日誌的結束位置，而沒有開始位置，這樣就會造成oplog恢復的開始位置不是T3，而是在T2，那麼就會存在T2~T3這段時間資料重複操作的問題，理論上會造成資料變化，為什麼mongorestore不設定一個開始時間引數去避免重複操作的問題呢？
本次測試在mongodb 4.2 副本集環境下進行。
（二）問題探索
（2.1）oplog日誌格式解析
既然該問題可能會發生在重做oplog時，那麼我們不妨先看一下oplog到底儲存了什麼資訊。為了檢視oplog日誌儲存了什麼資訊，向test集合中插入1條資料：
db.test.insert({"empno":1,"ename":"lijiaman","age":22,"address":"yunnan,kungming"});檢視test集合的資料資訊
db.test.find()
/* 1 */
{
"_id" : ObjectId("5f30eb58bcefe5270574cd54"),
"empno" : 1.0,
"ename" : "lijiaman",
"age" : 22.0,
"address" : "yunnan,kungming"
}
使用下面查詢語句檢視oplog日誌資訊：
use local db.oplog.rs.find( { $and : [ {"ns" : "testdb.test"} ] } ).sort({ts:1})
結果如下：
/* 1 */
{
"ts" : Timestamp(1597070283, 1),
"op" : "i",
"ns" : "lijiamandb.test",
"o" : {
"_id" : ObjectId("5f30eb58bcefe5270574cd54"),
"empno" : 1.0,
"ename" : "lijiaman",
"age" : 22.0,
"address" : "yunnan,kungming"
}
}
oplog中各個欄位的含義：
- ts：資料寫的時間，括號裡面第1位資料代表時間戳，是自unix紀元以來的秒值，第2位代表在1s內訂購時間戳的序列數
- op：操作型別，可選引數有：
-- "i"： insert
--"u"： update
--"d"： delete
--"c"： db cmd
--"db"：聲明當前資料庫 (其中ns 被設定成為=>資料庫名稱+ '.')
--"n": no op,即空操作，其會定期執行以確保時效性
- ns：名稱空間，通常是具體的集合
- o：具體的寫入資訊
- o2: 在執行更新操作時的where條件，僅限於update時才有該屬性
（2.2）文件中的“_id”欄位
在上面的插入文件中，我們發現每插入一個文件，都會伴隨著產生一個“_id”欄位，該欄位是一個object型別，對於“_id”，需要知道：
- "_id"是集合文件的主鍵，每個文件（即每行記錄）都有一個唯一的"_id"值
- "_id"會自動生成，也可以手動指定，但是必須唯一且非空。
經過測試，發現在執行文件的DML操作時，會根據ID進行，我們不妨來看看DML操作的文件變化。
（1）插入文件，檢視文件資訊與oplog資訊
use testdb
//插入文件
db.mycol.insert({id:1,name:"a"})
db.mycol.insert({id:2,name:"b"})
db.mycol.insert({id:3,name:"c"})
db.mycol.insert({id:4,name:"d"})
db.mycol.insert({id:5,name:"e"})
db.mycol.insert({id:6,name:"f"})
rstest:PRIMARY> db.mycol.find()
{ "_id" : ObjectId("5f3b471a6530eb8aa5bf88a0"), "id" : 1, "name" : "a" }
{ "_id" : ObjectId("5f3b471a6530eb8aa5bf88a1"), "id" : 2, "name" : "b" }
{ "_id" : ObjectId("5f3b471a6530eb8aa5bf88a2"), "id" : 3, "name" : "c" }
{ "_id" : ObjectId("5f3b471a6530eb8aa5bf88a3"), "id" : 4, "name" : "d" }
{ "_id" : ObjectId("5f3b471a6530eb8aa5bf88a4"), "id" : 5, "name" : "e" }
{ "_id" : ObjectId("5f3b471b6530eb8aa5bf88a5"), "id" : 6, "name" : "f" }
這裡記錄該集合文件的變化，可以發現，mongodb為每條資料都分配了一個唯一且非空的”_id”：
此時檢視oplog，如下
/* 1 */
{
"ts" : Timestamp(1597720346, 2),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "i",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"wall" : ISODate("2020-08-18T03:12:26.231Z"),
"o" : {
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a0"),
"id" : 1.0,
"name" : "a"
}
}
/* 2 */
{
"ts" : Timestamp(1597720346, 3),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "i",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"wall" : ISODate("2020-08-18T03:12:26.246Z"),
"o" : {
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a1"),
"id" : 2.0,
"name" : "b"
}
}
... 略 ...
（2)更新操作
rstest:PRIMARY> db.mycol.update({"id":1},{$set:{"name":"aa"}})
WriteResult({ "nMatched" : 1, "nUpserted" : 0, "nModified" : 1 })
這裡更新了1行資料，可以看到，文件id是沒有發生變化的
此時檢視oplog，如下：
/* 7 */
{
"ts" : Timestamp(1597720412, 1),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "u",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"o2" : {
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a0")
},
"wall" : ISODate("2020-08-18T03:13:32.649Z"),
"o" : {
"$v" : 1,
"$set" : {
"name" : "aa"
}
}
}
這裡值得我們注意：上面我們說到，oplog的”o2”引數是更新的where條件，我們在執行更新的時候，指定的where條件是”id=1”，id是我們自己定義的列，然而，在oplog裡面指定的where條件是
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a0")，很明顯，他們都指向了同一條資料。這樣，當我們使用oplog進行資料恢復的時候，直接根據”_id”去做資料更新，即使再執行N遍，也不會導致資料更新出錯。
（3)再次更新操作
上面我們是對某一條資料進行更新，並且在update中指出了更新後的資料，這裡再測試一下，我使用自增的方式更新資料。
// 每條資料的id在當前的基礎上加10rstest:PRIMARY> db.mycol.update({},{$inc:{"id":10}},{multi:true}) WriteResult({ "nMatched" : 6, "nUpserted" : 0, "nModified" : 6 })
資料變化如圖，可以看到，id雖然發生了變化，但是”_id”是沒有改變的。
再來看oplog資訊
/* 8 */
{
"ts" : Timestamp(1597720424, 1),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "u",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"o2" : {
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a0")
},
"wall" : ISODate("2020-08-18T03:13:44.398Z"),
"o" : {
"$v" : 1,
"$set" : {
"id" : 11.0
}
}
}
/* 9 */
{
"ts" : Timestamp(1597720424, 2),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "u",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"o2" : {
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a1")
},
"wall" : ISODate("2020-08-18T03:13:44.399Z"),
"o" : {
"$v" : 1,
"$set" : {
"id" : 12.0
}
}
}
/* 10 */
{
"ts" : Timestamp(1597720424, 3),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "u",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"o2" : {
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a2")
},
"wall" : ISODate("2020-08-18T03:13:44.399Z"),
"o" : {
"$v" : 1,
"$set" : {
"id" : 13.0
}
}
}
/* 11 */
{
"ts" : Timestamp(1597720424, 4),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "u",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"o2" : {
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a3")
},
"wall" : ISODate("2020-08-18T03:13:44.400Z"),
"o" : {
"$v" : 1,
"$set" : {
"id" : 14.0
}
}
}
/* 12 */
{
"ts" : Timestamp(1597720424, 5),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "u",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"o2" : {
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a4")
},
"wall" : ISODate("2020-08-18T03:13:44.400Z"),
"o" : {
"$v" : 1,
"$set" : {
"id" : 15.0
}
}
}
/* 13 */
{
"ts" : Timestamp(1597720424, 6),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "u",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"o2" : {
"_id" : ObjectId("5f3b471b6530eb8aa5bf88a5")
},
"wall" : ISODate("2020-08-18T03:13:44.400Z"),
"o" : {
"$v" : 1,
"$set" : {
"id" : 16.0
}
}
}
這裡也非常值得我們注意：o2記錄的是已經發生更改的文件_id，o就比較有意思了，記錄的是發生變更之後的值。我們可以發現，如果我們把上面自增更新的SQL執行每執行1次，id都會加10，但是，我們重複執行N次oplog，並不會改變對應記錄的值。
（4)再來看看刪除操作
// 刪除id大於14的條目
rstest:PRIMARY> db.mycol.remove({"id":{"$gt":14}})
WriteResult({ "nRemoved" : 2 })
資料變化如下圖:
再來看看oplog日誌：
/* 14 */
{
"ts" : Timestamp(1597720485, 1),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "d",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"wall" : ISODate("2020-08-18T03:14:45.511Z"),
"o" : {
"_id" : ObjectId("5f3b471a6530eb8aa5bf88a4")
}
}
/* 15 */
{
"ts" : Timestamp(1597720485, 2),
"t" : NumberLong(11),
"h" : NumberLong(0),
"v" : 2,
"op" : "d",
"ns" : "testdb.mycol",
"ui" : UUID("56c4e1ad-4a15-44ca-96c8-3b3b5be29616"),
"wall" : ISODate("2020-08-18T03:14:45.511Z"),
"o" : {
"_id" : ObjectId("5f3b471b6530eb8aa5bf88a5")
}
}
”op”:”d”選項記錄了該操作是執行刪除，具體刪除什麼資料，由o選項記錄，可以看到，o記錄的是”_id”，也就是說，oplog中刪除操作是根據”_id”執行的。
（三）結論
可以看到，在DML操作資料庫時，oplog時基於"_id"記錄文件變化的。那麼，我們來總結一下開頭提出的問題：未指定開始時間，oplog資料是否會重複操作呢？
- 如果當前資料庫已經存在相同id的資料，那麼不會執行二次插入，主鍵衝突報錯；
- 在做更新時，記錄的是更新文件的"_id"以及發生變更後的資料，因此，如果再次執行，只會修改該條資料，哪怕執行N遍，效果也和執行一遍是一樣的，所有也就不怕重複操作單條資料了；
- 在執行刪除操作時，記錄的是刪除的文件"_id"，同樣，執行N遍和執行一遍效果是一樣的，因為”_id”是唯一的。
因此，即使oplog從完全備份之前開始應用，也不會造成資料的多次變更。
【完】
|
相關文件： 1.MongoDB 2.7主從複製(master –> slave)環境基於時間點的恢復
|