I’m trying to stand up a 3-node PXC, MySQL 5.6 in RHEL 6.6. I was able to start the first node (172.30.200.45) OK. When I try to start the 2nd node (172.30.200.46) I’m getting this error:
[mysql@ldvdbamycl02 bin]$ /etc/init.d/mysql start
Starting MySQL… ERROR! The server quit without updating PID file (/var/lib/mysql/ldvdbamycl02.itap.purdue.edu.pid).
============================================
The my.cnf on the 2nd node is pretty simple:
[mysqld]
socket=/tmp/mysql.sock
datadir=/var/lib/mysql
basedir=/opt/mysql/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64
wsrep_provider=/opt/mysql/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/lib/libgalera_smm.so
user=mysql
log_error=/var/log/mysql/error.log
wsrep_cluster_address=‘gcomm://172.30.200.45,172.30.200.46,172.30.200.47’
binlog_format=ROW
default_storage_engine=InnoDB
innodb_autoinc_lock_mode=2
wsrep_node_address=172.30.200.46
wsrep_sst_method=rsync
wsrep_cluster_name=mysqldevcluster1
wsrep_sst_auth=“sstuser:xxxxx”
The error log on the 2nd node looks like this:
141114 14:27:17 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
141114 14:27:17 mysqld_safe WSREP: Running position recovery with --log_error=‘/var/lib/mysql/wsrep_recovery.KwUF7A’ --pid-file=‘/var/lib/mysql/ldvdbamycl02.itap.purdue.edu-recover.pid’
.
. (Lots of NOTES)
.
2014-11-14 14:27:20 17138 [Note] WSREP: gcomm: connecting to group ‘mysqldevcluster1’, peer ‘172.30.200.45:,172.30.200.46:,172.30.200.47:’
2014-11-14 14:27:20 17138 [Warning] WSREP: (4093e6a1, ‘tcp://0.0.0.0:4567’) address ‘tcp://172.30.200.46:4567’ points to own listening address, blacklisting
2014-11-14 14:27:20 17138 [Note] WSREP: (4093e6a1, ‘tcp://0.0.0.0:4567’) address ‘tcp://172.30.200.46:4567’ pointing to uuid 4093e6a1 is blacklisted, skipping
2014-11-14 14:27:20 17138 [Note] WSREP: (4093e6a1, ‘tcp://0.0.0.0:4567’) turning message relay requesting on, nonlive peers:
2014-11-14 14:27:21 17138 [Note] WSREP: gcomm: connected
2014-11-14 14:27:21 17138 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2014-11-14 14:27:21 17138 [Note] WSREP: Shifting CLOSED → OPEN (TO: 0)
2014-11-14 14:27:21 17138 [Note] WSREP: Opened channel ‘mysqldevcluster1’
2014-11-14 14:27:21 17138 [Note] WSREP: declaring 193c05ce at tcp://172.30.200.45:4567 stable
2014-11-14 14:27:21 17138 [Note] WSREP: Waiting for SST to complete.
2014-11-14 14:27:21 17138 [Note] WSREP: Node 193c05ce state prim
2014-11-14 14:27:21 17138 [Note] WSREP: save pc into disk
2014-11-14 14:27:21 17138 [Note] WSREP: discarding pending addr without UUID: tcp://172.30.200.47:4567
2014-11-14 14:27:21 17138 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2014-11-14 14:27:21 17138 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2014-11-14 14:27:21 17138 [Note] WSREP: STATE EXCHANGE: sent state msg: 40e2efd1-6c34-11e4-bb08-267a0fbc3147
2014-11-14 14:27:21 17138 [Note] WSREP: STATE EXCHANGE: got state msg: 40e2efd1-6c34-11e4-bb08-267a0fbc3147 from 0 (ldvdbamycl01.itap.purdue.edu)
2014-11-14 14:27:21 17138 [Note] WSREP: STATE EXCHANGE: got state msg: 40e2efd1-6c34-11e4-bb08-267a0fbc3147 from 1 (ldvdbamycl02.itap.purdue.edu)
2014-11-14 14:27:21 17138 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 3,
members = 1/2 (joined/total),
act_id = 5,
last_appl. = -1,
protocols = 0/6/3 (gcs/repl/appl),
group UUID = 58051e6b-6921-11e4-ab0b-a2658d23b81b
2014-11-14 14:27:21 17138 [Note] WSREP: Flow-control interval: [23, 23]
2014-11-14 14:27:21 17138 [Note] WSREP: Shifting OPEN → PRIMARY (TO: 5)
2014-11-14 14:27:21 17138 [Note] WSREP: State transfer required:
Group state: 58051e6b-6921-11e4-ab0b-a2658d23b81b:5
Local state: 00000000-0000-0000-0000-000000000000:-1
2014-11-14 14:27:21 17138 [Note] WSREP: New cluster view: global state: 58051e6b-6921-11e4-ab0b-a2658d23b81b:5, view# 4: Primary, number of nodes: 2, my index: 1, protocol version 3
2014-11-14 14:27:21 17138 [Warning] WSREP: Gap in state sequence. Need state transfer.
2014-11-14 14:27:21 17138 [Note] WSREP: Running: 'wsrep_sst_rsync --role ‘joiner’ --address ‘172.30.200.46’ --auth ‘sstuser:xxxxx’ --datadir ‘/var/lib/mysql/’ --defaults-file ‘/etc/my.cnf’ --parent ‘17138’ ‘’ ’
WSREP_SST: [ERROR] rsync daemon port ‘4444’ has been taken (20141114 14:27:21.093)
WSREP_SST: [INFO] Joiner cleanup. (20141114 14:27:21.094)
WSREP_SST: [INFO] Joiner cleanup done. (20141114 14:27:21.098)
2014-11-14 14:27:21 17138 [ERROR] WSREP: Failed to read ‘ready ’ from: wsrep_sst_rsync --role ‘joiner’ --address ‘172.30.200.46’ --auth ‘sstuser:xxxxx’ --datadir ‘/var/lib/mysql/’ --defaults-file ‘/etc/my.cnf’ --parent ‘17138’ ‘’
Read: ‘(null)’
2014-11-14 14:27:21 17138 [ERROR] WSREP: Process completed with error: wsrep_sst_rsync --role ‘joiner’ --address ‘172.30.200.46’ --auth ‘sstuser:xxxxxx’ --datadir ‘/var/lib/mysql/’ --defaults-file ‘/etc/my.cnf’ --parent ‘17138’ ‘’ : 16 (Device or resource busy)
2014-11-14 14:27:21 17138 [ERROR] WSREP: Failed to prepare for ‘rsync’ SST. Unrecoverable.
2014-11-14 14:27:21 17138 [ERROR] Aborting
.
. (more NOTEs)
.
2014-11-14 14:27:24 17138 [Note] WSREP: Closing slave action queue.
2014-11-14 14:27:24 17138 [Note] WSREP: Service disconnected.
2014-11-14 14:27:24 17138 [Note] WSREP: rollbacker thread exiting
2014-11-14 14:27:25 17138 [Note] WSREP: Some threads may fail to exit.
2014-11-14 14:27:25 17138 [Note] Binlog end
2014-11-14 14:27:25 17138 [Note] /opt/mysql/Percona-XtraDB-Cluster-5.6.20-rel68.0-25.7.886.Linux.x86_64/bin/mysqld: Shutdown complete
Error in my_thread_global_end(): 1 threads didn’t exit
141114 14:27:30 mysqld_safe mysqld from pid file /var/lib/mysql/ldvdbamycl02.itap.purdue.edu.pid ended
==================================================
The error log on the 1st node indicates that it’s receiving something from the 2nd node:
2014-11-14 14:27:20 6163 [Note] WSREP: (193c05ce, ‘tcp://0.0.0.0:4567’) turning message relay requesting on, nonlive peers:
2014-11-14 14:27:21 6163 [Note] WSREP: declaring 4093e6a1 at tcp://172.30.200.46:4567 stable
2014-11-14 14:27:21 6163 [Note] WSREP: Node 193c05ce state prim
2014-11-14 14:27:21 6163 [Note] WSREP: save pc into disk
2014-11-14 14:27:21 6163 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2014-11-14 14:27:21 6163 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 40e2efd1-6c34-11e4-bb08-267a0fbc3147
2014-11-14 14:27:21 6163 [Note] WSREP: STATE EXCHANGE: sent state msg: 40e2efd1-6c34-11e4-bb08-267a0fbc3147
2014-11-14 14:27:21 6163 [Note] WSREP: STATE EXCHANGE: got state msg: 40e2efd1-6c34-11e4-bb08-267a0fbc3147 from 0 (ldvdbamycl01.itap.purdue.edu)
2014-11-14 14:27:21 6163 [Note] WSREP: STATE EXCHANGE: got state msg: 40e2efd1-6c34-11e4-bb08-267a0fbc3147 from 1 (ldvdbamycl02.itap.purdue.edu)
2014-11-14 14:27:21 6163 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 3,
members = 1/2 (joined/total),
act_id = 5,
last_appl. = 0,
protocols = 0/6/3 (gcs/repl/appl),
group UUID = 58051e6b-6921-11e4-ab0b-a2658d23b81b
2014-11-14 14:27:21 6163 [Note] WSREP: Flow-control interval: [23, 23]
2014-11-14 14:27:21 6163 [Note] WSREP: New cluster view: global state: 58051e6b-6921-11e4-ab0b-a2658d23b81b:5, view# 4: Primary, number of nodes: 2, my index: 0, protocol version 3
2014-11-14 14:27:21 6163 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2014-11-14 14:27:21 6163 [Note] WSREP: REPL Protocols: 6 (3, 2)
2014-11-14 14:27:21 6163 [Note] WSREP: Service thread queue flushed.
2014-11-14 14:27:21 6163 [Note] WSREP: Assign initial position for certification: 5, protocol version: 3
2014-11-14 14:27:21 6163 [Note] WSREP: Service thread queue flushed.
2014-11-14 14:27:23 6163 [Note] WSREP: (193c05ce, ‘tcp://0.0.0.0:4567’) turning message relay requesting off
2014-11-14 14:27:24 6163 [Note] WSREP: forgetting 4093e6a1 (tcp://172.30.200.46:4567)
2014-11-14 14:27:24 6163 [Note] WSREP: Node 193c05ce state prim
2014-11-14 14:27:24 6163 [Note] WSREP: save pc into disk
2014-11-14 14:27:24 6163 [Note] WSREP: forgetting 4093e6a1 (tcp://172.30.200.46:4567)
2014-11-14 14:27:24 6163 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
2014-11-14 14:27:24 6163 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 42b34e55-6c34-11e4-903d-77406d125f6b
2014-11-14 14:27:24 6163 [Note] WSREP: STATE EXCHANGE: sent state msg: 42b34e55-6c34-11e4-903d-77406d125f6b
2014-11-14 14:27:24 6163 [Note] WSREP: STATE EXCHANGE: got state msg: 42b34e55-6c34-11e4-903d-77406d125f6b from 0 (ldvdbamycl01.itap.purdue.edu)
2014-11-14 14:27:24 6163 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 4,
members = 1/1 (joined/total),
act_id = 5,
last_appl. = 0,
protocols = 0/6/3 (gcs/repl/appl),
group UUID = 58051e6b-6921-11e4-ab0b-a2658d23b81b
2014-11-14 14:27:24 6163 [Note] WSREP: Flow-control interval: [16, 16]
2014-11-14 14:27:24 6163 [Note] WSREP: New cluster view: global state: 58051e6b-6921-11e4-ab0b-a2658d23b81b:5, view# 5: Primary, number of nodes: 1, my index: 0, protocol version 3
2014-11-14 14:27:24 6163 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2014-11-14 14:27:24 6163 [Note] WSREP: REPL Protocols: 6 (3, 2)
2014-11-14 14:27:24 6163 [Note] WSREP: Service thread queue flushed.
2014-11-14 14:27:24 6163 [Note] WSREP: Assign initial position for certification: 5, protocol version: 3
2014-11-14 14:27:24 6163 [Note] WSREP: Service thread queue flushed.
2014-11-14 14:27:29 6163 [Note] WSREP: cleaning up 4093e6a1 (tcp://172.30.200.46:4567)
====================================================
Any suggestions?