3.MongoDB恢復探究:為什麼oplogReplay引數只設定了日誌應用結束時間oplogLimit,而沒有設定開始時間?

gegeman發表於2020-08-19

(一)我的疑問

在使用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不給出恢復操作的開始時間引數。

clipboard

說了那麼多,把問題明確一下:

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”:

clipboard

此時檢視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是沒有發生變化的clipboard

此時檢視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在當前的基礎上加10
rstest:PRIMARY> db.mycol.update({},{$inc:{"id":10}},{multi:true}) WriteResult({ "nMatched" : 6, "nUpserted" : 0, "nModified" : 6 })

資料變化如圖,可以看到,id雖然發生了變化,但是”_id”是沒有改變的。

clipboard

再來看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 })

資料變化如下圖:

clipboard

再來看看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)環境基於時間點的恢復  
2.MongoDB 4.2副本集環境基於時間點的恢復


3.MongoDB恢復探究:為什麼oplogReplay引數只設定了日誌應用結束時間oplogLimit,而沒有設定開始時間?

相關文章