Thursday, June 2, 2016

Restart the mongod with an empty data directory and let MongoDB’s initial syncing

MongoDB provides two options for performing an initial sync:

Restart the mongod with an empty data directory and let MongoDB’s normal initial syncing feature restore the data. This is the more simple option but may take longer to replace the data.
See Procedures.
Restart the machine with a copy of a recent data directory from another member in the replica set. This procedure can replace the data more quickly but requires more manual steps.
See Sync by Copying Data Files from Another Member.


donghua@vmxdb01:~/week2$ mongo localhost:30001
MongoDB shell version: 3.0.5
connecting to: localhost:30001/test
Server has startup warnings:
CorruptionTest:PRIMARY> use testDB
switched to db testDB
CorruptionTest:PRIMARY> db.BlogColl.find().explain("executionStats")
{
        "queryPlanner" : {
                "plannerVersion" : 1,
                "namespace" : "testDB.BlogColl",
                "indexFilterSet" : false,
                "parsedQuery" : {
                        "$and" : [ ]
                },
                "winningPlan" : {
                        "stage" : "COLLSCAN",
                        "filter" : {
                                "$and" : [ ]
                        },
                        "direction" : "forward"
                },
                "rejectedPlans" : [ ]
        },
        "executionStats" : {
                "executionSuccess" : true,
                "nReturned" : 100000,
                "executionTimeMillis" : 552,
                "totalKeysExamined" : 0,
                "totalDocsExamined" : 100000,
                "executionStages" : {
                        "stage" : "COLLSCAN",
                        "filter" : {
                                "$and" : [ ]
                        },
                        "nReturned" : 100000,
                        "executionTimeMillisEstimate" : 70,
                        "works" : 100195,
                        "advanced" : 100000,
                        "needTime" : 1,
                        "needFetch" : 193,
                        "saveState" : 969,
                        "restoreState" : 969,
                        "isEOF" : 1,
                        "invalidates" : 0,
                        "direction" : "forward",
                        "docsExamined" : 100000
                }
        },
        "serverInfo" : {
                "host" : "vmxdb01",
                "port" : 30001,
                "version" : "3.0.5",
                "gitVersion" : "8bc4ae20708dbb493cb09338d9e7be6698e4a3a3"
        },
        "ok" : 1
}
CorruptionTest:PRIMARY>
bye
donghua@vmxdb01:~/week2$ mongo localhost:30002
MongoDB shell version: 3.0.5
connecting to: localhost:30002/test
Server has startup warnings:
CorruptionTest:SECONDARY> rs.slaveOk();
CorruptionTest:SECONDARY> use testDB;
switched to db testDB
CorruptionTest:SECONDARY> db.BlogColl.find().explain("executionStats")
2016-06-02T12:40:03.041+0100 E QUERY    Error: explain failed: {
        "errmsg" : "exception: BSONObj size: 1685417573 (0x64756E65) is invalid. Size must be between 0 and 16793600(16MB) First element: //drrdu/dvad\u0002string: ?type=111",
        "code" : 10334,
        "ok" : 0
}
    at Error ()
    at Function.throwOrReturn (src/mongo/shell/explainable.js:34:19)
    at constructor.finish (src/mongo/shell/explain_query.js:188:36)
    at DBQuery.explain (src/mongo/shell/query.js:434:25)
    at (shell):1:20 at src/mongo/shell/explainable.js:34

               
donghua@vmxdb01:~/week2$ cd mongod-sec/
donghua@vmxdb01:~/week2/mongod-sec$ ls
journal  local.0  local.1  local.ns  mongod.lock  storage.bson  testDB.0  testDB.1  testDB.2  testDB.ns
donghua@vmxdb01:~/week2/mongod-sec$ ls -ltr
total 426012
-rw------- 1 m202 m202  16777216 May  7  2014 testDB.ns
-rw------- 1 m202 m202  67108864 May  7  2014 testDB.2
-rw------- 1 m202 m202 268435456 May  7  2014 local.1
-rw------- 1 m202 m202  33554432 May  8  2014 testDB.1
drwxr-xr-x 2 m202 m202      4096 May  8  2014 journal
-rw-rw-r-- 1 m202 m202        69 Jun  2 12:22 storage.bson
-rw------- 1 m202 m202  16777216 Jun  2 12:22 testDB.0
-rw------- 1 m202 m202  16777216 Jun  2 12:39 local.ns
-rw------- 1 m202 m202  16777216 Jun  2 12:39 local.0
-rwxr-xr-x 1 m202 m202         0 Jun  2 12:40 mongod.lock
donghua@vmxdb01:~/week2/mongod-sec$ rm -rf *


donghua@vmxdb01:~/week2/mongod-sec$ mongod --port 30002 --dbpath /mongo/wk2/mongod-sec --replSet CorruptionTest --smallfiles --oplogSize 128 --nojournal
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] MongoDB starting : pid=4057 port=30002 dbpath=/mongo/wk2/mongod-sec 64-bit host=vmxdb01
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten]
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten]
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] **        We suggest setting it to 'never'
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten]
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] db version v3.0.5
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] git version: 8bc4ae20708dbb493cb09338d9e7be6698e4a3a3
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] build info: Linux ip-10-183-35-50 3.13.0-24-generic #46-Ubuntu SMP Thu Apr 10 19:11:08 UTC 2014 x86_64 BOOST_LIB_VERSION=1_49
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] allocator: tcmalloc
2016-06-02T12:41:36.913+0100 I CONTROL  [initandlisten] options: { net: { port: 30002 }, replication: { oplogSizeMB: 128, replSet: "CorruptionTest" }, storage: { dbPath: "/mongo/wk2/mongod-sec", journal: { enabled: false }, mmapv1: { smallFiles: true } } }
2016-06-02T12:41:36.913+0100 I INDEX    [initandlisten] allocating new ns file /mongo/wk2/mongod-sec/local.ns, filling with zeroes...
2016-06-02T12:41:37.102+0100 I STORAGE  [FileAllocator] allocating new datafile /mongo/wk2/mongod-sec/local.0, filling with zeroes...
2016-06-02T12:41:37.102+0100 I STORAGE  [FileAllocator] creating directory /mongo/wk2/mongod-sec/_tmp
2016-06-02T12:41:37.117+0100 I STORAGE  [FileAllocator] done allocating datafile /mongo/wk2/mongod-sec/local.0, size: 16MB,  took 0.012 secs
2016-06-02T12:41:37.125+0100 I REPL     [initandlisten] Did not find local replica set configuration document at startup;  NoMatchingDocument Did not find replica set configuration document in local.system.replset
2016-06-02T12:41:37.127+0100 I NETWORK  [initandlisten] waiting for connections on port 30002
2016-06-02T12:41:37.991+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:43789 #1 (1 connection now open)
2016-06-02T12:41:37.992+0100 I NETWORK  [initandlisten] connection accepted from 127.0.0.1:43790 #2 (2 connections now open)
2016-06-02T12:41:38.010+0100 I REPL     [WriteReplSetConfig] Starting replication applier threads
2016-06-02T12:41:38.011+0100 I REPL     [ReplicationExecutor] New replica set config in use: { _id: "CorruptionTest", version: 3, members: [ { _id: 0, host: "127.0.0.1:30001", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.0, tags: {}, slaveDelay: 0, votes: 1 }, { _id: 1, host: "127.0.0.1:30002", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.0, tags: {}, slaveDelay: 0, votes: 1 }, { _id: 2, host: "127.0.0.1:30003", arbiterOnly: true, buildIndexes: true, hidden: false, priority: 1.0, tags: {}, slaveDelay: 0, votes: 1 } ], settings: { chainingAllowed: true, heartbeatTimeoutSecs: 10, getLastErrorModes: {}, getLastErrorDefaults: { w: 1, wtimeout: 0 } } }
2016-06-02T12:41:38.012+0100 I REPL     [ReplicationExecutor] This node is 127.0.0.1:30002 in the config
2016-06-02T12:41:38.013+0100 I REPL     [ReplicationExecutor] transition to STARTUP2
2016-06-02T12:41:38.015+0100 I REPL     [ReplicationExecutor] Member 127.0.0.1:30003 is now in state ARBITER
2016-06-02T12:41:38.016+0100 I REPL     [ReplicationExecutor] Member 127.0.0.1:30001 is now in state PRIMARY
2016-06-02T12:41:38.017+0100 I REPL     [rsSync] ******
2016-06-02T12:41:38.018+0100 I REPL     [rsSync] creating replication oplog of size: 128MB...
2016-06-02T12:41:38.018+0100 I STORAGE  [FileAllocator] allocating new datafile /mongo/wk2/mongod-sec/local.1, filling with zeroes...
2016-06-02T12:41:38.053+0100 I STORAGE  [FileAllocator] done allocating datafile /mongo/wk2/mongod-sec/local.1, size: 256MB,  took 0.033 secs
2016-06-02T12:41:38.079+0100 I REPL     [rsSync] ******
2016-06-02T12:41:38.079+0100 I REPL     [rsSync] initial sync pending
2016-06-02T12:41:38.080+0100 I REPL     [ReplicationExecutor] syncing from: 127.0.0.1:30001
2016-06-02T12:41:38.082+0100 I REPL     [rsSync] initial sync drop all databases
2016-06-02T12:41:38.082+0100 I STORAGE  [rsSync] dropAllDatabasesExceptLocal 1
2016-06-02T12:41:38.083+0100 I REPL     [rsSync] initial sync clone all databases
2016-06-02T12:41:38.083+0100 I REPL     [rsSync] initial sync cloning db: testDB
2016-06-02T12:41:38.086+0100 I INDEX    [rsSync] allocating new ns file /mongo/wk2/mongod-sec/testDB.ns, filling with zeroes...
2016-06-02T12:41:38.166+0100 I STORAGE  [FileAllocator] allocating new datafile /mongo/wk2/mongod-sec/testDB.0, filling with zeroes...
2016-06-02T12:41:38.170+0100 I STORAGE  [FileAllocator] done allocating datafile /mongo/wk2/mongod-sec/testDB.0, size: 16MB,  took 0.003 secs
2016-06-02T12:41:38.311+0100 I STORAGE  [FileAllocator] allocating new datafile /mongo/wk2/mongod-sec/testDB.1, filling with zeroes...
2016-06-02T12:41:38.315+0100 I STORAGE  [FileAllocator] done allocating datafile /mongo/wk2/mongod-sec/testDB.1, size: 32MB,  took 0.003 secs
2016-06-02T12:41:38.331+0100 I INDEX    [rsSync] build index on: testDB.BlogColl properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "testDB.BlogColl" }
2016-06-02T12:41:38.332+0100 I INDEX    [rsSync]         building index using bulk method
2016-06-02T12:41:38.546+0100 I INDEX    [rsSync] build index done.  scanned 100000 total records. 0 secs
2016-06-02T12:41:38.548+0100 I REPL     [rsSync] initial sync data copy, starting syncup
2016-06-02T12:41:38.549+0100 I REPL     [rsSync] oplog sync 1 of 3
2016-06-02T12:41:38.549+0100 I REPL     [rsSync] oplog sync 2 of 3
2016-06-02T12:41:38.550+0100 I REPL     [rsSync] initial sync building indexes
2016-06-02T12:41:38.550+0100 I REPL     [rsSync] initial sync cloning indexes for : testDB
2016-06-02T12:41:38.551+0100 I STORAGE  [rsSync] copying indexes for: { name: "BlogColl", options: {} }
2016-06-02T12:41:38.552+0100 I REPL     [rsSync] oplog sync 3 of 3
2016-06-02T12:41:38.554+0100 I REPL     [rsSync] initial sync finishing up
2016-06-02T12:41:38.554+0100 I REPL     [rsSync] replSet set minValid=536aac95:1ba5
2016-06-02T12:41:38.554+0100 I REPL     [rsSync] initial sync done
2016-06-02T12:41:38.558+0100 I REPL     [ReplicationExecutor] transition to RECOVERING
2016-06-02T12:41:38.558+0100 I REPL     [ReplicationExecutor] transition to SECONDARY
2016-06-02T12:41:39.018+0100 I REPL     [ReplicationExecutor] could not find member to sync from


CorruptionTest:SECONDARY> rs.slaveOk();
CorruptionTest:SECONDARY> use testDB;
switched to db testDB
CorruptionTest:SECONDARY> db.BlogColl.find().explain("executionStats")
{
        "queryPlanner" : {
                "plannerVersion" : 1,
                "namespace" : "testDB.BlogColl",
                "indexFilterSet" : false,
                "parsedQuery" : {
                        "$and" : [ ]
                },
                "winningPlan" : {
                        "stage" : "COLLSCAN",
                        "filter" : {
                                "$and" : [ ]
                        },
                        "direction" : "forward"
                },
                "rejectedPlans" : [ ]
        },
        "executionStats" : {
                "executionSuccess" : true,
                "nReturned" : 100000,
                "executionTimeMillis" : 27,
                "totalKeysExamined" : 0,
                "totalDocsExamined" : 100000,
                "executionStages" : {
                        "stage" : "COLLSCAN",
                        "filter" : {
                                "$and" : [ ]
                        },
                        "nReturned" : 100000,
                        "executionTimeMillisEstimate" : 10,
                        "works" : 100002,
                        "advanced" : 100000,
                        "needTime" : 1,
                        "needFetch" : 0,
                        "saveState" : 781,
                        "restoreState" : 781,
                        "isEOF" : 1,
                        "invalidates" : 0,
                        "direction" : "forward",
                        "docsExamined" : 100000
                }
        },
        "serverInfo" : {
                "host" : "vmxdb01",
                "port" : 30002,
                "version" : "3.0.5",
                "gitVersion" : "8bc4ae20708dbb493cb09338d9e7be6698e4a3a3"
        },
        "ok" : 1
}
CorruptionTest:SECONDARY>