查找OOM 错误的信息

2018-02-09 2522 words 6 minutes

Contents

1. 概述

Linux 使用默认设置时，会过度使用内存。一方面，这提高了资源利用率。另一方面，这是危险的，不能由应用程序直接控制。这就是为什么我们需要实施分析和恢复，而不是试图减轻错误。

2、系统是否报OOM错误？

我们可以将 Linux 配置为使用不同的策略来分配内存。我们可以通过挂载proc文件系统并从*/proc/sys/vm/中读取来找到有效的策略。文件overcommit_ratio和overcommit_memory*控制系统可以提交多少不受物理内存支持的内存。

只有当我们将系统配置为过度使用内存时，OOM（内存不足）杀手才会运行。但是，如果我们想防止系统过度使用，我们会将 overcommit_memory 设置为2。在这种情况下，系统只会过度使用 total_memory * overcommit_ratio / 100。换句话说，如果我们将overcommit_memory设置为 2 并将overcommit_ratio设置为 0， OOM 杀手将被禁用。

不幸的是，我们需要依靠日志来发现 OOM 错误。Linux 拥有大量不同的日志记录工具。在本文中，我们将使用journald 来检查系统日志。journald使用syslog接口读取有关内核事件的信息，通常是从proc文件系统中的文件：/proc/kmsg。

读取此文件的另一个流行程序是*dmesg 。我们将使用journald*，因为与dmesg不同，它在系统重新启动后保持信息可用。

3. 查找日志

journald是一个负责收集和存储系统日志的守护进程。它有一个姊妹程序：journalctl 用于控制它。由于journald存储结构化日志， journalctl为我们提供了大量工具来快速筛选它们。

3.1. 非交互式使用

如果我们想找到被 OOM 杀手杀死的进程的进程 id 和程序名称，我们可以运行：

journalctl --list-boots | \
    awk '{ print $1 }' | \
    xargs -I{} journalctl --utc --no-pager -b {} -kqg 'killed process' -o verbose --output-fields=MESSAGE

它可能会输出如下内容：

Sun 2021-06-20 18:49:15.791688 UTC [s=f81666ba69664fb88b545f20e7a3eea6;i=4dc1ac1;b=b7a40e823b4a4bd0bdf9d
f5fc0dd9b10;m=92c6bf1db5;t=5c537037a9548;x=18ca447c19414dd8]
    MESSAGE=Killed process 3029 (Web Content) total-vm:10206696kB, anon-rss:6584572kB, file-rss:0kB, shm
em-rss:8732kB
Tue 2021-07-06 08:58:35.087345 UTC [s=bc64b16638964d46b0df6e203765c3f7;i=4dd75a3;b=20f10519157b4f1a9b244
352ffdb9577;m=5d93e0be98;t=5c670a08259f1;x=ca08824178edc0de]
    MESSAGE=Killed process 131641 (bash) total-vm:11257404kB, anon-rss:11243152kB, file-rss:12kB, shmem-
rss:0kB

让我们仔细看看我们使用的journalctl命令选项：

–utc告诉 journalctl 将日期转换为 UTC。这在处理从我们无法访问其时钟的其他系统导入的*systemd日志时特别有用。*否则，处理地理上不同的系统变得非常困难
-b选择与特定系统引导相关的日志。没有办法在一次调用中选择多个靴子。不幸的是，重新启动甚至一系列重新启动通常会出现 OOM 错误
-k使用*_TRANSPORT=kernel*过滤日志消息。换句话说，它过滤内核事件
-q指示journalctl省略与日志显示相关的技术信息。这在搜索任何与 OOM 相关的事件的脚本中很有用
-g以类似于 Emacs 中搜索的方式运行正则表达式搜索。如果表达式不包含大写字母，则假定它不区分大小写
–list-boots打印journalctl有日志的所有引导
-o verbose 指示journalctl打印与消息关联的字段的过滤列表。或者，我们可以使用*-o json*，它将生成 JSON 输出以在日志聚合系统中进行进一步处理
–output-fields是以逗号分隔的要打印的字段列表。journalctl将无条件打印一些字段。特别感兴趣的是日期之后出现在方括号中的那些。括号内的表达式指定光标。我们稍后可以为游标提供*-c*选项以在此位置打开日志

此外，我们使用带有*-I选项的xargs 将awk打印的内部版本号替换到最终的journalctl*调用中。

3.2. 互动使用

非交互式示例输出的有价值信息非常少。它可能用于触发警报，但不足以分析事件。一旦我们可以访问报告错误的系统，我们应该更详细地检查它的日志。

要开始以交互方式检查 OOM 日志，我们可以启动journalctl ，如下所示：

$ journalctl --utc -b -X -ke

X应该是一个整数，（减号是文字整数的一部分，而不是选项语法）。journalctl将负整数解释为从最后一次引导向后计数，而正整数从第一次引导向前计数。

交互模式下的导航命令将使用较少的键绑定。

-e选项会将寻呼机快进到日志的末尾。接下来，我们将使用其中一个可用的搜索命令，例如，键入“？” 紧随其后的是“杀死”。一旦光标移动到感兴趣的错误消息，我们可以再次搜索，现在搜索“Mem-info”，它将日志回滚到 OOM Killer 运行时虚拟内存状态的摘要，然后是列表进程及其内存使用情况的统计信息。

4. journald替代品

一些 Linux 系统不使用journald。在 Linux 上管理系统日志的流行工具是rsyslogd 。该工具具有丰富的模块系统和多种配置语言。但是，涵盖rsyslog的所有功能需要付出巨大的努力。rsyslog配置的入口点是文件*/etc/rsyslog.conf*。此外，它通常伴随着*/etc/rsyslog.d*目录，其中添加了更多的配置文件。

4.1. rsyslogd结构

从概念上讲，rsyslog由以下类型的模块组成：

输入（模块名称将以“im”开头，例如，用于从任意文件读取日志的imflie ）
输出（模块名称以“om”开头，例如，ommysql用于在 MySQL 数据库中存储日志）
解析器（模块名称将以“pm”开头，例如，pmlastmsg用于处理重复消息）
模块类型更少，提供更多技术功能。

4.2. rsyslog配置

让我们看一下rsyslog配置中的一些常见模式，尤其是那些可能帮助我们找到与 OOM 相关的消息的模式。匹配内核消息的配置规则通常如下所示：

kern.*				-/var/log/kern.log

这将指示rsyslog将来自内核的消息存储在一个名为*/var/log/kern.log*的文件中。如果这个文件太长，rsyslog通常会轮换和归档它。随后，zgrep 将帮助我们从这些文件中读取：

$ find /var/log -name kern* -exec grep -PnHe 'Killed process' {} + 2>

这是我们将看到的输出示例：

/dev/null/var/log/kern.log:5207:Jul  6 11:58:34 cheetah kernel: [401912.220043] Killed process 131641 (bash) total-vm:11257404kB, anon-rss:11243152kB, file-rss:12kB, shmem-rss:0kB

对于归档日志：

$ find /var/log -name kern*.gz -exec zgrep -PnHe 'Killed process' {} + 2>/dev/null

我们将看到如下输出：

/var/log/kern.log.3.gz:1967:Jun 13 14:41:02 cheetah kernel: [347531.586344] Killed process 98254 (chrome) total-vm:889684kB, anon-rss:113068kB, file-rss:0kB, shmem-rss:1784kB
/var/log/kern.log.3.gz:2861:Jun 13 14:41:22 cheetah kernel: [347551.430284] Killed process 102503 (chrome) total-vm:911152kB, anon-rss:104748kB, file-rss:0kB, shmem-rss:1968kB
/var/log/kern.log.3.gz:3781:Jun 13 14:41:52 cheetah kernel: [347582.087504] Killed process 96187 (chrome) total-vm:873296kB, anon-rss:103512kB, file-rss:0kB, shmem-rss:4540kB
/var/log/kern.log.2.gz:1593:Jun 20 21:49:15 cheetah kernel: [630398.445681] Killed process 3029 (Web Content) total-vm:10206696kB, anon-rss:6584572kB, file-rss:0kB, shmem-rss:8732kB

rsyslog的模块化结构既是祸也是福。由于极大的灵活性，我们的数据被发送到大量可能的存储位置。它可以被发送到一个集中的日志收集器，或者一个本地数据库服务器，或者只是一个伪终端，仅举几例。

当然，loggers 的选择远远大于journald和rsyslogd。要查找所有可能记录内核事件的程序，我们可以尝试：

$ sudo lsof | grep /dev/kmsg

这将列出所有正在读取该文件的程序，并可能将其内容存储在某处。