这个问题是好久以前的问题了,今天看自己的笔记,发现了这个问题,当时没有进行细看,想着现在复现一下。

 

1、半夜收到测试数据库备份告警:


报警内容就是8002端口,备份失败,因为有慢查询导致的。

白天想着手动跑一下备份命令:

mydumper -u root -S /tmp/mysql_8002.sock --kill-long-queries --regex '^(?!(test|information_schema|performance_schema|sys))' -o /data0/backup/sqldump/2021-06-11 --triggers --events --routines -c

报错:

** (mydumper:40672): WARNING **: Killed a query that was running for 64s

此时又收到了主从状态的告警,登上从库show slave status\G;可以看到:

mydumper mysql mydumper mysql8_sql


当时解决的办法是,在备份脚本中添加stop slave;然后再备份,备份完成后再start slave;该库也比较小,备份很快,不会产生太多延迟,再加上是凌晨备份,业务较少。

 

问题过去很久了,记不太清当时的场景了,悔恨当时没有详细的记录啊。

 

2、现在猜测是有大事务,现在就来模拟一下大事务的场景,看看有没有这种现象发生:

数据库版本为8.0.21,mydumper版本为0.10.x

首先测试表有三条数据:

select * from t1;

+----+------+

| id | age |

+----+------+

| 1 | 111 |

| 2 | 222 |

| 33 | 3 |

+----+------+

在主库开启事务执行update,并阻塞70s:

mysql> begin;

Query OK, 0 rows affected (0.00 sec)

 

mysql> update t1 set id=sleep(70)+3 where id=33;

Query OK, 1 row affected, 1 warning (20.01 sec)

Rows matched: 1 Changed: 1 Warnings: 1

 

mysql> commit;

 

3、此时在从库查看线程:


可以估计一下秒数,当超过60s的时候,执行备份命令:

mydumper -u root -S /tmp/mysql_8002.sock --kill-long-queries --regex '^(?!(test|information_schema|performance_schema|sys))' -o /data0/backup/sqldump/2021-06-11 --triggers --events --routines -c

此时报错:** (mydumper:37592): WARNING **: 16:43:23.791: Killed a query that was running for 63s

从库主从同步也报同样的错误。

复现成功,说明当时可能是有超过60s的大事务在执行。

 

4、mydumper中有两个重要的参数,说明一下:

① --long-query-guard :

该参数可以修改备份被阻塞的时间,mydumper检查的时候是在执行的时候进行检查并不是一直在检查,当执行的时候检测到有超过该时间的慢查询,备份进程将立即结束;

② --kill-long-queries :

该参数是杀掉慢查询,也是在执行开始的时候进行检查,默认是60s,当执行的时候检测到有超过60s的慢查询将其杀掉,然后继续进行备份;

以上两个参数可以联合起来使用,比如--long-query-guard 100就是当备份开始的时候,会检测有没有超过100s的慢查询,如果有的话会杀掉,然后继续进行备份(如果在备份开始的时候没有超过时间的慢查询,但是存在正在执行的慢查询,那么dump进程将会等待慢查询执行完成后,再进行备份)。

 

5、在mydumper bug库找到了一样的问题: 

mydumper bug库:https://bugs.launchpad.net/mydumper/+bug/1713201