グループレプリケーションの group_replication_applier と group_replication_recovery のリレーログ

TL;DR

• グループレプリケーションは(形式上かも知れないけど) group_replication_applier というレプリケーションチャンネルと group_replication_recovery というレプリケーションチャンネルを持っている
• グループレプリケーションの通信が問題なく行われている間は GCS(Group Communication System) から group_replication_applier のリレーログに書き込まれて group_repliation_applierのSQLスレッドが処理
  • この時、プライマリーノードはGCSから応答が返ってきた後にバイナリログに書く
• グループレプリケーションが途切れてGCSから直接受け取っていない間に発生した書き込みはバイナリログを経由して group_replication_recovery チャンネルを通じて受け取る
  • こっちは割とフツーのGTIDベースなAsyncレプリケーションっぽく振る舞う
  • group_replication_recoveryチャンネルが動いている間はgroup_replication_applierチャンネルが動かないような制御は入ってるっぽい

---

実験

• シングルプライマリーの3台構成

まずは3台ともONLINE

### node1 (PRIMARY)
mysql> CREATE DATABASE d1;
Query OK, 1 row affected (0.01 sec)

mysql> CREATE TABLE d1.t1 (num serial, val varchar(32));
Query OK, 0 rows affected (0.02 sec)

mysql> INSERT INTO d1.t1 VALUES (1, 'one');
Query OK, 1 row affected (0.01 sec)

リレーログとバイナリログと、 INSERT が記録されているファイルを雑に調べる( *.0000* はバイナリログとリレーログの連番部分だけを引っ掛けてるつもり、 binlog_rows_query_log_events の部分だけ抜粋)

### node1 (PRIMARY)
$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep INSERT | grep t1
/var/lib/mysql/binlog.000004 # INSERT INTO d1.t1 VALUES (1, 'one')

### node2
$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep INSERT | grep t1
/var/lib/mysql/binlog.000002 # INSERT INTO d1.t1 VALUES (1, 'one')
/var/lib/mysql/node2-relay-bin-group_replication_applier.000002 # INSERT INTO d1.t1 VALUES (1, 'one')

### node3
$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep INSERT | grep t1
/var/lib/mysql/binlog.000002 # INSERT INTO d1.t1 VALUES (1, 
/var/lib/mysql/node3-relay-bin-group_replication_applier.000002 # INSERT INTO d1.t1 VALUES (1, 'one')

プライマリーではバイナリログのみ、node2とnode3は group_replication_applier のリレーログとバイナリログに記録。

ノード停止中に発生した更新

### node3
$ sudo systemctl stop mysqld

### node1
mysql> DELETE FROM t1 WHERE num = 1;
Query OK, 1 row affected (0.00 sec)

### node1
$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep DELETE | grep t1
/var/lib/mysql/binlog.000004 # DELETE FROM t1 WHERE num = 1

### node2
$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep DELETE | grep t1
/var/lib/mysql/binlog.000002 # DELETE FROM t1 WHERE num = 1
/var/lib/mysql/node2-relay-bin-group_replication_applier.000002 # DELETE FROM t1 WHERE num = 1

### node3
$ sudo systemctl start mysqld
$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep DELETE | grep t1
/var/lib/mysql/binlog.000003 # DELETE FROM t1 WHERE num = 1

個人的には node3-relay-bin-group_replication_recovery の方でも観測できると良かったんだけど、なんかすぐパージされるのか何なのか観測できなかった。

performance_schema.replication_applier_status_by_worker テーブルからは、node3だけ group_replication_recovery チャンネルが仕事をしたのがわかる。

### node3
 MySQL  node3:33060+ ssl  SQL > SELECT channel_name, service_state, last_applied_transaction AS last_gtid, last_applied_transaction_original_commit_timestamp AS orig_ts, last_applied_transaction_immediate_commit_timestamp AS my_ts FROM performance_schema.replication_applier_status_by_worker;
+----------------------------+---------------+-----------------------------------------+---------------------+----------------------------+
| channel_name               | service_state | last_gtid                               | orig_ts             | my_ts                      |
+----------------------------+---------------+-----------------------------------------+---------------------+----------------------------+
| group_replication_applier  | ON            |                                         | 0000-00-00 00:00:00 | 0000-00-00 00:00:00        |
| group_replication_recovery | OFF           | 96bb7988-64ec-11ea-b013-122c3190731d:58 | 0000-00-00 00:00:00 | 2020-03-13 05:45:03.879562 |
+----------------------------+---------------+-----------------------------------------+---------------------+----------------------------+
2 rows in set (0.0020 sec)

### node2
 MySQL  node2:33060+ ssl  SQL > SELECT channel_name, service_state, last_applied_transaction AS last_gtid, last_applied_transaction_original_commit_timestamp AS orig_ts, last_applied_transaction_immediate_commit_timestamp AS my_ts FROM performance_schema.replication_applier_status_by_worker;
+----------------------------+---------------+-----------------------------------------+---------------------+--------------------------+
| channel_name               | service_state | last_gtid                               | orig_ts             | my_ts                    |
+----------------------------+---------------+-----------------------------------------+---------------------+--------------------------+
| group_replication_applier  | ON            | 96bb7988-64ec-11ea-b013-122c3190731d:58 | 0000-00-00 00:00:00 | 0000-00-00 00:00:00      |
| group_replication_recovery | OFF           | 96bb7988-64ec-11ea-b013-122c3190731d:39 | 0000-00-00 00:00:00 | 2020-03-13 05:37:00.4302 |
+----------------------------+---------------+-----------------------------------------+---------------------+--------------------------+
2 rows in set (0.0007 sec)

### node1
 MySQL  localhost:33060+ ssl  SQL > SELECT channel_name, service_state, last_applied_transaction AS last_gtid, last_applied_transaction_original_commit_timestamp AS orig_ts, last_applied_transaction_immediate_commit_timestamp AS my_ts FROM performance_schema.replication_applier_status_by_worker;
+---------------------------+---------------+-----------------------------------------+---------------------+---------------------+
| channel_name              | service_state | last_gtid                               | orig_ts             | my_ts               |
+---------------------------+---------------+-----------------------------------------+---------------------+---------------------+
| group_replication_applier | ON            | 96bb7988-64ec-11ea-b013-122c3190731d:58 | 0000-00-00 00:00:00 | 0000-00-00 00:00:00 |
+---------------------------+---------------+-----------------------------------------+---------------------+---------------------+
1 row in set (0.0004 sec)

言われてみれば、 グループレプリケーションを手で組む時 って CHANGE MASTER TO .. FOR CHANNEL 'group_replication_recovery' だけ設定するので、コイツらは比較的「いつものレプリケーション」に近い仕組みをしていそう。

折角なのでgdbで止めて、group_replication_recoveryチャンネルのリレーログに入っているところを見てみた（バイナリログ書き出し Binlog_event_writer::write の手前で止めればまだリレーログからは消えてないだろうという雑なアレ）

### node3
$ sudo gdb --args /usr/sbin/mysqld --user=mysql
(gdb) b Binlog_event_writer::write
Breakpoint 1 at 0x1bc0f80: file /export/home/pb2/build/sb_0-37170812-1575922551.75/rpm/BUILD/mysql-8.0.19/mysql-8.0.19/sql/binlog.cc, line 1260.
(gdb) r
Starting program: /usr/sbin/mysqld --user=mysql
..
Breakpoint 1, Binlog_event_writer::write (this=0x7fffc0095fb0, buffer=0x7fffc0095ce0 "LUk^!Wk\002\235R", length=19)
    at /export/home/pb2/build/sb_0-37170812-1575922551.75/rpm/BUILD/mysql-8.0.19/mysql-8.0.19/sql/binlog.cc:1260
1260    /export/home/pb2/build/sb_0-37170812-1575922551.75/rpm/BUILD/mysql-8.0.19/mysql-8.0.19/sql/binlog.cc: No such file or directory.

$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep DELETE | grep t1
/var/lib/mysql/node3-relay-bin-group_replication_recovery.000003 # DELETE FROM t1 WHERE num = 1

group_replication_recoveryのリレーログに入ってるところが見えて、そのままgdb側の処理を進めてやるとすぐにrelay-bin-group_replication_recovery.000003ファイルそのものが消えた。たぶんrelay_log_purge (group_replication_applierの方のリレーログが割と残るのは何なんだろう…？

ともあれ、グルーレプリケーションは2つのチャンネルを使っているのが何となくわかった。

​