Xtrabackup_56 exit code of 141

[chad_imh]

Greetings,

I’m using xtrabackup 2.1.9 to backup one of my database servers. The last few days when running the prepare process it exits with a code of 141. I can’t find anything in the logs (or online) that would suggest what this means or what the problem is. Can anyone shed some light on this?

The final message in the log file is

xtrabackup: starting shutdown with innodb_fast_shutdown = 1

It looks like the prepare worked but didn’t finish. Any insight would be great.

Chad

[jrivera]

Showing us the full xtrabackup error log might give a clue, include full command used.

[chad_imh]

The command I’m running is:

xtrabackup_56 --defaults-file=/opt/backup/ops/my.cnf --throttle=8 --parallel=1 --prepare --datadir=/var/lib/mysql/ --target-dir=/bkmnt/ib_backup/

Preparing InnoDB backup
xtrabackup_56 version 2.1.9 for MySQL server 5.6.17 Linux (x86_64) (revision id: 744)
xtrabackup: cd to /bkmnt/ib_backup
xtrabackup: This target seems to be not prepared yet.
xtrabackup: xtrabackup_logfile detected: size=705003520, start_lsn=(512318936491)
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_data_home_dir = ./
xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 705003520
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_data_home_dir = ./
xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 705003520
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: 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: Log scan progressed past the checkpoint lsn 512318936491
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: Doing recovery: scanned up to log sequence number 512324178944 (0%)
InnoDB: Doing recovery: scanned up to log sequence number 512329421824 (1%)
InnoDB: Doing recovery: scanned up to log sequence number 512334664704 (2%)
InnoDB: Doing recovery: scanned up to log sequence number 512339907584 (3%)
InnoDB: Doing recovery: scanned up to log sequence number 512345150464 (4%)
InnoDB: Doing recovery: scanned up to log sequence number 512350393344 (5%)
InnoDB: Doing recovery: scanned up to log sequence number 512355636224 (5%)
InnoDB: Doing recovery: scanned up to log sequence number 512360879104 (6%)
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 512366121984 (7%)
InnoDB: Doing recovery: scanned up to log sequence number 512371364864 (8%)
InnoDB: Doing recovery: scanned up to log sequence number 512376607744 (9%)
InnoDB: Doing recovery: scanned up to log sequence number 512381850624 (10%)
InnoDB: Doing recovery: scanned up to log sequence number 512387093504 (10%)
InnoDB: Doing recovery: scanned up to log sequence number 512392336384 (11%)
InnoDB: Doing recovery: scanned up to log sequence number 512397579264 (12%)
InnoDB: Doing recovery: scanned up to log sequence number 512402822144 (13%)
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: Doing recovery: scanned up to log sequence number 512937595904 (98%)
InnoDB: Doing recovery: scanned up to log sequence number 512942838784 (99%)
InnoDB: Doing recovery: scanned up to log sequence number 512945592711 (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: 128 rollback segment(s) are active.
InnoDB: Waiting for purge to start
InnoDB: 5.6.17 started; log sequence number 512945592711

[notice (again)]
If you use binary log and don’t use any hack of group commit,
the binary log position seems to be:

xtrabackup: starting shutdown with innodb_fast_shutdown = 1

That’s what I’ve got…

I’ve attached the full log since I ran out of characters…

Thanks
Chad