copytruncate + 非 O_APPEND 写日志 = 切分文件大小越来越大
现象
服务通过系统的logrotate切分,某次重启进程后,发现切分得到的日志文件越来越大,如下图,而且每次增大200M(重启之前,切分的每个文件都是200M)。但是同样的二进制,相同配置的其它机器却正常。

/etc/logrotate.d下配置:
{
daily
missingok
rotate 360
nocompress
copytruncate
dateext}
原因
定位发现,服务中写日志文件没有O_APPEND模式,然后配置copytruncate,导致“累计放大”现象。

代码中os.Create() 等价于:
os.OpenFile(name, O_RDWR|O_CREATE|O_TRUNC, 0666)
没有 O_APPEND 时,在 copytruncate 场景下:
文件被清零,每次copytruncate后都是在前一次fd的offset位置开始新写入,所以文件持续增大。
另外,打开日志文件有两种分支,这也是为什么不同机器的表现不同的原因。
模拟推演




(发现问题时不是第一时间,所以2.1G以前的日志,已经被清除了,所以实际不是从200M开始递增。而且这些文件的增加的大小也都是第一行)
复现
将logrotate中的"daily"改成"hourly"测试,去除bill.log拉起进程。
小时切分日志后,生成了030316和030317等后缀的新日志。打开发现,后一个日志文件是在第一行空了指定字节数的位置开始写入的('^@'空的字节数,刚好是前一个日志文件的大小)。



如果事先新建bill.log,然后重启进程,后续切分的日志文件大小就都正常了。
解决
- 新建bill.log,重启进程(这样,日志文件就会”src, err = os.OpenFile(fileName, os.O_APPEND|os.O_WRONLY, os.ModeAppend)“,指定O_APPEND模式)。
- 代码层完善
(1)打开文件统一改成如下,无论是否存在bill.log,都会O_APPEND
src, err := os.OpenFile(
fileName,
os.O_CREATE|os.O_APPEND|os.O_WRONLY,
0644,
)
(2)更通用的方式,因为copytruncate不适用高并发环境写日志。不过需要代码层需要增加USR1信号处理。



浙公网安备 33010602011771号