MySQL applying second incremental backup causes LSN in the ibdata files to be higher than LSN in the ib_logfiles

Question

Using the backup procedure described below, it gives warnings. These warnings start to appear from the 2nd till 6th (last) incremental backup that is being applied to the base backup.

How to solve this in the procedure?

Warning messages from innobackupex

InnoDB: The log sequence number in the ibdata files is higher than the log sequence number in the ib_logfiles! Are you sure you are using the right ib_logfiles to start up the database. Log sequence number in the ib_logfiles is 12881010402316, logsequence numbers stamped to ibdata file headers are between 12908127655307 and 12908127655307.
InnoDB: The log sequence numbers 12908127655307 and 12908127655307 in ibdata files do not match the log sequence number 12881010402316 in the ib_logfiles!
InnoDB: Database was not shutdown normally!
InnoDB: Starting crash recovery.

And a lot of these:

2016-05-31 04:28:16 7f00d9ec5780 InnoDB: Error: page 7 log sequence number 12908127624790
InnoDB: is in the future! Current system log sequence number 12881010402316.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.

It ends with:

xtrabackup: ########################################################
xtrabackup: # !!WARNING!!                                          #
xtrabackup: # The transaction log file is corrupted.               #
xtrabackup: # The log was not applied to the intended LSN!         #
xtrabackup: ########################################################

Procedure to create backups

• On Sunday, create a base backup

innobackupex --stream=xbstream /var/lib/mysql | nc $backup_server $port

• Monday-Saturday, daily create incremental backup based on last LSN from previous backup

innobackupex --stream=xbstream --incremental --incremental-lsn=$last_lsn /var/lib/mysql | nc $backup_server $port

Procedure to import backups

Import the base backup on Sunday to the standby environment:

• Copy the base backup from the backup server to /var/backups/base-<date> (leaving it untouched)
• Stop MySQL service
• Copy /var/backups/base-<date> stage to /var/lib/mysql
• Prepare the backup in /var/lib/mysql

sudo -u mysql innobackupex --ibbackup=/usr/bin/xtrabackup --apply-log /var/lib/mysql

• Start MySQL service

Import the incremental backups from Monday-Saturday to the standby environment:

• Copy the incremental backup from the backup server to /var/backups/incr-<date>
• Prepare the base backup to apply the incremental on it

innobackupex --apply-log --defaults-file=/root/.my.cnf --ibbackup=/usr/bin/xtrabackup --redo-only /var/backups/base-<date>

• Apply incremental on base backup

innobackupex --apply-log --defaults-file=/root/.my.cnf --ibbackup=/usr/bin/xtrabackup --redo-only /var/backups/base-<date> --incremental-dir=/var/backups/incr-date

• Stop MySQL service
• Copy /var/backups/base-<date> stage to /var/lib/mysql
• Prepare the backup in /var/lib/mysql (not in the stage dir!)

sudo -u mysql innobackupex --ibbackup=/usr/bin/xtrabackup --apply-log /var/lib/mysql

• Start MySQL service

Answer 1

When I see messages of that nature, I usually blame the redo logs. This is where is LSN is written.

The problem may stem from not preparing the incremental backup.

What seems to be missing is the use of the --prepare option.

What this essentially does is create the backup rolled forward to a specific point in time. This is particularly true if there were transactions occurring during the backup.

It's kind of like the opposite of a mysqldump --single-transaction, which makes a logical dump based on the start time of the backup. Doing a --prepare with xtrabackup will make the redo logs roll forward to match the end time of the backup.

Note what the opening paragraph of Preparing the backup from the XtraBackup Docs says:

After you make a backup with --backup, the next step is to prepare it. The data files are not point-in-time consistent until they’ve been prepared, because they were copied at different times as the program ran, and they might have been changed while this was happening. If you try to start InnoDB with these data files, it will detect corruption and crash itself to prevent you from running on damaged data. The --prepare step makes the files perfectly consistent at a single instant in time, so you can run InnoDB on them.

This should coalesce the LSN of the incremental after making the incremental.

For more information, please read Preparing the backup from the XtraBackup Docs