几天前,我的 Linux Apache 服务器内存不足。该服务器是 xen 客户机。该服务器杀死了除 ssh 之外的所有进程(甚至 cron、monit、syslog)。
在内存耗尽前一分钟,我的一个脚本保存了各种命令的输出。输出如下:
# free -m
total used free shared buffers cached
Mem: 2003 1866 137 0 3 1159
-/+ buffers/cache: 703 1300
Swap: 511 0 511
# vmstat 1 2
procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
r b swpd free buff cache si so bi bo in cs us sy id wa
2 1 144 140944 4192 1186964 0 0 0 0 1 0 1 0 98 1
3 1 144 142816 3704 1186896 0 0 4188 10132 3242 3242 0 19 59 22
# pidstat -dru 1 3
Linux 2.6.39-linode33 (web1) 09/10/11 _i686_
01:07:15 PID %user %system %CPU CPU Command
01:07:16 271 0.00 10.78 10.78 0 kswapd0
01:07:16 9871 0.00 100.00 100.00 1 flush-0:17
01:07:16 13082 0.00 1.96 1.96 0 apache2
01:07:16 15100 0.98 5.88 6.86 0 rm
01:07:16 15250 0.00 0.98 0.98 0 pidstat
01:07:15 PID minflt/s majflt/s VSZ RSS %MEM Command
01:07:16 13082 1.96 0.98 62872 29720 1.45 apache2
01:07:16 15250 224.51 0.00 1704 636 0.03 pidstat
01:07:15 PID kB_rd/s kB_wr/s kB_ccwr/s Command
01:07:16 13082 78.43 7.84 0.00 apache2
01:07:16 15100 1317.65 0.00 0.00 rm
01:07:16 15250 3.92 0.00 0.00 pidstat
01:07:16 PID %user %system %CPU CPU Command
01:07:17 3 0.00 0.99 0.99 0 ksoftirqd/0
01:07:17 12 0.00 0.99 0.99 2 ksoftirqd/2
01:07:17 271 0.00 1.98 1.98 2 kswapd0
01:07:17 9871 0.00 100.00 100.00 1 flush-0:17
01:07:17 15100 0.00 17.82 17.82 2 rm
01:07:17 15232 17.82 0.99 18.81 0 apache2
01:07:17 15250 0.99 1.98 2.97 0 pidstat
01:07:17 19944 0.00 0.99 0.99 0 kworker/0:2
01:07:16 PID minflt/s majflt/s VSZ RSS %MEM Command
01:07:17 15232 298.02 0.00 63096 12820 0.62 apache2
01:07:17 15250 231.68 0.00 1704 664 0.03 pidstat
01:07:16 PID kB_rd/s kB_wr/s kB_ccwr/s Command
01:07:17 15100 4261.39 0.00 0.00 rm
01:07:17 15232 3.96 7.92 0.00 apache2
01:07:17 15250 11.88 0.00 0.00 pidstat
01:07:17 PID %user %system %CPU CPU Command
01:07:18 271 0.00 11.11 11.11 2 kswapd0
01:07:18 9871 0.00 100.00 100.00 1 flush-0:17
01:07:18 15100 1.01 27.27 28.28 2 rm
01:07:18 15250 0.00 1.01 1.01 0 pidstat
01:07:18 19944 0.00 1.01 1.01 0 kworker/0:2
01:07:17 PID minflt/s majflt/s VSZ RSS %MEM Command
01:07:18 15250 229.29 0.00 1704 664 0.03 pidstat
01:07:17 PID kB_rd/s kB_wr/s kB_ccwr/s Command
01:07:18 15100 4230.30 0.00 0.00 rm
01:07:18 15250 16.16 4.04 0.00 pidstat
Average: PID %user %system %CPU CPU Command
Average: 3 0.00 0.33 0.33 - ksoftirqd/0
Average: 12 0.00 0.33 0.33 - ksoftirqd/2
Average: 271 0.00 7.95 7.95 - kswapd0
Average: 9871 0.00 100.00 100.00 - flush-0:17
Average: 13082 0.00 0.66 0.66 - apache2
Average: 15100 0.66 16.89 17.55 - rm
Average: 15232 5.96 0.33 6.29 - apache2
Average: 15250 0.33 1.32 1.66 - pidstat
Average: 19944 0.00 0.66 0.66 - kworker/0:2
Average: PID minflt/s majflt/s VSZ RSS %MEM Command
Average: 13082 0.66 0.33 62872 29720 1.45 apache2
Average: 15232 99.67 0.00 62927 12456 0.61 apache2
Average: 15250 228.48 0.00 1704 655 0.03 pidstat
Average: PID kB_rd/s kB_wr/s kB_ccwr/s Command
Average: 13082 26.49 2.65 0.00 apache2
Average: 15100 3256.95 0.00 0.00 rm
Average: 15232 1.32 2.65 0.00 apache2
Average: 15250 10.60 1.32 0.00 pidstat
Monit 报告了这些统计数据(也是在内存耗尽前一分钟):
System 'local'
status Resource limit matched
monitoring status monitored
load average [3.57] [2.63] [1.30]
cpu 0.5%us 18.5%sy 37.1%wa
memory usage 726464 kB [35.4%]
swap usage 148 kB [0.0%]
data collected Sat Sep 10 01:06:06 2011
以下是 kern.log 中记录内容的摘录:
Sep 10 01:07:31 web1 kernel: Out of memory: Kill process 2190 (portmap) score 1 or sacrifice child
Sep 10 01:07:31 web1 kernel: Killed process 2190 (portmap) total-vm:1820kB, anon-rss:100kB, file-rss:360kB
Sep 10 01:07:31 web1 kernel: apache2 invoked oom-killer: gfp_mask=0xd0, order=1, oom_adj=0, oom_score_adj=0
Sep 10 01:07:31 web1 kernel: Pid: 31143, comm: apache2 Tainted: G W 2.6.39-linode33 #5
Sep 10 01:07:31 web1 kernel: Call Trace:
Sep 10 01:07:31 web1 kernel: [<c0185c10>] ? T.663+0x80/0xd0
Sep 10 01:07:31 web1 kernel: [<c0185cbe>] ? T.661+0x5e/0x160
Sep 10 01:07:31 web1 kernel: [<c013d8ac>] ? has_capability_noaudit+0xc/0x20
Sep 10 01:07:31 web1 kernel: [<c0185a1c>] ? oom_badness+0xdc/0x130
Sep 10 01:07:31 web1 kernel: [<c0185f76>] ? out_of_memory+0x1b6/0x2f0
Sep 10 01:07:31 web1 kernel: [<c0189715>] ? __alloc_pages_nodemask+0x6b5/0x6d0
Sep 10 01:07:31 web1 kernel: [<c0131c35>] ? dup_task_struct+0x55/0x140
Sep 10 01:07:31 web1 kernel: [<c0132728>] ? copy_process+0x88/0xb80
Sep 10 01:07:31 web1 kernel: [<c013326f>] ? do_fork+0x4f/0x290
Sep 10 01:07:31 web1 kernel: [<c0156084>] ? getnstimeofday+0x44/0x110
Sep 10 01:07:31 web1 kernel: [<c010f510>] ? sys_clone+0x30/0x40
Sep 10 01:07:31 web1 kernel: [<c06900cd>] ? ptregs_clone+0x15/0x48
Sep 10 01:07:31 web1 kernel: [<c068f7b1>] ? syscall_call+0x7/0xb
Sep 10 01:07:31 web1 kernel: [<c0680000>] ? sctp_icmp_proto_unreachable+0x20/0xc0
Sep 10 01:07:31 web1 kernel: Mem-Info:
Sep 10 01:07:31 web1 kernel: DMA per-cpu:
Sep 10 01:07:31 web1 kernel: CPU 0: hi: 0, btch: 1 usd: 0
Sep 10 01:07:31 web1 kernel: CPU 1: hi: 0, btch: 1 usd: 0
Sep 10 01:07:31 web1 kernel: CPU 2: hi: 0, btch: 1 usd: 0
Sep 10 01:07:31 web1 kernel: CPU 3: hi: 0, btch: 1 usd: 0
Sep 10 01:07:31 web1 kernel: Normal per-cpu:
Sep 10 01:07:31 web1 kernel: CPU 0: hi: 186, btch: 31 usd: 36
Sep 10 01:07:31 web1 kernel: CPU 1: hi: 186, btch: 31 usd: 0
Sep 10 01:07:31 web1 kernel: CPU 2: hi: 186, btch: 31 usd: 18
Sep 10 01:07:31 web1 kernel: CPU 3: hi: 186, btch: 31 usd: 0
Sep 10 01:07:31 web1 kernel: HighMem per-cpu:
Sep 10 01:07:31 web1 kernel: CPU 0: hi: 186, btch: 31 usd: 54
Sep 10 01:07:31 web1 kernel: CPU 1: hi: 186, btch: 31 usd: 0
Sep 10 01:07:31 web1 kernel: CPU 2: hi: 186, btch: 31 usd: 0
Sep 10 01:07:31 web1 kernel: CPU 3: hi: 186, btch: 31 usd: 22
Sep 10 01:07:31 web1 kernel: active_anon:7174 inactive_anon:3515 isolated_anon:0
Sep 10 01:07:31 web1 kernel: active_file:156159 inactive_file:133601 isolated_file:0
Sep 10 01:07:31 web1 kernel: unevictable:0 dirty:12 writeback:0 unstable:0
Sep 10 01:07:31 web1 kernel: free:39375 slab_reclaimable:166268 slab_unreclaimable:3027
Sep 10 01:07:31 web1 kernel: mapped:1913 shmem:8277 pagetables:95 bounce:0
Sep 10 01:07:31 web1 kernel: DMA free:2908kB min:88kB low:108kB high:132kB active_anon:0kB inactive_anon:0kB active_file:292kB inactive_file:296kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15808kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:988kB slab_unreclaimable:132kB kernel_stack:72kB pagetables:20kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:11075 all_unreclaimable? yes
Sep 10 01:07:31 web1 kernel: lowmem_reserve[]: 0 702 2008 2008
Sep 10 01:07:31 web1 kernel: Normal free:5376kB min:4004kB low:5004kB high:6004kB active_anon:0kB inactive_anon:0kB active_file:2316kB inactive_file:2264kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:719320kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:664084kB slab_unreclaimable:11976kB kernel_stack:512kB pagetables:360kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:84892 all_unreclaimable? yes
Sep 10 01:07:31 web1 kernel: lowmem_reserve[]: 0 0 10444 10444
Sep 10 01:07:31 web1 kernel: HighMem free:149216kB min:512kB low:2372kB high:4236kB active_anon:28696kB inactive_anon:14060kB active_file:622028kB inactive_file:531844kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1336932kB mlocked:0kB dirty:48kB writeback:0kB mapped:7652kB shmem:33108kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Sep 10 01:07:31 web1 kernel: lowmem_reserve[]: 0 0 0 0
Sep 10 01:07:31 web1 kernel: DMA: 231*4kB 126*8kB 21*16kB 4*32kB 2*64kB 1*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2908kB
Sep 10 01:07:31 web1 kernel: Normal: 1310*4kB 18*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 5384kB
Sep 10 01:07:31 web1 kernel: HighMem: 18118*4kB 7805*8kB 836*16kB 27*32kB 1*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 149216kB
Sep 10 01:07:31 web1 kernel: 298087 total pagecache pages
Sep 10 01:07:31 web1 kernel: 35 pages in swap cache
Sep 10 01:07:31 web1 kernel: Swap cache stats: add 2601, delete 2566, find 2926/3087
Sep 10 01:07:31 web1 kernel: Free swap = 524144kB
Sep 10 01:07:31 web1 kernel: Total swap = 524284kB
Sep 10 01:07:31 web1 kernel: 1050608 pages RAM
Sep 10 01:07:31 web1 kernel: 865282 pages HighMem
Sep 10 01:07:31 web1 kernel: 537706 pages reserved
Sep 10 01:07:31 web1 kernel: 7195 pages shared
Sep 10 01:07:31 web1 kernel: 468537 pages non-shared
Sep 10 01:07:31 web1 kernel: [ pid ] uid tgid total_vm rss cpu oom_adj oom_score_adj name
Sep 10 01:07:31 web1 kernel: [ 1059] 0 1059 552 184 3 -17 -1000 udevd
Sep 10 01:07:31 web1 kernel: [ 2196] 104 2196 470 175 0 0 0 rpc.statd
Sep 10 01:07:31 web1 kernel: [ 2323] 0 2323 1044 575 2 0 0 syslog-ng
Sep 10 01:07:31 web1 kernel: [ 2334] 0 2334 1332 252 3 -17 -1000 sshd
Sep 10 01:07:31 web1 kernel: [ 2360] 101 2360 1047 303 3 0 0 ntpd
Sep 10 01:07:31 web1 kernel: [ 2426] 0 2426 425 125 0 0 0 getty
Sep 10 01:07:31 web1 kernel: [32223] 0 32223 523 220 0 0 0 cron
Sep 10 01:07:31 web1 kernel: [ 8378] 0 8378 3478 566 0 0 0 monit
Sep 10 01:07:31 web1 kernel: [31143] 0 31143 15446 2689 0 0 0 apache2
Sep 10 01:07:31 web1 kernel: [15030] 0 15030 606 228 2 0 0 cron
Sep 10 01:07:31 web1 kernel: [15034] 0 15034 622 248 3 0 0 sh
Sep 10 01:07:31 web1 kernel: [15100] 0 15100 429 58 2 0 0 rm
Sep 10 01:07:31 web1 kernel: Out of memory: Kill process 2196 (rpc.statd) score 1 or sacrifice child
Sep 10 01:07:31 web1 kernel: Killed process 2196 (rpc.statd) total-vm:1880kB, anon-rss:124kB, file-rss:576kB
而且,由于当时是凌晨 1 点,几乎没有 Apache 连接。
如您所见,交换区根本没有被使用。仍有相当多的可用内存(根据 monit)。
有什么想法可以让我找出原因吗?
另外,根据 pidstat,占用大量 CPU 的“flush-0:17”是什么?
答案1
从日志输出来看,apache 正在尝试 malloc 一个非常大的分配。要弄清楚原因,您可能需要查看 apache 设置并查看什么可以做到这一点(您是否使用 mod_perl、mod_python 等)。如果您无法通过这种方式找到它,您可以在 apache 前面放置一个像 nginx 这样的代理,然后 nginx 将记录哪个请求失败。如果您愿意,您可以在同一个主机上运行 nginx,然后使用 limits 命令来限制 apache,以便在调用 oom killer 之前将其杀死(让 nginx 继续,或 urlsnarf 等)。
flush PID 是处理同步 VFS 缓存缓冲区的内核线程。很可能与 rm 有关。您可以通过查找 flush 线程及其工作的设备并验证 rm 正在处理的设备来进行验证:
# ps axwwu | grep flush
root 21658 0.0 0.0 0 0 ? S 21:33 0:00 [flush-8:16]
# ls -l /dev/ | grep 8 | grep 16
brw-rw---- 1 root disk 8, 16 2011-09-13 13:53 sdb
答案2
您的系统已耗尽低内存(直接映射到内核虚拟内存空间的 RAM)。在 32 位 Linux 系统中,内核最多可使用大约 700-800 MB 的物理 RAM 来存储其内部数据(添加更多 RAM 实际上会使情况变得更糟,因为内存管理器使用的数据结构需要更多低内存)。其余 RAM 进入“高内存”区域,可供用户空间进程和页面缓存使用,但内核本身无法使用。
摘自您的日志:
DMA free:2908kB ... present:15808kB ...
Normal free:5376kB ... present:719320kB ... slab_reclaimable:664084kB slab_unreclaimable:11976kB ...
HighMem free:149216kB ... present:1336932kB ...
DMA 区域是与过时的 ISA 设备配合使用所需的低 16 MB;如今,它基本上可以忽略不计。低内存是 DMA 和正常区域的总和;只有此内存可用于保存内核数据。其余内存进入 HighMem 区域。
请注意,HighMem 区域中有大量可用内存,但系统仍然耗尽了内存,因为内核使用的某些结构需要内存,而 HighMem 不适合这样做。而 Normal 区域的大部分被 slab 缓存(slab_reclaimable
和slab_unreclaimable
)占用 — 这是另一个内核内存分配器,用于分配小于页面的块。不幸的是,无法从日志中找出哪些 slab 分配占用了这么多内存(可以从中读取当前 slab 缓存使用情况统计信息/proc/slabinfo
;也许您需要为这些数据设置一些监控)。
真正的问题可能是内核中的一些内存泄漏错误;/proc/slabinfo
如果问题再次发生,监控应该有助于找出原因。
答案3
从我的角度来看,OOM Killer 并不总是会终止有问题的进程。但是,如果你有 apache(prefork?),最常见的情况是它会导致内存占用。
而且,由于当时是凌晨 1 点,几乎没有 Apache 连接。
我会在这里小心一点。你无法知道你有多少个连接(或者也许你可以?-抱歉)。调用像 Collectd 这样的工具,它可以非常密集地绘制图表,在这种情况下非常有用:内存、tcp 连接数(当然是在 apache 使用的端口上)以及 http 错误(尤其是服务器错误 50x)。
我有时会感到震惊,服务器上 20 秒内可以发生多少变化。
您拥有的以下值有哪些:vm.overcommit_memory vm.overcommit_ratio(这可能太低导致过早终止进程)您的平均 apache 进程内存使用量是多少?
答案4
'rm' 到底在做什么?可能是清除了脚本遗漏的某些缓存,因此开始重建?是否有搜索引擎不幸在同一时间进行抓取?也许是缓存遗漏风暴?