38

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.

5 Answers 5

43

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.

3
  • thanks a lot, seems "(not reachable/healthy)" should be "SECONDARY"
    – irmorteza
    Nov 9, 2013 at 17:06
  • Thanks for the clarification on the optime and optimeDate fields. When upgrading from 2.4 to 2.6, the syncingTo message wouldn't go away, so I wasn't sure if there was an issue syncing correctly. Apr 21, 2015 at 19:08
  • Note that it is important to check the opTime, NOT just the state/stateStr. In some cases nodes can enter the SECONDARY state even when they are far behind the primary, and even if the oplog is not long enough to catch up automatically. Apr 7, 2020 at 1:52
36

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.

1
  • 1
    Use rs.printSecondaryReplicationInfo() for version after 4.4.1
    – Jerry An
    Jan 6, 2022 at 15:54
2

@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 
1

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');
}
0

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}}

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.