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

Rollback Throws Continuous Warnings And Does Not Appear To Be Completing

    • Type: Icon: Bug Bug
    • Resolution: Duplicate
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 2.0.9
    • Component/s: Replication
    • Labels:
      None
    • Environment:
      Centos 5.6 Rackspace Cloud
    • ALL

      Secondary went into rollback mode, then generates a massive amount of logs (~18GB in less than 16 hours).

      Sun Apr 28 14:06:41 [conn219706] command: unlock requested
      Sun Apr 28 14:06:41 [rsSync] repl: old cursor isDead, will initiate a new one
      Sun Apr 28 14:06:42 [rsSync] replSet syncing to: [primary address]:27017
      Sun Apr 28 14:06:42 [rsSync] replSet our last op time written: Apr 28 12:01:41:1f
      Sun Apr 28 14:06:42 [rsSync] replset source's GTE: Apr 28 13:01:00:20
      Sun Apr 28 14:06:42 [rsSync] replSet rollback 0
      Sun Apr 28 14:06:42 [rsSync] replSet ROLLBACK
      Sun Apr 28 14:06:42 [rsSync] replSet rollback 1
      Sun Apr 28 14:06:42 [rsSync] replSet rollback 2 FindCommonPoint
      Sun Apr 28 14:06:42 [rsSync] replSet info rollback our last optime: Apr 28 12:01:41:1f
      Sun Apr 28 14:06:42 [rsSync] replSet info rollback their last optime: Apr 28 14:06:42:22
      Sun Apr 28 14:06:42 [rsSync] replSet info rollback diff in end of log times: -7501 seconds

      FOLLOWED BY COUNTLESS SIMILAR TO:
      Sun Apr 28 16:50:07 [rsSync] replSet WARNING ignoring op on rollback no _id TODO : inv.system.indexes
      { ts: Timestamp 1367150501000|31, h: -3893062772133308244, op: "i", ns: "inv.system.indexes", o: { u
      nique: true, ns: "inv.fs.configs.chunks", name: "files_id_1_n_1", key:

      { files_id: 1, n: 1 }

      } }

      THEN THIS:
      Sun Apr 28 16:49:08 [rsSync] replSet rollback error RS101 reached beginning of local oplog
      Sun Apr 28 16:49:08 [rsSync] replSet them: [primary address]:27017 scanned: 40993835
      Sun Apr 28 16:49:08 [rsSync] replSet theirTime: Jul 16 09:03:02 5003d8c6:13
      Sun Apr 28 16:49:08 [rsSync] replSet ourTime: Apr 19 00:01:27 51708957:17
      Sun Apr 28 16:49:08 [rsSync] replSet rollback 2 error RS101 reached beginning of local oplog [2]
      Sun Apr 28 16:50:04 [rsSync] replSet syncing to: [primary address]:27017
      Sun Apr 28 16:50:05 [rsSync] replSet our last op time written: Apr 28 12:01:41:1f
      Sun Apr 28 16:50:05 [rsSync] replset source's GTE: Apr 28 13:01:00:20
      Sun Apr 28 16:50:05 [rsSync] replSet rollback 0
      Sun Apr 28 16:50:05 [rsSync] replSet rollback 1
      Sun Apr 28 16:50:05 [rsSync] replSet rollback 2 FindCommonPoint
      Sun Apr 28 16:50:05 [rsSync] replSet info rollback our last optime: Apr 28 12:01:41:1f
      Sun Apr 28 16:50:05 [rsSync] replSet info rollback their last optime: Apr 28 16:50:05:6
      Sun Apr 28 16:50:05 [rsSync] replSet info rollback diff in end of log times: -17304 seconds

      It seems to simply repeat these patterns.

            Assignee:
            gianfranco Gianfranco Palumbo
            Reporter:
            stuartr Stuart Rench
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved: