percona cluster db on 2nd node fail to start

conandor · February 23, 2015, 1:29pm

When I start mysql service in ubuntu. error.log keep looping at following message.


WSREP: Read nil XID from storage engines, skipping position init
150223 23:23:55 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/libgalera_smm.so'
150223 23:23:55 [Note] WSREP: wsrep_load(): Galera 2.8(r165) by Codership Oy <info&#64;codership.com> loaded successfully.
150223 23:23:55 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1
150223 23:23:55 [Note] WSREP: Reusing existing '/var/lib/mysql//galera.cache'.
150223 23:23:55 [Note] WSREP: Passing config to GCS: base_host = 10.1.1.30; base_port = 4567; cert.log_conflicts = no; gcache.dir = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.size = 128M; gcs.fc_debug = 0; gcs.fc_factor = 1; gcs.fc_limit = 16; gcs.fc_master_slave = NO; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = NO; replicator.causal_read_timeout = PT30S; replicator.commit_order = 3
150223 23:23:55 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
150223 23:23:55 [Note] WSREP: wsrep_sst_grab()
150223 23:23:55 [Note] WSREP: Start replication
150223 23:23:55 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
150223 23:23:55 [Note] WSREP: protonet asio version 0
150223 23:23:55 [Note] WSREP: backend: asio
150223 23:23:55 [Note] WSREP: GMCast version 0
150223 23:23:55 [Note] WSREP: (ef9c60a1-bb84-11e4-ae0e-5f6dda01f2fc, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
150223 23:23:55 [Note] WSREP: (ef9c60a1-bb84-11e4-ae0e-5f6dda01f2fc, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
150223 23:23:55 [Note] WSREP: EVS version 0
150223 23:23:55 [Note] WSREP: PC version 0
150223 23:23:55 [Note] WSREP: gcomm: connecting to group 'cluster', peer '10.1.1.29:,10.1.1.30:'
150223 23:23:55 [Warning] WSREP: (ef9c60a1-bb84-11e4-ae0e-5f6dda01f2fc, 'tcp://0.0.0.0:4567') address 'tcp://10.1.1.30:4567' points to own listening address, blacklisting
150223 23:23:55 [Note] WSREP: (ef9c60a1-bb84-11e4-ae0e-5f6dda01f2fc, 'tcp://0.0.0.0:4567') address 'tcp://10.1.1.30:4567' pointing to uuid ef9c60a1-bb84-11e4-ae0e-5f6dda01f2fc is blacklisted, skipping
150223 23:23:56 [Note] WSREP: declaring 9cc1474d-bb83-11e4-af2d-4a569b62ed1c stable
150223 23:23:56 [Note] WSREP: Node 9cc1474d-bb83-11e4-af2d-4a569b62ed1c state prim
150223 23:23:56 [Note] WSREP: view(view_id(PRIM,9cc1474d-bb83-11e4-af2d-4a569b62ed1c,36) memb {
9cc1474d-bb83-11e4-af2d-4a569b62ed1c,
ef9c60a1-bb84-11e4-ae0e-5f6dda01f2fc,
} joined {
} left {
} partitioned {
})
150223 23:23:56 [Note] WSREP: gcomm: connected
150223 23:23:56 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
150223 23:23:56 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
150223 23:23:56 [Note] WSREP: Opened channel 'cluster'
150223 23:23:56 [Note] WSREP: Waiting for SST to complete.
150223 23:23:56 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
150223 23:23:56 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
150223 23:23:56 [Note] WSREP: STATE EXCHANGE: sent state msg: 53dffab6-bb8a-11e4-8a2b-e309e267ec98
150223 23:23:56 [Note] WSREP: STATE EXCHANGE: got state msg: 53dffab6-bb8a-11e4-8a2b-e309e267ec98 from 0 (Pluto)
150223 23:23:56 [Note] WSREP: STATE EXCHANGE: got state msg: 53dffab6-bb8a-11e4-8a2b-e309e267ec98 from 1 (mars)
150223 23:23:56 [Note] WSREP: Quorum results:
version = 2,
component = PRIMARY,
conf_id = 35,
members = 1/2 (joined/total),
act_id = 1964141,
last_appl. = -1,
protocols = 0/4/3 (gcs/repl/appl),
group UUID = a1ce21ad-b997-11e4-ad11-a6b52963ec45
150223 23:23:56 [Note] WSREP: Flow-control interval: [23, 23]
150223 23:23:56 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 1964141)
150223 23:23:56 [Note] WSREP: State transfer required:
Group state: a1ce21ad-b997-11e4-ad11-a6b52963ec45:1964141
Local state: 00000000-0000-0000-0000-000000000000:-1
150223 23:23:56 [Note] WSREP: New cluster view: global state: a1ce21ad-b997-11e4-ad11-a6b52963ec45:1964141, view# 36: Primary, number of nodes: 2, my index: 1, protocol version 3
150223 23:23:56 [Warning] WSREP: Gap in state sequence. Need state transfer.
150223 23:23:56 [Note] WSREP: Running: 'wsrep_sst_xtrabackup --role 'joiner' --address '10.1.1.30' --auth 'user:pass' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '3589''
150223 23:23:56 [ERROR] WSREP: Failed to read 'ready <addr>' from: wsrep_sst_xtrabackup --role 'joiner' --address '10.1.1.30' --auth 'user:pass' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '3589'
Read: '(null)'
150223 23:23:56 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup --role 'joiner' --address '10.1.1.30' --auth 'user:pass' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '3589': 2 (No such file or directory)
150223 23:23:56 [ERROR] WSREP: Failed to prepare for 'xtrabackup' SST. Unrecoverable.
150223 23:23:56 [ERROR] Aborting

150223 23:23:58 [Note] WSREP: Closing send monitor...
150223 23:23:58 [Note] WSREP: Closed send monitor.
150223 23:23:58 [Note] WSREP: gcomm: terminating thread
150223 23:23:58 [Note] WSREP: gcomm: joining thread
150223 23:23:58 [Note] WSREP: gcomm: closing backend
150223 23:23:59 [Note] WSREP: view(view_id(NON_PRIM,9cc1474d-bb83-11e4-af2d-4a569b62ed1c,36) memb {
ef9c60a1-bb84-11e4-ae0e-5f6dda01f2fc,
} joined {
} left {
} partitioned {
9cc1474d-bb83-11e4-af2d-4a569b62ed1c,
})
150223 23:23:59 [Note] WSREP: view((empty))
150223 23:23:59 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
150223 23:23:59 [Note] WSREP: gcomm: closed
150223 23:23:59 [Note] WSREP: Flow-control interval: [16, 16]
150223 23:23:59 [Note] WSREP: Received NON-PRIMARY.
150223 23:23:59 [Note] WSREP: Shifting PRIMARY -> OPEN (TO: 1964153)
150223 23:23:59 [Note] WSREP: Received self-leave message.
150223 23:23:59 [Note] WSREP: Flow-control interval: [0, 0]
150223 23:23:59 [Note] WSREP: Received SELF-LEAVE. Closing connection.
150223 23:23:59 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 1964153)
150223 23:23:59 [Note] WSREP: RECV thread exiting 0: Success
150223 23:23:59 [Note] WSREP: recv_thread() joined.
150223 23:23:59 [Note] WSREP: Closing replication queue.
150223 23:23:59 [Note] WSREP: Closing slave action queue.
150223 23:23:59 [Note] WSREP: Service disconnected.
150223 23:23:59 [Note] WSREP: rollbacker thread exiting
150223 23:24:00 [Note] WSREP: Some threads may fail to exit.
150223 23:24:00 [Note] /usr/sbin/mysqld: Shutdown complete

I ran command line and it seem ok.


user&#64;home# wsrep_sst_xtrabackup --role 'joiner' --address '10.1.1.30' --auth 'user:pass' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '3474'
WSREP_SST: [INFO] Streaming with tar (20150223 23:43:10.344)
WSREP_SST: [INFO] Using socat as streamer (20150223 23:43:10.347)
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | tar xfi - --recursive-unlink -h; RC=( ${PIPESTATUS[&#64;]} ) (20150223 23:43:10.368)
ready 10.1.1.30:4444/xtrabackup_sst

Any idea where’s going wrong?

wydlakson · February 24, 2015, 2:47am

Did you run on 1st node?

Can you paste from 1st node?

PS: for logs use CODE

conandor · February 24, 2015, 6:46am

Thanks for the response.

How can I know if run on 1st node?
It’s not listening on port 4444 and there is no

conandor · February 24, 2015, 10:39pm

I discovered appamor is enabled in my ubuntu server.
[url]http://www.percona.com/blog/2012/12/20/percona-xtradb-cluster-selinux-is-not-always-the-culprit/[/url]

However disabling appamor doesn’t seem solve the problem. It get stuck in midway.

150225 8:33:39 [Note] WSREP: Flow-control interval: [23, 23]
150225 8:33:39 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 2633780)
150225 8:33:39 [Note] WSREP: State transfer required: 
Group state: a1ce21ad-b997-11e4-ad11-a6b52963ec45:2633780
Local state: 00000000-0000-0000-0000-000000000000:-1
150225 8:33:39 [Note] WSREP: New cluster view: global state: a1ce21ad-b997-11e4-ad11-a6b52963ec45:2633780, view# 2: Primary, number of nodes: 2, my index: 1, protocol version 3
150225 8:33:39 [Warning] WSREP: Gap in state sequence. Need state transfer.
150225 8:33:39 [Note] WSREP: Running: 'wsrep_sst_xtrabackup --role 'joiner' --address '10.1.1.30' --auth 'user:password' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '12655''
WSREP_SST: [INFO] Streaming with tar (20150225 08:33:39.859)
WSREP_SST: [INFO] Using socat as streamer (20150225 08:33:39.862)
150225 8:33:39 [ERROR] WSREP: Failed to read 'ready <addr>' from: wsrep_sst_xtrabackup --role 'joiner' --address '10.1.1.30' --auth 'user:password' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '12655'
Read: 'wait for listen'
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | tar xfi - --recursive-unlink -h; RC=( ${PIPESTATUS[&#64;]} ) (20150225 08:33:39.883)
150225 8:33:42 [Note] WSREP: (e5ab5336, 'tcp://0.0.0.0:4567') turning message relay requesting off

Manual executing

running wsrep_sst_xtrabackup --role 'joiner' --address '10.1.1.30' --auth 'user:password' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf'

–parent ‘12655’ seem ok.

WSREP_SST: [INFO] Streaming with tar (20150225 09:31:03.125)
WSREP_SST: [INFO] Using socat as streamer (20150225 09:31:03.128)
wait for listen
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | tar xfi - --recursive-unlink -h; RC=( ${PIPESTATUS[&#64;]} ) (20150225 09:31:03.149)

What I don’t understand why occur Read: ‘wait for listen’ error and then process get stuck.



150225 8:33:39 [ERROR] WSREP: Failed to read 'ready <addr>' from: wsrep_sst_xtrabackup --role 'joiner' --address '10.1.1.30' --auth 'user:password' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '12655'
Read: 'wait for listen'
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | tar xfi - --recursive-unlink -h; RC=( ${PIPESTATUS[&#64;]} ) (20150225 08:33:39.883)

mirfan · February 26, 2015, 3:32am

innobackup.backup.log should be in @datadir directory. Did you faced this error when you bootstrap first node of the cluster ? Can you please show my.cnf contents and also show the exacts steps you performed. Additionally, I would like you to follow this howto page on installation [url]Percona XtraDB Cluster

Topic		Replies	Views
Cluster Setup Percona XtraDB Cluster 5.x	0	876	August 7, 2013
Percona XTraDB Cluster Server not starting Percona XtraDB Cluster 5.x	2	726	July 31, 2012
Error joining to a xtradb cluster Percona XtraDB Cluster 5.x	2	15930	June 1, 2012
Failed to rejoin the cluster Percona XtraDB Cluster 5.x	2	1218	May 21, 2016
Can't start Percona Cluster on second node Percona XtraDB Cluster 5.x	2	2408	May 7, 2012

percona cluster db on 2nd node fail to start

Related Topics