Node 1 bootstrap is running, then node 2 is trying to join cluster, but eventually failed due to node 1 xtrabackup failing. Does anyone have idea why?
2014-06-04 04:55:01 29577 [Note] WSREP: declaring e9b4b1be-ebc5-11e3-a3a3-4eba949430e0 stable
2014-06-04 04:55:01 29577 [Note] WSREP: Node c277234e-ebc5-11e3-9dfd-2af600fcecb1 state prim
2014-06-04 04:55:01 29577 [Note] WSREP: view(view_id(PRIM,c277234e-ebc5-11e3-9dfd-2af600fcecb1,2) memb {
c277234e-ebc5-11e3-9dfd-2af600fcecb1,0
e9b4b1be-ebc5-11e3-a3a3-4eba949430e0,0
} joined {
} left {
} partitioned {
})
2014-06-04 04:55:01 29577 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2014-06-04 04:55:01 29577 [Note] WSREP: STATE_EXCHANGE: sent state UUID: ea01b398-ebc5-11e3-8864-c3b4b819bdf5
2014-06-04 04:55:01 29577 [Note] WSREP: STATE EXCHANGE: sent state msg: ea01b398-ebc5-11e3-8864-c3b4b819bdf5
2014-06-04 04:55:01 29577 [Note] WSREP: STATE EXCHANGE: got state msg: ea01b398-ebc5-11e3-8864-c3b4b819bdf5 from 0 (percona1)
2014-06-04 04:55:02 29577 [Note] WSREP: STATE EXCHANGE: got state msg: ea01b398-ebc5-11e3-8864-c3b4b819bdf5 from 1 (percona3)
2014-06-04 04:55:02 29577 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 1,
members = 1/2 (joined/total),
act_id = 2,
last_appl. = 0,
protocols = 0/5/2 (gcs/repl/appl),
group UUID = 88a6e968-ebb9-11e3-85dc-1ec3bdaa5a92
2014-06-04 04:55:02 29577 [Note] WSREP: Flow-control interval: [23, 23]
2014-06-04 04:55:02 29577 [Note] WSREP: New cluster view: global state: 88a6e968-ebb9-11e3-85dc-1ec3bdaa5a92:2, view# 2: Primary, number of nodes: 2, my index: 0, protocol version 2
2014-06-04 04:55:02 29577 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2014-06-04 04:55:02 29577 [Note] WSREP: REPL Protocols: 5 (3, 1)
2014-06-04 04:55:02 29577 [Note] WSREP: Service thread queue flushed.
2014-06-04 04:55:02 29577 [Note] WSREP: Assign initial position for certification: 2, protocol version: 3
2014-06-04 04:55:02 29577 [Note] WSREP: Service thread queue flushed.
2014-06-04 04:55:14 29577 [Note] WSREP: Member 1.0 (percona3) requested state transfer from '*any*'. Selected 0.0 (percona1)(SYNCED) as donor.
2014-06-04 04:55:14 29577 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 2)
2014-06-04 04:55:14 29577 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2014-06-04 04:55:14 29577 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '
192.168.15.79:4444/xtrabackup_sst' --auth 'sstuser:blackbox' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' '' --gtid '88a6e968-ebb9-11e3-85dc-1ec3bdaa5a92:2''
2014-06-04 04:55:14 29577 [Note] WSREP: sst_donor_thread signaled with 0
WSREP_SST: [INFO] Streaming with xbstream (20140604 04:55:15.091)
WSREP_SST: [INFO] Using socat as streamer (20140604 04:55:15.095)
WSREP_SST: [INFO] Using /tmp/tmp.7XYUezOnDB as xtrabackup temporary directory (20140604 04:55:15.294)
WSREP_SST: [INFO] Using /tmp/tmp.Dp4vvDgFpf as innobackupex temporary directory (20140604 04:55:15.300)
WSREP_SST: [INFO] Streaming GTID file before SST (20140604 04:55:15.308)
WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | socat -u stdio TCP:
192.168.15.79:4444; RC=( ${PIPESTATUS[@]} ) (20140604 04:55:15.312)
WSREP_SST: [INFO] Sleeping before data transfer for SST (20140604 04:55:15.320)
2014-06-04 04:55:17 29577 [Note] WSREP: Node c277234e-ebc5-11e3-9dfd-2af600fcecb1 state prim
2014-06-04 04:55:17 29577 [Note] WSREP: view(view_id(PRIM,c277234e-ebc5-11e3-9dfd-2af600fcecb1,3) memb {
c277234e-ebc5-11e3-9dfd-2af600fcecb1,0
} joined {
} left {
} partitioned {
e9b4b1be-ebc5-11e3-a3a3-4eba949430e0,0
})
2014-06-04 04:55:17 29577 [Note] WSREP: forgetting e9b4b1be-ebc5-11e3-a3a3-4eba949430e0 (tcp://
192.168.15.79:4567)
2014-06-04 04:55:17 29577 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
2014-06-04 04:55:17 29577 [Note] WSREP: STATE_EXCHANGE: sent state UUID: f39e6709-ebc5-11e3-88d9-e78656dc225b
2014-06-04 04:55:17 29577 [Note] WSREP: STATE EXCHANGE: sent state msg: f39e6709-ebc5-11e3-88d9-e78656dc225b
2014-06-04 04:55:17 29577 [Note] WSREP: STATE EXCHANGE: got state msg: f39e6709-ebc5-11e3-88d9-e78656dc225b from 0 (percona1)
2014-06-04 04:55:17 29577 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 2,
members = 1/1 (joined/total),
act_id = 2,
last_appl. = 0,
protocols = 0/5/2 (gcs/repl/appl),
group UUID = 88a6e968-ebb9-11e3-85dc-1ec3bdaa5a92
2014-06-04 04:55:17 29577 [Note] WSREP: Flow-control interval: [16, 16]
2014-06-04 04:55:17 29577 [Note] WSREP: New cluster view: global state: 88a6e968-ebb9-11e3-85dc-1ec3bdaa5a92:2, view# 3: Primary, number of nodes: 1, my index: 0, protocol version 2
2014-06-04 04:55:17 29577 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2014-06-04 04:55:17 29577 [Note] WSREP: REPL Protocols: 5 (3, 1)
2014-06-04 04:55:17 29577 [Note] WSREP: Service thread queue flushed.
2014-06-04 04:55:17 29577 [Note] WSREP: Assign initial position for certification: 2, protocol version: 3
2014-06-04 04:55:17 29577 [Note] WSREP: Service thread queue flushed.
2014-06-04 04:55:23 29577 [Note] WSREP: cleaning up e9b4b1be-ebc5-11e3-a3a3-4eba949430e0 (tcp://
192.168.15.79:4567)
WSREP_SST: [INFO] Streaming the backup to joiner at 192.168.15.79 4444 (20140604 04:55:25.326)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/mysql/my.cnf --no-version-check $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio TCP:
192.168.15.79:4444; RC=( ${PIPESTATUS[@]} ) (20140604 04:55:25.329)
2014/06/04 04:55:25 socat[29976] E write(3, 0x19d0250, 8192): Connection reset by peer
WSREP_SST: [ERROR] innobackupex finished with error: 1. Check /var/lib/mysql//innobackup.backup.log (20140604 04:55:26.519)
WSREP_SST: [ERROR] Cleanup after exit with status:22 (20140604 04:55:26.522)
WSREP_SST: [INFO] Cleaning up temporary directories (20140604 04:55:26.528)
2014-06-04 04:55:26 29577 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup-v2 --role 'donor' --address '
192.168.15.79:4444/xtrabackup_sst' --auth 'sstuser:blackbox' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' '' --gtid '88a6e968-ebb9-11e3-85dc-1ec3bdaa5a92:2'
2014-06-04 04:55:26 29577 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'donor' --address '
192.168.15.79:4444/xtrabackup_sst' --auth 'sstuser:blackbox' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' '' --gtid '88a6e968-ebb9-11e3-85dc-1ec3bdaa5a92:2': 22 (Invalid argument)
2014-06-04 04:55:26 29577 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup-v2 --role 'donor' --address '
192.168.15.79:4444/xtrabackup_sst' --auth 'sstuser:blackbox' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' '' --gtid '88a6e968-ebb9-11e3-85dc-1ec3bdaa5a92:2'
2014-06-04 04:55:26 29577 [Warning] WSREP: Could not find peer: e9b4b1be-ebc5-11e3-a3a3-4eba949430e0
2014-06-04 04:55:26 29577 [Warning] WSREP: 0.0 (percona1): State transfer to -1.-1 (left the group) failed: -22 (Invalid argument)
2014-06-04 04:55:26 29577 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 2)
2014-06-04 04:55:26 29577 [Note] WSREP: Member 0.0 (percona1) synced with group.
2014-06-04 04:55:26 29577 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 2)
2014-06-04 04:55:26 29577 [Note] WSREP: Synchronized with group, ready for connections
2014-06-04 04:55:26 29577 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.