怎么解决Mysql中Slave延迟很大并且不动了问题

问题描述

收到SLAVE延迟时间一直很大的报警，于是检查一下SLAVE状态（无关状态我给隐去了）：

Slave_IO_State: Waiting for master to send event Master_Log_File: mysql-bin.000605 ---当前master的binlog

Read_Master_Log_Pos: 305864 ---master binlog位置

Relay_Log_File: mysql-relay-bin.003224 Relay_Log_Pos: 295105 Relay_Master_Log_File: mysql-bin.000604 ----当前salve同步到的master的binlog日志

Slave_IO_Running: Yes Slave_SQL_Running: Yes Last_Errno: 0 Last_Error: Exec_Master_Log_Pos: 294959 -----当前slave执行到的master的binlog 的pos

Relay_Log_Space: 4139172581 Seconds_Behind_Master: 10905 ---延迟一般是Read_Master_Log_Pos-Exec_Master_Log_Pos

可以看到，延迟确实很大，而且从多次show slave status的结果来看，发现binlog的position一直不动。

点击(此处)折叠或打开

Relay_Master_Log_File: mysql-bin.000604

Exec_Master_Log_Pos: 294959

Relay_Log_Space: 4139172581

检查processlist 也没发现异常sql语句

在master上查看相应binlog，确认都在干神马事：

[yejr@imysql.com]# mysqlbinlog -vvv --base64-output=decode-rows -j 294959 mysql-bin.000604 | more

--base64-output=decode-rows --去除一些不必要的二进制日志展示 /*!40019 SET @@session.max_insert_delayed_threads=0*/;/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;DELIMITER /*!*/;**# at 294959**#160204 6:16:30 server id 1 end_log_pos 295029 **Query thread_id=461151** **exec_time=2144** error_code=0SET TIMESTAMP=1454537790/*!*/;SET @@session.pseudo_thread_id=461151/*!*/;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 latin1 *//*!*/;SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=33/*!*/;SET @@session.lc_time_names=0/*!*/;SET @@session.collation_database=DEFAULT/*!*/;BEGIN/*!*/;# at 295029# at 295085# at 296040# at 297047# at 298056# at 299068# at 300104

上面这段内容的几个关键信息：

# at 294959 — binlog起点
thread_id=461151 — master上执行的线程ID
exec_time=2144 — 该事务执行总耗时

再往下看都是一堆的binlog position信息，通过这种方式可读性不强，我们换一种姿势看看

[yejr@imysql.com (test)]> show binlog events in 'mysql-bin.000604' from 294959 limit 10; +------------------+--------+-------------+-----------+-------------+----------------------------+| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |+------------------+--------+-------------+-----------+-------------+----------------------------+| mysql-bin.000604 | 294959 | Query | 1 | 295029 | BEGIN || mysql-bin.000604 | 295029 | Table_map | 1 | 295085 | table_id: 84 (bacula.File) || mysql-bin.000604 | 295085 | Delete_rows | 1 | 296040 | table_id: 84 || mysql-bin.000604 | 296040 | Delete_rows | 1 | 297047 | table_id: 84 || mysql-bin.000604 | 297047 | Delete_rows | 1 | 298056 | table_id: 84 || mysql-bin.000604 | 298056 | Delete_rows | 1 | 299068 | table_id: 84 || mysql-bin.000604 | 299068 | Delete_rows | 1 | 300104 | table_id: 84 || mysql-bin.000604 | 300104 | Delete_rows | 1 | 301116 | table_id: 84 || mysql-bin.000604 | 301116 | Delete_rows | 1 | 302147 | table_id: 84 || mysql-bin.000604 | 302147 | Delete_rows | 1 | 303138 | table_id: 84 |

可以看到，这个事务不干别的，一直在删除数据。
这是一个Bacula备份系统，会每天自动删除一个月前的过期数据。
事实上，这个事务确实非常大，从binlog的294959开始，一直到这个binlog结束4139169218，一直都是在干这事，总共大概有3.85G的binlog要等着apply。

-rw-rw---- 1 mysql mysql 1.1G Feb 3 03:07 mysql-bin.000597

-rw-rw---- 1 mysql mysql 1.1G Feb 3 03:19 mysql-bin.000598

-rw-rw---- 1 mysql mysql 2.1G Feb 3 03:33 mysql-bin.000599

-rw-rw---- 1 mysql mysql 1.4G Feb 3 03:45 mysql-bin.000600

-rw-rw---- 1 mysql mysql 1.8G Feb 3 04:15 mysql-bin.000601

-rw-rw---- 1 mysql mysql 1.3G Feb 3 04:53 mysql-bin.000602

-rw-rw---- 1 mysql mysql 4.5G Feb 4 06:16 mysql-bin.000603

-rw-rw---- 1 mysql mysql 3.9G Feb 4 06:52 mysql-bin.000604

-rw-rw---- 1 mysql mysql 1.2K Feb 4 06:52 mysql-bin.000605

怎么解决

由于这是Bacula备份系统内置生成的大事务，除非去修改它的源码，否则没有太好的办法。