Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-61790

Inserting to custom collection in "local" database on secondary yields writeConcernError with PrimarySteppedDown(189)

    • Type: Icon: Bug Bug
    • Resolution: Gone away
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 5.0.0
    • Component/s: None
    • None
    • ALL
    • Replication 2022-01-10, Replication 2022-01-24, Replication 2022-02-07, Repl 2022-02-21, Repl 2022-03-07, Repl 2022-03-21, Repl 2022-04-04

      I assume this is related to the implicit default write concern in MongoDB 5.0+, despite the docs saying that write concerns will be ignored for the "local" database.

      Consider the following mongo shell session, from a direct connection to a secondary member within a three-member replica set (no arbiter).

      MongoDB Enterprise repl0:SECONDARY> rs.status()
      {
      	"set" : "repl0",
      	"date" : ISODate("2021-11-29T23:58:43.564Z"),
      	"myState" : 2,
      	"term" : NumberLong(3),
      	"syncSourceHost" : "localhost:27018",
      	"syncSourceId" : 1,
      	"heartbeatIntervalMillis" : NumberLong(2000),
      	"majorityVoteCount" : 2,
      	"writeMajorityCount" : 2,
      	"votingMembersCount" : 3,
      	"writableVotingMembersCount" : 3,
      	"optimes" : {
      		"lastCommittedOpTime" : {
      			"ts" : Timestamp(1638230323, 1),
      			"t" : NumberLong(3)
      		},
      		"lastCommittedWallTime" : ISODate("2021-11-29T23:58:43.279Z"),
      		"readConcernMajorityOpTime" : {
      			"ts" : Timestamp(1638230323, 1),
      			"t" : NumberLong(3)
      		},
      		"appliedOpTime" : {
      			"ts" : Timestamp(1638230323, 1),
      			"t" : NumberLong(3)
      		},
      		"durableOpTime" : {
      			"ts" : Timestamp(1638230323, 1),
      			"t" : NumberLong(3)
      		},
      		"lastAppliedWallTime" : ISODate("2021-11-29T23:58:43.279Z"),
      		"lastDurableWallTime" : ISODate("2021-11-29T23:58:43.279Z")
      	},
      	"lastStableRecoveryTimestamp" : Timestamp(1638230271, 1),
      	"members" : [
      		{
      			"_id" : 0,
      			"name" : "localhost:27017",
      			"health" : 1,
      			"state" : 1,
      			"stateStr" : "PRIMARY",
      			"uptime" : 2813,
      			"optime" : {
      				"ts" : Timestamp(1638230322, 1),
      				"t" : NumberLong(3)
      			},
      			"optimeDurable" : {
      				"ts" : Timestamp(1638230322, 1),
      				"t" : NumberLong(3)
      			},
      			"optimeDate" : ISODate("2021-11-29T23:58:42Z"),
      			"optimeDurableDate" : ISODate("2021-11-29T23:58:42Z"),
      			"lastHeartbeat" : ISODate("2021-11-29T23:58:42.808Z"),
      			"lastHeartbeatRecv" : ISODate("2021-11-29T23:58:42.873Z"),
      			"pingMs" : NumberLong(0),
      			"lastHeartbeatMessage" : "",
      			"syncSourceHost" : "",
      			"syncSourceId" : -1,
      			"infoMessage" : "",
      			"electionTime" : Timestamp(1638227503, 1),
      			"electionDate" : ISODate("2021-11-29T23:11:43Z"),
      			"configVersion" : 1,
      			"configTerm" : 3
      		},
      		{
      			"_id" : 1,
      			"name" : "localhost:27018",
      			"health" : 1,
      			"state" : 2,
      			"stateStr" : "SECONDARY",
      			"uptime" : 2813,
      			"optime" : {
      				"ts" : Timestamp(1638230322, 1),
      				"t" : NumberLong(3)
      			},
      			"optimeDurable" : {
      				"ts" : Timestamp(1638230322, 1),
      				"t" : NumberLong(3)
      			},
      			"optimeDate" : ISODate("2021-11-29T23:58:42Z"),
      			"optimeDurableDate" : ISODate("2021-11-29T23:58:42Z"),
      			"lastHeartbeat" : ISODate("2021-11-29T23:58:42.808Z"),
      			"lastHeartbeatRecv" : ISODate("2021-11-29T23:58:43.417Z"),
      			"pingMs" : NumberLong(0),
      			"lastHeartbeatMessage" : "",
      			"syncSourceHost" : "localhost:27017",
      			"syncSourceId" : 0,
      			"infoMessage" : "",
      			"configVersion" : 1,
      			"configTerm" : 3
      		},
      		{
      			"_id" : 2,
      			"name" : "localhost:27019",
      			"health" : 1,
      			"state" : 2,
      			"stateStr" : "SECONDARY",
      			"uptime" : 2814,
      			"optime" : {
      				"ts" : Timestamp(1638230323, 1),
      				"t" : NumberLong(3)
      			},
      			"optimeDate" : ISODate("2021-11-29T23:58:43Z"),
      			"syncSourceHost" : "localhost:27018",
      			"syncSourceId" : 1,
      			"infoMessage" : "",
      			"configVersion" : 1,
      			"configTerm" : 3,
      			"self" : true,
      			"lastHeartbeatMessage" : ""
      		}
      	],
      	"ok" : 1,
      	"$clusterTime" : {
      		"clusterTime" : Timestamp(1638230323, 1),
      		"signature" : {
      			"hash" : BinData(0,"klt6L8rDyJJW2C/QLGz//VJelBE="),
      			"keyId" : NumberLong("7036133351224246275")
      		}
      	},
      	"operationTime" : Timestamp(1638230323, 1)
      }
      MongoDB Enterprise repl0:SECONDARY> use local
      switched to db local
      MongoDB Enterprise repl0:SECONDARY> db.foo.insert({x:1})
      WriteResult({
      	"nInserted" : 1,
      	"writeConcernError" : {
      		"code" : 189,
      		"codeName" : "PrimarySteppedDown",
      		"errmsg" : "Primary stepped down while waiting for replication",
      		"errInfo" : {
      			"writeConcern" : {
      				"w" : "majority",
      				"wtimeout" : 0,
      				"provenance" : "implicitDefault"
      			}
      		}
      	}
      })
      

            Assignee:
            vesselina.ratcheva@mongodb.com Vesselina Ratcheva (Inactive)
            Reporter:
            jmikola@mongodb.com Jeremy Mikola
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

              Created:
              Updated:
              Resolved: