【问题分析】
1、定位哪种操作导致从库延迟
1.1 猜测:导致从库延迟的两种操作:1)delete, update 两种操作过滤条无索引,或者影响行数量很大。 2)ALTER TABLE 修改表结构。
1.2 根据Slave behide master的时间段, 12:45到12:59这个区间,查看从库的Innodb Row operations监控。
上图分析: 根据上面从库的Innodb Row Operations图,和Slave behide Master的时间区间吻合,大量的Innodb Rows Deeletd.
结论: 说明这次从库延迟, 是由于delete删除了大量的行导致的。
2、定位是由哪个库,哪个SQL引起的?
从1中分析可知,是由12:44到12:45之前的一个大delete操作导致延迟,而且这个操作之前没有任何延迟,说明SQL线程完全能跟上IO的读取操作。
那我们根据时间区别12:44到12:45这一分钟内,查看从库relay log的所有delete操作:
1)命令:mysqlbinlog -vv --start-datetime='2013-03-27 12:44:00' --stop-datetime='2013-03-27 12:45:00' mysql1227_relay-log.000057 | grep -i delete -B 10 -A 10
2)分析结果图:注意图中标红部分
上图分析: 很明显:delete from xxxx where addtime < '2013-03-20 02:28:24' 操作是导致这次slag的原凶。
注意:那为什么此relay log event的时间戳是:130327 12:29:51, 而从库延迟由12:45开始的呢?
原理:因为从库IO Thread在读取主库的Binlog时,记录的时间戳仍然保持主库的不变, 而主库的binlog记录event的时间戳为,这个事件刚开始执行时的点,
如果我们查看主库的这个操作,在近12:29分开始做,就证明没有问题。
上图分析:这为主库的Innodb Row Operations, 可见在12:30到12:45的这段删除很大;这个事件被记录binlog的时间戳为起始12:29:51。
所以前面relay log中会是12:29:51.
3、分析是由哪个人员执行的? 由于防止类似的问题发生,需要定位到人员,提醒到不要再进行此类操作。
1)操作方式: 由于这个库共3个用户,多部部门使用,可能是由于线上job, 或者通过跳板机删除的。
2)定位人员试: a. 通过应用的负责人,调查有没人员进行相关操作,这是最快的方式,最终定位到由某部分,新上线应用,对日志表进行一次自动删除。
b. 如果确认程序没操作,只能通过跳板日志排查,这个时间成本高,且结果不明显。
4、操作时间比较长的delete&update的处理方式:
1)确定过滤字段有索引,防止时间操作长,且为形成表锁,导致严重影响应用。
2)加上主键范围分批处理,不过,此操作要对主键的数据分布情况了解。
3)应用程序定时任务清理数据,但第一次最好让他们通知我们,由我们手动执行,因为第一次往往跨度范围大,历史数据多。
总结: 1)结合innodb row operations + Slave behide master + relay log来定们已经执行完了,导致从库延迟的SQL.
2) 注意:binlog 和 relay log 登记事件时间戳,为此SQL开始执行的时间点。