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 
} 
] 
}

12345678910111213141516171819202122232425262728293031323334

){,,[{,,{,,{,,{,,true,{,,true,{,,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: <a href=”http://www.ttlsa.com/linux/”>Linux</a> 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 <a href=”http://www.ttlsa.com/shell/”>shell</a> — 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

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184

982801exceptionDOWNexceptionDOWNexceptionDOWNexceptionDOWNexceptionDOWNupARBITERupSECONDARYupARBITERupSECONDARYupARBITERPRIMARY20011endsexiting:.78920011.sock......20011]slaveTracking20011%%finished.removeJournalFiles.now*com4.5329f3c47fe8136c03392c8f0e548506cb21f8ebf#1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_41}journalneeded4.488.127.96012)done2001220011200122001120012locallyreplset.upupupupPRIMARYARBITERARBITERupSECONDARYARBITER secs*pending20011}secsdatabases1databasesadmin TASK_SUCCESS}413735%%%.%secs%.%commitsecs}secs}secs}secs4342053464575TASK_SUCCESS201211 primary}565213%.%secs commit_115_116659mssecsprimary}%.%secs%%.%secs%.%commit 1695ms secsprimary.}%.commit_159_160secsminValidd21c8.12320011]2001120011)applyoplog]]failedDOWNpending20011databases3removeJournalFilesremoveJournalFilesleak

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

12345678

eup20}secsdone20011SECONDARY

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

1234567891011121314151617181920212223242526272829303132333435363738394041424344454647484950515253

failed,}DOWNfailed,}DOWN‘t see a majority of the set, relinquishing primaryMon Dec 24 10:52:57 [rsMgr] replSet relinquishing primary stateMon Dec 24 10:52:57 [rsMgr] replSet SECONDARYMon Dec 24 10:52:57 [rsMgr] replSet closing client sockets after reqlinquishing primaryMon Dec 24 10:52:57 [rsHealthPoll] replSet info 10.0.0.106:20012 is down (or slow to respond): socket exceptionMon Dec 24 10:52:57 [rsHealthPoll] replSet member 10.0.0.106:20012 is now in state DOWNselfexceptionDOWNupARBITERupARBITER685986upSECONDARYveto1PRIMARYfailed,}DOWNprimarystateSECONDARYprimaryexceptionDOWNexceptionDOWNupARBITERupARBITERupSECONDARYveto1PRIMARY685986upSTARTUP2ARBITER685986

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

123456789101112

*open:.......finishednow

http://duoyun.org/topic/51ceaffa0acf7bac02001f4b