log block numbers mismatch, xtrabackup never ends

Bug #1050355 reported by Adrián Chapela on 2012-09-13
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Percona XtraBackup moved to https://jira.percona.com/projects/PXB

Bug Description

I am having problems with xtrabackup (xtrabackup_51 version 2.0.2). I am getting next error (during backup) and it never ends. I have stopped when it has spend 7 hours to get 25% of total backup. When it were running ok, it took about 3,5 hours to get the backup:
xtrabackup: error: log block numbers mismatch:
xtrabackup: error: expected log block no. 410098410, but got no. 412146402 from the log file.
xtrabackup: error: it looks like InnoDB log has wrapped around before xtrabackup could process all records due to either log copying being too slow, or log files being too small.
xtrabackup: Error: xtrabackup_copy_logfile() failed.

Same error with version 1.6.4:
>> ###Warning###: The copying transaction log migh be overtaken already by the target.
>> : Waiting log block no 80669053, but the bumber is already 84765037.
>> : If the number equals 80669053 + n * 2047992, it should be overtaken already

I have increased log file from 100MB to 500MB and 1GB but the result is the same.

I have done a change in my apps and now it is doing transactions smaller. Could this affect the backup utility ?

MySQL Version: 5.1.62-log

Alexey Kopytov (akopytov) wrote :

The root cause is just what it says: xtrabackup cannot catch up with log writing activity on the server, so the log wraps around before xtrabackup can copy records before they are overwritten.

What command line was used to take a backup? Were I/O throttling, streaming or compression used?

Changed in percona-xtrabackup:
status: New → Incomplete
Adrián Chapela (achapela) wrote :

I am using the next command:
/root/backup/xtra/innobackupex --user=user --password=pwd --ibbackup=/path/to/xtrabackup_51 --no-timestamp /path/to/backup/folder

Changed in percona-xtrabackup:
status: Incomplete → New
Alexey Kopytov (akopytov) wrote :

Does the target device where /path/to/backup/folder is located has enough bandwidth? Is it a local mount? If yes, is server datadir on the same device?

Adrián Chapela (achapela) wrote :

/path/to/backup/folder is not the same datadir, and I think that it has the enough bandwith, because before it was running OK.

We have more transactions but no more queries, the work done by database server is the same, but we have improved lock problems. The time needed for do it a backup has increased eight times. I have calculated that xtrabackup need about 24 hours to do a backup of 550 GB now and before it needs about 3,5 hours. It's too much difference to be caused by transactions improvement. I think that xtrabackup is doing something wrong with log files... no ?

Alexey Kopytov (akopytov) wrote :

You can check if I/O bandwidth is the issue by streaming the backup to /dev/null:

/root/backup/xtra/innobackupex --user=user --password=pwd --stream=tar --ibbackup=/path/to/xtrabackup_51 /tmp >/dev/null

xtrabackup will still copy the logfile to disk (to /tmp/xtrabackup_logfile with that command line), but the datafile will be streamed to /dev/null. If that succeeds, then it failed previously due to writes starvation.

Adrián Chapela (achapela) wrote :

Sorry for take your time. You were right. My problem was about io bandwith.

Sorry again.

Changed in percona-xtrabackup:
status: New → Invalid
Alexey Kopytov (akopytov) wrote :

Thanks for the update.

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

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers