OOM-Killer 的取证分析

OOM-Killer 的取证分析

Ubuntu 的内存不足杀手对我的服务器造成了严重破坏,悄悄地摧毁了我的应用程序、sendmail、apache 和其他程序。

我设法了解了 OOM Killer 是什么,以及它的“不良”规则。虽然我的机器很小,但我的应用程序更小,而且通常只有一半的物理内存在使用,更不用说交换空间了,所以我很惊讶。我正在努力找出罪魁祸首,但我不知道如何阅读 OOM-Killer 日志。

谁能给我提供一份关于如何读取日志中的数据的教程(什么是vefreegen?),或者帮我解析这些日志?

Apr 20 20:03:27 EL135 kernel: kill_signal(13516.0): selecting to kill, queued 0, seq 1, exc 2326 0 goal 2326 0...
Apr 20 20:03:27 EL135 kernel: kill_signal(13516.0): task ebb0c6f0, thg d33a1b00, sig 1
Apr 20 20:03:27 EL135 kernel: kill_signal(13516.0): selected 1, signalled 1, queued 1, seq 1, exc 2326 0 red 61795 745
Apr 20 20:03:27 EL135 kernel: kill_signal(13516.0): selecting to kill, queued 0, seq 2, exc 122 0 goal 383 0...
Apr 20 20:03:27 EL135 kernel: kill_signal(13516.0): task ebb0c6f0, thg d33a1b00, sig 1
Apr 20 20:03:27 EL135 kernel: kill_signal(13516.0): selected 1, signalled 1, queued 1, seq 2, exc 383 0 red 61795 745
Apr 20 20:03:27 EL135 kernel: kill_signal(13516.0): task ebb0c6f0, thg d33a1b00, sig 2
Apr 20 20:03:27 EL135 kernel: OOM killed process watchdog (pid=14490, ve=13516) exited, free=43104 gen=24501.
Apr 20 20:03:27 EL135 kernel: OOM killed process tail (pid=4457, ve=13516) exited, free=43104 gen=24502.
Apr 20 20:03:27 EL135 kernel: OOM killed process ntpd (pid=10816, ve=13516) exited, free=43104 gen=24503.
Apr 20 20:03:27 EL135 kernel: OOM killed process tail (pid=27401, ve=13516) exited, free=43104 gen=24504.
Apr 20 20:03:27 EL135 kernel: OOM killed process tail (pid=29009, ve=13516) exited, free=43104 gen=24505.
Apr 20 20:03:27 EL135 kernel: OOM killed process apache2 (pid=10557, ve=13516) exited, free=49552 gen=24506.
Apr 20 20:03:27 EL135 kernel: OOM killed process apache2 (pid=24983, ve=13516) exited, free=53117 gen=24507.
Apr 20 20:03:27 EL135 kernel: OOM killed process apache2 (pid=29129, ve=13516) exited, free=68493 gen=24508.
Apr 20 20:03:27 EL135 kernel: OOM killed process sendmail-mta (pid=941, ve=13516) exited, free=68803 gen=24509.
Apr 20 20:03:27 EL135 kernel: OOM killed process tail (pid=12418, ve=13516) exited, free=69330 gen=24510.
Apr 20 20:03:27 EL135 kernel: OOM killed process python (pid=22953, ve=13516) exited, free=72275 gen=24511.
Apr 20 20:03:27 EL135 kernel: OOM killed process apache2 (pid=6624, ve=13516) exited, free=76398 gen=24512.
Apr 20 20:03:27 EL135 kernel: OOM killed process python (pid=23317, ve=13516) exited, free=94285 gen=24513.
Apr 20 20:03:27 EL135 kernel: OOM killed process tail (pid=29030, ve=13516) exited, free=95339 gen=24514.
Apr 20 20:03:28 EL135 kernel: OOM killed process apache2 (pid=20583, ve=13516) exited, free=101663 gen=24515.
Apr 20 20:03:28 EL135 kernel: OOM killed process logger (pid=12894, ve=13516) exited, free=101694 gen=24516.
Apr 20 20:03:28 EL135 kernel: OOM killed process bash (pid=21119, ve=13516) exited, free=101849 gen=24517.
Apr 20 20:03:28 EL135 kernel: OOM killed process atd (pid=991, ve=13516) exited, free=101880 gen=24518.
Apr 20 20:03:28 EL135 kernel: OOM killed process apache2 (pid=14649, ve=13516) exited, free=102748 gen=24519.
Apr 20 20:03:28 EL135 kernel: OOM killed process grep (pid=21375, ve=13516) exited, free=132167 gen=24520.
Apr 20 20:03:57 EL135 kernel: kill_signal(13516.0): selecting to kill, queued 0, seq 4, exc 4215 0 goal 4826 0...
Apr 20 20:03:57 EL135 kernel: kill_signal(13516.0): task ede29370, thg df98b880, sig 1
Apr 20 20:03:57 EL135 kernel: kill_signal(13516.0): selected 1, signalled 1, queued 1, seq 4, exc 4826 0 red 189481 331
Apr 20 20:03:57 EL135 kernel: kill_signal(13516.0): task ede29370, thg df98b880, sig 2
Apr 20 20:04:53 EL135 kernel: kill_signal(13516.0): selecting to kill, queued 0, seq 5, exc 3564 0 goal 3564 0...
Apr 20 20:04:53 EL135 kernel: kill_signal(13516.0): task c6c90110, thg cdb1a100, sig 1
Apr 20 20:04:53 EL135 kernel: kill_signal(13516.0): selected 1, signalled 1, queued 1, seq 5, exc 3564 0 red 189481 331
Apr 20 20:04:53 EL135 kernel: kill_signal(13516.0): task c6c90110, thg cdb1a100, sig 2
Apr 20 20:07:14 EL135 kernel: kill_signal(13516.0): selecting to kill, queued 0, seq 6, exc 8071 0 goal 8071 0...
Apr 20 20:07:14 EL135 kernel: kill_signal(13516.0): task d7294050, thg c03f42c0, sig 1
Apr 20 20:07:14 EL135 kernel: kill_signal(13516.0): selected 1, signalled 1, queued 1, seq 6, exc 8071 0 red 189481 331
Apr 20 20:07:14 EL135 kernel: kill_signal(13516.0): task d7294050, thg c03f42c0, sig 2

Watchdog 是一个处于空闲状态的看门狗任务;日志中没有任何内容表明它几天来没有做过任何事情。它的工作是重新启动某个应用程序(如果该应用程序死机),因此有点讽刺的是它是第一个被杀死的。

Tail 正在监控一些日志文件。不太可能疯狂消耗内存。

Apache Web 服务器只向一位老太太提供网页,她只在星期天使用它去教堂,还有几位开发人员在床上睡觉,几个星期都没有访问过网站上的网页。它可能拥有的唯一流量来自端口扫描器;所有内容都受密码保护,并且没有从任何地方链接,因此没有蜘蛛感兴趣。

Python 正在运行两个独立的自定义应用程序。日志中没有任何迹象表明它们没有正常运行。其中一个是相对较新的实现,这使得怀疑 #1 成为可能。它没有任何重要的数据结构,并且通常只使用总物理 RAW 的约 8%。自那以后,它就再也没有出现过问题。

grep 是第二个嫌疑犯,也是我希望它有罪的,因为它是一个一次性命令。该命令(将 grep -r 的输出通过管道传输到另一个 grep)至少在 30 分钟前启动,而且它仍在运行的事实令人怀疑。但是,我没想到 grep 会使用大量内存。OOM 杀手花了一段时间才找到它,这表明它并没有发疯,但 OOM 杀手在它被杀死后就停止了,这表明它可能是一个内存占用大户,最终满足了 OOM 杀手的嗜血欲望。

答案1

我是 ServerFault 的新手,刚刚看到这篇文章。虽然它已经很老了,但似乎又重新出现在队列的前面了。也许我们应该把这个可怕的问题解决掉?

首先,我对这个主题很感兴趣,因为我正在优化具有有限 RAM 的系统,以便以安全的方式运行许多用户进程。

我认为该日志中的错误消息涉及 OpenVZ Linux 容器。

“ve” 是虚拟环境,在 OpenVZ 中也称为容器。每个容器都有一个 ID,您看到的数字就是该 ID。有关更多信息,请访问:

https://openvz.org/Container

术语“空闲”是指当时空闲的内存(以字节为单位)。您可以看到空闲内存随着进程被终止而逐渐增加。

我不太确定“gen”这个术语的含义。我认为这指的是代数。也就是说,它从 1 开始,容器中每生成一个进程,它的值就会增加 1。因此,对于您的系统,自启动以来似乎已执行了 24K+ 个进程。如果我错了,请纠正我。这应该很容易测试。

至于为什么它会终止进程,那是因为你的 OOM 终止程序配置。它试图将可用内存恢复到预期量(看起来是 128 Kb)。Oracle 有一篇很好的文章,介绍了如何将其配置为你可能更喜欢的内容:

http://www.oracle.com/technetwork/articles/servers-storage-dev/oom-killer-1911807.html

此外,如果您想查看每个容器的内存配置,请查看以下内容:

https://openvz.org/Setting_UBC_parameters

相关内容