I have all my backups made with Xtrabackup 2.1.3.
On preparing the backup in order to do a restore, Xtrabackup segfaults, and dumps core.
After that, it doesn’t work to re-run the prepare stage as shown below.
So I compiled Xtrabackup 2.1.4 (bzr branch lp:~akopytov/percona-xtrabackup/bugs-1177206-and-1187071-2.1), took a new full backup, and tried restoring that also.
Unfortunately with the same bad result. I have tested restoring databases from 4 different servers, and all my tests fail in the same way.
For me this means that I have 11TB useless backups on disk, and no backup of my databases since I have relied on Xtrabackup only
mysqlbackup/sb3/base/2013-07-19_11-00-02/backup-my.cnf" --defaults-group=“mysqld” --prepare --target-dir=/srv/storage
/mysqlbackup/sb3/base/2013-07-19_11-00-02 --apply-log-only --tmpdir=/tmp
…
Expanding ./accesstoken/refreshtoken.ibd
Expanding ./accesstoken/externalapplication.ibd
Expanding ./accesstoken/accesstokenchannelid.ibd
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 = 856162304
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
130801 2:08:00 InnoDB: The InnoDB memory heap is disabled
130801 2:08:00 InnoDB: Mutexes and rw_locks use GCC atomic builtins
130801 2:08:00 InnoDB: Compressed tables use zlib 1.2.3
130801 2:08:00 InnoDB: Initializing buffer pool, size = 100.0M
130801 2:08:00 InnoDB: Completed initialization of buffer pool
130801 2:08:01 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 899274494433
130801 2:08:01 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 899279736832 (0 %)
InnoDB: Doing recovery: scanned up to log sequence number 899284979712 (1 %)
InnoDB: Doing recovery: scanned up to log sequence number 899290222592 (2 %)
130801 2:08:40 InnoDB: Starting an apply batch of log records to the database…
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68
69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 899295465472 (2 %)
InnoDB: Doing recovery: scanned up to log sequence number 899300708352 (3 %)
InnoDB: Doing recovery: scanned up to log sequence number 899305951232 (4 %)
InnoDB: Doing recovery: scanned up to log sequence number 899311194112 (4 %)
130801 2:10:11 InnoDB: Starting an apply batch of log records to the database…
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68
69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 899316436992 (5 %)
InnoDB: Doing recovery: scanned up to log sequence number 899321679872 (6 %)
InnoDB: Doing recovery: scanned up to log sequence number 899326922752 (6 %)
InnoDB: Doing recovery: scanned up to log sequence number 899332165632 (7 %)
130801 2:11:02 InnoDB: Starting an apply batch of log records to the database…
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 Segmentation fault (core dumped)
innobackupex: Error:
innobackupex: ibbackup failed at /usr/bin/innobackupex line 389.
Re running doesnt work better:
mysqlbackup/sb3/base/2013-07-19_11-00-02/backup-my.cnf" --defaults-group=“mysqld” --prepare --target-dir=/srv/storage/mysqlbackup/sb3/base/2013-07-19_11-00-02 --apply-log-only --tmpdir=/tmp
xtrabackup_55 version 2.1.3 for MySQL server 5.5.17 Linux (x86_64) (revision id: undefined)
xtrabackup: cd to /srv/storage/mysqlbackup/sb3/base/2013-07-19_11-00-02
xtrabackup: This target seems to be not prepared yet.
130806 11:45:18 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=963182592, start_lsn=(899274494433)
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 = 963182592
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 = 963182592
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
130806 11:45:18 InnoDB: The InnoDB memory heap is disabled
130806 11:45:18 InnoDB: Mutexes and rw_locks use GCC atomic builtins
130806 11:45:18 InnoDB: Compressed tables use zlib 1.2.3
130806 11:45:18 InnoDB: Initializing buffer pool, size = 100.0M
130806 11:45:18 InnoDB: Completed initialization of buffer pool
130806 11:45:19 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 899274494433
130806 11:45:19 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 899279736832 (0 %)
InnoDB: Doing recovery: scanned up to log sequence number 899284979712 (1 %)
InnoDB: Doing recovery: scanned up to log sequence number 899290222592 (1 %)
130806 11:45:29 InnoDB: Starting an apply batch of log records to the database…
InnoDB: Progress in percents: 130806 11:45:29 InnoDB: Assertion failure in thread 139642902509312 in file log0recv.c line 1083
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.5/…-recovery.html
InnoDB: about forcing recovery.
Aborted (core dumped)
innobackupex: Error:
innobackupex: ibbackup failed at /usr/bin/innobackupex line 389.
So I checked this forum and found out one problem could come from me doing apply logs on the backup server, and not the actual server I want to restore to in the end. I took a new fullbackup, and tried again:
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 = 573194240
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
130807 14:02:32 InnoDB: The InnoDB memory heap is disabled
130807 14:02:32 InnoDB: Mutexes and rw_locks use GCC atomic builtins
130807 14:02:32 InnoDB: Compressed tables use zlib 1.2.3
130807 14:02:32 InnoDB: Initializing buffer pool, size = 100.0M
130807 14:02:32 InnoDB: Completed initialization of buffer pool
130807 14:02:32 InnoDB: highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 960942418808
130807 14:02:32 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 960947661312 (1 %)
InnoDB: Doing recovery: scanned up to log sequence number 960952904192 (2 %)
InnoDB: Doing recovery: scanned up to log sequence number 960958147072 (3 %)
130807 14:02:37 InnoDB: Starting an apply batch of log records to the database…
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 960963389952 (4 %)
InnoDB: Doing recovery: scanned up to log sequence number 960968632832 (5 %)
InnoDB: Doing recovery: scanned up to log sequence number 960973875712 (6 %)
130807 14:02:56 InnoDB: Starting an apply batch of log records to the database…
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Doing recovery: scanned up to log sequence number 960979118592 (7 %)
InnoDB: Doing recovery: scanned up to log sequence number 960984361472 (8 %)
InnoDB: Doing recovery: scanned up to log sequence number 960989604352 (9 %)
InnoDB: Doing recovery: scanned up to log sequence number 960994847232 (10 %)
130807 14:04:04 InnoDB: Starting an apply batch of log records to the database…
[COLOR=#B22222]InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 InnoDB: Probable data corruption on page 388973
InnoDB: Original record (compact record)
InnoDB: on that page.
InnoDB: Cannot find the dir slot for record (compact record)
InnoDB: on that page!
130807 14:04:13 InnoDB: Page dump in ascii and hex (16384 bytes):
len 16384; hex 913adde20005ef6d0005ef6a0005ef6e000000dfbeeb19ab45 bf000000000000000000000452005e3e6782f52567118e31b5 00050000021d00000001126a224f0000000000000000059b00 00000000000000000000000000000000000000010002001a69 6e66696d756d0006000b000073757072656d756d0000102a93 8000124f1199be9280000000011cbd0c00001800158000124f 1199beb480000000011cbcb0000020168f8000124f1199beed 80000000011cbcbd08002800158000124f1199bfe080000000 011cbc6c00003012b48000124f1199c03880000000011cbbed 0000380fea8000124f1199c0a480000000011cc0b100004000 158000124f1199c0a580000000011cbb880700480fab800012 4f1199c0db80000000011cbb870000503cf38000124f1199c1 6280000000011cbc3f0600582d488000124f1199c166800000 00011cbc3e0000602d1e8000124f1199c16d80000000011cbc 3d05006800158000124f1199c20a80000000011cbc3c000070 296d8000124f1199c21e80000000011cbc3b00007800158000 124f1199c26e80000000011cbc3a00008000158000124f1199 c27b80000000011cbc0c0500883c368000124f1199c2938000 0000011cbb8a00009000158000124f1199c2f080000000011c bb8600009828ef8000124f1199c2fd80000000011cbb700000 a01dc78000124f1199c30080000000011cbc390800a83bcd80 00124f1199d30080000000011cbc380400b000158000124f11 99d35b80000000011cbc370000b82
…
InnoDB: End of page dump
130807 14:04:14 InnoDB: Page checksum 3742725938, prior-to-4.0.14-form checksum 1918383901
InnoDB: stored checksum 2436554210, prior-to-4.0.14-form stored checksum 223
InnoDB: Page lsn 223 3203078571, low 4 bytes of lsn at page end 3203078571
InnoDB: Page number (if stored to page already) 388973,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 1106
InnoDB: Page may be an index page where index id is 1435
Segmentation fault
innobackupex: Error:
innobackupex: ibbackup failed at /usr/bin/innobackupex line 389.