Add a test case for partial streaming backups + multiple tablespaces

[Ovais Tariq]

When doing a partial streaming backup using xbstream, upon extracting the archive it reports the following error:
xb_stream_read_chunk(): wrong chunk magic at offset 0x1b3990e.

This error seems spurious to me because I am able to successfully prepare the backup without any issues.

The XtraBackup version is:
[root@centos6_01 backup_test]# xtrabackup --version
xtrabackup version 2.0.5 for Percona Server 5.1.59 unknown-linux-gnu (x86_64) (revision id: 499)

The Percona Server version is:
[root@centos6_01 backup_test]# /usr/sbin/mysqld --version
/usr/sbin/mysqld Ver 5.5.29-29.4 for Linux on x86_64 (Percona Server (GPL), Release rel29.4, Revision 401)

The steps that were taken:

[root@centos6_01 backup_test]# innobackupex --stream=xbstream ./ --include=test.* > backup_test_db.xbstream

InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy
and Percona Ireland Ltd 2009-2012. All Rights Reserved.

This software is published under
the GNU GENERAL PUBLIC LICENSE Version 2, June 1991.

130314 11:18:32 innobackupex: Starting mysql with options: --unbuffered --
130314 11:18:32 innobackupex: Connected to database with mysql child process (pid=6151)
130314 11:18:38 innobackupex: Connection to database server closed
IMPORTANT: Please check that the backup run completes successfully.
           At the end of a successful backup run innobackupex
           prints "completed OK!".

innobackupex: Using mysql Ver 14.14 Distrib 5.5.29, for Linux (x86_64) using readline 5.1
innobackupex: Using mysql server version Copyright (c) 2000, 2012, Oracle and/or its affiliates. All rights reserved.

innobackupex: Created backup directory /root/backup_test
130314 11:18:38 innobackupex: Starting mysql with options: --unbuffered --
130314 11:18:38 innobackupex: Connected to database with mysql child process (pid=6181)
130314 11:18:40 innobackupex: Connection to database server closed

130314 11:18:40 innobackupex: Starting ibbackup with command: xtrabackup_55 --defaults-group="mysqld" --backup --suspend-at-end --target-dir=/tmp --tables='test.*' --stream=xbstream
innobackupex: Waiting for ibbackup (pid=6189) to suspend
innobackupex: Suspend file '/tmp/xtrabackup_suspended'

xtrabackup_55 version 2.0.5 for Percona Server 5.5.16 Linux (x86_64) (revision id: 499)
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:10M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 5242880
xtrabackup: using O_DIRECT
xtrabackup: tables regcomp(test.*): Success
130314 11:18:40 InnoDB: Warning: allocated tablespace 15, old maximum was 9
>> log scanned up to (23311379)
[01] Streaming ./ibdata1
[01] ...done
[01] Streaming ./test/t2.ibd
[01] ...done
[01] Streaming ./test/t3.ibd
[01] ...done
[01] Streaming ./test/test_export.ibd
[01] ...done

130314 11:18:41 innobackupex: Continuing after ibbackup has suspended
130314 11:18:41 innobackupex: Starting mysql with options: --unbuffered --
130314 11:18:41 innobackupex: Connected to database with mysql child process (pid=6203)
130314 11:18:43 innobackupex: Starting to lock all tables...
>> log scanned up to (23311379)
>> log scanned up to (23311379)
130314 11:18:53 innobackupex: All tables locked and flushed to disk

130314 11:18:53 innobackupex: Starting to backup non-InnoDB tables and files
innobackupex: in subdirectories of '/var/lib/mysql'
percona.deadlocks.frm is skipped because it does not match test.*.
percona.db.opt is skipped because it does not match test.*.
innobackupex: Backing up files '/var/lib/mysql/performance_schema/*.{frm,MYD,MYI,MAD,MAI,MRG,TRG,TRN,ARM,ARZ,CSM,CSV,opt,par}' (18 files)
performance_schema.threads.frm is skipped because it does not match test.*.
performance_schema.mutex_instances.frm is skipped because it does not match test.*.
performance_schema.events_waits_summary_by_thread_by_event_name.frm is skipped because it does not match test.*.
performance_schema.file_summary_by_instance.frm is skipped because it does not match test.*.
performance_schema.events_waits_summary_by_instance.frm is skipped because it does not match test.*.
performance_schema.file_instances.frm is skipped because it does not match test.*.
performance_schema.setup_instruments.frm is skipped because it does not match test.*.
performance_schema.rwlock_instances.frm is skipped because it does not match test.*.
performance_schema.events_waits_history.frm is skipped because it does not match test.*.
performance_schema.performance_timers.frm is skipped because it does not match test.*.
performance_schema.events_waits_summary_global_by_event_name.frm is skipped because it does not match test.*.
performance_schema.cond_instances.frm is skipped because it does not match test.*.
performance_schema.setup_timers.frm is skipped because it does not match test.*.
performance_schema.file_summary_by_event_name.frm is skipped because it does not match test.*.
performance_schema.events_waits_history_long.frm is skipped because it does not match test.*.
performance_schema.db.opt is skipped because it does not match test.*.
performance_schema.setup_consumers.frm is skipped because it does not match test.*.
performance_schema.events_waits_current.frm is skipped because it does not match test.*.
innobackupex: Backing up file '/var/lib/mysql/test/t2.frm'
innobackupex: Backing up file '/var/lib/mysql/test/test_export.frm'
innobackupex: Backing up file '/var/lib/mysql/test/t1.frm'
innobackupex: Backing up file '/var/lib/mysql/test/t3.frm'
innobackupex: Backing up files '/var/lib/mysql/mysql/*.{frm,MYD,MYI,MAD,MAI,MRG,TRG,TRN,ARM,ARZ,CSM,CSV,opt,par}' (72 files)
mysql.db.MYI is skipped because it does not match test.*.
mysql.func.MYD is skipped because it does not match test.*.
mysql.user.MYD is skipped because it does not match test.*.
mysql.proc.MYI is skipped because it does not match test.*.
mysql.time_zone_name.MYI is skipped because it does not match test.*.
mysql.time_zone_transition_type.frm is skipped because it does not match test.*.
mysql.help_relation.MYI is skipped because it does not match test.*.
mysql.help_relation.MYD is skipped because it does not match test.*.
mysql.general_log.CSM is skipped because it does not match test.*.
mysql.time_zone_transition.MYD is skipped because it does not match test.*.
mysql.event.frm is skipped because it does not match test.*.
mysql.func.frm is skipped because it does not match test.*.
mysql.db.MYD is skipped because it does not match test.*.
mysql.servers.MYD is skipped because it does not match test.*.
mysql.help_keyword.frm is skipped because it does not match test.*.
mysql.time_zone_name.MYD is skipped because it does not match test.*.
mysql.user.MYI is skipped because it does not match test.*.
mysql.help_topic.MYD is skipped because it does not match test.*.
mysql.time_zone_transition.MYI is skipped because it does not match test.*.
mysql.help_topic.MYI is skipped because it does not match test.*.
mysql.servers.MYI is skipped because it does not match test.*.
mysql.slow_log.CSV is skipped because it does not match test.*.
mysql.proc.frm is skipped because it does not match test.*.
mysql.time_zone_transition_type.MYI is skipped because it does not match test.*.
mysql.help_keyword.MYI is skipped because it does not match test.*.
mysql.procs_priv.MYD is skipped because it does not match test.*.
mysql.slow_log.frm is skipped because it does not match test.*.
mysql.user.frm is skipped because it does not match test.*.
mysql.ndb_binlog_index.frm is skipped because it does not match test.*.
mysql.slow_log.CSM is skipped because it does not match test.*.
mysql.plugin.frm is skipped because it does not match test.*.
mysql.help_category.MYI is skipped because it does not match test.*.
mysql.plugin.MYI is skipped because it does not match test.*.
mysql.procs_priv.frm is skipped because it does not match test.*.
mysql.columns_priv.MYD is skipped because it does not match test.*.
mysql.columns_priv.frm is skipped because it does not match test.*.
mysql.func.MYI is skipped because it does not match test.*.
mysql.event.MYD is skipped because it does not match test.*.
mysql.time_zone.MYI is skipped because it does not match test.*.
mysql.time_zone_name.frm is skipped because it does not match test.*.
mysql.host.MYD is skipped because it does not match test.*.
mysql.time_zone_leap_second.frm is skipped because it does not match test.*.
mysql.help_category.frm is skipped because it does not match test.*.
mysql.general_log.CSV is skipped because it does not match test.*.
mysql.help_topic.frm is skipped because it does not match test.*.
mysql.proxies_priv.MYI is skipped because it does not match test.*.
mysql.proxies_priv.frm is skipped because it does not match test.*.
mysql.plugin.MYD is skipped because it does not match test.*.
mysql.time_zone_transition_type.MYD is skipped because it does not match test.*.
mysql.servers.frm is skipped because it does not match test.*.
mysql.proxies_priv.MYD is skipped because it does not match test.*.
mysql.ndb_binlog_index.MYD is skipped because it does not match test.*.
mysql.time_zone.MYD is skipped because it does not match test.*.
mysql.time_zone_leap_second.MYD is skipped because it does not match test.*.
mysql.columns_priv.MYI is skipped because it does not match test.*.
mysql.time_zone_transition.frm is skipped because it does not match test.*.
mysql.time_zone.frm is skipped because it does not match test.*.
mysql.tables_priv.frm is skipped because it does not match test.*.
mysql.help_keyword.MYD is skipped because it does not match test.*.
mysql.help_relation.frm is skipped because it does not match test.*.
mysql.tables_priv.MYI is skipped because it does not match test.*.
mysql.tables_priv.MYD is skipped because it does not match test.*.
mysql.procs_priv.MYI is skipped because it does not match test.*.
mysql.event.MYI is skipped because it does not match test.*.
mysql.host.MYI is skipped because it does not match test.*.
mysql.time_zone_leap_second.MYI is skipped because it does not match test.*.
mysql.general_log.frm is skipped because it does not match test.*.
mysql.ndb_binlog_index.MYI is skipped because it does not match test.*.
mysql.db.frm is skipped because it does not match test.*.
mysql.host.frm is skipped because it does not match test.*.
mysql.help_category.MYD is skipped because it does not match test.*.
mysql.proc.MYD is skipped because it does not match test.*.
130314 11:18:53 innobackupex: Finished backing up non-InnoDB tables and files

130314 11:18:53 innobackupex: Waiting for log copying to finish

xtrabackup: The latest check point (for incremental): '23311379'
xtrabackup: Stopping log copying thread.
..>> log scanned up to (23311379)

xtrabackup: Streaming transaction log from a temporary file...
xtrabackup: Done.
xtrabackup: Transaction log of lsn (23311379) to (23311379) was copied.
130314 11:18:56 innobackupex: All tables unlocked
130314 11:18:56 innobackupex: Connection to database server closed

innobackupex: Backup created in directory '/root/backup_test'
innobackupex: MySQL binlog position: filename '', position
130314 11:18:57 innobackupex: completed OK!

[root@centos6_01 backup_test]# rm -rf uncompress/*

[root@centos6_01 backup_test]# xbstream -x -C uncompress/ < backup_test_db.xbstream
xb_stream_read_chunk(): wrong chunk magic at offset 0x1b3990e.

The MySQL datadir that is backed up is attached to the ticket.

The interesting thing to note is that if I take a complete dump of MySQL data using mysqldum, clean the MySQL datadir and import the dump and then run Xtrabackup, then the resultant archive is extracted without any error.

[Ovais Tariq (ovais-tariq)]

The output from preparing the uncompressed archive that xbstream reported an error on:

[root@centos6_01 backup_test]# echo "innodb_file_per_table=1" >> uncompress/backup-my.cnf
[root@centos6_01 backup_test]# innobackupex --apply-log --export uncompress/

InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy
and Percona Ireland Ltd 2009-2012. All Rights Reserved.

This software is published under
the GNU GENERAL PUBLIC LICENSE Version 2, June 1991.

option_ibbackup_binary is autodetect, trying to connect to MySQL
Connected to MySQL with pid 6286
130314 11:31:55 innobackupex: Connection to database server closed
Connected successfully
130314 11:31:55 innobackupex: Starting mysql with options: --unbuffered --
130314 11:31:55 innobackupex: Connected to database with mysql child process (pid=6290)
130314 11:32:01 innobackupex: Connection to database server closed
IMPORTANT: Please check that the apply-log run completes successfully.
           At the end of a successful apply-log run innobackupex
           prints "completed OK!".

130314 11:32:01 innobackupex: Starting ibbackup with command: xtrabackup_55 --defaults-file="/root/backup_test/uncompress/backup-my.cnf" --defaults-group="mysqld" --prepare --target-dir=/root/backup_test/uncompress --export

xtrabackup_55 version 2.0.5 for Percona Server 5.5.16 Linux (x86_64) (revision id: 499)
xtrabackup: cd to /root/backup_test/uncompress
xtrabackup: This target seems to be not prepared yet.
xtrabackup: xtrabackup_logfile detected: size=2097152, start_lsn=(23311379)
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 = 2097152
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 = 2097152
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
130314 11:32:01 InnoDB: The InnoDB memory heap is disabled
130314 11:32:01 InnoDB: Mutexes and rw_locks use GCC atomic builtins
130314 11:32:01 InnoDB: Compressed tables use zlib 1.2.3
130314 11:32:01 InnoDB: Initializing buffer pool, size = 100.0M
130314 11:32:01 InnoDB: Completed initialization of buffer pool
130314 11:32:01 InnoDB: highest supported file format is Barracuda.
130314 11:32:02 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
130314 11:32:02 InnoDB: Error: trying to open a table, but could not
InnoDB: open the tablespace file './percona/deadlocks.ibd'!
InnoDB: It will be removed from data dictionary.
130314 11:32:03 InnoDB: Waiting for the background threads to start...

[Ovais Tariq (ovais-tariq)]

I was also able to get a sporadic failure on a full backup but I am not able to repeat it with full backups

[Alexey Kopytov (akopytov)]

This bug is fixed in 2.0.6.

Background: the fix for bug #711166 released in 2.0.5 had broken, among other things, partial streaming backups with multiple InnoDB tablespaces. XtraBackup erroneously printed the "Skipping <tablespace>" message to stdout rather than stderr. I noticed and fixed that while working on the fix for #1130627, though I did not report a separate bug for it.

I cannot reproduce this bug with the fix for #1130627, but I can reproduce it with that fix reverted.

So this bug is not reproducible with XB 2.0.6, though technically it's not a duplicate of bug #1130627, it's just been fixed with the same patch.

And the reason why the mentioned regression went unnoticed is that the XB test suite does not have any tests for this combination, i.e. partial streaming backups with multiple InnoDB tablespaces.

Let's keep this report to add such a test case.

[Ovais Tariq (ovais-tariq)]

Thanks Alexey that sounds good.

[Shahriyar Rzayev (rzayev-sehriyar)]

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