某次项目发布过程中,当我们把 rpm 包下发到每台 nc 之后,发现过了一会儿文件就被删除了,当时百思不得其解,第二天亲自试了下,果然能够稳定复现。

试了几次发现,放在 /tmp 目录下的文件,只要文件权限是当前的帐号(假设 abc),并且最近修改时间比较久(大概是分钟级别),就会被自动清理。所以第一个线索:自动清理的脚本应该是 abc 权限运行的,而且根据修改时间去删除文件。

当时第一反应是 tmpwatch 搞得鬼,但是 tmpwatch 印象中是按天执行的,而且是删除 10 天内未修改的文件(ctime/mtime/atime),所以应该可以排除。当然不排除有人擅自修改了配置文件,看了下确实不是:

flags=-umc
/usr/sbin/tmpwatch "$flags" -x /tmp/.X11-unix -x /tmp/.XIM-unix \
	-x /tmp/.font-unix -x /tmp/.ICE-unix -x /tmp/.Test-unix \
	-X '/tmp/hsperfdata_*' 240 /tmp
/usr/sbin/tmpwatch "$flags" 720 /var/tmp
for d in /var/{cache/man,catman}/{cat?,X11R6/cat?,local/cat?}; do
    if [ -d "$d" ]; then
	/usr/sbin/tmpwatch "$flags" -f 720 "$d"
    fi
done

当确认不是 tmpwatch 的问题之后,我就想找个工具去监控“删除”这个行为,google 找到 inotify-tools 工具,尝试运行采集了一把:

$inotifywatch -v -t 60 -r /tmp/b.rpm.bak
Establishing watches...
Setting up watch(es) on /tmp/b.rpm.bak
OK, /tmp/b.rpm.bak is now being watched.
Total of 1 watches.
Finished establishing watches, now collecting statistics.
Will listen for events for 60 seconds.
total  attrib  delete_self  filename
3      1       1            /tmp/b.rpm.bak

但是很遗憾,这个工具无法知道是哪个进程操作的,只能确定确实发生了“删除”的行为。

既然工具不行,就开始想找找系统日志,Linux 有日志审计(audit)的功能,只不过服务器上不一定开启,开启看看是否可以抓到问题:

$sudo /etc/init.d/auditd start
$sudo /sbin/auditctl -w /tmp/test.rpm

运行一会后,可以使用 ausearch 命令查找审计日志:

$sudo ausearch -f /tmp/test.rpm
----
time->Thu Nov 20 16:23:15 2014
type=PATH msg=audit(1416471795.984:3893): item=1 name="/tmp/b.rpm.bak" inode=8304 dev=08:02 mode=0100664 ouid=505 ogid=505 rdev=00:00
type=PATH msg=audit(1416471795.984:3893): item=0 name="/tmp/" inode=8193 dev=08:02 mode=041777 ouid=0 ogid=0 rdev=00:00
type=CWD msg=audit(1416471795.984:3893):  cwd="/"
type=SYSCALL msg=audit(1416471795.984:3893): arch=c000003e syscall=87 success=yes exit=0 a0=7ffffd607bb5 a1=7ffffd607bb5 a2=2 a3=1 items=2 ppid=16473 pid=16475 auid=0 uid=505 gid=505 euid=505 suid=505 fsuid=505 egid=505 sgid=505 fsgid=505 tty=(none) ses=154149 comm="rm" exe="/bin/rm" key=(null)

审计日志中可以看到第二个线索:删除是通过 rm 命令操作的,而且发现了进程的 pid 和 ppid。但是很遗憾,对应的进程通过 ps 命令已经找不到了,说明不是常驻进程搞得鬼。得出第三个最宝贵的线索:是一个定时执行的脚本清理了 /tmp 目录下的文件

为了得到一些更具体的信息,我打算监控 /bin/rm 命令,看看能不能有意外的收获:

$sudo /sbin/auditctl -w /bin/rm
----
time->Thu Nov 20 16:50:15 2014
type=PATH msg=audit(1416473415.732:18186): item=1 name=(null) inode=1188193 dev=08:02 mode=0100755 ouid=0 ogid=0 rdev=00:00
type=PATH msg=audit(1416473415.732:18186): item=0 name="/bin/rm" inode=884844 dev=08:02 mode=0100755 ouid=0 ogid=0 rdev=00:00
type=CWD msg=audit(1416473415.732:18186):  cwd="/"
type=EXECVE msg=audit(1416473415.732:18186): argc=4 a0="rm" a1="-f" a2="/tmp/test.rpm" a3="/tmp/test.txt"
type=SYSCALL msg=audit(1416473415.732:18186): arch=c000003e syscall=59 success=yes exit=0 a0=7fffc004dea8 a1=646850 a2=7fffc004e138 a3=7fffc004fe82 items=2 ppid=21464 pid=21465 auid=0 uid=505 gid=505 euid=505 suid=505 fsuid=505 egid=505 sgid=505 fsgid=505 tty=(none) ses=154149 comm="rm" exe="/bin/rm" key=(null)

虽然上面的审计结果看不出罪魁祸首,但是我们更加确认是一个脚本在作祟,因为脚本内部关闭了 bash alias 功能,否则 rm 命令一般在 redhat 系统中是 rm -i 的 aias:

alias rm='/bin/rm -i'

从审计日志上已经看不出其他线索了,只能看到调用了 rm 命令,但是我们依然找不到调用者是谁。出于无奈,只能 hack rm 命令:

$ cat /bin/rm
LOG=" /home/abc/test_rm/`date +%s`.log"
echo "$*" > $LOG
ps auxfww >>   $LOG

上面的目的很简单,就是为了找到执行的脚本名字,同时抓取下进程现场。这样执行任何 rm 操作都会记录信息,终于逮到罪魁祸首了(为了保密,没有直接给出脚本信息):

abc    17626  0.0  0.0  63872  1068 ?        S    17:02   0:00  |   \_ /bin/bash /path/to/one/monitor_test.py
abc    17640  0.0  0.0  59204   532 ?        S    17:02   0:00  |   |   \_ xargs rm -f
abc    17641  0.0  0.0  63876  1088 ?        S    17:02   0:00  |   |       \_ /bin/sh /bin/rm -f /tmp/test.rpm /tmp/test.txt

monitor_test.py 是一个监控采集指令,脚本会每隔5分钟执行一次,它的脚本里面有下面一段代码:

LOG_DIR="/tmp/"

#clean log file out of date
if [ -d "$LOG_DIR" ]; then
    find $LOG_DIR -mtime +5 -type f | xargs rm -f
fi

很明白,脚本搞错了它自己的日志目录,导致错误地清理了不该清理的文件。这里辛亏是 /tmp 目录,存放的都是些临时文件,如果改成其他目录,那后果不堪设想。所以,对于删除动作,大家务必慎重,对脚本代码里用到的目录变量,千万不要赋值错误!