stream backup error with innobackupex-1.5.1

[tianma]

MySQL version : MySQL-5.1.45+XtraDB 1.0.6-10
Xtrabackup Version : XtraBackup-1.2（2010-4-12）

blog-bak@fs-28:~/wangwei/xtrabackup$ innobackupex-1.5.1 --defaults-file=/home/blog-bak/wangwei/db-36-2.cnf --user=root --password=tianma --stream=tar . |gzip - > /home/blog-bak/wangwei/xtrabackup-bak/db-36-2.tar.gz

Version string '' contains invalid data; ignoring: '' at /usr/bin/innobackupex-1.5.1 line 1636.

InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy.
All Rights Reserved.

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

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

innobackupex-1.5.1: Using mysql Ver 14.12 Distrib 5.0.38, for pc-linux-gnu (x86_64) using readline 5.2
VT102innobackupex-1.5.1: Using mysql server version Copyright (C) 2002 MySQL AB

innobackupex-1.5.1: Created backup directory /mnt/disk16/db-36-2
100506 16:13:56 innobackupex-1.5.1: Starting mysql with options: --defaults-file="/home/blog-bak/wangwei/db-36-2.cnf" --password=tianma --user=root --unbuffered --
100506 16:13:56 innobackupex-1.5.1: Connected to database with mysql child process (pid=28211)
VT102100506 16:14:00 innobackupex-1.5.1: Connection to database server closed

100506 16:14:00 innobackupex-1.5.1: Starting ibbackup with command: xtrabackup --defaults-file="/home/blog-bak/wangwei/db-36-2.cnf" --backup --suspend-at-end --log-stream --target-dir=./
innobackupex-1.5.1: Waiting for ibbackup (pid=28218) to suspend
innobackupex-1.5.1: Suspend file '/home/blog-bak/wangwei/xtrabackup/xtrabackup_suspended'

xtrabackup: suspend-at-end is enabled.
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /home/blog-bak/wangwei/xtrabackup
xtrabackup: Target instance is assumed as followings.
xtrabackup: innodb_data_home_dir = /home/blog-bak/wangwei/xtrabackup
xtrabackup: innodb_data_file_path = ibdata1:512M:autoextend
xtrabackup: innodb_log_group_home_dir = /home/blog-bak/wangwei/xtrabackup
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 536870912
xtrabackup: use O_DIRECT
xtrabackup: Stream mode.
>> log scanned up to (95031262927)

100506 16:14:02 innobackupex-1.5.1: Continuing after ibbackup has suspended

innobackupex-1.5.1: Starting to backup InnoDB tables and indexes
innobackupex-1.5.1: from original InnoDB data directory '/home/blog-bak/wangwei/xtrabackup'
innobackupex-1.5.1: Backing up as tar stream 'ibdata1'
The file 'ibdata1' may not be InnoDB datafile or may be corrupted.
tar_append_tree("ibdata1", "ibdata1"): Input/output error
innobackupex-1.5.1: tar returned with exit code 255.
innobackupex-1.5.1: Error: Failed to stream 'ibdata1': at /usr/bin/innobackupex-1.5.1 line 479.

MySQL :

mysql> show databases ;
+--------------------+
| Database |
+--------------------+
| information_schema |
| mysql |
| space |
+--------------------+
3 rows in set (0.00 sec)

mysql> use space ;
Database changed
mysql> show create table stest ;
+-------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table | Create Table |
+-------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| stest | CREATE TABLE `stest` (
  `id` int(10) unsigned NOT NULL,
  `k` int(10) unsigned NOT NULL DEFAULT '0',
  `c` char(120) NOT NULL DEFAULT '',
  `pad` char(60) NOT NULL DEFAULT '',
  PRIMARY KEY (`id`),
  KEY `k` (`k`)
) ENGINE=InnoDB DEFAULT CHARSET=gbk |
+-------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)

[Lee Faris (leelynnef)]

Is the cause of this bug known? And is there any work around available in 1.2?

[Daniel Harvey (daniel.harvey)]

With reference to the lines below from the output shown above:

xtrabackup: cd to /home/blog-bak/wangwei/xtrabackup
xtrabackup: Target instance is assumed as followings.
xtrabackup: innodb_data_home_dir = /home/blog-bak/wangwei/xtrabackup

Isn't this supposed to be the MySQL server's data dir that contains the Inno files?
e.g. ibdata1 etc...

This sounds like a configuration issue when calling innobackupex-1.5.1.

[Daniel Harvey (daniel.harvey)]

There is however a problem with the placement by the script of xtrabackup_suspended file in the streaming case.

When I call

innobackupex-1.5.1 --stream=tar --defaults-file=/home/xxx/.my.cnf ./ | gzip > 20100728.tgz

this file is placed in /var/lib/mysql/xtrabackup_suspended which my non-root user does not have write access to. I will attached my suggested patch fixing this.

Note that the my.cnf file does not overwrite the default MySQL datadir.

Sample output illustrating this:

<snip/>
innobackupex-1.5.1: Using mysql Ver 14.12 Distrib 5.0.75, for debian-linux-gnu (x86_64) using readline 5.2
innobackupex-1.5.1: Using mysql server version Copyright (C) 2000-2008 MySQL AB

innobackupex-1.5.1: Created backup directory /home/xxx/backup/mysql/current
100728 12:46:51 innobackupex-1.5.1: Starting mysql with options: --defaults-file="/home/xxx/.my.cnf" --unbuffered --
100728 12:46:51 innobackupex-1.5.1: Connected to database with mysql child process (pid=4522)
100728 12:46:59 innobackupex-1.5.1: Connection to database server closed
100728 12:46:59 innobackupex-1.5.1: Starting mysql with options: --defaults-file="/home/xxx/.my.cnf" --unbuffered --
100728 12:46:59 innobackupex-1.5.1: Connected to database with mysql child process (pid=4726)
100728 12:47:03 innobackupex-1.5.1: Connection to database server closed

100728 12:47:03 innobackupex-1.5.1: Starting ibbackup with command: xtrabackup_50 --defaults-file="/home/xxx/.my.cnf" --backup --suspend-at-end --log-stream --target-dir=./
innobackupex-1.5.1: Waiting for ibbackup (pid=4830) to suspend
innobackupex-1.5.1: Suspend file '/var/lib/mysql/xtrabackup_suspended'

xtrabackup: suspend-at-end is enabled.
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql
xtrabackup: Target instance is assumed as followings.
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 = 5242880
xtrabackup: Stream mode.
>> log scanned up to (0 95790)
100728 12:47:03 InnoDB: Operating system error number 13 in a file operation.
InnoDB: The error means mysqld does not have the access rights to
InnoDB: the directory.
InnoDB: File name .//xtrabackup_suspended
InnoDB: File operation call: 'open'.
xtrabackup: Error: failed to create file 'xtrabackup_suspended'
xtrabackup: The latest check point (for incremental): '0:95790'
xtrabackup: Error: cannot open .//xtrabackup_checkpoints
xtrabackup: error: xtrabackup_write_metadata()
>> log scanned up to (0 95790)
xtrabackup: Transaction log of lsn (0 95790) to (0 95790) was copied.
innobackupex-1.5.1: Error: ibbackup child process has died at /usr/bin/innobackupex-1.5.1 line 480.

[Daniel Harvey (daniel.harvey)]

Patch fixing the location of the xtrabackup_suspended and xtrabackup_checkpoints files.

[Alexey Kopytov (akopytov)]

Some clarifications on this bug report:

- the original report is not a bug per se, it's a result of misconfiguration ("/home/blog-bak/wangwei/xtrabackup" was mistakenly specified as datadir in my.cnf).

- the problem described by Daniel Harvey is a separate issue, so I reported it as a separate bug #691090.

- the only problem that should be fixed with respect to this report is the nonsensical error message from tar4ibd. It should give a more reasonable error message when the input file cannot be opened, rather than complain about it being "non-InnoDB" or "correpted".

[Alexey Kopytov (akopytov)]

After more looking at the libtar code and tar4ibd_libtar-1.2.11.patch, I think that we should have a proper error message when the input data file is missing.

Actually, I can't even repeat this bug, When datadir or innodb_data_home_dir point to a wrong directory, ibdata1 is recreated by the xtrabackup binary, then innobackupex-1.5.1 fails in a different way before invoking tar4ibd.

If I create an empty ibdata1 file, xtrabackup fails with the "Could not open or create data files" message, so innobackupex fails too, again before invoking tar4ibd.

This could be a result of a corrupted ibdata1 file, but then the failure and the error message are correct.

Can I have more info about the setup and steps required to repeat this bug?

[Stewart Smith (stewart)]

Marking as Invalid due to no feedback for several months and unable to reproduce.

[Shahriyar Rzayev (rzayev-sehriyar)]

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