从库io线程和sql线程状态双yes，主从数据却不同步了

一、出现问题得场景

主库MySQL5.7.22,从库为Mariadb10.2.17 此架构是MySQL多源复制架构 多个个主库MySQL实例同步复制到一个从库mariadb实例。

其中一个复制通道erp_rep 出现数据不复制的场景，db-saas主实例MySQL中db_core_assets 库中的表不在同步到从库实例。但是db-read1从库的io复制线程和从库的复制线程却一致是yes状态。导致基于这2个线程状态的复制监控检查失效，一直没触发报警。结果还是研发那边反馈的问题

出现问题的原因：下午给db-saas主库 db_core_assets 表b_refit_bill_sn（400多万记录）pt-osc 添加索引，诱发的从库db-read1复制通道rep_erp发生 Waiting for table metadata lock 索。导致这个复制通道的数据复制阻塞，不同步数据了。
主库db_core_assets.b_refit_bill_sn大表执行添加索引时候，在添加完成后，从库db-read1 rep_erp 复制通道出现Waiting for table metadata lock 索。

二、具体排查过程

登录db-read1从库show all slaves status\G

第一次检查了下db-read1库的所有的复制通道，发现状态都是yes，但是第二次db-read1从库show all slaves status\G 发现复制通道rep_erp Slave_SQL_Running_State: Waiting for table metadata lock

连续几次show slave 'rep_erp' status\G
发现 Exec_Master_Log_Pos: 151201185 一直保持不变。说明这个复制通道一直备阻塞着，不同步数据了。
Exec_Master_Log_Pos: 151201185
Relay_Log_Space: 1146902246

执行下面的命令发现 出现问题的原因:

[root@db-read1 ~]# mysql -e "show full processlist"|grep 'Waiting for table metadata lock'
30  system user     db_core_assets  Slave_SQL   15205   Waiting for table metadata lock CREATE DEFINER=`pt_tools`@`172.16.0.237` TRIGGER `pt_osc_db_core_assets_b_refit_bill_sn_del` AFTER DELETE ON `db_core_assets`.`b_refit_bill_sn` FOR EACH ROW DELETE IGNORE FROM `db_core_assets`.`_b_refit_bill_sn_new` WHERE `db_core_assets`.`_b_refit_bill_sn_new`.`id` <=> OLD.`id` 0.000

本以为尝试重启下rep_erp复制通道就可以解决问题，经过操作，是没用的

stop slave 'rep_erp';
start slave 'rep_erp';

为啥出现这样的问题呢？带着问题，查看了下当前的正在执行的事务的状态

root@db-read1 20:26:  [db_core_assets]> select * from information_schema.innodb_trx\G
*************************** 1. row ***************************
trx_id: 422133762488088
trx_state: RUNNING
trx_started: 2021-04-10 19:53:10
trx_requested_lock_id: NULL
trx_wait_started: NULL
trx_weight: 0
trx_mysql_thread_id: 288863654
trx_query: select count(*) from (
SELECT d.device_id, d.in_storage_rolex
FROM db_core_assets.b_refit_bill b
LEFT JOIN db_core_assets.b_refit_bill_sku s ON b.id = s.refit_bill_id
LEFT JOIN db_core_assets.b_refit_bill_sn n ON n.refit_sku_id = s.id
LEFT JOIN db_core_assets.d_depreciation d ON d.device_id = n.device_id
AND b.created_date >= '2021-01-01 00:00:00' AND b.created_date <= '2021-04-01 00:00:00'
AND s.refit_operate_type = 1 AND s.sku_type = 1
) a
trx_operation_state: NULL
trx_tables_in_use: 4
trx_tables_locked: 0
trx_lock_structs: 0
trx_lock_memory_bytes: 1136
trx_rows_locked: 0
trx_rows_modified: 0
trx_concurrency_tickets: 0
trx_isolation_level: REPEATABLE READ
trx_unique_checks: 1
trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
trx_adaptive_hash_latched: 0
trx_is_read_only: 1
trx_autocommit_non_locking: 1
1 row in set (0.00 sec)

原因分析：
因为在db-saas主实例 表 db_core_assets.b_refit_bill_sn 在 pt-osc添加索引动作之前，从库db-read1上一直存在关于db_core_assets.b_refit_bill_sn 表的查询事务一直在运行还没完成提交。
正好这时主库对表db_core_assets.b_refit_bill_sn online DDL操作，导致从库的 Waiting for table metadata lock 索，造成复制阻塞。

出现Waiting for table metadata lock的等待场景：

MySQL在进行alter table等DDL操作时，有时会出现Waiting for table metadata lock的等待场景。
而且，一旦alter table TableA的操作停滞在Waiting for table metadata lock的状态，后续对TableA的任何操作（包括读）都无法进行，因为他们也会在Opening tables的阶段进入到Waiting for table metadata lock的锁等待队列。
如果是业务核心系统表出现了这样的锁等待队列，就会造成灾难性的后果

三、造成alter table产生Waiting for table metadata lock的原因的几个场景

场景一：长事物运行，阻塞DDL，继而阻塞所有同表的后续操作

通过show processlist可以看到TableA上有正在进行的操作（包括读），此时alter table语句无法获取到metadata 独占锁，会进行等待。

这是最基本的一种情形，这个和mysql 5.6中的online ddl并不冲突。一般alter table的操作过程中（见下图），在after create步骤会获取metadata 独占锁，当进行到altering table的过程时（通常是最花时间的步骤），对该表的读写都可以正常进行，这就是online ddl的表现，并不会像之前在整个alter table过程中阻塞写入。
（当然，也并不是所有类型的alter操作都能online的，具体可以参见官方手册：http://dev.mysql.com/doc/refman/5.6/en/innodb-create-index-overview.html）
处理方法： kill 掉 DDL所在的session.

于是针对上述的问题KILL 掉DDL所在的session的会话id

[root@db-read1 ~]# mysql -e "show full processlist"|grep 'Waiting for table metadata lock'
30  system user     db_core_assets  Slave_SQL   15205   Waiting for table metadata lock CREATE DEFINER=`pt_tools`@`172.16.0.237` TRIGGER `pt_osc_db_core_assets_b_refit_bill_sn_del` AFTER DELETE ON `db_core_assets`.`b_refit_bill_sn` FOR EACH ROW DELETE IGNORE FROM `db_core_assets`.`_b_refit_bill_sn_new` WHERE `db_core_assets`.`_b_refit_bill_sn_new`.`id` <=> OLD.`id` 0.000

KILL   30;

执行下面的命令：此时复制报错

root@db-read1 20:15:  [db_core_assets]> show slave 'rep_erp' status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 172.16.0.127
Master_User: backup
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: saas-mysql-bin.011335
Read_Master_Log_Pos: 97512499
Relay_Log_File: db-read1-relay-bin-rep_erp.003561
Relay_Log_Pos: 105416465
Relay_Master_Log_File: saas-mysql-bin.011327
Slave_IO_Running: Yes
Slave_SQL_Running: No
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table: mysql.%,db_redis.%,db_scheduler.%
Last_Errno: 1927
Last_Error: Error 'Connection was killed' on query. Default database: 'db_core_assets'. Query: 'CREATE DEFINER=`pt_tools`@`172.16.0.237` TRIGGER `pt_osc_db_core_assets_b_refit_bill_sn_del` AFTER DELETE ON `db_core_assets`.`b_refit_bill_sn` FOR EACH ROW DELETE IGNORE FROM `db_core_assets`.`_b_refit_bill_sn_new` WHERE `db_core_assets`.`_b_refit_bill_sn_new`.`id` <=> OLD.`id`'
Skip_Counter: 0
Exec_Master_Log_Pos: 151201185
Relay_Log_Space: 1119370857
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: NULL
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 1927
Last_SQL_Error: Error 'Connection was killed' on query. Default database: 'db_core_assets'. Query: 'CREATE DEFINER=`pt_tools`@`172.16.0.237` TRIGGER `pt_osc_db_core_assets_b_refit_bill_sn_del` AFTER DELETE ON `db_core_assets`.`b_refit_bill_sn` FOR EACH ROW DELETE IGNORE FROM `db_core_assets`.`_b_refit_bill_sn_new` WHERE `db_core_assets`.`_b_refit_bill_sn_new`.`id` <=> OLD.`id`'
Replicate_Ignore_Server_Ids:
Master_Server_Id: 172160127
Master_SSL_Crl:
Master_SSL_Crlpath:
Using_Gtid: No
Gtid_IO_Pos:
Replicate_Do_Domain_Ids:
Replicate_Ignore_Domain_Ids:
Parallel_Mode: conservative
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State:
1 row in set (0.00 sec)

重启了下rep_erp复制通道 stop slave 'rep_erp';start slave 'rep_erp';
复制状态恢复成双yes.但是 Slave_SQL_Running_State: Waiting for table metadata lock 还是一直在阻塞。

root@db-read1 20:29:  [(none)]> show slave 'rep_erp' status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 172.16.0.127
Master_User: backup
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: saas-mysql-bin.011335
Read_Master_Log_Pos: 167521372
Relay_Log_File: db-read1-relay-bin-rep_erp.003561
Relay_Log_Pos: 105416465
Relay_Master_Log_File: saas-mysql-bin.011327
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table: mysql.%,db_redis.%,db_scheduler.%
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 151201185
Relay_Log_Space: 1146902246
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_Ignore_Server_Ids:
Master_Server_Id: 172160127
Master_SSL_Crl:
Master_SSL_Crlpath:
Using_Gtid: No
Gtid_IO_Pos:
Replicate_Do_Domain_Ids:
Replicate_Ignore_Domain_Ids:
Parallel_Mode: conservative
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: Waiting for table metadata lock
1 row in set (0.00 sec)

场景二：未提交事物，阻塞DDL，继而阻塞所有同表的后续操作

通过show processlist看不到TableA上有任何操作，但实际上存在有未提交的事务，可以在 information_schema.innodb_trx中查看到。在事务没有完成之前，TableA上的锁不会释放，alter table同样获取不到metadata的独占锁。

处理方法：通过 select * from information_schema.innodb_trx\G, 找到未提交事物的sid, 然后 kill 掉，让其回滚。

root@db-read1 20:26:  [db_core_assets]> select * from information_schema.innodb_trx\G
*************************** 1. row ***************************
trx_id: 422133762488088
trx_state: RUNNING
trx_started: 2021-04-10 19:53:10
trx_requested_lock_id: NULL
trx_wait_started: NULL
trx_weight: 0
trx_mysql_thread_id: 288863654
trx_query: select count(*) from (
SELECT d.device_id, d.in_storage_rolex
FROM db_core_assets.b_refit_bill b
LEFT JOIN db_core_assets.b_refit_bill_sku s ON b.id = s.refit_bill_id
LEFT JOIN db_core_assets.b_refit_bill_sn n ON n.refit_sku_id = s.id
LEFT JOIN db_core_assets.d_depreciation d ON d.device_id = n.device_id
AND b.created_date >= '2021-01-01 00:00:00' AND b.created_date <= '2021-04-01 00:00:00'
AND s.refit_operate_type = 1 AND s.sku_type = 1
) a
trx_operation_state: NULL
trx_tables_in_use: 4
trx_tables_locked: 0
trx_lock_structs: 0
trx_lock_memory_bytes: 1136
trx_rows_locked: 0
trx_rows_modified: 0
trx_concurrency_tickets: 0
trx_isolation_level: REPEATABLE READ
trx_unique_checks: 1
trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
trx_adaptive_hash_latched: 0
trx_is_read_only: 1
trx_autocommit_non_locking: 1
1 row in set (0.00 sec)

KILL 掉 trx_mysql_thread_id: 288863654

root@db-read1 20:30:  [db_core_assets]> KILL 288863654 ;
Query OK, 0 rows affected (0.00 sec)
root@db-read1 20:29:  [(none)]> show slave 'rep_erp' status\G

此时复制状态正常了。数据可以正常同步了。

场景三：

通过show processlist看不到TableA上有任何操作，在information_schema.innodb_trx中也没有任何进行中的事务。这很可能是因为在一个显式的事务中，对TableA进行了一个失败的操作（比如查询了一个不存在的字段），这时事务没有开始，但是失败语句获取到的锁依然有效，没有释放。从performance_schema.events_statements_current表中可以查到失败的语句。

官方手册上对此的说明如下：

If the server acquires metadata locks for a statement that is syntactically valid but fails during execution, it does not release the locks early. Lock release is still deferred to the end of the transaction because the failed statement is written to the binary log and the locks protect log consistency.

也就是说除了语法错误，其他错误语句获取到的锁在这个事务提交或回滚之前，仍然不会释放掉。because the failed statement is written to the binary log and the locks protect log consistency 但是解释这一行为的原因很难理解，因为错误的语句根本不会被记录到二进制日志。

处理方法：通过performance_schema.events_statements_current找到其sid, kill 掉该session. 也可以 kill 掉DDL所在的session.

四、问题总结

alter table的语句是很危险的(其实他的危险其实是未提交事物或者长事务导致的)，在操作之前最好确认对要操作的表没有任何进行中的操作、没有未提交事务、也没有显式事务中的报错语句。（包括主从库复制环境，尤其是主库大表添加字段或者是索引时，一定要是业务低峰期，一定要在slave库上也确认下是否存在大的事务）如果有alter table的维护任务，在无人监管的时候运行，最好通过lock_wait_timeout设置好超时时间，避免长时间的metedata锁等待