Linux物理内存较少导致OOM问题分析

背景

开发项目过程中，发现盒子启动后物理内存持续的减少，CMA内存过了一段时间后也出现明显减少情况，到最后会低概率性的出现OOM杀掉进程的情况；通过ps命令监控所有进程在开机后的虚拟内存VSZ没有明显的增加，说明不是用户进程申请的内存出现的泄漏，目前怀疑是某个进程频繁读写文件导致缓存持续增大，导致了虚拟内存持续减少。

OOM打印

umts_traffic.sh invoked oom-killer: gfp_mask=0x27000c0(GFP_KERNEL_ACCOUNT|__GFP_NOTRACK), nodemask=0, order=1, oom_score_adj=0
CPU: 0 PID: 3603 Comm: umts_traffic.sh Not tainted 4.9.11 #1
Hardware name: Freescale i.MX6 UltraLite (Device Tree)
[<c010e540>] (unwind_backtrace) from [<c010b61c>] (show_stack+0x18/0x1c)
[<c010b61c>] (show_stack) from [<c0205124>] (dump_header+0x70/0x1c0)
[<c0205124>] (dump_header) from [<c01bff4c>] (oom_kill_process+0xcc/0x470)
[<c01bff4c>] (oom_kill_process) from [<c01c065c>] (out_of_memory+0x1d8/0x3f8)
[<c01c065c>] (out_of_memory) from [<c01c4754>] (__alloc_pages_nodemask+0x9ac/0xa98)
[<c01c4754>] (__alloc_pages_nodemask) from [<c0122098>] (copy_process.part.5+0xf8/0x1654)
[<c0122098>] (copy_process.part.5) from [<c0123768>] (_do_fork+0xc4/0x3a0)
[<c0123768>] (_do_fork) from [<c0123b28>] (SyS_clone+0x24/0x2c)
[<c0123b28>] (SyS_clone) from [<c0107000>] (ret_fast_syscall+0x0/0x3c)
Mem-Info:
active_anon:2337 inactive_anon:64 isolated_anon:0
 active_file:257 inactive_file:187 isolated_file:41
 unevictable:25598 dirty:0 writeback:0 unstable:0
 slab_reclaimable:872 slab_unreclaimable:1267
 mapped:489 shmem:64 pagetables:271 bounce:0
 free:22334 free_pcp:18 free_cma:13391
Node 0 active_anon:9348kB inactive_anon:256kB active_file:376kB inactive_file:384kB unevictable:102548kB isolated(anon):0kB isolated(file):128kB mapped:996kB dirty:0kB writeback:4kB shmem:256kB writeback_tmp:0kB unstable:0kB pages_scanned:32 all_unreclaimable? no
Normal free:90216kB min:24000kB low:30000kB high:36000kB active_anon:9348kB inactive_anon:256kB active_file:444kB inactive_file:448kB unevictable:102708kB writepending:0kB present:262144kB managed:251684kB mlocked:0kB slab_reclaimable:3488kB slab_unreclaimable:5068kB kernel_stack:992kB pagetables:1084kB bounce:0kB free_pcp:116kB local_pcp:116kB free_cma:54316kB
lowmem_reserve[]: 0 0 0
Normal: 1267*4kB (MHC) 716*8kB (UMHC) 430*16kB (UMHC) 209*32kB (UMHC) 75*64kB (UMHC) 34*128kB (HC) 14*256kB (HC) 6*512kB (HC) 5*1024kB (HC) 6*2048kB (HC) 2*4096kB (C) 1*8192kB (C) 1*16384kB (C) 0*32768kB = 90348kB
26213 total pagecache pages
0 pages in swap cache
Swap cache stats: add 0, delete 0, find 0/0
Free swap  = 0kB
Total swap = 0kB
65536 pages RAM
0 pages HighMem/MovableOnly
2615 pages reserved
16384 pages cma reserved
[ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
[  146]     0   146      372       13       5       0        0             0 logger
[  188]     0   188      432       68       4       0        0             0 gild
[  193]     0   193      386       73       4       0        0             0 uild
[  316]     0   316      435      161       4       0        0             0 syslogd
[  324]     0   324      371      131       3       0        0             0 klogd
[095.661]recv: 4M 1K 944B  in 3557 msec
[  339]     0   339      404       95       4       0        0             0 hotplug2
[  354]     0   354      362       29       4       0        0             0 fonstated
[  361]     0   361      443       59       6       0        0             0 ubusd
[  381]     0   381      371        8       3       0        0             0 httpd
[  390]     0   390      422      181       4       0        0             0 uadcd
[  392]     0   392      535       62       4       0        0             0 ucand
[  398]     0   398      371       23       4       0        0             0 watchdog
[  402]     0   402      424       79       5       0        0             0 ugpiod
[  411]     0   411      436       24       4       0        0             0 dropbear
[  432]     0   432      422       51       5       0        0             0 upowerd
[  442]     0   442      530      132       5       0        0             0 usensord
[  448]     0   448      645      106       6       0        0             0 ugpsd
[  458]     0   458      545       54       5       0        0             0 useriald
[  464]     0   464      530      147       5       0        0             0 uvehicled
[  639]     0   639      433       31       3       0        0             0 dnsmasq
[  678]     0   678      483       40       6       0        0             0 iccard
[  699]     0   699     8137      340      11       0        0             0 ifotond
[  708]     0   708     4539      263       9       0        0             0 tigerfaced
[  709]     0   709     3416      272       6       0        0             0 ifotond-c
[  710]     0   710     5177       70       8       0        0             0 eold
[  746]     0   746     2906       84       7       0        0             0 maudiod
[  788]     0   788      493       48       5       0        0             0 mild
[  789]     0   789     5464      114      10       0        0             0 basevdrd
[  804]     0   804     3239      112       7       0        0             0 mavctld
[  813]     0   813      371       12       3       0        0             0 vdrd_dog.sh
[  820]     0   820     2825       60       6       0        0             0 mantd
[  833]     0   833      400       39       4       0        0             0 upalld
[  835]     0   835      371       17       3       0        0             0 check_rild.sh
[ 1084]     0  1084      591      149       5       0        0             0 powermgrd
[ 1106]     0  1106      371       12       3       0        0             0 doiccard.sh
[ 1157]     0  1157      371       13       4       0        0             0 netdetc.sh
[ 1209]     0  1209      526       69       5       0        0             0 msmsd
[ 1246]     0  1246      371       13       3       0        0             0 usbdetc.sh
[ 1251]     0  1251      371       11       4       0        0             0 sms_dog.sh
[ 2588]     0  2588      470       38       5       0        0             0 printer
[ 2952]     0  2952     1783       41       7       0        0             0 rild
[ 2996]     0  2996      372       18       4       0        0             0 ash
[ 3190]     0  3190      371       14       4       0        0             0 nd.sh
[ 3198]     0  3198      404       30       5       0        0             0 umtsd
[ 3221]     0  3221      599       55       5       0        0             0 pppd
[ 3518]     0  3518      371      133       4       0        0             0 check_dns_serve
[ 3603]     0  3603      371       16       3       0        0             0 umts_traffic.sh
[ 3675]     0  3675      356       30       4       0        0             0 platagentd
[ 3688]     0  3688      404       53       4       0        0             0 inform.sh
[ 3720]     0  3720      444       33       6       0        0             0 ntpclient
[29237]     0 29237      385       46       4       0        0             0 QLog
[30748]     0 30748      371        9       4       0        0             0 sleep
[31085]     0 31085      371        9       4       0        0             0 sleep
Out of memory (oom_kill_allocating_task): Kill process 3603 (umts_traffic.sh) score 0 or sacrifice child
Killed process 3603 (umts_traffic.sh) total-vm:1484kB, anon-rss:60kB, file-rss:4kB, shmem-rss:0kB
oom_reaper: reaped process 3603 (umts_traffic.sh), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
doiccard.sh invoked oom-killer: gfp_mask=0x27000c0(GFP_KERNEL_ACCOUNT|__GFP_NOTRACK), nodemask=0, order=1, oom_score_adj=0

第一个被杀掉的进程是umts_traffic.sh后台脚本，说明是其他进程导致内存空间不足引发的问题。

实验

关闭某些常用进程查看物理内存是否明显减少：

	root@www:~# free
                     total         used         free       shared      buffers
	Mem:        251684        86548       165136          256        16764
	-/+ buffers:              69784       181900
	Swap:            0            0            0

发现关闭nev进程后物理内存没有明显减少。

通过了解发现nve没有连接平台时会把数据（盲区实时日志）写在emmc文件中，且数据量大而频繁，文件很大，持续的写入；

	root@www:~# free
                     total         used         free       shared      buffers
	Mem:        251684       201068        50616          256        59832
	-/+ buffers:             141236       110448
	Swap:            0            0            0

这样就会导致文件缓存持续增长，但是为何缓存没有定时的刷新导致了物理内存持续的较少，是这个原因导致概率性的出现OOM情况吗？

写缓存buffers不会被自动清空，因为系统认为后面可能还会用到的，通过上面free信息看到真正可用的内存还有110MB，还远没有达到紧张的地步，所以应该不会引发OOM问题。

分析

手动刷新清空缓存OK，怀疑是内存的刷新缓存机制没有配置正确，待确认。没有找到内核配置。

echo 3 > /proc/sys/vm/drop_caches；清理pagecache、dentries和inodes

读写文件使用的是open,read,write系统调用，不会在用户层产生缓存，这样的话就只能在文件系统层产生缓存，通过free命令和top命令查看到buffers大小好像是写的文件总大小偏小一点，但是通过查看/proc/vmstat没有发现文件系统层存在过多的缓存：

nr_dirty 14    缓存页数量
nr_writeback 0
nr_dirtied 286139
nr_written 286125

page size是4kb，文件系统缓存才几十KB，那为何缓存增大这么多？难道是写完文件后只要内存还够用缓存不会清除，读取的数据到cache然后也不会清除吗？待确认。

惊喜

测试4G模块EC20 Qlog时把log文件存在/tmp下触发了OOM，且每次都要触发，必现的话可见有希望。

查看tmp目录挂载方式：

ramfs on /tmp type ramfs (rw,nosuid,nodev,relatime,mode=1777)

手动dd命令测试触发OOM：

dd if=/dev/zero of=100.img bs=/tmp/1M count=104

通过查询信息得知由于ramfs文件系统不能指定大小，会无限的使用系统内存，在文件较大时会导致系统内存紧张触发OOM。

测试发现写文件104MB会100%触发OOM，系统内存有160多MB可用。

查看tmp目录下，有很多进程写的临时日志文件，可能在异常情况下日志文件会无限增大导致耗尽内存触发OOM。

尝试tmp目录挂载为tmpfs文件系统，并指定size大小为32MB：

/etc/preinit	
	mount -o size=32m -t tmpfs tmpfs /tmp
mount
	tmpfs on /tmp type tmpfs (rw,relatime,size=32768k)
df -h
	Filesystem                Size      Used Available Use% Mounted on
	tmpfs                    32.0M    188.0K     31.8M   1% /tmp
dd
	root@www:~# dd if=/dev/zero of=100.img bs=1M count=32
	32+0 records in
	31+1 records out
	root@www:~# dd if=/dev/zero of=100.img bs=1M count=33
	dd: writing '100.img': No space left on device
	33+0 records in
	31+1 records out
df
	root@www:~# ls -lh
	-rw-r--r--    1 root     root       31.8M Aug 16 13:44 100.img
	tmpfs                    32.0M     32.0M         0 100% /tmp

优化后挂载：tmpfs on /tmp type tmpfs (rw,nosuid,nodev,noatime,size=65536k)，目前没有发现问题

mount -o size=64m,rw,nosuid,nodev,noatime -t tmpfs tmpfs /tmp

总结

1、引发的OOM一般是第二现场，这种问题只能设立假设然后逐步验证，平时写代码需注意内存管理。

2、目前还不知道是哪个进程在异常情况下写满tmp目录导致OOM，使用tmpfs方式只能保护系统不被弄崩溃，后续继续关注此问题，揪出幕后黑手暴打应用程序员。