mysql外建导致的复制中断,从库mysqldump会导致复制中断

作者&＃xff1a;张政俊

就职于中欧基金&＃xff0c;知数堂粉丝&＃xff0c;数据库爱好者&＃xff0c;熟悉RDBMS、nosql、new sql等各类数据库。

背景环境数据库版本&＃xff1a;5.6.24-log

主从架构&＃xff1a;一主两从搭配mha

操作步骤开发要求truncate一张表&＃xff0c;在删除之前需要备份下数据&＃xff1b;

在从库上使用mysqldump命令做逻辑备份&＃xff0c;备份sql&＃xff1a;

mysqldump -uXXX -p osdc osdc_XXX > /tmp/osdc_info.sql&＃xff1b;这台从库与主库的同步出现中断&＃xff0c;报错为&＃xff1a;

Slave_IO_Running: YesSlave_SQL_Running: NoLast_Errno: 1756Last_Error: … The slave coordinator and worker threads are stopped, possibly leaving data in inconsistent state. A restart should restore consistency automatically, although using non-transactional storage for data or info tables or DDL queries could lead to problems. In such cases you have to examine your data (see documentation for details).ERROR NO 是1756&＃xff0c;而且只是 Slave_SQL_Running 停了。

处理方式停止同步&＃xff1a;

stop slave;打开同步&＃xff1a;

start slave;重新启停同步服务后&＃xff0c;恢复正常。

分析之前形形色色的主从问题遇到过很多&＃xff0c;但是 1756 这个错误还是第一次遇到&＃xff0c;所以事后还是很有兴趣去深入分析下这个问题。

1. 详细报错查看数据库的 error log &＃xff0c;这个报错的具体输出如下&＃xff1a;

2020-08-18 22:04:19 208840 [Warning] Slave SQL: Worker 2 failed executing transaction ‘fe0ed3ca-cacc-11e9-8d49-6c92bfcf73b6:1377629720’ at master log mysql-bin.003536, end_log_pos 861741231; Could not execute Update_rows event on table osdc.osdc_XXX; Lock wait timeout exceeded; try restarting transaction, Error_code: 1205; handler error HA_ERR_LOCK_WAIT_TIMEOUT; the event’smaster log mysql-bin.003536, end_log_pos 861741231, Error_code: 12052020-08-18 22:04:19 208840 [Note] Worker 2 is exiting: killed 0, error 1, running_status 12020-08-18 22:04:19 208840 [ERROR] Slave SQL: … The slave coordinator and worker threads are stopped, possibly leaving data in inconsistent state. A restart should restore consistency automatically, although using non-transactional storage for data or info tables or DDL queries could lead to problems. In such cases you have to examine your data (see documentation for details). Error_code: 1756错误日志里有个 Lock wait timeout exceeded &＃xff0c;这个我们先记下&＃xff0c;稍后再说。

先找到 master 事务的 gtid&＃xff0c;直接去主库的 binlog 里找下这个 gtid 所对应的 sql&＃xff1a;

SET &＃64;&＃64;SESSION.GTID_NEXT&＃61; ‘fe0ed3ca-cacc-11e9-8d49-6c92bfcf73b6:1377629720’/*!*/;# at 861740635#200818 21:58:42 server id 31 end_log_pos 861740715 CRC32 0xa9ab0dd2 Query thread_id&＃61;9403182 exec_time&＃61;0 error_code&＃61;0SET TIMESTAMP&＃61;1597759122/*!*/;BEGIN/*!*/;# at 861740715#200818 21:58:42 server id 31 end_log_pos 861740840 CRC32 0xbd8ba613 Rows_query# update osdc_XXX# set modify_time&＃61;now(),status&＃61;’04’# where id&＃61;9298XXXXX and status&＃61;’01’可以看到&＃xff0c;这时候主库对 osdc_XXX 表进行了 update 操作。

2. 问题分析首先&＃xff0c;mysqldump 不加任何参数去执行&＃xff0c;会对备份的表加表级锁。

这时候从库需要执行从主库同步过来的 update 语句&＃xff0c;因为 mysqldump 表锁的存在&＃xff0c;该语句会处理等待状态。

update 等待超时&＃xff0c;这个错误我们在上面的 error log 里可以看到(Lock wait timeout exceeded)。

因为在5.6.26版本下&＃xff0c;在使用 MTS 的情况下&＃xff0c;slave_transaction_retries 是不生效的。所以当 update 语句超时后&＃xff0c;它没有重试机制&＃xff0c;导致整个 SQL threads 都停掉了(这也就是为什么 Slave_IO_Running 显示YES&＃xff0c;而 Slave_SQL_Running 显示NO)。

在 rpl_slave.cc 里可以看到&＃xff1a;

—-/* MTS technical limitation no support of trans retry */if (mi->rli->opt_slave_parallel_workers !&＃61; 0 && slave_trans_retries !&＃61; 0—-这个 bug 很早就由 Yoshinori Matsunobu 提在 https://bugs.mysql.com/bug.phpid&＃61;68465 了&＃xff0c;官方也采纳了&＃xff0c;并于 MySQL 5.7.5 修复掉了该问题。

Yoshinori Matsunobu 就是大名鼎鼎的 MHA 的作者&＃xff01;

3. 问题复现相关参数slave_parallel_workers&＃xff1a;3

[root&＃64;localhost][(none)]> show variables like ‘%slave_parallel_workers%’;&＃43;————————&＃43;——-&＃43;| Variable_name | Value |&＃43;————————&＃43;——-&＃43;| slave_parallel_workers | 5 |&＃43;————————&＃43;——-&＃43;innodb_lock_wait_timeout&＃xff1a;50

[root&＃64;localhost][(none)]> show variables like ‘%innodb_lock_wait_timeout%’;&＃43;————————–&＃43;——-&＃43;| Variable_name | Value |&＃43;————————–&＃43;——-&＃43;| innodb_lock_wait_timeout | 50 |&＃43;————————–&＃43;——-&＃43;slave_transaction_retries&＃xff1a;10

[root&＃64;localhost][none]> show variables like ‘%slave_transaction_retries%’;&＃43;—————————&＃43;——-&＃43;| Variable_name | Value |&＃43;—————————&＃43;——-&＃43;| slave_transaction_retries | 10 |&＃43;—————————&＃43;——-&＃43;测试数据&＃xff1a;

[root&＃64;localhost][bug]> select * from repl_test;&＃43;——&＃43;——-&＃43;| id | info |&＃43;——&＃43;——-&＃43;| 1 | tom || 2 | jerry |&＃43;——&＃43;——-&＃43;从库加锁操作从库&＃xff1a;

[root&＃64;localhost][bug]> begin;update repl_test set info&＃61;’all’;Query OK, 0 rows affected (0.00 sec)Query OK, 2 rows affected (0.01 sec)Rows matched: 2 Changed: 2 Warnings: 0显性开启事务&＃xff0c;让它持续持有 InnoDB lock

主库更新操作主库&＃xff1a;

[root&＃64;localhost][bug]> update repl_test set info&＃61;’all’ where id&＃61;1;commit;Query OK, 1 row affected (0.00 sec)Rows matched: 1 Changed: 1 Warnings: 0Query OK, 0 rows affected (0.00 sec)手工更新 repl_test 表的一条数据&＃xff0c;此时从库的复制线程会等待这条sql的应用&＃xff0c;并处于 system lock 状态&＃xff1a;

从库&＃xff1a;

[root&＃64;localhost][(none)]> show processlist;&＃43;—-&＃43;—————–&＃43;———–&＃43;——&＃43;———&＃43;——&＃43;—————————————————————————–&＃43;——————————————–&＃43;| Id | User | Host | db | Command | Time | State | Info |&＃43;—-&＃43;—————–&＃43;———–&＃43;——&＃43;———&＃43;——&＃43;—————————————————————————–&＃43;——————————————–&＃43;| 6 | event_scheduler | localhost | NULL | Daemon | 545 | Waiting on empty queue | NULL || 9 | root | localhost | bug | Sleep | 10 | | NULL || 15 | system user | | NULL | Connect | 44 | Waiting for master to send event | NULL || 16 | system user | | NULL | Connect | 5 | Slave has read all relay log; waiting for the slave I/O thread to update it | NULL || 17 | system user | | NULL | Connect | 44 | Waiting for an event from Coordinator | NULL || 18 | system user | | NULL | Connect | 44 | Waiting for an event from Coordinator | NULL || 19 | system user | | NULL | Connect | 5 | System lock | update repl_test set info&＃61;’all’ where id&＃61;1 || 20 | root | localhost | NULL | Query | 0 | init | show processlist |&＃43;—-&＃43;—————–&＃43;———–&＃43;——&＃43;———&＃43;——&＃43;—————————————————————————–&＃43;——————————————–&＃43;8 rows in set (0.04 sec)errorlog错误日志开始打印错误信息&＃xff1a;

2020-08-20 11:01:00 22391 [Warning] Slave SQL: Worker 2 failed executing transaction ” at master log mysql-bin.000272, end_log_pos 654587717; Could not execute Update_rows event on table bug.repl_test; Lock wait timeout exceeded; try restarting transaction, Error_code: 1205; handler error HA_ERR_LOCK_WAIT_TIMEOUT; the event’s master log FIRST, end_log_pos 654587717, Error_code: 12052020-08-20 11:01:00 22391 [ERROR] Slave SQL: … The slave coordinator and worker threads are stopped, possibly leaving data in inconsistent state. A restart should restore consistency automatically, although using non-transactional storage for data or info tables or DDL queries could lead to problems. In such cases you have to examine your data (see documentation for details). Error_code: 17562020-08-20 11:01:00 22391 [Note] Error reading relay log event: slave SQL thread was killed报的错与当时的内容一致。

4. 总结mysqldump 即使在从库中执行&＃xff0c;也必须加上 –single-transcation 等参数&＃xff0c;直接执行会上表锁&＃xff0c;成本大大。

部分mysql工具&＃xff0c;如 navicat 直接使用它自带的导出功能&＃xff0c;也会锁住全表。所以尽量不要使用工具去处理导出工作。

mysql> show open tables where in_use >0 ;&＃43;———-&＃43;———–&＃43;——–&＃43;————-&＃43;| Database | Table | In_use | Name_locked |&＃43;———-&＃43;———–&＃43;——–&＃43;————-&＃43;| osdc | osdc_XXX | 1 | 0 |&＃43;———-&＃43;———–&＃43;——–&＃43;————-&＃43;1 row in set (0.00 sec)5.6 的主从的坑已经踩了很多了&＃xff0c;大多是由于自身的bug&＃xff0c;而且在 5.6 下根本体现不出 MTS 的优势。把 5.6 升级至 5.7 或 8.0 是非常有必要的&＃xff0c;之前测试的 8.0 的复制稳定性和性能的提升非常大&＃xff0c;推荐直接升级至 8.0 版本。

全文完。

Enjoy MySQL:)

叶老师的「MySQL核心优化」大课已升级到MySQL 8.0&＃xff0c;扫码开启MySQL 8.0修行之旅吧

死锁案例七来源&＃xff1a;公众号yangyidba一、前言死锁&＃xff0c;其实是一个很有意思也很有挑战的技术问题&＃xff0c;大概每个 DBA 和部分开发同学都会在工作过程中遇见 。关于死锁我会持续写一个系列的案例分析&＃xff0c;希望能够对想了解死锁的…...

Server 层混杂信息字典表 | 全方位认识 information_schema(中)上期《Server 层混杂信息字典表 | 全方位认识 information_schema(上)》为大家介绍了部分关于Server层混杂信息字典表的知识&＃xff0c;本期“Server层混杂信息字典表(中)”将继…...

死锁案例五来源&＃xff1a;公众号yangyidba一、前言死锁其实是一个很有意思也很有挑战的技术问题&＃xff0c;大概每个 DBA 和部分开发朋友都会在工作过程中遇见。关于死锁我会持续写一个系列的案例分析&＃xff0c;希望能够对想了解死锁的朋友…...

免费好用的MySQL高可用方案徐晨亮&＃xff0c;MySQL DBA&＃xff0c;知数堂学员。热衷于数据库优化&＃xff0c;自动化运维及数据库周边工具开发&＃xff0c;对MySQL源码有一定的兴趣。环境说明地址端口角色说明127.0.0.13306master-127.0.0.…...