-
Type: Bug
-
Resolution: Done
-
Priority: Critical - P2
-
Affects Version/s: 3.0.0
-
Component/s: Replication, WiredTiger
-
Fully Compatible
-
ALL
-
after re-sync is done, the _id index count, secondary index count and data table count could be different.
"index" : 2000000, "secondary_index" : 2047102, "table" : 2047102
and log file show (with Dan's patch for more printout)
2015-03-06T01:05:28.851+0000 I REPL [rsSync] ****** 2015-03-06T01:05:28.851+0000 I REPL [rsSync] creating replication oplog of size: 4094MB... 2015-03-06T01:05:28.853+0000 I STORAGE [rsSync] Starting WiredTigerRecordStoreThread local.oplog.rs 2015-03-06T01:05:28.870+0000 I REPL [rsSync] ****** 2015-03-06T01:05:28.870+0000 I REPL [rsSync] initial sync pending 2015-03-06T01:05:28.870+0000 I REPL [ReplicationExecutor] syncing from: 10.1.1.107:27017 2015-03-06T01:05:28.874+0000 I REPL [rsSync] initial sync drop all databases 2015-03-06T01:05:28.874+0000 I STORAGE [rsSync] dropAllDatabasesExceptLocal 1 2015-03-06T01:05:28.874+0000 I REPL [rsSync] initial sync clone all databases 2015-03-06T01:05:28.875+0000 I REPL [rsSync] initial sync cloning db: sbtest 2015-03-06T01:05:42.605+0000 I INDEX [rsSync] build index on: sbtest.sbtest1 properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "sbtest.sbtest1" } 2015-03-06T01:05:42.605+0000 I INDEX [rsSync] building index using bulk method 2015-03-06T01:05:47.969+0000 I INDEX [rsSync] build index done. scanned 2047128 total records. 5 secs 2015-03-06T01:05:47.969+0000 I STORAGE [rsSync] Deleting: RecordId(1955618) 2015-03-06T01:05:47.969+0000 I STORAGE [rsSync] Deleting: RecordId(1955661) 2015-03-06T01:05:47.970+0000 I STORAGE [rsSync] Deleting: RecordId(1955710) 2015-03-06T01:05:47.970+0000 I STORAGE [rsSync] Deleting: RecordId(1955778) 2015-03-06T01:05:47.970+0000 I STORAGE [rsSync] Deleting: RecordId(1955802) 2015-03-06T01:05:47.970+0000 I STORAGE [rsSync] Deleting: RecordId(1955996) 2015-03-06T01:05:47.970+0000 I STORAGE [rsSync] Deleting: RecordId(1956089) 2015-03-06T01:05:47.970+0000 I STORAGE [rsSync] Deleting: RecordId(1956102) 2015-03-06T01:05:47.970+0000 I STORAGE [rsSync] Deleting: RecordId(1956127) 2015-03-06T01:05:47.970+0000 I STORAGE [rsSync] Deleting: RecordId(1956187) 2015-03-06T01:05:47.970+0000 I STORAGE [rsSync] Deleting: RecordId(1956305) .... 2015-03-06T01:05:49.275+0000 I STORAGE [rsSync] Deleting: RecordId(2047128) 2015-03-06T01:05:49.275+0000 I STORAGE [rsSync] index build dropped: 47128 dups 2015-03-06T01:05:49.449+0000 I REPL [rsSync] initial sync data copy, starting syncup 2015-03-06T01:05:49.449+0000 I REPL [rsSync] oplog sync 1 of 3
- not sure why there is dup for _id
- dropped dups are not removed from data table and secondary index tree
- saw one case when mixed traffic stopped, re-sync still have issue with dups and out of sync, but cannot reproduce it now.