导读

今天遇到一个离谱的问题, mysql的error日志mysql.err文件 大小会变化, 偶尔猛增, 然后过一会又降下来… 过一会又猛涨, 每次涨的幅度都是一样的. 然后过大概1个月, 涨幅又翻倍. 过3个月又降下来,重新开始涨, 每月1周期,3月1轮回

环境

x86
rhel 8.6
multipath
mysql 5.7.41
从库
MTS
未配置日志轮转等

详情

生产环境,不方便放截图, 就画个类似的图吧. 监控的虽然是文件系统, 但排查下来就只有mysql.err这个文件有这种变化. 差不多就每隔一段时间就会涨上去, 然后过一会就会降下来, 很有规律…

说明: 纵坐标可以当作是du -sh mysql.err文件大小. 横坐标是时间.
每隔一段时间, 这个涨幅就会翻倍. 看起来像是操作系统/文件系统的问题, 但日志里面没得任何记录(除了用户登录之类的外). 难道是玄学问题?

猜测:

du 和 df 看到的大小才有这个波动, 如果是使用ls -l或者stat看到的就是无变化的, 即一条直线.
也就是比较像是 文件系统 预分配空间给 mysql.err文件, 导致du/df看到的空间比较大, 但ls/stat看到的还是记录值. 由于后续未使用到, 所有又偷偷回收回去了?

结论

暂无结论, 也没找到相关BUG.
后续有结论了再说吧

原因

原因找到了, 就是我们猜测的那样, 也就是xfs文件系统的锅, 也不能说是锅吧.
当写入比较频繁的时候, 会申请 1/2 当前文件大小的空间, du能看到, 但是ls看不到(未实际使用).
当写入不频繁的时候, 会慢慢回收掉预分配的空间 XFS:程序小老弟,你咋回事,给你空间,你咋个不用呢
我模拟的时候, 使用os.fsync也不会回收预分配空间, 只有慢慢写入才会回收.

RHEL将其称为 定性预分配 Speculative preallocation 描述如下, 基本上符合我们看到的现象

XFS uses speculative preallocation to allocate blocks past EOF as files are written. This avoids file fragmentation due to concurrent streaming write workloads on NFS servers. By default, this preallocation increases with the size of the file and will be apparent in “du” output. If a file with speculative preallocation is not dirtied for five minutes the preallocation will be discarded. If the inode is cycled out of cache before that time, then the preallocation will be discarded when the inode is reclaimed.
If premature ENOSPC problems are seen due to speculative preallocation, a fixed preallocation amount may be specified with the -o allocsize=amount mount option.
原文: https://access.redhat.com/documentation/en-us/red_hat_enterprise_linux/7/html/storage_administration_guide/migrating-ext4-xfs

复现方法

1. 清空error log (方便观察)
2. 产生大量error log (模拟程序异常断开就行, 反正开发也不喜欢正常关闭连接)
3. 产生小量error log
   观察期间的error log大小

# 模拟大量日志
import pymysql
import time
while True:
	conn = pymysql.connect(
			host='192.168.101.202',
			port=3306,
			user='u1',
			password='xxxx',
			)
	#conn.close() # 不主动断开
	time.sleep(0.01)

# 跑2秒就行了, 然后ctrl+c 看下error log文件大小
SEHLL> du -sh mysql.err && ls -lh mysql.err && date

# 模拟小量日志
import pymysql
import time
while True:
	conn = pymysql.connect(
			host='192.168.101.202',
			port=3306,
			user='u1',
			password='xxxx',
			)
	#conn.close()
	time.sleep(30)

# 慢慢等, 这里会等很久....
# 然后再观察error log

我这里测试了多次, 所以空间不是 1/2, 它这具体的比例和算法,咱也不知道.