xtrabackup fail in stream mode - The file 'ibdata1' may not be InnoDB datafile or may be corrupted.

[Andrew Sitnikov]

Fresh db (Percona-Server-server-51-5.1.47-rel11.2.53)
mysqldump , remove ib* file deleted, mysql restore from mysqldump.

After this i run xtrabackup in streaming mode

innobackupex: Using mysql Ver 14.14 Distrib 5.1.47, for unknown-linux-gnu (x86_64) using readline 5.1
innobackupex: Using mysql server version Copyright (c) 2000, 2010, Oracle and/or its affiliates. All rights reserved.

innobackupex: Created backup directory /tmp
100828 18:28:03 innobackupex: Starting mysql with options: --password=***** --user=root --unbuffered --
100828 18:28:03 innobackupex: Connected to database with mysql child process (pid=23969)
100828 18:28:11 innobackupex: Connection to database server closed
100828 18:28:11 innobackupex: Starting mysql with options: --password=***** --user=root --unbuffered --
100828 18:28:11 innobackupex: Connected to database with mysql child process (pid=23982)
100828 18:28:15 innobackupex: Connection to database server closed

100828 18:28:15 innobackupex: Starting ibbackup with command: xtrabackup --backup --suspend-at-end --log-stream --target-dir=./ --throttle=50
innobackupex: Waiting for ibbackup (pid=23988) to suspend
innobackupex: 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:300M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 268435456
xtrabackup: Stream mode.

100828 18:28:17 innobackupex: Continuing after ibbackup has suspended

innobackupex: Starting to backup InnoDB tables and indexes
innobackupex: from original InnoDB data directory '/var/lib/mysql'
innobackupex: 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: tar returned with exit code 255.
innobackupex: Error: Failed to stream 'ibdata1': at /usr/bin/innobackupex line 480.

[Andrew Sitnikov (sitnikov-gmail)]

After some talking with Peter Zaitsev we found that in nonstream mode backup work properly, but with these message

xtrabackup: innodb_log_file_size = 1073741824
>> log scanned up to (258630780823)
Copying ./ibdata1
     to /home/backup/2010-11-06_21-14-07/ibdata1
xtrabackup: Page 64 seems double write buffer. passing the check.
xtrabackup: Page 65 seems double write buffer. passing the check.
...
xtrabackup: Page 191 seems double write buffer. passing the check.
>> log scanned up to (258630816455)

in stream mode tar4ibd stop read data file after 67 x 16K read,

strace
...
read(3, "1C\341\300\0\0\0>\0\0\7\0\0\0\4\36\0\0\0;C+\362/E\277\0\0\0\0\0\0"..., 16384) = 16384
write(1, "1C\341\300\0\0\0>\0\0\7\0\0\0\4\36\0\0\0;C+\362/E\277\0\0\0\0\0\0"..., 512) = 512
....

write(1, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 512) = 512
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
lseek(3, -16384, SEEK_CUR) = 1048576
read(3, "'\361\375W\0\f\0\1\0\0\0\0\0\0\0\0\0\0\0<\\\226\204\326\0\5\0\0\0\0\0\0"..., 16384) = 16384
write(2, "The file 'ibdata1' may not be In"..., 67) = 67
write(2, "tar_append_tree(\"ibdata1\", \"ibda"..., 58) = 58

[Peter Zaitsev (pz-percona)]

Hi,

Is it possible the warning printout is done in the wrong channel so it screws up the tar or there is another check out there ?

What is really interesting why does it complains on double write buffers in this case but not in other cases

[Lee Faris (leelynnef)]

Running xtrabackup on mysql 5.1.40 I get this error only when using innodb_file_per_table otherwise tar4ibd has no problem with ibdata1.

[Valentine Gostev (longbow)]

Andrew,

have tried reproducing the issue w/ XtraBackup 1.5 and Percona Server 5.1.54-12.5 in scenario you have described

~# innobackupex-1.5.1 --stream=tar /backup > /backup/out.tar

After that I was able to restore backup, and data was consistent.

Could you please specify the command you have issued to create streaming backup?
Can you post the mysqld part of config here?
Are you able to reproduce it only some particulat server or at several boxes?

[Valentine Gostev (longbow)]

works for me

[Andrew Sitnikov (sitnikov-gmail)]

xtrabackup Ver 1.5 Rev 203 for 5.1.53 unknown-linux-gnu (x86_64)

Percona-Server-server-51-5.1.54-rel12.5.188.rhel5

110222 17:09:45 InnoDB: Warning: allocated tablespace 33045, old maximum was 9
xtrabackup: Stream mode.
>> log scanned up to (714428260132)

110222 17:09:46 innobackupex: Continuing after ibbackup has suspended

innobackupex: Starting to backup InnoDB tables and indexes
innobackupex: from original InnoDB data directory '/var/lib/mysql'
innobackupex: 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: tar returned with exit code 255.
innobackupex: Error: Failed to stream '/var/lib/mysql/ibdata1': at /usr/bin/innobackupex line 542.

[Henrik Ingo (hingo)]

Isn't this a duplicate of:
https://bugs.launchpad.net/percona-xtrabackup/+bug/665210

Andrew, can you confirm you are using innodb row_format=compressed?

[Andrew Sitnikov (sitnikov-gmail)]

Yes, i use row_format=compressed

[Andrew Sitnikov (sitnikov-gmail)]

[root@murr sbin]# xtrabackup --help
xtrabackup Ver 1.6 Rev 245 for 5.1.55 unknown-linux-gnu (x86_64)

...

110412 22:36:14 innobackupex: Continuing after ibbackup has suspended

innobackupex: Starting to backup InnoDB tables and indexes
innobackupex: from original InnoDB data directory '/var/lib/mysql'
innobackupex: 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: tar returned with exit code 255.
innobackupex: Error: Failed to stream '/var/lib/mysql/ibdata1': at /usr/bin/innobackupex line 336.