MySQL中sync_relay_log选项对I/O thread的影响分析

最新推荐文章于 2021-02-17 13:26:15 发布

老叶茶馆_

最新推荐文章于 2021-02-17 13:26:15 发布

阅读量754

点赞数

导读

作者：高鹏（重庆八怪）

原文地址：

http://blog.itpub.net/7728585/viewspace-2137737/

搭建好的一套从库，发现延迟很高，一直追不上，从库的bin_log没开，flush_log_at_trx_commit设置为0，简化的状态如下：

640?wx_fmt=png

发现Master_Log_File,Read_Master_Log_Pos一直进展比较缓慢，一般来说内网的瓶颈不会在网络，同时一般I/O THREAD并不存再CPU密集型操作，那么瓶颈很可能在I/O,使用iotop命令查看服务器I/O情况如下：

640?wx_fmt=png

发现MYSQL线程LWP号为44706 的线程I/O非常高，但是写入只有600来K，明显这种情况是不正常的。

一般来说，LINUX有KERNEL BUFFER/CACHE，write只是写入到KERNEL BUFFER/CACHE就好了；

例外就是以dirctor写入方式，这种方式依赖的是用户态缓存，还有就是写入调用了大量的fsync之类的同步kernel cache/buffer到磁盘的系统调用。

然后查看这个LWP号是否为I/O thread如下，因为5.7可以非常轻松的找到MYSQL conn_id和系统LWP之间的关系如下：

确实发现这个大量I/O的确实是MYSQL从库的I/O thread，那么接下来的就是进行strace看看到底为什么这么慢，strace片段如下：

640?wx_fmt=png

我们发现文件描述符fd=50的文件有大量的写入而且频繁的调用fdatasync来同步磁盘，消耗时间非常可观，是MUTEX调用和write操作的N倍，我们可以通过/proc/pid目录下找到文件描述符和文件的对应关系，那么我们就看看文件描述符50到底是什么，如下：

确实是我们的replay log。
那么问题就确定了，就是因为replay log的写入调用了大量的fdatasync造成的I/O THREAD非常慢，那么是哪一个参数呢？
其实参数就是sync_relay_log，这个参数用来保证relay log的安全，官方文档有如下的图：

640?wx_fmt=png

我们可以看到如果不设置sync_relay_log那么有可能造成relay log丢失的风险，其实上面的分析已经看到就是调用fdatasync来完成这个功能，但是
这样的代价基本是不可接受的。

官方文档有如下说明：

It is important to note the impact of sync_relay_log=1, which requires a write of to the relay log per transaction. Although this setting is the most resilient to an unexpected halt, with at most one unwritten transaction being lost, it also has the potential to greatly increase the load on storage. Without sync_relay_log=1, the effect of an unexpected halt depends on how the relay log is handled by the operating system.

A value of 1 is the safest choice because in the event of a crash you lose at most one event from the relay log. However, it is also the slowest choice (unless the disk has a battery-backed cache, which makes synchronization very fast).

每次事务都会调用fdatasync，代价太高。所以没办法修改了sync_relay_log的设置，默认值是10000，也就是10000个事务进行一次fdatasync。

对本文有任何疑问可扫码添加原文作者微信

640?wx_fmt=jpeg

叶问也讨论过这个话题哦，且看下文分解

叶问（2018年6月27日，周三）

主从复制线程均正常（为Yes，也没报错），Master的binlog已到binlog.000100，但slave上看到Master_Log_File却只到binlog.000090，可能的原因有哪些?

首先是Master_Log_File IO线程延迟，并不是Relay_Master_Log_File SQL线程延迟，大多数的同学都没有认真审题哦~
可能的原因如下：
1.由于sync_relay_log值过低，导致Slave频繁刷新relay_log文件，使 Slave的硬盘资源消耗过高，所以导致SlaveIO Thread很慢。
2.Master/Slave压力过大导致Slave IO Thread不能及时响应，无法及时获得Master的event。
3.网络丢包严重。小包可以连接并且保持连接不断，但是大包就无法发送。可能是Master和Slave关于TCP MTU值设置不一致导致。
4.Master和Slave网络链接已经断开。但slave_net_timeout值等于0（表示完全禁用心跳）或者slave_net_timeout和Slave_heartbeat_period非常大（表示检测主从心跳的时间）。
5.Master的binlog非常大，io线程的file很长时间都在读同一个。
总结
本次案例是在主库进行压力测试，在压力测试的过程中，因为Master本身的压力就很大Master来不及把binlog发送给Slave。所以表面上看起来没有延迟，但实际上已经产生了延迟。

640?