[SERVER-2232] Replication oplog sync log output more detailed Created: 16/Dec/10  Updated: 12/Jul/16  Resolved: 21/Mar/11

Status: Closed
Project: Core Server
Component/s: Replication
Affects Version/s: None
Fix Version/s: 1.9.0

Type: Improvement Priority: Minor - P4
Reporter: David Mytton Assignee: Kristina Chodorow (Inactive)
Resolution: Fixed Votes: 1
Labels: None

Issue Links:
Duplicate
is duplicated by SERVER-2730 Show approx progress % in rs.status()... Closed
Participants:

 Description   

The log output when a replica set has completed the initial clone and is now running through the oplog is not very detailed. E.g. I had no idea what was happening for 25 minutes here:

Thu Dec 16 07:45:55 [replica set sync] replSet initial sync cloning db: admin
Thu Dec 16 07:45:55 [replica set sync] replSet initial sync cloning db: test
Thu Dec 16 07:45:55 [replica set sync] replSet initial sync query minValid
Thu Dec 16 07:45:55 [replica set sync] replSet initial sync initial oplog application
Thu Dec 16 08:09:34 [replica set sync] building new index on

{ _id: 1 }

for postbacks.postbacks
Thu Dec 16 08:09:35 [replica set sync] done for 108421 records 0.465secs
Thu Dec 16 08:09:55 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 187ms
Thu Dec 16 08:10:01 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 180ms
Thu Dec 16 08:10:08 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 127ms
Thu Dec 16 08:10:11 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 330ms
Thu Dec 16 08:10:35 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 109ms
Thu Dec 16 08:10:39 allocating new datafile /mongodbdata/sd.2, filling with zeroes...
Thu Dec 16 08:10:39 done allocating datafile /mongodbdata/sd.2, size: 256MB, took 0.244 secs
Thu Dec 16 08:10:44 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 206ms
Thu Dec 16 08:10:45 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 187ms
Thu Dec 16 08:10:46 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 136ms
Thu Dec 16 08:10:50 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 136ms
Thu Dec 16 08:10:51 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 187ms
Thu Dec 16 08:10:54 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 188ms
Thu Dec 16 08:11:01 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 114ms
Thu Dec 16 08:11:03 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 169ms
Thu Dec 16 08:11:11 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 120ms
Thu Dec 16 08:11:18 [replica set sync] replSet initialSyncOplogApplication 100000
Thu Dec 16 08:11:21 [conn3] query admin.$cmd ntoreturn:1 command:

{ serverStatus: 1 }

reslen:1181 211ms
Thu Dec 16 08:12:01 [replica set sync] replSet initial sync finishing up
Thu Dec 16 08:12:02 [replica set sync] replSet set minValid=4d09c3b3:af
Thu Dec 16 08:12:02 [replica set sync] building new index on

{ _id: 1 }

for local.replset.minvalid
Thu Dec 16 08:12:03 [replica set sync] done for 0 records 0.074secs
Thu Dec 16 08:12:03 [replica set sync] replSet initial sync done
Thu Dec 16 08:12:04 [replica set sync] replSet SECONDARY

It would be useful to output more about what is happening and the % complete.



 Comments   
Comment by Reinaldo Giudici [ 28/Feb/11 ]

Agree, and specially when the intiial sync is taking multiple days to complete.
Is there actually any way to monitor where exactly the sync is ?
The current status is only: "initial sync initial oplog application"

Comment by auto (Inactive) [ 21/Mar/11 ]

Author:

{u'login': u'kchodorow', u'name': u'Kristina', u'email': u'kristina@10gen.com'}

Message: more detailed log output on initial sync SERVER-2232
https://github.com/mongodb/mongo/commit/79d8885cadc7ce988909c601e82f52eefb01210e

Generated at Sun Nov 19 12:22:45 UTC 2017 using JIRA 7.2.10#72012-sha1:2651463a07e52d81c0fcf01da710ca333fcb42bc.