Receiving Invariant failure for "Impossible Optime Received" Mongo 3.6 Arbiter

Ops and Admin
1

Hello,

We have a 3 node PSA deployment that is currently running MongoDB 3.6. They are all RHEL 7.9 Virtual Machines.

Historically, we have not had any issues with this setup but recently the mongod service on our Arbiter has been crashing and giving us this error:

2023-01-18T04:58:12.204-0500 F -        [replexec-200] Invariant failure opTime.getTimestamp().getInc() > 0 Impossible optime received: { ts: Timestamp(1674035892, 0), t: 252 } src/mongo/db/repl/replication_coordinator_impl.cpp 1213
2023-01-18T04:58:12.204-0500 F -        [replexec-200] \n\n***aborting after invariant() failure\n\n
2023-01-18T04:58:12.375-0500 F -        [replexec-200] Got signal: 6 (Aborted).

The mongod service is able to be immediately restarted after the crash, but will crash again as early as two days later.

I am not experienced with MongoDB, and have been trying to do some research here and on the main MongoDB support. However, I have not seen any mention of this specific Invariant failure.

Currently, we are having issues authenticating to the DB on the Arbiter to provide any rs.status() or rs.conf() outputs, but we are able to authenticate to the DB on our test environment and see that information there if it is needed.

I have read posts about the concerns of Arbiters and certain benefits of HA that are impeded with the Arbiter implementation, but unfortunately I was not with the company when the decision was made to add the Arbiter. Furthermore, the Primary and Secondary nodes are managed by a Third Party company that maintains their bespoke application running on the nodes. Understandably this adds complexity and leads to why we are still on an older version of MongoDB.

Additional information in the Log File after crash/service restart:

2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] ** WARNING: This replica set node is running without journaling enabled but the
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] **          writeConcernMajorityJournalDefault option to the replica set config
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] **          is set to true. The writeConcernMajorityJournalDefault
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] **          option to the replica set config must be set to false
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] **          or w:majority write concerns will never complete.
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] **          In addition, this node's memory consumption may increase until all
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] **          available free RAM is exhausted.
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0]
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] New replica set config in use: { _id: "<rsName>", version: 489159, protocolVersion: 1, members: [ { _id: 1, host: "node2:27017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.0, tags: {}, slaveDelay: 0, votes: 1 }, { _id: 2, host: "node1:27017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 2.0, tags: {}, slaveDelay: 0, votes: 1 }, { _id: 3, host: "node3:27017", arbiterOnly: true, buildIndexes: true, hidden: false, priority: 0.0, tags: {}, slaveDelay: 0, votes: 1 } ], settings: { chainingAllowed: true, heartbeatIntervalMillis: 2000, heartbeatTimeoutSecs: 10, electionTimeoutMillis: 10000, catchUpTimeoutMillis: 60000, catchUpTakeoverDelayMillis: 30000, getLastErrorModes: {}, getLastErrorDefaults: { w: 1, wtimeout: 0 }, replicaSetId: ObjectId('59c5a4175d7da122417038c8') } }
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] This node is node3.mfps.com:27017 in the config
2023-01-18T06:20:02.305-0500 I REPL     [replexec-0] transition to ARBITER from STARTUP
2023-01-18T06:20:02.320-0500 I REPL     [replexec-0] Member node2:27017 is now in state SECONDARY
2023-01-18T06:20:02.332-0500 I REPL     [replexec-1] Member node1:27017 is now in state PRIMARY

I also saw in the documentation regarding MajorityReadConcern being enabled in a PSA architecture leading to performance issues, but I am not sure if that applies here. I can confirm that on Node1 and Node2, enableMajorityReadConcern is set to true in mongod.conf while Node3 is set to false. We have also not seen any evidence of the RAM being exhausted leading up to this crash as cautioned in the log above.

Any further guidance on where to troubleshoot this issue would be greatly appreciated. Thank you to anyone who takes time to read this.

3

Hey @ddonzella,

Welcome to the MongoDB Community Forums! :leaves:

The error message

Invariant failure opTime.getTimestamp().getInc() > 0 Impossible optime received: { ts: Timestamp([1674035892](tel:1674035892), 0), t: 252 }

suggests that there is an issue with the replication process between the nodes in the replica set. The fact that the mongod service on the Arbiter node is crashing and giving this error indicates that there may be a problem with the way the Arbiter is configured or communicating with the other nodes in the replica set. It may be necessary to engage with the third-party company that is managing the Primary and Secondary nodes to ensure that they are properly configured and communicating with the Arbiter. They may also have more insight into the specific configuration of the replica set and any recent changes that may have caused the issue.

Also, the warning message

WARNING: This replica set node is running without journaling enabled but the writeConcernMajorityJournalDefault option to the replica set config is set to true

indicates that the replica set is not configured correctly, which can cause issues with the ability to complete write concerns with the majority of the nodes in the replica set. It is recommended you enable journaling and set writeConcernMajorityJournalDefault to false for your replica set, as it will prevent the warning that you’re seeing and it’s a best practice in MongoDB to have journaling enabled for replica sets. You can read more about setting up and managing journaling here: Journaling

Please let us know if this helps or not. Feel free to reach out for anything else as well.

Regards,
Satyam

2 Likes
4

Hello @Satyam,

Thank you so much for replying. I will reach out to our third-party about the journaling and see what they say about any communication errors.

As of now, our mongod service on the Arbiter has been running for 7 days without crashing or seeing that error.

I will do my best to give an update within reasonable time, but that is fully dependent on when I can schedule time with the other company.

Thanks again,
Derek

1 Like
5

Hello @Satyam,

I was able to meet with our partners and discuss the issue. In doing so, I dug deeper beyond timedatectl showing ntp enabled: yes and ntp synchronized: yes and found that the systems are polling our local ntp appliance at very different intervals, 128s 512s and 1024s.

Although they are all reporting the same time when entering the timedatectl command, would the interval settings be enough to throw off the opTime timestamps and produce this error?

Thanks for your help and patience,
Derek

6

Hey @ddonzella,

The intervals you mentioned should not be a cause for concern since MongoDB can tolerate date differences of up to a year. Is there anything else that your third party mentioned? Any recent changes to any nodes, any maintenance or upgrades? If not, I would suggest you upgrade your MongoDB version. Support for the 3.6 series officially ended on January 2020, and if this is a known issue, it won’t be backported to 3.6 and the solution is to upgrade to a supported version anyway. So it maybe it’s time you discuss upgrading your version if this failure continues and see if that helps.

Regards,
Satyam

2 Likes
7

@Satyam,

Unfortunately we could not find any major changes since this has been happening. I found documentation from the individual who set up the Arbiter, that is no longer with the company, that mentions the mongod service crashing during high I/O. However, we cannot find any instances of abnormal spikes of read writes to the VM or to the Database.

I will continue talking with our counterparts from the third party and see how they feel about upgrading.

Thanks again for your time, I greatly appreciate your help.

If we do find the root cause, I will be sure to come back and post it here.

Best,
Derek

1 Like