Details
-
Bug
-
Resolution: Done
-
Minor - P4
-
None
-
3.2.11
-
None
-
FreeBSD 11 64bit, MongoDB 3.2.11
-
Minor Change
-
ALL
-
Description
Hi all!
I think I found a bug when querying for config server optime via replSetGetStatus command somehow.
config.rs0:SECONDARY> rs.status()
|
{
|
"set" : "config.rs0", |
"date" : ISODate("2017-02-07T13:35:02.792Z"), |
"myState" : 2, |
"term" : NumberLong(25), |
"syncingTo" : "config1", |
"configsvr" : true, |
"heartbeatIntervalMillis" : NumberLong(2000), |
"members" : [ |
{
|
"_id" : 3, |
"name" : "config2:27019", |
"health" : 1, |
"state" : 2, |
"stateStr" : "SECONDARY", |
"uptime" : 7358, |
"optime" : { |
"ts" : Timestamp(1486474501, 4), |
"t" : NumberLong(25) |
},
|
"optimeDate" : ISODate("2017-02-07T13:35:01Z"), |
"syncingTo" : "config1:27019", |
"configVersion" : 14, |
"self" : true |
},
|
{
|
"_id" : 4, |
"name" : "config1:27019", |
"health" : 1, |
"state" : 1, |
"stateStr" : "PRIMARY", |
"uptime" : 7356, |
"optime" : { |
"ts" : Timestamp(1486474501, 4), |
"t" : NumberLong(25) |
},
|
"optimeDate" : ISODate("2017-02-07T13:35:01Z"), |
"lastHeartbeat" : ISODate("2017-02-07T13:35:02.516Z"), |
"lastHeartbeatRecv" : ISODate("2017-02-07T13:35:02.515Z"), |
"pingMs" : NumberLong(0), |
"electionTime" : Timestamp(1486467112, 1), |
"electionDate" : ISODate("2017-02-07T11:31:52Z"), |
"configVersion" : 14 |
},
|
{
|
"_id" : 5, |
"name" : "config3:27019", |
"health" : 1, |
"state" : 2, |
"stateStr" : "SECONDARY", |
"uptime" : 7355, |
"optime" : { |
"ts" : Timestamp(1486474501, 4), |
"t" : NumberLong(25) |
},
|
"optimeDate" : ISODate("2017-02-07T13:35:01Z"), |
"lastHeartbeat" : ISODate("2017-02-07T13:35:02.764Z"), |
"lastHeartbeatRecv" : ISODate("2017-02-07T13:35:02.576Z"), |
"pingMs" : NumberLong(190), |
"syncingTo" : "config1:27019", |
"configVersion" : 14 |
}
|
],
|
"ok" : 1 |
}
|
If you see the above, the optime on the primary is 1486474501, which is the actual last entry in the oplog. However, when I query the config server using replSetGetStatus (pymongo), it shows the uptime instead.
[{u'uptime': 7362,
|
u'configVersion': 14,
|
u'optime': {
|
u'ts': Timestamp(1486474506, 1),
|
u't': 25L
|
},
|
u'name': u'config2:27019',
|
u'self': True,
|
u'optimeDate': datetime.datetime(2017, 2, 7, 13, 35, 6),
|
u'syncingTo': u'config1:27019',
|
u'state': 2,
|
u'health': 1.0,
|
u'stateStr': u'SECONDARY',
|
u'_id': 3},
|
{u'uptime': 7360,
|
u'configVersion': 14,
|
u'optime': {
|
u'ts': Timestamp(1486474506, 1),
|
u't': 25L
|
},
|
u'name': u'config1:27019',
|
u'pingMs': 0L,
|
u'optimeDate': datetime.datetime(2017, 2, 7, 13, 35, 6),
|
u'electionTime': Timestamp(1486467112, 1),
|
u'electionDate': datetime.datetime(2017, 2, 7, 11, 31, 52),
|
u'state': 1,
|
u'health': 1.0,
|
u'stateStr': u'PRIMARY',
|
u'lastHeartbeatRecv': datetime.datetime(2017, 2, 7, 13, 35, 6, 522000),
|
u'_id': 4,
|
u'lastHeartbeat': datetime.datetime(2017, 2, 7, 13, 35, 6, 522000)},
|
{u'uptime': 7359,
|
u'configVersion': 14,
|
u'optime': {
|
u'ts': Timestamp(1486474504, 1),
|
u't': 25L
|
},
|
u'name': u'config3:27019',
|
u'pingMs': 190L,
|
u'optimeDate': datetime.datetime(2017, 2, 7, 13, 35, 4),
|
u'syncingTo': u'config1',
|
u'state': 2,
|
u'health': 1.0,
|
u'stateStr': u'SECONDARY',
|
u'lastHeartbeatRecv': datetime.datetime(2017, 2, 7, 13, 35, 4, 771000),
|
u'_id': 5,
|
u'lastHeartbeat': datetime.datetime(2017, 2, 7, 13, 35, 4, 959000)}]
|
|
This only happens on CSRS config server replica sets.
Thanks!