[SERVER-55278] replSetReconfig ignoring specified version in command Created: 17/Mar/21  Updated: 27/Oct/23  Resolved: 29/Mar/21

Status: Closed
Project: Core Server
Component/s: Replication
Affects Version/s: 4.4.4
Fix Version/s: None

Type: Question Priority: Major - P3
Reporter: Yuta Arai Assignee: Backlog - Replication Team
Resolution: Works as Designed Votes: 1
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: Text File libracluster0-shard-00-02-4hdny.mongodb.net_2021-03-16T20_31_09_2021-03-16T21_00_00_mongodb.log     Text File mongodb.log    
Assigned Teams:
Replication
Participants:
Case:

 Description   

There was a cluster on Atlas continuing to fail on rs.reconfig due to the version of the replSetConfig not matching what was expected. Attached mongod logs show that the reconfig command had specified version:6 yet the new config created had much larger version number being incremented by every run. Eventually the version number became too large and version field value of 2147501593 is out of range error was thrown during the reconfig.

I'm curious if this is an expected behavior or a bug in how we are handling replSetConfig versions.

{"t":{"$date":"2021-03-16T20:50:19.841+00:00"},"s":"I",  "c":"REPL",     "id":21352,   "ctx":"conn205053","msg":"replSetReconfig admin command received from client","attr":{"newConfig":{"_id":"LibraCluster0-shard-0","version":6,"members":[{"slaveDelay":0,"buildIndexes":true,"host":"libracluster0-shard-00-00-4hdny.mongodb.net:27017","priority":6.5,"votes":1,"arbiterOnly":false,"tags":{"nodeType":"ELECTABLE","provider":"AWS","region":"US_EAST_1","workloadType":"OPERATIONAL"},"_id":0,"horizons":{"PRIVATE":"libracluster0-shard-00-00-pri.4hdny.mongodb.net:27017","PUBLIC":"libracluster0-shard-00-00.4hdny.mongodb.net:27017","MESH":"libracluster0-shard-00-00.4hdny.mesh.mongodb.net:30454"},"hidden":false},{"_id":1,"hidden":false,"arbiterOnly":false,"priority":7.0,"host":"libracluster0-shard-00-01-4hdny.mongodb.net:27017","slaveDelay":0,"horizons":{"PRIVATE":"libracluster0-shard-00-01-pri.4hdny.mongodb.net:27017","PUBLIC":"libracluster0-shard-00-01.4hdny.mongodb.net:27017","MESH":"libracluster0-shard-00-01.4hdny.mesh.mongodb.net:30454"},"tags":{"provider":"AWS","region":"US_EAST_1","workloadType":"OPERATIONAL","nodeType":"ELECTABLE"},"buildIndexes":true,"votes":1},{"tags":{"nodeType":"ELECTABLE","provider":"AWS","region":"US_EAST_1","workloadType":"OPERATIONAL"},"hidden":false,"horizons":{"MESH":"libracluster0-shard-00-02.4hdny.mesh.mongodb.net:30454","PRIVATE":"libracluster0-shard-00-02-pri.4hdny.mongodb.net:27017","PUBLIC":"libracluster0-shard-00-02.4hdny.mongodb.net:27017"},"_id":2,"votes":1,"arbiterOnly":false,"buildIndexes":true,"slaveDelay":0,"host":"libracluster0-shard-00-02-4hdny.mongodb.net:27017","priority":7.0}],"settings":{"replicaSetId":{"$oid":"604fda5b42a6090a243ffdaa"},"heartbeatTimeoutSecs":10,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0},"catchUpTimeoutMillis":-1,"chainingAllowed":false,"electionTimeoutMillis":10000.0,"catchUpTakeoverDelayMillis":30000,"heartbeatIntervalMillis":2000},"protocolVersion":1}}}
{"t":{"$date":"2021-03-16T20:50:20.053+00:00"},"s":"I",  "c":"NETWORK",  "id":22943,   "ctx":"listener","msg":"Connection accepted","attr":{"remote":"192.168.248.67:36324","connectionId":205110,"connectionCount":41}}
{"t":{"$date":"2021-03-16T20:50:20.088+00:00"},"s":"I",  "c":"REPL",     "id":21353,   "ctx":"conn205053","msg":"replSetReconfig config object parses ok","attr":{"numMembers":3}}
{"t":{"$date":"2021-03-16T20:50:20.088+00:00"},"s":"I",  "c":"REPL",     "id":51814,   "ctx":"conn205053","msg":"Persisting new config to disk"}
{"t":{"$date":"2021-03-16T20:50:20.091+00:00"},"s":"I",  "c":"REPL",     "id":21392,   "ctx":"conn205053","msg":"New replica set config in use","attr":{"config":{"_id":"LibraCluster0-shard-0","version":811109984,"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"members":[{"_id":0,"host":"libracluster0-shard-00-00-4hdny.mongodb.net:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":6.5,"tags":{"nodeType":"ELECTABLE","provider":"AWS","region":"US_EAST_1","workloadType":"OPERATIONAL"},"horizons":{"MESH":"libracluster0-shard-00-00.4hdny.mesh.mongodb.net:30454","PRIVATE":"libracluster0-shard-00-00-pri.4hdny.mongodb.net:27017","PUBLIC":"libracluster0-shard-00-00.4hdny.mongodb.net:27017"},"slaveDelay":0,"votes":1},{"_id":1,"host":"libracluster0-shard-00-01-4hdny.mongodb.net:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":7.0,"tags":{"provider":"AWS","region":"US_EAST_1","workloadType":"OPERATIONAL","nodeType":"ELECTABLE"},"horizons":{"MESH":"libracluster0-shard-00-01.4hdny.mesh.mongodb.net:30454","PUBLIC":"libracluster0-shard-00-01.4hdny.mongodb.net:27017","PRIVATE":"libracluster0-shard-00-01-pri.4hdny.mongodb.net:27017"},"slaveDelay":0,"votes":1},{"_id":2,"host":"libracluster0-shard-00-02-4hdny.mongodb.net:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":7.0,"tags":{"nodeType":"ELECTABLE","provider":"AWS","region":"US_EAST_1","workloadType":"OPERATIONAL"},"horizons":{"PUBLIC":"libracluster0-shard-00-02.4hdny.mongodb.net:27017","PRIVATE":"libracluster0-shard-00-02-pri.4hdny.mongodb.net:27017","MESH":"libracluster0-shard-00-02.4hdny.mesh.mongodb.net:30454"},"slaveDelay":0,"votes":1}],"settings":{"chainingAllowed":false,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0},"replicaSetId":{"$oid":"604fda5b42a6090a243ffdaa"}}}}}

Out of range:

{"t":{"$date":"2021-03-17T19:55:00.542+00:00"},"s":"E",  "c":"REPL",     "id":21420,   "ctx":"conn266426","msg":"replSetReconfig error while validating new config","attr":{"error":{"code":2,"codeName":"BadValue","errmsg":"version field value of 2147511677 is out of range"},"newConfig":{"_id":"LibraCluster0-shard-0","version":2147511677,"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"members":[{"_id":0,"host":"libracluster0-shard-00-00-4hdny.mongodb.net:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":6.5,"tags":{"provider":"AWS","region":"US_EAST_1","workloadType":"OPERATIONAL","nodeType":"ELECTABLE"},"horizons":{"MESH":"libracluster0-shard-00-00.4hdny.mesh.mongodb.net:30454","PUBLIC":"libracluster0-shard-00-00.4hdny.mongodb.net:27017","PRIVATE":"libracluster0-shard-00-00-pri.4hdny.mongodb.net:27017"},"slaveDelay":0,"votes":1},{"_id":1,"host":"libracluster0-shard-00-01-4hdny.mongodb.net:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":7.0,"tags":{"nodeType":"ELECTABLE","provider":"AWS","region":"US_EAST_1","workloadType":"OPERATIONAL"},"horizons":{"MESH":"libracluster0-shard-00-01.4hdny.mesh.mongodb.net:30454","PUBLIC":"libracluster0-shard-00-01.4hdny.mongodb.net:27017","PRIVATE":"libracluster0-shard-00-01-pri.4hdny.mongodb.net:27017"},"slaveDelay":0,"votes":1},{"_id":2,"host":"libracluster0-shard-00-02-4hdny.mongodb.net:27017","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":7.0,"tags":{"nodeType":"ELECTABLE","provider":"AWS","region":"US_EAST_1","workloadType":"OPERATIONAL"},"horizons":{"MESH":"libracluster0-shard-00-02.4hdny.mesh.mongodb.net:30454","PUBLIC":"libracluster0-shard-00-02.4hdny.mongodb.net:27017","PRIVATE":"libracluster0-shard-00-02-pri.4hdny.mongodb.net:27017"},"slaveDelay":0,"votes":1}],"settings":{"chainingAllowed":false,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0},"replicaSetId":{"$oid":"604fda5b42a6090a243ffdaa"}}}}}



 Comments   
Comment by Yuta Arai [ 29/Mar/21 ]

This can be closed as "Works as Designed", thanks!

Comment by Judah Schvimer [ 19/Mar/21 ]

Is there further work to be done on this ticket, or can I close it "Works as Designed"?

Comment by Yuta Arai [ 18/Mar/21 ]

Ah that would make sense, the reconfig command being run (pasted below) did have a "force: true" flag set. Thanks for the help!

 

{replSetReconfig map[_id:LibraCluster0-shard-0 members:[map[_id:0 arbiterOnly:false buildIndexes:true hidden:false horizons:map[MESH:libracluster0-shard-00-00.4hdny.mesh.mongodb.net:30454 PRIVATE:libracluster0-shard-00-00-pri.4hdny.mongodb.net:27017 PUBLIC:libracluster0-shard-00-00.4hdny.mongodb.net:27017] host:libracluster0-shard-00-00-4hdny.mongodb.net:27017 priority:6.5 slaveDelay:0 tags:map[nodeType:ELECTABLE provider:AWS region:US_EAST_1 workloadType:OPERATIONAL] votes:1] map[_id:1 arbiterOnly:false buildIndexes:true hidden:false horizons:map[MESH:libracluster0-shard-00-01.4hdny.mesh.mongodb.net:30454 PRIVATE:libracluster0-shard-00-01-pri.4hdny.mongodb.net:27017 PUBLIC:libracluster0-shard-00-01.4hdny.mongodb.net:27017] host:libracluster0-shard-00-01-4hdny.mongodb.net:27017 priority:7 slaveDelay:0 tags:map[nodeType:ELECTABLE provider:AWS region:US_EAST_1 workloadType:OPERATIONAL] votes:1] map[_id:2 arbiterOnly:false buildIndexes:true hidden:false horizons:map[MESH:libracluster0-shard-00-02.4hdny.mesh.mongodb.net:30454 PRIVATE:libracluster0-shard-00-02-pri.4hdny.mongodb.net:27017 PUBLIC:libracluster0-shard-00-02.4hdny.mongodb.net:27017] host:libracluster0-shard-00-02-4hdny.mongodb.net:27017 priority:7 slaveDelay:0 tags:map[nodeType:ELECTABLE provider:AWS region:US_EAST_1 workloadType:OPERATIONAL] votes:1]] protocolVersion:1 settings:map[catchUpTakeoverDelayMillis:30000 catchUpTimeoutMillis:-1 chainingAllowed:false electionTimeoutMillis:10000 getLastErrorDefaults:map[w:1 wtimeout:0] getLastErrorModes:map[] heartbeatIntervalMillis:2000 heartbeatTimeoutSecs:10 replicaSetId:ObjectID("604fda5b42a6090a243ffdaa")] version:6]} {force true}

Comment by Judah Schvimer [ 18/Mar/21 ]

Hi yuta.arai,

Thanks for bringing this to our attention! Do you know the exact replSetReconfig command the user ran? Reconfigs with "force: true" will bump the version number by an arbitrary large number. If the user specified "force: true" in the command, then the large version number would be expected behavior.

Generated at Thu Feb 08 05:36:01 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.