ablog

不器用で落着きのない技術者のメモ

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
$ 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