apply-log Failed with Small xtrabackup_logfile
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Percona XtraBackup moved to https://jira.percona.com/projects/PXB |
Fix Released
|
High
|
Sergei Glushchenko | ||
2.2 |
Fix Released
|
High
|
Sergei Glushchenko | ||
2.3 |
Fix Released
|
High
|
Sergei Glushchenko |
Bug Description
When running apply-log on a backup taken with 2.2.7 and small xtrabackup_logfile, the process failed.
141216 17:09:26 innobackupex: Starting ibbackup with command: xtrabackup --defaults-
xtrabackup version 2.2.7 based on MySQL server 5.6.21 Linux (x86_64) (revision id: )
xtrabackup: cd to /mnt/data/
xtrabackup: This target seems to be not prepared yet.
xtrabackup: xtrabackup_logfile detected: size=2097152, start_lsn=
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
InnoDB: Using atomics to ref count buffer pool pages
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Memory barrier is not used
InnoDB: Compressed tables use zlib 1.2.3
InnoDB: Using CPU crc32 instructions
InnoDB: Initializing buffer pool, size = 100.0M
InnoDB: Completed initialization of buffer pool
InnoDB: Highest supported file format is Barracuda.
InnoDB: The log sequence numbers 6041770903387 and 6041770903387 in ibdata files do not match the log sequence number 6539475748335 in the ib_logfiles!
InnoDB: Database was not shutdown normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages
InnoDB: from the doublewrite buffer...
InnoDB: We scanned the log up to 6539475747840. A checkpoint was at 6539475748335 and the maximum LSN on a database page was 0. It is possible that the database is now corrupt!
2014-12-16 17:09:26 7f79175f8720 InnoDB: Error: page 2 log sequence number 6539633980252
InnoDB: is in the future! Current system log sequence number 6539475748335.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://
InnoDB: for more information.
[LSN errors continues until Ctrl-C]
[root@mysql02-2 full]# cat 2014-12-
# This MySQL options file was generated by innobackupex.
# The MySQL server
[mysqld]
innodb_
innodb_
innodb_
innodb_
innodb_
innodb_
You can see an ib_logfile0 was created with only 2M in size.
[root@mysql02-2 full]# ls -alh 2014-12-15_23-00-46
total 28G
drwxr-xr-x 16 root root 4.0K Dec 16 17:09 .
drwxr-xr-x 4 root root 4.0K Dec 16 17:09 ..
[...]
-rw-r--r-- 1 root root 265 Dec 15 23:00 backup-my.cnf
-rw-r----- 1 root root 28G Dec 16 17:09 ibdata1
-rw-r----- 1 root root 2.0M Dec 16 17:09 ib_logfile0
-rw-r----- 1 root root 93M Dec 16 06:04 ib_lru_dump
drwxr-xr-x 2 root root 4.0K Dec 16 06:04 mysql
drwx------ 2 root root 75 Dec 16 06:04 percona
drwxr-xr-x 2 root root 4.0K Dec 16 06:04 performance_schema
drwx------ 2 root root 122 Dec 16 06:04 test
-rw-r--r-- 1 root root 26 Dec 16 06:04 xtrabackup_
-rw-r----- 1 root root 101 Dec 16 06:04 xtrabackup_
-rw-r--r-- 1 root root 633 Dec 16 06:04 xtrabackup_info
Here's one more backup previously taken with the same version, notice the difference in ibdata1 size:
[root@mysql02-2 full]# ls -alh 2014-12-14_13-04-31
total 17G
drwxr-xr-x 16 root root 4.0K Dec 15 21:31 .
drwxr-xr-x 4 root root 4.0K Dec 16 17:09 ..
[...]
-rw-r--r-- 1 root root 265 Dec 14 13:04 backup-my.cnf
-rw-r----- 1 root root 2.1G Dec 15 21:31 ibdata1
-rw-r--r-- 1 root root 6.0G Dec 15 21:31 ib_logfile0
-rw-r--r-- 1 root root 6.0G Dec 15 21:31 ib_logfile1
-rw-r----- 1 root root 92M Dec 14 19:38 ib_lru_dump
drwxr-xr-x 2 root root 4.0K Dec 14 19:38 mysql
drwx------ 2 root root 75 Dec 14 19:38 percona
drwxr-xr-x 2 root root 4.0K Dec 14 19:38 performance_schema
drwx------ 2 root root 122 Dec 14 19:38 test
-rw-r--r-- 1 root root 25 Dec 14 19:38 xtrabackup_
-rw-r--r-- 1 root root 42 Dec 15 21:31 xtrabackup_
-rw-r----- 1 root root 101 Dec 15 21:31 xtrabackup_
-rw-r--r-- 1 root root 632 Dec 14 19:38 xtrabackup_info
-rw-r----- 1 root root 2.5G Dec 15 21:03 xtrabackup_logfile
Related branches
- Alexey Kopytov (community): Approve
-
Diff: 97 lines (+26/-6)3 files modifiedstorage/innobase/include/log0log.h (+2/-0)
storage/innobase/log/log0recv.cc (+10/-2)
storage/innobase/xtrabackup/src/xtrabackup.cc (+14/-4)
- Alexey Kopytov (community): Approve
-
Diff: 97 lines (+26/-6)3 files modifiedstorage/innobase/include/log0log.h (+2/-0)
storage/innobase/log/log0recv.cc (+10/-2)
storage/innobase/xtrabackup/src/xtrabackup.cc (+14/-4)
Without hitting Ctrl-C, I'd eventually get an assertion, the full command was: innobackupex --apply-log 2014-12-16_18-02-25
141217 16:21:42 innobackupex: Starting ibbackup with command: xtrabackup --defaults- file="/ mnt/data/ localbackup/ mysql06- 2.hostname. com/full/ 2014-12- 16_18-02- 25/backup- my.cnf" --defaults- group=" mysqld" --prepare --target- dir=/mnt/ data/localbacku p/mysql06- 2.hostname. com/full/ 2014-12- 16_18-02- 25
xtrabackup version 2.2.7 based on MySQL server 5.6.21 Linux (x86_64) (revision id: ) localbackup/ mysql06- 2.hostname. com/full/ 2014-12- 16_18-02- 25 (6542575355872) data_home_ dir = ./ data_file_ path = ibdata1: 10M:autoextend log_group_ home_dir = ./ log_files_ in_group = 1 log_file_ size = 2097152 data_home_ dir = ./ data_file_ path = ibdata1: 10M:autoextend log_group_ home_dir = ./ log_files_ in_group = 1 log_file_ size = 2097152 dev.mysql. com/doc/ refman/ 5.6/en/ forcing- innodb- recovery. html master/ bin-log. 003375
xtrabackup: cd to /mnt/data/
xtrabackup: This target seems to be not prepared yet.
xtrabackup: xtrabackup_logfile detected: size=2097152, start_lsn=
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
InnoDB: Using atomics to ref count buffer pool pages
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Memory barrier is not used
InnoDB: Compressed tables use zlib 1.2.3
InnoDB: Using CPU crc32 instructions
InnoDB: Initializing buffer pool, size = 100.0M
InnoDB: Completed initialization of buffer pool
InnoDB: Highest supported file format is Barracuda.
InnoDB: The log sequence numbers 6041770903387 and 6041770903387 in ibdata files do not match the log sequence number 6542575355872 in the ib_logfiles!
InnoDB: Database was not shutdown normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages
InnoDB: from the doublewrite buffer...
InnoDB: We scanned the log up to 6542575355392. A checkpoint was at 6542575355872 and the maximum LSN on a database page was 0. It is possible that the database is now corrupt!
[...]
2014-12-17 16:21:44 7f9506c08720 InnoDB: Error: page 98345 log sequence number 6542647464609
InnoDB: is in the future! Current system log sequence number 6542575355872.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://
InnoDB: for more information.
InnoDB: 125 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 0 row operations to undo
InnoDB: Trx id counter is 32925002752
InnoDB: Last MySQL binlog file position 0 1019564159, file name /mnt/data/
InnoDB: Cleaning up trx with id 32945843215
2014-12-17 16:21:44 7f9506c08720 InnoDB: Assertion failure in thread 14...