mysql - galera 节点上的完整 SST 未启动 ("WSREP: Prepared SST request"缺失)

Question

我有一个 galera 集群 (10.0.27)，有 3 个节点，每个节点位于一个专用服务器上。其中一台服务器重新启动后，该节点无法再加入集群，也无法执行完整的 SST。实际上，这就像 mysql “错过”启动一些命令。

我有第二个“开发”集群，具有相同的配置，运行良好，添加节点没有问题。当我为完整的 SST 添加节点时，我注意到工作集群和不工作集群之间存在差异:

节点加入工作集群:

 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Quorum results: 
 11:44:52  mysqld: #011version    = 4, 
 11:44:52  mysqld: #011component  = PRIMARY, 
 11:44:52  mysqld: #011conf_id    = 8, 
 11:44:52  mysqld: #011members    = 2/3 (joined/total), 
 11:44:52  mysqld: #011act_id     = 906976, 
 11:44:52  mysqld: #011last_appl. = -1, 
 11:44:52  mysqld: #011protocols  = 0/7/3 (gcs/repl/appl), 
 11:44:52  mysqld: #011group UUID = 27ba4c4f-9b78-11e6-824c-f3b1e60fa202 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Flow-control interval: [28, 28] 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 906976) 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: State transfer required: 
 11:44:52  mysqld: #011Group state: 27ba4c4f-9b78-11e6-824c-f3b1e60fa202:906976 
 11:44:52  mysqld: #011Local state: 00000000-0000-0000-0000-000000000000:-1 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: New cluster view: global state: 27ba4c4f-9b78-11e6-824c-f3b1e60fa202:906976, view# 9: Primary, number of nodes: 3, my index: 2, protocol version 3 
 11:44:52  mysqld: 170628 11:44:52 [Warning] WSREP: Gap in state sequence. Need state transfer. 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '192.***.***.**2' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --defaults-group-suffix '' --parent '16472' --binlog '/var/log/mysql/mariadb-bin' ' 
 **11:44:52  rsyncd[16514]: rsyncd version 3.1.1 starting, listening on port 4444** 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Prepared SST request: rsync|192.***.***.**2:4444/rsync_sst 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: REPL Protocols: 7 (3, 2) 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Assign initial position for certification: 906976, protocol version: 3 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Service thread queue flushed. 
 11:44:52  mysqld: 170628 11:44:52 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (27ba4c4f-9b78-11e6-824c-f3b1e60fa202): 1 (Operation not permitted) 
 11:44:52  mysqld: #011 at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable. 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Member 2.0 (server-3) requested state transfer from '*any*'. Selected 0.0 (server1)(SYNCED) as donor. 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 906977) 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: Requesting state transfer: success, donor: 0 
 11:44:52  mysqld: 170628 11:44:52 [Note] WSREP: GCache history reset: old(00000000-0000-0000-0000-000000000000:0) -> new(27ba4c4f-9b78-11e6-824c-f3b1e60fa202:906976) 
 11:44:52  rsyncd[16531]: name lookup failed for 192.***.***.**1: Name or service not known 
 11:44:52  rsyncd[16531]: connect from UNKNOWN (192.***.***.**1) 
 11:44:52  rsyncd[16531]: rsync to rsync_sst/ from UNKNOWN (192.***.***.**1) 
 11:44:52  rsyncd[16531]: receiving file list 
 11:44:54  rsyncd[16553]: name lookup failed for 192.***.***.**1: Name or service not known 
 11:44:54  rsyncd[16553]: connect from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16531]: sent 114 bytes  received 146847600 bytes  total size 146810880 
 11:44:54  rsyncd[16553]: rsync to rsync_sst-log_dir/ from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16553]: receiving file list 
 11:44:54  rsyncd[16553]: sent 63 bytes  received 100688095 bytes  total size 100663296 
 11:44:54  rsyncd[16559]: name lookup failed for 192.***.***.**1: Name or service not known 
 11:44:54  rsyncd[16559]: connect from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16560]: name lookup failed for 192.***.***.**1: Name or service not known 
 11:44:54  rsyncd[16560]: connect from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16561]: name lookup failed for 192.***.***.**1: Name or service not known 
 11:44:54  rsyncd[16561]: connect from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16562]: name lookup failed for 192.***.***.**1: Name or service not known 
 11:44:54  rsyncd[16562]: connect from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16559]: rsync to rsync_sst/./db_1 from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16562]: rsync to rsync_sst/./db_2 from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16560]: rsync to rsync_sst/./db_3 from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16561]: rsync to rsync_sst/./db_3 from UNKNOWN (192.***.***.**1) 
 11:44:54  rsyncd[16560]: receiving file list
...

节点加入非工作集群:

 13:36:28  mysqld: 170630 13:36:28 [Note] WSREP: Quorum results: 
 13:36:28   mysqld: #011version    = 4, 
 13:36:28   mysqld: #011component  = PRIMARY, 
 13:36:28   mysqld: #011conf_id    = 514, 
 13:36:28   mysqld: #011members    = 2/3 (joined/total), 
 13:36:28   mysqld: #011act_id     = 242914778, 
 13:36:28   mysqld: #011last_appl. = -1, 
 13:36:28   mysqld: #011protocols  = 0/7/3 (gcs/repl/appl), 
 13:36:28   mysqld: #011group UUID = 8119e584-9f83-11e6-b292-7a8102156c2d 
 13:36:28   mysqld: 170630 13:36:28 [Note] WSREP: Flow-control interval: [28, 28] 
 13:36:28   mysqld: 170630 13:36:28 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 242914778) 
 13:36:28   mysqld: 170630 13:36:28 [Note] WSREP: State transfer required: 
 13:36:28   mysqld: #011Group state: 8119e584-9f83-11e6-b292-7a8102156c2d:242914778 
 13:36:28   mysqld: #011Local state: 00000000-0000-0000-0000-000000000000:-1 
 13:36:28   mysqld: 170630 13:36:28 [Note] WSREP: New cluster view: global state: 8119e584-9f83-1
1e6-b292-7a8102156c2d:242914778, view# 515: Primary, number of nodes: 3, my index: 2, protocol version 3 
 13:36:28   mysqld: 170630 13:36:28 [Warning] WSREP: Gap in state sequence. Need state transfer. 
 13:36:28   mysqld: 170630 13:36:28 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --add
ress '192.***.***.*11' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --defaults-group-suffix '' --pare
nt '13253' --binlog '/var/log/mysql/mariadb-bin' ' 
 13:36:28   rsyncd[13316]: rsyncd version 3.1.1 starting, listening on port 4444 
 13:36:32   mysqld: 170630 13:36:32 [Note] WSREP: (85c5aae8, 'tcp://0.0.0.0:4567') turning messag
e relay requesting off 
 13:36:56   /etc/init.d/mysql[14935]: 0 processes alive and '/usr/bin/mysqladmin --defaults-file=
/etc/mysql/debian.cnf ping' resulted in 

区别就在行之后:

rsyncd[13316]: rsyncd version 3.1.1 starting, listening on port 4444 

在工作集群上，以下行是

WSREP: Prepared SST request: rsync|192.***.***.**2:4444/rsync_sst 

在不工作的集群上，这条线不会出现，就像没有发出 SST 请求一样。

如果您认为有助于查找问题，我可以提供有关配置的更多信息。

感谢您的帮助!

Answer 1

有同样的问题，这就是我发现的:

wsrep_sst_rsync 陷入无限循环。就我而言，因为 lsof -i :$rsync_port 的输出为空。由于某些(未知)原因，lsof 设置了 setgid 位:

[dbserver1:~]# ls -l /usr/bin/lsof
-rwxr-sr-x 1 root root 163224 Oct 28  2015 /usr/bin/lsof

这导致了 wsrep_sst_rsync 的无限循环，因为它检查 rsync 是否可以启动。删除该标志会导致脚本继续，最终启动 SST。

可以使用以下方法删除该标志:

[dbserver1:~]# chmod g-s /usr/bin/lsof