Failure Analysis | Xtrabackup Backup Failure Caused by DDL

Author: Zhao Liming

A member of the MySQL DBA team of Aikesheng, familiar with databases such as Oracle and MySQL, good at diagnosing database performance problems, analyzing transaction and lock problems, etc., responsible for handling the daily operation and maintenance problems of customer MySQL and our self-developed DMP platform. Related technologies are of great interest.

Source of this article: original contribution

*The original content is produced by the open source community of Aikesheng, and the original content shall not be used without authorization. For reprinting, please contact the editor and indicate the source.

---

background

Recently, the customer reported that the physical backup of a production business system failed in the early morning (a cluster with one master and two slaves only performs Xtrabackup full backup on two slave databases, and the master database does not participate in the backup). It is necessary to investigate the cause of the backup failure.

case analysis

Since the customer uses our company's DMP database management platform, when the backup fails, a FAIL flag file will be written in the backup directory, and then the residual files will be rolled back. At this time, Xtrabackup's own logs can no longer be viewed. , but you can get the backup failure information through the log of the urman-agent component (responsible for backup and recovery), the following is the error information on the two slave libraries at that time

• log from library 1

• log from library 2

Although the two slave libraries report errors at different times, the content of the errors reported is the same, and both point to "DDL operations that do not record redo logs":

[FATAL] InnoDB: An optimized(without redo logging) DDL operation has been performed. All modified pages may not have been flushed to the disk yet.
PXB will not be able to take a consistent backup. Retry the backup operation

It was confirmed that the customer did perform a DDL business change in the early morning. The content of the change was to create a new table and add fields to the existing two tables. The content of the output is consistent, it seems that the problem is likely to be in the DDL operation of adding fields

So what is the operation of DDL that does not record redo? Why is there DDL that doesn't record redo?

First of all, we know that adding fields to a table in MySQL 5.7 belongs to ONLINE DLL, which will rebuild the table, but allows concurrent DML (PS: MySQL 8.0 adding fields does not require rebuilding the table)

Since MySQL uses an index-organized table (IOT), the index on the table also needs to be rebuilt. Due to the method of ALGORITHM=INPLACE, concurrent DML is allowed.

In MySQL 5.7, there is an optimization for the index, that is, Sorted Index Builds, which will fill the index records by bulk load and bottom-up when creating or rebuilding the index.

<br/>

When the index is created in the Sorted Index Build method, it will not be recorded in the redo log, and this is the scenario of "An optimized (without redo logging) DDL operation" described in the previous Xtrabackup error report.

Percona calls this a bug in Xtrabackup 2.4.x, mainly to avoid getting a wrong backup set. Once a DDL operation that does not record redo is detected, the backup process will be terminated, and the PXB version in the customer's production environment is running is 2.4.5

In response to this problem, Percona added the --lock-ddl, --lock-ddl-timeout, --lock-ddl-per-table parameters in Xtrabackup 2.4.8 and later versions, making it You can add backup locks during backup, or add MDL locks to tables to block other DDL operations, so that the backup can be completed successfully

After the reason is clear, we know how to solve the problem. Finally, we perform manual backup on 2 slave databases respectively. Each instance (about 500G) takes about 2 hours and 40 minutes to complete the backup.

Percona provides a solution to backup failure by adding parameters. If the PXB version cannot be upgraded temporarily, is there a solution only at the MySQL level? Actually it is possible.

Let's test the scenarios mentioned above.

Scenario test

Environmental preparation

Create test table

 /usr/local/sysbench/share/sysbench# sysbench oltp_insert.lua --db-driver=mysql --threads=256 --time=300 --mysql-host=10.186.60.68 --mysql-port=3332 --mysql-user=zlm --mysql-password=zlm --tables=2 --table-size=2000000 --db-ps-mode=disable --report-interval=10 prepare
sysbench 1.0.17 (using bundled LuaJIT 2.1.0-beta2)

Initializing worker threads...

Creating table 'sbtest2'...
Inserting 2000000 records into 'sbtest2'
Creating table 'sbtest1'...
Inserting 2000000 records into 'sbtest1'
Creating a secondary index on 'sbtest2'...
Creating a secondary index on 'sbtest1'...

Prepare script (batch_ddl.sh)

 -- 该脚本的作用是对测试表进行持续的DDL操作（增加/删除字段，模拟客户的业务变更）
dmp2 (master) ~/script# echo > batch_ddl.sh
dmp2 (master) ~/script# cat << EOF > batch_ddl.sh
> #!/bin/bash
> echo "alter table sbtest1 add sid varchar(32);"|/data/mysql/base/5.7.36/bin/mysql -h10.186.60.68 -P3332 -uzlm -pzlm sbtest
> sleep 1
> echo "alter table sbtest2 add sid varchar(32);"|/data/mysql/base/5.7.36/bin/mysql -h10.186.60.68 -P3332 -uzlm -pzlm sbtest
> sleep 10
> echo "alter table sbtest1 drop sid;"|/data/mysql/base/5.7.36/bin/mysql -h10.186.60.68 -P3332 -uzlm -pzlm sbtest
> sleep 1
> echo "alter table sbtest2 drop sid;"|/data/mysql/base/5.7.36/bin/mysql -h10.186.60.68 -P3332 -uzlm -pzlm sbtest
> EOF

Scenario 1: Concurrent DDL execution during backup (no extra parameters)

execute script

 dmp2 (master) ~/script# while true; do bash batch_ddl.sh; done
mysql: [Warning] Using a password on the command line interface can be insecure.
mysql: [Warning] Using a password on the command line interface can be insecure.
... 略

Verify that the script works (observe the sid field of the test table, sometimes, sometimes not)

 zlm@10.186.60.68 [sbtest]> show create table sbtest1\G
*************************** 1. row ***************************
       Table: sbtest1
Create Table: CREATE TABLE `sbtest1` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `k` int(11) NOT NULL DEFAULT '0',
  `c` char(120) NOT NULL DEFAULT '',
  `pad` char(60) NOT NULL DEFAULT '',
  PRIMARY KEY (`id`),
  KEY `k_1` (`k`)
) ENGINE=InnoDB AUTO_INCREMENT=2000001 DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

zlm@10.186.60.68 [sbtest]> show create table sbtest1\G
*************************** 1. row ***************************
       Table: sbtest1
Create Table: CREATE TABLE `sbtest1` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `k` int(11) NOT NULL DEFAULT '0',
  `c` char(120) NOT NULL DEFAULT '',
  `pad` char(60) NOT NULL DEFAULT '',
  `sid` varchar(32) DEFAULT NULL,
  PRIMARY KEY (`id`),
  KEY `k_1` (`k`)
) ENGINE=InnoDB AUTO_INCREMENT=2000001 DEFAULT CHARSET=utf8
1 row in set (0.00 sec)

Perform Xtrabackup backup

 -- 检查Xtrabackup的版本（客户生产环境为2.4.5）
dmp2 /data/urman-agent/bin# ./xtrabackup --version
xtrabackup: recognized server arguments: --datadir=/var/lib/mysql
./xtrabackup version 2.4.20 based on MySQL server 5.7.26 Linux (x86_64) (revision id: c8b4056)

-- 执行备份
./xtrabackup --defaults-file=/data/mysql/mysql3332/my.cnf \
--user=zlm --password=zlm --target-dir=/data/backup/`date +%F_%H-%M-%S` \
--backup --host=127.0.0.1 --port=3332 --parallel 4 \
--check-privileges --no-version-check
... 略
220512 15:11:11 [01] Copying ./sbtest/db.opt to /data/backup/2022-05-12_15-10-56/sbtest/db.opt
220512 15:11:11 [01]        ...done
220512 15:11:11 [01] Copying ./sbtest/sbtest2.frm to /data/backup/2022-05-12_15-10-56/sbtest/sbtest2.frm
220512 15:11:11 [01]        ...done
220512 15:11:11 [01] Copying ./sbtest/sbtest1.frm to /data/backup/2022-05-12_15-10-56/sbtest/sbtest1.frm
220512 15:11:11 [01]        ...done
220512 15:11:11 Finished backing up non-InnoDB tables and files
220512 15:11:11 [00] Writing /data/backup/2022-05-12_15-10-56/xtrabackup_binlog_info
220512 15:11:11 [00]        ...done
220512 15:11:11 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
xtrabackup: The latest check point (for incremental): '250912794909'
xtrabackup: Stopping log copying thread.
.InnoDB: Last flushed lsn: 250912650797 load_index lsn 250913206547
InnoDB: An optimized (without redo logging) DDL operation has been performed. All modified pages may not have been flushed to the disk yet.
PXB will not be able to make a consistent backup. Retry the backup operation
dmp2 /data/urman-agent/bin#

## 以上步骤，直接复现了客户生产环境的故障场景

kill script

 mysql: [Warning] Using a password on the command line interface can be insecure.
mysql: [Warning] Using a password on the command line interface can be insecure.
mysql: [Warning] Using a password on the command line interface can be insecure.
mysql: [Warning] Using a password on the command line interface can be insecure.
mysql: [Warning] Using a password on the command line interface can be insecure.
mysql: [Warning] Using a password on the command line interface can be insecure.
^C^C -- query aborted
ERROR 1317 (70100) at line 1: Query execution was interrupted

summary

By default, even in higher versions of Xtrabackup, if DDL is executed concurrently during backup and DDL lock parameters (--lock-ddl, --lock-ddl-per-table) are not specified, the backup will fail

Scenario 2: DDL is executed concurrently during backup (add --lock-ddl parameter)

execute script

 dmp2 (master) ~/script# while true; do bash batch_ddl.sh; done
mysql: [Warning] Using a password on the command line interface can be insecure.
mysql: [Warning] Using a password on the command line interface can be insecure.
... 略

Perform Xtrabackup backup

 dmp2 /data/urman-agent/bin# ./xtrabackup --defaults-file=/data/mysql/mysql3332/my.cnf --user=zlm --password=zlm --target-dir=/data/backup/`date +%F_%H-%M-%S` --backup --host=127.0.0.1 --port=3332 --parallel 4 --check-privileges --no-version-check --lock-ddl
xtrabackup: recognized server arguments: --datadir=/data/mysql/mysql3332/data --tmpdir=/data/mysql/mysql3332/tmp --open_files_limit=65535 --server-id=31782647 --log_bin=/data/mysql/mysql3332/logs/mysql-bin --innodb_buffer_pool_size=100M --innodb_data_file_path=ibdata1:100M:autoextend --innodb_flush_log_at_trx_commit=1 --innodb_log_buffer_size=8M --innodb_log_file_size=100M --innodb_log_files_in_group=3 --innodb_max_dirty_pages_pct=50 --innodb_file_per_table=1 --innodb_io_capacity=2000 --innodb_flush_method=O_DIRECT --innodb_flush_log_at_trx_commit=1 --parallel=4
xtrabackup: recognized client arguments: --port=3332 --socket=/tmp/mysql3332.sock --user=zlm --password=* --target-dir=/data/backup/2022-05-12_16-02-37 --backup=1 --host=127.0.0.1 --port=3332 --check-privileges=1 --no-version-check=1 --lock-ddl=1
220512 16:02:37 Connecting to MySQL server host: 127.0.0.1, user: zlm, password: set, port: 3332, socket: /tmp/mysql3332.sock
Using server version 5.7.36-log
220512 16:02:37 Error: LOCK TABLES FOR BACKUP is not supported.

## MySQL社区版不支持--lock-ddl参数，直接报错

summary

lock-ddl actually executes the backup lock (LOCK TABLES FOR BACKUP) to block the DDL statement during backup. Since only Percona Server supports this syntax, the MySQL Community Edition cannot simulate it for the time being, and the MariaDB branch also does not support this syntax.

Scenario 3: DDL is executed concurrently during backup (add --lock-ddl-per-table parameter)

execute script

 dmp2 (master) ~/script# while true; do bash batch_ddl.sh; done
mysql: [Warning] Using a password on the command line interface can be insecure.
mysql: [Warning] Using a password on the command line interface can be insecure.
... 略

Perform Xtrabackup backup

 dmp2 /data/urman-agent/bin# ./xtrabackup --defaults-file=/data/mysql/mysql3332/my.cnf --user=zlm --password=zlm --target-dir=/data/backup/`date +%F_%H-%M-%S` --backup --host=127.0.0.1 --port=3332 --parallel 4 --check-privileges --no-version-check --lock-ddl-per-table
xtrabackup: recognized server arguments: --datadir=/data/mysql/mysql3332/data --tmpdir=/data/mysql/mysql3332/tmp --open_files_limit=65535 --server-id=31782647 --log_bin=/data/mysql/mysql3332/logs/mysql-bin --innodb_buffer_pool_size=100M --innodb_data_file_path=ibdata1:100M:autoextend --innodb_flush_log_at_trx_commit=1 --innodb_log_buffer_size=8M --innodb_log_file_size=100M --innodb_log_files_in_group=3 --innodb_max_dirty_pages_pct=50 --innodb_file_per_table=1 --innodb_io_capacity=2000 --innodb_flush_method=O_DIRECT --innodb_flush_log_at_trx_commit=1 --parallel=4
xtrabackup: recognized client arguments: --port=3332 --socket=/tmp/mysql3332.sock --user=zlm --password=* --target-dir=/data/backup/2022-05-12_16-07-12 --backup=1 --host=127.0.0.1 --port=3332 --check-privileges=1 --no-version-check=1 --lock-ddl-per-table=1
220512 16:07:12 Connecting to MySQL server host: 127.0.0.1, user: zlm, password: set, port: 3332, socket: /tmp/mysql3332.sock
Using server version 5.7.36-log
./xtrabackup version 2.4.20 based on MySQL server 5.7.26 Linux (x86_64) (revision id: c8b4056)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /data/mysql/mysql3332/data
xtrabackup: open files limit requested 65535, set to 65535
xtrabackup: using the following InnoDB configuration:
xtrabackup:   innodb_data_home_dir = .
xtrabackup:   innodb_data_file_path = ibdata1:100M:autoextend
xtrabackup:   innodb_log_group_home_dir = ./
xtrabackup:   innodb_log_files_in_group = 3
xtrabackup:   innodb_log_file_size = 104857600
xtrabackup: using O_DIRECT
InnoDB: Number of pools: 1
220512 16:07:13 >> log scanned up to (250920385317)
xtrabackup: Generating a list of tablespaces 
... 略
220512 16:07:14 Locking MDL for `sbtest`.`sbtest1`  ## 备份sbtest1表数据前，先加上MDL锁
220512 16:07:14 [04] Copying ./sbtest/sbtest1.ibd to /data/backup/2022-05-12_16-07-12/sbtest/sbtest1.ibd
220512 16:07:14 [02] Copying ./sbtest/sbtest2.ibd to /data/backup/2022-05-12_16-07-12/sbtest/sbtest2.ibd
220512 16:07:15 >> log scanned up to (250920494721)
220512 16:07:16 >> log scanned up to (250920494832)
220512 16:07:17 >> log scanned up to (250920494841)
220512 16:07:18 >> log scanned up to (250920494841)
220512 16:07:19 [02]        ...done
220512 16:07:19 >> log scanned up to (250920494841)
220512 16:07:20 >> log scanned up to (250920494841)
220512 16:07:20 [01]        ...done
220512 16:07:20 [04]        ...done
220512 16:07:21 Starting to backup non-InnoDB tables and files
... 略
220512 16:07:21 [01] Copying ./sbtest/sbtest2.frm to /data/backup/2022-05-12_16-07-12/sbtest/sbtest2.frm
220512 16:07:21 [01]        ...done
220512 16:07:21 [01] Copying ./sbtest/sbtest1.frm to /data/backup/2022-05-12_16-07-12/sbtest/sbtest1.frm
220512 16:07:21 [01]        ...done
220512 16:07:21 Finished backing up non-InnoDB tables and files
220512 16:07:21 [00] Writing /data/backup/2022-05-12_16-07-12/xtrabackup_binlog_info
220512 16:07:21 [00]        ...done
220512 16:07:21 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
xtrabackup: The latest check point (for incremental): '250920494832'
xtrabackup: Stopping log copying thread.
.220512 16:07:21 >> log scanned up to (250920494841)

220512 16:07:21 Executing UNLOCK TABLES
220512 16:07:21 All tables unlocked
220512 16:07:21 [00] Copying ib_buffer_pool to /data/backup/2022-05-12_16-07-12/ib_buffer_pool
220512 16:07:21 [00]        ...done
220512 16:07:21 Backup created in directory '/data/backup/2022-05-12_16-07-12/'
MySQL binlog position: filename 'mysql-bin.000012', position '472261259', GTID of the last change '0e795785-0ee5-11ec-9350-02000aba3c44:1-1619'
220512 16:07:21 [00] Writing /data/backup/2022-05-12_16-07-12/backup-my.cnf
220512 16:07:21 [00]        ...done
220512 16:07:21 [00] Writing /data/backup/2022-05-12_16-07-12/xtrabackup_info
220512 16:07:21 [00]        ...done
220512 16:07:21 Unlocking MDL for all tablesxtrabackup: Transaction log of lsn (250920249371) to (250920494841) was copied.  ## 释放所有表上的MDL锁
220512 16:07:22 completed OK!

kill script

 ... 略
mysql: [Warning] Using a password on the command line interface can be insecure.
^C^C -- query aborted
ERROR 1317 (70100) at line 1: Query execution was interrupted
mysql: [Warning] Using a password on the command line interface can be insecure.
^C^C -- query aborted
ERROR 1317 (70100) at line 1: Query execution was interrupted
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1060 (42S21) at line 1: Duplicate column name 'sid'
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1060 (42S21) at line 1: Duplicate column name 'sid'

^C
dmp2 (master) ~/script#

summary

Using the --lock-ddl-per-table parameter during backup will add an MDL lock before copying the ibd file of each table to block the execution of DDL statements on the table until the backup is completed, DDL can continue to execute

Scenario 4: DDL is executed concurrently during backup (set MySQL parameter: old_alter_table=1)

Turn off the ONLINE DDL feature

 zlm@10.186.60.68 [(none)]> set global old_alter_table=1;
Query OK, 0 rows affected (0.00 sec)

zlm@10.186.60.68 [(none)]> show variables like 'old_alter_table';
+-----------------+-------+
| Variable_name   | Value |
+-----------------+-------+
| old_alter_table | OFF   |
+-----------------+-------+
1 row in set (0.00 sec)

zlm@10.186.60.68 [(none)]> exit
Bye
dmp2 (master) ~/script# m3332 -Nse "show variables like 'old_alter_table';"
mysql: [Warning] Using a password on the command line interface can be insecure.
old_alter_table ON

execute script

 dmp2 (master) ~/script# while true; do bash batch_ddl.sh; done
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1060 (42S21) at line 1: Duplicate column name 'sid'
mysql: [Warning] Using a password on the command line interface can be insecure.
ERROR 1060 (42S21) at line 1: Duplicate column name 'sid'
mysql: [Warning] Using a password on the command line interface can be insecure.
mysql: [Warning] Using a password on the command line interface can be insecure.
... 略

Perform Xtrabackup backup

 dmp2 /data/urman-agent/bin# ./xtrabackup --defaults-file=/data/mysql/mysql3332/my.cnf --user=zlm --password=zlm --target-dir=/data/backup/`date +%F_%H-%M-%S` --backup --host=127.0.0.1 --port=3332 --parallel 4 --check-privileges --no-version-check
xtrabackup: recognized server arguments: --datadir=/data/mysql/mysql3332/data --tmpdir=/data/mysql/mysql3332/tmp --open_files_limit=65535 --server-id=31782647 --log_bin=/data/mysql/mysql3332/logs/mysql-bin --innodb_buffer_pool_size=100M --innodb_data_file_path=ibdata1:100M:autoextend --innodb_flush_log_at_trx_commit=1 --innodb_log_buffer_size=8M --innodb_log_file_size=100M --innodb_log_files_in_group=3 --innodb_max_dirty_pages_pct=50 --innodb_file_per_table=1 --innodb_io_capacity=2000 --innodb_flush_method=O_DIRECT --innodb_flush_log_at_trx_commit=1 --parallel=4
xtrabackup: recognized client arguments: --port=3332 --socket=/tmp/mysql3332.sock --user=zlm --password=* --target-dir=/data/backup/2022-05-12_16-48-00 --backup=1 --host=127.0.0.1 --port=3332 --check-privileges=1 --no-version-check=1
220512 16:48:00 Connecting to MySQL server host: 127.0.0.1, user: zlm, password: set, port: 3332, socket: /tmp/mysql3332.sock
Using server version 5.7.36-log
./xtrabackup version 2.4.20 based on MySQL server 5.7.26 Linux (x86_64) (revision id: c8b4056)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /data/mysql/mysql3332/data
xtrabackup: open files limit requested 65535, set to 65535
xtrabackup: using the following InnoDB configuration:
xtrabackup:   innodb_data_home_dir = .
xtrabackup:   innodb_data_file_path = ibdata1:100M:autoextend
xtrabackup:   innodb_log_group_home_dir = ./
xtrabackup:   innodb_log_files_in_group = 3
xtrabackup:   innodb_log_file_size = 104857600
xtrabackup: using O_DIRECT
InnoDB: Number of pools: 1
220512 16:48:02 >> log scanned up to (251659945145)
xtrabackup: Generating a list of tablespaces
... 略
220512 16:48:03 [02] Copying ./zlm/t.ibd to /data/backup/2022-05-12_16-48-00/zlm/t.ibd
220512 16:48:03 [03]        ...done
220512 16:48:03 [02]        ...done
220512 16:48:03 [03] Copying ./sbtest/sbtest2.ibd to /data/backup/2022-05-12_16-48-00/sbtest/sbtest2.ibd
220512 16:48:03 [04] Copying ./zlm1/t1.ibd to /data/backup/2022-05-12_16-48-00/zlm1/t1.ibd
220512 16:48:03 [02] Copying ./sbtest/sbtest1.ibd to /data/backup/2022-05-12_16-48-00/sbtest/sbtest1.ibd
220512 16:48:03 [04]        ...done
220512 16:48:03 [04] Copying ./sbtest/#sql-c61_30133.ibd to /data/backup/2022-05-12_16-48-00/sbtest/#sql-c61_30133.ibd
220512 16:48:04 >> log scanned up to (251669706184)
220512 16:48:04 [04]        ...done
220512 16:48:05 >> log scanned up to (251672429294)
220512 16:48:06 >> log scanned up to (251675700622)
220512 16:48:07 >> log scanned up to (251678520383)
220512 16:48:08 >> log scanned up to (251681195105)
220512 16:48:09 [02]        ...done
220512 16:48:09 >> log scanned up to (251683273712)
220512 16:48:09 [01]        ...done
220512 16:48:10 >> log scanned up to (251694062575)
220512 16:48:11 >> log scanned up to (251707703017)
220512 16:48:12 [03]        ...done
220512 16:48:12 >> log scanned up to (251713134341)
220512 16:48:12 Executing FLUSH NO_WRITE_TO_BINLOG TABLES...
220512 16:48:13 >> log scanned up to (251721786959)
... 略
220512 16:48:38 [01] Copying ./sbtest/sbtest1.frm to /data/backup/2022-05-12_16-48-00/sbtest/sbtest1.frm
220512 16:48:38 [01]        ...done
220512 16:48:38 [01] Copying ./sbtest/sbtest2.frm to /data/backup/2022-05-12_16-48-00/sbtest/sbtest2.frm
220512 16:48:38 [01]        ...done
220512 16:48:38 Finished backing up non-InnoDB tables and files
220512 16:48:38 [00] Writing /data/backup/2022-05-12_16-48-00/xtrabackup_binlog_info
220512 16:48:38 [00]        ...done
220512 16:48:38 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
xtrabackup: The latest check point (for incremental): '251977260800'
xtrabackup: Stopping log copying thread.
.220512 16:48:38 >> log scanned up to (252017389382)

220512 16:48:38 Executing UNLOCK TABLES
220512 16:48:38 All tables unlocked
220512 16:48:38 [00] Copying ib_buffer_pool to /data/backup/2022-05-12_16-48-00/ib_buffer_pool
220512 16:48:38 [00]        ...done
220512 16:48:38 Backup created in directory '/data/backup/2022-05-12_16-48-00/'
MySQL binlog position: filename 'mysql-bin.000012', position '472262307', GTID of the last change '0e795785-0ee5-11ec-9350-02000aba3c44:1-1625'
220512 16:48:38 [00] Writing /data/backup/2022-05-12_16-48-00/backup-my.cnf
220512 16:48:38 [00]        ...done
220512 16:48:38 [00] Writing /data/backup/2022-05-12_16-48-00/xtrabackup_info
220512 16:48:38 [00]        ...done
xtrabackup: Transaction log of lsn (251552488790) to (252017389382) was copied.
220512 16:48:38 completed OK!
dmp2 /data/urman-agent/bin#

## Xtrabackup备份日志中没有发现MDL锁，备份也顺利地执行完了，说明启用old_alter_table也能够解决备份失败的问题

kill script

 ... 略
mysql: [Warning] Using a password on the command line interface can be insecure.
^C^C -- query aborted
ERROR 1317 (70100) at line 1: Query execution was interrupted
mysql: [Warning] Using a password on the command line interface can be insecure.
^C^C -- query aborted
ERROR 1317 (70100) at line 1: Query execution was interrupted
^C
04:48 PM dmp2 (master) ~/script#

summary

When the ONLINE DDL feature is turned off (old_alter_table=1), that is, when executing DDL, it is forced to use ALGORITHM=COPY instead of ALGORITHM=INPLACE. At this time, even if the DDL lock parameter is not used during backup, it will not affect the backup execution. Note that turning off the ONLINE DDL feature will affect DML concurrency on the table and is not recommended.

Summarize

1. DDL business change operations should avoid backup windows as much as possible
2. The optimization of Sorted Index Builds for index creation conflicts with PXB 2.4.x backup. It needs to be replaced with a higher version of PXB, and the backup lock or MDL lock parameters should be added to avoid backup failure.
3. MySQL itself can also solve the problem of backup failure by turning off the ONLINE DDL feature, but it will affect DML concurrency, and the pros and cons need to be weighed

Reference link

https://dev.mysql.com/doc/refman/5.7/en/sorted-index-builds.html

https://dev.mysql.com/doc/refman/5.7/en/innodb-online-ddl-operations.html#online-ddl-column-operations

https://dev.mysql.com/doc/refman/5.7/en/server-system-variables.html#sysvar_old_alter_table