title: Full SST on galera node doesn't start ("WSREP: Prepared SST request" missing)
body: <p>I have a galera cluster (10.0.27) with 3 nodes, each on a dedicated server. 
  After the reboot of one of the servers, the node cannot join the cluster anymore neither perform a full SST.
  Actually, it's like mysql 'misses' to launch some commands.</p>
  
  <p>I have a second 'development' cluster  with the same configuration working perfectly, I have no problem to add a node. I noticed a difference between the working cluster and not working when I add back a node for a full SST :</p>
  
  <p><strong>Node joining on working cluster :</strong></p>
  
  <pre><code> 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 -&gt; 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 -&gt; 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) -&gt; 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
  ...
  </code></pre>
  
  <p><strong>Node joining on non-working cluster :</strong></p>
  
  <pre><code> 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 -&gt; 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 
  </code></pre>
  
  <p>The difference is just after the line :</p>
  
  <pre><code>rsyncd[13316]: rsyncd version 3.1.1 starting, listening on port 4444 
  </code></pre>
  
  <p>On the working cluster, the following line is</p>
  
  <pre><code>WSREP: Prepared SST request: rsync|192.***.***.**2:4444/rsync_sst 
  </code></pre>
  
  <p>On the not working cluster this line doesn't appear, it's like the SST request is not made.</p>
  
  <p>I can provide more information about the configuration if you think it can help to find the issue.</p>
  
  <p>Thanks for your help !</p>