一次OOM問題排查

作者：彥珝

問題描述

使用者問題：

使用者發現自己的伺服器CPU在某一時刻陡然升高，但從監控上看，同一時刻的業務量卻并不高，客戶懷疑是雲伺服器有問題，希望技術支援團隊予以解決。

經過我們的排查，發現cpu的兩次間歇飙高是由于客戶系統當時發生了OOM（out of memory）的情況，并觸發了oom-killer造成的。但客戶并不接受這個結論，認為是雲伺服器的異常導緻了cpu飙高，而cpu的升高又導緻了oom情況的發生。也就是對于cpu升高和oom誰為因果這件事上，客戶和我們持完全相反的态度。

下面我們将通過對oom時系統日志的解讀來說明cpu升高和oom之間的因果關系。

知識點梳理

1 預備知識

在解讀日志之前，我們先回顧一下linux核心的記憶體管理。

1.1 幾個基本的概念

（1）Page 頁

處理器的最小‘尋址單元’是位元組或者字，而頁是記憶體的‘管理單元’。

（2） Zone 區

（a）區存在的原因：

有些硬體裝置隻能對特定的記憶體位址執行DMA(direct memory access)操作。

在一些架構中，實際實體記憶體是比系統可尋址的虛拟記憶體要大的，這就導緻有些實體記憶體沒有辦法被永久的映射在核心的位址空間中。

區的劃分也是直接以上面兩個原因為依據的。

（b）區的種類

ZONE_DMA—這個區包含的page可以執行DMA操作。這部分區域的大小和CPU架構有關，在x86架構中，該部分區域大小限制為16MB。

ZONE_DMA32—類似于ZOME_DMA, 這個區也包含可以執行DMA操作的page。該區域隻存在于64位系統中，适合32位的裝置通路。

ZONE_NORMAL—這個區包含可以正常映射到位址空間中的page，或者說這個區包含了除了DMA和HIGHMEM以外的記憶體。許多核心操作都僅在這個區域進行。

ZONE_HIGHMEM—這個區包含的是high memory，也就是那些不能被永久映射到核心位址空間的頁。

32位的x86架構中存在三種記憶體區域，ZONE_DMA，ZONE_NORMAL，ZONE_HIGHMEM。根據位址空間劃分的不同，三個區域的大小不一樣：

1）1G核心空間/3G使用者空間

ZONE_DMA	< 16M
ZONE_NORMAL	16M~896M
ZONE_HIGHMEM	> 896

2) 4G核心空間/4G使用者空間

	16M~3968M
	> 3968M

64位的系統由于尋址能力的提高，不存在highmem區，是以64位系統中存在的區有DMA，DMA32和NORMAL三個區。

ZONE_DMA32	16M~4G
	> 4G

1.2 核心配置設定記憶體的函數

下面是核心配置設定記憶體的核心函數之一，它會配置設定2的order次方個連續的實體頁記憶體，并将第一頁的邏輯位址傳回。

unsigned long __get_free_pages(gfp_t gfp_mask, unsigned int order)

核心空間的記憶體配置設定函數和使用者空間最大的不同就是每個函數會有一個gfp_mask參數。

其中gfp 代表的就是我們上面的記憶體配置設定函數 __get_free_pages()。

gfp_mask可以分成三種: 行為修飾符（action modifier）,區修飾符 （zone modifier）和類型（ type）.

（1）行為修飾符是用來指定核心該如何配置設定記憶體的。比如配置設定記憶體時是否可以進行磁盤io，是否可以進行檔案系統操作，核心是否可以睡眠（sleep）等等。

（2）區修飾符指定記憶體需要從哪個區來配置設定。

（3）類型是行為修飾符和區修飾符結合之後的産物。在一些特定的記憶體配置設定場合下，我們可能需要同時指定多個行為修飾符和區修飾符，而type就是針對這些固定的場合，将所需要的行為修飾符和區修飾符都整合到了一起，這樣使用者隻要指定一個type就可以了。

不同type所代表的含義可以參看下面的表格：

2 日志解讀

下面是從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/2014
 0000000000000000 ffff880070611a00 ffffffff8172a3b4 ffff88012af6c800
 0000000000000000 ffff880070611a88 ffffffff8172495d ffffffff81069b76
 ffff880070611a60 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情況是可能引發系統崩潰的。