Node IP address not obtained from bind_addres

Hi Friends,

Please find the below error log information. we are getting this error while start first node PXC server.

2015-08-11 16:34:45 22259 [ERROR] WSREP: Node IP address not obtained from bind_address, trying alternate methods

Please suggest to resolve this issues.
Thanks,
Periyannan N.

Error Log Information:
2015-08-11 16:34:43 22259 [Note] WSREP: Opened channel ‘PXC_PROD_MCR’
2015-08-11 16:34:43 22259 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 2, memb_num = 3
2015-08-11 16:34:43 22259 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2015-08-11 16:34:43 22259 [Note] WSREP: Waiting for SST to complete.
2015-08-11 16:34:43 22259 [Note] WSREP: STATE EXCHANGE: sent state msg: d4a58626-402d-11e5-9e30-ce7e6f4bdc3b
2015-08-11 16:34:43 22259 [Note] WSREP: STATE EXCHANGE: got state msg: d4a58626-402d-11e5-9e30-ce7e6f4bdc3b from 0 (ip-0-0-0-3)
2015-08-11 16:34:43 22259 [Note] WSREP: STATE EXCHANGE: got state msg: d4a58626-402d-11e5-9e30-ce7e6f4bdc3b from 1 (ip-0-0-0-2)
2015-08-11 16:34:43 22259 [Note] WSREP: STATE EXCHANGE: got state msg: d4a58626-402d-11e5-9e30-ce7e6f4bdc3b from 2 (ip-0-0-0-1)
2015-08-11 16:34:43 22259 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 43,
members = 2/3 (joined/total),
act_id = 308865134,
last_appl. = -1,
protocols = 0/5/2 (gcs/repl/appl),
group UUID = 9d60ae4a-ebdf-11e3-aae0-67d4869e4557
2015-08-11 16:34:43 22259 [Note] WSREP: Flow-control interval: [28, 28]
2015-08-11 16:34:43 22259 [Note] WSREP: Shifting OPEN → PRIMARY (TO: 308865134)
2015-08-11 16:34:43 22259 [Note] WSREP: State transfer required:
Group state: 9d60ae4a-ebdf-11e3-aae0-67d4869e4557:308865134
Local state: 5ad7d245-402d-11e5-8e5c-8ea64b577c2d:0
2015-08-11 16:34:43 22259 [Note] WSREP: New cluster view: global state: 9d60ae4a-ebdf-11e3-aae0-67d4869e4557:308865134, view# 44: Primary, number of nodes: 3, my index: 2, protocol version 2
2015-08-11 16:34:43 22259 [Warning] WSREP: Gap in state sequence. Need state transfer.
2015-08-11 16:34:45 22259 [ERROR] WSREP: Node IP address not obtained from bind_address, trying alternate methods
2015-08-11 16:34:45 22259 [Note] WSREP: Running: 'wsrep_sst_xtrabackup --role ‘joiner’ --address ‘0.0.0.1’ --auth ‘sstuser:s3cret’ --datadir ‘/data/mysql/’ --defaults-file ‘/etc/my.cnf’ --parent ‘22259’ ‘’ ’
WSREP_SST: [INFO] Streaming with tar (20150811 16:34:46.231)
WSREP_SST: [INFO] Using socat as streamer (20150811 16:34:46.235)
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | tar xfi - --recursive-unlink -h; RC=( ${PIPESTATUS[@]} ) (20150811 16:34:46.265)
2015-08-11 16:34:46 22259 [Note] WSREP: Prepared SST request: xtrabackup|0.0.0.1:4444/xtrabackup_sst
2015-08-11 16:34:46 22259 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2015-08-11 16:34:46 22259 [Note] WSREP: REPL Protocols: 5 (3, 1)
2015-08-11 16:34:46 22259 [Note] WSREP: Service thread queue flushed.
2015-08-11 16:34:46 22259 [Note] WSREP: Assign initial position for certification: 308865134, protocol version: 3
2015-08-11 16:34:46 22259 [Note] WSREP: Service thread queue flushed.
2015-08-11 16:34:46 22259 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (5ad7d245-402d-11e5-8e5c-8ea64b577c2d) does not match group state UUID (9d60ae4a-ebdf-11e3-aae0-67d4869e4557): 1 (Operation not permitted)
at galera/src/replicator_str.cpp:prepare_for_IST():447. IST will be unavailable.
2015-08-11 16:34:46 22259 [Note] WSREP: Member 2.0 (ip-0-0-0-1) requested state transfer from ‘any’. Selected 0.0 (ip-0-0-0-3)(SYNCED) as donor.
2015-08-11 16:34:46 22259 [Note] WSREP: Shifting PRIMARY → JOINER (TO: 308865160)
2015-08-11 16:34:46 22259 [Note] WSREP: Requesting state transfer: success, donor: 0
2015-08-11 16:34:49 22259 [Warning] WSREP: 0.0 (ip-0-0-0-3): State transfer to 2.0 (ip-0-0-0-1) failed: -1 (Operation not permitted)
2015-08-11 16:34:49 22259 [ERROR] WSREP: gcs/src/gcs_group.c:gcs_group_handle_join_msg():723: Will never receive state. Need to abort.
2015-08-11 16:34:49 22259 [Note] WSREP: gcomm: terminating thread
2015-08-11 16:34:49 22259 [Note] WSREP: gcomm: joining thread
2015-08-11 16:34:49 22259 [Note] WSREP: gcomm: closing backend
2015-08-11 16:34:49 22259 [Note] WSREP: view(view_id(NON_PRIM,1905c6d1-005b-11e5-8451-af1af983a4a8,51) memb {
b935504f-402d-11e5-a1ba-cae5d7da2e75,0
} joined {
} left {
} partitioned {
1905c6d1-005b-11e5-8451-af1af983a4a8,0
1fb922ce-fb49-11e4-97ea-768153323ea7,0
})
2015-08-11 16:34:49 22259 [Note] WSREP: view((empty))
2015-08-11 16:34:49 22259 [Note] WSREP: gcomm: closed
2015-08-11 16:34:49 22259 [Note] WSREP: /usr/sbin/mysqld: Terminated.
150811 16:34:49 mysqld_safe mysqld from pid file /data/mysql/mysql.pid ended

What version of Percona XtraDB Cluster you are using ? How did you started node1 ? Please provide my.cnf file output from node1 which failed to start along with full output of innobackup.backup.log[LEFT][COLOR=#252C2F]

Hi,

PXC the version 5.6.15 which we are using. Please find the below rpm details.

Percona-XtraDB-Cluster-client-56-5.6.15-25.5.759.rhel6.x86_64

my.cnf file of DB Node 1.


24 GB RAM 2014-06-04 11:44:18

[mysql]

CLIENT

port = 3308
socket = /var/lib/mysql/mysql.sock

[mysqld]

GENERAL

user = mysql
default-storage-engine = InnoDB
port = 3308
socket = /var/lib/mysql/mysql.sock
pid-file = /data/mysql/mysql.pid

MyISAM

key-buffer-size = 32M
myisam-recover = FORCE,BACKUP

SAFETY

max-allowed-packet = 16M
max-connect-errors = 1000000
skip-name-resolve
sql-mode = STRICT_TRANS_TABLES,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_AUTO_VALUE_ON_ZERO,NO_ENGINE_SUBSTITUTION,NO_ZERO_DATE,NO_ZERO_IN_DATE,ONLY_FULL_GROUP_BY
sysdate-is-now = 1
innodb = FORCE
innodb-strict-mode = 1

DATA STORAGE

datadir = /data/mysql/

BINARY LOGGING

log-bin = /log/binary/mysql-bin
expire-logs-days = 14
sync-binlog = 1

CACHES AND LIMITS

tmp-table-size = 32M
max-heap-table-size = 32M
query-cache-type = 0
query-cache-size = 0
max-connections = 2000
thread-cache-size = 100
open-files-limit = 65535
table-definition-cache = 4096
table-open-cache = 4096

INNODB

innodb-flush-method = O_DIRECT
innodb-log-files-in-group = 2
innodb-log-file-size = 256M
innodb-flush-log-at-trx-commit = 1
innodb-file-per-table = 1
innodb-buffer-pool-size = 12G

LOGGING

log-error = /log/binary/mysql-error.log
#log-queries-not-using-indexes = 1
slow-query-log = 1
slow-query-log-file = /log/binary/mysql-slow.log

wait_timeout = 600
interactive_timeout = 600
explicit_defaults_for_timestamp

binlog_format=ROW
wsrep_provider=/usr/lib64/libgalera_smm.so
wsrep_slave_threads=2
default_storage_engine=InnoDB
innodb_locks_unsafe_for_binlog=1
innodb_autoinc_lock_mode=2
wsrep_sst_method=xtrabackup
wsrep_sst_auth=“sstuser:s3cret”

wsrep_cluster_name=PXC_PROD_MCR
server_id=2
wsrep_node_name=ip-0-0-0-1
wsrep_cluster_address=gcomm://0.0.0.2,0.0.0.3,0.0.0.1
wsrep_node_incoming_address=0.0.0.1:3308

#wait_timeout = 6000
#interactive_timeout = 6000
#connect_timeout = 6000
#net_read_timeout = 6000
#net_write_timeout = 1000

[mysqldump]
max-allowed-packet = 256M

innobackup.backup.log is not generating on DB Node 3.

Thanks and Regards,
Periyannan N.

Hi ,

Please find the DB server 3 error log information:

2015-08-11 16:35:28 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) address ‘tcp://0.0.0.3:4567’ pointing to uuid 1905c6d1-005b-11e5-8451-af1af983a4a8 is blacklisted, skipping
2015-08-11 16:35:28 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) turning message relay requesting on, nonlive peers: tcp://0.0.0.1:4567
2015-08-11 16:35:28 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) address ‘tcp://0.0.0.3:4567’ pointing to uuid 1905c6d1-005b-11e5-8451-af1af983a4a8 is blacklisted, skipping
2015-08-11 16:35:28 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) turning message relay requesting off
2015-08-11 16:35:28 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) address ‘tcp://0.0.0.3:4567’ pointing to uuid 1905c6d1-005b-11e5-8451-af1af983a4a8 is blacklisted, skipping
2015-08-11 16:35:28 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) address ‘tcp://0.0.0.3:4567’ pointing to uuid 1905c6d1-005b-11e5-8451-af1af983a4a8 is blacklisted, skipping
2015-08-11 16:35:28 23012 [Note] WSREP: declaring 1fb922ce-fb49-11e4-97ea-768153323ea7 stable
2015-08-11 16:35:28 23012 [Note] WSREP: declaring b935504f-402d-11e5-a1ba-cae5d7da2e75 stable
2015-08-11 16:35:28 23012 [Note] WSREP: Node 1905c6d1-005b-11e5-8451-af1af983a4a8 state prim
2015-08-11 16:35:28 23012 [Note] WSREP: view(view_id(PRIM,1905c6d1-005b-11e5-8451-af1af983a4a8,51) memb {
1905c6d1-005b-11e5-8451-af1af983a4a8,0
1fb922ce-fb49-11e4-97ea-768153323ea7,0
b935504f-402d-11e5-a1ba-cae5d7da2e75,0
} joined {
} left {
} partitioned {
})
2015-08-11 16:35:28 23012 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3
2015-08-11 16:35:29 23012 [Note] WSREP: STATE_EXCHANGE: sent state UUID: d4a58626-402d-11e5-9e30-ce7e6f4bdc3b
2015-08-11 16:35:29 23012 [Note] WSREP: STATE EXCHANGE: sent state msg: d4a58626-402d-11e5-9e30-ce7e6f4bdc3b
2015-08-11 16:35:29 23012 [Note] WSREP: STATE EXCHANGE: got state msg: d4a58626-402d-11e5-9e30-ce7e6f4bdc3b from 0 (ip-0-0-0-3)
2015-08-11 16:35:29 23012 [Note] WSREP: STATE EXCHANGE: got state msg: d4a58626-402d-11e5-9e30-ce7e6f4bdc3b from 1 (ip-0-0-0-2)
2015-08-11 16:35:29 23012 [Note] WSREP: STATE EXCHANGE: got state msg: d4a58626-402d-11e5-9e30-ce7e6f4bdc3b from 2 (ip-0-0-0-1)
2015-08-11 16:35:29 23012 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 43,
members = 2/3 (joined/total),
act_id = 308865134,
last_appl. = 308865108,
protocols = 0/5/2 (gcs/repl/appl),
group UUID = 9d60ae4a-ebdf-11e3-aae0-67d4869e4557
2015-08-11 16:35:29 23012 [Note] WSREP: Flow-control interval: [28, 28]
2015-08-11 16:35:29 23012 [Note] WSREP: New cluster view: global state: 9d60ae4a-ebdf-11e3-aae0-67d4869e4557:308865134, view# 44: Primary, number of nodes: 3, my index: 0, protocol version 2
2015-08-11 16:35:29 23012 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2015-08-11 16:35:29 23012 [Note] WSREP: REPL Protocols: 5 (3, 1)
2015-08-11 16:35:30 23012 [Note] WSREP: Service thread queue flushed.
2015-08-11 16:35:30 23012 [Note] WSREP: Assign initial position for certification: 308865134, protocol version: 3
2015-08-11 16:35:30 23012 [Note] WSREP: Service thread queue flushed.
2015-08-11 16:35:30 23012 [Warning] WSREP: Releasing seqno 308865134 before 308865135 was assigned.
2015-08-11 16:35:31 23012 [Note] WSREP: Member 2.0 (ip-0-0-0-1) requested state transfer from ‘any’. Selected 0.0 (ip-0-0-0-3)(SYNCED) as donor.
2015-08-11 16:35:31 23012 [Note] WSREP: Shifting SYNCED → DONOR/DESYNCED (TO: 308865160)
2015-08-11 16:35:31 23012 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2015-08-11 16:35:31 23012 [Note] WSREP: Running: ‘wsrep_sst_xtrabackup --role ‘donor’ --address ‘0.0.0.1:4444/xtrabackup_sst’ --auth ‘sstuser:s3cret’ --socket ‘/var/lib/mysql/mysql.sock’ --datadir ‘/data/mysql/’ --defaults-file ‘/etc/my.cnf’ ‘’ --gtid ‘9d60ae4a-ebdf-11e3-aae0-67d4869e4557:308865160’’
2015-08-11 16:35:32 23012 [Note] WSREP: sst_donor_thread signaled with 0
2015-08-11 16:35:34 23012 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup --role ‘donor’ --address ‘0.0.0.1:4444/xtrabackup_sst’ --auth ‘sstuser:s3cret’ --socket ‘/var/lib/mysql/mysql.sock’ --datadir ‘/data/mysql/’ --defaults-file ‘/etc/my.cnf’ ‘’ --gtid ‘9d60ae4a-ebdf-11e3-aae0-67d4869e4557:308865160’
2015-08-11 16:35:34 23012 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup --role ‘donor’ --address ‘0.0.0.1:4444/xtrabackup_sst’ --auth ‘sstuser:s3cret’ --socket ‘/var/lib/mysql/mysql.sock’ --datadir ‘/data/mysql/’ --defaults-file ‘/etc/my.cnf’ ‘’ --gtid ‘9d60ae4a-ebdf-11e3-aae0-67d4869e4557:308865160’: 1 (Operation not permitted)
2015-08-11 16:35:34 23012 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup --role ‘donor’ --address ‘0.0.0.1:4444/xtrabackup_sst’ --auth ‘sstuser:s3cret’ --socket ‘/var/lib/mysql/mysql.sock’ --datadir ‘/data/mysql/’ --defaults-file ‘/etc/my.cnf’ ‘’ --gtid ‘9d60ae4a-ebdf-11e3-aae0-67d4869e4557:308865160’
2015-08-11 16:35:34 23012 [Warning] WSREP: 0.0 (ip-0-0-0-3): State transfer to 2.0 (ip-0-0-0-1) failed: -1 (Operation not permitted)
2015-08-11 16:35:34 23012 [Note] WSREP: Shifting DONOR/DESYNCED → JOINED (TO: 308865209)
2015-08-11 16:35:34 23012 [Note] WSREP: Member 0.0 (ip-0-0-0-3) synced with group.
2015-08-11 16:35:34 23012 [Note] WSREP: Shifting JOINED → SYNCED (TO: 308865209)
2015-08-11 16:35:34 23012 [Note] WSREP: declaring 1fb922ce-fb49-11e4-97ea-768153323ea7 stable
2015-08-11 16:35:34 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) address ‘tcp://0.0.0.3:4567’ pointing to uuid 1905c6d1-005b-11e5-8451-af1af983a4a8 is blacklisted, skipping
2015-08-11 16:35:34 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) address ‘tcp://0.0.0.3:4567’ pointing to uuid 1905c6d1-005b-11e5-8451-af1af983a4a8 is blacklisted, skipping
2015-08-11 16:35:34 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) turning message relay requesting on, nonlive peers: tcp://0.0.0.1:4567
2015-08-11 16:35:34 23012 [Note] WSREP: Node 1905c6d1-005b-11e5-8451-af1af983a4a8 state prim
2015-08-11 16:35:34 23012 [Note] WSREP: view(view_id(PRIM,1905c6d1-005b-11e5-8451-af1af983a4a8,52) memb {
1905c6d1-005b-11e5-8451-af1af983a4a8,0
1fb922ce-fb49-11e4-97ea-768153323ea7,0
} joined {
} left {
} partitioned {
b935504f-402d-11e5-a1ba-cae5d7da2e75,0
})
2015-08-11 16:35:34 23012 [Note] WSREP: forgetting b935504f-402d-11e5-a1ba-cae5d7da2e75 (tcp://0.0.0.1:4567)
2015-08-11 16:35:34 23012 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2015-08-11 16:35:34 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) address ‘tcp://0.0.0.3:4567’ pointing to uuid 1905c6d1-005b-11e5-8451-af1af983a4a8 is blacklisted, skipping
2015-08-11 16:35:34 23012 [Note] WSREP: (1905c6d1-005b-11e5-8451-af1af983a4a8, ‘tcp://0.0.0.0:4567’) turning message relay requesting off
2015-08-11 16:35:34 23012 [Note] WSREP: STATE_EXCHANGE: sent state UUID: d831d630-402d-11e5-b30a-e27bdc773558
2015-08-11 16:35:34 23012 [Note] WSREP: STATE EXCHANGE: sent state msg: d831d630-402d-11e5-b30a-e27bdc773558
2015-08-11 16:35:34 23012 [Note] WSREP: STATE EXCHANGE: got state msg: d831d630-402d-11e5-b30a-e27bdc773558 from 0 (ip-0-0-0-3)
2015-08-11 16:35:34 23012 [Note] WSREP: STATE EXCHANGE: got state msg: d831d630-402d-11e5-b30a-e27bdc773558 from 1 (ip-0-0-0-2)
2015-08-11 16:35:34 23012 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 44,
members = 2/2 (joined/total),
act_id = 308865209,
last_appl. = 308865112,
protocols = 0/5/2 (gcs/repl/appl),
group UUID = 9d60ae4a-ebdf-11e3-aae0-67d4869e4557
2015-08-11 16:35:34 23012 [Note] WSREP: Flow-control interval: [23, 23]
2015-08-11 16:35:35 23012 [Note] WSREP: Synchronized with group, ready for connections
2015-08-11 16:35:35 23012 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2015-08-11 16:35:35 23012 [Note] WSREP: New cluster view: global state: 9d60ae4a-ebdf-11e3-aae0-67d4869e4557:308865209, view# 45: Primary, number of nodes: 2, my index: 0, protocol version 2
2015-08-11 16:35:35 23012 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2015-08-11 16:35:35 23012 [Note] WSREP: REPL Protocols: 5 (3, 1)
2015-08-11 16:35:36 23012 [Note] WSREP: Service thread queue flushed.
2015-08-11 16:35:36 23012 [Note] WSREP: Assign initial position for certification: 308865209, protocol version: 3
2015-08-11 16:35:36 23012 [Note] WSREP: Service thread queue flushed.
2015-08-11 16:35:36 23012 [Warning] WSREP: Releasing seqno 308865209 before 308865210 was assigned.
2015-08-11 16:35:40 23012 [Note] WSREP: cleaning up b935504f-402d-11e5-a1ba-cae5d7da2e75 (tcp://0.0.0.1:4567)

Thanks,
Peri.