Trouble inializing the replica set / HW-2.4

In HW-2.4, I have some trouble inializing the replica set.
While I can run this:

rs.initiate({_id: ‘HW-2.4’,
members: [
{_id:1, host: ‘database.m310.mongodb.university:31240’}
]
})

with no problem. But I get an error when I want to add the other members:

MongoDB Enterprise HW-2.4:PRIMARY>
MongoDB Enterprise HW-2.4:PRIMARY> rs.add(‘database.m310.mongodb.university:31241’)
2020-11-30T04:39:31.597+0000 E QUERY [thread1] Error: count failed: {
“ok” : 0,
“errmsg” : “not authorized on local to execute command { count: “system.replset”, query: {}, fields: {} }”,
“code” : 13
} :
_getErrorWithCode@src/mongo/shell/utils.js:25:13
DBQuery.prototype.count@src/mongo/shell/query.js:370:11
DBCollection.prototype.count@src/mongo/shell/collection.js:1713:12
rs.add@src/mongo/shell/utils.js:1163:1
@(shell):1:1

MongoDB Enterprise HW-2.4:PRIMARY>

To connect I tried both:

mongo --host database.m310.mongodb.university --ssl --sslPEMKeyFile ~/shared/certs/client.pem --sslCAFile ~/shared/certs/ca.pem --port 31240

and:

mongo --host ‘database.m310.mongodb.university:31240’ --ssl --sslPEMKeyFile ~/shared/certs/client.pem --sslCAFile ~/shared/certs/ca.pem

So I don’t really understand why there seem to be an authorization problem. But both solution failed.

For information, in case this may be useful, the result of running rs.isMaster():

MongoDB Enterprise HW-2.4:PRIMARY>
MongoDB Enterprise HW-2.4:PRIMARY> rs.isMaster()
{
“hosts” : [
“database.m310.mongodb.university:31240”
],
“setName” : “HW-2.4”,
“setVersion” : 1,
“ismaster” : true,
“secondary” : false,
“primary” : “database.m310.mongodb.university:31240”,
“me” : “database.m310.mongodb.university:31240”,
“electionId” : ObjectId(“7fffffff0000000000000001”),
“maxBsonObjectSize” : 16777216,
“maxMessageSizeBytes” : 48000000,
“maxWriteBatchSize” : 1000,
“localTime” : ISODate(“2020-11-30T04:39:14.129Z”),
“maxWireVersion” : 4,
“minWireVersion” : 0,
“ok” : 1
}
MongoDB Enterprise HW-2.4:PRIMARY>

You may be connected to local DB

Switch to admin and try

“local DB” ? Do you mean “test” ?

I have also tried:
use admin

But it didn’t make any difference.

I even created a user with the role:

	{
		"role" : "root",
		"db" : "admin"
	}

used it to authenticate and tried again. But it keeps failing.

But this time like this:

MongoDB Enterprise HW-2.4:PRIMARY> rs.add(‘database.m310.mongodb.university:31241’)
{
“ok” : 0,
“errmsg” : “Quorum check failed because not enough voting nodes responded; required 2 but only the following 1 voting nodes responded: database.m310.mongodb.university:31240; the following nodes did not respond affirmatively: database.m310.mongodb.university:31241 failed with not authorized on admin to execute command { replSetHeartbeat: “HW-2.4”, pv: 1, v: 2, from: “database.m310.mongodb.university:31240”, fromId: 1, checkEmpty: false }”,
“code” : 74
}
MongoDB Enterprise HW-2.4:PRIMARY>

This message is somewhat similar to an issue I had before, but the situation was different.

How did you start database.m310.mongodb.university:31241?

Share the output of ps -aef | grep [m]ongo.

This is the command I used to start the server on port 31241:

mongod --replSet HW-2.4 --dbpath ./r1 --logpath ./r1/mongodb.log --port 31241 --auth --fork --sslMode requireSSL --sslPEMKeyFile ~/shared/certs/server.pem --sslCAFile ~/shared/certs/ca.pem

The servers on ports 31240 and 31242 were started similarly.

And this is the result you want from the ps command:

vagrant@database:~/M310-HW-2.4$ ps -aef | grep [m]ongo
vagrant 7899 1 1 02:16 ? 00:00:01 mongod --replSet HW-2.4 --dbpath ./r0 --logpath ./r0/mongodb.log --port 31240 --auth --fork --sslMode requireSSL --sslPEMKeyFile /home/vagrant/shared/certs/server.pem --sslCAFile /home/vagrant/shared/certs/ca.pem
vagrant 7926 1 1 02:16 ? 00:00:01 mongod --replSet HW-2.4 --dbpath ./r1 --logpath ./r1/mongodb.log --port 31241 --auth --fork --sslMode requireSSL --sslPEMKeyFile /home/vagrant/shared/certs/server.pem --sslCAFile /home/vagrant/shared/certs/ca.pem
vagrant 7953 1 1 02:16 ? 00:00:01 mongod --replSet HW-2.4 --dbpath ./r2 --logpath ./r2/mongodb.log --port 31242 --auth --fork --sslMode requireSSL --sslPEMKeyFile /home/vagrant/shared/certs/server.pem --sslCAFile /home/vagrant/shared/certs/ca.pem
vagrant@database:~/M310-HW-2.4$

Now please share the content of the log files. May 20 lines of each at around the time you ran the rs.add command.

OK then after connection using:

mongo --host database.m310.mongodb.university --ssl --sslPEMKeyFile ~/shared/certs/client.pem --sslCAFile ~/shared/certs/ca.pem --port 31240

then running:

rs.initiate({_id: ‘HW-2.4’,
members: [
{_id:1, host: ‘database.m310.mongodb.university:31240’}
]
})

and:

use dbAdmin

and then:

rs.add(‘database.m310.mongodb.university:31241’)

These are the log files:

vagrant@database:~ vagrant@database:~ tail M310-HW-2.4/r0/mongodb.log
2020-12-01T03:17:17.600+0000 I REPL [ReplicationExecutor] transition to STARTUP2
2020-12-01T03:17:17.606+0000 I REPL [conn5] Starting replication applier threads
2020-12-01T03:17:17.609+0000 I REPL [ReplicationExecutor] transition to RECOVERING
2020-12-01T03:17:17.609+0000 I REPL [ReplicationExecutor] transition to SECONDARY
2020-12-01T03:17:17.609+0000 I REPL [ReplicationExecutor] conducting a dry run election to see if we could be elected
2020-12-01T03:17:17.609+0000 I REPL [ReplicationExecutor] dry election run succeeded, running for election
2020-12-01T03:17:17.616+0000 I REPL [ReplicationExecutor] election succeeded, assuming primary role in term 1
2020-12-01T03:17:17.616+0000 I REPL [ReplicationExecutor] transition to PRIMARY
2020-12-01T03:17:18.609+0000 I REPL [rsSync] transition to primary complete; database writes are now permitted
2020-12-01T03:20:36.805+0000 I ACCESS [conn5] Unauthorized: not authorized on local to execute command { count: “system.replset”, query: {}, fields: {} }
vagrant@database:~$

and:

vagrant@database:~ vagrant@database:~ tail M310-HW-2.4/r1/mongodb.log
2020-12-01T02:16:41.051+0000 I CONTROL [initandlisten] distmod: ubuntu1404
2020-12-01T02:16:41.051+0000 I CONTROL [initandlisten] distarch: x86_64
2020-12-01T02:16:41.051+0000 I CONTROL [initandlisten] target_arch: x86_64
2020-12-01T02:16:41.051+0000 I CONTROL [initandlisten] options: { net: { port: 31241, ssl: { CAFile: “/home/vagrant/shared/certs/ca.pem”, PEMKeyFile: “/home/vagrant/shared/certs/server.pem”, mode: “requireSSL” } }, processManagement: { fork: true }, replication: { replSet: “HW-2.4” }, security: { authorization: “enabled” }, storage: { dbPath: “./r1” }, systemLog: { destination: “file”, path: “./r1/mongodb.log” } }
2020-12-01T02:16:41.071+0000 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=1G,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),verbose=(recovery_progress),
2020-12-01T02:16:41.134+0000 I REPL [initandlisten] Did not find local voted for document at startup.
2020-12-01T02:16:41.134+0000 I REPL [initandlisten] Did not find local replica set configuration document at startup; NoMatchingDocument: Did not find replica set configuration document in local.system.replset
2020-12-01T02:16:41.134+0000 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory ‘/home/vagrant/M310-HW-2.4/./r1/diagnostic.data’
2020-12-01T02:16:41.134+0000 I NETWORK [initandlisten] waiting for connections on port 31241 ssl
2020-12-01T02:16:41.134+0000 I NETWORK [HostnameCanonicalizationWorker] Starting hostname canonicalization worker
vagrant@database:~$

Have you used this command?
You have to use
use admin
Your mongods look fine
Once you are running with --auth you need to authenticate the user
It should work if you have authenticated

or you can add all 3 nodes at rs.initiate() itself using rs.initaite(cfg)
In cfg define all 3 nodes

This was a mistype, sorry.

No. I have also tried to do:

use admin

before running rs.initiate and rs.add, it did not work.

I have also tried running:

rs.initiate({_id: ‘HW-2.4’,
members: [
{_id:1, host: ‘database.m310.mongodb.university:31240’},
{_id:2, host: ‘database.m310.mongodb.university:31241’},
{_id:3, host: ‘database.m310.mongodb.university:31242’}
]
})

instead of:

rs.initiate({_id: ‘HW-2.4’,
members: [
{_id:1, host: ‘database.m310.mongodb.university:31240’}
]
})

but it did not work either.

As I mentioned before I also tried to create a user for that but to no avail:

db.createUser({
user: “m103-admin”,
pwd: “m103-pass”,
roles: [
{role: “root”, db: “admin”}
]
})

and then:

db.auth({user:“m103-admin”,pwd:“m103-pass”})

I could create the user and autenticate, but could not run rs.add().

Since this is not working, I am trying to see if I can get luckier using a config file.

Here is the file I have set for the first server:

vagrant@database:~$ cat cfg.1
storage:
  dbPath: ~/M310-HW-2.4/r0
net:
  bindIp: localhost,127.0.0.1
  port: 31240
  ssl:
     mode: requireSSL
     PEMKeyFile:  ~/shared/certs/server.pem
     CAFile: ~/shared/certs/ca.pem
security:
  authorization: enabled
systemLog:
  destination: file
  path: ~/M310-HW-2.4/r0/mongodb.log
  logAppend: true
processManagement:
  fork: true
replication:
  replSetName: HW-2.4
vagrant@database:~$ 

Is it correct? I can say that for the time being it is not working.
This what I get:

vagrant@database:~$ 
vagrant@database:~$ mongod -f cfg.1
about to fork child process, waiting until server is ready for connections.
forked process: 10524
ERROR: child process failed, exited with error number 1
vagrant@database:~$ 
vagrant@database:~$ 

What am I missing?

the log will providemore info about the error

Yes. So please tell me where the log is, I tried to find it but couldn’t.
It was in no place I could think of.

This the location of your mongod.log

path: ~/M310-HW-2.4/r0/mongodb.log

~/M310-HW-2.4/r0/mongodb.log=/home/vagrant/M310-HW-2.4/r0/mongodb.log
(~ means home dir)

Most likely your logfile could not be created as you already had the logfile with same name from previous runs you did from command line

Remove or rename the old file and try again
Infact error number 1 means unable to create logfile or unable to read keyfile

When I looked there, there was simply nothing.

This log file you are referring to is (in my understanding) the file used by mongodb for logs, once it is started. Here, I have removed every thing that was previous there, in order to start brand new trying to use a config file, instead of “command line only”. The directory ~/M310-HW-2.4/r0/ is there but empty.

So when I run:

mongod -f cfg.1

Starting the server fails and no log is there. Let me know if I am wrong.

I also tried to see if I could find some kind of logs under /etc/var but was not lucky.
I found something but with no relevant information inside.

I have redone everything and made a detailed report of all my actions so you can follow and tell me where I am doing something wrong. I have also added some ls commands on the way so you can be aware of the state of things at various moments. You will note for example that there are no logs where you said after running mongod -f cfg.1.

Shell-Prompt$ vagrant up database
Bringing machine 'database' up with 'virtualbox' provider...
==> database: Importing base box 'ubuntu/trusty64'...
==> database: Matching MAC address for NAT networking...
==> database: Checking if box 'ubuntu/trusty64' version '20190514.0.0' is up to date...
==> database: Setting the name of the VM: m310-vagrant-env_database_1606877102673_28126
==> database: Clearing any previously set forwarded ports...
==> database: Clearing any previously set network interfaces...
==> database: Preparing network interfaces based on configuration...
    database: Adapter 1: nat
    database: Adapter 2: hostonly
==> database: Forwarding ports...
.......
.......
Shell-Prompt$
Shell-Prompt$ vagrant ssh database
Welcome to Ubuntu 14.04.6 LTS (GNU/Linux 3.13.0-170-generic x86_64)
.......
.......
vagrant@database:~$ 
vagrant@database:~$ ls
shared
vagrant@database:~$ 
vagrant@database:~$ mkdir -p M310-HW-2.4/{r0,r1,r2}
vagrant@database:~$ ls M310-HW-2.4/*
M310-HW-2.4/r0:

M310-HW-2.4/r1:

M310-HW-2.4/r2:
vagrant@database:~$ 
vagrant@database:~$ vi cfg.1
vagrant@database:~$ 
vagrant@database:~$ cat cfg.1 
storage:
  dbPath: ~/M310-HW-2.4/r0
net:
  bindIp: localhost
  port: 31240
security:
  authorization: enabled
net:
   ssl:
      mode: requireSSL
      PEMKeyFile: ~/shared/certs/server.pem
      CAFile: ~/shared/certs/ca.pem
systemLog:
  destination: file
  path: ~/M310-HW-2.4/r0/mongodb.log
  logAppend: true
processManagement:
  fork: true
replication:
  replSetName: HW-2.4

vagrant@database:~$ 
vagrant@database:~$ mongod -f cfg.1 
about to fork child process, waiting until server is ready for connections.
forked process: 7851
ERROR: child process failed, exited with error number 1
vagrant@database:~$ ls M310-HW-2.4/*
M310-HW-2.4/r0:

M310-HW-2.4/r1:

M310-HW-2.4/r2:
vagrant@database:~$ 

I hope this is useful to spot the problem.

I expect that my config file (cfg.1) has something bad in it. I’d like to know what.

But I have also tried another approach (based on command line options), where I can fire up the servers, though still can’t run rs.add in the mongo shell. I have created another thread for that ( HW-2.4, step by step checking. rs.add() keeps failing) also with a detailed report.

  1. Do not use tilde in configuration files. Use full path name for easier traceability. In the other thread I wrote about permission. But I think the tilde might be the issue. I am not sure if mongod can expand the shell short-cut to /home/vagrant as the shell does.

  2. localhost and 127.0.0.1 is redundant.

  3. Since we are using certificate to authenticate and authorize internally, you must bindIp using the same host name as you have in the certificates.

I remade the config file like this:

storage:
  dbPath: /home/vagrant/M310-HW-2.4/r0
net:
  bindIp: localhost,database.m310.mongodb.university
  port: 31240
security:
  authorization: enabled
net:
   ssl:
      mode: requireSSL
      PEMKeyFile: /home/vagrant/shared/certs/server.pem
      CAFile: /home/vagrant/shared/certs/ca.pem
systemLog:
  destination: file
  path: /home/vagrant/M310-HW-2.4/r0/mongodb.log
  logAppend: true
processManagement:
  fork: true
replication:
  replSetName: HW-2.4

At least now the server is starting as I expect.

Output of ps -aef | grep [m]ongo and ss -tlnp please.

vagrant@database:~$ ps -aef | grep [m]ongo 
vagrant   8326     1  2 16:05 ?        00:00:17 mongod -f cfg.1
vagrant   8529     1  1 16:14 ?        00:00:02 mongod -f cfg.2
vagrant   8556     1  1 16:14 ?        00:00:02 mongod -f cfg.3
vagrant@database:~$ 

vagrant@database:~$ 
vagrant@database:~$ ss -tlnp
State      Recv-Q Send-Q                                                                                                                                Local Address:Port                                                                                                                                  Peer Address:Port 
LISTEN     0      128                                                                                                                                               *:111                                                                                                                                              *:*     
LISTEN     0      128                                                                                                                                               *:22                                                                                                                                               *:*     
LISTEN     0      128                                                                                                                                               *:59233                                                                                                                                            *:*     
LISTEN     0      128                                                                                                                                       127.0.1.1:31240                                                                                                                                            *:*      users:(("mongod",8326,9))
LISTEN     0      128                                                                                                                                       127.0.0.1:31240                                                                                                                                            *:*      users:(("mongod",8326,7))
LISTEN     0      128                                                                                                                                       127.0.1.1:31241                                                                                                                                            *:*      users:(("mongod",8529,9))
LISTEN     0      128                                                                                                                                       127.0.0.1:31241                                                                                                                                            *:*      users:(("mongod",8529,7))
LISTEN     0      128                                                                                                                                       127.0.1.1:31242                                                                                                                                            *:*      users:(("mongod",8556,9))
LISTEN     0      128                                                                                                                                       127.0.0.1:31242                                                                                                                                            *:*      users:(("mongod",8556,7))
LISTEN     0      128                                                                                                                                              :::111                                                                                                                                             :::*     
LISTEN     0      128                                                                                                                                              :::56978                                                                                                                                           :::*     
LISTEN     0      128                                                                                                                                              :::22                                                                                                                                              :::*     
vagrant@database:~$

This is my last rs.add trial at this point, something is still not right:

MongoDB Enterprise HW-2.4:PRIMARY> 
MongoDB Enterprise HW-2.4:PRIMARY> rs.add('database.m310.mongodb.university:31241')
{
	"ok" : 0,
	"errmsg" : "Quorum check failed because not enough voting nodes responded; required 2 but only the following 1 voting nodes responded: database.m310.mongodb.university:31240; the following nodes did not respond affirmatively: database.m310.mongodb.university:31241 failed with not authorized on admin to execute command { replSetHeartbeat: \"HW-2.4\", pv: 1, v: 2, from: \"database.m310.mongodb.university:31240\", fromId: 1, checkEmpty: false }",
	"code" : 74
}
MongoDB Enterprise HW-2.4:PRIMARY> 
MongoDB Enterprise HW-2.4:PRIMARY> exit
bye
vagrant@database:~$ tail M310-HW-2.4/r0/mongodb.log
2020-12-02T16:26:28.642+0000 I ACCESS   [conn10] Unauthorized: not authorized on admin to execute command { replSetGetStatus: 1.0, forShell: 1.0 }
2020-12-02T16:27:23.833+0000 I ACCESS   [conn10] Successfully authenticated as principal m103-admin on admin
2020-12-02T16:27:58.317+0000 I REPL     [conn10] replSetReconfig admin command received from client
2020-12-02T16:27:58.317+0000 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:46659 #11 (3 connections now open)
2020-12-02T16:27:58.325+0000 I REPL     [conn10] replSetReconfig config object with 2 members parses ok
2020-12-02T16:27:58.325+0000 W REPL     [ReplicationExecutor] Got error (Unauthorized: not authorized on admin to execute command { replSetHeartbeat: "HW-2.4", pv: 1, v: 2, from: "database.m310.mongodb.university:31240", fromId: 1, checkEmpty: false }) response on heartbeat request to database.m310.mongodb.university:31241; { ok: 1.0, hbmsg: "" }
2020-12-02T16:27:58.325+0000 E REPL     [conn10] replSetReconfig failed; NodeNotFound: Quorum check failed because not enough voting nodes responded; required 2 but only the following 1 voting nodes responded: database.m310.mongodb.university:31240; the following nodes did not respond affirmatively: database.m310.mongodb.university:31241 failed with not authorized on admin to execute command { replSetHeartbeat: "HW-2.4", pv: 1, v: 2, from: "database.m310.mongodb.university:31240", fromId: 1, checkEmpty: false }
2020-12-02T16:27:58.327+0000 I NETWORK  [conn11] end connection 127.0.0.1:46659 (2 connections now open)
2020-12-02T16:29:43.403+0000 I NETWORK  [conn10] end connection 127.0.0.1:46658 (1 connection now open)
2020-12-02T16:29:43.404+0000 I NETWORK  [conn9] end connection 127.0.0.1:46657 (0 connections now open)
vagrant@database:~$ 
vagrant@database:~$ tail M310-HW-2.4/r1/mongodb.log
2020-12-02T16:23:39.483+0000 I ACCESS   [conn2] Unauthorized: not authorized on admin to execute command { replSetHeartbeat: "HW-2.4", pv: 1, v: 2, from: "database.m310.mongodb.university:31240", fromId: 1, checkEmpty: false }
2020-12-02T16:25:18.253+0000 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49401 #3 (2 connections now open)
2020-12-02T16:25:18.258+0000 I NETWORK  [conn3] end connection 127.0.0.1:49401 (1 connection now open)
2020-12-02T16:25:18.258+0000 I ACCESS   [conn2] Unauthorized: not authorized on admin to execute command { replSetHeartbeat: "HW-2.4", pv: 1, v: 2, from: "database.m310.mongodb.university:31240", fromId: 1, checkEmpty: false }
2020-12-02T16:25:27.759+0000 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49403 #4 (2 connections now open)
2020-12-02T16:25:27.763+0000 I NETWORK  [conn4] end connection 127.0.0.1:49403 (1 connection now open)
2020-12-02T16:25:27.763+0000 I ACCESS   [conn2] Unauthorized: not authorized on admin to execute command { replSetHeartbeat: "HW-2.4", pv: 1, v: 2, from: "database.m310.mongodb.university:31240", fromId: 1, checkEmpty: false }
2020-12-02T16:27:58.321+0000 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:49407 #5 (2 connections now open)
2020-12-02T16:27:58.325+0000 I NETWORK  [conn5] end connection 127.0.0.1:49407 (1 connection now open)
2020-12-02T16:27:58.325+0000 I ACCESS   [conn2] Unauthorized: not authorized on admin to execute command { replSetHeartbeat: "HW-2.4", pv: 1, v: 2, from: "database.m310.mongodb.university:31240", fromId: 1, checkEmpty: false }
vagrant@database:~$ 

I launched mongo like this:

mongo --host 'HW-2.4/database.m310.mongodb.university:31240' --ssl --sslPEMKeyFile shared/certs/client.pem --sslCAFile shared/certs/ca.pem