标签：lan 运行 读取 for 接下来 t_sql 线程阻塞 中继 导致
文/温国兵
研发反应，有台从库和主库不同步。由于业务读操作是针对从库的，数据不同步必定会带来数据的不一致，业务获取的结果会受影响，所以这个问题必须尽快解决。
登上服务器，查看 MySQL 的从库状态，并没有任何报错信息。刷新从库状态，发现状态没有任何变化，Exec_Master_Log_Pos 卡住不动。
为了安全起见，此文略去 MySQL 版本以及其他可能会带来安全问题的信息。
接下来逐步分析问题。
首先查看从库状态：
mysql> SHOW SLAVE STATUS \G
*************************** 1. row ***************************
Slave_IO_State: Queueing master event to the relay log
Master_Host: masterIP
Master_User: replUser
Master_Port: masterPort
Connect_Retry: 60
Master_Log_File: binlog.000296
Read_Master_Log_Pos: 364027786
Relay_Log_File: relaylog.000002
Relay_Log_Pos: 250
Relay_Master_Log_File: binlog.000283
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:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 594374863
Relay_Log_Space: 13803486573
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: 256219
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: masterID
1 row in set (0.00 sec)
此时的 Slave_IO_State 为 Queueing master event to the relay log，而不是正常状态下的 Waiting for master to send event。刷新多次，状态没有任何变化，Exec_Master_Log_Pos 不变，从而导致 Seconds_Behind_Master 一直不变。
接下来查看 PROCESSLIST 状态：
mysql> SHOW FULL PROCESSLIST;
+--------+-------------+------------------+--------------------+---------+---------+---------------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+--------+-------------+------------------+--------------------+---------+---------+---------------+------------------+
| 51378 | system user | | NULL | Connect | 1121183 | Waiting for master to send event | NULL |
| 88917 | system user | | NULL | Connect | 245327 | Reading event from the relay log | NULL |
| 106029 | userA | xxx.xxx.xxx.xxx:14057 | NULL | Sleep | 14504 | | NULL |
| 106109 | userA | xxx.xxx.xxx.xxx:15077 | databaseA | Sleep | 79 | | NULL |
| 106110 | userA | xxx.xxx.xxx.xxx:15081 | databaseA | Sleep | 13000 | | NULL |
| 106116 | userB | xxx.xxx.xxx.xxx:15096 | databaseA | Sleep | 357 | | NULL |
| 106117 | userB | xxx.xxx.xxx.xxx:15097 | NULL | Sleep | 12964 | | NULL |
| 106119 | root | localhost | NULL | Query | 0 | NULL | SHOW FULL PROCESSLIST |
| 106126 | userB | xxx.xxx.xxx.xxx:15173 | NULL | Sleep | 12856 | | NULL |
| 106127 | userB | xxx.xxx.xxx.xxx:15180 | databaseA | Sleep | 12849 | | NULL |
| 106766 | userA | xxx.xxx.xxx.xxx:17960 | databaseA | Sleep | 64 | | NULL |
+--------+-------------+------------------+--------------------+---------+---------+---------------+------------------+
11 rows in set (0.00 sec)
从以上的结果来看，没有任何异常。
既然从上述信息中得不到任何对排查问题有帮助的信息，那么我们可以试着分析 MySQL 的 binlog，看 Pos 为 594374863 的点发生了什么操作。
分析日志我们可以使用 mysqlbinlog 命令，指定 start-position 为夯住的那个点，并重定向到文件。
/usr/local/mysql/bin/mysqlbinlog --no-defaults -v --start-position="594374863" binlog.000283 > /XXX/binlog.sql
查看输出结果，发现端倪了，以下是摘抄的部分结果：
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#150814 17:43:15 server id 21 end_log_pos 107 Start: binlog v 4, server v x.x.xx-log created 150814 17:43:15
BINLOG ‘
M7jNVQ8VAAAAZwAAAGsAAAAAAAQANS41LjE5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
‘/*!*/;
# at 594374863
#150814 18:09:36 server id 21 end_log_pos 594374945 Query thread_id=210702841 exec_time=43 error_code=0
SET TIMESTAMP=1439546976/*!*/;
SET @@session.pseudo_thread_id=210702841/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 594374945
# at 594375036
# at 594376047
# at 594377085
# at 594378123
# at 594379152
# at 594380187
# at 594381165
# at 594382194
# at 594383223
# at 594384252
# at 594385269
# at 594386307
# at 594387282
# at 594388299
# at 594389265
# at 594390270
# at 594391299
# at 594392310
# at 594393327
# at 594394344
# at 594395340
# at 594396336
# at 594397332
从以上输出中，我们可以知道，从夯住的那个点开始，binlog 记录的信息就出现了异常，可以推测在主库有大操作。另外，针对出现问题库，查看主库和从库的表数量，发现从库的表数量多于主库，有几个临时表出现。可以推测的，主库有删表的操作，从库同步夯住，导致同步异常，主库删表的操作还没来得及同步到从库。
经过和研发沟通，确认了两点。第一，确实有大操作，程序有大量的批量插入，而且是用的 LOAD DATA LOCAL INFILE；第二，主库确实有删表的操作，这几张表都是临时表。
既然问题找到了，那解决办法自然就有了。既然从库的表多于主库，而且这几张表是临时数据，我们可以过滤掉对这几张表的同步操作。具体思路如下：在主库备份临时表（虽然研发说数据不重要，但还是以防万一，DBA 还是谨慎为好），然后通知研发临时切走从库的流量，修改配置文件，指定 replicate-ignore-table 参数，重启 MySQL。
接下来就是具体的解决步骤，首先备份数据。备份时不加 –master-data 参数和 –single-transaction。究其原因，–master-data 禁用 –lock-tables 参数，在和 –single-transaction 一起使用时会禁用 –lock-all-tables。在备份开始时，会获取全局 read lock。 –single-transaction 参数设置默认级别为 REPEATABLE READ，
并且在开始备份时执行 START TRANSACTION。在备份期间， 其他连接不能执行如下语句：ALTER TABLE、CREATE TABLE、DROP TABLE、RENAME TABLE、TRUNCATE TABLE。MySQL 同步夯住，如果加了上述参数，mysqldump 也会夯住。mysqldump 会 FLUSH TABLES、LOCK TABLES，如果有 –master-data 参数，会导致 Waiting for table flush。同样，有 –single-transaction 参数，仍然会导致 Waiting for table flush。另外，还可以看到 Waiting for table metadata lock，此时做了 DROP TABLE 的操作。此时可以停掉 MySQL 同步来避免这个问题。
为了保险起见，我们在主库加大 expire_logs_days 参数，避免 binlog 丢失。
mysql> SHOW VARIABLES LIKE ‘%expire%‘;
+------------------+-------+
| Variable_name | Value |
+------------------+-------+
| expire_logs_days | 3 |
+------------------+-------+
1 row in set (0.00 sec)
mysql> SET GLOBAL expire_logs_days=5;
Query OK, 0 rows affected (0.00 sec)
mysql> SHOW VARIABLES LIKE ‘%expire%‘;
+------------------+-------+
| Variable_name | Value |
+------------------+-------+
| expire_logs_days | 5 |
+------------------+-------+
1 row in set (0.00 sec)
接着修改从库的配置文件：
vim /xxx/xxxx/xxx/my.cnf
在 mysqld 后，加入如下配置：
replicate-ignore-table=databaseA.tableA
replicate-ignore-table=databaseA.tableB
replicate-ignore-table=databaseA.tableC
replicate-ignore-table=databaseA.tableD
然后重启 MySQL：
/xxx/xxx/xxx/xxx/mysqld restart
登录 MySQL 从库，查看从库状态，并定时刷新状态，我们可以看到的是，Exec_Master_Log_Pos 在递增，Seconds_Behind_Master 在递减，证明问题已经解决了。
mysql> SHOW SLAVE STATUS \G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: masterIP
Master_User: replUser
Master_Port: masterPort
Connect_Retry: 60
Master_Log_File: binlog.000319
Read_Master_Log_Pos: 985656691
Relay_Log_File: relaylog.000004
Relay_Log_Pos: 709043542
Relay_Master_Log_File: binlog.000284
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table: databaseA.tableA,databaseA.tableB,databaseA.tableC,databaseA.tableD
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 709043399
Relay_Log_Space: 38579192969
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: 258490
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: masterID
1 row in set (0.00 sec)
需要注意的是，待同步完成后，需要把从库配置文件中增加的 replicate-ignore-table参数注释，并重启 MySQL。
在主库运行 LOAD DATA LOCAL INFILE，主库和从库时这样同步的：
在从节点执行的 1-4 步骤中，IO 线程会呈现 Reading event from the relay log 状态，持续地为下一个 LOAD DATA LOCAL INFILE 命令提取 CSV 行。此时从库会持续落后，一旦从库落后时间较长，会导致 SQL 线程阻塞，呈现 Queueing master event to the relay log 状态，从而复制夯住。
这样的故障，归根结底还是研发写的程序还有优化的余地。大批量的数据插入，这在 MySQL 中是不推荐使用的。我们可以这样：第一，一条 SQL 语句插入多条数据；第二，在事务中进行插入处理；第三，分批插入，在程序中设置 auto_commit 为 0，分批插入完成后，手动 COMMIT；第四，需要使用 LOAD DATA LOCAL INFILE 时，设置 sync_binlog 为 1。
–EOF–
标签：lan 运行 读取 for 接下来 t_sql 线程阻塞 中继 导致
原文地址：https://www.cnblogs.com/DataArt/p/10234861.html
