Protocol not supported 93

[Jakub]

The cluster doesn't start with xtrabackup-v2 sst method. It only starts with rsync sst.

node3: mysql Ver 14.14 Distrib 5.6.15, for Linux (x86_64) using EditLine wrapper
node1: mysql Ver 14.14 Distrib 5.6.22-72.0, for debian-linux-gnu (x86_64) using EditLine wrapper

Synchronization of node1 <=> node2 (both ways) with xtrabackup-v2 method works great.

So, what is wrong?

---------------------------------------------------------------------------------------

150515 11:28:56 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
150515 11:28:56 mysqld_safe Skipping wsrep-recover for empty datadir: /var/lib/mysql
150515 11:28:56 mysqld_safe Assigning 00000000-0000-0000-0000-000000000000:-1 to wsrep_start_position
2015-05-15 11:28:57 0 [Warning] Using unique option prefix key_buffer instead of key_buffer_size is deprecated and will be removed in a future release. Please use the full name instead.
2015-05-15 11:28:57 0 [Note] WSREP: wsrep_start_position var submitted: '00000000-0000-0000-0000-000000000000:-1'
2015-05-15 11:28:57 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2015-05-15 11:28:57 15729 [Note] WSREP: Read nil XID from storage engines, skipping position init
2015-05-15 11:28:57 15729 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/libgalera_smm.so'
2015-05-15 11:28:57 15729 [Note] WSREP: wsrep_load(): Galera 3.4(r176) by Codership Oy <email address hidden> loaded successfully.
2015-05-15 11:28:57 15729 [Note] WSREP: CRC-32C: using "slicing-by-8" algorithm.
2015-05-15 11:28:57 15729 [Warning] WSREP: Could not open saved state file for reading: /var/lib/mysql//grastate.dat
2015-05-15 11:28:57 15729 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1
2015-05-15 11:28:57 15729 [Note] WSREP: Passing config to GCS: base_host = 192.168.0.190; base_port = 4567; cert.log_conflicts = no; debug = no; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S;$
2015-05-15 11:28:57 15729 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
2015-05-15 11:28:57 15729 [Note] WSREP: wsrep_sst_grab()
2015-05-15 11:28:57 15729 [Note] WSREP: Start replication
2015-05-15 11:28:57 15729 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
2015-05-15 11:28:57 15729 [Note] WSREP: protonet asio version 0
2015-05-15 11:28:57 15729 [Note] WSREP: Using CRC-32C (optimized) for message checksums.
2015-05-15 11:28:57 15729 [Note] WSREP: backend: asio
2015-05-15 11:28:57 15729 [Note] WSREP: GMCast version 0
2015-05-15 11:28:57 15729 [Note] WSREP: (cfc45d48-fae4-11e4-9bcf-265d905fb2e6, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2015-05-15 11:28:57 15729 [Note] WSREP: (cfc45d48-fae4-11e4-9bcf-265d905fb2e6, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2015-05-15 11:28:57 15729 [Note] WSREP: EVS version 0
2015-05-15 11:28:57 15729 [Note] WSREP: PC version 0
2015-05-15 11:28:57 15729 [Note] WSREP: gcomm: connecting to group 'trimethylxanthine', peer '192.168.0.240:,192.168.0.204:,192.168.0.190:'
2015-05-15 11:28:57 15729 [Warning] WSREP: (cfc45d48-fae4-11e4-9bcf-265d905fb2e6, 'tcp://0.0.0.0:4567') address 'tcp://192.168.0.190:4567' points to own listening address, blacklisting
2015-05-15 11:28:57 15729 [Note] WSREP: (cfc45d48-fae4-11e4-9bcf-265d905fb2e6, 'tcp://0.0.0.0:4567') address 'tcp://192.168.0.190:4567' pointing to uuid cfc45d48-fae4-11e4-9bcf-265d905fb2e6 is blacklisted, skip$
2015-05-15 11:28:57 15729 [Note] WSREP: (cfc45d48-fae4-11e4-9bcf-265d905fb2e6, 'tcp://0.0.0.0:4567') address 'tcp://192.168.0.190:4567' pointing to uuid cfc45d48-fae4-11e4-9bcf-265d905fb2e6 is blacklisted, skip$
2015-05-15 11:28:57 15729 [Note] WSREP: (cfc45d48-fae4-11e4-9bcf-265d905fb2e6, 'tcp://0.0.0.0:4567') address 'tcp://192.168.0.190:4567' pointing to uuid cfc45d48-fae4-11e4-9bcf-265d905fb2e6 is blacklisted, skip$
2015-05-15 11:28:57 15729 [Note] WSREP: declaring 4e1bed32-fac8-11e4-8e2d-6a6e8f40098c stable
2015-05-15 11:28:57 15729 [Note] WSREP: declaring da9261d1-fac6-11e4-a3eb-ef95989b61f3 stable
2015-05-15 11:28:57 15729 [Note] WSREP: Node 4e1bed32-fac8-11e4-8e2d-6a6e8f40098c state prim
2015-05-15 11:28:57 15729 [Note] WSREP: view(view_id(PRIM,4e1bed32-fac8-11e4-8e2d-6a6e8f40098c,204) memb {
        4e1bed32-fac8-11e4-8e2d-6a6e8f40098c,0
        cfc45d48-fae4-11e4-9bcf-265d905fb2e6,0
        da9261d1-fac6-11e4-a3eb-ef95989b61f3,0
} joined {
} left {
} partitioned {
})
2015-05-15 11:28:57 15729 [Note] WSREP: gcomm: connected
2015-05-15 11:28:57 15729 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2015-05-15 11:28:57 15729 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2015-05-15 11:28:57 15729 [Note] WSREP: Opened channel 'trimethylxanthine'
2015-05-15 11:28:57 15729 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 3
2015-05-15 11:28:57 15729 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2015-05-15 11:28:57 15729 [Note] WSREP: Waiting for SST to complete.
2015-05-15 11:28:57 15729 [Note] WSREP: STATE EXCHANGE: sent state msg: d02b8e33-fae4-11e4-b47d-8322d89f9870
2015-05-15 11:28:57 15729 [Note] WSREP: STATE EXCHANGE: got state msg: d02b8e33-fae4-11e4-b47d-8322d89f9870 from 0 (node4)
2015-05-15 11:28:57 15729 [Note] WSREP: STATE EXCHANGE: got state msg: d02b8e33-fae4-11e4-b47d-8322d89f9870 from 2 (node1)
2015-05-15 11:28:57 15729 [Note] WSREP: STATE EXCHANGE: got state msg: d02b8e33-fae4-11e4-b47d-8322d89f9870 from 1 (node3)

2015-05-15 11:28:57 15729 [Note] WSREP: Quorum results:
        version = 3,
        component = PRIMARY,
        conf_id = 200,
        members = 2/3 (joined/total),
        act_id = 36686,
        last_appl. = -1,
        protocols = 0/5/2 (gcs/repl/appl),
        group UUID = ee3b46ea-c7eb-11e4-ad85-b399764bd6d0
2015-05-15 11:28:57 15729 [Note] WSREP: Flow-control interval: [28, 28]
2015-05-15 11:28:57 15729 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 36686)
2015-05-15 11:28:57 15729 [Note] WSREP: State transfer required:
        Group state: ee3b46ea-c7eb-11e4-ad85-b399764bd6d0:36686
        Local state: 00000000-0000-0000-0000-000000000000:-1
2015-05-15 11:28:57 15729 [Note] WSREP: New cluster view: global state: ee3b46ea-c7eb-11e4-ad85-b399764bd6d0:36686, view# 201: Primary, number of nodes: 3, my index: 1, protocol version 2
2015-05-15 11:28:57 15729 [Warning] WSREP: Gap in state sequence. Need state transfer.
2015-05-15 11:28:59 15729 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '192.168.0.190' --auth 'root:qaz123' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --parent '15729$
WSREP_SST: [INFO] Streaming with xbstream (20150515 11:29:00.003)
WSREP_SST: [INFO] Using socat as streamer (20150515 11:29:00.007)
WSREP_SST: [INFO] Evaluating timeout -k 110 100 socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20150515 11:29:00.361)
2015-05-15 11:29:00 15729 [Note] WSREP: Prepared SST request: xtrabackup-v2|192.168.0.190:4444/xtrabackup_sst
2015-05-15 11:29:00 15729 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2015-05-15 11:29:00 15729 [Note] WSREP: REPL Protocols: 5 (3, 1)
2015-05-15 11:29:00 15729 [Note] WSREP: Assign initial position for certification: 36686, protocol version: 3
2015-05-15 11:29:00 15729 [Note] WSREP: Service thread queue flushed.
2015-05-15 11:29:00 15729 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (ee3b46ea-c7eb-11e4-ad85-b399$
         at galera/src/replicator_str.cpp:prepare_for_IST():445. IST will be unavailable.
2015-05-15 11:29:00 15729 [Note] WSREP: Node 1.0 (node3) requested state transfer from 'node1'. Selected 2.0 (node1)(SYNCED) as donor.
2015-05-15 11:29:00 15729 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 36686)
2015-05-15 11:29:00 15729 [Note] WSREP: Requesting state transfer: success, donor: 2
2015-05-15 11:29:01 15729 [Warning] WSREP: 2.0 (node1): State transfer to 1.0 (node3) failed: -93 (Protocol not supported)
2015-05-15 11:29:01 15729 [ERROR] WSREP: gcs/src/gcs_group.c:gcs_group_handle_join_msg():723: Will never receive state. Need to abort.
2015-05-15 11:29:01 15729 [Note] WSREP: gcomm: terminating thread
2015-05-15 11:29:01 15729 [Note] WSREP: gcomm: joining thread
2015-05-15 11:29:01 15729 [Note] WSREP: gcomm: closing backend
2015-05-15 11:29:01 15729 [Note] WSREP: view(view_id(NON_PRIM,4e1bed32-fac8-11e4-8e2d-6a6e8f40098c,204) memb {
        cfc45d48-fae4-11e4-9bcf-265d905fb2e6,0
} joined {
} left {
} partitioned {
        4e1bed32-fac8-11e4-8e2d-6a6e8f40098c,0
        da9261d1-fac6-11e4-a3eb-ef95989b61f3,0
})
2015-05-15 11:29:01 15729 [Note] WSREP: view((empty))
2015-05-15 11:29:01 15729 [Note] WSREP: gcomm: closed
2015-05-15 11:29:01 15729 [Note] WSREP: /usr/sbin/mysqld: Terminated.
Aborted (core dumped)
150515 11:29:03 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

---------------------------------------------------------------------------------------
node3 my.cnf - node1 my.cnf is almost the same (the only difference is with wsrep_sst_donor and wsrep_node_name)

[mysql]

# CLIENT #
port=3306
socket=/var/lib/mysql/mysql.sock

[mysqld]

# GENERAL #
user=mysql
default-storage-engine=InnoDB
#socket=/var/lib/mysql/mysql.sock
#pid-file=/var/lib/mysql/mysql.pid
character-sets-dir=/usr/share/mysql/charsets/
back-log=2048
#skip-name-resolve=1
sort-buffer-size=2M
join-buffer-size=12M
#bind-address=0.0.0.0

# MyISAM #
key-buffer-size=16M
myisam-recover-options=FORCE,BACKUP
myisam-repair-threads=4
myisam-sort-buffer-size=32M

# SAFETY #
max-allowed-packet=256M
max-connect-errors=1000000
sql_mode=NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION
innodb=FORCE

# DATA STORAGE #
datadir=/var/lib/mysql/

# BINARY LOGGING #
log-bin=/var/lib/mysql/mysql-bin
expire-logs-days=4
sync-binlog=1
# CACHES AND LIMITS #
tmp-table-size=512M
max-heap-table-size=512M
query-cache-type=1
query-cache-size=128M
max-connections=500
thread-cache-size=50
open-files-limit=65535
table-definition-cache=4096
table-open-cache=4096
read-rnd-buffer-size=16M

# INNODB #
innodb_data_home_dir=/var/lib/mysql
innodb_log_group_home_dir=/var/lib/mysql
innodb-log-file-size=256M
innodb-data-file-path=ibdata1:1000M:autoextend:max:5G
innodb-flush-method=O_DIRECT
innodb-log-files-in-group=3
innodb-flush-log-at-trx-commit=2
innodb-file-per-table=1
innodb-buffer-pool-size=3G
innodb-buffer-pool-instances=4
innodb-log-buffer-size=12M
#innodb-flush-neighbor-pages=0
innodb-stats-on-metadata=0
#innodb-force-recovery=1

# LOGGING #
log-error=/var/lib/mysql/mysql-err.log
log-queries-not-using-indexes=1
slow-query-log=1
slow-query-log-file=/var/lib/mysql/mysql-slow.log

# OTHER #
local-infile=1

# CLUSTER #
wsrep_provider=/usr/lib/libgalera_smm.so
wsrep_cluster_address=gcomm://192.168.0.240,192.168.0.204,192.168.0.190
wsrep_node_address=192.168.0.190
wsrep_sst_method=xtrabackup-v2
binlog_format=ROW
innodb_autoinc_lock_mode=2
wsrep_sst_auth=xxx:yyy
wsrep_slave_threads=4
wsrep_cluster_name=trimethylxanthine
wsrep_node_name=node3
wsrep_provider_options="gcache.size=128M; gmcast.segment=0"
wsrep_sst_donor=node1

[mysqldump]

# GENERAL #
quick
max-allowed-packet=768M
single-transaction

[sst]
sst_special_dirs = 1
innodb-log-group_home-dir = /var/lib/mysql
innodb-data-home-dir = /var/lib/mysql

[Valerii Kravchuk (valerii-kravchuk)]

Whta is the version of Perrcona XtraDB Cluster on node2? Please, send also the output of

xtrabackup --version

frpom all 3 nodes.

[Jakub (jakub-luczynski)]

hi

mysql node 2: mysql Ver 14.14 Distrib 5.6.22-72.0, for debian-linux-gnu (x86_64) using EditLine wrapper

node1:~# xtrabackup --version
xtrabackup version 2.2.10 based on MySQL server 5.6.22 Linux (x86_64) (revision id: )

node2:~# xtrabackup --version
xtrabackup version 2.2.10 based on MySQL server 5.6.22 Linux (x86_64) (revision id: )

I'm sorry, I don't have the information about node 3 anymore.
I've updated percona cluster to 5.6.22 using repo percona precise (on ubuntu quantal 12.10)

Now:

node3:~# xtrabackup --version
xtrabackup version 2.2.10 based on MySQL server 5.6.22 Linux (x86_64) (revision id: )

node3:~# mysql --version
mysql Ver 14.14 Distrib 5.6.22-72.0, for debian-linux-gnu (x86_64) using EditLine wrapper

and everything works great.

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXC-1152