Hatena::ブログ(Diary)

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

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

インストール

# 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

環境


参考

2018-06-11

MySQL の InnoDB テーブルの断片化の影響を調べてみた

準備

  • テーブルを作成して1千万件データをロードする
$ sysbench /usr/share/sysbench/oltp_read_write.lua \
 --db-driver=mysql \
 --table-size=10000000 \
 --mysql-host=aurora01.******.ap-northeast-1.rds.amazonaws.com \
 --mysql-user=awsuser \
 --mysql-password=****** \
 --mysql-db=mydb \
 --db-ps-mode=disable \
 prepare
  • テーブルの件数と空き領域を確認する
mysql> select table_schema, table_name, data_free, table_rows from information_schema.tables where table_name='sbtest1';
+--------------+------------+-----------+------------+
| table_schema | table_name | data_free | table_rows |
+--------------+------------+-----------+------------+
| mydb         | sbtest1    |   3145728 |    9867937 |
+--------------+------------+-----------+------------+
1 row in set (0.00 sec)
  • 断片化させるプロシージャを作成する
mysql> delimiter //
mysql> create procedure fragment_sbtest1(in x int, in y int)
begin
 while x < y do
  delete from mydb.sbtest1 where id = x;
  set x = x + 2;
 end while;
end
//
mysql> delimiter ;

クエリ実行時間を測定する

1千万件
  • 実行時間は1分15秒程度
mysql> select count(pad) from sbtest1;
+------------+
| count(pad) |
+------------+
|   10000000 |
+------------+
1 row in set (1 min 15.50 sec)

mysql> select count(pad) from sbtest1;
+------------+
| count(pad) |
+------------+
|   10000000 |
+------------+
1 row in set (1 min 17.92 sec)
5百万件(断片化状態)
  • データを歯抜けに削除する
mysql> call fragment_sbtest1(1, 10000000);
  • テーブルの件数と空き領域を確認する
mysql> select table_schema, table_name, data_free, table_rows from information_schema.tables where table_name='sbtest1';
+--------------+------------+-----------+------------+
| table_schema | table_name | data_free | table_rows |
+--------------+------------+-----------+------------+
| mydb         | sbtest1    |   7340032 |    4922775 |
+--------------+------------+-----------+------------+
1 row in set (0.02 sec)
  • 実行時間は1分10秒程度でほぼ変化なし。
mysql> select count(pad) from sbtest1;
+------------+
| count(pad) |
+------------+
|    5000000 |
+------------+
1 row in set (1 min 8.51 sec)

mysql> select count(pad) from sbtest1;
+------------+
| count(pad) |
+------------+
|    5000000 |
+------------+
1 row in set (1 min 12.69 sec)

5百万件(断片化後)
  • 断片化を解消する
mysql> alter table sbtest1 engine innodb;
Query OK, 0 rows affected (34.10 sec)
Records: 0  Duplicates: 0  Warnings: 0
  • テーブルの件数と空き領域を確認する
mysql> select table_schema, table_name, data_free, table_rows from information_schema.tables where table_name='sbtest1';
+--------------+------------+-----------+------------+
| table_schema | table_name | data_free | table_rows |
+--------------+------------+-----------+------------+
| mydb         | sbtest1    |   4194304 |    5154227 |
+--------------+------------+-----------+------------+
1 row in set (0.00 sec)
  • 実行時間は35秒程度と半分程度に短縮。
mysql> select count(pad) from sbtest1;
+------------+
| count(pad) |
+------------+
|    5000000 |
+------------+
1 row in set (35.31 sec)

mysql> select count(pad) from sbtest1;
+------------+
| count(pad) |
+------------+
|    5000000 |
+------------+
1 row in set (34.81 sec)

環境

"select count(pad) from sbtest1" で実行時間を測定したインスタンスは以下の通り。性能差を測定するためミニマムな環境にした。

  • db.t2.small
  • query_cache_type: 0
  • innodb_buffer_pool_size: 67108864

2018-06-10

MySQL の InnoDB テーブルの断片化状況を確認する

MySQLInnoDB テーブルの空き領域は INFORMATION_SCHEMA.TABLES の DATA_FREE カラムで確認でき、ALTER TABLE <テーブル名> ENGINE INNODB で断片化(フラグメンテーション)を解消することができる。なお、テーブルの断片化でI/O量が増えて性能劣化するのはフルテーブルスキャンで、インデックススキャンは影響を受けない。


前提


確認方法

select table_schema, table_name, data_free, table_rows
	from information_schema.tables
	where table_name='テーブル名';

  • テーブルを作成してデータをロードする
$ sysbench /usr/share/sysbench/oltp_read_write.lua \
 --db-driver=mysql \
 --table-size=10000 \
 --mysql-host=aurora01.******.ap-northeast-1.rds.amazonaws.com \
 --mysql-user=awsuser \
 --mysql-password=******** \
 --mysql-db=mydb \
 --db-ps-mode=disable \
 prepare
  • 1件を残して削除する
mysql> delete from sbtest1 where id < 10000;
Query OK, 9999 rows affected (0.16 sec)
  • テーブルの空き領域を確認する
mysql> select table_schema, table_name, data_free, table_rows
    -> from information_schema.tables
    -> where table_name='sbtest1';
+--------------+------------+-----------+------------+
| table_schema | table_name | data_free | table_rows |
+--------------+------------+-----------+------------+
| mydb         | sbtest1    |   6291456 |          1 |
+--------------+------------+-----------+------------+
1 row in set (0.00 sec)
mysql> alter table sbtest1 engine innodb;
Query OK, 0 rows affected (0.08 sec)
Records: 0  Duplicates: 0  Warnings: 0
mysql> select table_schema, table_name, data_free, table_rows
    -> from information_schema.tables
    -> where table_name='sbtest1';
+--------------+------------+-----------+------------+
| table_schema | table_name | data_free | table_rows |
+--------------+------------+-----------+------------+
| mydb         | sbtest1    |         0 |          1 |
+--------------+------------+-----------+------------+
1 row in set (0.00 sec)

参考

DATA_FREE カラムには、InnoDB テーブルの空き領域がバイト単位で表示されます。

MySQL :: MySQL 5.6 リファレンスマニュアル :: 21.22 INFORMATION_SCHEMA TABLES テーブル

少し話がそれてしまったが、OPTIMIZEが必要になるのはどういう時だろうか?簡単にいうと、「行をDELETEのして無駄な領域がたくさん生じたとき」だけである。これによって、利用されていない領域が回収されることになる。そして、フラグメンテーションが解消するわけである。

実は、InnoDBにはOPTIMIZE TABLEに相当する機能は実装されておらず、代わりにALTER TABLEが実行される。OPTIMIZE TABLE t1は次のコマンドを実行するのと同じなのである。

mysql> ALTER TABLE t1 ENGINE INNODB;

このコマンドを実行すると、テーブルのデータが詰め直される。データの挿入は主キーの順番で行われるため、OPTIMIZE TABLEすると

という効果が期待できることになる。残念ながら、セカンダリインデックスセカンダリインデックスの順番で詰め直す方法はない。そのため、セカンダリインデックスの空間効率はあまりよくない場合があるので注意が必要である。

OPTIMIZE TABLEが内部的にALTER TABLEと同じということは、別に悪いことばかりではない。モノホンのOPTIMIZE TABLEだと実行中は参照も更新もブロックしてしまうことになるが、ALTER TABLEであればメンテナンス中も参照は可能なのである。

漢(オトコ)のコンピュータ道: 大人のためのInnoDBテーブルとの正しい付き合い方。

13.7.2.4 OPTIMIZE TABLE 構文

OPTIMIZE [NO_WRITE_TO_BINLOG | LOCAL] TABLE
    tbl_name [, tbl_name] ...

ストレージ領域を削減し、テーブルアクセス時の I/O 効率を向上させるために、テーブルデータとそれに関連付けられたインデックスデータの物理ストレージを再編成します。各テーブルに加えられる正確な変更は、そのテーブルによって使用されているストレージエンジンによって異なります。

OPTIMIZE TABLE は、テーブルのタイプに応じて次の場合に使用します。

  • innodb_file_per_table オプションが有効な状態で作成されたために独自の .ibd ファイル を含む InnoDB テーブルに対して大量の挿入、更新、または削除操作を行なったあと。テーブルとインデックスが再編成されるため、ディスク領域をオペレーティングシステムによる使用のために再利用できます。
  • InnoDB テーブル内の FULLTEXT インデックスの一部であるカラムに対して大量の挿入、更新、または削除操作を行なったあと。最初に、構成オプション innodb_optimize_fulltext_only=1 を設定します。インデックス保守期間を妥当な時間に維持するために、検索インデックスで更新するワード数を指定する innodb_ft_num_word_optimize オプションを設定し、検索インデックスが完全に更新されるまで OPTIMIZE TABLE ステートメントシーケンスを実行します。
  • MyISAM または ARCHIVE テーブルの大きな部分を削除するか、あるいは可変長行を含む MyISAM または ARCHIVE テーブル (VARCHAR、VARBINARY、BLOB、または TEXT カラムを含むテーブル) に多くの変更を行なったあと。削除された行はリンクリスト内に保持され、以降の INSERT 操作は古い行の位置を再利用します。OPTIMIZE TABLE を使用すると、未使用領域を再利用したり、データファイルをデフラグしたりできます。テーブルを大幅に変更したあとは、このステートメントにより、そのテーブルを使用するステートメントのパフォーマンスを (場合によっては大幅に) 向上させることができます。

(中略)

InnoDB の詳細

InnoDB テーブルの場合、OPTIMIZE TABLE は ALTER TABLE ... FORCE にマップされます。これは、インデックス統計を更新し、クラスタ化されたインデックス内の未使用領域を解放するためにテーブルを再構築します。これは、次に示すように、InnoDB テーブルに対して実行したときに OPTIMIZE TABLE の出力に表示されます。

MySQL :: MySQL 5.6 リファレンスマニュアル :: 13.7.2.4 OPTIMIZE TABLE 構文

MySQL 5.0以降は、INFORMATION_SCHEMAという便利なシロモノがある。SHOW TABLE STATUSコマンドを利用する代わりに、INFOMATION_SCHEMA.TABLESテーブルを参照することで同様の情報を表示することが可能であり、innodb_file_per_tableオプション利用時は次のように利用することで、全てのテーブルに関する情報を一括表示することが可能だ。

mysql> SELECT TABLE_SCHEMA,TABLE_NAME,DATA_FREE
    -> FROM INFORMATION_SCHEMA.TABLES
    -> WHERE ENGINE='innodb';
mysql> SELECT TABLE_SCHEMA,SUM(DATA_FREE)
    -> FROM INFORMATION_SCHEMA.TABLES
    -> WHERE ENGINE='innodb'
    -> GROUP BY TABLE_SCHEMA WITH ROLLUP;

SHOWコマンドの出力は加工することは出来ないが、INFORMATION_SCHEMAは好きなようにWHERE句で絞り込みを行ったり集計したりすることができるので便利なのだ。

ところで、Data_freeの数値はInnoDBにおいてどの程度信頼できるのだろうか。

InnoDBのテーブルスペース内では、データは16KBのページ単位で管理されており、さらに64個の連続するページから成るエクステントにグループ化されている。InnoDBテーブルからデータを削除すると、対応するBツリーインデックスが縮小される。これによって、他のテーブルに対して空き領域が再利用できるかどうかは、削除のパターンがテーブルスペースの個々のページやエクステントを解放するかどうかによる。エクステントが解放された場合には、そのエクステントは他のテーブルによって再利用されるが、個々のページやページの一部だけが開放されただけの場合には他のテーブルによって再利用されることはない。つまり、Data_freeは使用されていないエクステントのサイズであり、ページ単位で見ると空き領域がある場合があるということだ。しかしながら、領域を再利用できるかどうかはエクステント全体が空いているかどうかで決まるため、Data_freeはほぼ正確な空き領域を示していると言える。

最後にちょっとだけ内部構造的な話。SHOW TABLE STATUSやINFORMATION_SCHEMAの情報は、最終的にはinnobase/fsp/fsp0fsp.c内のfsp_get_available_space_in_free_extents()関数によって値が取得される。関数引数はテーブルスペースのIDである。下記は関数の末尾からの抜粋である。

return((ullint)(n_free - reserve)
* FSP_EXTENT_SIZE
* (UNIV_PAGE_SIZE / 1024));

空き領域(n_free)から予約された領域(reserve)を引いたものに、一つのエクステントに含まれるページ数(FSP_EXTENT_SIZE=64)を掛けて、さらにページサイズ(UNIV_PAGE_SIZE/1024=16kb)を掛けたものを返しているというワケである。興味のある人はソースコードを覗いてみよう。

漢(オトコ)のコンピュータ道: InnoDBテーブルスペースの空き領域

2018-06-06

Aurora MySQL で DDL を実行してみる

準備

  • データをロードする
$ sysbench /usr/share/sysbench/oltp_read_write.lua \
 --db-driver=mysql \
 --table-size=500000 \
 --mysql-host=aurora01.*********.ap-northeast-1.rds.amazonaws.com \
 --mysql-user=awsuser \
 --mysql-password=********* \
 --mysql-db=mydb \
 --db-ps-mode=disable \
 prepare
mysql> select count(id) from sbtest1;
+-----------+
| count(id) |
+-----------+
|   5000000 |
+-----------+
1 row in set (0.82 sec)

DDL実行

  • カラムを追加する
mysql> alter table sbtest1 add added_col1 char(255);
Query OK, 0 rows affected (53.13 sec)
Records: 0  Duplicates: 0  Warnings: 0
mysql> alter table sbtest1 add added_col2 char(255) default 'abcdefghijklmnopqrstuvwxyz';
Query OK, 0 rows affected (1 min 9.43 sec)
Records: 0  Duplicates: 0  Warnings: 0
  • テーブル定義を確認する
mysql> desc sbtest1;
+------------+-----------+------+-----+----------------------------+----------------+
| Field      | Type      | Null | Key | Default                    | Extra          |
+------------+-----------+------+-----+----------------------------+----------------+
| id         | int(11)   | NO   | PRI | NULL                       | auto_increment |
| k          | int(11)   | NO   | MUL | 0                          |                |
| c          | char(120) | NO   |     |                            |                |
| pad        | char(60)  | NO   |     |                            |                |
| added_col1 | char(255) | YES  |     | NULL                       |                |
| added_col2 | char(255) | YES  |     | abcdefghijklmnopqrstuvwxyz |                |
+------------+-----------+------+-----+----------------------------+----------------+
6 rows in set (0.00 sec)

DML実行

mysql> START TRANSACTION;
Query OK, 0 rows affected (0.00 sec)

mysql> update sbtest1 set added_col1 = '123' where id = 1;
Query OK, 0 rows affected (0.00 sec)
Rows matched: 1  Changed: 0  Warnings: 0

mysql> commit;
Query OK, 0 rows affected (0.01 sec)

参考

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

参考

YCSB をビルドしようとすると "invalid target release: 1.8" と怒られる

事象

  • YCSB をビルドしようとすると "invalid target release: 1.8" と怒られる。
$ git clone https://github.com/brianfrankcooper/YCSB.git 
$ mvn clean package
Failed to execute goal org.apache.maven.plugins:maven-compiler-plugin:3.1:compile (default-compile) on project hm_app: Fatal error compiling: invalid target release: 1.8 -> [Help 1]

解決策

$ sudo yum -y install java-1.8.0-openjdk-devel
  • JDK 1.8 に切替える
$ 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
  • YCSB をビルドする
$ mvn clean package

参考