我在一台Linux服务器(Ubantu16.04,16G内存)上测试mongodb(3.4版本)性能,循环向一个collection中import数据,数据文件大小大概44M,测试代码如下:
#!bin/bash
base_dir=/home/wja/log
:>${base_dir}/runtime.log
:>${base_dir}/dbcount.log
:>${base_dir}/memory.log
:>${base_dir}/connection.log
for((i = 0;i < 50;i++))
do
for((j = 0;j<3;j++))
do
start_time=`date +%s`
mongoimport --host localhost:27050 -d wja -c test --type csv --headerline --file /home/wja/mongotest/mongoimport_1000000.csv --numInsertionWorkers 4
end_time=`date +%s`
echo ------$[ $i * 3 + $j + 1]--------- >> ${base_dir}/connection.log
netstat -plan | grep 27050 | grep -P ^tcp | awk '{print $6}' | sort -n | uniq -c >> ${base_dir}/connection.log
echo $[ $i * 3 + $j + 1 ]th time: use $[ $end_time-$start_time ] s >> ${base_dir}/runtime.log
sleep 10
mongo localhost:27050 --quiet --eval "db=db.getSiblingDB('wja');var n = db.test.count();var cur = db.serverStatus().connections.current;var mem = db.serverStatus().mem;print(n,cur,mem.resident,mem.mapped,mem.virtual);" >> ${base_dir}/dbcount.log
done
sleep 20
done
脚本一开始运行很好,但是后续会开始出现丢失数据的现象,查看mongo的log,会有很多socket exception:
2017-04-09T16:39:20.643+0800 I NETWORK [thread1] connection accepted from 127.0.0.1:41626 #268 (8 connections now open)
2017-04-09T16:39:20.643+0800 D COMMAND [PeriodicTaskRunner] task: UnusedLockCleaner took: 0ms
2017-04-09T16:39:20.643+0800 D COMMAND [PeriodicTaskRunner] task: DBConnectionPool-cleaner took: 0ms
2017-04-09T16:39:20.639+0800 D REPL [conn265] Waiting for write concern. OpTime: { ts: Timestamp 0|0, t: -1 }, write concern: { w: 1, wtimeout: 0 }
2017-04-09T16:39:20.643+0800 D COMMAND [conn268] run command admin.$cmd { getnonce: 1 }
2017-04-09T16:39:20.643+0800 I COMMAND [conn268] command admin.$cmd command: getnonce { getnonce: 1 } numYields:0 reslen:65 locks:{} protocol:op_query 0ms
2017-04-09T16:39:20.643+0800 D COMMAND [conn268] run command admin.$cmd { ismaster: 1 }
2017-04-09T16:39:20.643+0800 I COMMAND [conn265] command wja.test command: insert { insert: "test", documents: 1000, writeConcern: { getLastError: 1, w: 1 }, ordered: false } ninserted:1000 keysInserted:2000 numYields:0 reslen:44 locks:{ Global: { acquireCount: { r: 16, w: 16 } }, Database: { acquireCount: { w: 16 } }, Collection: { acquireCount: { w: 16 } } } protocol:op_query 28930ms
2017-04-09T16:39:20.644+0800 D COMMAND [conn267] run command admin.$cmd { getnonce: 1 }
2017-04-09T16:39:20.643+0800 D NETWORK [conn266] Socket recv() conn closed? 127.0.0.1:41610
2017-04-09T16:39:20.644+0800 I COMMAND [conn267] command admin.$cmd command: getnonce { getnonce: 1 } numYields:0 reslen:65 locks:{} protocol:op_query 0ms
2017-04-09T16:39:20.644+0800 D NETWORK [conn266] SocketException: remote: 127.0.0.1:41610 error: 9001 socket exception [CLOSED] server [127.0.0.1:41610]
2017-04-09T16:39:20.643+0800 I NETWORK [thread1] connection accepted from 127.0.0.1:41628 #269 (9 connections now open)
2017-04-09T16:39:20.644+0800 I - [conn266] end connection 127.0.0.1:41610 (9 connections now open)
2017-04-09T16:39:20.644+0800 I NETWORK [thread1] connection accepted from 127.0.0.1:41630 #270 (9 connections now open)
2017-04-09T16:39:20.644+0800 D STORAGE [conn265] WiredTigerSizeStorer::storeInto table:collection-3--156072121439285558 -> { numRecords: 40911768, dataSize: 6054941664 }
2017-04-09T16:39:20.644+0800 D COMMAND [conn267] run command admin.$cmd { ismaster: 1 }
2017-04-09T16:39:20.646+0800 D NETWORK [conn267] Starting server-side compression negotiation
2017-04-09T16:39:20.646+0800 I COMMAND [conn267] command admin.$cmd command: isMaster { ismaster: 1 } numYields:0 reslen:189 locks:{} protocol:op_query 0ms
2017-04-09T16:39:20.647+0800 D NETWORK [conn267] Socket say send() Broken pipe 127.0.0.1:41624
2017-04-09T16:39:20.647+0800 D - [conn267] User Assertion: 6:socket exception [SEND_ERROR] for 127.0.0.1:41624 src/mongo/db/service_entry_point_mongod.cpp 155
2017-04-09T16:39:20.647+0800 I - [conn267] AssertionException handling request, closing client connection: 6 socket exception [SEND_ERROR] for 127.0.0.1:41624
2017-04-09T16:39:20.647+0800 I - [conn267] end connection 127.0.0.1:41624 (9 connections now open)
2017-04-09T16:39:20.643+0800 D NETWORK [conn268] Starting server-side compression negotiation
2017-04-09T16:39:20.649+0800 I COMMAND [conn268] command admin.$cmd command: isMaster { ismaster: 1 } numYields:0 reslen:189 locks:{} protocol:op_query 5ms
2017-04-09T16:39:20.649+0800 D NETWORK [conn268] Socket say send() Broken pipe 127.0.0.1:41626
2017-04-09T16:39:20.649+0800 D - [conn268] User Assertion: 6:socket exception [SEND_ERROR] for 127.0.0.1:41626 src/mongo/db/service_entry_point_mongod.cpp 155
2017-04-09T16:39:20.649+0800 I - [conn268] AssertionException handling request, closing client connection: 6 socket exception [SEND_ERROR] for 127.0.0.1:41626
2017-04-09T16:39:20.649+0800 D COMMAND [conn269] run command admin.$cmd { getnonce: 1 }
2017-04-09T16:39:20.650+0800 I COMMAND [conn269] command admin.$cmd command: getnonce { getnonce: 1 } numYields:0 reslen:65 locks:{} protocol:op_query 0ms
2017-04-09T16:39:20.650+0800 I - [conn268] end connection 127.0.0.1:41626 (8 connections now open)
每次导入结束后,打印了一下对应端口的连接数,感觉很正常,基本都是
2 ESTABLISHED
1 LISTEN
6 TIME_WAIT
出错的时候TIME_WAIT会很小,或者会出现FIN_WAIT2和CLOSE_WAIT
我不知道是什么问题造成了连接问题,是我的测试方法不对,还是哪里配置没有注意?这个问题困扰我好久了,能有人帮我解决吗?
试着回答一下:
1、检查操作系统的Socket的限制
2、检查MongoDB的maxConns的设定
3、看看mongoimport的网络连接是怎么实现的
这个问题是和网络连接相关联的问题,上述思路供参考。
Love MongoDB! Have fun!