Incremental Backup/Restore with Xtrabackup

[Keith Murphy]

First off, Xtrabackup is a great tool. Thanks for the work on it!

I can perform full backup/restore without any problems. However, when
trying to run a restore of an incremental backup it fails. I have
tried a dozen or more times, and searched high and low for what I
could be doing wrong. I believe I know what is wrong but don't know
how to do it correctly.

Here is an outline:

To test, I loaded the sakila database and then perform a full backup.
As I said, I can restore this without any problem. Statements run
(under the mysql user) to do this:

<to backup>

$ xtrabackup --backup --target-dir=/backups/full_backups/

I end up with the backup in /backups/full_backups. So far so good. To
restore the backup I just do this:


$ xtrabackup --prepare --target-dir=/backups/full_backups

Once this is run twice I end up with the equivalent of the data
directory which I can then copy to my data directory and start up
mysql.

So far so good.

Now to create an incremental backup, I begin by loading the employees
test database so that there is some differences. Once this is done I
run the incremental backup:

$ xtrabackup --backup --target-dir=/backups/incremenatal_backup_one --
incremental-basedir=/backups/full_backups

As you can see i specify the previous full backup as the basedir and /
backups/incremental_backup_one as where the incremental backup is to
be placed. This appears to run correctly:

-bash-3.2$ xtrabackup --backup --target-dir=/backups/
incremenatal_backup_one --incremental-basedir=/backups/full_backups
xtrabackup Ver rc-0.7 for 5.0.83 unknown-linux-gnu (x86_64)
incremental backup from 0:372733003 is enabled.
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql
xtrabackup: Target instance is assumed as followings.
xtrabackup: innodb_data_home_dir = /var/lib/mysql/
xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup: innodb_log_group_home_dir = /var/lib/mysql/
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 67108864
>> log scanned up to (0 738789408)
Copying /var/lib/mysql/ibdata1
to /backups/incremenatal_backup_one/ibdata1.delta
...done
Copying ./sakila/payment.ibd
to /backups/incremenatal_backup_one/sakila/payment.ibd.delta
...done
Copying ./sakila/language.ibd
to /backups/incremenatal_backup_one/sakila/language.ibd.delta
...done
Copying ./sakila/actor.ibd
to /backups/incremenatal_backup_one/sakila/actor.ibd.delta
...done
Copying ./sakila/inventory.ibd
to /backups/incremenatal_backup_one/sakila/inventory.ibd.delta
...done
Copying ./sakila/address.ibd
to /backups/incremenatal_backup_one/sakila/address.ibd.delta
...done
Copying ./sakila/rental.ibd
to /backups/incremenatal_backup_one/sakila/rental.ibd.delta
...done
Copying ./sakila/film_category.ibd
to /backups/incremenatal_backup_one/sakila/
film_category.ibd.delta
...done
Copying ./sakila/category.ibd
to /backups/incremenatal_backup_one/sakila/category.ibd.delta
...done
Copying ./sakila/country.ibd
to /backups/incremenatal_backup_one/sakila/country.ibd.delta
...done
Copying ./sakila/city.ibd
to /backups/incremenatal_backup_one/sakila/city.ibd.delta
...done
Copying ./sakila/film.ibd
to /backups/incremenatal_backup_one/sakila/film.ibd.delta
...done
Copying ./sakila/store.ibd
to /backups/incremenatal_backup_one/sakila/store.ibd.delta
...done
Copying ./sakila/customer.ibd
to /backups/incremenatal_backup_one/sakila/customer.ibd.delta
...done
Copying ./sakila/staff.ibd
to /backups/incremenatal_backup_one/sakila/staff.ibd.delta
...done
Copying ./sakila/film_actor.ibd
to /backups/incremenatal_backup_one/sakila/film_actor.ibd.delta
...done
Copying ./employees/titles.ibd
to /backups/incremenatal_backup_one/employees/titles.ibd.delta
...done
Copying ./employees/dept_manager.ibd
to /backups/incremenatal_backup_one/employees/
dept_manager.ibd.delta
...done
Copying ./employees/departments.ibd
to /backups/incremenatal_backup_one/employees/
departments.ibd.delta
...done
Copying ./employees/dept_emp.ibd
to /backups/incremenatal_backup_one/employees/dept_emp.ibd.delta
...done
Copying ./employees/employees.ibd
to /backups/incremenatal_backup_one/employees/employees.ibd.delta
>> log scanned up to (0 738789408)
...done
Copying ./employees/salaries.ibd
to /backups/incremenatal_backup_one/employees/salaries.ibd.delta
>> log scanned up to (0 738789408)
...done
xtrabackup: The latest check point (for incremental): '0:738789408'
>> log scanned up to (0 738789408)
xtrabackup: Stopping log copying thread.
xtrabackup: Transaction log of lsn (0 738789408) to (0 738789408) was
copied.
-bash-3.2$


The only thing that is even slightly out of whack here is that it
shows version 0.7 instead of 0.8. I compiled from source and I am
making the assumption that this is just a glitch.

Now the problem occurs when I prepare this incremental backup:

-bash-3.2$ xtrabackup --prepare --target-dir=/backups/full_backups --
incremental-dir=/backups/incremenatal_backup_one
xtrabackup Ver rc-0.7 for 5.0.83 unknown-linux-gnu (x86_64)
incremental backup from 0:372733003 is enabled.
xtrabackup: cd to /backups/full_backups
xtrabackup: This target seems to be already prepared.
xtrabackup: xtrabackup_logfile detected: size=2097152, start_lsn=(0
738789408)
Applying /backups/incremenatal_backup_one/ibdata1.delta ...
Applying /backups/incremenatal_backup_one/sakila/staff.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/
film_category.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/
customer.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/country.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/payment.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/film.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/
category.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/actor.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/address.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/rental.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/city.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/
inventory.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/
film_actor.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/store.ibd.delta ...
Applying /backups/incremenatal_backup_one/sakila/
language.ibd.delta ...
090713 13:33:24 InnoDB: Operating system error number 2 in a file
operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: error: cannot open /backups/full_backups/employees/
titles.ibd
xtrabackup: Error: xtrabackup_apply_delta() failed.
090713 13:33:24 InnoDB: Operating system error number 2 in a file
operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: error: cannot open /backups/full_backups/employees/
salaries.ibd
xtrabackup: Error: xtrabackup_apply_delta() failed.
090713 13:33:24 InnoDB: Operating system error number 2 in a file
operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: error: cannot open /backups/full_backups/employees/
employees.ibd
xtrabackup: Error: xtrabackup_apply_delta() failed.
090713 13:33:24 InnoDB: Operating system error number 2 in a file
operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: error: cannot open /backups/full_backups/employees/
dept_manager.ibd
xtrabackup: Error: xtrabackup_apply_delta() failed.
090713 13:33:24 InnoDB: Operating system error number 2 in a file
operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: error: cannot open /backups/full_backups/employees/
departments.ibd
xtrabackup: Error: xtrabackup_apply_delta() failed.
090713 13:33:24 InnoDB: Operating system error number 2 in a file
operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: error: cannot open /backups/full_backups/employees/
dept_emp.ibd
xtrabackup: Error: xtrabackup_apply_delta() failed.
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 = /backups/
incremenatal_backup_one
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 2097152
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory
parameter)
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
090713 13:33:25 InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
090713 13:33:25 InnoDB: Error: table 'employees/departments'
InnoDB: in InnoDB data dictionary has tablespace id 23,
InnoDB: but tablespace with that id or name does not exist. Have
InnoDB: you deleted or moved .ibd files?
InnoDB: This may also be a table created with CREATE TEMPORARY TABLE
InnoDB: whose .ibd and .frm files MySQL automatically removed, but the
InnoDB: table still exists in the InnoDB internal data dictionary.
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/innodb-troubleshooting.html
InnoDB: for how to resolve the issue.
090713 13:33:25 InnoDB: Error: table 'employees/dept_emp'
InnoDB: in InnoDB data dictionary has tablespace id 25,
InnoDB: but tablespace with that id or name does not exist. Have
InnoDB: you deleted or moved .ibd files?
InnoDB: This may also be a table created with CREATE TEMPORARY TABLE
InnoDB: whose .ibd and .frm files MySQL automatically removed, but the
InnoDB: table still exists in the InnoDB internal data dictionary.
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/innodb-troubleshooting.html
InnoDB: for how to resolve the issue.
090713 13:33:25 InnoDB: Error: table 'employees/dept_manager'
InnoDB: in InnoDB data dictionary has tablespace id 24,
InnoDB: but tablespace with that id or name does not exist. Have
InnoDB: you deleted or moved .ibd files?
InnoDB: This may also be a table created with CREATE TEMPORARY TABLE
InnoDB: whose .ibd and .frm files MySQL automatically removed, but the
InnoDB: table still exists in the InnoDB internal data dictionary.
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/innodb-troubleshooting.html
InnoDB: for how to resolve the issue.
090713 13:33:25 InnoDB: Error: table 'employees/employees'
InnoDB: in InnoDB data dictionary has tablespace id 22,
InnoDB: but tablespace with that id or name does not exist. Have
InnoDB: you deleted or moved .ibd files?
InnoDB: This may also be a table created with CREATE TEMPORARY TABLE
InnoDB: whose .ibd and .frm files MySQL automatically removed, but the
InnoDB: table still exists in the InnoDB internal data dictionary.
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/innodb-troubleshooting.html
InnoDB: for how to resolve the issue.
090713 13:33:25 InnoDB: Error: table 'employees/salaries'
InnoDB: in InnoDB data dictionary has tablespace id 27,
InnoDB: but tablespace with that id or name does not exist. Have
InnoDB: you deleted or moved .ibd files?
InnoDB: This may also be a table created with CREATE TEMPORARY TABLE
InnoDB: whose .ibd and .frm files MySQL automatically removed, but the
InnoDB: table still exists in the InnoDB internal data dictionary.
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/innodb-troubleshooting.html
InnoDB: for how to resolve the issue.
090713 13:33:25 InnoDB: Error: table 'employees/titles'
InnoDB: in InnoDB data dictionary has tablespace id 26,
InnoDB: but tablespace with that id or name does not exist. Have
InnoDB: you deleted or moved .ibd files?
InnoDB: This may also be a table created with CREATE TEMPORARY TABLE
InnoDB: whose .ibd and .frm files MySQL automatically removed, but the
InnoDB: table still exists in the InnoDB internal data dictionary.
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/innodb-troubleshooting.html
InnoDB: for how to resolve the issue.
InnoDB: Last MySQL binlog file position 0 340049538, file name ./mysql-
bin.000003
090713 13:33:25 InnoDB: Started; log sequence number 0 738789408

[notice (again)]
If you use binary log and don't use any hack of group commit,
the binary log position seems to be:
InnoDB: Last MySQL binlog file position 0 340049538, file name ./mysql-
bin.000003

xtrabackup: starting shutdown with innodb_fast_shutdown = 1
090713 13:33:25 InnoDB: Starting shutdown...
090713 13:33:26 InnoDB: Shutdown completed; log sequence number 0
738789408

So any ideas on what is going on?

From the error messages it seems that the incremental restore is
stopping because it doesn't see the "structure" of the employee
database in the full backup. Well, it wouldn't see it because it isn't
there. The employee database was loaded after the full backup was
taking..it essentially was what changed between the two backups. So of
course it isn't going on find it.

Any suggestions are greatly appreciated.

[Yasufumi Kinoshita]

Keith,

Thank you for reporting bug.
I have registered it as bug.
https://bugs.launchpad.net/percona-xtrabackup/+bug/400490

Yes... XtraBackup should create new dirs/files when not found.

Thank you, again.

Yasufumi