You can be a part of this team and this awesome organization too! Head on over to MongoDB’s careers page to see what’s available, or feel free to ping me on LinkedIn if you have any questions.
</SHAMELESS_PLUG>
The goal of this post is to showcase a change that is coming in MongoDB 5.0 that will significantly improve the feedback loop regarding initial sync progress monitoring. With SERVER-47863 being completed, the results of the db.adminCommand({ replSetGetStatus: 1, initialSync: 1 }) now include additional metrics that can be used to help determine how long (approximately) an initial sync will be running for.
Though this feature is planned to be backported to all supported versions (4.4, 4.2, 4.0, 3.6), at the time of writing backports had not been completed.
If you want to test this yourself, my setup was as follows:
The above steps will build the mongod and start up 2 nodes in a replica set with one in a STARTUP2 (initial sync) state.
By connecting to the secondary node directly and issuing a replSetGetStatus command we can now review the progress of the copy. Note that this will need to be done while the initial sync is in progress; once the node exits the STARTUP2 state and enters a SECONDARY state, the initialSyncStatus details will be unavailable.
If (approxBytesCopied == 0), this field will not be shown
I’ve opened SERVER-53017 to review this particular entry as the value did not appear to be properly updated throughout the initial sync process. As MongoDB 5.0 is not expected to be GA until mid 2021, this will likely be addressed before then.
= Sum (<collection>.approxBytesCopied for all collections)
What can we do with all this useful information you ask? Well I’ve written the following script that can be used to poll a secondary replica set member in STARTUP2 to provide details regarding the progress of the initial sync. This script will also provide estimated throughput and a calculated ETA based on data transfer rates.
The output will appear similar to:
12345
# start monitoring the initial sync (default refresh interval is 5 seconds)mongo --host $SECONDARY_HOST --port $SECONDARY_PORT --quiet --eval "load('measureInitialSyncProgress.js'); measureInitialSyncProgress();"# to use a custom refresh interval, the value is in milliseconds, so for a 1 second refresh# pass 1000 to measureInitialSyncProgress as follows:# mongo --host $SECONDARY_HOST --port $SECONDARY_PORT --quiet --eval "load('measureInitialSyncProgress.js'); measureInitialSyncProgress(1000);"
12345678910111213141516171819202122232425
Initial Sync running for 00:18:05.2 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:54.2 to go!
Initial Sync running for 00:18:10.8 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:18:17.9 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:18:22.9 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:18:27.9 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:18:33.1 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:18:38.4 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:49.1 to go!
Initial Sync running for 00:18:43.5 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:18:48.5 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:18:53.9 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:18:59.5 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:44.2 to go!
Initial Sync running for 00:19:05.3 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:39.2 to go!
Initial Sync running for 00:19:11.0 (remainingInitialSyncEstimatedMillis 0). Cloned 1.1 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:34.2 to go!
Initial Sync running for 00:19:16.6 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:29.2 to go!
Initial Sync running for 00:19:22.3 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:19:28.4 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:24.2 to go!
Initial Sync running for 00:19:34.5 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:19.2 to go!
Initial Sync running for 00:19:39.6 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:14.2 to go!
Initial Sync running for 00:19:45.3 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:19:54.6 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:09.2 to go!
Initial Sync running for 00:20:01.9 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:20:10.1 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (15.9 MB in past 5 second(s)) at a rate of 3.2 MB/second - 00:00:04.2 to go!
Initial Sync running for 00:20:15.7 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (No progress in past 5 second(s))Initial Sync running for 00:20:20.7 (remainingInitialSyncEstimatedMillis 0). Cloned 1.2 GB of 1.2 GB (11.6 MB in past 5 second(s)) at a rate of 2.3 MB/second - 00:00:00.7 to go!
Node not currently performing an initial sync
Once SERVER-53017 has been addressed I will update this script so that the remainingInitialSyncEstimatedMillis values can be used consistently.
var getReadableFileSizeString = function (fileSizeInBytes) {
var i = -1;
var byteUnits = [' kB', ' MB', ' GB', ' TB', 'PB', 'EB', 'ZB', 'YB'];
do {
fileSizeInBytes = fileSizeInBytes / 1024;
i++;
} while (fileSizeInBytes > 1024);
return Math.max(fileSizeInBytes, 0.1).toFixed(1) + byteUnits[i];
};
function measureSyncProgress(previousResults) {
var cmd = db.adminCommand({ replSetGetStatus: 1, initialSync: 1 });
if (!cmd.hasOwnProperty("initialSyncStatus")) {
print("Node not currently performing an initial sync");
return { exit: true };
}