If multiple data files and innodb_data_file_path is used but not explicitly set on prepare, can hit assertion in --prepare

Dreas van Donselaar reported a similar bug on 2010-10-16. But it was cancelled as it's not a repeatable case.
https://bugs.launchpad.net/percona-server/+bug/661828

When we're using Xtrabackup, we ran into the same bug. According to the GDB output, the problem happened in function call trx_undo_mem_create_at_db_start. I guess it's related with the undo tablespace in ibdata1.

Can you please verify that "innodb_data_file_path = ibdata1:10M:autoextend" reported by xtrabackup matches your InnoDB configuration?

Oh, there must be some bug for xtrabackup_55, it failed to get the correct value from my.cnf. However, it's not the root cause of the problem. The same backup script is running fine after we recreated the database.

If you run xtrabackup_55 twice with parameter "--prepare", they will start with different set of parameters. (Only the 2nd pass will use the correct value for innodb_log_files_in_group and innodb_log_file_size).

For example, in our case:
The first pass:
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 = 24969216

The second pass:
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 = 1572864000

That's expected behavior. On the first pass XtraBackup wants to replay the backup log, so it modifies log files configuration to match xtrabackup_logfile parameters. The second pass is used to pre-create InnoDB log files, so it uses real values read from configuration file.

So I'm not sure what specific problem we are chasing here. You mentioned that xtrabackup failed to get the correct innodb_data_file_path value from my.cnf. So does the crash occur with xtrabackup is doing recovery with a wrong value?

Can you paste the output of "xtrabackup_55 --print-param"? Does specifying --innodb-data-file-path explictly on the xtrabackup command line solve the problem?

Hi Alexey,

Actually, there were two seperate problems.
1. xtrabackup cannot read the parameter values from my.cnf correcty for
either pass while preparing. By providing the parameter value on the
command line, the problem can be workaround. However, not all parameters
are supported by the command line.
2. In our case, there was something corrupted in ibdata1. According to our
test, the datafile corrupted before the backup was taken. (The source
database failed to be started after a clean shutdown.) In order to fix the
problem, we had to dump all data and rebuilt the whole database. After
that, xtrabackup works as expected.

Best wishes,
Bob Gu

2011/10/21 Alexey Kopytov <email address hidden>

> That's expected behavior. On the first pass XtraBackup wants to replay
> the backup log, so it modifies log files configuration to match
> xtrabackup_logfile parameters. The second pass is used to pre-create
> InnoDB log files, so it uses real values read from configuration file.
>
> So I'm not sure what specific problem we are chasing here. You mentioned
> that xtrabackup failed to get the correct innodb_data_file_path value
> from my.cnf. So does the crash occur with xtrabackup is doing recovery
> with a wrong value?
>
> Can you paste the output of "xtrabackup_55 --print-param"? Does
> specifying --innodb-data-file-path explictly on the xtrabackup command
> line solve the problem?
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/839306
>
> Title:
> Failing assertion: addr.page == FIL_NULL || addr.boffset >=
> FIL_PAGE_DATA
>
> Status in Percona XtraBackup:
> Incomplete
>
> Bug description:
> When runing the prepare command line, it will ran into a "Failing
> assertion".
> $ ~/local/bin/xtrabackup_55 --prepare --target-dir=`pwd` --tmpdir=/tmp
> /export/home/mysql/local/bin/xtrabackup_55 Ver 1.6 Rev undefined for
> 5.5.9 Linux (x86_64)
> xtrabackup: cd to /data/backup/full/2011-09-01_06-27-55
> xtrabackup: This target seems to be not prepared yet.
> 110901 22:58:41 InnoDB: Operating system error number 2 in a file
> operation.
> InnoDB: The error means the system cannot find the path specified.
> xtrabackup: Warning: cannot open ./xtrabackup_logfile. will try to find.
> xtrabackup: 'ib_logfile0' seems to be 'xtrabackup_logfile'. will retry.
> xtrabackup: xtrabackup_logfile detected: size=6089359360,
> start_lsn=(1336207695220)
> 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 = 6089359360
> 110901 22:58:42 InnoDB: Using Linux native AIO
> xtrabackup: Starting InnoDB instance for recovery.
> xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory
> parameter)
> 110901 22:58:42 InnoDB: The InnoDB memory heap is disabled
> 110901 22:58:42 InnoDB: Mutexes and rw_locks use GCC atomic builtins
> 110901 22:58:42 InnoDB: Compressed tables use zlib 1.2.3
> 110901 22:58:42 InnoD...

Hi Bob,

Thanks for clarifications. So the actual problem was that xtrabackup was using an incorrect InnoDB data files configuration.

When innobackupex is used to create backups, the server's innodb_data_file_path value is written to backup-my.cnf, but that file is not automatically used at prepare, it has to be specified explicitly via --defaults-file. And when innobackupex is not used, we simply don't have any information about data files configuration at prepare. Which causes problems like the one in this bug when there are multiple data files configured with innodb_data_file_path.

There is a blueprint targeting this specific problem: https://blueprints.launchpad.net/percona-xtrabackup/+spec/backup-config-in-xtrabackup

Until that BP is implemented, the workaround is to either use --defaults-file=backup-my.cnf (if that file is available), or specify innodb_data_file_path on the xtrabackup command line explicitly (when backup was taken without innobackupex) using the same value as it was on the server where the backup was taken.

Hi Alexey,

Thank you for the update.

Best wishes,
Bob Gu

2011/11/25 Alexey Kopytov <email address hidden>

> Hi Bob,
>
> Thanks for clarifications. So the actual problem was that xtrabackup was
> using an incorrect InnoDB data files configuration.
>
> When innobackupex is used to create backups, the server's
> innodb_data_file_path value is written to backup-my.cnf, but that file
> is not automatically used at prepare, it has to be specified explicitly
> via --defaults-file. And when innobackupex is not used, we simply don't
> have any information about data files configuration at prepare. Which
> causes problems like the one in this bug when there are multiple data
> files configured with innodb_data_file_path.
>
> There is a blueprint targeting this specific problem:
> https://blueprints.launchpad.net/percona-xtrabackup/+spec/backup-config-
> in-xtrabackup
>
> Until that BP is implemented, the workaround is to either use
> --defaults-file=backup-my.cnf (if that file is available), or specify
> innodb_data_file_path on the xtrabackup command line explicitly (when
> backup was taken without innobackupex) using the same value as it was on
> the server where the backup was taken.
>
> ** Changed in: percona-xtrabackup
> Status: Incomplete => Confirmed
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/839306
>
> Title:
> Failing assertion: addr.page == FIL_NULL || addr.boffset >=
> FIL_PAGE_DATA
>
> Status in Percona XtraBackup:
> Confirmed
>
> Bug description:
> When runing the prepare command line, it will ran into a "Failing
> assertion".
> $ ~/local/bin/xtrabackup_55 --prepare --target-dir=`pwd` --tmpdir=/tmp
> /export/home/mysql/local/bin/xtrabackup_55 Ver 1.6 Rev undefined for
> 5.5.9 Linux (x86_64)
> xtrabackup: cd to /data/backup/full/2011-09-01_06-27-55
> xtrabackup: This target seems to be not prepared yet.
> 110901 22:58:41 InnoDB: Operating system error number 2 in a file
> operation.
> InnoDB: The error means the system cannot find the path specified.
> xtrabackup: Warning: cannot open ./xtrabackup_logfile. will try to find.
> xtrabackup: 'ib_logfile0' seems to be 'xtrabackup_logfile'. will retry.
> xtrabackup: xtrabackup_logfile detected: size=6089359360,
> start_lsn=(1336207695220)
> 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 = 6089359360
> 110901 22:58:42 InnoDB: Using Linux native AIO
> xtrabackup: Starting InnoDB instance for recovery.
> xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory
> parameter)
> 110901 22:58:42 InnoDB: The InnoDB memory heap is disabled
> 110901 22:58:42 InnoDB: Mutexes and rw_locks use GCC atomic builtins
> 110901 22:58:42 InnoDB: Compressed tables use zlib 1.2.3
> 110901 22:58:42 InnoDB: Using Linux native AIO
> 110901 22:58:42 InnoDB: Warning: innodb_file_io_threads is deprecated.
> Please use innodb_read_i...

Let's document that on prepare either "innobackupex --apply-log" should be used which will read InnoDB configuration from backup-my.cnf automatically, or --defaults-file=backup-my.cnf should be passed to the xtrabackup binary if it is used to prepare.

This will be fixed when we merge innobackupex and xtrabackup into a single executable (or implement the mentioned blueprint).

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