MySQL5.6で実装されたMulti Threads Slave（以下、MTS）は、MySQLレプリケーションを利用するユーザ共通の悩みである「スレーブ遅延」に対するソリューションの一つです。
スレーブ遅延の主因の一つは、スレーブのSQLスレッドが「1つ」しかないことでした。しかし、MySQL5.6からMTSを用いることで異なるデータベース間で複数スレッドによる並列処理が可能となり、MySQL5.7からは同一データベースでも並列処理が可能となりました。この結果、スレーブの遅延はかなり軽減されています。
しかし、以前MTSの検証をしていて気になる挙動を見つけたので、記載したいと思います。
事象の内容
きっかけは大きなバッチ処理を実行した時、マスタの実行時間よりも大幅に長くスレーブでの処理に時間がかかってしまう、という事象でした。
調査を進めるうちにエラーログに以下のようなメッセージが大量に出力されているのが分かりました。
|
1 |
[Note] Multi-threaded slave: Coordinator has waited 611 times hitting slave_pending_jobs_size_max; current event size = 8169. |
上記のメッセージは、マスタから送られたレプリケーションイベントのサイズが、スレーブのworkerスレッドの使用メモリ量を超えてしまった場合に、処理が待ち状態になっていることを示しています。「workerスレッドの使用メモリ量」は、slave_pending_jobs_size_max変数で決められます。
再現手順
AWSの「c5.xlarge」インスタンスを3台作成し、MySQL5.7の最新版をyumインストールします（この時点ではMySQL5.7.21）。
その後、「マスタ1台：スレーブ2台」のGTIDレプリケーション環境を構築し、MTSを設定します。なお、パラメータは以下の通り変更します。
master : max_allowed_packet=32MB
slave1 : max_allowed_packet=32MB / slave_pending_jobs_size_max=16MB
slave2 : max_allowed_packet=32MB / slave_pending_jobs_size_max=128MB
※ slave_parallel_workers変数は “4” で統一しています
この環境で、マスタでランダムデータのINSERT文を実行しています。
|
1 2 3 4 5 6 7 8 9 |
master$ mysql -u root -p mysql> CREATE DATABASE d1; mysql> USE d1; mysql> CREATE TABLE t1 (id int auto_increment primary key, col1 varchar(30), col2 varchar(30), col3 varchar(30)); mysql> INSERT t1 (col1,col2,col3) SELECT SUBSTRING(MD5(RAND()), 1, 30),SUBSTRING(MD5(RAND()), 1, 30),SUBSTRING(MD5(RAND()), 1, 30); mysql> INSERT t1 (col1,col2,col3) SELECT SUBSTRING(MD5(RAND()), 1, 30),SUBSTRING(MD5(RAND()), 1, 30),SUBSTRING(MD5(RAND()), 1, 30) FROM t1; ... 以下、繰り返し |
するとトランザクションのサイズが一定を超えた段階で、以下のようなメッセージがslave1のエラーログに出力されます。この時、スレーブで大幅な遅延が起きている可能性があります。
※ 別コンソールで tail -f /var/log/mysqld.log を実行しておくと分かりやすいです
|
1 2 3 4 |
2018-04-25T05:39:08.474653-00:00 2 [Note] Multi-threaded slave: Coordinator has waited 611 times hitting slave_pending_jobs_size_max; current event size = 8169. 2018-04-25T05:39:08.477240-00:00 2 [Note] Multi-threaded slave: Coordinator has waited 621 times hitting slave_pending_jobs_size_max; current event size = 8169. 2018-04-25T05:39:08.485007-00:00 2 [Note] Multi-threaded slave: Coordinator has waited 631 times hitting slave_pending_jobs_size_max; current event size = 8169. 2018-04-25T05:39:08.487578-00:00 2 [Note] Multi-threaded slave: Coordinator has waited 641 times hitting slave_pending_jobs_size_max; current event size = 8169. |
一方で、slave_pending_jobs_size_max変数を大きく設定しているslave2では同様のメッセージは発生していません。
対策
上記の問題を回避するためには、slave_pending_jobs_size_max 変数をあらかじめ大きくすることが推奨されます。特にマスタで巨大なトランザクションが実行されるケースが想定されるなら、ある程度大きい数値を設定すると良いでしょう。
また、max_allowed_packet > slave_pending_jobs_size_max という設定をしてしまうと、ペンディングが頻発する可能性があります。slave_pending_jobs_size_max のデフォルト値は「16MB」と少し小さめなので、注意しましょう。
参考URL
Multi-Threaded Slave Statistics
17.1.4.3 レプリケーションスレーブのオプションと変数
