0

I understand that some times MongoDB secondary data becomes stale at which point, we need to perform an init sync from the Primary instance.

But sometimes we see error logs that look like this:

2022-07-22T21:24:20.065+0000 I  REPL  [rsBackgroundSync] Starting rollback due to OplogStartMissing: Our last optime fetched: { ts: Timestamp(1658512549, 30), t: 57 }. source's GTE: { ts: Timestamp(1658513748, 2), t: 88 }

How is the above error message different from:

2022-08-01T02:30:21.915+0000 I  REPL     [replication-0] We are too stale to use xyz as a sync source. Blacklisting this sync source because our last fetched timestamp: Timestamp(1659314292, 1) is before their earliest timestamp: Timestamp(1659320029, 301) for 1min until: 2022-08-01T02:31:21.915+0000

I am trying to understand the difference between both of the above.

1 Answer 1

1

The first one is rolling back writes from one of the nodes.

When a secondary lost connectivity it claimed to be master and accepted some writes. The log entry says that 20 min before that the real primary accepted other writes, so the reunited secondary steps down and rolls back own writes.

The second one says the oplog size is not sufficient for such long downtime. Oplog is a capped collection. Newer writes overwrite older records. The last oplog entry on the node is Monday, 1 August 2022 00:38:12, the first oplog entry on at source is Monday, 1 August 2022 02:13:49. There is more than 1 and a half hours gap in the records, so mongo cannot reliably replay oplog.

Although you can work it around by increasing size of oplog in the config, it would make sense to address the connectivity issues. Mongo is designed to cover short network partitions, but is not as efficient with longer downtimes.

3
  • how are you calculating the timestamps. And secondly for the first error message, how did you infer that its the log of a secondary that claimed to be master and accepted writes ?
    – Vineel
    Aug 3, 2022 at 13:50
  • We had a primary (mongodb-1) that went down for couple of hours due to some host issues. And then mongodb-0 became primary and started accepting writes. Then later when mongodb-1 came back up , all the three instances kept rebooting. After some time, mongodb-1 became primary again. Now we see OplogStart Missing messages in mongodb-0 . This is the context. But I didn't understand your comment.
    – Vineel
    Aug 3, 2022 at 13:57
  • The log says there was a roll back. rollbacks happen when there are conflicting writes in the oplog. Only primary writes to oplog, which means at some point 2 nodes had connectivity to the client but couldnot talk to each other, so both step up as primaries. When replicaset connectivity restored they went through election, and the node that stepped down had to rollback its writes and report the log entry you posted. Timestamps in the log messages are in Unix Epoch format, so simple math gives you timings.
    – Alex Blex
    Aug 3, 2022 at 14:32

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.