Introduction and format analysis of oplog in mongodb

Time:2022-3-14

1. Basic concepts

Oplog uses a fixed size set to record the operation logs of all modification operations in the database (add, modify and delete, no query). After mongodb receives the modification request, it first executes the request at the primary node, and then saves the operation log to the oplog table. Other nodes pull oplog from the secondary node to the primary node and apply these operations in the asynchronous process, So as to achieve the consistency of master-slave data. All nodes in the replication group will save an oplog (set name local. Oplog. RS), which allows them to maintain the same database state.

In order to improve synchronization efficiency, all replication group members will send keep alive messages (pings) to other members. Any slave node can synchronize oplog from other member nodes (that is, it can synchronize from the master node or slave node). The result of the oplog operation is the same as that of the oplog operation in the database.

The schematic diagram of master-slave synchronization is as follows (the client writes data to the master node, and the slave node synchronizes oplog from the master node and applies it to this node):

2. Default storage size of oplog

When you start the replication group node for the first time, mongodb will use the default size to create the oplog when you do not specify the oplog size.

For UNIX and windows systems, the correspondence between the default size and the storage engine is as follows:

Storage engine type Oplog size lower limit upper limit
Memory 5% of physical memory 50MB 50GB
WiredTiger 5% of free disk 990MB 50GB 

(note that the latest version 4.4 of mongodb removes support for MMAP type storage engines.)

For 64 bit maxos system, the default size is 192mb (physical memory or disk space) by referring to the type of storage engine used, as follows:

Storage engine type Oplog size
Memory 192mb physical memory
WiredTiger 192mb of disk space

In most cases, the default size of oplog is sufficient. For example, if 5% of the disk space stores the operation logs of the last 24 hours, if the log synchronization time difference of a slave node exceeds 24 hours, the slave node will stop synchronizing oplog and switch its state from “secondary” to “state”. Of course, in the actual running environment, the load of most replication group members will be lower, and their oplog will hold logs for a longer period of time.

3. You may need a larger workload of oplog

If you predict that the workload of your replication group belongs to the following mode, you need to create a larger oplog than the default value. On the contrary, if your application is mostly read and only a small number of write operations, a smaller oplog is also required.

The following workloads may require a larger oplog

A single operation will update multiple records

In order to meet the idempotency of oplog, mongodb will record multiple operation logs into oplog when updating multiple records in a single operation. This scenario requires a lot of oplog space, although the data size or disk size does not increase so much at this time.

When there are as many delete operations as insert operations

If the number of delete requests and insert requests is roughly the same, the database will not increase significantly in disk space consumption, but the size of the operation log will be very huge.

Significant number of original document updates

If most of the workload operations are original file updates, the number of documents in the database will not be increased, but the database needs to record a large number of operation logs.

4. Oplog status

If you want to view the status of oplog, including the number of records and time range, you can use the command “rs.printreplicationinfo()”, as follows:

MongoDB Enterprise repa:PRIMARY> rs.printReplicationInfo()
Configured oplog size: 1024MB // the oplog size is 1024MB
Log length start to end: 867353secs (240.93hrs) // the time difference between the first log and the last log is 240.93 hours
oplog first event time:  Wed Jul 07 2021 20:24:57 GMT+0800
oplog last event time:   Sat Jul 17 2021 21:20:50 GMT+0800
now:                     Sat Jul 17 2021 21:20:56 GMT+0800

5. Oplog format

From the above, we know that oplog is stored in the database local, and the table name is “oplog. RS”. See the data format of oplog through the query command:

db. oplog. rs.find({"ns":"test.users"}). Limit (1) // the NS field indicates the query operation log on the users table in the database test
{
    "Ts": timestamp (1625660877, 2), // the operation timestamp of the log. The first number is the timestamp, in seconds, and the second number is the second operation in the current second
    "t": NumberLong(2),
    "h": NumberLong("5521980394145765083"),
    "v": 2,
    "Op": "I", // I means insert, u means update, D means delete, C means database commands, such as creating tables, n means NOOP, that is, empty operation
    "Ns": "test. Users", // namespace, that is, database and collection names
    "UI": UUID ("edabbd93-76eb-42be-b54a-cdc29eb1f267"), // client session ID connected to mongodb
    "Wall": Isodate ("2021-07-07t12:27:57.689z"), // operation execution time, UTC time
    "O": {// the content of the operation has different formats for different OP types
        "_id": ObjectId("60e59dcd46db1fb4605f8b18"),
        "name": "1"
    }
}

6. Correspondence between cud operation and oplog

When analyzing the oplog log format earlier, I checked the log corresponding to an insert operation, so I won’t repeat it. Next, I’ll look at the log format corresponding to delete and update (find will not generate oplog).

Delete operation

First insert three records:

MongoDB Enterprise repa:PRIMARY> use testswitched to db testMongoDB Enterprise repa:PRIMARY> db. users. Insert ({"name": "Zhang San", "age": numberint (10), "sex": "male"}) writeresult ({"ninserted": 1}) mongodb enterprise Rep: primary > dB users. Insert ({"name": "Li Si", "age": numberint (11), "sex": "male"}) writeresult ({"ninserted": 1}) mongodb enterprise Rep: primary > dB users. Insert ({"name": "Wang Wu", "age": numberint (12), "sex": "male"}) writeresult ({"ninserted": 1}) mongodb enterprise Rep: primary > dB users. Find() {"_id": objectid ("60f2e11b0d98dc3b374199de"), "name": "Zhang San", "age": 10, "sex": "male"} {"_id": objectid ("60f2e11e0d98dc3b374199df"), "name": "Li Si", "age": 11, "sex": "male"} {"_id": objectid ("60f2e11e0d98dc3b374199e0"), "name": "Wang Wu", "age": 12, "sex": "male"}

Execute the delete operation. The matching condition is {“sex”: “male”}, that is, delete all records with male gender:

MongoDB Enterprise repa:PRIMARY> db. users. Remove ({"sex": "male"})
WriteResult({ "nRemoved" : 3 })
MongoDB Enterprise repa:PRIMARY> db.users.find()
MongoDB Enterprise repa:PRIMARY>

You can see that one delete command deletes three records. What is the corresponding oplog? Let’s check:


MongoDB Enterprise repa:PRIMARY> use local
switched to db local
MongoDB Enterprise repa:PRIMARY> db.oplog.rs.find({"ns":"test.users","op":"d","wall":{"$gt":ISODate("2021-07-17T13:50:57.689Z")}})
{ "ts" : Timestamp(1626530154, 1), "t" : NumberLong(2), "h" : NumberLong("5834731856459959506"), "v" : 2, "op" : "d", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "wall" : ISODate("2021-07-17T13:55:54.424Z"), "o" : { "_id" : ObjectId("60f2e11b0d98dc3b374199de") } }
{ "ts" : Timestamp(1626530154, 2), "t" : NumberLong(2), "h" : NumberLong("-2164276082472824844"), "v" : 2, "op" : "d", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "wall" : ISODate("2021-07-17T13:55:54.424Z"), "o" : { "_id" : ObjectId("60f2e11e0d98dc3b374199df") } }
{ "ts" : Timestamp(1626530154, 3), "t" : NumberLong(2), "h" : NumberLong("3834858247238363179"), "v" : 2, "op" : "d", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "wall" : ISODate("2021-07-17T13:55:54.424Z"), "o" : { "_id" : ObjectId("60f2e11e0d98dc3b374199e0") } }
MongoDB Enterprise repa:PRIMARY>

It can be seen from the above that a delete command records three logs in oplog. Here is an analysis of one of them:

{
    "ts": Timestamp(1626530154, 1),
    "t": NumberLong(2),
    "h": NumberLong("5834731856459959506"),
    "v": 2,
    "Op": "d", // deleting
    "Ns": "test. Users"
    "ui": UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"),
    "wall": ISODate("2021-07-17T13:55:54.424Z"),
    "O": {// the _idof the record to be deleted
        "_id": ObjectId("60f2e11b0d98dc3b374199de")
    }
}

From the log analysis, we can draw the following conclusions:

If n records are deleted in a user’s deletion request, n logs will be recorded in oplog, and the “_id” field of the record to be deleted will be recorded in the log, which is independent of the parameters of the user’s deletion request.

Update operation

Next, let’s take a look at the number and format of oplog logs corresponding to the update operation.

First insert three records:

MongoDB Enterprise repa:PRIMARY> use test
switched to db test
MongoDB Enterprise repa:PRIMARY>
MongoDB Enterprise repa:PRIMARY> db. users. Insert ({"name": "Zhang San", "age": numberint (10), "sex": "male"})
WriteResult({ "nInserted" : 1 })
MongoDB Enterprise repa:PRIMARY> db. users. Insert ({"name": "Li Si", "age": numberint (11), "sex": "male"})
WriteResult({ "nInserted" : 1 })
MongoDB Enterprise repa:PRIMARY> db. users. Insert ({"name": "Wang Wu", "age": numberint (12), "sex": "male"})
WriteResult({ "nInserted" : 1 })
MongoDB Enterprise repa:PRIMARY> db.users.find()
{"_id": objectid ("60f2e2db0d98dc3b374199e1"), "name": "Zhang San", "age": 10, "sex": "male"}
{"_id": objectid ("60f2e2db0d98dc3b374199e2"), "name": "Li Si", "age": 11, "sex": "male"}
{"_id": objectid ("60f2e2dc0d98dc3b374199e3"), "name": "Wang Wu", "age": 12, "sex": "male"}

Perform the update operation again:

MongoDB Enterprise repa:PRIMARY> db. users. Update ({"sex": "male"}, {"$Inc": {"age": numberint (1)}}, false, true)
WriteResult({ "nMatched" : 3, "nUpserted" : 0, "nModified" : 3 })
MongoDB Enterprise repa:PRIMARY> db.users.find()                                                          
{"_id": objectid ("60f2e2db0d98dc3b374199e1"), "name": "Zhang San", "age": 11, "sex": "male"}
{"_id": objectid ("60f2e2db0d98dc3b374199e2"), "name": "Li Si", "age": 12, "sex": "male"}
{"_id": objectid ("60f2e2dc0d98dc3b374199e3"), "name": "Wang Wu", "age": 13, "sex": "male"}

It can be seen from the returned results that the update operation was successfully executed and three records were updated. Here is the log of oplog:


MongoDB Enterprise repa:PRIMARY> use local
switched to db local
MongoDB Enterprise repa:PRIMARY> db.oplog.rs.find({"ns":"test.users","op":"u","wall":{"$gt":ISODate("2021-07-17T13:50:57.689Z")}})
{ "ts" : Timestamp(1626530575, 1), "t" : NumberLong(2), "h" : NumberLong("-6359278368726841648"), "v" : 2, "op" : "u", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "o2" : { "_id" : ObjectId("60f2e2db0d98dc3b374199e1") }, "wall" : ISODate("2021-07-17T14:02:55.319Z"), "o" : { "$v" : 1, "$set" : { "age" : 11 } } }
{ "ts" : Timestamp(1626530575, 2), "t" : NumberLong(2), "h" : NumberLong("-4351658862590633053"), "v" : 2, "op" : "u", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "o2" : { "_id" : ObjectId("60f2e2db0d98dc3b374199e2") }, "wall" : ISODate("2021-07-17T14:02:55.319Z"), "o" : { "$v" : 1, "$set" : { "age" : 12 } } }
{ "ts" : Timestamp(1626530575, 3), "t" : NumberLong(2), "h" : NumberLong("5911110003695351597"), "v" : 2, "op" : "u", "ns" : "test.users", "ui" : UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"), "o2" : { "_id" : ObjectId("60f2e2dc0d98dc3b374199e3") }, "wall" : ISODate("2021-07-17T14:02:55.319Z"), "o" : { "$v" : 1, "$set" : { "age" : 13 } } }

Similar to delete, the update operation also generates three logs. Select the first one for analysis:

{
    "ts": Timestamp(1626530575, 1),
    "t": NumberLong(2),
    "h": NumberLong("-6359278368726841648"),
    "v": 2,
    "Op": "U", // update operation
    "Ns": "test. Users"
    "ui": UUID("edabbd93-76eb-42be-b54a-cdc29eb1f267"),
    "O2": {// query criteria for update operations, using the _idof the record
        "_id": ObjectId("60f2e2db0d98dc3b374199e1")
    },
    "wall": ISODate("2021-07-17T14:02:55.319Z"),
    "O": {// update the content of the update operation. The original Inc operator is transformed into a set operator, which can satisfy idempotency
        "$v": 1,
        "$set": {
            "age": 11
        }
    }
}

From the log analysis, we can draw the following conclusions:

If n records are updated in a user’s update request, n logs will be recorded in oplog. The “_id” field of the record to be updated in the log is the query condition. The update operation uses the set operator, not the user’s update operator.

Summary

From the analysis of the oplog logs corresponding to the delete and update operations above, it can be seen that oplog records not the original commands of the user, but the corresponding logical commands. In this way, the idempotency of oplog can be met, but the problem that a large number of oplog records may be generated will also be derived. The user needs to select the appropriate oplog size according to the needs of the business model.

https://github.com/tomliugen

summary

This is the end of this article about the introduction and format analysis of oplog in mongodb. For more information about mongodb oplog and format, please search the previous articles of developeppaer or continue to browse the relevant articles below. I hope you will support developeppaer in the future!