搭建好的一套从库,发现延迟很高,一直追不上,从库的bin_log没开,flush_log_at_trx_commit设置为0,简化的状态如下:
发现Master_Log_File,Read_Master_Log_Pos一直进展比较缓慢,一般来说内网的瓶颈不会在网络,同时一般I/O THREAD并不存再CPU密集型操作,那么瓶颈很可能在I/O,使用iotop命令查看服务器I/O情况如下:
发现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片段如下:
我们发现文件描述符fd=50的文件有大量的写入而且频繁的调用fdatasync来同步磁盘,消耗时间非常可观,是MUTEX调用和write操作的N倍,我们可以通过/proc/pid目录下找到文件描述符和文件的对应关系,那么我们就看看文件描述符50到底是什么,如下:
确实是我们的replay log。
那么问题就确定了,就是因为replay log的写入调用了大量的fdatasync造成的I/O THREAD非常慢,那么是哪一个参数呢?
其实参数就是sync_relay_log,这个参数用来保证relay log的安全,官方文档有如下的图:
我们可以看到如果不设置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。
原文发布时间为:2018-06-29
本文作者:八怪
本文来自云栖社区合作伙伴“ 老叶茶馆”,了解相关信息可以关注“ 老叶茶馆”。