linux kernel kauditd

一次文件被"神秘进程"删除的历程

Posted by lwk on December 25, 2019

申明:该事件发生于2018年

10.30号开始有同事反馈扩容流程进程端口扫描步骤没有输出,且执行成功(实际有些进程并没有启动成功)。导致用户以为扩容成功,从而影响正常上线。为什么进程端口扫描步骤没有输出信息呢?

首先就去分析工具执行的日志,查看日志发现是扩容机器上的部分管理工具文件不见了!导致无法获取扩容机器上包的进程状态信息,从而前台无法展示。另外,还有一个问题就是进程端口扫描工具不健壮,导致缺失文件的情况下最终提示成功,从而误导用户,针对不健壮问题已经修复。

今天重点介绍为什么管理工具会被“神秘进程”删除,从分析到排查以及最终的解决措施做个详细的阐述。

首先分析了工具被删除的机器特征以及被删除时间和业务。

1、 首先想到的就是重试失败流程,但无法重现问题,且扩容的一批机器中并不是所有的都有失败,部分失败,部分成功,无论重试多少次,都无法重现问题。

2、 其次,通过最近几个案例分析发现被删除机器的特征都是虚拟机,且都集中在组件组的扩容流程中,其他流程未发现。难道是特定用户组的扩容流程比较特殊?其实不然,扩容流程都是统一从扩容系统发起,且所有业务的扩容流程执行的工具都是相同的,并且分析了相同的时间其他扩容流程,并没有异常,排除和业务特性的关系

3、 然后分析管理工具被删除的时间:通过分析整个扩容流程,发现执行包安装工具是正常的,即安装包扩容,管理工具tools没有被删除。但通过stat查看tools的ctime,发现和扩容流程中的配置文件工具执行时间匹配得上,难道是下发配置过程,某个配置的脚本文件(前置or后置)清理了tools?于是将扩容中配置文件捞出来分析其前后置脚本,发现扩容中所有的配置都无前后置脚本,也就不可能由配置下发导致的。

4、 最后分析机器的crontab、扩容流程log、系统log都没发现任何异常

分析到这里,觉得不可思议,重试也重现不了,不过可以确定的是,扩容机器上一定存在过完整的tools,为什么这么肯定呢?因为在包安装过程中会使用这些工具,如果工具不完整,包安装肯定会失败,所以tools一定是会被神秘进程删除了!

那到底删除文件的神秘进程到底是谁呢?再分析被清理的文件特征发现,被清理的文件都是2018年之前的。

image 难道是按照时间清理的,脑海中浮现可能是被神秘进程执行find /tmp/ | xarg rm之类的语句删除的。那是不是可以通过劫持机器上的find rm命令找到这个神秘进程呢?不妨一试。在这之前,我们也提取了公司的安全agent shell历史cmd日志,但也没法找到根因。

因此,另外一个协助排查的同事打了一个trace_shell包,预先将包部署于待扩容的机器上,待问题重现时候,就可以从trace log找到神秘进程!满怀信心的等待问题重现ing

====================

过了几天。。。

终于又复现了,这次能摘下你的神秘面纱了吧,哼哼哼!!!

怀着激动and喜悦的心情登录到出问题的机器,查看对应trace log。NND,没有删除tools的log?不可能啊! image 此刻的心情,犹如自己中了五百W彩票,但去兑现的时候被告知彩票过期了。。。一落不是千丈,是一落到谷底~~~

不可思议,难道不是通过find rm这种方式删除的?如果是系统删除的话,trace这种方式是不是就捕获不到了呢?是的!

如果是被系统进程清理了,就不能用这种方式去捕获,于是google了一把,发现auditd可以实现追踪系统中文件的变化、用户对文件的读写以及系统调用等,且是基于配置的,使用起来也比较方面。

https://linux.die.net/man/8/auditd

在使用之前,先来介绍下audit审核系统的一些基本知识(周末补了一把,当然网上也有很多介绍)

首先看下audit的整体架构图。 image

图中主要分两部分,左侧图表示内核中几种系统调用,右侧图表示audit的应用程序。其中实现部分代表数据流方向,虚线表示组件之间的控制关系。

从图中可以看出,内核的运行情况可以通过audit中记录下来。Kauditd是内核线程,负责向auditd主线程发送消息,auditd主线程将消息传给auditd的log线程,写入log文件(默认位置/var/log/audit/audit.log)。auditd.conf 是 auditd 的配置文件,确定auditd的启动方式,日志文件存放位置等信息。audit.rules 是 audit 的规则文件,确定audit 的日志中记录哪些操作,且可以通过auditctl进行操作。auditctl主要负责添加规则,例如本文中增加对/tmp目录的审计信息(auditctl -w /tmp/ -p w)。

ausearch查看审计信息

aureport查看和生成审计信息报告,相比ausearch,aureport能以一定的format展示出来,更易读&分析

audispd负责将审计的信息转发给其他应用程序

autrace用于跟踪进程的命令,类似于strace

ausearch和aureport都要依赖于已存在的审计日志。本文主要使用ausearch

这篇文章不会重点介绍audit审计系统的详细逻辑,想深入了解audit处理逻辑的同学请参考内核代码:

https://github.com/torvalds/linux/blob/fa1b5d09d0771247d407df89228b3902de8e2ce6/kernel/audit.c

好了,了解了audit之后,现在用它来一展拳脚吧!

我们还是用包的形式启用audit,将包预先部署于待扩容的机器上,“坐等”问题复现

11月9号隔壁组同事扩容,问题复现

为了便于查看log,将log按行重定向到文件

ausearch -l >/tmp/a.log,根据tools被清理的时间点,查看/tmp/a.log,果不其然,tools的文件被神秘进程清理了,这个神秘进程到底是谁呢?systemd-tmpfiles!!!

image

简要阐述下systemd-tmpfiles是工作原理。

Systemd-tmpfiles是系统进程,并根据配置文件tmpfiles.d,创建、删除、清理文件。其中tmpfiles.d主要包括/etc/tmpfiles.d/.conf、/run/tmpfiles.d/.conf以及/usr/lib/tmpfiles.d/*.conf

其中,/etc/tmpfiles.d为本地配置文件,并且会覆盖系统配置/usr/lib/tmpfiles.d中相同名称的文件。 image 本地配置文件如下:

image 系统配置文件如下:

image

其中,在/usr/lib/tmpfiles.d/tmp.conf配置找到可能清理/tmp/pkg_tools_v2的配置项

image

从配置项看应该是清理10天前的文件,但是为什么有些超过10天的文件没有被清理呢?

image

带着这个疑问猜想,可能不是按照mtime判断的,于是乎查了下tmpfiles.c源代码,发现只有当atime、ctime和mtime都满足清理条件时才会删除文件。

image

那为什么每次都是该组同事扩容流程出现问题呢?到底是在什么情况下才被清理的呢?

其实,tlinux内核systemd-tmpfiles是定时清理机制,由内核中的定时器触发。其触发时间由/usr/lib/systemd/system/systemd-tmpfiles-clean.timer决定。 image

OnBootSec=15min表示系统启动后的第15分钟执行系统清理,完成后,从当前时间算起,每天执行一次。意思就是:例如开机启动时间是11月9号12:00:00,则第一次清理发生在11月9号12:15:00,下一次清理发生在11月10号:12:15:00

还有个疑点:装包时,是通过rsync将tools同步至目标机器的/tmp下,理论上atime、ctime和mtime至少有一个不会满足清理条件。猜想很有可能生产处的虚拟机器/tmp下已经有了tools,而且mtime和管理机上tools的mtime相同,从而不会更新文件。

于是我申请了一台TVM机器,/tmp下确实存在tools, image

image

当执行清理命令时SYSTEMD_LOG_LEVEL=debug systemd-tmpfiles –clean,发现tools下的文件确实被删除了!

image

结果复现!!!

image

image

总结:

以上的所有分析及验证过程证明了为什么会由扩容系统发起扩容的机器出现/tmp/tools部分文件被删除,为什么只有该组的扩容流程出现问题(因为该组的扩容流程超过了15分钟)。在尽可能改动小的前提下解决问题,我们给出的解决方案是:rsync时候,修改tools文件的atime时间。

从问题发生到解决,经历了接近10天时间,首先要感谢各位,给我们反馈这个问题,并持续给我们提供现场环境排查

写这篇文章一方面是分享排查的思路和方法,供其他同学参考,另一方面是提醒各位尽量不要把重要的文件放在/tmp下,也不要轻易以为系统不会对/tmp下的文件“动手脚”

当所有小概率事件叠加在一起的时候就成为了必然事件