XtraDB Initial SST fails

Hello,

I’ve been following the Ubuntu installation guide, but have hit a few problems when trying to bring the second node into the cluster. The first node is bootstrapped and seems to be fine, but when I start the second node the initial State transfer fails.

Packages (same on both nodes)
ii percona-xtradb-cluster-server-5.6 5.6.21-25.8-938.trusty
ii percona-xtrabackup 2.2.9-5067-1.trusty

my.cnf

# Path to Galera library
wsrep_provider=/usr/lib/libgalera_smm.so
# Cluster connection URL
wsrep_cluster_address=gcomm://10.17.40.150,10.17.40.135,10.17.40.132
#wsrep_cluster_address=gcomm://
# In order for Galera to work correctly binlog format should be ROW
binlog_format=ROW
# MyISAM storage engine has only experimental support
default_storage_engine=InnoDB
# This changes how |InnoDB| autoincrement locks are managed and is a requirement for Galera
innodb_autoinc_lock_mode=2
# Authentication for SST method
wsrep_sst_auth="sstuser:passwordhere"
# Node #1 address
wsrep_node_address=10.17.40.150
# SST method
wsrep_sst_method=xtrabackup-v2
# Cluster name
wsrep_cluster_name=brp
#innodb_buffer_pool_size=145774M
innodb_flush_log_at_trx_commit=2
innodb_file_per_table=1
innodb_data_file_path = ibdata1:100M:autoextend
## You may want to tune the below depending on number of cores and disk sub
innodb_read_io_threads=4
innodb_write_io_threads=4
innodb_io_capacity=200
innodb_doublewrite=1
innodb_log_file_size=1024M
innodb_log_buffer_size=96M
innodb_buffer_pool_instances=8
innodb_log_files_in_group=2
innodb_thread_concurrency=64
#innodb_file_format=barracuda
innodb_flush_method = O_DIRECT
innodb_autoinc_lock_mode=2
## avoid statistics update when doing e.g show tables
innodb_stats_on_metadata=0
innodb_data_home_dir=/var/lib/mysql
innodb_log_group_home_dir=/var/lib/mysql
xtrabackup would have been started with the following arguments:
--wsrep_provider=/usr/lib/libgalera_smm.so --wsrep_cluster_address=gcomm://10.17.40.150,10.17.40.135,10.17.40.132 --binlog_format=ROW --default_storage_engine=InnoDB --innodb_autoinc_lock_mode=2 --wsrep_sst_auth=sstuser:passwordhere --wsrep_node_address=10.17.40.150 --wsrep_sst_method=xtrabackup-v2 --wsrep_cluster_name=brp --user=mysql --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306 --basedir=/usr --datadir=/var/lib/mysql --tmpdir=/tmp --lc-messages-dir=/usr/share/mysql --skip-external-locking --bind-address=0.0.0.0 --key_buffer=16M --max_allowed_packet=16M --thread_stack=192K --thread_cache_size=8 --myisam-recover=BACKUP --innodb_flush_log_at_trx_commit=2 --innodb_file_per_table=1 --innodb_data_file_path=ibdata1:100M:autoextend --innodb_read_io_threads=4 --innodb_write_io_threads=4 --innodb_io_capacity=200 --innodb_doublewrite=1 --innodb_log_file_size=1024M --innodb_log_buffer_size=96M --innodb_buffer_pool_instances=8 --innodb_log_files_in_group=2 --innodb_thread_concurrency=64 --innodb_flush_method=O_DIRECT --innodb_autoinc_lock_mode=2 --innodb_stats_on_metadata=0 --innodb_data_home_dir=/var/lib/mysql --innodb_log_group_home_dir=/var/lib/mysql --query_cache_limit=1M --query_cache_size=16M --log_error=/var/log/mysql/error.log --expire_logs_days=10 --max_binlog_size=100M

Errors from mysql-error.log (node 2)

2015-02-25 09:32:48 26570 [Note] WSREP: State transfer required:
Group state: 8e461731-bc35-11e4-8a30-32847f70120f:3
Local state: 00000000-0000-0000-0000-000000000000:-1
2015-02-25 09:32:48 26570 [Note] WSREP: New cluster view: global state: 8e461731-bc35-11e4-8a30-32847f70120f:3, view# 16: Primary, number of nodes: 2, my index: 0, protocol version 3
2015-02-25 09:32:48 26570 [Warning] WSREP: Gap in state sequence. Need state transfer.
2015-02-25 09:32:48 26570 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '10.17.40.135' --auth 'sstuser:passwordhere' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '26570' '' '
WSREP_SST: [INFO] Streaming with xbstream (20150225 09:32:48.996)
WSREP_SST: [INFO] Using socat as streamer (20150225 09:32:49.000)
WSREP_SST: [INFO] Stale sst_in_progress file: /var/lib/mysql//sst_in_progress (20150225 09:32:49.395)
WSREP_SST: [INFO] Evaluating timeout -k 110 100 socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20150225 09:32:49.465)
2015-02-25 09:32:49 26570 [Note] WSREP: Prepared SST request: xtrabackup-v2|10.17.40.135:4444/xtrabackup_sst//1
2015-02-25 09:32:49 26570 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2015-02-25 09:32:49 26570 [Note] WSREP: REPL Protocols: 6 (3, 2)
2015-02-25 09:32:49 26570 [Note] WSREP: Service thread queue flushed.
2015-02-25 09:32:49 26570 [Note] WSREP: Assign initial position for certification: 3, protocol version: 3
2015-02-25 09:32:49 26570 [Note] WSREP: Service thread queue flushed.
2015-02-25 09:32:49 26570 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (8e461731-bc35-11e4-8a30-32847f70120f): 1 (Operation not permitted)
at galera/src/replicator_str.cpp:prepare_for_IST():456. IST will be unavailable.
2015-02-25 09:32:49 26570 [Note] WSREP: Member 0.0 (brppxdbl02) requested state transfer from '*any*'. Selected 1.0 (brppxdbcl01)(SYNCED) as donor.
2015-02-25 09:32:49 26570 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 3)
2015-02-25 09:32:49 26570 [Note] WSREP: Requesting state transfer: success, donor: 1
WSREP_SST: [INFO] Proceeding with SST (20150225 09:32:50.439)
WSREP_SST: [INFO] Cleaning the existing datadir (20150225 09:32:50.443)
removed ‘/var/lib/mysql/ib_logfile1’
removed ‘/var/lib/mysql/ibdata1’
removed ‘/var/lib/mysql/ib_logfile0’
removed ‘/var/lib/mysql/backup-my.cnf’
removed ‘/var/lib/mysql/auto.cnf’
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20150225 09:32:50.549)
2015-02-25 09:32:51 26570 [Note] WSREP: (426f677b, 'tcp://0.0.0.0:4567') turning message relay requesting off
grep: /var/lib/mysql//xtrabackup_checkpoints: No such file or directory
WSREP_SST: [INFO] Preparing the backup at /var/lib/mysql/ (20150225 09:33:00.698)
2015-02-25 09:33:00 26570 [Warning] WSREP: 1.0 (brppxdbcl01): State transfer to 0.0 (brppxdbl02) failed: -22 (Invalid argument)
2015-02-25 09:33:00 26570 [ERROR] WSREP: gcs/src/gcs_group.cpp:int gcs_group_handle_join_msg(gcs_group_t*, const gcs_recv_msg_t*)():722: Will never receive state. Need to abort.
2015-02-25 09:33:00 26570 [Note] WSREP: gcomm: terminating thread
2015-02-25 09:33:00 26570 [Note] WSREP: gcomm: joining thread
2015-02-25 09:33:00 26570 [Note] WSREP: gcomm: closing backend
WSREP_SST: [INFO] Evaluating innobackupex --no-version-check --apply-log $rebuildcmd ${DATA} &>${DATA}/innobackup.prepare.log (20150225 09:33:00.707)
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20150225 09:33:01.308)
2015-02-25 09:33:01 26570 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '10.17.40.135' --auth 'sstuser:passwordhere' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '26570' '' : 1 (Operation not permitted)
2015-02-25 09:33:01 26570 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
2015-02-25 09:33:01 26570 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
2015-02-25 09:33:01 26570 [ERROR] Aborting

2015-02-25 09:33:01 26570 [Note] WSREP: view(view_id(NON_PRIM,426f677b,16) memb {
426f677b,0
} joined {
} left {
} partitioned {
5ef44e98,0
})
2015-02-25 09:33:01 26570 [Note] WSREP: view((empty))
2015-02-25 09:33:01 26570 [Note] WSREP: gcomm: closed
2015-02-25 09:33:01 26570 [Note] WSREP: /usr/sbin/mysqld: Terminated.
Aborted
150225 09:33:01 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

I’ve seen several over posts similar to this, and so heres the permissions from my.cnf:
-rw-r–r-- 1 mysql root 4879 Feb 24 17:15 /etc/mysql/my.cnf
…and I do have datadir also, although it wasn’t included in the snip above…
datadir = /var/lib/mysql

Could I please have some suggestions here? As a newcomer it is virtually impossible to troubleshoot, and this is a fairly basic setup following a guide on your website.

Thanks,

J / robothands

One more log…

innobackup.prepare.log -

InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy
and Percona LLC and/or its affiliates 2009-2013. All Rights Reserved.

This software is published under
the GNU GENERAL PUBLIC LICENSE Version 2, June 1991.

Get the latest version of Percona XtraBackup, documentation, and help resources:
http://www.percona.com/xb/p

150225 09:33:01 innobackupex: Starting the apply-log operation

IMPORTANT: Please check that the apply-log run completes successfully.
At the end of a successful apply-log run innobackupex
prints "completed OK!".


150225 09:33:01 innobackupex: Starting ibbackup with command: xtrabackup --defaults-file="/var/lib/mysql/backup-my.cnf" --defaults-group="mysqld" --prepare --target-dir=/var/lib/mysql

xtrabackup version 2.2.9 based on MySQL server 5.6.22 Linux (x86_64) (revision id: )
xtrabackup: cd to /var/lib/mysql
xtrabackup: Error: cannot open ./xtrabackup_checkpoints
xtrabackup: error: xtrabackup_read_metadata()
xtrabackup: This target seems not to have correct metadata...
2015-02-25 09:33:01 7f01f3fed780 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: Warning: cannot open ./xtrabackup_logfile. will try to find.
2015-02-25 09:33:01 7f01f3fed780 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: Fatal error: cannot find ./xtrabackup_logfile.
xtrabackup: Error: xtrabackup_init_temp_log() failed.
innobackupex: got a fatal error with the following stacktrace: at /usr//bin/innobackupex line 2642.
main::apply_log() called at /usr//bin/innobackupex line 1570
innobackupex: Error:
innobackupex: ibbackup failed at /usr//bin/innobackupex line 2642.

Hi,

I figured out the problem. When adding the grant for the sstuser, I added it at 127.0.0.1, not ‘localhost’. I just added another grant for sstuser@localhost and it now works.

This can be closed.

Thanks,

Jamie

I don’t know if I am the only one interpreting this like this … but here it goes …
According to what you wrote on the TOP .

5.5.5.5:31082 → 10.10.10.10:3306
5.5.5.5:31083 → 10.10.10.10:4444
5.5.5.5:31084 → 10.10.10.10:4567
5.5.5.5:31085 → 10.10.10.10:4568

On your NAT you are already forwarding the non standard ports to the standard ports .
Now if what you want to do is used the non standard ports on the configuration let us know.


Our excellent online Testking ccna voice training programs will lead you to success in the togaf foundation We also offer latest hsbc and University of New Haven with 100% success guarantee. Our selftestengine is rare in IT world.

I had the same issue.