0

I have following DB cluster:

Node 1: Percona-XtraDB-Cluster-56-5.6.39-26.25.1

Node 2: Percona-XtraDB-Cluster-56-5.6.39-26.25.1

Node 3: Percona-XtraDB-Cluster-56-5.6.41-28.28.1

I start in order Node 1, Node 2 Node 3. Cluster started and work properly. But now my node1 then node2 crash. My cluster (node 3 only) continuing to work properly.

But I can't start other node like Node 2 and sync to the cluster. I had try to clear DB data dir then sync from begining but still failed.

Following is error log:

Node 2: service mysql start

2019-03-06 16:40:32 1007281 [Note] WSREP: Setting wsrep_ready to false
2019-03-06 16:40:32 1007281 [Note] WSREP: Read nil XID from storage engines, skipping position init
2019-03-06 16:40:32 1007281 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/libgalera_smm.so'
2019-03-06 16:40:32 1007281 [Note] WSREP: wsrep_load(): Galera 3.25(rac090bc) by Codership Oy <info@codership.com> loaded successfully.
2019-03-06 16:40:32 1007281 [Note] WSREP: CRC-32C: using hardware acceleration.
2019-03-06 16:40:32 1007281 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2019-03-06 16:40:32 1007281 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 10.58.49.161; base_port = 4567; cert.log_conflicts = no; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; gcache.keep_pages_count = 0; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.recover = no; gcache.size = 128M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; 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; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT
2019-03-06 16:40:32 1007281 [Note] WSREP: GCache history reset: 773c5ba0-1f0e-11e8-8359-366569ddd6b6:0 -> 00000000-0000-0000-0000-000000000000:-1
2019-03-06 16:40:32 1007281 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
2019-03-06 16:40:32 1007281 [Note] WSREP: wsrep_sst_grab()
2019-03-06 16:40:32 1007281 [Note] WSREP: Start replication
2019-03-06 16:40:32 1007281 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
2019-03-06 16:40:32 1007281 [Note] WSREP: protonet asio version 0
2019-03-06 16:40:32 1007281 [Note] WSREP: Using CRC-32C for message checksums.
2019-03-06 16:40:32 1007281 [Note] WSREP: backend: asio
2019-03-06 16:40:32 1007281 [Note] WSREP: gcomm thread scheduling priority set to other:0 
2019-03-06 16:40:32 1007281 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
2019-03-06 16:40:32 1007281 [Note] WSREP: restore pc from disk failed
2019-03-06 16:40:32 1007281 [Note] WSREP: GMCast version 0
2019-03-06 16:40:32 1007281 [Note] WSREP: (e27e1564, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2019-03-06 16:40:32 1007281 [Note] WSREP: (e27e1564, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2019-03-06 16:40:32 1007281 [Note] WSREP: EVS version 0
2019-03-06 16:40:32 1007281 [Note] WSREP: gcomm: connecting to group 'my_centos_cluster', peer '10.58.49.162:'
2019-03-06 16:40:32 1007281 [Note] WSREP: (e27e1564, 'tcp://0.0.0.0:4567') connection established to 879d48d1 tcp://10.58.49.162:4567
2019-03-06 16:40:32 1007281 [Note] WSREP: (e27e1564, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 
2019-03-06 16:40:32 1007281 [Note] WSREP: declaring 879d48d1 at tcp://10.58.49.162:4567 stable
2019-03-06 16:40:32 1007281 [Note] WSREP: Node 879d48d1 state prim
2019-03-06 16:40:32 1007281 [Note] WSREP: view(view_id(PRIM,879d48d1,22) memb {
    879d48d1,0
    e27e1564,0
} joined {
} left {
} partitioned {
})
2019-03-06 16:40:32 1007281 [Note] WSREP: save pc into disk
2019-03-06 16:40:33 1007281 [Note] WSREP: gcomm: connected
2019-03-06 16:40:33 1007281 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2019-03-06 16:40:33 1007281 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2019-03-06 16:40:33 1007281 [Note] WSREP: Opened channel 'my_centos_cluster'
2019-03-06 16:40:33 1007281 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2019-03-06 16:40:33 1007281 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2019-03-06 16:40:33 1007281 [Note] WSREP: Waiting for SST to complete.
2019-03-06 16:40:33 1007281 [Note] WSREP: STATE EXCHANGE: sent state msg: e2cb78cf-3ff3-11e9-a578-9a611af77143
2019-03-06 16:40:33 1007281 [Note] WSREP: STATE EXCHANGE: got state msg: e2cb78cf-3ff3-11e9-a578-9a611af77143 from 0 (v-connect-03)
2019-03-06 16:40:33 1007281 [Note] WSREP: STATE EXCHANGE: got state msg: e2cb78cf-3ff3-11e9-a578-9a611af77143 from 1 (localhost.localdomain)
2019-03-06 16:40:33 1007281 [Note] WSREP: Quorum results:
    version    = 4,
    component  = PRIMARY,
    conf_id    = 21,
    members    = 1/2 (joined/total),
    act_id     = 143386057,
    last_appl. = -1,
    protocols  = 0/8/3 (gcs/repl/appl),
    group UUID = 773c5ba0-1f0e-11e8-8359-366569ddd6b6
2019-03-06 16:40:33 1007281 [Note] WSREP: Flow-control interval: [23, 23]
2019-03-06 16:40:33 1007281 [Note] WSREP: Trying to continue unpaused monitor
2019-03-06 16:40:33 1007281 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 143386057)
2019-03-06 16:40:33 1007281 [Note] WSREP: State transfer required: 
    Group state: 773c5ba0-1f0e-11e8-8359-366569ddd6b6:143386057
    Local state: 00000000-0000-0000-0000-000000000000:-1
2019-03-06 16:40:33 1007281 [Note] WSREP: New cluster view: global state: 773c5ba0-1f0e-11e8-8359-366569ddd6b6:143386057, view# 22: Primary, number of nodes: 2, my index: 1, protocol version 3
2019-03-06 16:40:33 1007281 [Note] WSREP: Setting wsrep_ready to true
2019-03-06 16:40:33 1007281 [Warning] WSREP: Gap in state sequence. Need state transfer.
2019-03-06 16:40:33 1007281 [Note] WSREP: Setting wsrep_ready to false
2019-03-06 16:40:33 1007281 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '10.58.49.161' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '1007281'  '' '
WSREP_SST: [INFO] Streaming with xbstream (2019-03-06 16:40:33)
WSREP_SST: [INFO] Using socat as streamer (2019-03-06 16:40:33)
WSREP_SST: [INFO] Stale sst_in_progress file: /var/lib/mysql//sst_in_progress (2019-03-06 16:40:33)
WSREP_SST: [INFO] Evaluating timeout -s9 100 socat -u TCP-LISTEN:4444,reuseaddr,retry=30 stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (2019-03-06 16:40:33)
2019-03-06 16:40:33 1007281 [Note] WSREP: Prepared SST request: xtrabackup-v2|10.58.49.161:4444/xtrabackup_sst//1
2019-03-06 16:40:33 1007281 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2019-03-06 16:40:33 1007281 [Note] WSREP: REPL Protocols: 8 (3, 2)
2019-03-06 16:40:33 1007281 [Note] WSREP: Assign initial position for certification: 143386057, protocol version: 3
2019-03-06 16:40:33 1007281 [Note] WSREP: Service thread queue flushed.
2019-03-06 16:40:33 1007281 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (773c5ba0-1f0e-11e8-8359-366569ddd6b6): 1 (Operation not permitted)
     at galera/src/replicator_str.cpp:prepare_for_IST():535. IST will be unavailable.
2019-03-06 16:40:33 1007281 [Note] WSREP: Member 1.0 (localhost.localdomain) requested state transfer from '*any*'. Selected 0.0 (v-connect-03)(SYNCED) as donor.
2019-03-06 16:40:33 1007281 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 143386070)
2019-03-06 16:40:33 1007281 [Note] WSREP: Requesting state transfer: success, donor: 0
2019-03-06 16:40:33 1007281 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 773c5ba0-1f0e-11e8-8359-366569ddd6b6:143386057
WSREP_SST: [ERROR] Cleanup after exit with status:1 (2019-03-06 16:40:33)
2019-03-06 16:40:34 1007281 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '10.58.49.161' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '1007281'  '' : 1 (Operation not permitted)
2019-03-06 16:40:34 1007281 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
2019-03-06 16:40:34 1007281 [ERROR] WSREP: SST script aborted with error 1 (Operation not permitted)
2019-03-06 16:40:34 1007281 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
2019-03-06 16:40:34 1007281 [ERROR] Aborting

2019-03-06 16:40:34 1007281 [Note] WSREP: Signalling cancellation of the SST request.
2019-03-06 16:40:34 1007281 [Note] WSREP: SST request was cancelled
2019-03-06 16:40:34 1007281 [Note] WSREP: Closing send monitor...
2019-03-06 16:40:34 1007281 [Note] WSREP: Closed send monitor.
2019-03-06 16:40:34 1007281 [Note] WSREP: gcomm: terminating thread
2019-03-06 16:40:34 1007281 [Note] WSREP: gcomm: joining thread
2019-03-06 16:40:34 1007281 [Note] WSREP: gcomm: closing backend
2019-03-06 16:40:35 1007281 [Note] WSREP: (e27e1564, 'tcp://0.0.0.0:4567') turning message relay requesting off
2019-03-06 16:40:36 1007281 [Note] WSREP: Service disconnected.
2019-03-06 16:40:36 1007281 [Note] WSREP: Waiting to close threads......
2019-03-06 16:40:36 1007281 [Note] WSREP: rollbacker thread exiting
2019-03-06 16:40:37 1007281 [Note] WSREP: (e27e1564, 'tcp://0.0.0.0:4567') connection to peer 879d48d1 with addr tcp://10.58.49.162:4567 timed out, no messages seen in PT3S
2019-03-06 16:40:37 1007281 [Note] WSREP: (e27e1564, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://10.58.49.162:4567 
2019-03-06 16:40:38 1007281 [Note] WSREP: (e27e1564, 'tcp://0.0.0.0:4567') reconnecting to 879d48d1 (tcp://10.58.49.162:4567), attempt 0
2019-03-06 16:40:39 1007281 [Note] WSREP: evs::proto(e27e1564, LEAVING, view_id(REG,879d48d1,22)) suspecting node: 879d48d1
2019-03-06 16:40:39 1007281 [Note] WSREP: evs::proto(e27e1564, LEAVING, view_id(REG,879d48d1,22)) suspected node without join message, declaring inactive
2019-03-06 16:40:39 1007281 [Note] WSREP: view(view_id(NON_PRIM,879d48d1,22) memb {
    e27e1564,0
} joined {
} left {
} partitioned {
    879d48d1,0
})
2019-03-06 16:40:39 1007281 [Note] WSREP: view((empty))
2019-03-06 16:40:39 1007281 [Note] WSREP: gcomm: closed
2019-03-06 16:40:39 1007281 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2019-03-06 16:40:39 1007281 [Note] WSREP: Flow-control interval: [16, 16]
2019-03-06 16:40:39 1007281 [Note] WSREP: Trying to continue unpaused monitor
2019-03-06 16:40:39 1007281 [Note] WSREP: Received NON-PRIMARY.
2019-03-06 16:40:39 1007281 [Note] WSREP: Shifting JOINER -> OPEN (TO: 143386078)
2019-03-06 16:40:39 1007281 [Note] WSREP: Received self-leave message.
2019-03-06 16:40:39 1007281 [Note] WSREP: Flow-control interval: [0, 0]
2019-03-06 16:40:39 1007281 [Note] WSREP: Trying to continue unpaused monitor
2019-03-06 16:40:39 1007281 [Note] WSREP: Received SELF-LEAVE. Closing connection.
2019-03-06 16:40:39 1007281 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 143386078)
2019-03-06 16:40:39 1007281 [Note] WSREP: RECV thread exiting 0: Success
2019-03-06 16:40:39 1007281 [Note] WSREP: recv_thread() joined.
2019-03-06 16:40:39 1007281 [Note] WSREP: Closing replication queue.
2019-03-06 16:40:39 1007281 [Note] WSREP: Closing slave action queue.
2019-03-06 16:40:39 1007281 [ERROR] WSREP: Certification exception: Unsupported key prefix: : 71 (Protocol error)
     at galera/src/key_set.cpp:throw_bad_prefix():152
2019-03-06 16:40:39 1007281 [Note] WSREP: /usr/sbin/mysqld: Terminated.

Node 3: Currently running

2019-03-06 16:40:32 28615 [Note] WSREP: (879d48d1, 'tcp://0.0.0.0:4567') connection established to e27e1564 tcp://10.58.49.161:4567
2019-03-06 16:40:32 28615 [Note] WSREP: (879d48d1, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 
2019-03-06 16:40:32 28615 [Note] WSREP: declaring e27e1564 at tcp://10.58.49.161:4567 stable
2019-03-06 16:40:32 28615 [Note] WSREP: Node 879d48d1 state prim
2019-03-06 16:40:32 28615 [Note] WSREP: view(view_id(PRIM,879d48d1,22) memb {
    879d48d1,0
    e27e1564,0
} joined {
} left {
} partitioned {
})
2019-03-06 16:40:32 28615 [Note] WSREP: save pc into disk
2019-03-06 16:40:32 28615 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2019-03-06 16:40:32 28615 [Note] WSREP: STATE_EXCHANGE: sent state UUID: e2cb78cf-3ff3-11e9-a578-9a611af77143
2019-03-06 16:40:32 28615 [Note] WSREP: STATE EXCHANGE: sent state msg: e2cb78cf-3ff3-11e9-a578-9a611af77143
2019-03-06 16:40:32 28615 [Note] WSREP: STATE EXCHANGE: got state msg: e2cb78cf-3ff3-11e9-a578-9a611af77143 from 0 (v-connect-03)
2019-03-06 16:40:33 28615 [Note] WSREP: STATE EXCHANGE: got state msg: e2cb78cf-3ff3-11e9-a578-9a611af77143 from 1 (localhost.localdomain)
2019-03-06 16:40:33 28615 [Note] WSREP: Quorum results:
    version    = 4,
    component  = PRIMARY,
    conf_id    = 21,
    members    = 1/2 (joined/total),
    act_id     = 143386057,
    last_appl. = 143386003,
    protocols  = 0/8/3 (gcs/repl/appl),
    group UUID = 773c5ba0-1f0e-11e8-8359-366569ddd6b6
2019-03-06 16:40:33 28615 [Note] WSREP: Flow-control interval: [23, 23]
2019-03-06 16:40:33 28615 [Note] WSREP: Trying to continue unpaused monitor
2019-03-06 16:40:33 28615 [Note] WSREP: New cluster view: global state: 773c5ba0-1f0e-11e8-8359-366569ddd6b6:143386057, view# 22: Primary, number of nodes: 2, my index: 0, protocol version 3
2019-03-06 16:40:33 28615 [Note] WSREP: Setting wsrep_ready to true
2019-03-06 16:40:33 28615 [Note] WSREP: Auto Increment Offset/Increment re-align with cluster membership change (Offset: 1 -> 1) (Increment: 1 -> 2)
2019-03-06 16:40:33 28615 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2019-03-06 16:40:33 28615 [Note] WSREP: REPL Protocols: 8 (3, 2)
2019-03-06 16:40:33 28615 [Note] WSREP: Assign initial position for certification: 143386057, protocol version: 3
2019-03-06 16:40:33 28615 [Note] WSREP: Service thread queue flushed.
2019-03-06 16:40:33 28615 [Warning] WSREP: trx protocol version: 4 does not match certification protocol version: 3
2019-03-06 16:40:33 28615 [Warning] WSREP: trx protocol version: 4 does not match certification protocol version: 3
2019-03-06 16:40:33 28615 [Warning] WSREP: trx protocol version: 4 does not match certification protocol version: 3
2019-03-06 16:40:33 28615 [Warning] WSREP: trx protocol version: 4 does not match certification protocol version: 3
2019-03-06 16:40:33 28615 [Warning] WSREP: trx protocol version: 4 does not match certification protocol version: 3
2019-03-06 16:40:33 28615 [Warning] WSREP: trx protocol version: 4 does not match certification protocol version: 3
2019-03-06 16:40:33 28615 [Warning] WSREP: trx protocol version: 4 does not match certification protocol version: 3
2019-03-06 16:40:33 28615 [Warning] WSREP: trx protocol version: 4 does not match certification protocol version: 3
2019-03-06 16:40:33 28615 [Note] WSREP: Member 1.0 (localhost.localdomain) requested state transfer from '*any*'. Selected 0.0 (v-connect-03)(SYNCED) as donor.
2019-03-06 16:40:33 28615 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 143386070)
2019-03-06 16:40:33 28615 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2019-03-06 16:40:33 28615 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '10.58.49.161:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --mysqld-version '5.6.41-84.1-56'   '' --gtid '773c5ba0-1f0e-11e8-8359-366569ddd6b6:143386070' '
2019-03-06 16:40:33 28615 [Note] WSREP: sst_donor_thread signaled with 0
WSREP_SST: [INFO] Streaming with xbstream (2019-03-06 16:40:33)
WSREP_SST: [INFO] Using socat as streamer (2019-03-06 16:40:33)
WSREP_SST: [INFO] Streaming SST meta-info file before SST (2019-03-06 16:40:33)
WSREP_SST: [INFO] Evaluating xbstream -c ${FILE_TO_STREAM} | socat -u stdio TCP:10.58.49.161:4444,retry=30; RC=( ${PIPESTATUS[@]} ) (2019-03-06 16:40:33)
WSREP_SST: [INFO] Sleeping before data transfer for SST (2019-03-06 16:40:33)
2019-03-06 16:40:35 28615 [Note] WSREP: forgetting e27e1564 (tcp://10.58.49.161:4567)
2019-03-06 16:40:35 28615 [Note] WSREP: Node 879d48d1 state prim
2019-03-06 16:40:35 28615 [Note] WSREP: view(view_id(PRIM,879d48d1,23) memb {
    879d48d1,0
} joined {
} left {
} partitioned {
    e27e1564,0
})
2019-03-06 16:40:35 28615 [Note] WSREP: save pc into disk
2019-03-06 16:40:35 28615 [Note] WSREP: forgetting e27e1564 (tcp://10.58.49.161:4567)
2019-03-06 16:40:35 28615 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
2019-03-06 16:40:35 28615 [Note] WSREP: STATE_EXCHANGE: sent state UUID: e43901d6-3ff3-11e9-bbc9-83ea4282ab29
2019-03-06 16:40:35 28615 [Note] WSREP: STATE EXCHANGE: sent state msg: e43901d6-3ff3-11e9-bbc9-83ea4282ab29
2019-03-06 16:40:35 28615 [Note] WSREP: STATE EXCHANGE: got state msg: e43901d6-3ff3-11e9-bbc9-83ea4282ab29 from 0 (v-connect-03)
2019-03-06 16:40:35 28615 [Note] WSREP: Quorum results:
    version    = 4,
    component  = PRIMARY,
    conf_id    = 22,
    members    = 1/1 (joined/total),
    act_id     = 143386078,
    last_appl. = 143386003,
    protocols  = 0/9/3 (gcs/repl/appl),
    group UUID = 773c5ba0-1f0e-11e8-8359-366569ddd6b6
2019-03-06 16:40:35 28615 [Note] WSREP: Flow-control interval: [16, 16]
2019-03-06 16:40:35 28615 [Note] WSREP: Trying to continue unpaused monitor
2019-03-06 16:40:35 28615 [Note] WSREP: New cluster view: global state: 773c5ba0-1f0e-11e8-8359-366569ddd6b6:143386078, view# 23: Primary, number of nodes: 1, my index: 0, protocol version 3
2019-03-06 16:40:35 28615 [Note] WSREP: Setting wsrep_ready to true
2019-03-06 16:40:35 28615 [Note] WSREP: Auto Increment Offset/Increment re-align with cluster membership change (Offset: 1 -> 1) (Increment: 2 -> 1)
2019-03-06 16:40:35 28615 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2019-03-06 16:40:35 28615 [Note] WSREP: REPL Protocols: 9 (4, 2)
2019-03-06 16:40:35 28615 [Note] WSREP: Assign initial position for certification: 143386078, protocol version: 4
2019-03-06 16:40:35 28615 [Note] WSREP: Service thread queue flushed.
2019-03-06 16:40:35 28615 [Note] WSREP: (879d48d1, 'tcp://0.0.0.0:4567') turning message relay requesting off
2019-03-06 16:40:38 28615 [Note] WSREP: (879d48d1, 'tcp://0.0.0.0:4567') connection established to e27e1564 tcp://10.58.49.161:4567
2019-03-06 16:40:38 28615 [Warning] WSREP: discarding established (time wait) e27e1564 (tcp://10.58.49.161:4567) 
2019-03-06 16:40:40 28615 [Note] WSREP:  cleaning up e27e1564 (tcp://10.58.49.161:4567)
WSREP_SST: [INFO] Streaming the backup to joiner at 10.58.49.161 4444 (2019-03-06 16:40:43)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/my.cnf  --defaults-group=mysqld --no-version-check  $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio TCP:10.58.49.161:4444,retry=30; RC=( ${PIPESTATUS[@]} ) (2019-03-06 16:40:43)
2019/03/06 16:41:13 socat[24873] E connect(3, AF=2 10.58.49.161:4444, 16): Connection refused
WSREP_SST: [ERROR] innobackupex finished with error: 1.  Check /var/lib/mysql//innobackup.backup.log (2019-03-06 16:41:14)
WSREP_SST: [ERROR] Cleanup after exit with status:22 (2019-03-06 16:41:14)
WSREP_SST: [INFO] Cleaning up temporary directories (2019-03-06 16:41:14)
2019-03-06 16:41:14 28615 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup-v2 --role 'donor' --address '10.58.49.161:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --mysqld-version '5.6.41-84.1-56'   '' --gtid '773c5ba0-1f0e-11e8-8359-366569ddd6b6:143386070' 
2019-03-06 16:41:14 28615 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'donor' --address '10.58.49.161:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --mysqld-version '5.6.41-84.1-56'   '' --gtid '773c5ba0-1f0e-11e8-8359-366569ddd6b6:143386070' : 22 (Invalid argument)
2019-03-06 16:41:14 28615 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup-v2 --role 'donor' --address '10.58.49.161:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --mysqld-version '5.6.41-84.1-56'   '' --gtid '773c5ba0-1f0e-11e8-8359-366569ddd6b6:143386070' 
2019-03-06 16:41:14 28615 [Warning] WSREP: Could not find peer: e27e1564-3ff3-11e9-8f94-aa1e9dd03b7f
2019-03-06 16:41:14 28615 [Warning] WSREP: 0.0 (v-connect-03): State transfer to -1.-1 (left the group) failed: -22 (Invalid argument)
2019-03-06 16:41:14 28615 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 143386421)
2019-03-06 16:41:14 28615 [Note] WSREP: Member 0.0 (v-connect-03) synced with group.
2019-03-06 16:41:14 28615 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 143386421)
2019-03-06 16:41:14 28615 [Note] WSREP: Synchronized with group, ready for connections
2019-03-06 16:41:14 28615 [Note] WSREP: Setting wsrep_ready to true
2019-03-06 16:41:14 28615 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.

Log: /var/lib/mysql//innobackup.backup.log

190306 16:40:43 innobackupex: Starting the backup operation

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

190306 16:40:43 Connecting to MySQL server host: localhost, user: sstuser, password: set, port: not set, socket: /var/lib/mysql/mysql.sock
Using server version 5.6.41-84.1-56
innobackupex version 2.3.10 based on MySQL server 5.6.24 Linux (x86_64) (revision id: bd0d4403f36)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql/
xtrabackup: open files limit requested 65535, set to 65535
xtrabackup: using the following InnoDB configuration:
xtrabackup:   innodb_data_home_dir = ./
xtrabackup:   innodb_data_file_path = ibdata1:12M:autoextend
xtrabackup:   innodb_log_group_home_dir = ./
xtrabackup:   innodb_log_files_in_group = 2
xtrabackup:   innodb_log_file_size = 536870912
xtrabackup: using O_DIRECT
innobackupex: Error writing file 'UNOPENED' (Errcode: 32 - Broken pipe)
xb_stream_write_data() failed.
xtrabackup: Error: write to logfile failed
innobackupex: Error writing file 'UNOPENED' (Errcode: 32 - Broken pipe)
xtrabackup: Error: xtrabackup_copy_logfile() failed.

How can I join Node 2 back to the cluster?

0

I just ended up in exactly this situation. In my case there were 2 PXC 5.6.41 nodes and one 5.6.40, on which the issue appeared. Upgrading it to 5.6.41 solved the problem. In your case, most likely, it will be the same. Either upgrade or downgrade and you should be all set.

  • Thank you. It work after upgraded to same version. – Viet Mar 16 at 2:29
0

Your root cause of an issue is figured in the first log from node 2:

2019-03-06 16:40:34 1007281 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '10.58.49.161' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '1007281'  '' : 1 (Operation not permitted)

Please check if you have the right permissions to run innobackupex script.

At the third log you can see, that innobackupex cannot write to the file

innobackupex: Error writing file 'UNOPENED' (Errcode: 32 - Broken pipe)

You may also check:

  • if ports for sst are open in order to socat work (4444, 4567)
  • If you have firewalld enabled and properly configured
  • If you have selinux enabled and properly configured
  • try to delete all data from data and Binlog directories
  • If nothing helps try to upgrade, PXC 5.6 is quite old

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.