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

Config Server Optime difference from rs.status() output

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Minor - P4 Minor - P4
    • None
    • Affects Version/s: 3.2.11
    • Component/s: Replication
    • None
    • Environment:
      FreeBSD 11 64bit, MongoDB 3.2.11
    • Minor Change
    • ALL
    • Hide

      1. Deploy config server in CSRS.
      2. Query the replication status via replSetGetStatus

      Show
      1. Deploy config server in CSRS. 2. Query the replication status via replSetGetStatus

      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!

            Assignee:
            kelsey.schubert@mongodb.com Kelsey Schubert
            Reporter:
            weishan Wei Shan Ang
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: