mongodb数据库复制集随机同步数据

记一次MongoDB主从切换，重新同步数据。

PRIMARY> rs.conf()

{

"_id" : "poptask",

"version" : 4,

"members" : [

{

"_id" : 0,

"host" : "10.0.0.105:20011"

},

{

"_id" : 1,

"host" : "10.0.0.106:20011"

},

{

"_id" : 2,

"host" : "10.0.0.107:20011"

},

{

"_id" : 3,

"host" : "10.0.0.107:20012",

"arbiterOnly" : true

},

{

"_id" : 4,

"host" : "10.0.0.106:20012",

"arbiterOnly" : true

},

{

"_id" : 5,

"host" : "10.0.0.105:20012",

"arbiterOnly" : true

}

]

}

将主节点从105切换到106，

步骤：

107执行 rs.freeze(),
105执行 rs.stepdown()
切换后的环境：
10.0.0.105(secondary)
10.0.0.106(primary)
10.0.0.107 (secondary)

18号晚上开始切换，105的数据重新同步，数据较快同步完了，昨天在建索引，
今天重新同步107的数据，发现了一点小意外，算是有惊无险。
关掉107的mongod进程后，数据开始同步，此时发现105 down了，105的数据自动删除，然后重新开始同步。
此时停掉105，让107同步完。
经过分析，找到了原因：
1.105上的数据并非是看起来同步完了，关掉107的时刻，105还在做同步；
2.105是从107（从节点）上做的同步，并非是从106主节点同步数据；
3.107关掉时候，105发现连接不到107了，就自己删除已经同步的所有数据，然后从106主节点开始同步数据。
总结：mongodb同步有了新的认识，并非都是从主节点同步数据；即使做切换这样一个简单的操作的时候也要慎重，考虑周全。

105上log:

Tue Dec 18 20:00:15 [clientcursormon] mem (MB) res:61273 virt:1966680 mapped:982801

Tue Dec 18 20:02:48 [rsHealthPoll] replSet info 10.0.0.107:20012 is down (or slow to respond): socket exception

Tue Dec 18 20:02:48 [rsHealthPoll] replSet member 10.0.0.107:20012 is now in state DOWN

Tue Dec 18 20:02:48 [rsHealthPoll] replSet info 10.0.0.107:20011 is down (or slow to respond): socket exception

Tue Dec 18 20:02:48 [rsHealthPoll] replSet member 10.0.0.107:20011 is now in state DOWN

Tue Dec 18 20:02:49 [rsHealthPoll] replSet info 10.0.0.105:20012 is down (or slow to respond): socket exception

Tue Dec 18 20:02:49 [rsHealthPoll] replSet member 10.0.0.105:20012 is now in state DOWN

Tue Dec 18 20:02:49 [rsHealthPoll] replSet info 10.0.0.106:20011 is down (or slow to respond): socket exception

Tue Dec 18 20:02:49 [rsHealthPoll] replSet member 10.0.0.106:20011 is now in state DOWN

Tue Dec 18 20:02:49 [rsHealthPoll] replSet info 10.0.0.106:20012 is down (or slow to respond): socket exception

Tue Dec 18 20:02:49 [rsHealthPoll] replSet member 10.0.0.106:20012 is now in state DOWN

Tue Dec 18 20:02:50 [rsHealthPoll] replSet member 10.0.0.107:20012 is up

Tue Dec 18 20:02:50 [rsHealthPoll] replSet member 10.0.0.107:20012 is now in state ARBITER

Tue Dec 18 20:02:50 [rsHealthPoll] replSet member 10.0.0.107:20011 is up

Tue Dec 18 20:02:50 [rsHealthPoll] replSet member 10.0.0.107:20011 is now in state SECONDARY

Tue Dec 18 20:02:51 [rsHealthPoll] replSet member 10.0.0.105:20012 is up

Tue Dec 18 20:02:51 [rsHealthPoll] replSet member 10.0.0.105:20012 is now in state ARBITER

Tue Dec 18 20:02:51 [rsHealthPoll] replSet member 10.0.0.106:20011 is up

Tue Dec 18 20:02:51 [rsHealthPoll] replSet member 10.0.0.106:20011 is now in state SECONDARY

Tue Dec 18 20:02:51 [rsHealthPoll] replSet member 10.0.0.106:20012 is up

Tue Dec 18 20:02:51 [rsHealthPoll] replSet member 10.0.0.106:20012 is now in state ARBITER

Tue Dec 18 20:02:57 [rsHealthPoll] replSet member 10.0.0.106:20011 is now in state PRIMARY

Tue Dec 18 20:02:57 [rsSync] replSet syncing to: 10.0.0.106:20011

Tue Dec 18 20:04:15 got kill or ctrl c or hup signal 15 (Terminated), will terminate after current cmd ends

Tue Dec 18 20:04:15 [interruptThread] now exiting

Tue Dec 18 20:04:15 dbexit:

Tue Dec 18 20:04:15 [interruptThread] shutdown: going to close listening sockets...

Tue Dec 18 20:04:15 [interruptThread] closing listening socket: 7

Tue Dec 18 20:04:15 [interruptThread] closing listening socket: 8

Tue Dec 18 20:04:15 [interruptThread] closing listening socket: 9

Tue Dec 18 20:04:15 [interruptThread] removing socket file: /tmp/mongodb-20011.sock

Tue Dec 18 20:04:15 [interruptThread] shutdown: going to flush diaglog...

Tue Dec 18 20:04:15 [interruptThread] shutdown: going to close sockets...

Tue Dec 18 20:04:15 [interruptThread] shutdown: waiting for fs preallocator...

Tue Dec 18 20:04:15 [interruptThread] shutdown: lock for final commit...

Tue Dec 18 20:04:15 [interruptThread] shutdown: final commit...

Tue Dec 18 20:04:15 [interruptThread] shutdown: closing all files...

Tue Dec 18 20:04:15 [rsSync] Socket recv() errno:9 Bad file descriptor 10.0.0.106:20011

Tue Dec 18 20:04:15 [rsSync] SocketException: remote: 10.0.0.106:20011 error: 9001 socket exception [1] server [10.0.0.106:20011]

Tue Dec 18 20:04:15 ERROR: Client::shutdown not called: slaveTracking

Tue Dec 18 20:04:15 [rsSync] replSet syncThread: 10278 dbclient error communicating with server: 10.0.0.106:20011

25/491 5%

392/491 79%

Tue Dec 18 20:04:19 [interruptThread] closeAllFiles() finished

Tue Dec 18 20:04:19 [interruptThread] journalCleanup...

Tue Dec 18 20:04:19 [interruptThread] removeJournalFiles

Tue Dec 18 20:04:19 [interruptThread] shutdown: removing fs lock...

Tue Dec 18 20:04:19 dbexit: really exiting now

***** SERVER RESTARTED *****

Tue Dec 18 20:19:24 [initandlisten] MongoDB starting : pid=10105 port=20011 dbpath=/export/data/mongodb_data/ 64-bit host=xxx.com

Tue Dec 18 20:19:24 [initandlisten] db version v2.0.4, pdfile version 4.5

Tue Dec 18 20:19:24 [initandlisten] git version: 329f3c47fe8136c03392c8f0e548506cb21f8ebf

Tue Dec 18 20:19:24 [initandlisten] build info: Linux ip-10-110-9-236 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_41

Tue Dec 18 20:19:24 [initandlisten] options: { dbpath: "/export/data/mongodb_data/", directoryperdb: true, fork: true, keyFile: "/export/data/key/key", logappend: true, logpath: "/export/data/logs/rs.log", maxConns: 12000, port: 20011, replSet: "poptask", rest: true }

Tue Dec 18 20:19:24 [initandlisten] journal dir=/export/data/mongodb_data/journal

Tue Dec 18 20:19:24 [initandlisten] recover : no journal files present, no recovery needed

Tue Dec 18 20:19:24 [initandlisten] preallocateIsFaster=true 4.48

Tue Dec 18 20:19:25 [initandlisten] preallocateIsFaster=true 8.12

Tue Dec 18 20:19:26 [initandlisten] preallocateIsFaster=true 7.96

Tue Dec 18 20:19:26 [initandlisten] preallocating a journal file /export/data/mongodb_data/journal/prealloc.0

Tue Dec 18 20:19:30 [initandlisten] preallocating a journal file /export/data/mongodb_data/journal/prealloc.1

Tue Dec 18 20:19:34 [initandlisten] preallocating a journal file /export/data/mongodb_data/journal/prealloc.2

Tue Dec 18 20:19:37 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)

Tue Dec 18 20:19:37 [rsStart] replSet info you may need to run replSetInitiate -- rs.initiate() in the shell -- if that is not already done

Tue Dec 18 20:19:47 [rsStart] trying to contact 10.0.0.105:20012

Tue Dec 18 20:19:47 [rsStart] trying to contact 10.0.0.106:20011

Tue Dec 18 20:19:47 [rsStart] trying to contact 10.0.0.106:20012

Tue Dec 18 20:19:47 [rsStart] trying to contact 10.0.0.107:20011

Tue Dec 18 20:19:47 [rsStart] trying to contact 10.0.0.107:20012

Tue Dec 18 20:19:47 [rsStart] replSet got config version 4 from a remote, saving locally

Tue Dec 18 20:19:47 [rsStart] replSet info saving a newer config version to local.system.replset

...

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.107:20011 is up

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.106:20011 is up

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.105:20012 is up

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.107:20012 is up

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.106:20011 is now in state PRIMARY

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.105:20012 is now in state ARBITER

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.107:20012 is now in state ARBITER

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.106:20012 is up

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.107:20011 is now in state SECONDARY

Tue Dec 18 20:19:49 [rsHealthPoll] replSet member 10.0.0.106:20012 is now in state ARBITER

 

 

 

Tue Dec 18 20:22:56 [FileAllocator] done allocating datafile /export/data/mongodb_data/local/local.26, size: 2047MB, took 7.54 secs

Tue Dec 18 20:22:58 [rsSync] ******

Tue Dec 18 20:22:58 [rsSync] replSet initial sync pending

Tue Dec 18 20:22:58 [rsSync] replSet syncing to: 10.0.0.107:20011

Tue Dec 18 20:22:58 [rsSync] build index local.me { _id: 1 }

Tue Dec 18 20:22:58 [rsSync] build index done 0 records 0 secs

Tue Dec 18 20:22:58 [rsSync] replSet initial sync drop all databases

Tue Dec 18 20:22:58 [rsSync] dropAllDatabasesExceptLocal 1

Tue Dec 18 20:22:58 [rsSync] replSet initial sync clone all databases

Tue Dec 18 20:22:58 [rsSync] replSet initial sync cloning db: admin

 

Tue Dec 18 23:00:36 [rsSync] 643882501 objects cloned so far from collection poptask_mg.TASK_SUCCESS

Tue Dec 18 23:00:48 [rsSync] build index poptask_mg.TASK_SUCCESS { _id: 1 }

Tue Dec 18 23:00:52 [clientcursormon] mem (MB) res:58149 virt:828136 mapped:413735

2137000/644712203 0%

4484800/644712203 0%

6770300/644712203 1%

...

643722400/644712203 99%

Tue Dec 18 23:48:50 [rsSync] external sort used : 645 files in 2881 secs

116300/644712203 0%

...

643308900/644712203 99%

Wed Dec 19 05:42:30 [rsSync] done building bottom layer, going to commit

Wed Dec 19 05:45:33 [rsSync] build index done 644712203 records 24284.9 secs

Wed Dec 19 05:45:35 [rsSync] build index poptask_mg.TASK_EXPIRED { _id: 1 }

Wed Dec 19 05:45:35 [rsSync] build index done 8 records 0.03 secs

Wed Dec 19 05:45:41 [rsSync] build index poptask_mg.TASK_FAILURE { _id: 1 }

Wed Dec 19 05:45:42 [rsSync] build index done 115927 records 0.62 secs

Wed Dec 19 05:45:42 [rsSync] build index poptask_mg.TASK_TO_DO { _id: 1 }

Wed Dec 19 05:45:42 [rsSync] build index done 0 records 0.01 secs

Wed Dec 19 05:46:35 [clientcursormon] mem (MB) res:25750 virt:869184 mapped:434205

Wed Dec 19 05:46:42 [rsSync] clone poptask_mg.TASK_SUCCESS201211 3464575

Wed Dec 19 05:46:43 [rsSync] 3530351 objects cloned so far from collection poptask_mg.TASK_SUCCESS201211

 

Wed Dec 19 07:31:46 [rsSync] info: indexing in foreground on this replica; was a background index build on the primary

Wed Dec 19 07:31:46 [rsSync] build index poptask_mg.TASK_SUCCESS { taskId: 1.0 }

Wed Dec 19 07:31:49 [clientcursormon] mem (MB) res:53381 virt:1131366 mapped:565213

2164200/644712203 0%

...

643273700/644712203 99%

Wed Dec 19 08:23:09 [rsSync] external sort used : 645 files in 3083 secs

 

Wed Dec 19 13:25:07 [rsSync] done building bottom layer, going to commit

Wed Dec 19 13:25:22 [rsSync] old journal file will be removed: /export/data/mongodb_data/journal/j._115

Wed Dec 19 13:25:22 [rsSync] old journal file will be removed: /export/data/mongodb_data/journal/j._116

Wed Dec 19 13:26:25 [rsSync] DR101 latency warning on journal file open 659ms

Wed Dec 19 13:27:44 [rsSync] build index done 644712203 records 21357.6 secs

Wed Dec 19 13:27:44 [rsSync] info: indexing in foreground on this replica; was a background index build on the primary

Wed Dec 19 13:27:44 [rsSync] build index poptask_mg.TASK_SUCCESS { externalTaskId: 1.0 }

1451500/644712203 0%

...

644000000/644712203 99%

Wed Dec 19 14:34:52 [rsSync] external sort used : 645 files in 4027 secs

96200/644712203 0%

226100/644712203 0%

...

643000000/644712203 99%

Thu Dec 20 02:05:41 [rsSync] external sort used : 645 files in 3595 secs

169700/644712203 0%

...

643867200/644712203 99%

Thu Dec 20 06:44:39 [rsSync] done building bottom layer, going to commit

 

Thu Dec 20 06:46:25 [rsSync] DR101 latency warning on journal file open 1695ms

 

Thu Dec 20 06:47:11 [rsSync] build index done 644712203 records 20485.7 secs

Thu Dec 20 06:47:11 [rsSync] info: indexing in foreground on this replica; was a background index build on the primary

...

Thu Dec 20 06:47:16 [rsSync] build index poptask_mg.TASK_SUCCESS201211 { taskId: 1.0 }

1271200/33636123 3%

...

Thu Dec 20 09:49:13 [rsSync] done building bottom layer, going to commit

Thu Dec 20 09:49:17 [rsSync] old journal file will be removed: /export/data/mongodb_data/journal/j._159

Thu Dec 20 09:49:38 [rsSync] old journal file will be removed: /export/data/mongodb_data/journal/j._160

Thu Dec 20 09:50:01 [rsSync] build index done 197750701 records 2770.61 secs

Thu Dec 20 09:50:01 [rsSync] replSet initial sync query minValid

Thu Dec 20 09:50:12 [rsSync] replSet initial oplog application from 10.0.0.107:20011 starting at Dec 18 20:22:52:11 to Dec 20 09:49:55:d2

Thu Dec 20 09:50:29 [rsSync] replSet initialSyncOplogApplication applied 84000 operations, synced to Dec 18 20:35:44:1c

Thu Dec 20 09:50:40 [rsSync] replSet initialSyncOplogApplication applied 219000 operations, synced to Dec 18 20:59:46:8

...

Thu Dec 20 10:18:29 [rsSync] replSet initialSyncOplogApplication applied 13481000 operations, synced to Dec 20 00:58:42:123

Thu Dec 20 10:18:35 [rsSync] Socket recv() errno:104 Connection reset by peer 10.0.0.107:20011

Thu Dec 20 10:18:35 [rsSync] SocketException: remote: 10.0.0.107:20011 error: 9001 socket exception [1] server [10.0.0.107:20011]

Thu Dec 20 10:18:35 [rsSync] replSet initial sync failing, error applying oplog 10278 dbclient error communicating with server: 10.0.0.107:20011

Thu Dec 20 10:18:35 [rsSync] Socket flush send() errno:32 Broken pipe 10.0.0.107:20011

Thu Dec 20 10:18:35 [rsSync] caught exception (socket exception) in destructor (~PiggyBackData)

Thu Dec 20 10:18:35 [rsSync] replSet initial sync failed during applyoplog

Thu Dec 20 10:18:35 [rsSync] replSet cleaning up [1]

Thu Dec 20 10:18:35 [rsSync] replSet cleaning up [2]

Thu Dec 20 10:18:36 [rsHealthPoll] DBClientCursor::init call() failed

Thu Dec 20 10:18:36 [rsHealthPoll] replSet info 10.0.0.107:20011 is down (or slow to respond): DBClientBase::findN: transport error: 10.0.0.107:20011 query: { replSetHeartbeat: "poptask", v: 4, pv: 1, checkEmpty: false, from: "10.0.0.105:20011" }Thu Dec 20 10:18:36 [rsHealthPoll] replSet member 10.0.0.107:20011 is now in state DOWN

Thu Dec 20 10:18:41 [rsSync] replSet initial sync pending

Thu Dec 20 10:18:41 [rsSync] replSet syncing to: 10.0.0.106:20011

Thu Dec 20 10:18:41 [rsSync] replSet initial sync drop all databases

Thu Dec 20 10:18:41 [rsSync] dropAllDatabasesExceptLocal 3

Thu Dec 20 10:18:41 [rsSync] removeJournalFiles

Thu Dec 20 10:18:42 [rsSync] removeJournalFiles

Thu Dec 20 10:18:43 [conn22750] warning: virtual size (480327MB) - mapped size (471258MB) is large (9003MB). could indicate a memory leak

107重做同步完毕

Sat Dec 22 02:00:07 [rsSync] replSet initialSyncOplogApplication applied 21693000 operations, synced to Dec 22 01:08:12:e

Sat Dec 22 02:00:15 [rsSync] replSet initial sync finishing up

Sat Dec 22 02:00:15 [rsSync] replSet set minValid=50d49943:20

Sat Dec 22 02:00:15 [rsSync] build index local.replset.minvalid { _id: 1 }

Sat Dec 22 02:00:15 [rsSync] build index done 0 records 0.021 secs

Sat Dec 22 02:00:15 [rsSync] replSet initial sync done

Sat Dec 22 02:00:16 [rsSync] replSet syncing to: 10.0.0.106:20011

Sat Dec 22 02:00:16 [rsSync] replSet SECONDARY

107

[root@107 ~]# sync

[root@107 ~]# free -m

total used free shared buffers cached

Mem: 64454 64287 167 0 305 59896

-/+ buffers/cache: 4085 60369

Swap: 16386 560 15825

[root@107 ~]# echo 3 >/proc/sys/vm/drop_caches

[root@107 ~]# free -m

total used free shared buffers cached

Mem: 64454 56087 8367 0 1 52068

-/+ buffers/cache: 4017 60437

Swap: 16386 560 15825

[root@107 ~]# free -g

total used free shared buffers cached

Mem: 62 54 8 0 0 50

-/+ buffers/cache: 3 59

Swap: 16 0 15

numactl --interleave=all /export/servers/mongodb/bin/mongod --replSet poptask --keyFile /export/data/key/key --port 20011 --dbpath /export/data/mongodb_data/ --logpath /export/data/logs/rs.log --logappend --rest --directoryperdb --maxConns 12000 --fork

root 11095 9799 0 10:51 pts/0 00:00:00 grep mongo

numactl --interleave=all /export/servers/mongodb/bin/mongod -f /export/servers/mongodb/etc/arbiter.cnf

[root@107 ~]#init 6

[root@107 ~]# free -m

total used free shared buffers cached

Mem: 64454 430 64024 0 13 251

-/+ buffers/cache: 166 64288

Swap: 16386 0 16386

107重启后（此时105mongod是停掉的，arbiter启动状态），主节点106降级了，应用不能写了，这算是一个事故。
降级原因，整个副本集一半成员都是down掉的。
106:

Mon Dec 24 10:52:30 [rsHealthPoll] DBClientCursor::init call() failed

Mon Dec 24 10:52:30 [rsHealthPoll] replSet info 10.0.0.107:20011 is down (or slow to respond): DBClientBase::findN: transport error: 10.0.0.107:20011 query: { replSetHeartbeat: "poptask",

v: 4, pv: 1, checkEmpty: false, from: "10.0.0.106:20011" }

Mon Dec 24 10:52:30 [rsHealthPoll] replSet member 10.0.0.107:20011 is now in state DOWN

Mon Dec 24 10:52:37 [rsHealthPoll] DBClientCursor::init call() failed

Mon Dec 24 10:52:37 [rsHealthPoll] replSet info 10.0.0.107:20012 is down (or slow to respond): DBClientBase::findN: transport error: 10.0.0.107:20012 query: { replSetHeartbeat: "poptask",

v: 4, pv: 1, checkEmpty: false, from: "10.0.0.106:20011" }

Mon Dec 24 10:52:37 [rsHealthPoll] replSet member 10.0.0.107:20012 is now in state DOWN

Mon Dec 24 10:52:57 [rsMgr] can't see a majority of the set, relinquishing primary

Mon Dec 24 10:52:57 [rsMgr] replSet relinquishing primary state

Mon Dec 24 10:52:57 [rsMgr] replSet SECONDARY

Mon Dec 24 10:52:57 [rsMgr] replSet closing client sockets after reqlinquishing primary

Mon Dec 24 10:52:57 [rsHealthPoll] replSet info 10.0.0.106:20012 is down (or slow to respond): socket exception

Mon Dec 24 10:52:57 [rsHealthPoll] replSet member 10.0.0.106:20012 is now in state DOWN

Mon Dec 24 10:52:57 [rsMgr] replSet can't see a majority, will not try to elect self

Mon Dec 24 10:52:59 [rsHealthPoll] replSet info 10.0.0.105:20012 is down (or slow to respond): socket exception

Mon Dec 24 10:52:59 [rsHealthPoll] replSet member 10.0.0.105:20012 is now in state DOWN

Mon Dec 24 10:52:59 [rsHealthPoll] replSet member 10.0.0.106:20012 is up

Mon Dec 24 10:52:59 [rsHealthPoll] replSet member 10.0.0.106:20012 is now in state ARBITER

Mon Dec 24 10:53:01 [rsHealthPoll] replSet member 10.0.0.105:20012 is up

Mon Dec 24 10:53:01 [rsHealthPoll] replSet member 10.0.0.105:20012 is now in state ARBITER

Mon Dec 24 10:56:08 [clientcursormon] mem (MB) res:60093 virt:1373714 mapped:685986

Mon Dec 24 10:57:53 [rsHealthPoll] replSet member 10.0.0.107:20011 is up

Mon Dec 24 10:57:53 [rsHealthPoll] replSet member 10.0.0.107:20011 is now in state SECONDARY

Mon Dec 24 10:57:53 [rsMgr] not electing self, 10.0.0.105:20012 would veto

Mon Dec 24 10:57:58 [rsMgr] replSet info electSelf 1

Mon Dec 24 10:57:58 [rsMgr] replSet PRIMARY

Mon Dec 24 10:58:45 [rsHealthPoll] DBClientCursor::init call() failed

Mon Dec 24 10:58:45 [rsHealthPoll] replSet info 10.0.0.107:20011 is down (or slow to respond): DBClientBase::findN: transport error: 10.0.0.107:20011 query: { replSetHeartbeat: "poptask",

v: 4, pv: 1, checkEmpty: false, from: "10.0.0.106:20011" }

Mon Dec 24 10:58:45 [rsHealthPoll] replSet member 10.0.0.107:20011 is now in state DOWN

Mon Dec 24 10:59:05 [rsMgr] can't see a majority of the set, relinquishing primary

Mon Dec 24 10:59:05 [rsMgr] replSet relinquishing primary state

Mon Dec 24 10:59:05 [rsMgr] replSet SECONDARY

Mon Dec 24 10:59:05 [rsMgr] replSet closing client sockets after reqlinquishing primary

Mon Dec 24 10:59:05 [rsHealthPoll] replSet info 10.0.0.105:20012 is down (or slow to respond): socket exception

Mon Dec 24 10:59:05 [rsHealthPoll] replSet member 10.0.0.105:20012 is now in state DOWN

Mon Dec 24 10:59:06 [rsHealthPoll] replSet info 10.0.0.106:20012 is down (or slow to respond): socket exception

Mon Dec 24 10:59:06 [rsHealthPoll] replSet member 10.0.0.106:20012 is now in state DOWN

Mon Dec 24 10:59:07 [rsHealthPoll] replSet member 10.0.0.105:20012 is up

Mon Dec 24 10:59:07 [rsHealthPoll] replSet member 10.0.0.105:20012 is now in state ARBITER

Mon Dec 24 10:59:08 [rsHealthPoll] replSet member 10.0.0.106:20012 is up

Mon Dec 24 10:59:08 [rsHealthPoll] replSet member 10.0.0.106:20012 is now in state ARBITER

Mon Dec 24 10:59:41 [rsHealthPoll] replSet member 10.0.0.107:20011 is up

Mon Dec 24 10:59:41 [rsHealthPoll] replSet member 10.0.0.107:20011 is now in state SECONDARY

Mon Dec 24 10:59:41 [rsMgr] not electing self, 10.0.0.105:20012 would veto

Mon Dec 24 10:59:46 [rsMgr] replSet info electSelf 1

Mon Dec 24 10:59:46 [rsMgr] replSet PRIMARY

Mon Dec 24 11:01:08 [clientcursormon] mem (MB) res:60108 virt:1373684 mapped:685986

Mon Dec 24 11:01:14 [rsHealthPoll] replSet member 10.0.0.107:20012 is up

Mon Dec 24 11:01:14 [rsHealthPoll] replSet member 10.0.0.107:20012 is now in state STARTUP2

Mon Dec 24 11:01:16 [rsHealthPoll] replSet member 10.0.0.107:20012 is now in state ARBITER

Mon Dec 24 11:06:08 [clientcursormon] mem (MB) res:60132 virt:1373462 mapped:685986

105升级操作系统后

***** SERVER RESTARTED *****

Mon Dec 24 16:15:23 permissions on /export/data/mongodb/key/key are too open

Mon Dec 24 16:15:23 dbexit:

Mon Dec 24 16:15:23 shutdown: going to close listening sockets...

Mon Dec 24 16:15:23 shutdown: going to flush diaglog...

Mon Dec 24 16:15:23 shutdown: going to close sockets...

Mon Dec 24 16:15:23 shutdown: waiting for fs preallocator...

Mon Dec 24 16:15:23 shutdown: lock for final commit...

Mon Dec 24 16:15:23 shutdown: final commit...

Mon Dec 24 16:15:23 shutdown: closing all files...

Mon Dec 24 16:15:23 closeAllFiles() finished

Mon Dec 24 16:15:23 dbexit: really exiting now