innobackupex crash during backup preparation phasis

[deviantony]

System informations:

xtrabackup version: xtrabackup version 2.2.6 based on MySQL server 5.6.21 Linux (x86_64) (revision id: )
innobackupex version: InnoDB Backup Utility v1.5.1-xtrabackup
OS: Ubuntu 12.04.2 LTS
MySQL version: 5.5.31-0ubuntu0.12.04.2-log

An error occurs when executing the following command:

innobackupex --apply-log /path/to/backup/dir

Note: This error occurs randomly since last week, we haven't change anything on our system.

Here is the trace:

[...]
InnoDB: Doing recovery: scanned up to log sequence number 8800632183296 (99%)
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 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 8800637426176 (99%)
InnoDB: Doing recovery: scanned up to log sequence number 8800642669056 (99%)
InnoDB: Doing recovery: scanned up to log sequence number 8800644964094 (99%)
InnoDB: Transaction 18923466512 was in the XA prepared state.
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 18923467008
InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 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 103842633, file name /replication/mysql-bin.045845
InnoDB: 128 rollback segment(s) are active.
InnoDB: Starting in background the rollback of uncommitted transactions
2014-12-04 10:32:41 7f1beb95e700 InnoDB: Rolling back trx with id 18923466512, 1 rows to undo
InnoDB: Waiting for purge to start
InnoDB: 5.6.21 started; log sequence number 8800644964094
InnoDB: Rollback of trx with id 18923466512 completed
2014-12-04 10:32:41 7f1beb95e700 InnoDB: Rollback of non-prepared transactions completed

[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 103842633, file name /replication/mysql-bin.045845

xtrabackup: starting shutdown with innodb_fast_shutdown = 1
InnoDB: FTS optimize thread exiting.
InnoDB: Starting shutdown...
2014-12-04 10:32:46 7f1be8958700 InnoDB: Assertion failure in thread 139757842958080 in file buf0flu.cc line 2507
InnoDB: Failing assertion: UT_LIST_GET_LEN(buf_pool->flush_list) == 0
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.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
09:32:46 UTC - xtrabackup got signal 6 ;
This could be because you hit a bug or data is corrupted.
This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x10000
xtrabackup(my_print_stacktrace+0x24) [0x8e9804]
xtrabackup(handle_fatal_signal+0x254) [0x72cbb4]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xfcb0) [0x7f1bf915bcb0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35) [0x7f1bf76d0425]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x17b) [0x7f1bf76d3b8b]
xtrabackup(buf_flush_page_cleaner_thread+0x94e) [0x6c94ee]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7e9a) [0x7f1bf9153e9a]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f1bf778e3fd]

Please report a bug at https://bugs.launchpad.net/percona-xtrabackup
innobackupex: got a fatal error with the following stacktrace: at /usr/bin/innobackupex line 2632
        main::apply_log() called at /usr/bin/innobackupex line 1561
innobackupex: Error:
innobackupex: ibbackup failed at /usr/bin/innobackupex line 2632.

[Muhammad Irfan (muhammad-irfan)]

I did try quite few times but failed to reproduce it. Can you please share your my.cnf, exact commands you used for the backups.

$ cat /etc/issue
Ubuntu 12.04.5 LTS \n \l

mysql [localhost] {msandbox} ((none)) > show global variables like '%version%';
+-------------------------+------------------------------+
| Variable_name | Value |
+-------------------------+------------------------------+
| innodb_version | 5.5.31 |
| protocol_version | 10 |
| slave_type_conversions | |
| version | 5.5.31 |
| version_comment | MySQL Community Server (GPL) |
| version_compile_machine | x86_64 |
| version_compile_os | linux2.6 |
+-------------------------+------------------------------+

$ xtrabackup --version
xtrabackup version 2.2.6 based on MySQL server 5.6.21 Linux (x86_64) (revision id: )

$ innobackupex --defaults-file=/home/mirfan/sandboxes/msb_mysql5_5_31/my.sandbox.cnf --no-timestamp /home/mirfan/backups/bk1/
innobackupex: completed OK!

$ innobackupex --apply-log /home/mirfan/backups/bk1/
innobackupex: completed OK!

[deviantony (lapenna-anthony)]

Here is some details on the system/mysql versions:

$ cat /etc/issue
Ubuntu 12.04.2 LTS \n \l

mysql> show global variables like '%version%';
+-------------------------+-----------------------------+
| Variable_name | Value |
+-------------------------+-----------------------------+
| innodb_version | 5.5.31 |
| protocol_version | 10 |
| slave_type_conversions | |
| version | 5.5.31-0ubuntu0.12.04.2-log |
| version_comment | (Ubuntu) |
| version_compile_machine | x86_64 |
| version_compile_os | debian-linux-gnu |
+-------------------------+-----------------------------+
7 rows in set (0.00 sec)

Also, I've updated the schedule of my backup from midnight to 21h , which is a less busy period for my MySQL server, and now the backup seems to work well.

I'm using the following options for the backup:

$ innobackupex --user=my_user --password=my_pass --parallel=1 --no-lock --no-timestamp

$ innobackupex --apply-log

[Alexey Kopytov (akopytov)]

Symptoms are identical to bug #1368846. Marking as a duplicate.