MongoDB tip: MongoDB 3.4, adding replica set members, issue/resolution
In this post I am working with mongodb 3.4.6 on Redhat 7.x
This was supposed to be a super straight forward exercise for me as I had done it a few times in the past and I'd never really encountered any issue until today.
I started the mongod service as such, and I verified the process is running
Note: every node in this exercise started the same way, same data mount, log mount, same port, etc.
Then I logged into this node by issuing and started working on adding replica set member
Let's start adding:
At this point, my first thought was... ok, I should just switch to the node I added because obviously my current node has been demoted to secondary, I just needed to continue there to add the third node.
When I went to the node I just added, I saw
It took me a little while to figure this out because the whole time I was using IP to add the node, so started over and I tried using the hostname instead and it failed immediately
It was then I realized I was not able to ping the hostname, even though I was able to ping the IP address.
So this is what I think is happening. When the node is added using IP address, initially it was fine for a moment, soon replicaSet started to resolve its hostname with its IP and that's when it believes it had lost connectivity to the other node, hence, election was triggered and it bumped the current node to second node because no majority was achieved.
The workaround is simply editing the /etc/hosts with proper IP matching to hostname.
After that, it was smooth sail from there!
I started the mongod service as such, and I verified the process is running
Note: every node in this exercise started the same way, same data mount, log mount, same port, etc.
[root@msdlva-dsnopm02 apps]# mongod --port 30000 --dbpath /apps/data --logpath /apps/log/appDBlog.log &
[root@msdlva-dsnopm02 apps]# ps -ef | grep mongod
root 12854 23282 6 08:31 pts/0 00:00:00 mongod --port 30000 --dbpath /apps/data --logpath /apps/log/appDBlog.log
root 12880 23282 0 08:32 pts/0 00:00:00 grep --color=auto mongod
Then I logged into this node by issuing and started working on adding replica set member
[root@msdlva-dsnopm02 apps]# mongo --port 30000
MongoDB shell version v3.4.6
connecting to: mongodb://127.0.0.1:30000/
MongoDB server version: 3.4.6
Server has startup warnings:
2017-07-31T08:33:33.167-0400 I CONTROL [initandlisten]
2017-07-31T08:33:33.167-0400 I CONTROL [initandlisten] ** WARNING: Access control is not enabled for the database.
2017-07-31T08:33:33.167-0400 I CONTROL [initandlisten] ** Read and write access to data and configuration is unrestricted.
2017-07-31T08:33:33.167-0400 I CONTROL [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
2017-07-31T08:33:33.167-0400 I CONTROL [initandlisten]
2017-07-31T08:33:33.167-0400 I CONTROL [initandlisten]
2017-07-31T08:33:33.167-0400 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2017-07-31T08:33:33.168-0400 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2017-07-31T08:33:33.168-0400 I CONTROL [initandlisten]
2017-07-31T08:33:33.168-0400 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2017-07-31T08:33:33.168-0400 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2017-07-31T08:33:33.168-0400 I CONTROL [initandlisten]
MongoDB Enterprise > rs.status()
{
"info" : "run rs.initiate(...) if not yet done for the set",
"ok" : 0,
"errmsg" : "no replset config has been received",
"code" : 94,
"codeName" : "NotYetInitialized"
}
MongoDB Enterprise > rs.initiate()
{
"info2" : "no configuration specified. Using a default configuration for the set",
"me" : "msdlva-dsnopm02:30000",
"ok" : 1
}
MongoDB Enterprise repApp:PRIMARY>
rs.status() looks okMongoDB Enterprise repApp:PRIMARY> rs.status()
{
"set" : "repApp",
"date" : ISODate("2017-07-31T12:36:58.255Z"),
"myState" : 1,
"term" : NumberLong(1),
"heartbeatIntervalMillis" : NumberLong(2000),
"optimes" : {
"lastCommittedOpTime" : {
"ts" : Timestamp(1501504608, 1),
"t" : NumberLong(1)
},
"appliedOpTime" : {
"ts" : Timestamp(1501504608, 1),
"t" : NumberLong(1)
},
"durableOpTime" : {
"ts" : Timestamp(1501504608, 1),
"t" : NumberLong(1)
}
},
"members" : [
{
"_id" : 0,
"name" : "msdlva-dsnopm02:30000",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 206,
"optime" : {
"ts" : Timestamp(1501504608, 1),
"t" : NumberLong(1)
},
"optimeDate" : ISODate("2017-07-31T12:36:48Z"),
"electionTime" : Timestamp(1501504466, 2),
"electionDate" : ISODate("2017-07-31T12:34:26Z"),
"configVersion" : 1,
"self" : true
}
],
"ok" : 1
}
Let's start adding:
MongoDB Enterprise repApp:PRIMARY> rs.add("10.155.226.232:30000","10.155.226.96:30000")
{ "ok" : 1 }
MongoDB Enterprise repApp:PRIMARY> rs.status()
{
"set" : "repApp",
"date" : ISODate("2017-07-31T12:41:00.093Z"),
"myState" : 1,
"term" : NumberLong(1),
"heartbeatIntervalMillis" : NumberLong(2000),
"optimes" : {
"lastCommittedOpTime" : {
"ts" : Timestamp(1501504856, 1),
"t" : NumberLong(1)
},
"appliedOpTime" : {
"ts" : Timestamp(1501504856, 1),
"t" : NumberLong(1)
},
"durableOpTime" : {
"ts" : Timestamp(1501504856, 1),
"t" : NumberLong(1)
}
},
"members" : [
{
"_id" : 0,
"name" : "msdlva-dsnopm02:30000",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 448,
"optime" : {
"ts" : Timestamp(1501504856, 1),
"t" : NumberLong(1)
},
"optimeDate" : ISODate("2017-07-31T12:40:56Z"),
"electionTime" : Timestamp(1501504466, 2),
"electionDate" : ISODate("2017-07-31T12:34:26Z"),
"configVersion" : 2,
"self" : true
},
{
"_id" : 1,
"name" : "10.155.226.232:30000",
"health" : 1,
"state" : 0,
"stateStr" : "STARTUP",
"uptime" : 3,
"lastHeartbeat" : ISODate("2017-07-31T12:40:58.238Z"),
"lastHeartbeatRecv" : ISODate("1970-01-01T00:00:00Z"),
"pingMs" : NumberLong(0),
"configVersion" : -2
}
],
"ok" : 1
}
MongoDB Enterprise repApp:PRIMARY> rs.add("10.155.226.96:30000")
2017-07-31T08:41:17.854-0400 E QUERY [thread1] Error: error doing query: failed: network error while attempting to run command 'count' on host '127.0.0.1:30000' :
DB.prototype.runCommand@src/mongo/shell/db.js:132:1
DB.prototype.runReadCommand@src/mongo/shell/db.js:109:16
DBQuery.prototype.count@src/mongo/shell/query.js:380:15
DBCollection.prototype.count@src/mongo/shell/collection.js:1700:12
rs.add@src/mongo/shell/utils.js:1227:1
@(shell):1:1
2017-07-31T08:41:17.856-0400 I NETWORK [thread1] trying reconnect to 127.0.0.1:30000 (127.0.0.1) failed
2017-07-31T08:41:17.856-0400 I NETWORK [thread1] reconnect 127.0.0.1:30000 (127.0.0.1) ok
MongoDB Enterprise repApp:SECONDARY>
MongoDB Enterprise repApp:SECONDARY>
MongoDB Enterprise repApp:SECONDARY>
MongoDB Enterprise repApp:SECONDARY>
At this point, my first thought was... ok, I should just switch to the node I added because obviously my current node has been demoted to secondary, I just needed to continue there to add the third node.
When I went to the node I just added, I saw
[root@msdlva-dsnopm05 ~]# mongo --port 30000 MongoDB shell version v3.4.6 connecting to: mongodb://127.0.0.1:30000/ MongoDB server version: 3.4.6 Server has startup warnings: 2017-07-31T08:57:56.828-0400 I CONTROL [initandlisten] 2017-07-31T08:57:56.828-0400 I CONTROL [initandlisten] ** WARNING: Access control is not enabled for the database. 2017-07-31T08:57:56.828-0400 I CONTROL [initandlisten] ** Read and write access to data and configuration is unrestricted. 2017-07-31T08:57:56.828-0400 I CONTROL [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended. 2017-07-31T08:57:56.828-0400 I CONTROL [initandlisten] 2017-07-31T08:57:56.829-0400 I CONTROL [initandlisten] 2017-07-31T08:57:56.829-0400 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'. 2017-07-31T08:57:56.829-0400 I CONTROL [initandlisten] ** We suggest setting it to 'never' 2017-07-31T08:57:56.829-0400 I CONTROL [initandlisten] 2017-07-31T08:57:56.829-0400 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'. 2017-07-31T08:57:56.829-0400 I CONTROL [initandlisten] ** We suggest setting it to 'never' 2017-07-31T08:57:56.829-0400 I CONTROL [initandlisten] MongoDB Enterprise >I was a little confused at the moment as this node was not being added as it was supposed to.
It took me a little while to figure this out because the whole time I was using IP to add the node, so started over and I tried using the hostname instead and it failed immediately
MongoDB Enterprise repApp:PRIMARY> rs.add("msdlva-dsnopm05:30000")
{
"ok" : 0,
"errmsg" : "Quorum check failed because not enough voting nodes responded; required 2 but only the following 1 voting nodes responded: msdlva-dsnopm02:30000; the following nodes did not respond affirmatively: msdlva-dsnopm05:30000 failed with HostUnreachable",
"code" : 74,
"codeName" : "NodeNotFound"
}
It was then I realized I was not able to ping the hostname, even though I was able to ping the IP address.
So this is what I think is happening. When the node is added using IP address, initially it was fine for a moment, soon replicaSet started to resolve its hostname with its IP and that's when it believes it had lost connectivity to the other node, hence, election was triggered and it bumped the current node to second node because no majority was achieved.
The workaround is simply editing the /etc/hosts with proper IP matching to hostname.
After that, it was smooth sail from there!
[root@msdlva-dsnopm02 apps]# mongo --port 30000
MongoDB shell version v3.4.6
connecting to: mongodb://127.0.0.1:30000/
MongoDB server version: 3.4.6
Server has startup warnings:
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten]
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten] ** WARNING: Access control is not enabled for the database.
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten] ** Read and write access to data and configuration is unrestricted.
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten] ** WARNING: You are running this process as the root user, which is not recommended.
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten]
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten]
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten]
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2017-07-31T13:50:48.051-0400 I CONTROL [initandlisten]
MongoDB Enterprise repApp:PRIMARY> rs.add({"_id":1,host:"msdlva-dsnopm05.csc.nycnet:30000"})
{ "ok" : 1 }
MongoDB Enterprise repApp:PRIMARY> rs.add({"_id":2,host:"msdlva-dsnopm06.csc.nycnet:30000"})
{ "ok" : 1 }
MongoDB Enterprise repApp:PRIMARY> rs.status()
{
"set" : "repApp",
"date" : ISODate("2017-07-31T18:21:49.249Z"),
"myState" : 1,
"term" : NumberLong(1),
"heartbeatIntervalMillis" : NumberLong(2000),
"optimes" : {
"lastCommittedOpTime" : {
"ts" : Timestamp(1501525306, 1),
"t" : NumberLong(1)
},
"appliedOpTime" : {
"ts" : Timestamp(1501525306, 1),
"t" : NumberLong(1)
},
"durableOpTime" : {
"ts" : Timestamp(1501525306, 1),
"t" : NumberLong(1)
}
},
"members" : [
{
"_id" : 0,
"name" : "msdlva-dsnopm02:30000",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 1862,
"optime" : {
"ts" : Timestamp(1501525306, 1),
"t" : NumberLong(1)
},
"optimeDate" : ISODate("2017-07-31T18:21:46Z"),
"electionTime" : Timestamp(1501523469, 2),
"electionDate" : ISODate("2017-07-31T17:51:09Z"),
"configVersion" : 3,
"self" : true
},
{
"_id" : 1,
"name" : "msdlva-dsnopm05.csc.nycnet:30000",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"uptime" : 35,
"optime" : {
"ts" : Timestamp(1501525306, 1),
"t" : NumberLong(1)
},
"optimeDurable" : {
"ts" : Timestamp(1501525306, 1),
"t" : NumberLong(1)
},
"optimeDate" : ISODate("2017-07-31T18:21:46Z"),
"optimeDurableDate" : ISODate("2017-07-31T18:21:46Z"),
"lastHeartbeat" : ISODate("2017-07-31T18:21:48.042Z"),
"lastHeartbeatRecv" : ISODate("2017-07-31T18:21:46.048Z"),
"pingMs" : NumberLong(0),
"configVersion" : 3
},
{
"_id" : 2,
"name" : "msdlva-dsnopm06.csc.nycnet:30000",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"uptime" : 3,
"optime" : {
"ts" : Timestamp(1501525306, 1),
"t" : NumberLong(1)
},
"optimeDurable" : {
"ts" : Timestamp(1501525306, 1),
"t" : NumberLong(1)
},
"optimeDate" : ISODate("2017-07-31T18:21:46Z"),
"optimeDurableDate" : ISODate("2017-07-31T18:21:46Z"),
"lastHeartbeat" : ISODate("2017-07-31T18:21:48.044Z"),
"lastHeartbeatRecv" : ISODate("2017-07-31T18:21:46.126Z"),
"pingMs" : NumberLong(1),
"configVersion" : 3
}
],
"ok" : 1
}
Thank you for sharing wonderful information with us to get some idea about that content.
ReplyDeleteFull Stack Training in Hyderabad
Full Stack Training in Ameerpet