なからなLife

geekに憧れと敬意を抱きながら、SE、ITコンサル、商品企画、事業企画、管理会計、総務・情シス、再び受託でDB屋さんと流浪する人のブログです。

お兄さんとの約束は守ろう!(MySQLのtx_isolationとbinlogの話)

MySQL Casual Advent Calendar 2016 - Qiita 21日目の記事です。


穴があったら埋めたいタイプの人です。5回目。。。


なお、大トリの25日が空いているみたいですが、3年連続であの方でしょうか?(・_|襖|


ある日、MySQLおじさんお兄さんに、、、

f:id:atsuizo:20161216164417p:plain

って言われたので、約束破ってみたw



やることは、以下の通り。

  1. binlog出力ON、binlog_format=MIXED
  2. まったく同じ構造のテーブルを3つ用意
  3. テーブル1に1000万件用意(ibdファイル1.6GB)
  4. ログをFLHSH
  5. REPEATABLE-READで、テーブル1からテーブル2へINSERT ... SELECT 全件
  6. ログをFLHSH
  7. READ-COMMITTEDに切り替えて、テーブル1からテーブル3へINSERT ... SELECT 全件
  8. ログをFLHSH
  9. ログファイル確認

実験結果

WindowsノートPCの上で動いているLinux on VirtualBoxなMySQL5.6.35なので、処理時間は絶対値じゃなく相対的なものとして見ていただくのが良いと思います。

tx_isolation Insert Select時間 ログサイズ
REPEATABLE-READ 7 min 9.53 sec 400Byte程度
READ-COMMITTED 8 min 33.82 sec 1.3GB


binlog_format=MIXED、tx_isolation=REPEATABLE-READの場合、STATEMENTベースでログ出力されます。400Byte程度の中にはファイルヘッダ的なものもありますが、INSERTのログ自体はSQL文1行そのままです。


binlog_format=MIXED、tx_isolation=READ-COMMITTEDの場合、ROWベースでログ出力されます。そのSQLでの更新行数が多ければ多いほど、STATEMENTベースでの出力量との差は開きますので、それがそのままI/Oの反応速度に跳ね返ってきます。



ログ関係パラメータの調整、ハードウェア側のストレージ見積り、必要IOPSなど、色々な所に影響が出てくるはずです。


「ギャップロック怖い」「ぼくOracle脳」ってだけで安易にREAD-COMMITTEDを選択すると、別の所ではまる可能性がありますね。


特に、プロジェクトの途中から変更(多重度を無闇に上げてギャップロック絡みのデッドロックで悩まされる)する場合は、設計当初のH/W調達要件と違ってきてしまうので、その辺も踏まえた上での対応が必要です。

おまけ

マニュアルにこんな記述があります。

InnoDB テーブルを使用中で、トランザクション分離レベルが READ COMMITTED または READ UNCOMMITTED の場合、行ベースのロギングのみを使用することができます。ロギング形式を STATEMENT に変更することは可能ですが、InnoDB は挿入を実行できないため、実行時にこれを行うと、非常に速くエラーが発生します。
https://dev.mysql.com/doc/refman/5.6/ja/binary-log-setting.html

こんなメッセージです。

mysql> insert into tbl3 select * from tbl1;
ERROR 1665 (HY000): Cannot execute statement: impossible to write to binary log since BINLOG_FORMAT = STATEMENT and at least one table uses a storage engine limited to row-based logging. InnoDB is limited to row-logging when transaction isolation level is READ COMMITTED or READ UNCOMMITTED.

AmazonのRDSは、そもそもSTATEMENTを選択できない(MIXEDかROWのみ)仕様になっているので、このメッセージを見ることは無いかと思いますが、オンプレやEC2等にインストールして動かしている場合は要注意ですね。

まとめ

  • binlog_format=MIXEDのとき、トランザクション分離レベルによって、ログの出力フォーマットが変わる。
  • ログ出力量の差は結構大きいので、ストレージサイズ、IOPS等への影響も考慮しましょう。
  • 約束は守ろう!約束を破るときは、どんなしっぺ返しがあるか考えてからにしよう!

実験エビデンス

こんなかんじです。
はてな「続きを読む」記法使ってるのですが、うまく機能してなかったらごめんなさい。




binlog_format=MIXEDでtx_isolationの違いによる計測
mysql> show create table tbl1\G
*************************** 1. row ***************************
       Table: tbl1
Create Table: CREATE TABLE `tbl1` (
  `id` int(11) NOT NULL DEFAULT '0',
  `col1` char(10) COLLATE utf8mb4_bin DEFAULT NULL,
  `col2` char(10) COLLATE utf8mb4_bin DEFAULT NULL,
  `col3` char(10) COLLATE utf8mb4_bin DEFAULT NULL,
  `col4` char(10) COLLATE utf8mb4_bin DEFAULT NULL,
  `delete_flag` tinyint(1) DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin
1 row in set (0.00 sec)

mysql> select * from tbl1 limit 5;
+----+--------------------------------+--------------------------------+--------------------------------+--------------------------------+-------------+
| id | col1                           | col2                           | col3                           | col4                           | delete_flag |
+----+--------------------------------+--------------------------------+--------------------------------+--------------------------------+-------------+
|  1 | あいうえおかきくけこ           | さしすせそたちつてと           | なにぬねのはひふへほ           | まみむめもやゆよわを           |           1 |
|  2 | あいうえおかきくけこ           | さしすせそたちつてと           | なにぬねのはひふへほ           | まみむめもやゆよわを           |           0 |
|  3 | あいうえおかきくけこ           | さしすせそたちつてと           | なにぬねのはひふへほ           | まみむめもやゆよわを           |           1 |
|  4 | あいうえおかきくけこ           | さしすせそたちつてと           | なにぬねのはひふへほ           | まみむめもやゆよわを           |           0 |
|  5 | あいうえおかきくけこ           | さしすせそたちつてと           | なにぬねのはひふへほ           | まみむめもやゆよわを           |           1 |
+----+--------------------------------+--------------------------------+--------------------------------+--------------------------------+-------------+
5 rows in set (0.04 sec)


mysql> show tables;
+-----------------------+
| Tables_in_test_binlog |
+-----------------------+
| tbl1                  |
| tbl2                  |
| tbl3                  |
+-----------------------+
3 rows in set (0.00 sec)


mysql> select @@log_bin,@@binlog_format;
+-----------+-----------------+
| @@log_bin | @@binlog_format |
+-----------+-----------------+
|         1 | MIXED           |
+-----------+-----------------+
1 row in set (0.00 sec)


mysql> select @@tx_isolation;
+-----------------+
| @@tx_isolation  |
+-----------------+
| REPEATABLE-READ |
+-----------------+
1 row in set (0.00 sec)

mysql> FLUSH LOGS;
Query OK, 0 rows affected (0.05 sec)

mysql> insert into tbl2 select * from tbl1;
Query OK, 10000000 rows affected (7 min 9.53 sec)
Records: 10000000  Duplicates: 0  Warnings: 0

mysql> FLUSH LOGS;
Query OK, 0 rows affected (0.06 sec)


mysql> set @@session.tx_isolation='READ-COMMITTED';
Query OK, 0 rows affected (0.00 sec)

mysql> select @@tx_isolation;
+----------------+
| @@tx_isolation |
+----------------+
| READ-COMMITTED |
+----------------+
1 row in set (0.00 sec)

mysql> FLUSH LOGS;
Query OK, 0 rows affected (0.05 sec)

mysql> insert into tbl3 select * from tbl1;
Query OK, 10000000 rows affected (8 min 33.82 sec)
Records: 10000000  Duplicates: 0  Warnings: 0


000002が、binlog_format=MIXED` で `tx_isolation=READ-COMMITTED` な時のログ。

# ll -h mysqld-bin.*
-rw-rw---- 1 mysql mysql  415 1216 15:38 2016 mysqld-bin.000001
-rw-rw---- 1 mysql mysql 1.3G 1216 15:49 2016 mysqld-bin.000002
-rw-rw---- 1 mysql mysql  120 1216 15:49 2016 mysqld-bin.000003
-rw-rw---- 1 mysql mysql   60 1216 15:49 2016 mysqld-bin.index
binlog_format=STATEMENTでtx_isolation=READ-COMMITTEDなやつ
mysql> select @@log_bin,@@binlog_format;
+-----------+-----------------+
| @@log_bin | @@binlog_format |
+-----------+-----------------+
|         1 | STATEMENT       |
+-----------+-----------------+
1 row in set (0.00 sec)

mysql> select @@tx_isolation;
+-----------------+
| @@tx_isolation  |
+-----------------+
| REPEATABLE-READ |
+-----------------+
1 row in set (0.00 sec)

mysql> set @@session.tx_isolation='READ-COMMITTED';
Query OK, 0 rows affected (0.00 sec)

mysql> select @@tx_isolation;
+----------------+
| @@tx_isolation |
+----------------+
| READ-COMMITTED |
+----------------+
1 row in set (0.00 sec)

mysql> insert into tbl3 select * from tbl1;
ERROR 1665 (HY000): Cannot execute statement: impossible to write to binary log since BINLOG_FORMAT = STATEMENT and at least one table uses a storage engine limited to row-based logging. InnoDB is limited to row-logging when transaction isolation level is READ COMMITTED or READ UNCOMMITTED.