本文主要是介绍记一次 OOM内存溢出案例,希望对大家解决编程问题提供一定的参考价值,需要的开发者们随着小编来一起学习吧!
在linux中,出现killed的原因是系统资源不足或内存不足;当系统资源不足时,Linux内核也可以决定终止一个或多个进程,内存不足时会在系统的物理内存耗尽时触发killed,可以利用“dmesg | tail -7”命令来查看killed日志。
linux出现killed的原因是什么
触发Killed常见原因
当系统资源不足时,Linux 内核也可以决定终止一个或多个进程。 一个非常常见的例子是内存不足 (OOM) killer,会在系统的物理内存耗尽时触发。
当内存不足时,内核会将相关信息记录到内核日志缓冲区中,该缓冲区可通过 /dev/kmsg 获得。
有几个工具/脚本/命令 可以更轻松地从该虚拟设备读取数据,其中最常见的是 dmesg 和 journalctl。
查看Killed日志
使用sudo dmesg | tail -7命令(任意目录下,不需要进入log目录,这应该是最简单的一种)
可以看到:oom-kill之后,就是解释那个被killed的程序的pid和uid
Out of memory: Killed process 1138439 (python3) total-vm:8117956kB, anon-rss:5649844kB,内存不够
- total_vm:总共使用的虚拟内存 Virtual memory use (in 4 kB pages)
8117956/1024(得到MB)/1024(得到GB)=7.741GB
- rss:常驻内存使用Resident memory use (in 4 kB pages)
5649844/1024/1024=5.388GB
补充:
Nov 22 11:09:03 VM_0_14_centos kernel: [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name
Nov 22 11:09:03 VM_0_14_centos kernel: [19272] 0 19272 678212 422656 1329 0 0 nmap
Nov 22 11:09:03 VM_0_14_centos kernel: Out of memory: Kill process 19272 (nmap) score 873 or sacrifice child
Nov 22 11:09:03 VM_0_14_centos kernel: Killed process 19272 (nmap) total-vm:2712848kB, anon-rss:1690624kB, file-rss:0kB, shmem-rss:0kB
实际占用内存计算: RSS(物理内存页)大小是 4kB,可以查看 messages 日志中打印的 rss 数值(进程占用的物理内存页数量) 例如这里我们看到 nmap 进程占用最高,实际占用物理内存页是422656,乘以4KB等于 1690624KB,除以 1024 等于 1651MB
日志解读
下面是从oom killer被触发到进程到被杀掉的一个大概过程,我们来具体看一下。
nginx invoked oom-killer: gfp_mask=0x200da, order=0, oom_score_adj=0
nginx cpuset=6011a7f12bac1c4592ce41407bb41d49836197001a0e355f5a1d9589e4001e42 mems_allowed=0
CPU: 1 PID: 10242 Comm: nginx Not tainted 3.13.0-86-generic #130-Ubuntu
Hardware name: Xen HVM domU, BIOS 4.0.1 12/16/20140000000000000000 ffff880070611a00 ffffffff8172a3b4 ffff88012af6c8000000000000000000 ffff880070611a88 ffffffff8172495d ffffffff81069b76ffff880070611a60 ffffffff810ca5ac ffff88020fff7e38 0000000000000000
Node 0 DMA free:15908kB min:128kB low:160kB high:192kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
lowmem_reserve[]: 0 3746 7968 7968
Node 0 DMA32 free:48516kB min:31704kB low:39628kB high:47556kB active_anon:3619272kB inactive_anon:216kB active_file:556kB inactive_file:1516kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3915776kB managed:3836724kB mlocked:0kB dirty:4kB writeback:0kB mapped:324kB shmem:1008kB slab_reclaimable:67136kB slab_unreclaimable:67488kB kernel_stack:1792kB pagetables:14540kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:7365 all_unreclaimable? yes
lowmem_reserve[]: 0 0 4221 4221
Node 0 Normal free:35640kB min:35748kB low:44684kB high:53620kB active_anon:4019124kB inactive_anon:292kB active_file:1292kB inactive_file:2972kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:4456448kB managed:4322984kB mlocked:0kB dirty:24kB writeback:4kB mapped:1296kB shmem:1324kB slab_reclaimable:81196kB slab_unreclaimable:83432kB kernel_stack:3392kB pagetables:20252kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned: 7874 all_unreclaimable? yes
lowmem_reserve[]: 0 0 0 0
Node 0 DMA: 1*4kB (U) 0*8kB 0*16kB 1*32kB (U) 2*64kB (U) 1*128kB (U) 1*256kB (U) 0*512kB 1*1024kB (U) 1*2048kB (R) 3*4096kB (M) = 15908kB Node 0 DMA32: 1101*4kB (UE) 745*8kB (UEM) 475*16kB (UEM) 263*32kB (EM) 88*64kB (UEM) 25*128kB (E)12*256kB (EM) 6*512kB (E) 7*1024kB (EM) 0*2048kB 0*4096kB = 48524kB
Node 0 Normal: 5769*4kB (EM) 1495*8kB (EM) 24*16kB (UE) 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 35420kB
Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
2273 total pagecache pages
0 pages in swap cache
Swap cache stats: add 0, delete 0, find 0/0
Free swap = 0kB
Total swap = 0kB
2097054 pages RAM
0 pages HighMem/MovableOnly
33366 pages reserved
[ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name
[ 355] 0 355 4868 66 13 0 0 upstart-udev-br
[ 361] 0 361 12881 145 28 0 -1000 systemd-udevd
[ 499] 0 499 3814 60 13 0 0 upstart-socket-
[ 562] 0 562 5855 79 15 0 0 rpcbind
[ 644] 106 644 5398 142 16 0 0 rpc.statd
[ 775] 0 775 3818 58 12 0 0 upstart-file-br
...(此处有省略)
[10396] 104 10396 21140 12367 44 0 0 nginx
[10397] 104 10397 21140 12324 44 0 0 nginx
[10398] 104 10398 21140 12324 44 0 0 nginx
[10399] 104 10399 21140 12367 44 0 0 nginx
Out of memory: Kill process 10366 (nginx) score 6 or sacrifice child
Killed process 10366 (nginx) total-vm:84784kB, anon-rss:49156kB, file-rss:520kB
先来看一下第一行,它给出了oom killer是由谁触发的信息。
nginx invoked oom-killer: gfp_mask=0x200da, order=0, oom_score_adj=0
order=0 告诉我们所请求的内存的大小是多少,即nginx请求了2的0次方这么多个page的内存,也就是一个page,或者说是4KB。
gfp_mask的最后两个bit代表的是zone mask,也就是说它指明内存应该从哪个区来分配。
Flag value Description
0x00u 0 implicitly means allocate from ZONE_NORMAL
__GFP_DMA 0x01u Allocate from ZONE_DMA if possible
__GFP_HIGHMEM 0x02u Allocate from ZONE_HIGHMEM if possible
(这里有一点需要注意,在64位的x86系统中,是没有highmem区的,64位系统中的normal区就对应上表中的highmem区。)
在本案例中,zonemask是2,也就是说nginx正在从zone-normal(64位系统)中请求内存。
其他标志位的含义如下:
#define __GFP_WAIT 0x10u /* Can wait and reschedule? */
#define __GFP_HIGH 0x20u /* Should access emergency pools? */
#define __GFP_IO 0x40u /* Can start physical IO? */
#define __GFP_FS 0x80u /* Can call down to low-level FS? */
#define __GFP_COLD 0x100u /* Cache-cold page required */
#define __GFP_NOWARN 0x200u /* Suppress page allocation failure warning */
#define __GFP_REPEAT 0x400u /* Retry the allocation. Might fail */
#define __GFP_NOFAIL 0x800u /* Retry for ever. Cannot fail */
#define __GFP_NORETRY 0x1000u /* Do not retry. Might fail */
#define __GFP_NO_GROW 0x2000u /* Slab internal usage */
#define __GFP_COMP 0x4000u /* Add compound page metadata */
#define __GFP_ZERO 0x8000u /* Return zeroed page on success */
#define __GFP_NOMEMALLOC 0x10000u /* Don't use emergency reserves */
#define __GFP_NORECLAIM 0x20000u /* No realy zone reclaim during allocation */
所以我们当前这个内存请求带有这几个标志:GFP_NORECLAIM,GFP_FS,GFP_IO,GFP_WAIT, 都是比较正常的几个标志,那么我们这个请求为什么会有问题呢?继续往下看,可以看到下面的信息:
Node 0 Normal free:35640kB min:35748kB low:44684kB high:53620kB active_anon:4019124kB inactive_anon:292kB active_file:1292kB inactive_file:2972kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:4456448kB managed:4322984kB mlocked:0kB dirty:24kB writeback:4kB mapped:1296kB shmem:1324kB slab_reclaimable:81196kB slab_unreclaimable:83432kB kernel_stack:3392kB pagetables:20252kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB pages_scanned: 7874 all_unreclaimable? yes
可以看到normal区free的内存只有35640KB,比系统允许的最小值(min)还要低,这意味着application已经无法再从系统中申请到内存了,并且系统会开始启动oom killer来缓解系统内存压力。
这里我们说一下一个常见的误区,就是有人会认为触发了oom-killer的进程就是问题的罪魁祸首,比如我们这个例子中的这个nginx进程。其实日志中invoke oom-killer的这个进程有时候可能只是一个受害者,因为其他应用/进程已将系统内存用尽,而这个invoke oomkiller的进程恰好在此时发起了一个分配内存的请求而已。在系统内存已经不足的情况下,任何一个内存请求都可能触发oom killer的启动。
oom-killer的启动会使系统从用户空间转换到内核空间。内核会在短时间内进行大量的工作,比如计算每个进程的oom分值,从而筛选出最适合杀掉的进程。我们从日志中也可以看到这一筛选过程:
[ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name
[ 355] 0 355 4868 66 13 0 0 upstart-udev-br
[ 361] 0 361 12881 145 28 0 -1000 systemd-udevd
[ 499] 0 499 3814 60 13 0 0 upstart-socket-
[ 562] 0 562 5855 79 15 0 0 rpcbind
[ 644] 106 644 5398 142 16 0 0 rpc.statd
[ 775] 0 775 3818 58 12 0 0 upstart-file-br
...
[10396] 104 10396 21140 12367 44 0 0 nginx
[10397] 104 10397 21140 12324 44 0 0 nginx
[10398] 104 10398 21140 12324 44 0 0 nginx
[10399] 104 10399 21140 12367 44 0 0 nginx
本例中,一个nginx进程被选中作为缓解内存压力的牺牲进程:
Out of memory: Kill process 10366 (nginx) score 6 or sacrifice child
Killed process 10366 (nginx) total-vm:84784kB, anon-rss:49156kB, file-rss:520kB
整个过程进行的时间很短,只有毫秒级别,但是工作量/计算量很大,这就导致了cpu短时间内迅速飙升,出现峰值。但这一切工作都由内核在内核空间中完成,所以用户在自己的业务监控数据上并不会看到业务量的异常。这些短时间升高的cpu是内核使用的,而不是用户的业务。
本例中客户只是偶尔看到这个现象,且业务并没有受到影响。我们给客户的建议是分析业务内存需求量最大值,如果系统已经没有办法满足特定时段业务的内存需求,建议用户升级内存来避免oom的情况发生,因为严重的oom情况是可能引发系统崩溃的。
这篇关于记一次 OOM内存溢出案例的文章就介绍到这儿,希望我们推荐的文章对编程师们有所帮助!