Failed backup using innobackupex calling InnoDB

[Tom Fallon]

Hi there

we are running innobackupex via a simple bash script to backup MySQL DBs (a mix of iSAM and InnoDB) running on MySQL (Ver 14.14 Distrib 5.6.21-69.0) and xtrabackup version 2.2.6 based on MySQL server 5.6.21. This is on a pair of CentOS 6.5 servers which run the backup script and store the resulting backups on a Synology mounted via CIFS.

Script is as follows, note this was amended from xtrabackup to innobackupex at some point.

#########################################################
#/bin/bash

# Simple backup script to create full backups

# determine the current date
NOW=$(date +%Y-%m-%d)

TARGETDIR="/media/db_backups/`hostname`/"

# specify the location to save the backup to
DIR="$TARGETDIR$NOW/"

<email address hidden>"

# exit if backup location already exists
#if [ -d "$DIR" ]; then
# echo "Backup Directory $DIR already exists"
# exit 1
#fi

# create backup location
mkdir -p $DIR

# create location to store output log
mkdir -p /var/log/xtrabackup

# run backup and push output to log file
#xtrabackup --backup --datadir=/var/lib/mysql/ --target-dir=$DIR 2> /var/log/xtrabackup/$NOW.log

innobackupex --user=backup --password=fVUSWGgG $DIR 2>> /var/log/xtrabackup-full.log

RETVAL=$?
if [ $RETVAL -ne 0 ]; then
    mail -s "Full Backup Failed on $HOST" NOTIFY <<< "Full Backup failed on $HOST please see /var/log/xtrabackup-full.log for more info"
fi

#########################################################

Some backups work ok but some fail most recent of which shows the following errors.

#########################################################

2017-04-07 12:11:02 7fe2b7881720 InnoDB: Operating system error number 112 in a file operation.
InnoDB: Error number 112 means 'Host is down'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
InnoDB: File /<email address hidden>/2017-04-07/2017-04-07_12-00-01/xtrabackup_suspended_2: 'stat' returned OS error 212.
2017-04-07 12:11:02 7fe2b7881720 InnoDB: Assertion failure in thread 140611718485792 in file xtrabackup.cc line 3085
InnoDB: Failing assertion: success
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
11:11:02 UTC - xtrabackup got signal 6 ;
This could be because you hit a bug or data is corrupted.
This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.

Thread pointer: 0x2112eb0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x10000
xtrabackup(my_print_stacktrace+0x35) [0x9f34fc]
xtrabackup(handle_fatal_signal+0x2bb) [0x7f6733]
/lib64/libpthread.so.0(+0xf710) [0x7fe2b7470710]
/lib64/libc.so.6(gsignal+0x35) [0x7fe2b5a8c625]
/lib64/libc.so.6(abort+0x175) [0x7fe2b5a8de05]
xtrabackup() [0x60a50f]
xtrabackup() [0x60b7bf]
xtrabackup(main+0x892) [0x611424]
/lib64/libc.so.6(__libc_start_main+0xfd) [0x7fe2b5a78d5d]
xtrabackup() [0x604269]

Please report a bug at https://bugs.launchpad.net/percona-xtrabackup
cp: closing `/<email address hidden>/2017-04-07/2017-04-07_12-00-01/company_dev/tblDealReferences.MYD': Input/output error
innobackupex: got a fatal error with the following stacktrace: at /usr/bin/innobackupex line 4884
        main::backup_file_via_copy('/var/lib/mysql/', 'company_dev/tblDealReferences.MYD', '/<email address hidden>/2017-04-07/2...') called at /usr/bin/innobackupex line 4906
        main::backup_file('/var/lib/mysql/', 'company_dev/tblDealReferences.MYD', '/<email address hidden>/2017-04-07/2...') called at /usr/bin/innobackupex line 4172
        main::backup_files(0) called at /usr/bin/innobackupex line 1987
        main::backup() called at /usr/bin/innobackupex line 1592
innobackupex: Error: Failed to copy file 'company_dev/tblDealReferences.MYD': 256 at /usr/bin/innobackupex line 4884.
170407 12:11:48 innobackupex: Waiting for ibbackup (pid=25755) to finish

#########################################################

There is plenty of space on the NAS, I'm not seeing any errors or other areas of concern re the hardware (these are virtualised servers in VMware).

Loooking at /usr/bin/innobackupex the lines its complaining about above are (I've included lines above and below as well as line numbers for context):

line 4884:

   4883 $ret = system("$CP_CMD \"$src_file_esc\" \"$dst_file_esc\"");
   4884 if ($ret != 0) {
   4885 die "Failed to copy file '$src_file': $ret";
   4886 }

line 4906:

   4903 if ($option_stream) {
   4904 backup_file_via_stream($src_path, $src_file);
   4905 } else {
   4906 backup_file_via_copy($src_path, $src_file, $dst_file);
   4907 }

line 4172:

   4171 } else {
   4172 backup_file("$source_dir", "$database/$file", "$backup_dir /$database/$file")
   4173 }

line 1987:

   1985 # backup non-InnoDB files and tables
   1986 # (or finalize the backup by syncing changes if using rsync)
   1987 backup_files(0);
   1988

line 1592:

   1590 } else {
   1591 # make a backup of InnoDB and MyISAM tables, indexes and .frm files.
   1592 $ibbackup_exit_code = backup();
   1593
   1594 mysql_close(\%mysql);

Could someone perhaps point me in the correct direction to diagnose this issue? Does it reside within MySQL itself or some sort of bug with the verion of xrtabackup we're running?

regards Tom

[Sergei Glushchenko (sergei.glushchenko)]

Both xtrabackup and innobackuped perl wrapper fail with IO error. It points to troubles with CIFS. xtrabackup reports OS error 112 'Host is down'. Maybe it is a good starting point to find out what the underlying issue is?

[Launchpad Janitor (janitor)]

[Expired for Percona XtraBackup because there has been no activity for 60 days.]

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXB-1438