GA

ラベル InnoDB Cluster の投稿を表示しています。 すべての投稿を表示
ラベル InnoDB Cluster の投稿を表示しています。 すべての投稿を表示

2021/03/04

Perl MongersのためのMySQL InnoDB Cluster超入門のはなし

Japan.pm 2021 のトークセッションで喋らせてもらったネタ。
Perlの話は DBI->connect くらいしか出てこないのでPerl Mongersでなくてもお楽しみいただけるかと思います。


InnoDB Clusterのキモは何と言っても「MySQLとMySQL Routerはそれぞれ別の観点から別の仕事をしている」というところで(ついでに言うなら、オーケストレーター的に働くMySQL Shellは一度動き出してしまえば常駐しなくても良いところ)これを理解しておくと理解が色々と捗る。

このへんの機能も「MySQL Routerの」機能であって、グループレプリケーションはこの辺の機能には一切関係ない。

そのへんを認識すると、全てのmysqldがいなくなった時にmysqlrouterが返してくるこのへんのエラーも「ああ、如何にもそれっぽい」と思えるようになるんではなかろうかなと。

グループレプリケーションにブラックボックスを全てつぎ込んだが故に、全てを理解しようと思うと当然のようにMySQLのソースコードを当たる必要があるけれど、MySQL RouterやMySQL Shell部分はシンプルなので、「Paxosまではいいけど表面的な動作はコードレベルで押さえておきたい」みたいなケースには学習がしやすいんじゃないかなあと思ったりしました。

----

しかし Japan.pm 2021 は想像していたより色々チャレンジをされていたみたいで、 (discordには慣れなかったけど) トーク後のおしゃべり可能タイムが設けられていて「トークおつかれさまでした!」ってまいんだーさんの肉声で言われた時にはかなり嬉しかった。

トークのラインナップもさすがPerl Mongersって感じのアレでだいぶ好みでした。次回もあるといいなあ。

2020/09/01

mysqlrouterに ERROR 2003 (HY000): Can't connect to remote MySQL server for client connected to '0.0.0.0:6446' と言われたら

TL;DR

  • ポートに対応する宛先(デフォルトでは6446はマスター、6447なら全てのスレーブとマスターも(デフォルトだとフォールバックするから))のmysqldが全滅していると、CR_CONN_HOST_ERROR(2003)の後ろのアドレスがmysqlrouterのLISTENポートになる

    • どこが落ちてるのかメッセージからわかりにくいと嘆かないで、「全滅した時だけ」だから
    • 切り分けの一助になれば幸い
  • ただしこの「全滅」は _hidden: true を含む。


フツーに「起動していないmysqld」のIPアドレスとポートを指定して接続できないと、エラーメッセージの後半は指定したIPアドレスが出る。括弧書きの中はOSエラーコード。たとえば111は ECONNREFUSED なのでIPアドレスかポート番号間違ってるよねというのがすぐにわかる。

$ mysql -h127.0.0.1 -P64080
ERROR 2003 (HY000): Can't connect to MySQL server on '127.0.0.1' (111)

それに対して、宛先を全滅させたmysqlrouterはちょっと違う感じのエラーを返す。エラー番号は同じ2003でもメッセージがちょっと違うしOSエラーコードも出ていない。mysqlコマンドラインクライアントから見た接続先である 127.0.0.1 もエラーメッセージには出てこない。

$ mysql -h127.0.0.1 -P6446
ERROR 2003 (HY000): Can't connect to remote MySQL server for client connected to '0.0.0.0:6446'

mysqlrouterプロセスそのものを止めてしまうと、いつも通り(?)のエラーメッセージになる。

$ sudo systemctl stop mysqlrouter
$ mysql -h127.0.0.1 -P6446
ERROR 2003 (HY000): Can't connect to MySQL server on '127.0.0.1' (111)

と、このようにエラーメッセージがちょっと違うことをおぼえておくと、mysqlrouterがおかしいのか、宛先のmysqldがおかしいのかの切り分けのチャンスになる鴨。

ちなみにルーティングそのものに失敗したのはmysqlrouter.logには出力されてなかった(今回は全滅させているので、延々(InnoDB RSの)メタデータ取得に失敗したログだけが吐かれている)

2020-09-01 18:49:10 metadata_cache WARNING [7fbc59665700] Failed connecting with Metadata Server 127.0.0.1:3306: Can't connect to MySQL server on '127.0.0.1' (111) (2003)
2020-09-01 18:49:10 metadata_cache WARNING [7fbc59665700] Could not connect to the instance: fd1c9072-ec24-11ea-b2bc-0201965f8d32 on 127.0.0.1:3306
2020-09-01 18:49:10 metadata_cache WARNING [7fbc59665700] Failed connecting with Metadata Server 127.0.0.1:3307: Can't connect to MySQL server on '127.0.0.1' (111) (2003)
2020-09-01 18:49:10 metadata_cache WARNING [7fbc59665700] Could not connect to the instance: 06d3bc79-ec25-11ea-8c8c-0201965f8d32 on 127.0.0.1:3307
2020-09-01 18:49:10 metadata_cache WARNING [7fbc59665700] Failed connecting with Metadata Server 127.0.0.1:3308: Can't connect to MySQL server on '127.0.0.1' (111) (2003)
2020-09-01 18:49:10 metadata_cache WARNING [7fbc59665700] Could not connect to the instance: 135d0639-ec25-11ea-8bbd-0201965f8d32 on 127.0.0.1:3308
2020-09-01 18:49:10 metadata_cache ERROR [7fbc59665700] Failed fetching metadata from any of the 3 metadata servers.

ところで、「クライアントサイドのエラーってクライアントライブラリにハードコーディングで可変部分そんなに多くなかったよね?」と思ったそこのアナタ。アナタは鋭い。


この2003、クライアントサイドエラーの番号を使ってはいるが「mysqlrouterがmysqlコマンドラインクライアントに対して『サーバーサイドエラーパケット』として送り込んでいる」

なのでクライアントの実装によらずに「クライアントライブラリまでエラーメッセージの本文が渡る」であろうことが期待できる。

エラーメッセージの本文を握りつぶすので有名(?)なConnector/Jはどう振る舞うんだろうってちょっと心配になってきた。

2020/08/31

MySQL InnoDB Cluster/ReplicaSet 8.0.21で「mysqlrouterから参照されないように」設定する

TL;DR


まずはフツーにMySQL Shellでサンドボックスを3つばかり作る。

$ mysqlsh -- dba deploySandboxInstance 3306 { --password="" }
$ mysqlsh -- dba deploySandboxInstance 3307 { --password="" }
$ mysqlsh -- dba deploySandboxInstance 3308 { --password="" }

3306のインスタンスで dba.createaReplicaSet('myRs')

$ mysqlsh --uri=root:""@localhost:3306 -- dba createReplicaSet myRs

--replicasetrs に受けてからの rs.addInstance
(このコマンドラインオプションの奇妙な書き方は 日々の覚書: CentOS 7のAMIでEC2を起動してGroup Replicationを組むところまでを何も考えずに をやってる時に見つけた)

$ mysqlsh --uri=root:""@localhost:3306 --replicaset -- rs addInstance root@localhost:3307 { --recoveryMethod=clone }
$ mysqlsh --uri=root:""@localhost:3306 --replicaset -- rs addInstance root@localhost:3308 { --recoveryMethod=clone }

以前にInnoDB Clusterとかを組んだことがあると mysqlrouter.conf に書かれていたりするので一度消してから mysqlrouter --bootstrap

$ sudo rm /etc/mysqlrouter/mysqlrouter.conf
$ sudo mysqlrouter --bootstrap=root@localhost:3306 --user=mysqlrouter
Please enter MySQL password for root:
$ sudo systemctl start mysqlrouter

この状態でRead-Onlyな6447は3307と3308にラウンドロビンされている。

$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3307
$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3308
$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3307
$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3308
$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3307
$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3308

rs.setInstanceOption(‘127.0.0.1:3308’, ‘tag:_hidden’, true) とやると

$ mysqlsh --uri=root:""@localhost:3306 --replicaset -- rs setInstanceOption '127.0.0.1:3308' 'tag:_hidden' 'true'
WARNING: Using a password on the command line interface can be insecure.
You are connected to a member of replicaset 'myRs'.

ルーターを再起動とかしなくても読み取り分散から外れる。

$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3307
$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3307
$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3307
$ mysql -h127.0.0.1 -P6447 -sse "SELECT @@port"
3307

これはうまく使えば便利そう。


ただし、_hidden: trueのままでもsetPrimaryInstanceできてしまうし、_hiddenは効いたままなのでその辺はどうなのか感ある。

2020/03/16

わざと件数をズラしたグループレプリケーションで、「遅延中」の動きを観察する

件数をズラした上で OPTIMIZE TABLE をかけるといくらでもセカンダリーが遅延した状況が作り出せる、というとことまでは良いとして。
node3のグループレプリケーションを一旦止める。
### node3
mysql> STOP GROUP_REPLICATION;
Query OK, 0 rows affected (4.49 sec)
またnode1から OPTIMIZE TABLE を5発くらい叩き込んでついでに更新SQLを入れておく。
### node1
mysql> OPTIMIZE TABLE sbtest.sbtest1; -- これを5回くらい

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

mysql> SELECT * FROM d1.t1;
+-----+-------+
| num | val   |
+-----+-------+
|   1 | one   |
|   2 | two   |
|   3 | three |
|   4 | four  |
+-----+-------+
4 rows in set (0.00 sec)

### node2
mysql> SELECT * FROM d1.t1; -- OPTIMIZE TABLEにやられて遅れてる
+-----+-------+
| num | val   |
+-----+-------+
|   1 | one   |
|   2 | two   |
|   3 | three |
+-----+-------+
3 rows in set (0.00 sec)

### node3
mysql> SELECT * FROM d1.t1;  -- そもそもグループレプリケーション止めてるので同期されない
+-----+-------+
| num | val   |
+-----+-------+
|   1 | one   |
|   2 | two   |
|   3 | three |
+-----+-------+
3 rows in set (0.00 sec)
ここでnode3のグループレプリケーションを再開。
### node3
mysql> START GROUP_REPLICATION;
Query OK, 0 rows affected (4.93 sec)

$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep INSERT | grep d1
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-48-relay-bin-group_replication_recovery.000003 ### INSERT INTO `d1`.`t1`
この時点で、「グループレプリケーション停止中に更新した行はrecoveryの方のリレーログに入る」のは実験済み。
じゃあ、 “RECOVERING” 中に新しく突っ込まれた更新の行は?
### node1
mysql> INSERT INTO d1.t1 VALUES (5, 'five');
Query OK, 1 row affected (0.01 sec)

### node3
$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep INSERT | grep d1
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-48-relay-bin-group_replication_recovery.000003 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-48-relay-bin-group_replication_recovery.000003 ### INSERT INTO `d1`.`t1`
これもrecoveryの方に入った。recoveryが動きを止める
遅延が完全に追い付いてからnode1にINSERTした値はapplierの方に入る。
### node1
mysql> INSERT INTO d1.t1 VALUES (6, 'six');
Query OK, 1 row affected (0.01 sec)

### node3
for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep INSERT | grep d1
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-48-relay-bin-group_replication_applier.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-48-relay-bin-group_replication_applier.000002 ### INSERT INTO `d1`.`t1`
ん? 何故かapplierの方に (5, ‘five’) と思しきイベントも入ってる
### node3
$ mysqlbinlog -vv /var/lib/mysql/ip-172-31-1-48-relay-bin-group_replication_applier.000002
..
SET @@SESSION.GTID_NEXT= '14b471b9-66e5-11ea-888f-12c40920c9ad:454'/*!*/;
### INSERT INTO `d1`.`t1`
### SET
###   @1=5
###   @2='five'
..
SET @@SESSION.GTID_NEXT= '14b471b9-66e5-11ea-888f-12c40920c9ad:455'/*!*/;
### INSERT INTO `d1`.`t1`
### SET
###   @1=6
###   @2='six'
recoveryの方のリレーログすぐ消えちゃうからな… relay_log_purge=OFF したら残ってくれるかしらん。
### node3
mysql> 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            | 14b471b9-66e5-11ea-888f-12c40920c9ad:455 | 2020-03-15 18:23:10.568424 | 0000-00-00 00:00:00.000000 |
| group_replication_recovery | OFF           | 14b471b9-66e5-11ea-888f-12c40920c9ad:453 | 0000-00-00 00:00:00.000000 | 2020-03-15 18:18:30.913861 |
+----------------------------+---------------+------------------------------------------+----------------------------+----------------------------+
2 rows in set (0.00 sec)
performance_schemaで調べる限り、RECOVERING中に入ってきた2行はapplierの方が処理しているっぽい。
正直どっちが処理してくれても(recoveryが止まって初めてapplierが動くなら)構いはしない気がするけど、これがDMLだからなのかDDLなのかちょっと気になるね。
…と調べてみたら、DML/DDLに関わらずグループレプリケーションを再開した後に打たれたSQLはrecoveryのリレーログで一度受けた後にapplierの方に回すっぽい。
謎が深まった。

シングルプライマリーモードだろうとInnoDB Cluster内のデータをズラす方法

TL;DR

  • 単にプライマリーノードで SET sql_log_bin = 0 で効くんだからびっくりだ

動作確認用にd1.t1テーブルを作って2行くらい入れておく。
### node1
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)

mysql> INSERT INTO d1.t1 VALUES (2, 'two');
Query OK, 1 row affected (0.00 sec)
プライマリーノードで sysbench を使って100万行くらいのテーブルを作る。
### node1
$ sysbench --mysql-user=root oltp_common --table_size=1000000 prepare
sysbench 1.0.17 (using system LuaJIT 2.0.4)

Creating table 'sbtest1'...
Inserting 1000000 records into 'sbtest1'
Creating a secondary index on 'sbtest1'...

### node1
mysql> SELECT COUNT(*) FROM sbtest.sbtest1;                                                 
+----------+
| COUNT(*) |
+----------+
|  1000000 |
+----------+
1 row in set (0.32 sec)

### node2
mysql> SELECT COUNT(*) FROM sbtest.sbtest1;
+----------+
| COUNT(*) |
+----------+
|  1000000 |
+----------+
1 row in set (0.14 sec)

### node3
mysql> SELECT COUNT(*) FROM sbtest.sbtest1;
+----------+
| COUNT(*) |
+----------+
|  1000000 |
+----------+
1 row in set (0.13 sec)
sql_log_bin=OFF でいけるかなと思ったらいけてしまった。
### node1
mysql> SET SESSION sql_log_bin = 0;
Query OK, 0 rows affected (0.00 sec)

mysql> DELETE FROM sbtest.sbtest1;
Query OK, 1000000 rows affected (9.65 sec)

### node1
mysql> SELECT COUNT(*) FROM sbtest.sbtest1;
+----------+
| COUNT(*) |
+----------+
|        0 |
+----------+
1 row in set (0.00 sec)

### node2
mysql> SELECT COUNT(*) FROM sbtest.sbtest1;
+----------+
| COUNT(*) |
+----------+
|  1000000 |
+----------+
1 row in set (0.24 sec)

### node3
mysql> SELECT COUNT(*) FROM sbtest.sbtest1;
+----------+
| COUNT(*) |
+----------+
|  1000000 |
+----------+
1 row in set (0.15 sec)
これで何が嬉しいかっていうと、この状態でnode1に対してテキトーな OPTIMIZE TABLE でも投げ続ければ、node2とnode3は十分遅れてくれるだろうっていうこと。
### node1
mysql> OPTIMIZE TABLE sbtest.sbtest1; -- これを5回くらい

mysql> SELECT MEMBER_ID, COUNT_TRANSACTIONS_IN_QUEUE AS queue, COUNT_TRANSACTIONS_REMOTE_IN_APPLIER_QUEUE FROM performance_schema.replication_group_member_stats;                                        +--------------------------------------+-------+--------------------------------------------+
| MEMBER_ID                            | queue | COUNT_TRANSACTIONS_REMOTE_IN_APPLIER_QUEUE |
+--------------------------------------+-------+--------------------------------------------+
| ec62dfb5-66e4-11ea-a8d3-12c40920c9ad |     0 |                                          0 |
| ee6bca41-66e4-11ea-b904-123209691891 |     0 |                                          5 |
| f35fec8f-66e4-11ea-9a69-12dd5d4a2e3d |     0 |                                          5 |
+--------------------------------------+-------+--------------------------------------------+
3 rows in set (0.00 sec)
溜まってるのが確認できる。
溜まってる間に追い越してApplyされないのは前々回くらいに試した通りなんだけど。
### node1
mysql> INSERT INTO d1.t1 VALUES (3, 'three');
Query OK, 1 row affected (0.00 sec)

mysql> SELECT * FROM t1;
+-----+-------+
| num | val   |
+-----+-------+
|   1 | one   |
|   2 | two   |
|   3 | three |
+-----+-------+
3 rows in set (0.00 sec)

$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep INSERT | grep d1
/var/lib/mysql/binlog.000003 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000003 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000003 ### INSERT INTO `d1`.`t1`

### node2
mysql> SELECT * FROM t1;
+-----+------+
| num | val  |
+-----+------+
|   1 | one  |
|   2 | two  |
+-----+------+
2 rows in set (0.00 sec)

$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep INSERT | grep d1                              [22/19445]
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-120-relay-bin-group_replication_applier.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-120-relay-bin-group_replication_applier.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-120-relay-bin-group_replication_applier.000002 ### INSERT INTO `d1`.`t1`

### node3
mysql> SELECT * FROM t1;
+-----+------+
| num | val  |
+-----+------+
|   1 | one  |
|   2 | two  |
+-----+------+
2 rows in set (0.00 sec)

$ for f in /var/lib/mysql/*.0000* ; do mysqlbinlog -vv $f | stdbuf -oL awk '{print "'$f'", $0}'; done | grep INSERT | grep d1                               [22/18451]
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/binlog.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-48-relay-bin-group_replication_applier.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-48-relay-bin-group_replication_applier.000002 ### INSERT INTO `d1`.`t1`
/var/lib/mysql/ip-172-31-1-48-relay-bin-group_replication_applier.000002 ### INSERT INTO `d1`.`t1`
Applierの方のリレーログはまではちゃんと受け取っている。
DMLだと、DML適用の番になった時にフツーのレプリケーションと同じようにDUP_KEYなりROW_NOT_FOUNDでエラーになって面白くないだけだと思うので、この状態で「グループレプリケーションが遅延しまくっている」のを再現させるのが使いどころじゃないかなあとは思う。
遅延させて何を試していたかはタイトルにそぐわなくなってきたのでまた今度。

続きはこっち → 日々の覚書: わざと件数をズラしたグループレプリケーションで、「遅延中」の動きを観察する

2020/03/13

グループレプリケーションの 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つのチャンネルを使っているのが何となくわかった。