1亿条记录的MongoDB数据库随机查询性能测试
作者：
mongdb性能压力测试，随机查询，数据量1亿条记录
操作系统centos6.4x64位
从测试结果看，当mongodb将数据全部载入到内存后，查询速度根据文档的大小，性能瓶颈通常会是在网络流量和CPU的处理性能（该次测试中当数据全部在内存后，纯粹的查询速度可以稳定在10W/S左右，系统load可以维持在1以下，由于此时CPU已经被使用到极限了，当并发再大时load值会直线飙升，性能急剧下降）。
压力生成服务器与Mongodb服务器基本配置
cpu型号：Intel(R) Xeon(R) CPU E5-2630 0 @ 2.30GHz
内存：64G
硬盘：10K转速 6块做RAID0，raid卡cache 1G（磁盘的IO性能决定MONGODB将非热点数据载入到内存的速度，当热点数据全部在内存后，IO性能可以忽略）
网卡速度：接入千兆交互机，速度1000MB
数据结构，user_id为索引键值为0-99999999，数据总大小约37G左右，全部载入内存后约32G
> db.thing.findOne();
{
"_id" : ObjectId("51fd6830c6db9d15676f89ef"),
"ip" : "192.168.168.254",
"g_roup" : "kiwi",
"mac" : "of:fd:67:8c:2f:8f",
"address" : "hongmei1801num",
"user_id" : 10000000,
"name" : "user10000000",
"title" : "system",
"database" : "mongodb",
"telphone" : NumberLong("15718441234"),
"mail" : "yj@chinapnr.com",
"os" : "win7",
"company" : "chinapnr"
}
压力生成脚本开启40个进程，并发随机查询
[root@mdb-166 app]# cat mselectmongodb.py
import time,pymongo,multiprocessing,random,string
class SqlToMongo:
def m_sql(self,x,y):
server="mongodb://python:oracle@192.168.4.167:27017/syslog"
conn=pymongo.Connection(server)
db=conn.syslog
col=db.thing
start=x*y
end=start+x
for i in xrange(start,end):
d=random.randint(start,end)
val=col.find({"user_id":d})
a=list(val)
def gen_load(x,taskid):
task=SqlToMongo()
print "task %s start!" % taskid
task.m_sql(x,taskid)
if __name__ == "__main__":
inser_number=2500000
pro_pool = multiprocessing.Pool(processes=101)
print time.strftime('%Y-%m-%d:%H-%M-%S',time.localtime(time.time()))
start_time=time.time()
manager = multiprocessing.Manager()
for i in xrange(40):
taskid=i
pro_pool.apply_async(gen_load,args=(inser_number,taskid))
pro_pool.close()
pro_pool.join()
elapsed = time.time()-start_time
print elapsed
time.sleep(1)
print "Sub-process(es) done."
压力生成服务器负载，同时开启80个并发时抗不住了
top - 17:12:59 up 2 days, 7:34, 4 users, load average: 35.87, 29.41, 18.16
Tasks: 487 total, 64 running, 423 sleeping, 0 stopped, 0 zombie
Cpu0 : 88.1%us, 10.6%sy, 0.0%ni, 1.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu1 : 87.7%us, 10.9%sy, 0.0%ni, 1.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu2 : 87.7%us, 11.0%sy, 0.0%ni, 1.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu3 : 88.0%us, 10.3%sy, 0.0%ni, 1.7%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu4 : 87.7%us, 11.0%sy, 0.0%ni, 1.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu5 : 88.7%us, 9.9%sy, 0.0%ni, 1.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu6 : 40.2%us, 3.3%sy, 0.0%ni, 0.3%id, 0.0%wa, 0.0%hi, 56.1%si, 0.0%st
Cpu7 : 89.7%us, 8.9%sy, 0.0%ni, 1.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu8 : 88.1%us, 10.6%sy, 0.0%ni, 1.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu9 : 89.7%us, 9.3%sy, 0.0%ni, 1.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu10 : 88.7%us, 9.9%sy, 0.0%ni, 1.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu11 : 88.4%us, 10.2%sy, 0.0%ni, 1.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 65909128k total, 5409148k used, 60499980k free, 90680k buffers
Swap: 8388600k total, 0k used, 8388600k free, 4392420k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
13342 root 20 0 178m 9056 1480 R 15.9 0.0 5:15.79 python mselectmongodb.py
13430 root 20 0 178m 8976 1468 R 15.9 0.0 3:05.26 python mselectmongodb.py
13321 root 20 0 178m 9000 1464 R 15.6 0.0 5:17.26 python mselectmongodb.py
........
13311 root 20 0 178m 8980 1464 R 14.9 0.0 5:21.70 python mselectmongodb.py
系统负载，
[root@mdb-167 ~]# top
并发进程80的系统负载
[root@mdb-167 ~]# top
top - 17:08:33 up 4:49, 5 users, load average: 0.00, 0.00, 1.05
Tasks: 287 total, 2 running, 285 sleeping, 0 stopped, 0 zombie
Cpu0 : 60.1%us, 31.4%sy, 0.0%ni, 8.5%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu1 : 57.8%us, 33.0%sy, 0.0%ni, 9.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu2 : 58.4%us, 31.4%sy, 0.0%ni, 10.1%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu3 : 54.8%us, 33.9%sy, 0.0%ni, 11.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu4 : 55.8%us, 31.8%sy, 0.0%ni, 12.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu5 : 53.4%us, 32.9%sy, 0.0%ni, 13.7%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu6 : 31.4%us, 12.7%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 55.9%si, 0.0%st
Cpu7 : 61.0%us, 31.7%sy, 0.0%ni, 7.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu8 : 59.7%us, 32.3%sy, 0.0%ni, 8.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu9 : 59.0%us, 32.4%sy, 0.0%ni, 8.6%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu10 : 59.4%us, 31.4%sy, 0.0%ni, 9.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu11 : 57.8%us, 32.1%sy, 0.0%ni, 10.1%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 65909128k total, 34281160k used, 31627968k free, 50416k buffers
Swap: 8388600k total, 0k used, 8388600k free, 33502796k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2924 mdb 20 0 80.7g 31g 31g S 1092.6 50.7 458:42.39 /app/mongodb/bin/mongod -f /app/mongodb/etc/mdb.conf
1967 root 20 0 0 0 0 S 0.3 0.0 0:05.40 [kondemand/6]
1996 root 20 0 10964 720 432 S 0.3 0.0 0:05.12 irqbalance
3045 mdb 20 0 84500 38m 7076 S 0.3 0.1 0:01.99 mongostat -h 127.0.0.1 --port 27017 -u root -p xxxxx
mongstat监控
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn time
*0 92408 *0 *0 0 1|0 0 40.1g 80.7g 31.9g 0 syslog:0.0% 0 0|0 20|0 5m 28m 82 17:08:32
*0 92827 *0 *0 0 3|0 0 40.1g 80.7g 31.9g 0 syslog:0.0% 0 0|0 19|0 5m 28m 82 17:08:33
.......
*0 93717 *0 *0 0 1|0 0 40.1g 80.7g 31.9g 0 syslog:0.0% 0 0|0 25|0 5m 28m 82 17:08:38
*0 92193 *0 *0 0 3|0 0 40.1g 80.7g 31.9g 0 syslog:0.1% 0 1|0 11|0 5m 28m 82 17:08:39
*0 92250 *0 *0 0 1|0 0 40.1g 80.7g 31.9g 0 syslog:0.0% 0 0|0 25|0 5m 28m 82 17:08:40
*0 93790 *0 *0 0 3|0 0 40.1g 80.7g 31.9g 0 syslog:0.0% 0 1|0 16|0 5m 28m 82 17:08:41
网络流量
[root@mdb-167 app]# ./check_netflow.py -l 1 -i p1p1 -t 1
IN 1 seconds network transmit and receive average(KB)
transmit=34101,receive=11370
transmit=34354,receive=11452
.....
transmit=33957,receive=11322
transmit=34045,receive=11353
transmit=34244,receive=11416
磁盘IO
[root@mdb-167 ~]# tail -f mselectmongodb
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sda 0.00 7.00 0.00 4.00 0.00 48.00 24.00 0.00 0.00 0.00 0.00
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
.....
sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sda 0.00 7.00 0.00 5.00 0.00 48.00 19.20 0.00 0.00 0.00 0.00
二、并发进程达到120的时候系统负载（由于CPU的处理能力，系统已经无法承受）
top - 16:57:57 up 3:47, 5 users, load average: 58.18, 30.82, 16.40
Tasks: 288 total, 1 running, 287 sleeping, 0 stopped, 0 zombie
Cpu0 : 59.6%us, 40.2%sy, 0.0%ni, 0.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu1 : 59.3%us, 40.5%sy, 0.0%ni, 0.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu2 : 59.0%us, 40.8%sy, 0.0%ni, 0.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu3 : 58.7%us, 41.0%sy, 0.0%ni, 0.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu4 : 58.8%us, 40.9%sy, 0.0%ni, 0.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu5 : 58.8%us, 40.9%sy, 0.0%ni, 0.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu6 : 27.2%us, 13.1%sy, 0.0%ni, 0.1%id, 0.0%wa, 0.0%hi, 59.6%si, 0.0%st
Cpu7 : 60.5%us, 39.3%sy, 0.0%ni, 0.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu8 : 60.2%us, 39.5%sy, 0.0%ni, 0.2%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu9 : 59.8%us, 39.9%sy, 0.0%ni, 0.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu10 : 59.5%us, 40.2%sy, 0.0%ni, 0.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Cpu11 : 59.4%us, 40.4%sy, 0.0%ni, 0.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 65909128k total, 34278248k used, 31630880k free, 45652k buffers
Swap: 8388600k total, 0k used, 8388600k free, 33501056k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
2924 mdb 20 0 80.7g 31g 31g S 1193.2 50.4 165:06.51 /app/mongodb/bin/mongod -f /app/mongodb/etc/mdb.conf
mongstat监控
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn time
*0 103334 *0 *0 0 1|0 0 40.1g 80.7g 31.7g 0 syslog:0.1% 0 0|0 56|0 6m 31m 122 16:55:19
*0 103299 *0 *0 0 3|0 0 40.1g 80.7g 31.7g 0 syslog:0.0% 0 0|0 55|0 6m 31m 122 16:55:20
......
*0 102858 *0 *0 0 3|0 0 40.1g 80.7g 31.7g 0 syslog:0.0% 0 0|0 66|0 6m 31m 122 16:55:26
*0 103201 *0 *0 0 1|0 0 40.1g 80.7g 31.7g 0 syslog:0.0% 0 0|0 60|0 6m 31m 122 16:55:27
*0 102381 *0 *0 0 3|0 0 40.1g 80.7g 31.7g 0 syslog:0.1% 0 1|0 89|0 6m 31m 122 16:55:28
磁盘IO
[root@mdb-167 ~]# tail -f mselectmongodb
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sda 0.00 7.00 0.00 4.00 0.00 48.00 24.00 0.00 0.00 0.00 0.00
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
.....
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sda 0.00 7.00 0.00 5.00 0.00 48.00 19.20 0.00 0.00 0.00 0.00
网络流量
transmit=37567,receive=12525
......
transmit=37691,receive=12568
transmit=37592,receive=12534
transmit=37480,receive=12498
以下是mongodb从测试开始时的查询速度变化过程，当数据逐步载入内存后，查询速度也在逐步提高，大约会花费了20分钟将所有数据载入到了内存。
[mdb@mdb-167 ~]$ more mselectmongodb
connected to: 127.0.0.1:27017
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn time
*0 679 *0 *0 0 1|0 0 40.1g 80.6g 494m 671 syslog:1.0% 0 0|0 0|0 40k 213k 42 16:37:16
*0 562 *0 *0 0 3|0 0 40.1g 80.6g 500m 625 syslog:0.9% 0 36|0 2|0 33k 176k 42 16:37:17
..........
*0 626 *0 *0 0 1|0 0 40.1g 80.6g 550m 667 syslog:1.0% 0 36|0 1|0 36k 196k 42 16:37:24
*0 649 *0 *0 0 3|0 1 40.1g 80.6g 557m 671 syslog:0.9% 0 35|0 1|0 38k 202k 42 16:37:25
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn time
*0 706 *0 *0 0 1|0 0 40.1g 80.6g 565m 709 syslog:1.0% 0 39|0 1|0 41k 221k 42 16:37:26
..........
*0 992 *0 *0 0 1|0 0 40.1g 80.6g 954m 751 syslog:1.1% 0 0|0 1|0 58k 309k 42 16:38:12
*0 942 *0 *0 0 3|0 0 40.1g 80.6g 964m 759 syslog:0.9% 0 0|0 0|0 55k 294k 42 16:38:13
*0 1026 *0 *0 0 1|0 0 40.1g 80.6g 974m 813 syslog:0.8% 0 0|0 0|0 60k 319k 42 16:38:14
*0 1062 *0 *0 0 3|0 0 40.1g 80.6g 985m 826 syslog:0.8% 0 0|0 0|0 62k 331k 42 16:38:15
*0 1044 *0 *0 0 1|0 0 40.1g 80.6g 995m 800 syslog:0.9% 0 0|0 0|0 61k 325k 42 16:38:16
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn time
*0 1005 *0 *0 0 3|0 0 40.1g 80.6g 1005m 785 syslog:0.7% 0 30|0 1|0 59k 313k 42 16:38:17
*0 1008 *0 *0 0 1|0 0 40.1g 80.6g 1015m 737 syslog:0.9% 0 0|0 1|0 59k 314k 42 16:38:18
*0 1137 *0 *0 0 3|0 0 40.1g 80.6g 1g 853 syslog:0.7% 0 0|0 0|0 67k 354k 42 16:38:19
*0 993 *0 *0 0 1|0 0 40.1g 80.6g 1.01g 768 syslog:0.9% 0 0|0 0|0 58k 310k 42 16:38:20
*0 1114 *0 *0 0 3|0 0 40.1g 80.6g 1.02g 811 syslog:1.0% 0 0|0 0|0 65k 346k 42 16:38:21
*0 1001 *0 *0 0 1|0 0 40.1g 80.6g 1.03g 744 syslog:1.0% 0 10|0 1|0 59k 312k 42 16:38:22
..........
*0 1892 *0 *0 0 1|0 0 40.1g 80.6g 2.03g 900 syslog:0.7% 0 1|0 1|0 111k 587k 42 16:39:44
*0 1881 *0 *0 0 3|0 0 40.1g 80.6g 2.04g 894 syslog:0.7% 0 0|0 0|0 111k 583k 42 16:39:45
*0 1927 *0 *0 0 1|0 0 40.1g 80.6g 2.06g 902 syslog:0.8% 0 0|0 0|0 113k 598k 42 16:39:46
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn time
*0 1950 *0 *0 0 3|0 0 40.1g 80.6g 2.07g 912 syslog:0.6% 0 37|0 1|0 115k 605k 42 16:39:47
*0 2086 *0 *0 0 1|0 0 40.1g 80.6g 2.09g 901 syslog:0.8% 0 0|0 1|0 123k 647k 42 16:39:48
*0 1774 *0 *0 0 3|0 0 40.1g 80.6g 2.1g 846 syslog:0.8% 0 0|0 0|0 105k 551k 42 16:39:49
.......
*0 2589 *0 *0 0 1|0 0 40.1g 80.6g 2.56g 933 syslog:0.8% 0 0|0 1|0 152k 803k 42 16:40:18
*0 2289 *0 *0 0 3|0 0 40.1g 80.6g 2.58g 849 syslog:0.9% 0 0|0 0|0 135k 710k 42 16:40:19
*0 2523 *0 *0 0 1|0 0 40.1g 80.6g 2.59g 930 syslog:0.7% 0 0|0 0|0 148k 781k 42 16:40:20
*0 2636 *0 *0 0 3|0 0 40.1g 80.6g 2.61g 878 syslog:0.8% 0 0|0 1|0 155k 817k 42 16:40:21
*0 2509 *0 *0 0 1|0 0 40.1g 80.6g 2.63g 889 syslog:0.7% 0 0|0 1|0 148k 777k 42 16:40:22
*0 2637 *0 *0 0 3|0 0 40.1g 80.6g 2.65g 916 syslog:0.7% 0 0|0 0|0 155k 817k 42 16:40:23
*0 2575 *0 *0 0 1|0 0 40.1g 80.6g 2.67g 911 syslog:0.8% 0 0|0 0|0 151k 798k 42 16:40:24
*0 2516 *0 *0 0 3|0 1 40.1g 80.6g 2.68g 873 syslog:6.5% 0 16|0 0|0 148k 779k 42 16:40:25
*0 2498 *0 *0 0 1|0 0 40.1g 80.6g 2.7g 879 syslog:0.8% 0 0|0 0|0 147k 774k 42 16:40:26
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn time
*0 2536 *0 *0 0 3|0 0 40.1g 80.6g 2.72g 872 syslog:0.7% 0 0|0 0|0 149k 786k 42 16:40:27
*0 2826 *0 *0 0 1|0 0 40.1g 80.6g 2.74g 959 syslog:0.8% 0 0|0 1|0 166k 876k 42 16:40:28
*0 2676 *0 *0 0 3|0 0 40.1g 80.6g 2.75g 925 syslog:0.8% 0 0|0 0|0 158k 829k 42 16:40:29
.......
*0 8934 *0 *0 0 1|0 0 40.1g 80.6g 4.85g 1088 syslog:0.6% 0 0|0 1|0 527k 2m 42 16:41:50
*0 9583 *0 *0 0 3|0 0 40.1g 80.6g 4.89g 1161 syslog:0.6% 0 0|0 2|0 565k 2m 42 16:41:51
*0 8982 *0 *0 0 1|0 0 40.1g 80.6g 4.93g 1107 syslog:0.6% 0 23|0 3|0 530k 2m 42 16:41:52
*0 9950 *0 *0 0 3|0 0 40.1g 80.6g 4.97g 1067 syslog:0.5% 0 0|0 0|0 587k 3m 42 16:41:53
*0 9580 *0 *0 0 1|0 1 40.1g 80.6g 5.01g 1084 syslog:0.7% 0 0|0 1|0 565k 2m 42 16:41:54
.......
*0 92475 *0 *0 0 3|0 0 40.1g 80.7g 31.9g 1 syslog:0.0% 0 0|0 18|0 5m 28m 82 16:53:28
insert query update delete getmore command flushes mapped vsize res faults locked db idx miss % qr|qw ar|aw netIn netOut conn time
*0 92832 *0 *0 0 1|0 0 40.1g 80.7g 31.9g 0 syslog:0.0% 0 0|0 19|0 5m 28m 82 16:53:29
*0 92077 *0 *0 0 3|0 0 40.1g 80.7g 31.9g 0 syslog:0.0% 0 0|0 12|0 5m 28m 82 16:53:30
*0 93296 *0 *0 0 1|0 0 40.1g 80.7g 31.9g 0 syslog:0.1% 0 0|0 18|0 5m 28m 82 16:53:31
*0 91269 *0 *0 0 3|0 0 40.1g 80.7g 31.9g 0 syslog:0.0% 0 1|0 10|0 5m 28m 82 16:53:32
*0 93878 *0 *0 0 1|0 0 40.1g 80.7g 31.9g 0 syslog:0.0%