How to check secondary is synced now or not

Question

there is the replica with three member (primary,secondary,secondary). Suppose one of secondaries down for a day, after return secondary back to replica how can i find, is it synced yet or not?

I did that in testing environment, But couldn't find useful data from rs.status() and db.printReplicationInfo().

there is "log length start to end" in db.printReplicationInfo(). but it's big time by default and grows when secondary is down.

Answer 1

Note: Be sure to check the answer provided by arcseldon for an user friendly equivalent.

You can use output of rs.status(). If secondary is synced and wasn't created with slaveDelay option then optime and optimeDate of secondary should be equal or close (if there are current operations) to those of primary. In that case stateStr should be equal to SECONDARY. So if secondary is synced you should see output similar to this (one member has been removed from output for clarity):

 {
    "set" : "rs0",
    "date" : ISODate("2013-11-08T14:58:49Z"),
    "myState" : 1,
    "members" : [
        {
            "_id" : 0,
            "name" : "hostname:27001",
            "health" : 1,
            "state" : 1,
            "stateStr" : "PRIMARY",
            "uptime" : 155,
            "optime" : Timestamp(1383915748, 1),
            "optimeDate" : ISODate("2013-11-08T13:02:28Z"),
            "self" : true
        },

        {
            "_id" : 2,
            "name" : "hostname:27003",
            "health" : 0,
            "state" : 8,
            "stateStr" : "SECONDARY",
            "uptime" : 0,
            "optime" : Timestamp(1383915748, 1),
            "optimeDate" : ISODate("2013-11-08T13:02:28Z"),
            "lastHeartbeat" : ISODate("2013-11-08T14:58:48Z"),
            "lastHeartbeatRecv" : ISODate("2013-11-08T14:58:42Z"),
            "pingMs" : 0,
            "syncingTo" : "hostname:27001"
        }
    ],
    "ok" : 1
}

Here you have output of rs.status() for the same replica set if one of secondaries is not synced. First of all you'll see that optime and optimeDate for hostname:27003 differs from primary, stateStr is set to RECOVERING and there is appropriate lastHeartbeatMessage.

{
    "set" : "rs0",
    "date" : ISODate("2013-11-08T15:01:34Z"),
    "myState" : 1,
    "members" : [
        {
            "_id" : 0,
            "name" : "hostname:27001",
            "health" : 1,
            "state" : 1,
            "stateStr" : "PRIMARY",
            "uptime" : 320,
            "optime" : Timestamp(1383922858, 767),
            "optimeDate" : ISODate("2013-11-08T15:00:58Z"),
            "self" : true
        },

        {
            "_id" : 2,
            "name" : "hostname:27003",
            "health" : 1,
            "state" : 3,
            "stateStr" : "RECOVERING",
            "uptime" : 14,
            "optime" : Timestamp(1383915748, 1),
            "optimeDate" : ISODate("2013-11-08T13:02:28Z"),
            "lastHeartbeat" : ISODate("2013-11-08T15:01:34Z"),
            "lastHeartbeatRecv" : ISODate("2013-11-08T15:01:34Z"),
            "pingMs" : 0,
            "lastHeartbeatMessage" : "still syncing, not yet to minValid optime 527cfc90:19c4",
            "syncingTo" : "hostname:27001"
        }
    ],
    "ok" : 1
}

If secondary has been created with slaveDelay then optime and optimeDate can be different but stateStr and lastHeartbeatMessage will indicate if there is some lag.

Answer 2

Update 13th February 2017

Agree with the accepted answer that rs.status() offers adequate information and is an easy command to remember. However, (personally using Mongo 3 now), do also really like the convenience and readability of rs.printSlaveReplicationInfo().

It gives an output something like:

rs.printSlaveReplicationInfo()

source: node-2:27017
    syncedTo: Mon Feb 13 2017 06:15:17 GMT-0500 (EST)
    0 secs (0 hrs) behind the primary
source: node-3:27017
    syncedTo: Mon Feb 13 2017 06:15:16 GMT-0500 (EST)
    1 secs (0 hrs) behind the primary

As you can see, it is easy to get a sense of whether the synchronization between the nodes in the replica set is healthy or not.

Answer 3

I wrote a little script for mongoDB shell. It shows a diff between optime and optimeDate. You can use it instead of comparing manually replica set members.

var isMaster = rs.isMaster();
var me = isMaster.me;

if(!isMaster.ismaster && isMaster.secondary)
{
    var status = rs.status();
    var master = isMaster.primary;

    var masterOptime = 0;
    var masterOptimeDate = 0;
    var myOptime = 0;
    var myOptimeDate = 0;

    for(var i = 0 ; i < status.members.length ; i++)
    {
        var member = status.members[i];
        if(member.name == me)
        {
            if(member.stateStr == "SECONDARY") {
                myOptime = member.optime.getTime();
                myOptimeDate = member.optimeDate.getTime();
            }
            else
            {
                print(me + ' is out of sync ' + member.stateStr);
                break;
            }
        }
        else if(member.name == master)
        {
            masterOptime = member.optime.getTime();
            masterOptimeDate = member.optimeDate.getTime();
        }

    }

    if(myOptime && myOptimeDate)
    {
        var optimeDiff = masterOptime - myOptime;
        var optimeDateDiff = masterOptimeDate - myOptimeDate;

        print('optime diff: ' + optimeDiff);
        print('optimeDate diff: ' + optimeDateDiff);
    }

}
else
{
    print(me + ' is not secondary');
}

Answer 4

@arcseldon gave the right answer, however, rs.printSlaveReplicationInfo() will be depricated soon

rs0:PRIMARY> rs.printSlaveReplicationInfo() WARNING: printSlaveReplicationInfo is deprecated and may be removed in the next major release. Please use printSecondaryReplicationInfo instead.

So, start using rs.printSecondaryReplicationInfo() instead

rs0:PRIMARY> rs.printSecondaryReplicationInfo()
source: mongo-1.mongo.ns.svc.cluster.local:27017
        syncedTo: Sat Sep 26 2020 01:26:32 GMT+0000 (UTC)
        10 secs (0 hrs) behind the primary 
source: mongo-2.mongo.ns.svc.cluster.local:27017
        syncedTo: Sat Sep 26 2020 01:26:32 GMT+0000 (UTC)
        10 secs (0 hrs) behind the primary 

Answer 5

Update on command rs.printSecondaryReplicationInfo(): When your SECONDARY is in initial synch, i.e. STARTUP2 then the output will be like this:

shard_03:PRIMARY> db.printSecondaryReplicationInfo()
source: mongo-1.mongo.ns.svc.cluster.local:27017
        syncedTo: Thu Jan 01 1970 01:00:00 GMT+0100 (CET)
        1623062383 secs (450850.66 hrs) behind the primary 

It does not give any indication when the initial synch might be finished. In order to get this, connect to the SECONDARY rather than the PRIMARY:

shard_03:STARTUP2> db.printSecondaryReplicationInfo()
source: mongo-2.mongo.ns.svc.cluster.local:27017
        InitialSyncSyncSource: mongo-1.mongo.ns.svc.cluster.local:27017
        InitialSyncRemainingEstimatedDuration: 1 hour(s) 11 minute(s)

Which would be more useful.

From the local log files you also see the progress, see this example:

$ tail -f /var/log/mongodb/mongod.log | grep Repl
{"t":{"$date":"2021-06-07T12:44:57.310+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplWriterWorker-15","msg":"progress meter","attr":{"name":"data.sessions.20210603 collection clone progress","done":2541288,"total":14003530,"percent":18,"units":"documents copied"}}
{"t":{"$date":"2021-06-07T12:46:02.478+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplWriterWorker-15","msg":"progress meter","attr":{"name":"data.sessions.20210603 collection clone progress","done":5703094,"total":14003530,"percent":40,"units":"documents copied"}}
{"t":{"$date":"2021-06-07T12:47:11.357+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplWriterWorker-15","msg":"progress meter","attr":{"name":"data.sessions.20210603 collection clone progress","done":9131425,"total":14003530,"percent":65,"units":"documents copied"}}
{"t":{"$date":"2021-06-07T12:48:13.295+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplWriterWorker-15","msg":"progress meter","attr":{"name":"data.sessions.20210603 collection clone progress","done":11761778,"total":14003530,"percent":83,"units":"documents copied"}}
{"t":{"$date":"2021-06-07T12:49:01.000+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplCoordExtern-0","msg":"progress meter","attr":{"name":"Index Build: inserting keys from external sorter into index","done":4847100,"total":14003530,"percent":34}}
{"t":{"$date":"2021-06-07T12:49:04.001+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplCoordExtern-0","msg":"progress meter","attr":{"name":"Index Build: inserting keys from external sorter into index","done":10169600,"total":14003530,"percent":72}}
{"t":{"$date":"2021-06-07T12:49:05.952+02:00"},"s":"I",  "c":"INDEX",    "id":20685,   "ctx":"ReplCoordExtern-0","msg":"Index build: inserted keys from external sorter into index","attr":{"namespace":"data.sessions.20210603","index":"tsi_1_t0_1_t_1","keysInserted":14003530,"durationMillis":8000}}
{"t":{"$date":"2021-06-07T12:49:09.000+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplCoordExtern-0","msg":"progress meter","attr":{"name":"Index Build: inserting keys from external sorter into index","done":6208700,"total":14003530,"percent":44}}
{"t":{"$date":"2021-06-07T12:49:11.977+02:00"},"s":"I",  "c":"INDEX",    "id":20685,   "ctx":"ReplCoordExtern-0","msg":"Index build: inserted keys from external sorter into index","attr":{"namespace":"data.sessions.20210603","index":"si_1","keysInserted":14003530,"durationMillis":5000}}
{"t":{"$date":"2021-06-07T12:49:15.001+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplCoordExtern-0","msg":"progress meter","attr":{"name":"Index Build: inserting keys from external sorter into index","done":4498400,"total":14003530,"percent":32}}
{"t":{"$date":"2021-06-07T12:49:18.001+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplCoordExtern-0","msg":"progress meter","attr":{"name":"Index Build: inserting keys from external sorter into index","done":11187800,"total":14003530,"percent":79}}
{"t":{"$date":"2021-06-07T12:49:19.557+02:00"},"s":"I",  "c":"INDEX",    "id":20685,   "ctx":"ReplCoordExtern-0","msg":"Index build: inserted keys from external sorter into index","attr":{"namespace":"data.sessions.20210603","index":"tsi_1_si_1","keysInserted":14003530,"durationMillis":7000}}
{"t":{"$date":"2021-06-07T12:49:19.697+02:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"ReplCoordExtern-0","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"data.sessions.20210603","index":"tsi_1_t0_1_t_1","commitTimestamp":{"$timestamp":{"t":1623062959,"i":22000}}}}
{"t":{"$date":"2021-06-07T12:49:19.698+02:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"ReplCoordExtern-0","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"data.sessions.20210603","index":"si_1","commitTimestamp":{"$timestamp":{"t":1623062959,"i":22000}}}}
{"t":{"$date":"2021-06-07T12:49:19.699+02:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"ReplCoordExtern-0","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"data.sessions.20210603","index":"tsi_1_si_1","commitTimestamp":{"$timestamp":{"t":1623062959,"i":22000}}}}
{"t":{"$date":"2021-06-07T12:49:26.001+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplCoordExtern-0","msg":"progress meter","attr":{"name":"Index Build: inserting keys from external sorter into index","done":5717400,"total":14003530,"percent":40}}
{"t":{"$date":"2021-06-07T12:49:29.000+02:00"},"s":"I",  "c":"-",        "id":51773,   "ctx":"ReplCoordExtern-0","msg":"progress meter","attr":{"name":"Index Build: inserting keys from external sorter into index","done":12567700,"total":14003530,"percent":89}}
{"t":{"$date":"2021-06-07T12:49:29.618+02:00"},"s":"I",  "c":"INDEX",    "id":20685,   "ctx":"ReplCoordExtern-0","msg":"Index build: inserted keys from external sorter into index","attr":{"namespace":"data.sessions.20210603","index":"_id_","keysInserted":14003530,"durationMillis":9000}}
{"t":{"$date":"2021-06-07T12:49:29.833+02:00"},"s":"I",  "c":"INDEX",    "id":20345,   "ctx":"ReplCoordExtern-0","msg":"Index build: done building","attr":{"buildUUID":null,"namespace":"data.sessions.20210603","index":"_id_","commitTimestamp":{"$timestamp":{"t":1623062969,"i":7002}}}}
{"t":{"$date":"2021-06-07T12:49:29.839+02:00"},"s":"I",  "c":"STORAGE",  "id":20320,   "ctx":"ReplCoordExtern-0","msg":"createCollection","attr":{"namespace":"data.sessions.20210601","uuidDisposition":"provided","uuid":{"uuid":{"$uuid":"bddc70be-463a-472a-a1e9-bdc5162a13f0"}},"options":{"uuid":{"$uuid":"bddc70be-463a-472a-a1e9-bdc5162a13f0"}}}}
{"t":{"$date":"2021-06-07T12:49:29.846+02:00"},"s":"I",  "c":"INDEX",    "id":20384,   "ctx":"ReplCoordExtern-0","msg":"Index build: starting","attr":{"namespace":"data.sessions.20210601","buildUUID":null,"properties":{"v":2,"key":{"tsi":1.0,"t0":1.0,"t":1.0},"name":"tsi_1_t0_1_t_1"},"method":"Hybrid","maxTemporaryMemoryUsageMB":66}}
{"t":{"$date":"2021-06-07T12:49:29.849+02:00"},"s":"I",  "c":"INDEX",    "id":20384,   "ctx":"ReplCoordExtern-0","msg":"Index build: starting","attr":{"namespace":"data.sessions.20210601","buildUUID":null,"properties":{"v":2,"key":{"si":1.0},"name":"si_1"},"method":"Hybrid","maxTemporaryMemoryUsageMB":66}}
{"t":{"$date":"2021-06-07T12:49:29.853+02:00"},"s":"I",  "c":"INDEX",    "id":20384,   "ctx":"ReplCoordExtern-0","msg":"Index build: starting","attr":{"namespace":"data.sessions.20210601","buildUUID":null,"properties":{"v":2,"key":{"tsi":1.0,"si":1.0},"name":"tsi_1_si_1"},"method":"Hybrid","maxTemporaryMemoryUsageMB":66}}
{"t":{"$date":"2021-06-07T12:49:29.859+02:00"},"s":"I",  "c":"INDEX",    "id":20384,   "ctx":"ReplCoordExtern-0","msg":"Index build: starting","attr":{"namespace":"data.sessions.20210601","buildUUID":null,"properties":{"v":2,"key":{"_id":1},"name":"_id_"},"method":"Hybrid","maxTemporaryMemoryUsageMB":200}}