0

进行服务的压力测试,测试一段时间后,突然发现服务处理能力下来。用top查看,如下:
top – 21:12:11 up 161 days, 4:35, 5 users, load average: 203.58, 211.83, 210.21
Tasks: 202 total, 2 running, 200 sleeping, 0 stopped, 0 zombie
Cpu0 : 73.5%us, 22.8%sy, 0.0%ni, 0.3%id, 0.0%wa, 0.0%hi, 3.3%si, 0.0%st
Cpu1 : 77.9%us, 21.8%sy, 0.0%ni, 0.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu2 : 73.6%us, 25.4%sy, 0.0%ni, 1.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu3 : 76.7%us, 23.3%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu4 : 71.9%us, 27.4%sy, 0.0%ni, 0.7%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu5 : 75.6%us, 24.4%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu6 : 72.9%us, 26.4%sy, 0.0%ni, 0.7%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu7 : 73.9%us, 25.4%sy, 0.0%ni, 0.7%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 65920984k total, 65651256k used, 269728k free, 79804k buffers
Swap: 8388604k total, 0k used, 8388604k free, 60771760k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
6700 mongod 20 0 123g 18g 18g S 757.6 29.9 10032:32 mongod
mongod的cpu 达到了750%。

查看db.currentOp()。如下:
{
“desc” : “conn4005640”,
“threadId” : “0xde45a00”,
“connectionId” : 4005640,
“opid” : 944254032,
“active” : true,
“secs_running” : 0,
“microsecs_running” : NumberLong(151666),
“op” : “query”,
“ns” : “brcommondb.$cmd”,
“query” : {
“saslContinue” : 1,
“conversationId” : 1,
“mechanism” : “SCRAM-SHA-1”,
“payload” : BinData(0,””)
},
“client” : “*.*.*.*:46578”,
“numYields” : 0,
“locks” : {

},
“waitingForLock” : false,
“lockStats” : {

}
},
{
“desc” : “conn4005611”,
“threadId” : “0xde45ba0”,
“connectionId” : 4005611,
“opid” : 944254085,
“active” : true,
“secs_running” : 0,
“microsecs_running” : NumberLong(50631),
“op” : “query”,
“ns” : “admin.$cmd”,
“query” : {
“serverStatus” : 1,
“recordStats” : 0
},
“client” : “127.0.0.1:27200”,
“numYields” : 0,
“locks” : {

},
“waitingForLock” : false,
“lockStats” : {

}
},
{
“desc” : “conn4006275”,
“threadId” : “0xacf2be0”,
“connectionId” : 4006275,
“opid” : 944253962,
“active” : true,
“secs_running” : 0,
“microsecs_running” : NumberLong(231709),
“op” : “query”,
“ns” : “brcommondb.$cmd”,
“query” : {
“saslStart” : 1,
“mechanism” : “SCRAM-SHA-1”,
“payload” : BinData(0,”biwsbj1zdXBlclVzZXIscj1XK1hOVnVPeQ==”)
},
“client” : “*.*.*.*:47258”,
“numYields” : 0,
“locks” : {

},
“waitingForLock” : false,
“lockStats” : {

}
},
{
“desc” : “conn4005282”,
“threadId” : “0x1d0db0c0”,
“connectionId” : 4005282,
“opid” : 944253532,
“active” : true,
“secs_running” : 0,
“microsecs_running” : NumberLong(431131),
“op” : “query”,
“ns” : “admin.$cmd”,
“query” : {
“saslStart” : 1,
“mechanism” : “SCRAM-SHA-1”,
“payload” : BinData(0,”biwsbj1zdXBlclVzZXIscj1waGpVVVI2SA==”)
},
“client” : “127.0.0.1:27199”,
“numYields” : 0,
“locks” : {

},
“waitingForLock” : false,
“lockStats” : {

}
}
日志如下:

2015-08-14T20:00:02.449+0800 I ACCESS [conn4001415] Successfully authenticated as principal *** on ***db
2015-08-14T20:00:02.625+0800 I COMMAND [conn4001260] command brcommondb.$cmd command: saslStart { saslStart: 1, mechanism: “SCRAM-SHA-1”, payload: BinData(0, 6E2C2C6E3D7375706572557365722C723D355A5A41752B4E79) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:154 locks:{} 26ms
2015-08-14T20:00:02.739+0800 I ACCESS [conn4001260] Successfully authenticated as principal *** on ***db
2015-08-14T20:00:02.753+0800 I COMMAND [conn4001532] command brcommondb.$cmd command: saslStart { saslStart: 1, mechanism: “SCRAM-SHA-1”, payload: BinData(0, 6E2C2C6E3D7375706572557365722C723D2B2F5752516D476E) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:154 locks:{} 57ms
2015-08-14T20:00:02.784+0800 I COMMAND [conn3998762] command admin.$cmd command: saslStart { saslStart: 1, mechanism: “SCRAM-SHA-1”, payload: BinData(0, 6E2C2C6E3D7375706572557365722C723D4442524564333255) } keyUpdates:0 writeConflicts:0 numYields:0 reslen:154 locks:{} 23ms
2015-08-14T20:00:02.789+0800 I ACCESS [conn4001532] Successfully authenticated as principal *** on ***db

有几个疑问:
1、 saslStart 这样的command是做什么的? 我的mongodb访问鉴权方式都是采用”MONGODB-CR”的方式
2、像这种mongodb cpu高但是currentOp中看不出什么异常,有什么方法能够确定问题?