The Ultimate Guide to High Availability with MariaDB

mariabackup 10.11.3-MariaDB incremental backup taking long time due to "Waiting for log copy thread to read lsn"

Incremental backups taking long time due to "Waiting for log copy thread to read lsn 11214585412" which takes 3 minutes. Everything else is blazing fast. If i restart mariadb incremental backups are fast afterwards. I suspect that the long wait time "Waiting for log copy ...." is related to the binlog filesize pm-bin.0000X.

Any ideas how I can keep mariabackup fast without restarting mariadb?

Enviropnment: mariabackup based on MariaDB server 10.11.3-MariaDB debian-linux-gnu (x86_64) on DEBIAN 12

Command: mariabackup --backup --extra-lsndir=... --incremental-basedir=.... --stream=xbstream

Log Output (excerpt): [00] 2023-10-05 18:11:38 Connecting to MariaDB server host [01] 2023-10-05 18:11:43 Streaming ./pm_ng/userrights.frm to <STDOUT> [01] 2023-10-05 18:11:43 ...done [00] 2023-10-05 18:11:43 Finished backing up non-InnoDB tables and files [01] 2023-10-05 18:11:43 Streaming /var/lib/mysqlaria_log_control to <STDOUT> [01] 2023-10-05 18:11:43 ...done [01] 2023-10-05 18:11:43 Streaming /var/lib/mysqlaria_log.00000001 to <STDOUT> [01] 2023-10-05 18:11:43 ...done [00] 2023-10-05 18:11:43 Waiting for log copy thread to read lsn 11214585412 [00] 2023-10-05 18:14:35 Streaming xtrabackup_binlog_info [00] 2023-10-05 18:14:35 ...done [00] 2023-10-05 18:14:35 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS... [00] 2023-10-05 18:14:35 mariabackup: The latest check point (for incremental): '10845015067' mariabackup: Stopping log copying thread. [00] 2023-10-05 18:14:35 Executing BACKUP STAGE END [00] 2023-10-05 18:14:35 All tables unlocked [00] 2023-10-05 18:14:35 Backup created in directory '/home/cebert/xtrabackup_backupfiles/' [00] 2023-10-05 18:14:35 MySQL binlog position: filename 'pm-bin.000012', position '440233284', GTID of the last change '0-8333-1236501' [00] 2023-10-05 18:14:35 Streaming backup-my.cnf [00] 2023-10-05 18:14:35 ...done [00] 2023-10-05 18:14:35 Streaming xtrabackup_info [00] 2023-10-05 18:14:35 ...done [00] 2023-10-05 18:14:35 Redo log (from LSN 10845015067 to 11214589787) was copied. [00] 2023-10-05 18:14:35 completed OK!

Following settings are configured in MariaDb:

[mariadb] group_concat_max_len=65000

  1. default setting ONLY_FULL_GROUP_BY is removed sql_mode = "STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION"

max_allowed_packet=16M innodb_flush_log_at_trx_commit=1 innodb_file_per_table=1 innodb_buffer_pool_size=10G innodb_log_file_size=1G

server_id=8333 log_bin max_binlog_size=1G log-basename=pm binlog-format=mixed expire_logs_days=14

slow_query_log slow_query_log_file=/var/log/mysql/mysql-slow.log long_query_time=0.5

log_error=/var/log/mysql/error.log

[mysqldump] quick max_allowed_packet=32M

Answer Answered by Marko Mäkelä in this comment.

Your problem description is very similar to MDEV-31410. You could SET GLOBAL innodb_max_dirty_pages_pct_lwm=0.001; to make the InnoDB log checkpoint advance more often. This should become unnnecessary once MDEV-30000 has been fixed.

To my knowledge, FLUSH LOGS and PURGE LOGS have nothing to do with the InnoDB storage engine.

Comments

Comments loading...
Content reproduced on this site is the property of its respective owners, and this content is not reviewed in advance by MariaDB. The views, information and opinions expressed by this content do not necessarily represent those of MariaDB or any other party.