MongoDB Replica Set : Cannot use non-local read concern until replica set is finished initializing

user_17488374 0
Viewed 8350

I tried to create a replica set following instruction such as : https://hevodata.com/learn/mongodb-replica-set-3-easy-methods/

Sadly, I have a problem at the first step :

Problem

The command :

mongod --port 27017 --dbpath "C:\Program Files\MongoDB\Server\5.0\data" --replSet replicaSet1

Log file

{"t":{"$date":"2021-11-23T13:24:04.506+01:00"},"s":"I",  "c":"CONTROL",  "id":23285,   "ctx":"-","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"}
{"t":{"$date":"2021-11-23T13:24:05.247+01:00"},"s":"I",  "c":"NETWORK",  "id":4915701, "ctx":"-","msg":"Initialized wire specification","attr":{"spec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":13},"outgoing":{"minWireVersion":0,"maxWireVersion":13},"isInternalClient":true}}}
{"t":{"$date":"2021-11-23T13:24:05.250+01:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2021-11-23T13:24:05.251+01:00"},"s":"I",  "c":"NETWORK",  "id":4648602, "ctx":"main","msg":"Implicit TCP FastOpen in use."}
{"t":{"$date":"2021-11-23T13:24:05.255+01:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2021-11-23T13:24:05.258+01:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
{"t":{"$date":"2021-11-23T13:24:05.261+01:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationDonorService","ns":"config.tenantMigrationDonors"}}
{"t":{"$date":"2021-11-23T13:24:05.261+01:00"},"s":"I",  "c":"REPL",     "id":5123008, "ctx":"main","msg":"Successfully registered PrimaryOnlyService","attr":{"service":"TenantMigrationRecipientService","ns":"config.tenantMigrationRecipients"}}
{"t":{"$date":"2021-11-23T13:24:05.270+01:00"},"s":"I",  "c":"CONTROL",  "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":2852,"port":27017,"dbPath":"C:/Program Files/MongoDB/Server/5.0/data","architecture":"64-bit","host":"DQFQNH2"}}
{"t":{"$date":"2021-11-23T13:24:05.272+01:00"},"s":"I",  "c":"CONTROL",  "id":23398,   "ctx":"initandlisten","msg":"Target operating system minimum version","attr":{"targetMinOS":"Windows 7/Windows Server 2008 R2"}}
{"t":{"$date":"2021-11-23T13:24:05.272+01:00"},"s":"I",  "c":"CONTROL",  "id":23403,   "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"5.0.3","gitVersion":"657fea5a61a74d7a79df7aff8e4bcf0bc742b748","modules":[],"allocator":"tcmalloc","environment":{"distmod":"windows","distarch":"x86_64","target_arch":"x86_64"}}}}
{"t":{"$date":"2021-11-23T13:24:05.281+01:00"},"s":"I",  "c":"CONTROL",  "id":51765,   "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Microsoft Windows 10","version":"10.0 (build 18363)"}}}
{"t":{"$date":"2021-11-23T13:24:05.292+01:00"},"s":"I",  "c":"CONTROL",  "id":21951,   "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"net":{"port":27017},"replication":{"replSet":"replicaSet1"},"storage":{"dbPath":"C:\\Program Files\\MongoDB\\Server\\5.0\\data"}}}}
{"t":{"$date":"2021-11-23T13:24:05.298+01:00"},"s":"I",  "c":"STORAGE",  "id":22270,   "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"C:/Program Files/MongoDB/Server/5.0/data","storageEngine":"wiredTiger"}}
{"t":{"$date":"2021-11-23T13:24:05.298+01:00"},"s":"I",  "c":"STORAGE",  "id":22315,   "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=3525M,session_max=33000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),builtin_extension_config=(zstd=(compression_level=6)),file_manager=(close_idle_time=600,close_scan_interval=10,close_handle_minimum=250),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress,compact_progress],"}}
{"t":{"$date":"2021-11-23T13:24:05.330+01:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1637670245:330481][2852:140718885658272], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 55 through 56"}}
{"t":{"$date":"2021-11-23T13:24:05.406+01:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1637670245:405280][2852:140718885658272], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 56 through 56"}}
{"t":{"$date":"2021-11-23T13:24:05.500+01:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1637670245:500025][2852:140718885658272], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Main recovery loop: starting at 55/55552 to 56/256"}}
{"t":{"$date":"2021-11-23T13:24:05.656+01:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1637670245:656606][2852:140718885658272], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 55 through 56"}}
{"t":{"$date":"2021-11-23T13:24:05.749+01:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1637670245:748359][2852:140718885658272], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 56 through 56"}}
{"t":{"$date":"2021-11-23T13:24:05.821+01:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1637670245:821165][2852:140718885658272], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global recovery timestamp: (0, 0)"}}
{"t":{"$date":"2021-11-23T13:24:05.821+01:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1637670245:821165][2852:140718885658272], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global oldest timestamp: (0, 0)"}}
{"t":{"$date":"2021-11-23T13:24:05.826+01:00"},"s":"I",  "c":"STORAGE",  "id":22430,   "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1637670245:826155][2852:140718885658272], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1, snapshot max: 1 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 68329"}}
{"t":{"$date":"2021-11-23T13:24:05.840+01:00"},"s":"I",  "c":"STORAGE",  "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":542}}
{"t":{"$date":"2021-11-23T13:24:05.841+01:00"},"s":"I",  "c":"RECOVERY", "id":23987,   "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":0,"i":0}}}}
{"t":{"$date":"2021-11-23T13:24:05.854+01:00"},"s":"I",  "c":"STORAGE",  "id":4366408, "ctx":"initandlisten","msg":"No table logging settings modifications are required for existing WiredTiger tables","attr":{"loggingEnabled":false}}
{"t":{"$date":"2021-11-23T13:24:05.858+01:00"},"s":"I",  "c":"STORAGE",  "id":22262,   "ctx":"initandlisten","msg":"Timestamp monitor starting"}
{"t":{"$date":"2021-11-23T13:24:05.865+01:00"},"s":"W",  "c":"CONTROL",  "id":22120,   "ctx":"initandlisten","msg":"Access control is not enabled for the database. Read and write access to data and configuration is unrestricted","tags":["startupWarnings"]}
{"t":{"$date":"2021-11-23T13:24:05.866+01:00"},"s":"W",  "c":"CONTROL",  "id":22140,   "ctx":"initandlisten","msg":"This server is bound to localhost. Remote systems will be unable to connect to this server. Start the server with --bind_ip  to specify which IP addresses it should serve responses from, or with --bind_ip_all to bind to all interfaces. If this behavior is desired, start the server with --bind_ip 127.0.0.1 to disable this warning","tags":["startupWarnings"]}
{"t":{"$date":"2021-11-23T13:24:05.879+01:00"},"s":"I",  "c":"NETWORK",  "id":4915702, "ctx":"initandlisten","msg":"Updated wire specification","attr":{"oldSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":0,"maxWireVersion":13},"outgoing":{"minWireVersion":0,"maxWireVersion":13},"isInternalClient":true},"newSpec":{"incomingExternalClient":{"minWireVersion":0,"maxWireVersion":13},"incomingInternalClient":{"minWireVersion":13,"maxWireVersion":13},"outgoing":{"minWireVersion":13,"maxWireVersion":13},"isInternalClient":true}}}
{"t":{"$date":"2021-11-23T13:24:05.883+01:00"},"s":"I",  "c":"STORAGE",  "id":5071100, "ctx":"initandlisten","msg":"Clearing temp directory"}
{"t":{"$date":"2021-11-23T13:24:05.891+01:00"},"s":"I",  "c":"CONTROL",  "id":20536,   "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"}
{"t":{"$date":"2021-11-23T13:24:05.901+01:00"},"s":"I",  "c":"SHARDING", "id":20997,   "ctx":"initandlisten","msg":"Refreshed RWC defaults","attr":{"newDefaults":{}}}
{"t":{"$date":"2021-11-23T13:24:06.182+01:00"},"s":"W",  "c":"FTDC",     "id":23718,   "ctx":"initandlisten","msg":"Failed to initialize Performance Counters for FTDC","attr":{"error":{"code":179,"codeName":"WindowsPdhError","errmsg":"PdhAddEnglishCounterW failed with 'L’objet spécifié n’a pas été trouvé sur l’ordinateur.'"}}}
{"t":{"$date":"2021-11-23T13:24:06.182+01:00"},"s":"I",  "c":"FTDC",     "id":20625,   "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"C:/Program Files/MongoDB/Server/5.0/data/diagnostic.data"}}
{"t":{"$date":"2021-11-23T13:24:06.192+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"ReadConcernMajorityNotAvailableYet: Read concern majority reads are currently not possible.","nextWakeupMillis":200}}
{"t":{"$date":"2021-11-23T13:24:06.197+01:00"},"s":"I",  "c":"REPL",     "id":21311,   "ctx":"initandlisten","msg":"Did not find local initialized voted for document at startup"}
{"t":{"$date":"2021-11-23T13:24:06.200+01:00"},"s":"I",  "c":"REPL",     "id":21529,   "ctx":"initandlisten","msg":"Initializing rollback ID","attr":{"rbid":1}}
{"t":{"$date":"2021-11-23T13:24:06.200+01:00"},"s":"I",  "c":"REPL",     "id":21313,   "ctx":"initandlisten","msg":"Did not find local replica set configuration document at startup","attr":{"error":{"code":47,"codeName":"NoMatchingDocument","errmsg":"Did not find replica set configuration document in local.system.replset"}}}
{"t":{"$date":"2021-11-23T13:24:06.208+01:00"},"s":"I",  "c":"CONTROL",  "id":20714,   "ctx":"LogicalSessionCacheRefresh","msg":"Failed to refresh session cache, will try again at the next refresh interval","attr":{"error":"NotYetInitialized: Replication has not yet been configured"}}
{"t":{"$date":"2021-11-23T13:24:06.209+01:00"},"s":"I",  "c":"REPL",     "id":40440,   "ctx":"initandlisten","msg":"Starting the TopologyVersionObserver"}
{"t":{"$date":"2021-11-23T13:24:06.209+01:00"},"s":"I",  "c":"CONTROL",  "id":20711,   "ctx":"LogicalSessionCacheReap","msg":"Failed to reap transaction table","attr":{"error":"NotYetInitialized: Replication has not yet been configured"}}
{"t":{"$date":"2021-11-23T13:24:06.218+01:00"},"s":"I",  "c":"REPL",     "id":40445,   "ctx":"TopologyVersionObserver","msg":"Started TopologyVersionObserver"}
{"t":{"$date":"2021-11-23T13:24:06.219+01:00"},"s":"I",  "c":"NETWORK",  "id":23015,   "ctx":"listener","msg":"Listening on","attr":{"address":"127.0.0.1"}}
{"t":{"$date":"2021-11-23T13:24:06.219+01:00"},"s":"I",  "c":"NETWORK",  "id":23016,   "ctx":"listener","msg":"Waiting for connections","attr":{"port":27017,"ssl":"off"}}
{"t":{"$date":"2021-11-23T13:24:06.413+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":400}}
{"t":{"$date":"2021-11-23T13:24:06.844+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":600}}
{"t":{"$date":"2021-11-23T13:24:07.445+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":800}}
{"t":{"$date":"2021-11-23T13:24:08.245+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":1000}}
{"t":{"$date":"2021-11-23T13:24:09.247+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":1200}}
{"t":{"$date":"2021-11-23T13:24:10.448+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":1400}}
{"t":{"$date":"2021-11-23T13:24:11.849+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":1600}}
{"t":{"$date":"2021-11-23T13:24:13.451+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":1800}}
{"t":{"$date":"2021-11-23T13:24:15.252+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":2000}}
{"t":{"$date":"2021-11-23T13:24:17.253+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":2200}}
{"t":{"$date":"2021-11-23T13:24:19.454+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":2400}}
{"t":{"$date":"2021-11-23T13:24:21.856+01:00"},"s":"I",  "c":"-",        "id":4939300, "ctx":"monitoring-keys-for-HMAC","msg":"Failed to refresh key cache","attr":{"error":"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing.","nextWakeupMillis":2600}}

I think the problem is with the sentence :

"NotYetInitialized: Cannot use non-local read concern until replica set is finished initializing"

Any ideas on what to do here? I am on windows 10.

More info

# mongod.conf

# for documentation of all options, see:
#   http://docs.mongodb.org/manual/reference/configuration-options/

# Where and how to store data.
storage:
  dbPath: C:\Program Files\MongoDB\Server\5.0\data
  journal:
    enabled: true
#  engine:
#  wiredTiger:

# where to write logging data.
systemLog:
  destination: file
  logAppend: true
  path:  C:\Program Files\MongoDB\Server\5.0\log\mongod.log

# network interfaces
net:
  port: 27017
  bindIp: 127.0.0.1


#processManagement:

#security:

#operationProfiling:

#replication:

#sharding:

## Enterprise-Only Options:

#auditLog:

#snmp:
mongodb-replica-set replicaset mongodb
4 Answers

You need to initialize the replicaSet

$ mongo --port 27017
> rs.initiate()

Then to deploy additional members

$ mongod --port 27018 --dbpath "C:\Program Files\MongoDB\Server\5.0\data2" --replSet replicaSet1

Make sure the port & dbpath are different for each new node.

Add each new node to the replicaSet from the shell

$ mongo --port 27017
PRIMARY> rs.add("localhost:27018")
user_10158200

Well, first, I must say that Matt's answer (https://stackoverflow.com/a/71179703/1264663) gave some clues about the solution. What was missing there was a better explanation.

Yes, the thing is that the replica server itself must be initiated. The commands starting the MongoDB daemons will continue to show the error until that happens, or will eventually stop (for a timeout).

I want to make clear that this worked for me on Windows. I was following a tutorial where the instructor did the procedure on Linux, and the error didn't appear. I'm going to describe here all the steps to make more clear how to solve the problem.

As it has already been said, the port and the data folder must be different for each node.

  1. On separate command shells run every mongod command (e.g. mongod --replSet cookingSet --dbpath=c:\temp\mongodb\data\rs1 --port 27018) and let them run.
  2. On another command shell, connect to some of the daemons started in the step 1, using the MongoDB shell, like mongosh --port 27018 Note that the port must be specified, and must match one of the ports used for starting the nodes.
  3. On this shell, create a variable like
rsconfig = {
  _id: "cookingSet",
  members: [
      {_id: 0, host: "localhost:27018"},
      {_id: 1, host: "localhost:27019"},
      {_id: 2, host: "localhost:27020"}
  ]
}

where _id must be equal to the value of the parameter 'replSet' used for starting the nodes. In this case, all nodes are running in my localhost. This variable represents the configuration of the replica set.

  1. run the command rs.initiate(rsconfig)

'rsconfig' is the name of the variable created before.

  1. Verify the replica set by running rs.status() You should see the members listed in the result.

  2. Verify the error is not thrown any more. Go to some of the shells where the nodes were started and see that the error is not thrown anymore.

user_12646630

this is expected. You would have to open a new terminal while mongod daemon is running in another terminal.

And carry on with the "mongo" command to open the mongo shell.

user_176283940

I was facing this issue on windows 10. This happened because the mongodb daemon was running as a service by default. Follow these steps

  • Go to task manager and click on the services tab
  • Find mongodb service
  • right click and select stop

hopefully, this will fix the issue.

user_80499500
Related