Skip to content

Instantly share code, notes, and snippets.

@sarjarapu
Created June 15, 2018 06:13
Show Gist options
  • Save sarjarapu/f4a8c3c086d9fa5fdaf3a15adf1f3ad1 to your computer and use it in GitHub Desktop.
Save sarjarapu/f4a8c3c086d9fa5fdaf3a15adf1f3ad1 to your computer and use it in GitHub Desktop.
A bash script to show the transition of mon02 from Secondary to Primary
# Server mon02
tail -100 data/mongod.log | grep REPL
# 2018-06-15T03:52:42.304+0000 I REPL [rsBackgroundSync] could not find member to sync from
# 2018-06-15T03:52:42.305+0000 I REPL [replexec-28] Member mon01:27000 is now in state SECONDARY
# 2018-06-15T03:52:43.306+0000 I REPL [SyncSourceFeedback] SyncSourceFeedback error sending update to mon01:27000: InvalidSyncSource: Sync source was cleared. Was mon01:27000
# 2018-06-15T03:52:43.360+0000 I REPL [replexec-26] Starting an election, since weve seen no PRIMARY in the past 2000ms
# 2018-06-15T03:52:43.360+0000 I REPL [replexec-26] conducting a dry run election to see if we could be elected. current term: 4
# 2018-06-15T03:52:43.360+0000 I REPL [replexec-24] VoteRequester(term 4 dry run) received a yes vote from mon01:27000; response message: { term: 4, voteGranted: true, reason: "", ok: 1.0, operationTime: Timestamp(1529034758, 1), $clusterTime: { clusterTime: Timestamp(1529034758, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } } }
# 2018-06-15T03:52:43.360+0000 I REPL [replexec-24] dry election run succeeded, running for election in term 5
# 2018-06-15T03:52:43.363+0000 I REPL [replexec-28] VoteRequester(term 5) received a yes vote from mon01:27000; response message: { term: 5, voteGranted: true, reason: "", ok: 1.0, operationTime: Timestamp(1529034758, 1), $clusterTime: { clusterTime: Timestamp(1529034758, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } } }
# 2018-06-15T03:52:43.363+0000 I REPL [replexec-28] election succeeded, assuming primary role in term 5
# 2018-06-15T03:52:43.363+0000 I REPL [replexec-28] transition to PRIMARY from SECONDARY
# 2018-06-15T03:52:43.363+0000 I REPL [replexec-28] Entering primary catch-up mode.
# 2018-06-15T03:52:43.584+0000 I REPL [replexec-23] Caught up to the latest optime known via heartbeats after becoming primary.
# 2018-06-15T03:52:43.584+0000 I REPL [replexec-23] Exited primary catch-up mode.
# 2018-06-15T03:52:45.301+0000 I REPL [rsSync] transition to primary complete; database writes are now permitted
# Server mon03
tail -100 data/mongod.log | grep REPL
# 2018-06-15T03:52:29.029+0000 I REPL [rsBackgroundSync] sync source candidate: mon01:27000
# 2018-06-15T03:52:31.631+0000 I REPL [conn27] 'freezing' for 120 seconds
# 2018-06-15T03:52:42.794+0000 I REPL [replication-1] Choosing new sync source because our current sync source, mon01:27000, has an OpTime ({ ts: Timestamp(1529034758, 1), t: 4 }) which is not ahead of ours ({ ts: Timestamp(1529034758, 1), t: 4 }), it does not have a sync source, and its not the primary (sync source does not know the primary)
# 2018-06-15T03:52:42.794+0000 I REPL [replication-1] Canceling oplog query due to OplogQueryMetadata. We have to choose a new sync source. Current source: mon01:27000, OpTime { ts: Timestamp(1529034758, 1), t: 4 }, its sync source index:-1
# 2018-06-15T03:52:42.794+0000 W REPL [rsBackgroundSync] Fetcher stopped querying remote oplog with error: InvalidSyncSource: sync source mon01:27000 (config version: 4; last applied optime: { ts: Timestamp(1529034758, 1), t: 4 }; sync source index: -1; primary index: -1) is no longer valid
# 2018-06-15T03:52:42.794+0000 I REPL [rsBackgroundSync] could not find member to sync from
# 2018-06-15T03:52:43.420+0000 I REPL [ReplicationExecutor] Not starting an election, since we are not electable due to: Not standing for election because I am still waiting for stepdown period to end at 2018-06-09T13:09:29.408+0000 (mask 0x20)
# 2018-06-15T03:52:43.481+0000 I REPL [ReplicationExecutor] Member mon01:27000 is now in state SECONDARY
# 2018-06-15T03:52:43.584+0000 I REPL [ReplicationExecutor] Not starting an election, since we are not electable due to: Not standing for election because I am still waiting for stepdown period to end at 2018-06-09T13:09:29.408+0000 (mask 0x20)
# 2018-06-15T03:52:43.584+0000 I REPL [ReplicationExecutor] Member mon02:27000 is now in state PRIMARY
# 2018-06-15T03:52:43.663+0000 I REPL [replexec-31] Member mon02:27000 is now in state PRIMARY
# 2018-06-15T03:52:43.817+0000 I REPL [SyncSourceFeedback] SyncSourceFeedback error sending update to mon01:27000: InvalidSyncSource: Sync source was cleared. Was mon01:27000
# 2018-06-15T03:52:45.795+0000 I REPL [rsBackgroundSync] sync source candidate: mon02:27000
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment