‘E11000 duplicate key error‘ is an error that you might have encountered during the restore process. In this blog, we will talk about in what scenario you might face this error when restoring Oplog for PITR (point-in-time recovery).
You might wonder why this error will come during PITR as the operations in the Oplog are idempotent, meaning they always result in the same change to the database no matter how many times they’re performed. Now let’s see in which scenario you might face this error while applying Oplog.
I created a collection book with four documents with a unique compound index. So as per the application logic, the document is first inserted, updated, and deleted, but when a new document is re-inserted, it is created with the same keys and values on which a unique index is created.
|
1 |
{<br> "v" : 2,<br> "unique" : true,<br> "key" : {<br> "number" : 1,<br> "author" : 1<br> },<br> "name" : "number_1_author_1"<br> } |
Now your application logic is written in such a way that it is doing insert, update, delete, and again inserting the document with the same values in the number and author keys on which the unique index is created. Below we have already inserted four docs, and now, we will update one of the below documents.
|
1 |
rs1:PRIMARY> db.book.find()<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610c"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610d"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610e"), "number" : 3, "title" : "2 states", "author" : "Peter" }<br>{ "_id" : ObjectId("641c11c1d0495f80ac5e610f"), "number" : 4, "title" : "a time to kill", "author" : "Graham" }<br>rs1:PRIMARY> Date()<br>Thu Mar 23 2023 08:45:55 GMT+0000 (UTC)<br>rs1:PRIMARY> |
|
1 |
rs1:PRIMARY> db.oplog.rs.find({ns:"london.book"})<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("9cb7ae0a-6974-4363-ae24-0de30f0cd915"), "o" : { "_id" : ObjectId("641c11bfd0495f80ac5e610c"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }, "ts" : Timestamp(1679561151, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T08:45:51.775Z") }<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("9cb7ae0a-6974-4363-ae24-0de30f0cd915"), "o" : { "_id" : ObjectId("641c11bfd0495f80ac5e610d"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }, "ts" : Timestamp(1679561151, 2), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T08:45:51.778Z") }<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("9cb7ae0a-6974-4363-ae24-0de30f0cd915"), "o" : { "_id" : ObjectId("641c11bfd0495f80ac5e610e"), "number" : 3, "title" : "2 states", "author" : "Peter" }, "ts" : Timestamp(1679561151, 3), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T08:45:51.781Z") }<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("9cb7ae0a-6974-4363-ae24-0de30f0cd915"), "o" : { "_id" : ObjectId("641c11c1d0495f80ac5e610f"), "number" : 4, "title" : "a time to kill", "author" : "Graham" }, "ts" : Timestamp(1679561153, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T08:45:53.302Z") }<br>rs1:PRIMARY><br> |
|
1 |
rs1:PRIMARY> db.book.update({"number":4},{$set: {title: "Minion"}})<br>WriteResult({ "nMatched" : 1, "nUpserted" : 0, "nModified" : 1 })<br>rs1:PRIMARY> Date()<br>Thu Mar 23 2023 08:47:29 GMT+0000 (UTC)<br>rs1:PRIMARY> db.book.find()<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610c"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610d"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610e"), "number" : 3, "title" : "2 states", "author" : "Peter" }<br>{ "_id" : ObjectId("641c11c1d0495f80ac5e610f"), "number" : 4, "title" : "Minion", "author" : "Graham" }<br>rs1:PRIMARY><br> |
|
1 |
rs1:PRIMARY> db.oplog.rs.find({ns:"london.book"}).sort({$natural:-1}).limit(1)<br>{ "op" : "u", "ns" : "london.book", "ui" : UUID("9cb7ae0a-6974-4363-ae24-0de30f0cd915"), "o" : { "$v" : 1, "$set" : { "title" : "Minion" } }, "o2" : { "_id" : ObjectId("641c11c1d0495f80ac5e610f") }, "ts" : Timestamp(1679561243, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T08:47:23.448Z") }<br>rs1:PRIMARY><br> |
|
1 |
rs1:PRIMARY> db.book.remove({number: 4})<br>WriteResult({ "nRemoved" : 1 })<br>rs1:PRIMARY> Date()<br>Thu Mar 23 2023 08:48:37 GMT+0000 (UTC)<br>rs1:PRIMARY> db.book.find()<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610c"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610d"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610e"), "number" : 3, "title" : "2 states", "author" : "Peter" }<br>rs1:PRIMARY> |
|
1 |
rs1:PRIMARY> db.oplog.rs.find({ns:"london.book"}).sort({$natural:-1}).limit(1)<br>{ "op" : "d", "ns" : "london.book", "ui" : UUID("9cb7ae0a-6974-4363-ae24-0de30f0cd915"), "o" : { "_id" : ObjectId("641c11c1d0495f80ac5e610f") }, "ts" : Timestamp(1679561315, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T08:48:35.203Z") }<br>rs1:PRIMARY> |
|
1 |
rs1:PRIMARY> db.book.insert({"number" : 4, "title" : "Stranger things", "author" : "Graham" })<br>WriteResult({ "nInserted" : 1 })<br>rs1:PRIMARY> Date()<br>Thu Mar 23 2023 08:50:46 GMT+0000 (UTC)<br>rs1:PRIMARY> db.book.find()<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610c"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610d"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610e"), "number" : 3, "title" : "2 states", "author" : "Peter" }<br>{ "_id" : ObjectId("641c12e4d0495f80ac5e6111"), "number" : 4, "title" : "Stranger things", "author" : "Graham" }<br>rs1:PRIMARY> |
|
1 |
rs1:PRIMARY> db.oplog.rs.find({ns:"london.book"}).sort({$natural:-1}).limit(1)<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("9cb7ae0a-6974-4363-ae24-0de30f0cd915"), "o" : { "_id" : ObjectId("641c12e4d0495f80ac5e6111"), "number" : 4, "title" : "Stranger things", "author" : "Graham" }, "ts" : Timestamp(1679561444, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T08:50:44.861Z") }<br>rs1:PRIMARY> |
|
1 |
# mongodump<br>2023-03-23T08:52:01.032+0000 writing admin.system.version to dump/admin/system.version.bson<br>2023-03-23T08:52:01.033+0000 done dumping admin.system.version (1 document)<br>2023-03-23T08:52:01.033+0000 writing london.book to dump/london/book.bson<br>2023-03-23T08:52:01.034+0000 done dumping london.book (4 documents)<br># |
|
1 |
rs1:PRIMARY> db.book.insert({"number" : 5, "title" : "Stranger things", "author" : "Graham" })<br>WriteResult({ "nInserted" : 1 })<br>rs1:PRIMARY> Date()<br>Thu Mar 23 2023 08:52:37 GMT+0000 (UTC)<br>rs1:PRIMARY> db.book.find()<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610c"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610d"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610e"), "number" : 3, "title" : "2 states", "author" : "Peter" }<br>{ "_id" : ObjectId("641c12e4d0495f80ac5e6111"), "number" : 4, "title" : "Stranger things", "author" : "Graham" }<br>{ "_id" : ObjectId("641c1352673573868f17cacf"), "number" : 5, "title" : "Stranger things", "author" : "Graham" }<br>rs1:PRIMARY> |
|
1 |
rs1:PRIMARY> db.oplog.rs.find({ns:"london.book"}).sort({$natural:-1}).limit(1)<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("9cb7ae0a-6974-4363-ae24-0de30f0cd915"), "o" : { "_id" : ObjectId("641c1352673573868f17cacf"), "number" : 5, "title" : "Stranger things", "author" : "Graham" }, "ts" : Timestamp(1679561554, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T08:52:34.739Z") }<br>rs1:PRIMARY> |
|
1 |
# mongodump --db=local --collection=oplog.rs --query '{"ts":{"$gte":{"$timestamp": {"i":1, "t": 1679561120}}, "$lte":{"$timestamp": {"i":2, "t": 1679561151}}}}'<br>2023-03-23T08:59:29.667+0000 writing local.oplog.rs to dump/local/oplog.rs.bson<br>2023-03-23T08:59:29.668+0000 done dumping local.oplog.rs (7 documents)<br>#<br># cd dump/local/<br># ls -ltrh<br>total 8.0K<br>-rw-r--r-- 1 root root 193 Mar 23 08:59 oplog.rs.metadata.json<br>-rw-r--r-- 1 root root 1.1K Mar 23 08:59 oplog.rs.bson<br># mv oplog.rs.metadata.json oplog_1.rs.metadata.json<br># mv oplog.rs.bson oplog_1.rs.bson<br># ls -ltr<br>total 8<br>-rw-r--r-- 1 root root 193 Mar 23 08:59 oplog_1.rs.metadata.json<br>-rw-r--r-- 1 root root 1.1K Mar 23 08:59 oplog_1.rs.bson<br>#<br># bsondump oplog_1.rs.bson | tail -n 1<br><br>2023-03-23T09:01:50.590+0000 7 objects found<br>{"op":"i","ns":"london.book","ui":{"$binary":{"base64":"nLeuCml0Q2OuJA3jDwzZFQ==","subType":"04"}},"o":{"_id":{"$oid":"641c11bfd0495f80ac5e610d"},"number":{"$numberDouble":"2.0"},"title":"game of thrones","author":"chetan"},"ts":{"$timestamp":{"t":1679561151,"i":2}},"t":{"$numberLong":"1"},"v":{"$numberLong":"2"},"wall":{"$date":{"$numberLong":"1679561151778"}}}<br># |
After second Oplog dump (incremental):
|
1 |
# mongodump --db=local --collection=oplog.rs --query '{"ts":{"$gt":{"$timestamp": {"i":2, "t": 1679561151}}, "$lte":{"$timestamp": {"i":1, "t": 1679562180}}}}'<br>2023-03-23T09:03:27.070+0000 writing local.oplog.rs to dump/local/oplog.rs.bson<br>2023-03-23T09:03:27.071+0000 done dumping local.oplog.rs (107 documents)<br>#<br># ls -ltrh<br>total 24K<br>-rw-r--r-- 1 root root 193 Mar 23 08:59 oplog_1.rs.metadata.json<br>-rw-r--r-- 1 root root 1.1K Mar 23 08:59 oplog_1.rs.bson<br>-rw-r--r-- 1 root root 193 Mar 23 09:03 oplog.rs.metadata.json<br>-rw-r--r-- 1 root root 12K Mar 23 09:03 oplog.rs.bson<br>#<br># bsondump oplog.rs.bson | head -n 1<br>2023-03-23T09:04:28.976+0000 107 objects found<br>{"op":"i","ns":"london.book","ui":{"$binary":{"base64":"nLeuCml0Q2OuJA3jDwzZFQ==","subType":"04"}},"o":{"_id":{"$oid":"641c11bfd0495f80ac5e610e"},"number":{"$numberDouble":"3.0"},"title":"2 states","author":"Peter"},"ts":{"$timestamp":{"t":1679561151,"i":3}},"t":{"$numberLong":"1"},"v":{"$numberLong":"2"},"wall":{"$date":{"$numberLong":"1679561151781"}}}<br># |
Above is the starting document of the second/incremental Oplog backup i.e., $timestamp”:{“t”:1679561151,”i”:3}}
|
1 |
rs1:PRIMARY> db.dropDatabase()<br>{<br> "dropped" : "london",<br> "ok" : 1,<br> "$clusterTime" : {<br> "clusterTime" : Timestamp(1679562380, 2),<br> "signature" : {<br> "hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),<br> "keyId" : NumberLong(0)<br> }<br> },<br> "operationTime" : Timestamp(1679562380, 2)<br>}<br>rs1:PRIMARY> Date()<br>Thu Mar 23 2023 09:06:37 GMT+0000 (UTC)<br>rs1:PRIMARY> |
|
1 |
rs1:PRIMARY> db.oplog.rs.find({ns:"london.$cmd"}).sort({$natural:-1}).limit(1)<br>{ "op" : "c", "ns" : "london.$cmd", "o" : { "dropDatabase" : 1 }, "ts" : Timestamp(1679562380, 2), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T09:06:20.121Z") }<br>rs1:PRIMARY> |
|
1 |
# mongorestore dump/london/book.bson<br>2023-03-23T09:09:05.433+0000 checking for collection data in dump/london/book.bson<br>2023-03-23T09:09:05.433+0000 reading metadata for london.book from dump/london/book.metadata.json<br>2023-03-23T09:09:05.448+0000 restoring london.book from dump/london/book.bson<br>2023-03-23T09:09:05.490+0000 finished restoring london.book (4 documents, 0 failures)<br>2023-03-23T09:09:05.490+0000 restoring indexes for collection london.book from metadata<br>2023-03-23T09:09:05.490+0000 index: &idx.IndexDocument{Options:primitive.M{"name":"number_1_author_1", "unique":true, "v":2}, Key:primitive.D{primitive.E{Key:"number", Value:1}, primitive.E{Key:"author", Value:1}}, PartialFilterExpression:primitive.D(nil)}<br>2023-03-23T09:09:05.526+0000 4 document(s) restored successfully. 0 document(s) failed to restore.<br># |
|
1 |
rs1:PRIMARY> db.book.find()<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610c"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610d"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }<br>{ "_id" : ObjectId("641c11bfd0495f80ac5e610e"), "number" : 3, "title" : "2 states", "author" : "Peter" }<br>{ "_id" : ObjectId("641c12e4d0495f80ac5e6111"), "number" : 4, "title" : "Stranger things", "author" : "Graham" }<br>rs1:PRIMARY> |
|
1 |
{ "lsid" : { "id" : UUID("ce17fa90-9f06-4710-9b3b-3f4e9484e213"), "uid" : BinData(0,"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=") }, "txnNumber" : NumberLong(1), "op" : "i", "ns" : "london.book", "ui" : UUID("9e30c316-b21a-4f43-bbcc-d80593001391"), "o" : { "_id" : ObjectId("641c12e4d0495f80ac5e6111"), "number" : 4, "title" : "Stranger things", "author" : "Graham" }, "ts" : Timestamp(1679562545, 5), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T09:09:05.451Z"), "stmtId" : 3, "prevOpTime" : { "ts" : Timestamp(1679562545, 4), "t" : NumberLong(1) } }<br><br>{ "lsid" : { "id" : UUID("ce17fa90-9f06-4710-9b3b-3f4e9484e213"), "uid" : BinData(0,"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=") }, "txnNumber" : NumberLong(1), "op" : "i", "ns" : "london.book", "ui" : UUID("9e30c316-b21a-4f43-bbcc-d80593001391"), "o" : { "_id" : ObjectId("641c11bfd0495f80ac5e610e"), "number" : 3, "title" : "2 states", "author" : "Peter" }, "ts" : Timestamp(1679562545, 4), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T09:09:05.451Z"), "stmtId" : 2, "prevOpTime" : { "ts" : Timestamp(1679562545, 3), "t" : NumberLong(1) } }<br><br>{ "lsid" : { "id" : UUID("ce17fa90-9f06-4710-9b3b-3f4e9484e213"), "uid" : BinData(0,"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=") }, "txnNumber" : NumberLong(1), "op" : "i", "ns" : "london.book", "ui" : UUID("9e30c316-b21a-4f43-bbcc-d80593001391"), "o" : { "_id" : ObjectId("641c11bfd0495f80ac5e610d"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }, "ts" : Timestamp(1679562545, 3), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T09:09:05.451Z"), "stmtId" : 1, "prevOpTime" : { "ts" : Timestamp(1679562545, 2), "t" : NumberLong(1) } }<br><br>{ "lsid" : { "id" : UUID("ce17fa90-9f06-4710-9b3b-3f4e9484e213"), "uid" : BinData(0,"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=") }, "txnNumber" : NumberLong(1), "op" : "i", "ns" : "london.book", "ui" : UUID("9e30c316-b21a-4f43-bbcc-d80593001391"), "o" : { "_id" : ObjectId("641c11bfd0495f80ac5e610c"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }, "ts" : Timestamp(1679562545, 2), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T09:09:05.451Z"), "stmtId" : 0, "prevOpTime" : { "ts" : Timestamp(0, 0), "t" : NumberLong(-1) } } |
|
1 |
# bsondump oplog_1.rs.bson | tail -n 1<br>2023-03-23T09:11:40.539+0000 7 objects found<br>{"op":"i","ns":"london.book","ui":{"$binary":{"base64":"nLeuCml0Q2OuJA3jDwzZFQ==","subType":"04"}},"o":{"_id":{"$oid":"641c11bfd0495f80ac5e610d"},"number":{"$numberDouble":"2.0"},"title":"game of thrones","author":"chetan"},"ts":{"$timestamp":{"t":1679561151,"i":2}},"t":{"$numberLong":"1"},"v":{"$numberLong":"2"},"wall":{"$date":{"$numberLong":"1679561151778"}}}<br># |
|
1 |
# bsondump oplog.rs.bson | head -n 1<br>2023-03-23T09:12:31.646+0000 107 objects found<br>{"op":"i","ns":"london.book","ui":{"$binary":{"base64":"nLeuCml0Q2OuJA3jDwzZFQ==","subType":"04"}},"o":{"_id":{"$oid":"641c11bfd0495f80ac5e610e"},"number":{"$numberDouble":"3.0"},"title":"2 states","author":"Peter"},"ts":{"$timestamp":{"t":1679561151,"i":3}},"t":{"$numberLong":"1"},"v":{"$numberLong":"2"},"wall":{"$date":{"$numberLong":"1679561151781"}}}<br>#<br>#mongorestore --oplogFile=oplog.rs.bson --oplogReplay --oplogLimit 1679562370:1 /root/dump/local/<br>2023-03-23T09:13:18.969+0000 preparing collections to restore from<br>2023-03-23T09:13:18.969+0000 don't know what to do with file "/root/dump/local/oplog.rs.bson", skipping…<br>2023-03-23T09:13:18.969+0000 don't know what to do with file "/root/dump/local/oplog.rs.metadata.json", skipping…<br>2023-03-23T09:13:18.969+0000 don't know what to do with file "/root/dump/local/oplog_1.rs.bson", skipping…<br>2023-03-23T09:13:18.969+0000 don't know what to do with file "/root/dump/local/oplog_1.rs.metadata.json", skipping…<br>2023-03-23T09:13:18.969+0000 replaying oplog<br>2023-03-23T09:13:18.978+0000 Failed: restore error: error applying oplog: applyOps: (DuplicateKey) E11000 duplicate key error collection: london.book index: number_1_author_1 dup key: { number: 4.0, author: "Graham" }<br>2023-03-23T09:13:18.978+0000 0 document(s) restored successfully. 0 document(s) failed to restore.<br># |
|
1 |
{ "_id" : ObjectId("641c12e4d0495f80ac5e6111"), "number" : 4, "title" : "Stranger things", "author" : "Graham" } |
|
1 |
# bsondump oplog.rs.bson | grep Graham <br>{"op":"i","ns":"london.book","ui":{"$binary":{"base64":"nLeuCml0Q2OuJA3jDwzZFQ==","subType":"04"}},"o":{"_id":{"$oid":"641c11c1d0495f80ac5e610f"},"number":{"$numberDouble":"4.0"},"title":"a time to kill","author":"Graham"},"ts":{"$timestamp":{"t":1679561153,"i":1}},"t":{"$numberLong":"1"},"v":{"$numberLong":"2"},"wall":{"$date":{"$numberLong":"1679561153302"}}}<br>{"op":"i","ns":"london.book","ui":{"$binary":{"base64":"nLeuCml0Q2OuJA3jDwzZFQ==","subType":"04"}},"o":{"_id":{"$oid":"641c12e4d0495f80ac5e6111"},"number":{"$numberDouble":"4.0"},"title":"Stranger things","author":"Graham"},"ts":{"$timestamp":{"t":1679561444,"i":1}},"t":{"$numberLong":"1"},"v":{"$numberLong":"2"},"wall":{"$date":{"$numberLong":"1679561444861"}}}<br>{"op":"i","ns":"london.book","ui":{"$binary":{"base64":"nLeuCml0Q2OuJA3jDwzZFQ==","subType":"04"}},"o":{"_id":{"$oid":"641c1352673573868f17cacf"},"number":{"$numberDouble":"5.0"},"title":"Stranger things","author":"Graham"},"ts":{"$timestamp":{"t":1679561554,"i":1}},"t":{"$numberLong":"1"},"v":{"$numberLong":"2"},"wall":{"$date":{"$numberLong":"1679561554739"}}}<br>2023-03-23T09:14:34.118+0000 107 objects found<br># |
There are two solutions for the above issue:
To overcome the above issue, I configured the PBM on the same replica set and took a backup (both full and incremental Oplog). Here’s how to install, set up, and configure PBM.
Below is the process I followed again from step one to step six for PBM, and below are the corresponding ops in Oplog:
|
1 |
rs1:PRIMARY> db.oplog.rs.find({ns:"london.book"})<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c3b0a6eddc54ce4f75df8"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }, "ts" : Timestamp(1679571722, 2), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T11:42:02.988Z") }<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c3b0a6eddc54ce4f75df9"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }, "ts" : Timestamp(1679571722, 3), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T11:42:02.990Z") }<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c3b0a6eddc54ce4f75dfa"), "number" : 3, "title" : "2 states", "author" : "Peter" }, "ts" : Timestamp(1679571722, 4), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T11:42:02.992Z") }<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c3b0b6eddc54ce4f75dfb"), "number" : 4, "title" : "a time to kill", "author" : "Graham" }, "ts" : Timestamp(1679571723, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T11:42:03.840Z") }<br>{ "op" : "u", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "$v" : 1, "$set" : { "title" : "Minion" } }, "o2" : { "_id" : ObjectId("641c3b0b6eddc54ce4f75dfb") }, "ts" : Timestamp(1679571914, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T11:45:14.026Z") }<br>{ "op" : "d", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c3b0b6eddc54ce4f75dfb") }, "ts" : Timestamp(1679573573, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T12:12:53.817Z") }<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c42519662ff210d35343e"), "number" : 4, "title" : "Stranger things", "author" : "Graham" }, "ts" : Timestamp(1679573585, 3), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T12:13:05.567Z") }<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c433b474b755a080f10bb"), "number" : 5, "title" : "Stranger things", "author" : "Graham" }, "ts" : Timestamp(1679573819, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T12:16:59.806Z") } |
Below are the two full backups taken + incremental Oplog backup:
|
1 |
# pbm list<br>Backup snapshots:<br> 2023-03-23T11:52:05Z <logical> [restore_to_time: 2023-03-23T11:52:10Z]<br> 2023-03-23T12:14:04Z <logical> [restore_to_time: 2023-03-23T12:14:08Z]<br>PITR <off>:<br> 2023-03-23T11:52:11Z - 2023-03-23T13:06:45Z<br># |
Above, you can see the latest backup was taken till 2023-03-23T12:14:08, and incremental Oplog backup was taken till 2023-03-23T13:06:45.
Now we will drop the database:
|
1 |
rs1:PRIMARY> db.dropDatabase()<br>{<br> "dropped" : "london",<br> "ok" : 1,<br> "$clusterTime" : {<br> "clusterTime" : Timestamp(1679576445, 4),<br> "signature" : {<br> "hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),<br> "keyId" : NumberLong(0)<br> }<br> },<br> "operationTime" : Timestamp(1679576445, 4)<br>}<br>rs1:PRIMARY> Date()<br>Thu Mar 23 2023 13:00:51 GMT+0000 (UTC) |
Now we will restore the database and perform PITR using PBM:
|
1 |
# pbm restore --time="2023-03-23T13:00:44" |
Below are the logs for restore + PITR:
|
1 |
# pbm logs --tail=100 | grep -i restore<br>2023-03-23T13:07:37Z I [rs1/127.0.0.1:27017] got command pitrestore [name: 2023-03-23T13:07:37.410117048Z, point-in-time ts: 1679576444] <ts: 1679576857><br>2023-03-23T13:07:37Z I [rs1/127.0.0.1:27017] [pitrestore/2023-03-23T13:07:37.410117048Z] to time: 2023-03-23T13:00:44Z<br>2023-03-23T13:07:37Z I [rs1/127.0.0.1:27017] [pitrestore/2023-03-23T13:07:37.410117048Z] recovery started<br>2023-03-23T13:07:38Z I [rs1/127.0.0.1:27017] [pitrestore/2023-03-23T13:07:37.410117048Z] moving to state running<br>2023-03-23T13:07:41Z I [rs1/127.0.0.1:27017] [pitrestore/2023-03-23T13:07:37.410117048Z] restoring users and roles<br>2023-03-23T13:07:41Z I [rs1/127.0.0.1:27017] [pitrestore/2023-03-23T13:07:37.410117048Z] moving to state dumpDone<br>2023-03-23T13:07:43Z I [rs1/127.0.0.1:27017] [pitrestore/2023-03-23T13:07:37.410117048Z] starting oplog replay<br>2023-03-23T13:07:43Z I [rs1/127.0.0.1:27017] [pitrestore/2023-03-23T13:07:37.410117048Z] oplog replay finished on {1679576440 2}<br>2023-03-23T13:07:44Z I [rs1/127.0.0.1:27017] [pitrestore/2023-03-23T13:07:37.410117048Z] recovery successfully finished |
Below are the documents after restore + PITR via PBM:
|
1 |
rs1:PRIMARY> db.book.find()<br>{ "_id" : ObjectId("641c3b0a6eddc54ce4f75df8"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }<br>{ "_id" : ObjectId("641c3b0a6eddc54ce4f75df9"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }<br>{ "_id" : ObjectId("641c3b0a6eddc54ce4f75dfa"), "number" : 3, "title" : "2 states", "author" : "Peter" }<br>{ "_id" : ObjectId("641c42519662ff210d35343e"), "number" : 4, "title" : "Stranger things", "author" : "Graham" }<br>{ "_id" : ObjectId("641c433b474b755a080f10bb"), "number" : 5, "title" : "Stranger things", "author" : "Graham"<br>rs1:PRIMARY> |
Below are the Oplog entries after PBM restore, and we can see that PBM restored the relevant base backup first and started applying Oplog after the last op in the base backup.
|
1 |
rs1:PRIMARY> db.oplog.rs.find({ns:/^london/}).sort({$natural:-1})<br>{ "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c433b474b755a080f10bb"), "number" : 5, "title" : "Stranger things", "author" : "Graham" }, "ts" : Timestamp(1679576863, 9), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T13:07:43.222Z") }<br>{ "op" : "c", "ns" : "london.$cmd", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "commitIndexBuild" : "book", "indexBuildUUID" : UUID("c95a669a-9e62-4a59-974a-a702c52127da"), "indexes" : [ { "v" : 2, "unique" : true, "key" : { "number" : 1, "author" : 1 }, "name" : "number_1_author_1" } ] }, "ts" : Timestamp(1679576861, 8), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T13:07:41.159Z") }<br>{ "op" : "c", "ns" : "london.$cmd", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "startIndexBuild" : "book", "indexBuildUUID" : UUID("c95a669a-9e62-4a59-974a-a702c52127da"), "indexes" : [ { "v" : 2, "unique" : true, "key" : { "number" : 1, "author" : 1 }, "name" : "number_1_author_1" } ] }, "ts" : Timestamp(1679576861, 6), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T13:07:41.152Z") }<br>{ "lsid" : { "id" : UUID("6ec94b0c-098b-4986-a971-078c36761cf5"), "uid" : BinData(0,"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=") }, "txnNumber" : NumberLong(3), "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c42519662ff210d35343e"), "number" : 4, "title" : "Stranger things", "author" : "Graham" }, "ts" : Timestamp(1679576861, 4), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T13:07:41.006Z"), "stmtId" : 3, "prevOpTime" : { "ts" : Timestamp(1679576861, 3), "t" : NumberLong(1) } }<br>{ "lsid" : { "id" : UUID("6ec94b0c-098b-4986-a971-078c36761cf5"), "uid" : BinData(0,"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=") }, "txnNumber" : NumberLong(3), "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c3b0a6eddc54ce4f75dfa"), "number" : 3, "title" : "2 states", "author" : "Peter" }, "ts" : Timestamp(1679576861, 3), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T13:07:41.006Z"), "stmtId" : 2, "prevOpTime" : { "ts" : Timestamp(1679576861, 2), "t" : NumberLong(1) } }<br>{ "lsid" : { "id" : UUID("6ec94b0c-098b-4986-a971-078c36761cf5"), "uid" : BinData(0,"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=") }, "txnNumber" : NumberLong(3), "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c3b0a6eddc54ce4f75df9"), "number" : 2, "title" : "game of thrones", "author" : "chetan" }, "ts" : Timestamp(1679576861, 2), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T13:07:41.006Z"), "stmtId" : 1, "prevOpTime" : { "ts" : Timestamp(1679576861, 1), "t" : NumberLong(1) } }<br>{ "lsid" : { "id" : UUID("6ec94b0c-098b-4986-a971-078c36761cf5"), "uid" : BinData(0,"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=") }, "txnNumber" : NumberLong(3), "op" : "i", "ns" : "london.book", "ui" : UUID("5959bd53-6986-4d0d-a72a-9fac81113934"), "o" : { "_id" : ObjectId("641c3b0a6eddc54ce4f75df8"), "number" : 1, "title" : "harry potter", "author" : "shakespear" }, "ts" : Timestamp(1679576861, 1), "t" : NumberLong(1), "v" : NumberLong(2), "wall" : ISODate("2023-03-23T13:07:41.006Z"), "stmtId" : 0, "prevOpTime" : { "ts" : Timestamp(0, 0), "t" : NumberLong(-1) } } |
Above, you can see that PBM has applied the latest backup and performed the PITR automatically. The reason that we didn’t face the ‘E11000 duplicate key error‘ during PITR using PBM is that PBM handles it automatically, from which Oplog entry it needs to apply the ops after the restore from a full backup. PBM will ensure consistency while restoring a full backup + incremental Oplog backup.
Here’s how Percona Backup for MongoDB works.
So above, we can see how to avoid the ‘E11000 duplicate key error’ using PBM automatically. Another way is also possible, as explained above, but that will require a manual process. Why go with a manual process when PBM is open source, does not require any license, and can handle it automatically?
Please check out our products for Percona Server for MongoDB, Percona Backup for MongoDB, and Percona Operator for MongoDB. We also recommend checking out our blog MongoDB: Why Pay for Enterprise When Open Source Has You Covered?
Percona Distribution for MongoDB is a freely available MongoDB database alternative, giving you a single solution that combines the best and most important enterprise components from the open source community, designed and tested to work together.
Resources
RELATED POSTS
