Script to help identify the progress of an intial sync of a MongoDB SECONDARY node

initialSyncProgress.js

/*
* initialSyncProgress
* @author Alex Bevilacqua <[email protected]>
*
* Can be run against a MongoDB 3.4+ mongod that is in STARTUP2 (intitial sync) state to gain some
* insight into how the sync is progressing. This script WILL NOT tell you how long until the sync
* is complete, but based on how the script reports progress can be used to estimate this.
*
* usage:
*   mongo --quiet --eval "load('initialSyncProgress.js'); initialSyncProgress();"
*/
var printPercentage = function (position, length, type) {
  var p = Math.round((position / length) * 100, 2);
  return position + "/" + length + " " + type + " (" + p + "%)";
}

var msToTime = function (duration) {
  var milliseconds = parseInt((duration % 1000) / 100),
    seconds = Math.floor((duration / 1000) % 60),
    minutes = Math.floor((duration / (1000 * 60)) % 60),
    hours = Math.floor((duration / (1000 * 60 * 60)) % 24);

  hours = (hours < 10) ? "0" + hours : hours;
  minutes = (minutes < 10) ? "0" + minutes : minutes;
  seconds = (seconds < 10) ? "0" + seconds : seconds;

  return hours + ":" + minutes + ":" + seconds + "." + milliseconds;
}

var initialSyncProgress = function () {
  var status = db.adminCommand({ replSetGetStatus: 1, initialSync: 1 });
  var dbs_cloned = status.initialSyncStatus.databases.databasesCloned;
  delete status.initialSyncStatus.databases.databasesCloned;
  var dbs = Object.keys(status.initialSyncStatus.databases);
  var dbs_total = dbs.length;

  // total time elapsed syncing databases
  var elapsedMillis = 0;

  // status message based on the position within the currently
  // cloning database (collections cloned of collections total)
  var currentlyCloningStatus = "";

  for (var i = 0; i < dbs_total; i++) {
    var d = status.initialSyncStatus.databases[dbs[i]];
    // if the counts aren't the same either it's the database that's in progress or
    // hasn't started cloning yet
    if (d.clonedCollections < d.collections) {
      currentlyCloningStatus = "Cloning database " + dbs[i];
      currentlyCloningStatus += " - cloned " + printPercentage(d.clonedCollections, d.collections, "collections");
      var collectionKeys = Object.keys(d);
      for (var j = 0; j < collectionKeys.length; j++) {
        var c = d[collectionKeys[j]];
        if (c.hasOwnProperty("documentsToCopy") && (c.documentsCopied < c.documentsToCopy)) {
          currentlyCloningStatus += "\nCloning collection " + collectionKeys[j] + " " + printPercentage(c.documentsCopied, c.documentsToCopy, "documents");
        }
      }
    }
    // only add time if there's time to record
    if (d.hasOwnProperty("elapsedMillis")) {
      elapsedMillis += d.elapsedMillis;
    }
  }
  print("===================")
  print("Initial Sync Status")
  print("===================")
  var now = new Date();
  var started = status.initialSyncStatus.initialSyncStart;
  print("Cloning started at " + started + " (" + msToTime(now - started) + " ago)");
  var members = status.members;
  for (var i = 0; i < members.length; i++) {
    if (members[i].stateStr == "PRIMARY") {
      var optime = members[i].optimeDate
      var me = new Date(status.initialSyncStatus.initialSyncOplogStart.getTime() * 1000);
      print("Currently " + msToTime(optime - me) + " behind the PRIMARY (based on optimes)");
    }
  }
  if (status.initialSyncStatus.hasOwnProperty("initialSyncAttempts") && status.initialSyncStatus.initialSyncAttempts.length > 0) {
    var failures = status.initialSyncStatus.initialSyncAttempts.length;
    print("Cloning has already failed " + failures + " time(s) ...");
    print("Last Failure: " + status.initialSyncStatus.initialSyncAttempts[failures - 1].status);
  }
  print("Copying databases for " + msToTime(elapsedMillis) + ". Note this updates AFTER a collection has been cloned.");
  print("Cloned " + printPercentage(dbs_cloned, dbs_total, "databases"));
  print(currentlyCloningStatus);
}