2017年12月9日土曜日

ファイル倉庫系DBをSQLiteでなんとかできるか

MySQLのDBAをしていると、MySQLを「SQLでアクセス可能なファイル倉庫」として使う人たちに出会うことがある。

彼らの要件はだいたいこんな感じ・・・

  • SQLを喋れる「何か」である必要があるが、MySQLである必要はない
  • DBサーバに入れておけば、可用性やバックアップ面が担保されているので楽チンだからDBに入れる
  • DBサーバを自分たちで運用したくない
  • 処理はアドホックに行われ、雑なSQLが流れる、多くは解析系
  • ログやバイナリを雑に保存する。容量が増えていく

ファイル倉庫系は「そこそこ」動いてれば良いので問題が出ても根本対策がされず、だましだまし運用を続ける、「癌化」しやすい注意案件である。

Excel 以上、MySQL 未満 がマッチしているような案件…SQLite が使えるかも?と思ったので検証してみる。

SQLite は今や Mac OSやiOSに同梱されており、実績は十分である。Percona LIVEのkeynote のスライドを見るとSQLiteはぜんぜん「Lite」ではない高機能なプロダクトであることがわかる。

SQLiteのデータベースは単一ファイル。レプリカを作りたければ、他のサーバにデータファイルをコピーするだけで良い。
冗長化やバックアップも(そこそこのレベルで良いのであれば)非常にお手軽である。

検証環境

SQLite はローカルで更新・参照して計測した、MySQL はDBサーバとクライアントは分離する。
設定は全部デフォ。メモリはデータ量以上に積んでるので基本すべてメモリにキャッシュされている状態で試した。 サーバはVMと、、、割りと雑な検証です。。。
$ rpm -qa |egrep 'sqlite|mysql-community-server'
sqlite-3.7.17-8.el7.x86_64
mysql-community-server-5.7.20-1.el7.x86_64

容量比較

sysbench を利用して500万行のテーブルを作る。

$ sudo ls -alh /var/lib/mysql/sbtest
total 1.2G
drwxr-x--- 2 mysql mysql   55 Dec  9 15:26 .
drwxr-x--x 7 mysql mysql 4.0K Dec  9 15:22 ..
-rw-r----- 1 mysql mysql   65 Dec  9 15:22 db.opt
-rw-r----- 1 mysql mysql 8.5K Dec  9 15:26 sbtest1.frm
-rw-r----- 1 mysql mysql 1.2G Dec  9 15:26 sbtest1.ibd
こいつを、SELECT OUT INTO でCSVとして出力→sqliteでロードした。
$ ls -alh tmp.db
-rw-r--r--  1 user user 1.1G Dec  9 15:54 tmp.db
どっちも1Gちょい。容量はあまり変わらない。ただし、MySQL (InnoDB) は圧縮が利用できるので、MySQLで圧縮するほうが物理容量面では有利である。
※ データにも依存するが、InnoDBで圧縮すればだいたい半分ぐらいになることが多い。

インポートの時間

ほとんど差がなかった・・・! ネットワーク経由でデータを送るMySQLのほうが多少遅くなると思ったが、そうでもないようだ。

mysql> LOAD DATA LOCAL INFILE 'tmp2.csv' INTO TABLE sbtest1 FIELDS TERMINATED BY ',' ENCLOSED BY '"';
Query OK, 5000000 rows affected (2 min 28.06 sec)
Records: 5000000  Deleted: 0  Skipped: 0  Warnings: 0
$ time sqlite3 tmp.db  < imp.sql

real    2m28.788s
user    0m53.754s
sys     0m19.732s

エクスポートの時間

SQLiteのほうが3割ぐらい速い。

mysql> SELECT * FROM sbtest1 INTO OUTFILE '/var/lib/mysql-files/out.csv' FIELDS TERMINATED BY ','   OPTIONALLY ENCLOSED BY '"';
Query OK, 5000000 rows affected (14.96 sec)
sqlite> .mode csv
sqlite> .output result.csv
sqlite> .timer on
sqlite> SELECT * FROM sbtest1;
CPU Time: user 7.159407 sys 1.355699
ちなみにMySQLでローカルでやった場合もあまり時間は変わらなかった。
mysql>  SELECT * FROM sbtest1 INTO OUTFILE '/var/lib/mysql-files/aout.csv'   FIELDS TERMINATED BY ','   OPTIONALLY ENCLOSED BY '"';
Query OK, 5000000 rows affected (16.35 sec)

まとめ

ファイル倉庫系のワークロードでSQLiteが劣っているようなことはなさそう。
Excel以上、MySQL未満を必要とするユーザに提案してみたい。

2017年12月7日木曜日

MySQLのデッドロックについて

この記事は MySQL Casual Advent Calendar 2017 の7日目です。 最近、デッドロックを真剣に対応する機会があったのでその時のメモです。

デッドロックとは?

デッドロックとは「複数のトランザクションが互いがロックの開放を待ち、結果として、どの処理も先に進めなくなってしまった状態」を指す。 単にロック待ちが長時間になっているケースはデッドロックとは呼ばない。

時間 TRANSACTION(1) TRANSACTION(2)
1 BEGIN
2 BEGIN
3 UPDATE t1 SET col1 = 'session1' WHERE pk = 1;
4 UPDATE t2 SET col1 = 'session2' WHERE pk = 1;
5 UPDATE t2 SET col1 = 'session1' WHERE pk = 1;
※ TRANSACTION 2 がt2のロックを持ってるので進めない
6 UPDATE t1 SET col1 = 'session2' WHERE pk = 1;
※ TRANSACTION 1 がt1のロックを持ってるので進めない

MySQL (InnoDB) はデッドロック状態になった場合、片方のトランザクションを強制ロールバックし、もう片方のトランザクションに必要な ロックを獲得させ、処理を進める。その際、強制ロールバックされたクエリは以下のエラーが発生する。

mysql> UPDATE t1 SET col1 = 'session2' WHERE pk = 1;
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

デッドロックの対処方法


1. リトライ

根本的な対応ではないが、良くとられる解決策。 タイミング悪く更新が重なったときに起こる程度であれば、リトライで十分。

2. クエリを修正し、ロックを獲得する順番を揃える

上記の例でいうと、片方のトランザクションがt1→t2 という順でロックしているのに対し、もう片方はt2→t1という順でロックしているため、互いにロックを取り合う構造になっている。 ロックを取る順番を揃えれば、デッドロックにはならない(後続のクエリは待つ)。

3. ロックを取る範囲を小さくする

MySQL は条件に一致した行ではなく、スキャンした行やインデックスをロックする。 例えば、以下のクエリは条件にマッチする行が1つもないが、全部の行をロックしてしまう。

mysql> SELECT * FROM t1;
+----+------+
| pk | col1 |
+----+------+
|  1 | t1-1 |
|  2 | t1-2 |
|  3 | t1-3 |
|  4 | t1-4 |
|  5 | t1-5 |
+----+------+
5 rows in set (0.00 sec)

mysql> BEGIN;

-- mysql> EXPLAIN SELECT * FROM t1 WHERE col1 = 'INVALID' FOR UPDATE;
-- +----+-------------+-------+------------+------+---------------+------+---------+------+------+----------+-------------+
-- | id | select_type | table | partitions | type | possible_keys | key  | key_len | ref  | rows | filtered | Extra       |
-- +----+-------------+-------+------------+------+---------------+------+---------+------+------+----------+-------------+
-- |  1 | SIMPLE      | t1    | NULL       | ALL  | NULL          | NULL | NULL    | NULL |    5 |    20.00 | Using where |
-- +----+-------------+-------+------------+------+---------------+------+---------+------+------+----------+-------------+


-- col1 にインデックスがないのでフルスキャン
mysql> SELECT * FROM t1 WHERE col1 = 'INVALID' FOR UPDATE;
Query OK, 0 rows affected (0.00 sec)

適切なインデックスを追加し、スキャンする範囲を小さくする、もしくは、
SELECTしたあとに主キーで対象の行のみを狙って更新する方法が有効。yoku0825さんの MySQLから大量のレコードをちまちま削除するメモ はその例。

SHOW ENGINE INNODB STATUS から情報を得る

SHOW ENGINE INNODB STATUS の LATEST DETECTED DEADLOCK にデッドロックの詳細が記録される。
どのような経緯でデッドロックに到ったか確認する手助けになる。

------------------------
LATEST DETECTED DEADLOCK
------------------------
2017-11-30 17:21:52 0x7fd26c11d700
*** (1) TRANSACTION:
TRANSACTION 1383, ACTIVE 25 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 8, OS thread handle 140541732701952, query id 84 localhost root updating
UPDATE t2 SET col1 = 'session1' WHERE pk = 1
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 28 page no 3 n bits 80 index PRIMARY of table `lockt`.`t2` trx id 1383 lock_mode X locks rec but not gap waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 000000000568; asc      h;;
 2: len 7; hex 46000001530110; asc F   S  ;;
 3: len 8; hex 73657373696f6e32; asc session2;;

*** (2) TRANSACTION:
TRANSACTION 1384, ACTIVE 15 sec starting index read
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 7, OS thread handle 140541732968192, query id 85 localhost root updating
UPDATE t1 SET col1 = 'session2' WHERE pk = 1
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 28 page no 3 n bits 72 index PRIMARY of table `lockt`.`t2` trx id 1384 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 000000000568; asc      h;;
 2: len 7; hex 46000001530110; asc F   S  ;;
 3: len 8; hex 73657373696f6e32; asc session2;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 27 page no 3 n bits 80 index PRIMARY of table `lockt`.`t1` trx id 1384 lock_mode X locks rec but not gap waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 000000000567; asc      g;;
 2: len 7; hex 45000001520110; asc E   R  ;;
 3: len 8; hex 73657373696f6e31; asc session1;;

*** WE ROLL BACK TRANSACTION (2)

1. 取得するタイミングに注意

LATEST DETECTED DEADLOCK とあるとおり、「最後に発生したデッドロック」の情報になる。 複数のデッドロックが発生している場合、自分が狙ってる情報が取れるよう、必要に応じて定期的にSHOW ENGINE INNODB STATUSを実行するなどする。

2. 最後のクエリしか記載されない

SHOW ENGINE INNODB STATUSの情報にはトランザクションの最後のクエリしか表示されない。 例でいうと
TRANSACTION(1) の UPDATE t1 SET col1 = 'session1' WHERE pk = 1;
TRANSACTION(2) の UPDATE t2 SET col1 = 'session2' WHERE pk = 1;
が表示されてない。

どういうクエリが原因でデッドロックが発生したか特定するには、LATEST DETECTED DEADLOCKに記載されているクエリを手がかりにソースコードなどから トランザクション全体のクエリを把握する必要がある(SHOW ENGINE INNODB STATUSだけでは全体の流れはわからない)。

3. HOLDS THE LOCKS はTRANSACTION(2)しか表示されない

HOLDS THE LOKCS がTRANSACTION(1)に表示されてないがロックは取ってる。 X row lock(s) に注目したほうが良い。

2017年9月22日金曜日

MySQL 8.0 で導入されたリソースグループを試す

MySQL 8.0.3 リリース候補版がリリースされました。
8.0.3はDMR(Developer Milestone Release) ではなく、 RC(リリース候補) でした。正式リリースまで一歩前進。正式リリースが楽しみですね。

8.0.3 ではリソースグループという機能が導入されました。

The purpose of Resource Groups is to decide on the mapping between user/system threads and CPUs. This can be used to split workloads across CPUs to obtain better efficiency and/or performance in some use cases.
リソースグループはMySQLのスレッドを特定のCPUに割り当てることができる機能。
「ワークロードごとに割り当てるCPUを分けることで性能が上がるケースがある」とあるのは、固定することで CPUのキャッシュヒット率が上がるようなケースを指していると思われます。

デフォルトで、以下の2つのリソースグループが設定されている。
RESOURCE_GROUP_TYPEがSYSTEMのものはInnoDBのpurge thread のようなバックグランドスレッドに割り当てられるリソースグループ。

デフォルトではVCPU_IDSが0-3となっていて、すべてのCPUを使う設定になっている。 つまり、特に制限はかかってない状態。

mysql> desc INFORMATION_SCHEMA.RESOURCE_GROUPS;
+------------------------+-----------------------+------+-----+---------+-------+
| Field                  | Type                  | Null | Key | Default | Extra |
+------------------------+-----------------------+------+-----+---------+-------+
| RESOURCE_GROUP_NAME    | varchar(64)           | NO   |     | NULL    |       |
| RESOURCE_GROUP_TYPE    | enum('SYSTEM','USER') | NO   |     | NULL    |       |
| RESOURCE_GROUP_ENABLED | tinyint(1)            | NO   |     | NULL    |       |
| VCPU_IDS               | blob                  | YES  |     | NULL    |       |
| THREAD_PRIORITY        | int(11)               | NO   |     | NULL    |       |
+------------------------+-----------------------+------+-----+---------+-------+

mysql> SELECT * from INFORMATION_SCHEMA.RESOURCE_GROUPS;
+---------------------+---------------------+------------------------+----------+-----------------+
| RESOURCE_GROUP_NAME | RESOURCE_GROUP_TYPE | RESOURCE_GROUP_ENABLED | VCPU_IDS | THREAD_PRIORITY |
+---------------------+---------------------+------------------------+----------+-----------------+
| USR_default         | USER                |                      1 | 0-3      |               0 |
| SYS_default         | SYSTEM              |                      1 | 0-3      |               0 |
+---------------------+---------------------+------------------------+----------+-----------------+
2 rows in set (0.00 sec)
$ cat /proc/cpuinfo | grep processor
processor       : 0
processor       : 1
processor       : 2
processor       : 3

デフォルトリソースグループは消したり、変更したりできない。

mysql> DROP RESOURCE GROUP USR_default;
ERROR 4557 (HY000): Drop operation  operation is disallowed on default resource groups.

mysql> ALTER RESOURCE GROUP USR_default VCPU=0-1;
ERROR 4557 (HY000): Alter operation is disallowed on default resource groups.

mysql> ALTER RESOURCE GROUP USR_default DISABLE;
ERROR 4557 (HY000): Alter operation is disallowed on default resource groups.

CPUを1個しか使わないリソースグループを試しに作ってみる

mysql> CREATE RESOURCE GROUP OneCPU TYPE=USER VCPU=0 ;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * from INFORMATION_SCHEMA.RESOURCE_GROUPS;
+---------------------+---------------------+------------------------+----------+-----------------+
| RESOURCE_GROUP_NAME | RESOURCE_GROUP_TYPE | RESOURCE_GROUP_ENABLED | VCPU_IDS | THREAD_PRIORITY |
+---------------------+---------------------+------------------------+----------+-----------------+
| USR_default         | USER                |                      1 | 0-3      |               0 |
| SYS_default         | SYSTEM              |                      1 | 0-3      |               0 |
| OneCPU              | USER                |                      1 | 0        |               0 |
+---------------------+---------------------+------------------------+----------+-----------------+
3 rows in set (0.00 sec)
まずは、何もしない状態でsysbench で負荷をかけてみます。 CPU0-3まですべて使われてることがわかります。
$ mpstat -P ALL 1
02:20:36 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
02:20:37 PM  all   44.50    0.00    5.50    0.00    0.00    0.00   50.00    0.00    0.00   0.00
02:20:37 PM    0   43.56    0.00    5.94    0.00    0.00    0.00   50.50    0.00    0.00   0.00
02:20:37 PM    1   44.00    0.00    6.00    0.00    0.00    0.00   50.00    0.00    0.00   0.00
02:20:37 PM    2   44.00    0.00    6.00    0.00    0.00    0.00   50.00    0.00    0.00   0.00
02:20:37 PM    3   45.00    0.00    5.00    0.00    0.00    0.00   50.00    0.00    0.00   0.00
次に、OneCPU グループを使うようにsysbench に細工してから実行します。
$ vim /usr/share/sysbench/oltp_read_only.lua
function prepare_statements()
   con:query("SET RESOURCE GROUP oneCPU")

   prepare_point_selects()
意図したとおり、1つのCPU(CPU0だけ)使うようになってますね!
$ mpstat -P ALL 1
02:24:08 PM  CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
02:24:09 PM  all   11.11    0.00    3.28    0.00    0.00    0.00   12.63    0.00    0.00   72.98
02:24:09 PM    0   41.00    0.00    9.00    0.00    0.00    0.00   50.00    0.00    0.00    0.00
02:24:09 PM    1    1.02    0.00    0.00    0.00    0.00    0.00    0.00    0.00    0.00   98.98
02:24:09 PM    2    1.02    0.00    1.02    0.00    0.00    0.00    0.00    0.00    0.00   97.96
02:24:09 PM    3    1.01    0.00    1.01    0.00    0.00    0.00    0.00    0.00    0.00   97.98

ヒント句でも指定できる。 QueryRewrite プラグインでリソースグループを使うようにヒント句を差し込んで、特定の重い処理を隔離して他への影響を抑える・・・みたいな用途にも使えそう。
1. /*+ RESOURCE_GROUP(resource_group_name) */ -- for executing this SQL query switch the given thread to Resource Group 'name', then switch it back once the query execution is finished.

2017年6月17日土曜日

OSC 2017 Okinawa で MySQLの冗長構成について発表してきた

大阪で話した内容とほぼ一緒なのですが、、、MySQL Shell を試してみました。 OSC Hokkaido も参加したので、これで南は沖縄から北は北海道まで行ったと言える・・・!

2017年3月25日土曜日

MyNA 会 201703 で MySQL のDB利用者向けベストプラクティスの話してきた

MySQL のプロダクトマネジャーである Matt Lord さんをお招きして 日本MySQLユーザ会会 を開催しました。

当日はベストプラクティス・・・というかDBAからのお願いを発表してきました。
DB利用者に意識してほしいことを中心に取り上げてみました。



Matt さんからはGroup Replication を使った高可用構成と、さらにGroup Replicationのセット複数並べてシャーディングする InnoDB Cluster を紹介がありました。

当日の様子は yoku0825 さんが toggeter にまとめてくれてます。
MyNA(日本MySQLユーザ会)会 2017年3月まとめ
https://togetter.com/li/1092945


しかし、Matt さんのパンクな見た目のインパクトが凄かった(笑)

2017年2月2日木曜日

MySQL Causal Talk vol.10 で Group Replication について話した

MySQL Causal Talk vol.10 で Group Replication について話してきました。 最近ずっとGroup Replication しか触ってない・・・・

また、 myfinder さんから、MySQL Casual slack の general チャンネルを英語用とし、日本語用のチャンネルを別途作ることが提案されました。
早速、general チャンネルにMySQLの中の人(!)が投稿し、ちょっとした騒ぎになっている様です。

2017年1月28日土曜日

OSC 2017 Osaka で MySQLの冗長構成について発表してきた

OSC Osaka で MySQL の高可用性構成について発表してきました。 会場でフォローして頂いた。sakai さん、ありがとうございました!

2017年1月20日金曜日

Group Replication を試す(4) リカバリ

Group Replication で特定のサーバのデータが吹き飛んでしまった場合の復旧手順を確認。 動いているサーバからdumpを取って、復旧すれば良いのだが、、、
--single-transaction で mysqldump しようとすると、GRではSavepoint がサポートされていないため、 コケる。。。
https://bugs.mysql.com/bug.php?id=81494 で修正の要望が出されている

-bash-4.1$ mysqldump --all-databases --single-transaction -uroot --triggers --routines --events -p > dump.sql
mysqldump: [Warning] Using a password on the command line interface can be insecure.
mysqldump: Couldn't execute 'SAVEPOINT sp': The MySQL server is running with the --transaction-write-set-extraction!=OFF option so it cannot execute this statement (1290)
--single-transactionが使えないので、--lock-all-tables を使う。テーブルがロックされてしまうので、バックアップ中にはバックアップを取得するサーバには更新が行われないようにする必要がある。 3台構成だと、壊れていてるやつが1台、バックアップ取得用に1台ということでサービス用が1台になってしまう。。。
  1. アプリからのアクセスをなくす
  2. STOP GROUP_REPLIACTION (他のノードから更新を受け取らないようにする)
  3. mysqldump
  4. START GROUP_REPLICATION
  5. 追いついたら、アプリからのアクセスを復旧
-bash-4.1$ mysqldump --all-databases --lock-all-tables -uroot --triggers --routines --events -p > dump.sql
mysqldump: [Warning] Using a password on the command line interface can be insecure.
後は、壊れたやつにダンプしたデータを流しこんで、START GROUP_REPLICATIONすれば復旧できる。
mysql> reset master;
Query OK, 0 rows affected (0.02 sec)
 
mysql> source dump.sql
 
mysql> start group_replication;
Query OK, 0 rows affected (2.22 sec)
 
mysql> SELECT * FROM performance_schema.replication_group_members;
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
| CHANNEL_NAME              | MEMBER_ID                            | MEMBER_HOST                           | MEMBER_PORT | MEMBER_STATE |
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
| group_replication_applier | 0cdd0b6a-cd84-11e6-b223-fa163e0b2b7c | gr02                                  |        3306 | ONLINE       |
| group_replication_applier | 1edf2e1d-cd83-11e6-961b-fa163e83e8e7 | gr01                                  |        3306 | ONLINE       |
| group_replication_applier | a1c37edb-cd89-11e6-a463-fa163e49d992 | gr03                                  |        3306 | ONLINE       |
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
3 rows in set (0.00 sec)
ちなみにGroup ReplicationのGTIDのUUID部分はgroup_replication_group_name で指定したものが使われる
-bash-4.1$ grep -A2 GTID_PURGED dump.sql
SET @@GLOBAL.GTID_PURGED='1edf2e1d-cd83-11e6-961b-fa163e83e8e7:1,
87e5ed8c-cd83-11e6-bc3c-fa163e83e8e7:1-12947';
 
-bash-4.1$ grep group_name /etc/my.cnf
loose-group_replication_group_name="87e5ed8c-cd83-11e6-bc3c-fa163e83e8e7"

2017年1月13日金曜日

Group Replication を試す(3) 障害時の挙動

group_replication_recovery チャネルは障害後のサーバ間の差分同期のみに使われる。

Group Replication のステータスが ONLINE 状態のときは、Master_HostがNULL、Slave_{IO,SQL}_Running は NO。

mysql>  select * from performance_schema.replication_group_members;
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
| CHANNEL_NAME              | MEMBER_ID                            | MEMBER_HOST                           | MEMBER_PORT | MEMBER_STATE |
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
| group_replication_applier | 0cdd0b6a-cd84-11e6-b223-fa163e0b2b7c | gr02                                  |        3306 | ONLINE       |
| group_replication_applier | 1edf2e1d-cd83-11e6-961b-fa163e83e8e7 | gr01                                  |        3306 | ONLINE       |
| group_replication_applier | a1c37edb-cd89-11e6-a463-fa163e49d992 | gr03                                  |        3306 | ONLINE       |
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
3 rows in set (0.00 sec)
 
 
mysql> show slave status for channel 'group_replication_recovery' \G
*************************** 1. row ***************************
               Slave_IO_State:
                  Master_Host: 
                  Master_User: rpl_user
                  Master_Port: 0
                Connect_Retry: 60
              Master_Log_File:
          Read_Master_Log_Pos: 4
               Relay_Log_File: gr02-group_replication_recovery.000001
                Relay_Log_Pos: 4
        Relay_Master_Log_File:
             Slave_IO_Running: No
            Slave_SQL_Running: No
              Replicate_Do_DB:
## snip ##

障害によって他のサーバと差分が生じ、差分同期中(RECOVERING) になると、Group Replication Plugin が自動的にマスターを指定し、差分を同期する。

mysql>  select * from performance_schema.replication_group_members;
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
| CHANNEL_NAME              | MEMBER_ID                            | MEMBER_HOST                           | MEMBER_PORT | MEMBER_STATE |
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
| group_replication_applier | 0cdd0b6a-cd84-11e6-b223-fa163e0b2b7c | gr02                                  |        3306 | RECOVERING   |
| group_replication_applier | 1edf2e1d-cd83-11e6-961b-fa163e83e8e7 | gr01                                  |        3306 | ONLINE       |
| group_replication_applier | a1c37edb-cd89-11e6-a463-fa163e49d992 | gr03                                  |        3306 | ONLINE       |
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
3 rows in set (0.00 sec)
 
mysql> show slave status for channel 'group_replication_recovery' \G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: gr01
                  Master_User: rpl_user
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: binlog.000001
          Read_Master_Log_Pos: 65574674
               Relay_Log_File: gr02-group_replication_recovery.000003
                Relay_Log_Pos: 31852573
        Relay_Master_Log_File: binlog.000001
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes

## snip ##

binary log がすでにロストしてた場合

galera ではIST(差分同期)をあきらめて、SST(バックアップ取得→同期) になるケース。 Group Replication では、バイナリログを探し続けて、試行回数が一定に達すると、起動できずに終了する。

2016-12-30T01:54:26.017573Z 14 [Note] Plugin group_replication reported: 'Retrying group recovery connection with another donor. Attempt 5/10'
2016-12-30T01:55:26.030228Z 14 [Note] 'CHANGE MASTER TO FOR CHANNEL 'group_replication_recovery' executed'. Previous state master_host='', master_port= 0, master_log_file='', master_log_pos= 4, master_bind=''. New state master_host
='gr02', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''.
2016-12-30T01:55:26.045140Z 14 [Note] Plugin group_replication reported: 'Establishing connection to a group replication recovery donor 0cdd0b6a-cd84-11e6-b223-fa163e0b2b7c at gr02 port: 3306.'
2016-12-30T01:55:26.046151Z 23 [Warning] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for STA
RT SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.
2016-12-30T01:55:26.059113Z 23 [Note] Slave I/O thread for channel 'group_replication_recovery': connected to master 'rpl_user@gr02:3306',replication started in log 'FIRST' at position 4
2016-12-30T01:55:26.061461Z 24 [Note] Slave SQL thread for channel 'group_replication_recovery' initialized, starting replication in log 'FIRST' at position 0, relay log './gr03-group_replication_recovery.000001' position: 4
2016-12-30T01:55:26.066858Z 23 [ERROR] Error reading packet from server for channel 'group_replication_recovery': The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires. (server_errno=1236)
2016-12-30T01:55:26.066904Z 23 [ERROR] Slave I/O for channel 'group_replication_recovery': Got fatal error 1236 from master when reading data from binary log: 'The slave is connecting using CHANGE MASTER TO MASTER_AUTO_POSITION = 1, but the master has purged binary logs containing GTIDs that the slave requires.', Error_code: 1236
2016-12-30T01:55:26.066917Z 23 [Note] Slave I/O thread exiting for channel 'group_replication_recovery', read up to log 'FIRST', position 4
2016-12-30T01:55:26.066983Z 14 [Note] Plugin group_replication reported: 'Terminating existing group replication donor connection and purging the corresponding logs.'
2016-12-30T01:55:26.067037Z 24 [Note] Error reading relay log event for channel 'group_replication_recovery': slave SQL thread was killed
2016-12-30T01:55:26.079298Z 14 [Note] 'CHANGE MASTER TO FOR CHANNEL 'group_replication_recovery' executed'. Previous state master_host='gr02', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''. New state master_host='', master_port= 0, master_log_file='', master_log_pos= 4, master_bind=''.
2016-12-30T01:55:26.091463Z 14 [Note] Plugin group_replication reported: 'Retrying group recovery connection with another donor. Attempt 6/10'
 
## snip ##
 
2016-12-30T02:00:22.345848Z 0 [Note] InnoDB: Starting shutdown...
2016-12-30T02:00:22.446097Z 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2016-12-30T02:00:22.447044Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 161230 11:00:22
2016-12-30T02:00:23.959156Z 0 [Note] InnoDB: Shutdown completed; log sequence number 280039404
2016-12-30T02:00:23.962273Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2016-12-30T02:00:23.962291Z 0 [Note] Shutting down plugin 'MyISAM'
2016-12-30T02:00:23.962302Z 0 [Note] Shutting down plugin 'CSV'
2016-12-30T02:00:23.962308Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2016-12-30T02:00:23.962346Z 0 [Note] Shutting down plugin 'sha256_password'
2016-12-30T02:00:23.962352Z 0 [Note] Shutting down plugin 'mysql_native_password'
2016-12-30T02:00:23.963043Z 0 [Note] Shutting down plugin 'binlog'
2016-12-30T02:00:23.963818Z 0 [Note] /usr/sbin/mysqld: Shutdown complete

スプリットブレイン時

2台構成で、1台を落とし、スプリットブレイン状態を再現。

mysql> select * from performance_schema.replication_group_members;
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
| CHANNEL_NAME              | MEMBER_ID                            | MEMBER_HOST                           | MEMBER_PORT | MEMBER_STATE |
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
| group_replication_applier | 0cdd0b6a-cd84-11e6-b223-fa163e0b2b7c | gr02                                  |        3306 | UNREACHABLE  |
| group_replication_applier | 1edf2e1d-cd83-11e6-961b-fa163e83e8e7 | gr01                                  |        3306 | ONLINE       |
+---------------------------+--------------------------------------+---------------------------------------+-------------+--------------+
2 rows in set (0.00 sec)
 
 
mysql> select * from test.t limit 2;
+----+---------------------+
| pk | col1                |
+----+---------------------+
|  1 | 2016-12-29 15:23:07 |
|  8 | 2016-12-29 15:23:07 |
+----+---------------------+
2 rows in set (0.00 sec)
 
 
mysql> INSERT INTO test.t (col1) VALUES(NOW());
(戻ってこない)
mysql> SHOW PROCESSLIST;
+------+-------------+-----------+------+---------+-------+--------------------------------------------------------+-----------------------------------------+
| Id   | User        | Host      | db   | Command | Time  | State                                                  | Info                                    |
+------+-------------+-----------+------+---------+-------+--------------------------------------------------------+-----------------------------------------+
|    7 | system user |           | NULL | Connect | 75875 | executing                                              | NULL                                    |
|   10 | system user |           | NULL | Connect | 75875 | Slave has read all relay log; waiting for more updates | NULL                                    |
| 5482 | root        | localhost | NULL | Query   |    53 | query end                                              | INSERT INTO test.t (col1) VALUES(NOW()) |
| 5786 | root        | localhost | NULL | Query   |     0 | starting                                               | SHOW PROCESSLIST                        |
+------+-------------+-----------+------+---------+-------+--------------------------------------------------------+-----------------------------------------+
4 rows in set (0.00 sec)

SELECTはできるが、更新はブロックされ、ハングしたような状態になる。スプリットブレイン時も整合性は保たれる。スプリットブレインが解消されるとINSERT文が成功する。 Lab 版ではスプリットブレインの状態をうまくハンドリングできてなかったが、GAではちゃんとハンドリングできるようになってた。

2台だと1台死んだだけでスプリットブレインになってしまうため、Group Replicationを構成する場合は3台以上が推奨される。

2017年1月6日金曜日

Group Replication を試す(2) ロックの挙動

テスト用のテーブル

mysql> CREATE TABLE grplt.tbl (pk SERIAL, col1 int, who_update varchar(10));
Query OK, 0 rows affected (0.00 sec)
 
mysql> INSERT INTO grplt.tbl (col1, who_update) VALUES (1, 'node1') , (2, 'node1'), (3, 'node1');
Query OK, 3 rows affected (0.00 sec)
Records: 3  Duplicates: 0  Warnings: 0
 
mysql>  SELECT * FROM grplt.tbl;
+----+------+------------+
| pk | col1 | who_update |
+----+------+------------+
|  1 |    1 | node1      |
|  8 |    2 | node1      |
| 15 |    3 | node1      |
+----+------+------------+
3 rows in set (0.00 sec)

いつものデッドロック

同じサーバに対して、入れ子の行ロックを取る2つのトランザクションを実行するパターン。
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction が発生し、発生したデッドロックの情報は SHOW ENGINE INNODB STATUS で確認できる。

TIME T1 T2
1 > BEGIN;
Query OK, 0 rows affected (0.00 sec)

> UPDATE grplt.tbl SET col1 = 10, who_update = 'node1' WHERE pk = 1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0
2 > BEGIN;
Query OK, 0 rows affected (0.00 sec)

> UPDATE grplt.tbl SET col1 = 10, who_update = 'node1' WHERE pk = 15;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0
3 T2 が pk = 15 を開放するのを待つ。
> UPDATE grplt.tbl SET col1 = 10, who_update = 'node1' WHERE pk = 15;
4 T2 が pk = 1 を要求したため、T1は強制ロールバックしpk = 1 を開放
ERROR 1213 (40001): Deadlock found when trying to get lock;
try restarting transaction
> UPDATE grplt.tbl SET col1 = 10, who_update = 'node1' WHERE pk = 1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0
mysql> SHOW ENGINE INNODB STATUS\G
------------------------
LATEST DETECTED DEADLOCK
------------------------
2016-12-29 16:02:59 0x7f539018a700
*** (1) TRANSACTION:
TRANSACTION 6102, ACTIVE 42 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 3838, OS thread handle 139996877612800, query id 11406 localhost root updating
UPDATE grplt.tbl  SET col1 = 10, who_update = 'node1' WHERE pk = 15
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 26 page no 3 n bits 72 index pk of table `grplt`.`tbl` trx id 6102 lock_mode X locks rec but not gap waiting
Record lock, heap no 4 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 8; hex 000000000000000f; asc         ;;
 1: len 6; hex 0000000017d7; asc       ;;
 2: len 7; hex 30000001880233; asc 0     3;;
 3: len 4; hex 8000000a; asc     ;;
 4: len 5; hex 6e6f646531; asc node1;;
*** (2) TRANSACTION:
TRANSACTION 6103, ACTIVE 9 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 3841, OS thread handle 139996876547840, query id 11407 localhost root updating
UPDATE grplt.tbl  SET col1 = 10, who_update = 'node1' WHERE pk = 1

Group Replication でサーバ間でロックが競合

Group Replication で複数のサーバで同時に同じレコードを更新した場合の挙動。 サーバ間のロックのアルゴリズムは「楽観的ロック」になっている。
コミット時に、そのレコードが他のサーバで既に更新済みだった場合、そのトランザクションは強制ロールバックされる。
要するに「先勝ち」

pk = 1 のレコードを別々のサーバで更新。エラーメッセージが異なり通常のデッドロックと区別することができる。
※ ちなみに、Galera Cluster の場合、通常のデッドロックと、複数サーバ間で競合しロールバックされた場合で同じエラーメッセージが出力されるため区別が付かない。

しかし、もう少しわかりやすいメッセージにできなかったんだろうか。
SHOW ENGINE INNODB STATUS に情報は出力されない。

TIME T1 T2
1 > BEGIN;
Query OK, 0 rows affected (0.00 sec)

> UPDATE grplt.tbl SET col1 = 10, who_update = 'node1' WHERE pk = 1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0
2 > BEGIN;
Query OK, 0 rows affected (0.00 sec)

> UPDATE grplt.tbl SET col1 = 10, who_update = 'node2' WHERE pk = 1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0
3 pk = 1 の行をノード1で更新確定する
> COMMIT;
Query OK, 0 rows affected (0.00 sec)
(この時点でT1が更新したことが伝わってくる)
4 > COMMIT;
ERROR 1180 (HY000): Got error 149 during COMMIT
mysql> pager grep DEAD
PAGER set to 'grep DEAD'
 
mysql> SHOW ENGINE INNODB STATUS\G
1 row in set (0.00 sec)