MongoDB に YCSB でベンチマークをかけてみる

インストール

MongoDB

$ sudo vi /etc/yum.repos.d/mongodb.repo
[mongodb]
name=MongoDB repo
baseurl=http://downloads-distro.mongodb.org/repo/redhat/os/x86_64/
gpgcheck=0
enabled=1
$ sudo yum -y install git mongodb-org

JDK 1.8

$ sudo yum -y install java-1.8.0-openjdk-devel
$ sudo update-alternatives --config java

There are 2 programs which provide 'java'.

  Selection    Command
-----------------------------------------------
*+ 1           /usr/lib/jvm/jre-1.7.0-openjdk.x86_64/bin/java
   2           /usr/lib/jvm/jre-1.8.0-openjdk.x86_64/bin/java

Enter to keep the current selection[+], or type selection number: 2

Maven

• Maven

$ cd /usr/local/lib/
$ sudo wget http://ftp.riken.jp/net/apache/maven/maven-3/3.5.3/binaries/apache-maven-3.5.3-bin.tar.gz
$ sudo tar xfvz apache-maven-3.5.3-bin.tar.gz
$ sudo ln -s apache-maven-3.5.3/ maven

• ~/.bash_profile に以下を追記する

MAVEN_HOME=/usr/local/lib/maven
export PATH=$PATH:$MAVEN_HOME/bin

• ~/.bash_profile を読み込む

$ . ~/.bash_profile

YCSB

$ cd
$ git clone https://github.com/brianfrankcooper/YCSB.git 
$ mvn clean package

準備

• MongoDB を起動する

$ sudo service mongod start

• ~/YCSB/workload/workloada を以下の通り編集

#recordcount=1000
recordcount=1000000
#operationcount=1000
operationcount=1000000

• データをロードする

$ ./bin/ycsb load mongodb -P workloads/workloada >> ycsb-load.log

ベンチマーク実行

$ ./bin/ycsb run mongodb -threads 5 -P workloads/workloada >> ycsb-run.log

結果

サマリ

• AverageLatency(us)

項目	5スレッド	10スレッド	50スレッド	100スレッド	200スレッド
READ	105	279	598	708	4121
CLEANUP	675	481	157	116	65
UPDATE	152	312	2869	6087	9450

• mongostat の接続数(conn)とキュー数(qr)
  • conn: The total number of open connections.
  • qr: The length of the queue of clients waiting to read data from the MongoDB instance.

項目	5スレッド	10スレッド	50スレッド	100スレッド	200スレッド
conn	0-3	3-8	47-48	102	102
qr	7	12	52	99	98

5スレッド

• 実行結果

$ ./bin/ycsb run mongodb -threads 5 -P workloads/workloada
（中略）
[OVERALL], RunTime(ms), 26441
[OVERALL], Throughput(ops/sec), 37820.052191672024
[TOTAL_GCS_PS_Scavenge], Count, 211
[TOTAL_GC_TIME_PS_Scavenge], Time(ms), 163
[TOTAL_GC_TIME_%_PS_Scavenge], Time(%), 0.616466850724254
[TOTAL_GCS_PS_MarkSweep], Count, 0
[TOTAL_GC_TIME_PS_MarkSweep], Time(ms), 0
[TOTAL_GC_TIME_%_PS_MarkSweep], Time(%), 0.0
[TOTAL_GCs], Count, 211
[TOTAL_GC_TIME], Time(ms), 163
[TOTAL_GC_TIME_%], Time(%), 0.616466850724254
[READ], Operations, 499550
[READ], AverageLatency(us), 105.58547292563307
[READ], MinLatency(us), 36
[READ], MaxLatency(us), 52735
[READ], 95thPercentileLatency(us), 214
[READ], 99thPercentileLatency(us), 306
[READ], Return=OK, 499550
（中略）
[CLEANUP], Operations, 5
[CLEANUP], AverageLatency(us), 675.8
[CLEANUP], MinLatency(us), 1
[CLEANUP], MaxLatency(us), 3369
[CLEANUP], 95thPercentileLatency(us), 3369
[CLEANUP], 99thPercentileLatency(us), 3369
[CLEANUP], 1, 3.0
[CLEANUP], 7, 1.0
[CLEANUP], 3369, 1.0
[UPDATE], Operations, 500450
[UPDATE], AverageLatency(us), 152.94304725746827
[UPDATE], MinLatency(us), 56
[UPDATE], MaxLatency(us), 52735
[UPDATE], 95thPercentileLatency(us), 176
[UPDATE], 99thPercentileLatency(us), 242
[UPDATE], Return=OK, 500450

• mongostat

$ mongostat 5
connected to: 127.0.0.1
insert  query update delete getmore command flushes mapped  vsize    res faults  locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn       time
     *0     *0     *0     *0       0     0|0       0  4.03g  8.38g  2.02g      0  ycsb:0.0%          0       0|0     0|0    12b   635b     1   17:38:25
    *0  13106  13080     *0       0     4|0       0  4.03g  8.38g  3.07g      0 ycsb:29.1%          0       0|0     0|5     4m    16m     7   17:38:30
    *0  19245  19289     *0       0     0|0       0  4.03g  8.38g  3.29g      0 ycsb:40.3%          0       0|0     0|5     7m    24m     7   17:38:35
    *0  19340  19428     *0       0     0|0       0  4.03g  8.38g  3.25g      0 ycsb:40.2%          0       3|0     0|1     7m    24m     7   17:38:40
    *0  19533  19365     *0       0     0|0       0  4.03g  8.38g  2.13g      0 ycsb:40.8%          0       4|0     0|1     7m    24m     7   17:38:45
    *0  19203  19476     *0       0     0|0       0  4.03g  8.38g  2.57g      0 ycsb:40.5%          0       1|0     4|0     7m    24m     7   17:38:50
    *0   9481   9448     *0       0     0|0       0  4.03g  8.38g  2.02g      0 ycsb:19.7%          0       0|0     0|0     3m    12m     1   17:38:55

10スレッド

• 実行結果

$ ./bin/ycsb run mongodb -threads 10 -P workloads/workloada
（中略）
[OVERALL], RunTime(ms), 30006
[OVERALL], Throughput(ops/sec), 33326.667999733385
[TOTAL_GCS_PS_Scavenge], Count, 214
[TOTAL_GC_TIME_PS_Scavenge], Time(ms), 180
[TOTAL_GC_TIME_%_PS_Scavenge], Time(%), 0.599880023995201
[TOTAL_GCS_PS_MarkSweep], Count, 0
[TOTAL_GC_TIME_PS_MarkSweep], Time(ms), 0
[TOTAL_GC_TIME_%_PS_MarkSweep], Time(%), 0.0
[TOTAL_GCs], Count, 214
[TOTAL_GC_TIME], Time(ms), 180
[TOTAL_GC_TIME_%], Time(%), 0.599880023995201
[READ], Operations, 499879
[READ], AverageLatency(us), 279.0026706462964
[READ], MinLatency(us), 36
[READ], MaxLatency(us), 58719
[READ], 95thPercentileLatency(us), 670
[READ], 99thPercentileLatency(us), 973
[READ], Return=OK, 499879
（中略）
[CLEANUP], Operations, 10
[CLEANUP], AverageLatency(us), 481.7
[CLEANUP], MinLatency(us), 0
[CLEANUP], MaxLatency(us), 4807
[CLEANUP], 95thPercentileLatency(us), 4807
[CLEANUP], 99thPercentileLatency(us), 4807
[CLEANUP], 0, 3.0
[CLEANUP], 1, 5.0
[CLEANUP], 6, 1.0
[CLEANUP], 4807, 1.0
[UPDATE], Operations, 500121
[UPDATE], AverageLatency(us), 312.47620275893235
[UPDATE], MinLatency(us), 58
[UPDATE], MaxLatency(us), 58623
[UPDATE], 95thPercentileLatency(us), 384
[UPDATE], 99thPercentileLatency(us), 597
[UPDATE], Return=OK, 500121

• mongostat

$ mongostat 5
    *0     *0     *0     *0       0     0|0       0  4.03g  8.38g  2.02g      0  ycsb:0.0%          0       0|0     0|0    12b   635b     1   17:45:52
    *0   1929   1904     *0       0     7|0       0  4.03g  8.38g  2.76g      0  ycsb:5.8%          0       6|0     0|1   720k     2m    12   17:45:57
    *0  19215  19298     *0       0     0|0       0  4.03g  8.38g  2.78g      0 ycsb:47.1%          0       3|0     2|0     7m    24m    12   17:46:02
    *0  17083  17092     *0       0     0|0       0  4.03g  8.38g  3.09g      0 ycsb:42.9%          0       7|0     0|1     6m    21m    12   17:46:07
    *0  16112  16202     *0       0     0|0       0  4.03g  8.38g  2.63g      0 ycsb:41.4%          0       7|0     0|1     6m    20m    12   17:46:12
    *0  16150  16125     *0       0     0|0       0  4.03g  8.38g  2.73g      0 ycsb:41.3%          0       6|0     1|0     6m    20m    12   17:46:17
    *0  16327  16227     *0       0     0|0       0  4.03g  8.38g  3.16g      0 ycsb:40.5%          0       8|0     0|1     6m    20m    12   17:46:22
    *0  13158  13174     *0       0     0|0       0  4.03g  8.38g  2.52g      0 ycsb:33.9%          0       0|0     0|0     4m    16m     1   17:46:27

50スレッド

• 実行結果

$ ./bin/ycsb run mongodb -threads 50 -P workloads/workloada
（中略）
[OVERALL], RunTime(ms), 35126
[OVERALL], Throughput(ops/sec), 28468.94038603883
[TOTAL_GCS_PS_Scavenge], Count, 44
[TOTAL_GC_TIME_PS_Scavenge], Time(ms), 71
[TOTAL_GC_TIME_%_PS_Scavenge], Time(%), 0.2021294767408757
[TOTAL_GCS_PS_MarkSweep], Count, 0
[TOTAL_GC_TIME_PS_MarkSweep], Time(ms), 0
[TOTAL_GC_TIME_%_PS_MarkSweep], Time(%), 0.0
[TOTAL_GCs], Count, 44
[TOTAL_GC_TIME], Time(ms), 71
[TOTAL_GC_TIME_%], Time(%), 0.2021294767408757
[READ], Operations, 499284
[READ], AverageLatency(us), 598.3327685245271
[READ], MinLatency(us), 36
[READ], MaxLatency(us), 91775
[READ], 95thPercentileLatency(us), 1805
[READ], 99thPercentileLatency(us), 3273
[READ], Return=OK, 499284
（中略）
[CLEANUP], Operations, 50
[CLEANUP], AverageLatency(us), 157.74
[CLEANUP], MinLatency(us), 0
[CLEANUP], MaxLatency(us), 7863
[CLEANUP], 95thPercentileLatency(us), 2
[CLEANUP], 99thPercentileLatency(us), 7863
[CLEANUP], 0, 30.0
[CLEANUP], 1, 17.0
[CLEANUP], 2, 1.0
[CLEANUP], 6, 1.0
[CLEANUP], 7863, 1.0
[UPDATE], Operations, 500716
[UPDATE], AverageLatency(us), 2869.2255490138123
[UPDATE], MinLatency(us), 56
[UPDATE], MaxLatency(us), 103935
[UPDATE], 95thPercentileLatency(us), 6539
[UPDATE], 99thPercentileLatency(us), 17967
[UPDATE], Return=OK, 500716

• mongostat

$ mongostat 5
connected to: 127.0.0.1
insert  query update delete getmore command flushes mapped  vsize    res faults  locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn       time
    *0     *0     *0     *0       0     0|0       0  4.03g  8.38g  2.02g      0  ycsb:0.0%          0       0|0     0|0    12b   635b     1   17:49:02
    *0   3960   3963     *0       0    31|0       0  4.03g  8.39g  2.68g      0 ycsb:12.4%          0      48|0     0|1     1m     5m    52   17:49:07
    *0  15027  15111     *0       0     0|0       0  4.03g  8.39g   3.2g      0 ycsb:38.6%          0      43|0     1|0     5m    19m    52   17:49:12
    *0  14852  14883     *0       0     0|0       0  4.03g  8.39g  2.95g      0 ycsb:38.6%          0      47|0     0|1     5m    18m    52   17:49:17
    *0  14897  14960     *0       0     0|0       0  4.03g  8.39g   2.6g      0 ycsb:38.7%          0      47|0     1|0     5m    18m    52   17:49:22
    *0  14114  14153     *0       0     0|0       0  4.03g  8.39g  2.94g      0 ycsb:37.4%          0       0|0    0|49     5m    17m    52   17:49:27
    *0  13728  13753     *0       0     0|0       0  4.03g  8.39g  2.88g      0 ycsb:36.6%          0      48|0     0|0     5m    17m    52   17:49:32
    *0  13769  13751     *0       0     0|0       0  4.03g  8.39g  3.04g      0 ycsb:36.4%          0      49|0     0|1     5m    17m    52   17:49:37
    *0   9507   9565     *0       0     0|0       0  4.03g  8.38g  2.02g      0 ycsb:25.9%          0       0|0     0|0     3m    12m     1   17:49:42

100スレッド

• 実行結果

$ ./bin/ycsb run mongodb -threads 100 -P workloads/workloada
（中略）
[OVERALL], RunTime(ms), 34437
[OVERALL], Throughput(ops/sec), 29038.534134796875
[TOTAL_GCS_PS_Scavenge], Count, 45
[TOTAL_GC_TIME_PS_Scavenge], Time(ms), 86
[TOTAL_GC_TIME_%_PS_Scavenge], Time(%), 0.2497313935592531
[TOTAL_GCS_PS_MarkSweep], Count, 0
[TOTAL_GC_TIME_PS_MarkSweep], Time(ms), 0
[TOTAL_GC_TIME_%_PS_MarkSweep], Time(%), 0.0
[TOTAL_GCs], Count, 45
[TOTAL_GC_TIME], Time(ms), 86
[TOTAL_GC_TIME_%], Time(%), 0.2497313935592531
[READ], Operations, 499757
[READ], AverageLatency(us), 708.4381929617795
[READ], MinLatency(us), 33
[READ], MaxLatency(us), 140031
[READ], 95thPercentileLatency(us), 2329
[READ], 99thPercentileLatency(us), 4363
[READ], Return=OK, 499757
（中略）
[CLEANUP], Operations, 100
[CLEANUP], AverageLatency(us), 116.06
[CLEANUP], MinLatency(us), 0
[CLEANUP], MaxLatency(us), 11575
[CLEANUP], 95thPercentileLatency(us), 1
[CLEANUP], 99thPercentileLatency(us), 6
[CLEANUP], 0, 70.0
[CLEANUP], 1, 28.0
[CLEANUP], 6, 1.0
[CLEANUP], 11575, 1.0
[UPDATE], Operations, 500243
[UPDATE], AverageLatency(us), 6087.91907532939
[UPDATE], MinLatency(us), 52
[UPDATE], MaxLatency(us), 146815
[UPDATE], 95thPercentileLatency(us), 13855
[UPDATE], 99thPercentileLatency(us), 22255
[UPDATE], Return=OK, 500243

• mongostat

$ mongostat 5
connected to: 127.0.0.1
insert  query update delete getmore command flushes mapped  vsize    res faults  locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn       time
    *0     *0     *0     *0       0     0|0       0  4.03g  8.38g  2.02g      0  ycsb:0.0%          0       0|0     0|0    12b   635b     1   17:53:18
    *0   1742   1711     *0       0    61|0       0  4.03g  8.44g  2.41g      0  ycsb:6.0%          0      97|0     0|0   650k     2m   102   17:53:23
    *0  14664  14544     *0       0     0|0       0  4.03g  8.44g  3.04g      0 ycsb:39.0%          0      97|0     0|1     5m    18m   102   17:53:28
    *0  14603  14616     *0       0     0|0       0  4.03g  8.44g  2.83g      0 ycsb:37.9%          0       0|0   0|100     5m    18m   102   17:53:33
    *0  14826  14810     *0       0     0|0       0  4.03g  8.44g  2.36g      0 ycsb:37.9%          0      99|1     0|1     5m    18m   102   17:53:38
    *0  14792  14851     *0       0     0|0       0  4.03g  8.44g   2.9g      0 ycsb:38.4%          0      99|0     0|1     5m    18m   102   17:53:43
    *0  14713  14861     *0       0     0|0       0  4.03g  8.44g  2.57g      0 ycsb:38.5%          0      27|0    0|73     5m    18m   102   17:53:48
    *0  14712  14718     *0       0     0|0       0  4.03g  8.44g  2.95g      0 ycsb:37.6%          0      97|0     0|1     5m    18m   102   17:53:53
    *0   9896   9935     *0       0     0|0       0  4.03g  8.38g  2.02g      0 ycsb:26.3%          0       0|0     0|0     3m    12m     1   17:53:58
    *0     *0     *0     *0       0     0|0       0  4.03g  8.38g  2.02g      0  ycsb:0.0%          0       0|0     0|0    12b   635b     1   17:54:03

200スレッド

• 実行結果

$ ./bin/ycsb run mongodb -threads 200 -P workloads/workloada
（中略）
[OVERALL], RunTime(ms), 34298
[OVERALL], Throughput(ops/sec), 29156.21902151729
[TOTAL_GCS_PS_Scavenge], Count, 45
[TOTAL_GC_TIME_PS_Scavenge], Time(ms), 87
[TOTAL_GC_TIME_%_PS_Scavenge], Time(%), 0.2536591054872004
[TOTAL_GCS_PS_MarkSweep], Count, 0
[TOTAL_GC_TIME_PS_MarkSweep], Time(ms), 0
[TOTAL_GC_TIME_%_PS_MarkSweep], Time(%), 0.0
[TOTAL_GCs], Count, 45
[TOTAL_GC_TIME], Time(ms), 87
[TOTAL_GC_TIME_%], Time(%), 0.2536591054872004
[READ], Operations, 500000
[READ], AverageLatency(us), 4121.626464
[READ], MinLatency(us), 36
[READ], MaxLatency(us), 145279
[READ], 95thPercentileLatency(us), 7095
[READ], 99thPercentileLatency(us), 10551
[READ], Return=OK, 500000
（中略）
[CLEANUP], Operations, 200
[CLEANUP], AverageLatency(us), 65.245
[CLEANUP], MinLatency(us), 0
[CLEANUP], MaxLatency(us), 13007
[CLEANUP], 95thPercentileLatency(us), 1
[CLEANUP], 99thPercentileLatency(us), 1
[CLEANUP], 0, 166.0
[CLEANUP], 1, 32.0
[CLEANUP], 13, 1.0
[CLEANUP], 13007, 1.0
[UPDATE], Operations, 500000
[UPDATE], AverageLatency(us), 9450.302092
[UPDATE], MinLatency(us), 52
[UPDATE], MaxLatency(us), 138367
[UPDATE], 95thPercentileLatency(us), 17359
[UPDATE], 99thPercentileLatency(us), 27167
[UPDATE], Return=OK, 500000

• mongostat

$ mongostat 5
connected to: 127.0.0.1
insert  query update delete getmore command flushes mapped  vsize    res faults  locked db idx miss %     qr|qw   ar|aw  netIn netOut  conn       time
    *0     *0     *0     *0       0     0|0       0  4.03g  8.38g  2.02g      0  ycsb:0.0%          0       0|0     0|0    12b   635b     1   17:57:23
    *0   4428   4480     *0       0    61|0       0  4.03g  8.44g  2.62g      0 ycsb:14.0%          0      98|0     0|1     1m     5m   102   17:57:28
    *0  14708  14627     *0       0     0|0       0  4.03g  8.44g  2.71g      0 ycsb:39.1%          0      40|0    0|60     5m    18m   102   17:57:33
    *0  14720  14637     *0       0     0|0       0  4.03g  8.44g  2.71g      0 ycsb:38.9%          0      97|0     0|1     5m    18m   102   17:57:38
    *0  14875  14886     *0       0     0|0       0  4.03g  8.44g  3.07g      0 ycsb:39.4%          0      97|0     0|1     5m    18m   102   17:57:43
    *0  14684  14527     *0       0     0|0       0  4.03g  8.44g  2.54g      0 ycsb:39.0%          0      96|0     0|1     5m    18m   102   17:57:48
    *0  14762  14872     *0       0     0|0       0  4.03g  8.44g  2.32g      0 ycsb:39.6%          0      98|0     0|1     5m    18m   102   17:57:53
    *0  14675  14800     *0       0     0|0       0  4.03g  8.44g  3.01g      0 ycsb:39.2%          0      98|1     0|1     5m    18m   102   17:57:58
    *0   7144   7168     *0       0     0|0       0  4.03g  8.38g  2.02g      0 ycsb:19.5%          0       0|0     0|0     2m     9m     1   17:58:03
    *0     *0     *0     *0       0     0|0       0  4.03g  8.38g  2.02g      0  ycsb:0.0%          0       0|0     0|0    12b   635b     1   17:58:08

環境

• c5.4xlarge

参考

• https://qiita.com/ykyk1218/items/1c1824e77fb8af78bcf5
• YCSBでDynamoDBを殴ってみた ｜ DevelopersIO
• How to Benchmark MongoDB with YCSB?
• YCSBでNoSQLのベンチマーク その2 - 工場長のブログ
• MongoDBの単体性能（前編） (2/2)：EnterpriseZine（エンタープライズジン）
• MongoDBが遅いときの切り分け方法
• mongostat — MongoDB Manual
• Learn About Lock Percentage: Concurrency in MongoDB | MongoDB