The bug is similar to the https://bugs.launchpad.net/fuel/+bug/1574999, although this one may happen a step down the road.
When an SST finished streaming data to a joiner, the "innobackupex--move-back" command may randomly fail because of a race /var/lib/mysql/ib_logfile0 failed: Destination file exists , with the following log /var/log/mysql/error.log:
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20160427 14:21:09.268)
2016-04-27 14:21:21 22037 [Note] WSREP: 0.0 (n1): State transfer to 3.0 (n3) complete.
2016-04-27 14:21:21 22037 [Note] WSREP: Member 0.0 (n1) synced with group.
2016-04-27 14:21:21 22037 [Note] WSREP: 1.0 (n5): State transfer to 2.0 (n4) complete.
2016-04-27 14:21:21 22037 [Note] WSREP: Member 1.0 (n5) synced with group.
WSREP_SST: [INFO] Preparing the backup at /var/lib/mysql//.sst (20160427 14:21:27.817)
WSREP_SST: [INFO] Evaluating innobackupex --no-version-check --apply-log $rebuildcmd ${DATA} &>${DATA}/innobackup.prepare.log (20160427 14:21:27.819)
WSREP_SST: [INFO] Moving the backup to /var/lib/mysql/ (20160427 14:21:33.597)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/mysql/my.cnf --no-version-check --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log (20160427 14:21:33.598)
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20160427 14:21:33.602)
2016-04-27 14:21:33 22037 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '10.10.10.4' --auth 'root:root' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '22037' '' : 1 (Operation not permitted)
2016-04-27 14:21:33 22037 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
2016-04-27 14:21:33 22037 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
2016-04-27 14:21:33 22037 [ERROR] Aborting
And here is the innobackup log with straces:
execve("/usrbin/innobackupex", ["innobackupex", "--defaults-file=/etc/mysql/my.cn"..., "--no-version-check", "--move-back", "--force-non-empty-directories", "/var/lib/mysql.sst"], [/
* 55 vars */]) = 0
(... snip ...)
write(2, "160428 07:43:06 innobackupex: St"..., 236160428 07:43:06 innobackupex: Starting the move-back operation
IMPORTANT: Please check that the move-back run completes successfully.
At the end of a successful move-back run innobackupex
prints "completed OK!".
The bug is similar to the https:/ /bugs.launchpad .net/fuel/ +bug/1574999, although this one may happen a step down the road. -move-back" command may randomly fail because of a race /var/lib/ mysql/ib_ logfile0 failed: Destination file exists , with the following log /var/log/ mysql/error. log:
When an SST finished streaming data to a joiner, the "innobackupex-
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN: 4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20160427 14:21:09.268) mysql// .sst (20160427 14:21:27.817) /innobackup. prepare. log (20160427 14:21:27.819) file=/etc/ mysql/my. cnf --no-version-check --move-back --force- non-empty- directories ${DATA} &>${DATA} /innobackup. move.log (20160427 14:21:33.598) xtrabackup- v2 --role 'joiner' --address '10.10.10.4' --auth 'root:root' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --parent '22037' '' : 1 (Operation not permitted)
2016-04-27 14:21:21 22037 [Note] WSREP: 0.0 (n1): State transfer to 3.0 (n3) complete.
2016-04-27 14:21:21 22037 [Note] WSREP: Member 0.0 (n1) synced with group.
2016-04-27 14:21:21 22037 [Note] WSREP: 1.0 (n5): State transfer to 2.0 (n4) complete.
2016-04-27 14:21:21 22037 [Note] WSREP: Member 1.0 (n5) synced with group.
WSREP_SST: [INFO] Preparing the backup at /var/lib/
WSREP_SST: [INFO] Evaluating innobackupex --no-version-check --apply-log $rebuildcmd ${DATA} &>${DATA}
WSREP_SST: [INFO] Moving the backup to /var/lib/mysql/ (20160427 14:21:33.597)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20160427 14:21:33.602)
2016-04-27 14:21:33 22037 [ERROR] WSREP: Process completed with error: wsrep_sst_
2016-04-27 14:21:33 22037 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
2016-04-27 14:21:33 22037 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
2016-04-27 14:21:33 22037 [ERROR] Aborting
And here is the innobackup log with straces: "/usrbin/ innobackupex" , ["innobackupex", "--defaults- file=/etc/ mysql/my. cn"..., "--no-version- check", "--move-back", "--force- non-empty- directories" , "/var/lib/ mysql.sst" ], [/
execve(
* 55 vars */]) = 0
(... snip ...)
write(2, "160428 07:43:06 innobackupex: St"..., 236160428 07:43:06 innobackupex: Starting the move-back operation
IMPORTANT: Please check that the move-back run completes successfully.
At the end of a successful move-back run innobackupex
prints "completed OK!".
) = 236 var/lib/ mysql", {st_mode= S_IFDIR| 0700, st_size=4096, ...}) = 0 O_NONBLOCK| O_DIRECTORY| O_CLOEXEC) = 3 var/lib/ mysql", {st_mode= S_IFDIR| 0700, st_size=4096, ...}) = 0 O_NONBLOCK| O_DIRECTORY| O_CLOEXEC) = 3 /var/lib/ mysql// .sst") = 0 /var/lib/ mysql", 0700) = -1 EEXIST (File exists) S_IFREG| 0660, st_size=83886080, ...}) = 0 var/lib/ mysql/" , {st_mode= S_IFDIR| 0700, st_size=4096, ...}) = 0 O_NONBLOCK| O_DIRECTORY| O_CLOEXEC) = 3 var/lib/ mysql/ib_ logfile0" , {st_mode= S_IFREG| 0660, st_size=83886080, ...}) = 0 mysql/ib_ logfile0 failed: Destination file exists
write(2, "innobackupex version 2.3.4 based"..., 94innobackupex version 2.3.4 based on MySQL server 5.6.24 Linux (x86_64) (revision id: e80c779)
) = 94
stat("/
openat(AT_FDCWD, "/var/lib/mysql", O_RDONLY|
close(3) = 0
stat("/
openat(AT_FDCWD, "/var/lib/mysql", O_RDONLY|
close(3) = 0
chdir("
brk(0x25a5000) = 0x25a5000
mkdir("
stat("ib_logfile0", {st_mode=
stat("/
openat(AT_FDCWD, "/var/lib/mysql/", O_RDONLY|
close(3) = 0
stat("/
write(2, "Error: Move file ib_logfile0 to "..., 91Error: Move file ib_logfile0 to /var/lib/
) = 91
exit_group(1) = ?
+++ exited with 1 +++
____ sst_xtrabackup- v2 sst_xtrabackup- v2
Note, to get strace debugs, I applied the patch to the
--- a/wsrep_
+++ b/wsrep_
@@ -578,8 +578,8 @@ fi
INNOEXTRA="" "${INNOBACKUPEX _BIN} $disver $iapts --apply-log \$rebuildcmd \${DATA} &>\${DATA} /innobackup. prepare. log" "${INNOBACKUPEX _BIN} --defaults- file=${ WSREP_SST_ OPT_CONF} $disver $impts --move-back --force- non-empty- directories \${DATA} &>\${DATA} /innobackup. move.log" "${INNOBACKUPEX _BIN} --defaults- file=${ WSREP_SST_ OPT_CONF} $disver $iopts \$tmpopts \$INNOEXTRA --galera-info --stream=\$sfmt \$itmpdir 2>\${DATA} /innobackup. backup. log" file=${ WSREP_SST_ OPT_CONF} $disver $impts --move-back --force- non-empty- directories \${DATA} &>\${DATA} /innobackup. move.log" file=${ WSREP_SST_ OPT_CONF} $disver $iopts \$tmpopts \$INNOEXTRA --galera-info --stream=\$sfmt \$itmpdir 2>\${DATA} /innobackup. backup. log"
INNOAPPLY=
-INNOMOVE=
-INNOBACKUP=
+INNOMOVE="strace -f ${INNOBACKUPEX_BIN} --defaults-
+INNOBACKUP="strace -f ${INNOBACKUPEX_BIN} --defaults-
if [ "$WSREP_ SST_OPT_ ROLE" = "donor" ]
then