Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-20669

Unable to init mongodb node: rollback error RS100 reached beginning of remote oplog

XMLWordPrintableJSON

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: None
    • Component/s: Replication
    • None
    • ALL

      MongoVersion: 3.0.6
      WiredTiger.

      My mongo node stop responding at 10 AM today. With this log:

      2015-09-28T05:04:43.706-0500 I QUERY    [conn12126] assertion 13435 not master and slaveOk=false ns:db.colname query:{ active: true }
2015-09-28T05:04:43.706-0500 I QUERY    [conn12126] assertion 13435 not master and slaveOk=false ns:db.colname query:{ active: true }
2015-09-28T05:04:43.706-0500 I QUERY    [conn12126] assertion 13435 not master and slaveOk=false ns:db.colname query:{ active: true }
2015-09-28T05:04:43.706-0500 I QUERY    [conn12126] assertion 13435 not master and slaveOk=false ns:db.colname query:{ active: true }
2015-09-28T05:04:43.706-0500 I QUERY    [conn12126] assertion 13435 not master and slaveOk=false ns:db.colname query:{ active: true }
2015-09-28T05:04:43.707-0500 I QUERY    [conn12126] assertion 13435 not master and slaveOk=false ns:db.colname query:{ active: true }
2015-09-28T05:04:43.707-0500 I QUERY    [conn12126] assertion 13435 not master and slaveOk=false ns:db.colname query:{ active: true }
2015-09-28T05:04:43.707-0500 I QUERY    [conn12126] assertion 13435 not master and slaveOk=false ns:db.colname query:{ active: true }
2015-09-28T05:04:43.707-0500 I REPL     [rsBackgroundSync] replSet our last op time fetched: Sep 28 04:19:00:a3
2015-09-28T05:04:43.707-0500 I REPL     [rsBackgroundSync] replset source's GTE: Sep 28 04:19:01:1
2015-09-28T05:04:43.707-0500 I QUERY    [conn12126] assertion 13435 not master and slaveOk=false ns:db.colname query:{ active: true }
2015-09-28T05:04:43.707-0500 I REPL     [rsBackgroundSync] beginning rollback
2015-09-28T05:04:43.707-0500 I REPL     [rsBackgroundSync] rollback 0
2015-09-28T05:04:43.707-0500 I REPL     [rsBackgroundSync] rollback 1
2015-09-28T05:04:43.708-0500 I REPL     [rsBackgroundSync] rollback 2 FindCommonPoint
2015-09-28T05:04:44.212-0500 I REPL     [rsBackgroundSync] replSet info rollback our last optime:   Sep 28 04:19:00:a3
2015-09-28T05:04:44.212-0500 I REPL     [rsBackgroundSync] replSet info rollback their last optime: Sep 28 05:04:41:25
2015-09-28T05:04:44.212-0500 I REPL     [rsBackgroundSync] replSet info rollback diff in end of log times: -2741 seconds
2015-09-28T05:04:44.212-0500 I REPL     [rsBackgroundSync] replSet rollback error RS100 reached beginning of remote oplog
2015-09-28T05:04:44.212-0500 I REPL     [rsBackgroundSync] replSet   them:      mongo2:27017 (10.0.0.2) scanned: 1
2015-09-28T05:04:44.212-0500 I REPL     [rsBackgroundSync] replSet   theirTime: Sep 28 05:04:41 560910b9:25
2015-09-28T05:04:44.212-0500 I REPL     [rsBackgroundSync] replSet   ourTime:   Sep 28 04:19:00 56090604:a3
2015-09-28T05:04:44.212-0500 E REPL     [rsBackgroundSync] RS100 reached beginning of remote oplog [1]
2015-09-28T05:04:44.220-0500 I -        [rsBackgroundSync] Fatal Assertion 18752
2015-09-28T05:04:44.221-0500 I -        [rsBackgroundSync]

***aborting after fassert() failure

      Since that, my mongo was trying to init but every time this error occurs:

      2015-09-28T13:16:32.081-0500 E REPL     [rsBackgroundSync] sync producer problem: 10278 dbclient error communicating with server: mongo2:27017
2015-09-28T13:16:32.081-0500 I REPL     [ReplicationExecutor] syncing from: mongo2:27017
2015-09-28T13:16:32.973-0500 I REPL     [rsBackgroundSync] replSet our last op time fetched: Sep 28 04:19:00:a3
2015-09-28T13:16:32.973-0500 I REPL     [rsBackgroundSync] replset source's GTE: Sep 28 04:19:01:1
2015-09-28T13:16:32.973-0500 I REPL     [rsBackgroundSync] beginning rollback
2015-09-28T13:16:32.973-0500 I REPL     [rsBackgroundSync] rollback 0
2015-09-28T13:16:32.973-0500 I REPL     [rsBackgroundSync] rollback 1
2015-09-28T13:16:32.973-0500 I REPL     [rsBackgroundSync] rollback 2 FindCommonPoint
2015-09-28T13:16:33.402-0500 I REPL     [rsBackgroundSync] replSet info rollback our last optime:   Sep 28 04:19:00:a3
2015-09-28T13:16:33.403-0500 I REPL     [rsBackgroundSync] replSet info rollback their last optime: Sep 28 13:16:27:2f
2015-09-28T13:16:33.403-0500 I REPL     [rsBackgroundSync] replSet info rollback diff in end of log times: -32247 seconds
2015-09-28T13:16:33.403-0500 I REPL     [rsBackgroundSync] replSet rollback error RS100 reached beginning of remote oplog
2015-09-28T13:16:33.403-0500 I REPL     [rsBackgroundSync] replSet   them:      mongo2:27017 (10.0.0.2) scanned: 1
2015-09-28T13:16:33.403-0500 I REPL     [rsBackgroundSync] replSet   theirTime: Sep 28 13:16:27 560983fb:2f
2015-09-28T13:16:33.403-0500 I REPL     [rsBackgroundSync] replSet   ourTime:   Sep 28 04:19:00 56090604:a3
2015-09-28T13:16:33.403-0500 E REPL     [rsBackgroundSync] RS100 reached beginning of remote oplog [1]
2015-09-28T13:16:33.403-0500 I -        [rsBackgroundSync] Fatal Assertion 18752
2015-09-28T13:16:33.403-0500 I -        [rsBackgroundSync]

***aborting after fassert() failure

      What is going on?

            Assignee:
            Unassigned Unassigned
            Reporter:
            lucasoares Lucas
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: