天天看点

Mysql 5.7 Gtid内部学习(九) 实际案例(一)

本案例是一个朋友的案例他也写了出来如下:

<a href="https://link.jianshu.com/?t=https://mp.weixin.qq.com/s/XSnFkuYzIlGWMaXIl-oPeQ" target="_blank">https://mp.weixin.qq.com/s/XSnFkuYzIlGWMaXIl-oPeQ</a>

但是和他交流后他也准备改因为分析有一些小问题。

binlog_gtid_simple_recovery=false。

5.7.6以上版本。

Gtid 关闭或者Gtid中途开启有大量的未开启Gtid的binlog。

版本:MySQL版本 5.7.19。

故障为:大概每半小时发生一次故障,整个Mysql压力巨大,很多简单的操作都相应缓慢。使用iotop,top等工具都发现Mysql某个线程有大量的I/O。

分析方法:使用strace发现有大量的binlog文件读取。

Gtid关闭,中途开启,但是留下了很多未开启Gtid的binlog。

数据库没有重启,但是由于expire_logs_days触发了binlog删除。

其实本案例就是前文第七部分总结中的:

从案例中我们得知是中途开启的Gtid,但是留下了很多未开启Gtid的binlog,从第六部分源码bool MYSQL_BIN_LOG::init_gtid_sets()函数的分析,我们知道删除binlog后也会触发正向查找来获取gtid_purged(Gtid_state.lost_gtids)。当读取到第一个binlog的时候虽然获取到了PREVIOUS GTID EVENT但是没有GTID EVENT,而simple_recovery=flase所以需要继续查找下一个文件,直到找到同时包含PREVIOUS GTID EVENT和GTID EVENT的 那个binlog才会停止,那么显然这种情况下那些Gtid关闭的时候生成的binlog将会全部扫描一遍,如果量大那么代价将是巨大的。

而案例中每半个小时会触发一次binlog切换,因为触发超过expire_logs_days参数设置导致binlog进行删除,触发了大量的binlog扫描。

显然有了前面的基础这个案例很容易分析。

这个案例非常好模拟。我打算直接使用strace查看。因为不是每位朋友都能方便使用GDB调试。

使用测试版本社区版本5.7.17:

然后我修改了系统时间同时Mysql开启Gtid

到一步我们已经达到了触发的标准,只要手动触发一次flush binary logs,让binlog刷新就会看到。当然线上是binlog满了做的切换。

这个时候开始做strace,并且做flush tables,我们观察到

受限篇幅我这里删除了一些。我们看到很多read/lseek系统调用正是读取binlog的证据。

至此整个案例模拟完成。

前文已经描述过在5.7.6以上binlog_gtid_simple_recovery应该设置为true,这样可以避免可能的大量的binlog的扫描。具体分析可以参考第七节和从第六部分源码bool MYSQL_BIN_LOG::init_gtid_sets()函数的分析。