从一次用cat空文件到log文件来清log方法的失败说开去

发现问题

最近在“不务正业”,应老板需求,给我极的极 go 写一个插件,方便公司员工方便地登录 VPN。关于这个插件的事情另外单说,我这里主要讲下开发、调试这个插件期间发现的另外一个问题。

我在 OpenVPN 服务器上编写认证鉴权程序的时候,需要频繁查看 OpenVPN 的日志,我的 OpenVPN 日志文件是用参数 log 而非 log-append 指定的。

某日,我基于以下几个原因想把日志文件不停服务清一下:

  • 文件很大,不方便打开来看
  • 日志打的很细,所以增长很快
  • 自己要的日志特征也不明显,不方便用 grep 来过滤

所以,基于 Linux 系统管理员的基本常识,直接

1
: > log;

但是当我 1 秒钟后(几乎也就是马上)

1
ls -l log;

发现这个文件的大小比清之前又大了一些!然后又做过几次测试,具体就不赘述了,反正现象就是:当清 log 的当时,文件大小是变为 0 了的,但是几乎是马上,文件立马又恢复到清之前的大小还大一点,仿佛就是跟没有执行清除 log 文件操作一样!

分析原因

最早我以为是内容没有及时刷到硬盘上的原因,于是在清日志操作前后加上了

1
sync;

结果发现还是一样的。于是就大概网上扫了下,发现是日志文件 log 的打开方式所致。具体情况我们通过一点实验来演示下:

1
2
3
4
5
6
7
exec 3>log;
# 用文件描述符33来打开文件 log
printf zzz >&3;
# 把字符串 "zzz" 写入文件描述符 33 打开的文件(也就是文件 log)
# 注意:此时的光标在文件的第四个位置(最右边那个字母 "z" 的右边)
ls -l log;od -c log;
# 查看文件大小及其内容

系统输出:

-rw-r–r– 1 root root 3 Nov 23 16:00 log
0000000 z z z
0000003

可以看到,文件 log 的大小是 3 字节、内容为 “zzz”,接着做:

1
2
3
4
5
6
7
8
printf aaaa >> log;
# 通过另外一个文件描述符打开文件 log,
# 并在其后追加了字符串 "aaaa"
# 注意:这里并没有修改文件描述符 3 光标的位置!
# 文件描述符 3 的光标还在第四个字符的位置
# 也就是最左边那个字符 "a" 的位置
ls -l log;od -c log;
# 再次查看文件 log 的大小和内容

系统输出:

-rw-r–r– 1 root root 7 Nov 23 16:11 log
0000000 z z z a a a a
0000007

由此可知现在文件 log 的大小为 7 字节,内容是 “zzzaaaa”,再接着做实验:

1
2
3
4
5
6
printf bb >&3;
# 在文件描述符 3 的光标位置开始写入字符串 "bb"
# 注意:写完后光标到了第 6 个字符的位置
# 也就是左边那个字符 "a" 的位置
ls -l log;od -c log;
# 再次查看文件 log 的大小和内容

系统输出:

-rw-r–r– 1 root root 7 Nov 23 16:19 log
0000000 z z z b b a a
0000007

表示此时文件 log 的大小没变,但是内容变成了 “zzzbbaa”,接着要清 log 了:

1
2
3
4
: > log;
# 清空文件 log 的内容
ls -l log;od -c log;
# 看文件 log 的大小和内容

系统输出:

-rw-r–r– 1 root root 0 Nov 23 16:26 log
0000000

可以看出,文件 log 的大小变为 0,内容是空的,再接着看如果此时再通过文件描述符 3 写入内容会怎么样:

1
2
3
4
printf x >&3;
# 通过文件描述符 3 再次写入字符 "x"
ls -l log;od -c log;
# 看文件 log 的大小和内容

系统输出:

-rw-r–r– 1 root root 6 Nov 23 16:32 log
0000000 \0 \0 \0 \0 \0 x
0000006

看到没有,新写入的字符 “x” 直接写到了文件描述符 3 的光标位置,整个文件 log 的大小也还是通过文件描述符 3 写入的大小。这个实验应该完美地解释了前面我提到的日志文件的问题。实验最后,别忘了关闭文件描述符 3:

1
2
exec 3>&-;
rm -f log;

延展话题

其实在 /proc 下能看到每个文件描述符打开文件时的参数,当然命令 lsof 也可以看到相关信息。来个实例:

1
lsof -nP +f g | grep -E log$;

基于敏感信息原因系统输出就不贴了,我只把输出大概讲一下:

  • FILE-FLAG 列的 W 代表写入
  • FILE-FLAG 列的 AP 代表 O_APPEND
  • FILE-FLAG 列的 LG 代表 O_LARGEFILE

可以看出,大部分日志的打开方式都是有 AP 字样的,也就是说打开时是有 O_APPEND 参数的,这种日志文件直接用 :>log 清是没有问题的,但是 OpenVPN 的这几个日志文件就不带 AP,所以这些个日志文件是不能用 :>log 来清。

参考