# Xtrabackup fails after some time **URL:** \ **Category:** Percona XtraBackup\ **Tags:** mysql\ **Created:** [April 22, 2023, 10:38am UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580 "2023-04-22T10:38:33Z")\ **Posts on this page:** 9\ **Page:** 1
**Author:** ![julienarcin](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/julienarcin/32/10269_2.png) [@julienarcin](https://forums.percona.com/u/julienarcin)\ **Post date:** [April 22, 2023, 10:38am UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580/1 "2023-04-22T10:38:33Z")
Hi, My Xtrabackup is failing after a few hours, and I don’t understand why. The script was working previously, but it seems to be crashing randomly (about 3/4 of the times) since I implemented MySQL replication. I’m doing the backup on the master server. The error is: ```auto 2023-04-22T07:49:18.972506-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./altics_old/users.ibd 2023-04-22T07:49:18.973212-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./altics_old/users.ibd 2023-04-22T07:49:19.632497-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_1.ibd 2023-04-22T07:52:50.183322-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_1.ibd 2023-04-22T07:52:50.542174-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_2.ibd 2023-04-22T07:52:50.542852-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_2.ibd 2023-04-22T07:52:51.002925-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_3.ibd 2023-04-22T07:52:51.003487-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_3.ibd 2023-04-22T07:52:51.417160-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_4.ibd 2023-04-22T07:52:51.418115-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_4.ibd 2023-04-22T07:52:51.727882-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_5.ibd 2023-04-22T07:52:51.730003-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_5.ibd 2023-04-22T07:52:52.066593-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_6.ibd 2023-04-22T07:52:52.067192-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./altics_old/fts_0000000000000508_00000000000002a1_index_6.ibd 2023-04-22T07:52:52.441710-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./mysql.ibd 2023-04-22T07:52:55.090708-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./mysql.ibd 2023-04-22T07:52:55.596008-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./undo_002 2023-04-22T07:53:42.241119-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./undo_002 2023-04-22T07:53:42.668876-00:00 3 [Note] [MY-011825] [Xtrabackup] Streaming ./undo_001 2023-04-22T07:53:45.016203-00:00 3 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./undo_001 2023-04-22T08:08:17.312105-00:00 2 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./altics_old/abc_import.ibd 2023-04-22T08:11:48.062722-00:00 6 [Note] [MY-011825] [Xtrabackup] Done: Streaming ./altics/websites.ibd 2023-04-22T08:58:12.257839-00:00 1 [ERROR] [MY-012894] [InnoDB] Unable to open './#innodb_redo/#ib_redo18131' (error: 1504). 2023-04-22T08:58:12.261142-00:00 1 [ERROR] [MY-011825] [Xtrabackup] read_logfile() failed. 2023-04-22T08:58:12.845628-00:00 0 [ERROR] [MY-011825] [Xtrabackup] log copying failed. ``` Here is the command that is used to generate the backup: ```auto xtrabackup --defaults-extra-file=/root/.my.cnf --backup --parallel=5 --stream=xbstream | pigz | gpg --trust-model always -e -r “My Name” | aws s3 cp --expected-size=$((1024*1024*1024 * 1000)) --cli-connect-timeout=3600 --cli-read-timeout=3600 - s3://bucket/db/$BACKUP_DATE.xbstream.gz.gpg > /home/forge/sync.log ``` For reference, here are some informations: ```auto root@server:~# mysql -V mysql Ver 8.0.30 for Linux on x86_64 (MySQL Community Server - GPL) root@server:~# xtrabackup --version 2023-04-22T10:34:48.623486-00:00 0 [Note] [MY-011825] [Xtrabackup] recognized server arguments: --datadir=/home/forge/data/mysql-data --tmpdir=/home/forge/data/mysql-tmp --server-id=1 --log_bin=/home/forge/data/mysql-data/mysql-bin --innodb_data_home_dir=/home/forge/data/mysql-data --innodb_log_file_size=3G --innodb_log_files_in_group=4 --innodb_buffer_pool_size=42G --innodb_read_io_threads=64 --innodb_write_io_threads=64 --open_files_limit=8192 xtrabackup version 8.0.32-25 based on MySQL server 8.0.32 Linux (x86_64) (revision id: 14f007fb) ``` Do you have any insight ? Thanks a lot ! ---
**Author:** ![julienarcin](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/julienarcin/32/10269_2.png) [@julienarcin](https://forums.percona.com/u/julienarcin)\ **Post date:** [April 22, 2023, 11:41am UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580/2 "2023-04-22T11:41:49Z")
I’ve found this in the doc: > [Percona XtraBackup 8.0.30-23](https://docs.percona.com/percona-xtrabackup/8.0/release-notes/8.0/8.0.30-23.0.html) adds `--register-redo-log-consumer` parameter. The `--register-redo-log-consumer` parameter is disabled by default. When enabled, this parameter lets Percona XtraBackup register as a redo log consumer at the start of the backup. The server does not remove a redo log that Percona XtraBackup (the consumer) has not yet copied. The consumer reads the redo log and manually advances the log sequence number (LSN). The server blocks the writes during the process. Based on the redo log consumption, the server determines when it can purge the log. here: [https://docs.percona.com/percona-xtrabackup/8.0/how\_xtrabackup\_works.html](https://docs.percona.com/percona-xtrabackup/8.0/how_xtrabackup_works.html) I will try it and let you know if the problem is solved. ---
**Author:** ![julienarcin](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/julienarcin/32/10269_2.png) [@julienarcin](https://forums.percona.com/u/julienarcin)\ **Post date:** [April 22, 2023, 10:11pm UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580/3 "2023-04-22T22:11:31Z")
It didn’t work: ```auto 2023-04-22T20:09:49.080871-00:00 7 [Note] [MY-011825] [Xtrabackup] Streaming mysql/general_log_972.sdi to 2023-04-22T20:09:49.080883-00:00 8 [Note] [MY-011825] [Xtrabackup] Done: Streaming performance_schema/socket_summary_b_908.sdi to 2023-04-22T20:09:49.081046-00:00 7 [Note] [MY-011825] [Xtrabackup] Done: Streaming mysql/general_log_972.sdi to 2023-04-22T20:09:49.081615-00:00 10 [Note] [MY-011825] [Xtrabackup] Streaming mysql/general_log.CSM to 2023-04-22T20:09:49.081788-00:00 9 [Note] [MY-011825] [Xtrabackup] Streaming mysql/slow_log.CSV to 2023-04-22T20:09:49.081817-00:00 9 [Note] [MY-011825] [Xtrabackup] Done: Streaming mysql/slow_log.CSV to 2023-04-22T20:09:49.081834-00:00 11 [Note] [MY-011825] [Xtrabackup] Streaming mysql/slow_log.CSM to 2023-04-22T20:09:49.081850-00:00 8 [Note] [MY-011825] [Xtrabackup] Streaming mysql/slow_log_974.sdi to 2023-04-22T20:09:49.081853-00:00 10 [Note] [MY-011825] [Xtrabackup] Done: Streaming mysql/general_log.CSM to 2023-04-22T20:09:49.082019-00:00 11 [Note] [MY-011825] [Xtrabackup] Done: Streaming mysql/slow_log.CSM to 2023-04-22T20:09:49.082028-00:00 8 [Note] [MY-011825] [Xtrabackup] Done: Streaming mysql/slow_log_974.sdi to 2023-04-22T20:09:49.150480-00:00 0 [Note] [MY-011825] [Xtrabackup] Finished backing up non-InnoDB tables and files 2023-04-22T20:09:49.150522-00:00 0 [Note] [MY-011825] [Xtrabackup] Executing FLUSH NO_WRITE_TO_BINLOG BINARY LOGS 2023-04-22T20:10:06.140096-00:00 0 [Note] [MY-011825] [Xtrabackup] Selecting LSN and binary log position from p_s.log_status 2023-04-22T20:10:06.195741-00:00 0 [Note] [MY-011825] [Xtrabackup] Streaming /home/forge/data/mysql-data/mysql-bin.001868 to up to position 21310 2023-04-22T20:10:06.195810-00:00 0 [Note] [MY-011825] [Xtrabackup] Done: Streaming /home/forge/data/mysql-data/mysql-bin.001868 to 2023-04-22T20:10:06.195946-00:00 0 [Note] [MY-011825] [Xtrabackup] Streaming 2023-04-22T20:10:06.195964-00:00 0 [Note] [MY-011825] [Xtrabackup] Done: Streaming file 2023-04-22T20:10:06.218565-00:00 0 [Note] [MY-011825] [Xtrabackup] Streaming 2023-04-22T20:10:06.218610-00:00 0 [Note] [MY-011825] [Xtrabackup] Done: Streaming file 2023-04-22T20:10:06.218644-00:00 0 [Note] [MY-011825] [Xtrabackup] Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS... 2023-04-22T20:10:06.241097-00:00 0 [Note] [MY-011825] [Xtrabackup] The latest check point (for incremental): '21429372624635' 2023-04-22T20:10:06.241141-00:00 0 [Note] [MY-011825] [Xtrabackup] Stopping log copying thread at LSN 21435121924755 2023-04-22T21:04:38.375485-00:00 1 [ERROR] [MY-012894] [InnoDB] Unable to open './#innodb_redo/#ib_redo18181' (error: 1504). 2023-04-22T21:04:38.375534-00:00 1 [ERROR] [MY-011825] [Xtrabackup] read_logfile() failed. 2023-04-22T21:04:38.376303-00:00 0 [ERROR] [MY-011825] [Xtrabackup] last checkpoint LSN (21429372624635) is larger than last copied LSN (21372158273024). 2023-04-22T21:04:38.376331-00:00 0 [ERROR] [MY-011825] [Xtrabackup] Error stopping copy thread at LSN 21435121924755 ``` ---
**Author:** ![kedarpercona](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/kedarpercona/32/809_2.png) [@kedarpercona](https://forums.percona.com/u/kedarpercona)\ **Post date:** [April 23, 2023, 12:43pm UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580/4 "2023-04-23T12:43:31Z")
Greetings Julienarcin, Welcome to Percona Community. You might be [stung by this bug](https://forums.percona.com/t/xtrabackup-8-0-30-issue-error-my-011825-xtrabackup-read-logfile-failed/21184) and it is fixed in XtraBackup 8.0.32-26. Can you upgrade to latest Xtrabackup and try again? Also backup on master is not a good idea, let’s think about moving that to replica. Good luck, K. ---
**Author:** ![michael.villegas](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/michael.villegas/32/6933_2.png) [@michael.villegas](https://forums.percona.com/u/michael.villegas)\ **Post date:** [April 23, 2023, 1:20pm UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580/5 "2023-04-23T13:20:29Z")
Hello Julienarcin, I would try increasing the redo log size, as I believe it might be related to having a small redo log that is not able to keep all the records requested by xtrabackup. Given that you are on MySQL 8.0.30, you can take advantage of parameter [innodb\_redo\_log\_capacity](https://dev.mysql.com/doc/refman/8.0/en/innodb-parameters.html#sysvar_innodb_redo_log_capacity). This parameter is dynamic, so you don’t need to restart your server to change it. Please verify the current size of your redo log and try to increase it. If you had PMM you can get a very educated guess about the size looking at the graph “Innodb Log File Usage Hourly”. The idea is that you have a redo log size big enough to hold at least one hour of transactions. ---
**Author:** ![julienarcin](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/julienarcin/32/10269_2.png) [@julienarcin](https://forums.percona.com/u/julienarcin)\ **Post date:** [April 24, 2023, 5:13am UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580/6 "2023-04-24T05:13:23Z")
Hi! Thanks for your answers 🙏 I’ve updated xtrabackup to version 8.0.32-26 and moved the backup to the replica. And I’ve set-up the innodb\_redo\_log\_capacity to 128Gb (it was previously at 64Gb). Can I have some problems with such a high value? (other than disk usage) The backup is running now, I will keep you updated. ---
**Author:** ![julienarcin](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/julienarcin/32/10269_2.png) [@julienarcin](https://forums.percona.com/u/julienarcin)\ **Post date:** [April 24, 2023, 7:51am UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580/7 "2023-04-24T07:51:09Z")
Backup has been completed successfully, thanks for your help 🙏 ---
**Author:** ![kedarpercona](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/kedarpercona/32/809_2.png) [@kedarpercona](https://forums.percona.com/u/kedarpercona)\ **Post date:** [April 24, 2023, 9:45am UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580/8 "2023-04-24T09:45:29Z")
Awesome @julienarcin, Best wishes ahead. ---
**Author:** ![matthewb](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/matthewb/32/34_2.png) [@matthewb](https://forums.percona.com/u/matthewb)\ **Post date:** [April 24, 2023, 2:39pm UTC](https://forums.percona.com/t/xtrabackup-fails-after-some-time/21580/9 "2023-04-24T14:39:12Z")
Backups from replicas are good ONLY if you have ensured the data is an exact copy from source. Please use [pt-table-checksum — Percona Toolkit Documentation](https://docs.percona.com/percona-toolkit/pt-table-checksum.html) to ensure the data is the same BEFORE you backup from a replica.