3.MongoDB恢復探究：為什麼oplogReplay參數只設置了日誌應用結束時間oplogLimit，而沒有設置開始時間？

2020 年 8 月 19 日
筆記
--400 MongoDB

（一）我的疑問

在使用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在當前的基礎上加10
rstest: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」執行的。

（三）結論