某次项目发布过程中,当我们把 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 目录,存放的都是些临时文件,如果改成其他目录,那后果不堪设想。所以,对于删除动作,大家务必慎重,对脚本代码里用到的目录变量,千万不要赋值错误!