-
Type:
Bug
-
Resolution: Done
-
Priority:
Critical - P2
-
None
-
Affects Version/s: 3.0.5
-
Component/s: Replication
-
None
-
ALL
MongoDB v3.0.5 replica set (2 servers 1 arbiter)
After creating several indexes and very little replication lag (5 mins), a failover occurred, the secondary server was then stuck in the rollback state with the last line showing 'rollback 3 fixup'. the only fix seems to be restoring from a previous backup and then re-syncing...
note the warnings in the log
2016-01-11T14:23:29.914+0000 I REPL [rsBackgroundSync] replSet our last op time fetched: Jan 11 13:45:14:1
2016-01-11T14:23:29.914+0000 I REPL [rsBackgroundSync] replset source's GTE: Jan 11 13:49:34:1
2016-01-11T14:23:29.914+0000 I REPL [rsBackgroundSync] beginning rollback
2016-01-11T14:23:29.914+0000 I REPL [rsBackgroundSync] rollback 0
2016-01-11T14:23:29.914+0000 I REPL [ReplicationExecutor] transition to ROLLBACK
2016-01-11T14:23:29.914+0000 I REPL [rsBackgroundSync] rollback 1
2016-01-11T14:23:29.914+0000 I REPL [rsBackgroundSync] rollback 2 FindCommonPoint
2016-01-11T14:23:30.273+0000 I REPL [rsBackgroundSync] replSet info rollback our last optime: Jan 11 13:45:14:1
2016-01-11T14:23:30.273+0000 I REPL [rsBackgroundSync] replSet info rollback their last optime: Jan 11 14:23:15:1
2016-01-11T14:23:30.273+0000 I REPL [rsBackgroundSync] replSet info rollback diff in end of log times: -2281 seconds
2016-01-11T14:23:38.430+0000 W REPL [rsBackgroundSync] ignoring op with no _id during rollback. ns: JER_DB.system.indexes, document: { ts: Timestamp 1452519153000|2, h: -6306293468986696903, v: 2, op: "i", ns: "JER_DB.system.indexes", o: { name: "uuid_state_1", ns: "JER_DB.Celery_log", unique: true, key: { uuid: 1, state: 1 } } }
2016-01-11T14:23:38.436+0000 W REPL [rsBackgroundSync] replSet info rollback of dropIndexes is slow in this version of mongod
2016-01-11T14:23:38.445+0000 W REPL [rsBackgroundSync] ignoring op with no _id during rollback. ns: JER_DB.system.indexes, document: { ts: Timestamp 1452518828000|1, h: -4918113476754073791, v: 2, op: "i", ns: "JER_DB.system.indexes", o: { name: "uuid_1", ns: "JER_DB.Celery_log", key: { uuid: 1 } } }
2016-01-11T14:23:38.986+0000 W REPL [rsBackgroundSync] ignoring op with no _id during rollback. ns: JER_SIGNALS.system.indexes, document: { ts: Timestamp 1452518673000|4, h: -8456178278876933663, v: 2, op: "i", ns: "JER_SIGNALS.system.indexes", o: { ns: "JER_SIGNALS.test_ndfd_weather_forecast_", name: "ts_1", key: { ts: 1 } } }
2016-01-11T14:23:38.986+0000 W REPL [rsBackgroundSync] ignoring op with no _id during rollback. ns: JER_SIGNALS.system.indexes, document: { ts: Timestamp 1452518673000|3, h: 1746040611747149689, v: 2, op: "i", ns: "JER_SIGNALS.system.indexes", o: { ns: "JER_SIGNALS.test_ndfd_weather_forecast_", unique: true, name: "pid_ts_1_1", key: { pid: 1, ts: 1 } } }
2016-01-11T14:23:41.113+0000 I REPL [rsBackgroundSync] replSet rollback found matching events at Jan 11 13:12:04:b0
2016-01-11T14:23:41.113+0000 I REPL [rsBackgroundSync] replSet rollback findcommonpoint scanned : 105683
2016-01-11T14:23:41.144+0000 I REPL [rsBackgroundSync] replSet rollback 3 fixup
- related to
-
SERVER-22179 Log progress during rollback 3 fixup
-
- Closed
-