Error while running innobackupex-1.5.1 --apply-log

369 views
Skip to first unread message

Pavel Shevaev

unread,
Feb 18, 2011, 3:18:14 AM2/18/11
to percona-d...@googlegroups.com
Hi,

In my previous mail I wrote about innobackupex stream error, so I
decided to backup my database using non-streamed method.
The first step works just fine(according to output logs). Then I
tarred the archive and sent it to the backup machine and tried to run
apply-log procedure on this machine.

And here is what I get:

# innobackupex-1.5.1 --apply-log 2011-02-17_02-40-48/
Version string '' contains invalid data; ignoring: '' at
/usr/bin/innobackupex-1.5.1 line 1719.

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 apply-log run completes successfully.
At the end of a successful apply-log run innobackupex-1.5.1
prints "completed OK!".

110218 11:00:20 innobackupex-1.5.1: Starting ibbackup with command:
xtrabackup --prepare
--target-dir=/home/pachanga/backup/2011-02-17_02-40-48

xtrabackup Ver 1.5 Rev 203 for 5.1.53 unknown-linux-gnu (x86_64)
xtrabackup: cd to /home/pachanga/backup/2011-02-17_02-40-48
xtrabackup: This target seems to be not prepared yet.
xtrabackup: xtrabackup_logfile detected: size=67977216, start_lsn=(280425881818)
xtrabackup: Temporary instance for recovery is set 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 = 1
xtrabackup: innodb_log_file_size = 67977216
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory
parameter)
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Compressed tables use zlib 1.2.3
InnoDB: Warning: innodb_file_io_threads is deprecated. Please use
innodb_read_io_threads and innodb_write_io_threads instead
110218 11:00:21 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 280425881818
110218 11:00:21 InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Doing recovery: scanned up to log sequence number 280431124480 (8 %)
InnoDB: Doing recovery: scanned up to log sequence number 280436367360 (17 %)
InnoDB: Doing recovery: scanned up to log sequence number 280441610240 (26 %)
InnoDB: Doing recovery: scanned up to log sequence number 280446853120 (34 %)
InnoDB: Doing recovery: scanned up to log sequence number 280452096000 (43 %)
InnoDB: Doing recovery: scanned up to log sequence number 280457338880 (52 %)
InnoDB: Doing recovery: scanned up to log sequence number 280462581760 (60 %)
InnoDB: Doing recovery: scanned up to log sequence number 280467824640 (69 %)
InnoDB: Doing recovery: scanned up to log sequence number 280473067520 (78 %)
110218 11:00:22 InnoDB: Starting an apply batch of log records to the
database...
InnoDB: Progress in percents: 110218 11:01:25 InnoDB: Assertion
failure in thread 47594875402000 in file log/log0recv.c line 1236
InnoDB: Failing assertion: !page || (ibool)!!page_is_comp(page) ==
dict_table_is_comp(index->table)
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.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
innobackupex-1.5.1: Error:
innobackupex-1.5.1: ibbackup failed at /usr/bin/innobackupex-1.5.1 line 542.

I'm using 1.5-203.lucid.3 version of xtrabackup installed from
official Percona deb. repositories. The Percona server 5.1.54-rel12.5
is installed both on master and backup boxes.

--
Best regards, Pavel

Pavel Shevaev

unread,
Feb 18, 2011, 5:42:03 PM2/18/11
to percona-d...@googlegroups.com
I'm replying to myself, I think I know what happened - there was an
error during the very _first_ stage of the backup process but I didn't
look too carefully into the log since it said OK in the end. Here is
the error:

[01] xtrabackup: Database page corruption detected at page 51790. retrying...
[01] xtrabackup: Database page corruption detected at page 51790. retrying...
[01] xtrabackup: Database page corruption detected at page 51790. retrying...
[01] xtrabackup: Database page corruption detected at page 51790. retrying...
[01] xtrabackup: Database page corruption detected at page 51790. retrying...
[01] xtrabackup: Database page corruption detected at page 51790. retrying...
[01] xtrabackup: Database page corruption detected at page 51790. retrying...
[01] xtrabackup: Database page corruption detected at page 51790. retrying...
[01] xtrabackup: Database page corruption detected at page 51790. retrying...
[01] xtrabackup: Error: 10 retries resulted in fail. Thisfile seems to
be corrupted.
[01] xtrabackup: Error: xtrabackup_copy_datafile() failed.
[01] xtrabackup: Warning: failed to copy, but continuing.

Looks like I need to fix this corruption somehow. What would be the
best way to achieve that?

--
Best regards, Pavel

Pavel Shevaev

unread,
Feb 20, 2011, 7:04:39 PM2/20/11
to percona-d...@googlegroups.com
I'm again replying to myself....Yep, I had an innodb corruption which
I could almost completely fix using this invaluable article
http://www.mysqlperformanceblog.com/2008/07/04/recovering-innodb-table-corruption

After fixing all errors backup process went just fine. What puzzling
me is the fact innobackupex doesn't stop even if there are
corruptions. What's the point of such a behavior? The resulting backup
is unusable anyway, right?


--
Best regards, Pavel

Alexey Kopytov

unread,
Feb 21, 2011, 1:33:26 AM2/21/11
to percona-d...@googlegroups.com, Pavel Shevaev
Hi Pavel,

Thanks for investigating the problem and posting the results here.

I noticed and fixed this problem while working on another bug. For some
obscure reasons, the xtrabackup binary considered corruption in
non-system tablespaces as non-fatal and would happily continue the
backup process after printing the warning which you saw in the logs.

Anyway, the fix for that issue is now in the XtraBackup trunk, and hence
will be available in the next release.

Best regards,
Alexey.

Baron Schwartz

unread,
Feb 21, 2011, 4:18:13 AM2/21/11
to percona-d...@googlegroups.com
Hi,

On Mon, Feb 21 at 9:33 Alexey Kopytov wrote:
> I noticed and fixed this problem while working on another bug. For some
> obscure reasons, the xtrabackup binary considered corruption in
> non-system tablespaces as non-fatal and would happily continue the
> backup process after printing the warning which you saw in the logs.

I wonder if that was related to the Percona Server feature to warn, but
not crash, when a table is corrupted.

Reply all
Reply to author
Forward
0 new messages