xtrabackup: error: log block numbers mismatch

Asked by Oleg M on 2012-01-10

Running innobackupex I see the following in its output:

xtrabackup: error: log block numbers mismatch:
xtrabackup: error: expected log block no. 91292509, but got no. 90768229 from the log file.
xtrabackup: Error: xtrabackup_copy_logfile() failed.

innobackupex continues, but at the end I see this:

innobackupex: xtrabackup_55 failed! (exit code 1) The backup may not be complete.

Studying Bug #805593 I understood that one possible reason for this error message could be transaction log being wrapped around while xtrabackup works.

Will much appretiate if you answer the following:
1) Is it really transaction log wrapping issue?
Is there a way to find out?
2) If the above is true, how the backup logic should be build?
Restart backup?
Shall this go to FAQ/User Guide?
3) Is it possible to delay log wrapping till xtrabackup ends?

I'm using
Ubuntu Natty 11.04(2.6.38-8-server #42-Ubuntu SMP Mon Apr 11 03:49:04 UTC 2011 x86_64 x86_64 x86_64 GNU/Linux)
Percona Server 5.5.17-rel22.1
XTRABACKUP_VERSION=1.6.3

Please let me know if you need any further details to investgate the issue.

Thank you and best regards
O.

Question information

Alexey Kopytov (akopytov) said : #1

No, it doesn't look like a wrap-around issue. When the log file is wrapped around, the LSN seen by XtraBackup can jump forward, but it seems to jump backward in your case. Which is really strange.

Could InnoDB log files be overwritten during backup? As in, the server is reinstalled, or restored from a backup or something like that?

What's your InnoDB log file configuration?

Oleg M (olegme) said : #2

The scenario that log files are being overwritten during the backup is very unrealistic. The backup script is a part of a bigger nightly backup process and no other jobs are scheduled for the same time period and no users are logged in.

Configuration is as follows:
...
innodb_file_per_table=1
innodb_data_home_dir = /usr/local/mysql55/data
innodb_data_file_path = ibdata1:10M:autoextend
innodb_log_group_home_dir = /usr/local/mysql55/data
innodb_buffer_pool_size = 512M
innodb_additional_mem_pool_size = 20M
innodb_log_file_size = 128M
innodb_log_buffer_size = 4M
innodb_flush_log_at_trx_commit = 0
innodb_flush_method = O_DIRECT
innodb_lock_wait_timeout = 50
...

One additional note is that this server is running as a Virtualbox virtual machine. Known consequence is that system time may drift, but this is non-relevant I guess.

In regard to the usage pattern, the database is used to store monitoring data for zabbix monitoring server at average rate of about 60 queries per second.

Please let me know what further details are needed to investigate.

Thank you.

Alexey Kopytov (akopytov) said : #3

Oleg,

Thank you for additional information. After more detailed code analysis, I've identified this problem as a regression and updated bug #917823 accordingly.

Best regards,
Alexey.

Can you help with this problem?

Provide an answer of your own, or ask Oleg M for more information if necessary.

To post a message you must log in.