← Back to team overview

percona-discussion team mailing list archive

[Bug 339013] Re: apply-log fails with error log seq number is in future

 

Hello,

if i --prepare my backup, i get the following errors:

# ./xtrabackup --prepare                     
./xtrabackup  Ver beta-0.4 for 5.1.32 unknown-linux-gnu (x86_64)     
xtrabackup_logfile detected: size=231063552, start_lsn=(23 1769429644)
xtrabackup: Starting InnoDB instance for recovery.                    
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
InnoDB: Log scan progressed past the checkpoint lsn 23 1769429644                
090402 11:01:12  InnoDB: Database was not shut down normally!                    
InnoDB: Starting crash recovery.                                                 
InnoDB: Reading tablespace information from the .ibd files...                    
InnoDB: Restoring possible half-written data pages from the doublewrite          
InnoDB: buffer..
InnoDB: Doing recovery: scanned up to log sequence number 23 1774672384 (2 %)    
InnoDB: Doing recovery: scanned up to log sequence number 23 1779915264 (4 %)  
....
InnoDB: Doing recovery: scanned up to log sequence number 23 2000116224 (99 %)
InnoDB: Doing recovery: scanned up to log sequence number 23 2000474712 (99 %)
090402 11:28:39  InnoDB: ERROR: We were only able to scan the log up to 23 2000474712
InnoDB: but a database page a had an lsn 23 2137052144. It is possible that the
InnoDB: database is now corrupt!
090402 11:28:39  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: Last MySQL binlog file position 0 16569046, file name /mysql/logs/rad-db1.002794
090402 11:29:25  InnoDB: Started; log sequence number 23 2000474712

[notice (again)]
  If you use binary log and don't use any hack of group commit,
  the binary log position seems to be:
InnoDB: Last MySQL binlog file position 0 16569046, file name /mysql/logs/rad-db1.002794

090402 11:29:25  InnoDB: Starting shutdown...
090402 11:29:27  InnoDB: Assertion failure in thread 1171810624 in file btr/btr0pcur.c line 402
InnoDB: Failing assertion: btr_page_get_prev(next_page, mtr) == buf_frame_get_page_no(page)
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.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
Aborted

Is this related to this bugreport or something completly different? I
did not check, if this backup is functional or not.

Greets
Mark

-- 
apply-log fails with error log seq number is in future
https://bugs.launchpad.net/bugs/339013
You received this bug notification because you are a member of Percona
developers, which is the registrant for Percona-XtraBackup.

Status in Open source backup tool for InnoDB and XtraDB: Fix Released

Bug description:
./innobackup-1.5.1 --apply-log /var/lib/mysql/backup/2009-03-06_17-06-17/                                    

InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy.
All Rights Reserved.

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

IMPORTANT: Please check that the apply-log run completes successfully.
           At the end of a successful apply-log run innobackup
           prints "innobackup completed OK!".


innobackup:: Warning: Ignored unrecognized line 1 in options : './xtrabackup  Ver alpha-0.2 for 5.0.77 unknown-linux-gnu (x86_64)
'

090306 19:51:58  innobackup: Starting ibbackup with command: ./xtrabackup --prepare --target-dir=/var/lib/mysql/backup/2009-03-06_17-06-17

./xtrabackup  Ver alpha-0.2 for 5.0.77 unknown-linux-gnu (x86_64)
xtrabackup_logfile detected: size=4177920, start_lsn=(53 2203680185)
InnoDB: Log scan progressed past the checkpoint lsn 53 2203680185
090306 19:51:58  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Doing recovery: scanned up to log sequence number 53 2206675456
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 1 row operations to undo
InnoDB: Trx id counter is 0 457053440
090306 19:52:00  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 2 3 4 090306 19:52:00  InnoDB: Error: page 5698 log sequence number 53 2206837124
InnoDB: is in the future! Current system log sequence number 53 2206675233.
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.0/en/forcing-recovery.html
InnoDB: for more information.
090306 19:52:00  InnoDB: Error: page 5730 log sequence number 53 2206720672
InnoDB: is in the future! Current system log sequence number 53 2206675233.
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.0/en/forcing-recovery.html
InnoDB: for more information.



Follow ups

References