Xtradb cluster node 2 fail to join: xtrabackup_56: Error writing file 'UNOPENED' (Errcode: 32 - Broken pipe)

2,153 views
Skip to first unread message

Thomas G. Lau

unread,
Jun 4, 2014, 5:00:03 AM6/4/14
to percona-d...@googlegroups.com
All nodes running precona xtradb cluster: Version: '5.6.15-63.0'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Percona XtraDB Cluster (GPL), Release 25.5, wsrep_25.5.r4061


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?









Node 1:

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.

then I trace down to node 1 /var/lib/mysql//innobackup.backup.log:

InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy
and Percona LLC and/or its affiliates 2009-2013.  All Rights Reserved.

This software is published under
the GNU GENERAL PUBLIC LICENSE Version 2, June 1991.

Get the latest version of Percona XtraBackup, documentation, and help resources:

140604 04:55:25  innobackupex: Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_file=/etc/mysql/my.cnf;mysql_read_default_group=xtrabackup;mysql_socket=/var/run/mysqld/mysqld.sock' as 'sstuser'  (using password: YES).
140604 04:55:25  innobackupex: Connected to MySQL server
IMPORTANT: Please check that the backup run completes successfully.
           At the end of a successful backup run innobackupex
           prints "completed OK!".

innobackupex: Using mysql server version 5.6.15-63.0

innobackupex: Created backup directory /tmp/tmp.Dp4vvDgFpf

140604 04:55:25  innobackupex: Starting ibbackup with command: xtrabackup_56  --defaults-file="/etc/mysql/my.cnf"  --defaults-group="mysqld" --backup --suspend-at-end --target-dir=/tmp/tmp.7XYUezOnDB --tmpdir=/tmp/tmp.7XYUezOnDB --stream=xbstream
innobackupex: Waiting for ibbackup (pid=29984) to suspend
innobackupex: Suspend file '/tmp/tmp.7XYUezOnDB/xtrabackup_suspended_2'

xtrabackup_56 version 2.1.9 for MySQL server 5.6.17 Linux (x86_64) (revision id: 744)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql
xtrabackup: open files limit requested 0, set to 8192
xtrabackup: using the following InnoDB configuration:
xtrabackup:   innodb_data_home_dir = ./
xtrabackup:   innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup:   innodb_log_group_home_dir = ./
xtrabackup:   innodb_log_files_in_group = 2
xtrabackup:   innodb_log_file_size = 50331648
>> log scanned up to (1627397)
[01] Streaming ./ibdata1
xtrabackup_56: Error writing file 'UNOPENED' (Errcode: 32 - Broken pipe)
xb_stream_write_data() failed.
xtrabackup_56: Error writing file 'UNOPENED' (Errcode: 32 - Broken pipe)
[01] xtrabackup: Error: xtrabackup_copy_datafile() failed.
[01] xtrabackup: Error: failed to copy datafile.
innobackupex: Error: The xtrabackup child process has died at /usr//bin/innobackupex line 2622.


___________________________

node 1 config:
[mysqld]

datadir=/var/lib/mysql
user=mysql

# Path to Galera library
wsrep_provider=/usr/lib/libgalera_smm.so

# Empty gcomm address is being used when cluster is getting bootstrapped
wsrep_cluster_address=gcomm://

# In order for Galera to work correctly binlog format should be ROW
binlog_format=ROW

# MyISAM storage engine has only experimental support
default_storage_engine=InnoDB

# This changes how InnoDB autoincrement locks are managed and is a requirement for Galera
innodb_autoinc_lock_mode=2

# Node #1 address
wsrep_node_address=192.168.15.77

# SST method
wsrep_sst_method=xtrabackup-v2

# Cluster name
wsrep_cluster_name=percona_cluster

# Authentication for SST method
wsrep_sst_auth="sstuser:password"



node 2 config:

[mysqld]

datadir=/var/lib/mysql
user=mysql

# Path to Galera library
wsrep_provider=/usr/lib/libgalera_smm.so

# Cluster connection URL contains the IPs of node#1, node#2 and node#3
wsrep_cluster_address=gcomm://192.168.15.77,192.168.15.78,192.168.15.79

# In order for Galera to work correctly binlog format should be ROW
binlog_format=ROW

# MyISAM storage engine has only experimental support
default_storage_engine=InnoDB

# This changes how InnoDB autoincrement locks are managed and is a requirement for Galera
innodb_autoinc_lock_mode=2

# Node #3 address
wsrep_node_address=192.168.15.79

# SST method
wsrep_sst_method=xtrabackup-v2

# Cluster name
wsrep_cluster_name=percona_cluster

# Authentication for SST method
wsrep_sst_auth="sstuser:password"

Jayakumar Athi

unread,
Nov 5, 2014, 1:08:42 AM11/5/14
to percona-d...@googlegroups.com, lkth...@gmail.com
Thanks Thomas; even I have the same issue; by chance did you get a resolution on this issue that you had published earlier? 
Jay
Reply all
Reply to author
Forward
0 new messages