(一)我的疑問
在使用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 })
此時查看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)環境基於時間點的恢復
|