Hatena::ブログ(Diary)

ablog このページをアンテナに追加 RSSフィード

2018-07-30

sysbench で MySQL にカスタムクエリを同時多重実行して一時ファイルを大量に使ってみる

インストール

curl -s https://packagecloud.io/install/repositories/akopytov/sysbench/script.rpm.sh | sudo bash
sudo yum -y install sysbench mysql

準備

  • 初期データロード
$ sysbench /usr/share/sysbench/oltp_read_write.lua \
 --db-driver=mysql \
 --table-size=100000 \
 --mysql-host=aurora01.*********.ap-northeast-1.rds.amazonaws.com \
 --mysql-user=awsuser \
 --mysql-password=********* \
 --mysql-db=mydb \
 --db-ps-mode=disable \
 prepare
function event(thread_id)
        db_query("select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad")
end

負荷をかける

  • 負荷をかける
$ sysbench /usr/share/sysbench/select_sort.lua \
 --db-driver=mysql \
 --mysql-db=mydb \
 --mysql-host=aurora01.*********.ap-northeast-1.rds.amazonaws.com \
 --mysql-user=awsuser \
 --mysql-password=********* \
 --time=300 \
 --db-ps-mode=disable \
 --threads=30 \
 run
  • 実行結果
sysbench 1.0.15 (using bundled LuaJIT 2.1.0-beta2)

Running the test with following options:
Number of threads: 30
Initializing random number generator from current time


Initializing worker threads...

Threads started!

FATAL: mysql_store_result() returned error 3 (Error writing file '/rdsdbdata/tmp/MYz8AJRr' (Errcode: 28 - No space left on device))
FATAL: `thread_run' function failed: /usr/share/sysbench/select_sort.lua:2: db_query() failed
FATAL: mysql_store_result() returned error 3 (Error writing file '/rdsdbdata/tmp/MY4EuUqw' (Errcode: 28 - No space left on device))
FATAL: `thread_run' function failed: /usr/share/sysbench/select_sort.lua:2: db_query() failed
(中略)
FATAL: mysql_store_result() returned error 3 (Error writing file '/rdsdbdata/tmp/MYoI30Js' (Errcode: 28 - No space left on device))
FATAL: `thread_run' function failed: /usr/share/sysbench/select_sort.lua:2: db_query() failed
FATAL: mysql_store_result() returned error 3 (Error writing file '/rdsdbdata/tmp/MYgWJgNX' (Errcode: 28 - No space left on device))

性能統計情報を確認する

  • performance_schema.events_statements_current を確認する
mysql> select thread_id, sql_text, sort_range, sort_rows, sort_scan,created_tmp_disk_tables, created_tmp_tables from performance_schema.events_statements_current where sql_text = 'select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad';
+-----------+-------------------------------------------------------------------------------------------+------------+-----------+-----------+-------------------------+--------------------+
| thread_id | sql_text                                                                                  | sort_range | sort_rows | sort_scan | created_tmp_disk_tables | created_tmp_tables |
+-----------+-------------------------------------------------------------------------------------------+------------+-----------+-----------+-------------------------+--------------------+
|       533 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       534 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       535 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       536 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       537 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       538 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       539 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       540 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       541 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       542 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       543 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       544 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       545 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       546 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       547 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       548 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       549 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       550 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       551 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       552 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       553 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       554 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       555 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       556 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       557 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       558 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       559 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       560 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       561 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
|       562 | select c.* from (select a.* from mydb.sbtest1 a cross join sbtest1 b) as c order by c.pad |          0 |         0 |         0 |                       1 |                  1 |
+-----------+-------------------------------------------------------------------------------------------+------------+-----------+-----------+-------------------------+--------------------+
30 rows in set (0.42 sec)

参考

MySQLトラブルシューティング

MySQLトラブルシューティング

2018-07-11

chroot を使ってみる

  • 環境
$ cat /etc/issue
Amazon Linux AMI release 2018.03
Kernel \r on an \m

$ uname -r
4.14.33-51.37.amzn1.x86_64
  • 準備
$ mkdir -p change/the/dir
$ cd change/the/dir
$ cp --parents /bin/bash .
$ sudo cp --parents /bin/ls .
$ sudo cp --parents /bin/rm .
$ sudo cp -pr --parents /lib64 .
$ sudo cp -pr --parents /usr/lib64 .
$ sudo chroot . /bin/bash
bash-4.2#
bash-4.2# pwd
/
bash-4.2# ls
bin  lib64  usr
bash-4.2# rm -fr /
rm: it is dangerous to operate recursively on '/'
rm: use --no-preserve-root to override this failsafe
bash-4.2# rm -fr --no-preserve-root /
rm: cannot remove '/': Device or resource busy
bash-4.2# ls
bash: /bin/ls: No such file or directory
bash-4.2# exit
exit
$ ls

参考

2018-07-10

Docker を Mac にインストールする

ダウンロード


インストール

f:id:yohei-a:20180711020033p:image


起動する

f:id:yohei-a:20180711020029p:image

f:id:yohei-a:20180711020025p:image


使ってみる

  • Docker Hub からイメージを pull する
$ docker pull bash
  • 実行する
$ docker run -it --rm bash:4.4
Unable to find image 'bash:4.4' locally
4.4: Pulling from library/bash
Digest: sha256:f72240387ad0a579251a00c1d12dd12845e0d3336a3b518b5c267cdddf18f2f2
Status: Downloaded newer image for bash:4.4
bash-4.4#

環境

2018-06-12

MySQL on CentOS 6.9 に sysbench でベンチマークをかけてみる

ファイルシステムの初期化

  • ファイルシステムを初期化する
# mkdir /nvme0n1 /e32000
# fdisk -l
# mkfs.ext4 /dev/nvme0n1
# mkfs.ext4 /dev/xvdb
# mount /dev/nvme0n1 /nvme01
# mount /dev/xvdb /e32000

インストール

  • MySQLyum リポジトリを追加する
# yum -y install http://dev.mysql.com/get/mysql-community-release-el6-5.noarch.rpm
# yum -y install mysql-community-server
# curl -s https://packagecloud.io/install/repositories/akopytov/sysbench/script.rpm.sh | sudo bash
# sudo yum -y install sysbench
# yum -y install strace 
# mysql -u root
  • データベースを作成する
mysql> create database mydb;
  • テーブルを作成してデータをロードする
$ sysbench /usr/share/sysbench/oltp_read_write.lua \
 --db-driver=mysql \
 --table-size=100000 \
 --mysql-user=root \
 --mysql-db=mydb \
 --db-ps-mode=disable \
 prepare
  • datadir 配下のファイルをコピーしておく
# service mysqld stop
# cp -pr /var/lib/mysql /nvme01/
# cp -pr /var/lib/mysql /dev/shm/
# service mysqld start
  • ベンチマークをかける
$ sysbench /usr/share/sysbench/oltp_read_write.lua \
 --db-driver=mysql \
 --table-size=100000 \
 --mysql-db=mydb \
 --mysql-user=root \
 --time=30 \
 --db-ps-mode=disable \
 --threads=1 \
 run

結果

  • E300
sysbench 1.0.14 (using bundled LuaJIT 2.1.0-beta2)

Running the test with following options:
Number of threads: 1
Initializing random number generator from current time


Initializing worker threads...

Threads started!

SQL statistics:
    queries performed:
        read:                            101892
        write:                           29112
        other:                           14556
        total:                           145560
    transactions:                        7278   (242.57 per sec.)
    queries:                             145560 (★4851.45 per sec.)
    ignored errors:                      0      (0.00 per sec.)
    reconnects:                          0      (0.00 per sec.)

General statistics:
    total time:                          30.0013s
    total number of events:              7278

Latency (ms):
         min:                                    3.78
         avg:                                    4.12
         max:                                   22.54
         95th percentile:                        4.33
         sum:                                29979.87

Threads fairness:
    events (avg/stddev):           7278.0000/0.00
    execution time (avg/stddev):   29.9799/0.00
  • E32000
Running the test with following options:
Number of threads: 1
Initializing random number generator from current time


Initializing worker threads...

Threads started!

SQL statistics:
    queries performed:
        read:                            99582
        write:                           28452
        other:                           14226
        total:                           142260
    transactions:                        7113   (237.08 per sec.)
    queries:                             142260 (4741.55 per sec.)
    ignored errors:                      0      (0.00 per sec.)
    reconnects:                          0      (0.00 per sec.)

General statistics:
    total time:                          30.0007s
    total number of events:              7113

Latency (ms):
         min:                                    3.88
         avg:                                    4.21
         max:                                    7.83
         95th percentile:                        4.41
         sum:                                29979.78

Threads fairness:
    events (avg/stddev):           7113.0000/0.00
    execution time (avg/stddev):   29.9798/0.00
  • NVMe
Running the test with following options:
Number of threads: 1
Initializing random number generator from current time


Initializing worker threads...

Threads started!

SQL statistics:
    queries performed:
        read:                            152558
        write:                           43588
        other:                           21794
        total:                           217940
    transactions:                        10897  (363.17 per sec.)
    queries:                             217940 (★7263.49 per sec.)
    ignored errors:                      0      (0.00 per sec.)
    reconnects:                          0      (0.00 per sec.)

General statistics:
    total time:                          30.0027s
    total number of events:              10897

Latency (ms):
         min:                                    2.49
         avg:                                    2.75
         max:                                    4.85
         95th percentile:                        2.81
         sum:                                29972.98

Threads fairness:
    events (avg/stddev):           10897.0000/0.00
    execution time (avg/stddev):   29.9730/0.00
  • tmpfs
sysbench 1.0.14 (using bundled LuaJIT 2.1.0-beta2)

Running the test with following options:
Number of threads: 1
Initializing random number generator from current time


Initializing worker threads...

Threads started!

SQL statistics:
    queries performed:
        read:                            209902
        write:                           59972
        other:                           29986
        total:                           299860
    transactions:                        14993  (499.73 per sec.)
    queries:                             299860 (★9994.51 per sec.)
    ignored errors:                      0      (0.00 per sec.)
    reconnects:                          0      (0.00 per sec.)

General statistics:
    total time:                          30.0003s
    total number of events:              14993

Latency (ms):
         min:                                    1.89
         avg:                                    2.00
         max:                                    4.16
         95th percentile:                        2.07
         sum:                                29982.17

Threads fairness:
    events (avg/stddev):           14993.0000/0.00
    execution time (avg/stddev):   29.9822/0.00

システムコール(fsyncの所要時間)

  • コマンド
# strace -yy -fe fsync -Tttp <PID>
  • E300
[pid 28833] 15:16:59.322025 fsync(9</var/lib/mysql/ib_logfile1>) = 0 <0.001616>
[pid 28833] 15:16:59.340313 fsync(9</var/lib/mysql/ib_logfile1>) = 0 <0.001362>
[pid 28833] 15:16:59.358445 fsync(9</var/lib/mysql/ib_logfile1>) = 0 <0.001512>
  • NVMe
[pid 28510] 15:14:48.225248 fsync(8</nvme01/mysql/ib_logfile0>) = 0 <0.000204>
[pid 28510] 15:14:48.241499 fsync(8</nvme01/mysql/ib_logfile0>) = 0 <0.000194>
[pid 28510] 15:14:48.257621 fsync(8</nvme01/mysql/ib_logfile0>) = 0 <0.000224>
  • tmpfs
[pid  8264] 15:12:02.394681 fsync(9</dev/shm/mysql/ib_logfile1>) = 0 <0.000029>
[pid  8264] 15:12:02.410769 fsync(9</dev/shm/mysql/ib_logfile1>) = 0 <0.000029>
[pid  8264] 15:12:02.426758 fsync(9</dev/shm/mysql/ib_logfile1>) = 0 <0.000030>
[pid  8264] 15:12:02.442635 fsync(9</dev/shm/mysql/ib_logfile1>) = 0 <0.000030>

システムコール(集計)

  • コマンド
# strace -fcp <PID>
  • E300
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 55.57   51.989330       53487       972           io_getevents
 32.08   30.015424        3314      9057      1740 futex
 11.11   10.398417      142444        73           select
  1.01    0.945853      157642         6         5 restart_syscall
  0.15    0.142054          84      1686           fsync
  0.03    0.027272           0    199846           gettimeofday
  0.02    0.014865           0    103448           clock_gettime
  0.01    0.008399           0     65686         2 recvfrom
  0.01    0.007503           0     32842           sendto
  0.00    0.002924           0      8466           madvise
  0.00    0.001104           0      6570           sched_yield
  0.00    0.000734           0      1681           pwrite
  0.00    0.000233           1       339           pread
  0.00    0.000042           0       401           io_submit
  0.00    0.000020           3         6           read
  0.00    0.000000           0         6           open
  0.00    0.000000           0         5           close
  0.00    0.000000           0         1           stat
  0.00    0.000000           0         6           lstat
  0.00    0.000000           0         2           poll
  0.00    0.000000           0         9           lseek
  0.00    0.000000           0         3           mmap
  0.00    0.000000           0        22           mprotect
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0         2         1 access
  0.00    0.000000           0         1           accept
  0.00    0.000000           0         1           shutdown
  0.00    0.000000           0         2         1 setsockopt
  0.00    0.000000           0         5           fcntl
  0.00    0.000000           0         6           getcwd
------ ----------- ----------- --------- --------- ----------------
100.00   93.554174                431151      1749 total
  • NVMe
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 56.05   54.565652       37710      1447           io_getevents
 32.70   31.833832        3075     10353      1931 futex
 11.14   10.849351      139094        78           select
  0.03    0.027523           0    223938           gettimeofday
  0.02    0.022996        3833         6         5 restart_syscall
  0.02    0.016611           9      1892           fsync
  0.01    0.014254           0    115670           clock_gettime
  0.01    0.010720           0     73445         1 recvfrom
  0.01    0.007561           0     36722           sendto
  0.00    0.003592           0      9214           madvise
  0.00    0.002005           0      7359           sched_yield
  0.00    0.000726           0      1883           pwrite
  0.00    0.000205           0       447           pread
  0.00    0.000163           0       888           io_submit
  0.00    0.000000           0         6           read
  0.00    0.000000           0         6           open
  0.00    0.000000           0         5           close
  0.00    0.000000           0         1           stat
  0.00    0.000000           0         6           lstat
  0.00    0.000000           0         1           poll
  0.00    0.000000           0         9           lseek
  0.00    0.000000           0         3           mmap
  0.00    0.000000           0        22           mprotect
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0         2         1 access
  0.00    0.000000           0         1           accept
  0.00    0.000000           0         1           shutdown
  0.00    0.000000           0         2         1 setsockopt
  0.00    0.000000           0         5           fcntl
  0.00    0.000000           0         6           getcwd
------ ----------- ----------- --------- --------- ----------------
100.00   97.355191                483419      1939 total
  • tmpfs
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 55.82   41.885262       11926      3512           io_getevents
 33.08   24.819955        1427     17391      2800 futex
 11.02    8.271746      114885        72           select
  0.03    0.023314           0    230171           gettimeofday
  0.02    0.011618           0    117623           clock_gettime
  0.01    0.007673           0     74685         1 recvfrom
  0.01    0.006094           0     37342           sendto
  0.00    0.002555           0      8772           madvise
  0.00    0.001471           0      7508           sched_yield
  0.00    0.001067           0      3799           io_submit
  0.00    0.001000         167         6         5 restart_syscall
  0.00    0.000930           0      2012           pwrite
  0.00    0.000315           0      2100           fsync
  0.00    0.000000           0         1           close
  0.00    0.000000           0         1           poll
  0.00    0.000000           0         3           pread
  0.00    0.000000           0         1           access
  0.00    0.000000           0         1           accept
  0.00    0.000000           0         1           shutdown
  0.00    0.000000           0         2         1 setsockopt
  0.00    0.000000           0         3           fcntl
------ ----------- ----------- --------- --------- ----------------
100.00   75.033000                505006      2807 total

起動と停止

  • 停止
# service mysqld stop
  • datadir の変更
# vi /etc/my.conf
#datadir=/var/lib/mysql
#datadir=/e32000/mysql
#datadir=/nvme01/mysql
datadir=/dev/shm/mysql

  • 起動
# service mysqld start

環境

  • 16vCPU
  • 122 GB Memory
  • CentOS 6.9 (2.6.32-696.16.1.el6.x86_64)
  • 5.6.40 MySQL Community Server (GPL)

参考

2018-05-17

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スレッド
READ1052795987084121
CLEANUP67548115711665
UPDATE152312286960879450
  • 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スレッド
conn0-33-847-48102102
qr712529998

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

参考