天天看點

由hugepage設定導緻的資料庫事故

近期客戶希望提高業務處理能力,在現有的環境中加入幾台weblogic伺服器,是以需要增加一下連接配接數的配置,但是同時他們想對現有系統的設定一些變更,最後發送了一個清單給我們。

大體的變更如下:

Change Processes from 10000 to 18000

Change PGA from 10G to 20G

Change Buffer Cache from 20G to 40G

Change Shared pool from 10G to 20G

HugePage from 60 GB to 120GB

大體看了下沒有什麼問題,他們就去做了,等到今天早上的時候,檢視資料庫的負載,沒有發現什麼問題。但是使用top指令的時候發現近300G的記憶體,怎麼隻剩下50G了。

top - 10:21:47 up 43 days,  8:14,  2 users,  load average: 29.35, 29.56, 25.51

Tasks: 4524 total,  11 running, 4508 sleeping,   0 stopped,   5 zombie

Cpu(s):  3.0%us,  0.9%sy,  0.0%ni, 95.9%id,  0.1%wa,  0.0%hi,  0.2%si,  0.0%st

Mem:  288568372k total, 235419644k used, 53148728k free,  1982988k buffers

Swap: 377487328k total,        0k used, 377487328k free, 66761268k cached

這個問題有些奇怪,這台伺服器上還跑着幾台資料庫執行個體,但是據我所知,消耗的緩存其實并不大,其它幾個庫的sga都在10G以内。

使用ipcs -a 來檢視共享記憶體段的問題。

------ Shared Memory Segments --------

key        shmid      owner      perms      bytes      nattch     status

0x00000000 251789314  root      644        80         2

0x00000000 251822084  root      644        16384      2

0x00000000 251854853  root      644        280        2

0x5500025e 251887622  root      644        256064     1                 locked

0xdb22d1bc 252182538  xxxxx1     660        3340763136 31

0x91442618 252248075  xxxxxx2  660        4096       0

0xba17ff18 252510220  oraccbs1  660        68067262464 3073

0xd9152b54 252379149  oraarcs1  660        3542089728 36

...

使用vmstat來檢視

> 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 st

16  0      0 51928680 1983028 67193648    0    0   349   452    0    0  3  1 96  0  0

15  0      0 51898956 1983028 67195296    0    0 75000  8015 43425 108231 12  6 81  0  0

使用free -m來檢視。

> free -m

             total       used       free     shared    buffers     cached

Mem:        281805     225747      56057          0       1936      65625

-/+ buffers/cache:     158185     123619

Swap:       368639          0     368639

這個時候從業務部門和開發部門的回報來說還沒有什麼問題,是以就準備吃個飯回來繼續查。

過了一會回來的時候,連接配接資料庫時發現資料庫一下子特别慢,敲一個指令都得等好一會兒才能傳回結果。

馬上使用top檢視系統情況,發現剩餘程序隻有500M左右了。

> top -c

top - 12:23:12 up 43 days, 10:15, 13 users,  load average: 301.41, 205.59, 166.94

Tasks: 6701 total, 144 running, 6549 sleeping,   0 stopped,   8 zombie

Cpu(s):  2.8%us, 95.2%sy,  0.0%ni,  1.6%id,  0.1%wa,  0.0%hi,  0.2%si,  0.0%st

Mem:  288568372k total, 288021512k used,   546860k free,     1108k buffers

Swap: 377487328k total, 10312300k used, 367175028k free, 64311712k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND

28855 root      11  -5     0    0    0 S 84.9  0.0 728:45.31 [vxfs_thread]

30951 oraccbs1  25   0 63.6g 7.1g 7.1g R 58.7  2.6   4:44.29 ora_p025_CUST01

3852 root      20  -5     0    0    0 R 52.2  0.0  22:53.66 [kswapd3]

3849 root      20  -5     0    0    0 R 52.1  0.0   7:12.63 [kswapd0]

3851 root      20  -5     0    0    0 R 52.1  0.0  17:42.67 [kswapd2]

3850 root      20  -5     0    0    0 R 52.1  0.0   8:09.50 [kswapd1]

31028 oraccbs1  25   0 63.6g 5.9g 5.9g R 37.7  2.2   5:12.19 ora_p027_CUST01

31273 oraccbs1  19   0 63.6g 206m 203m R 35.6  0.1   0:09.73 oracleCUST01 (LOCAL=NO)

30511 oraccbs1  25   0 63.6g 4.3g 4.3g R 34.6  1.6   8:32.08 ora_p004_CUST01

21481 tivoliam  15   0  977m 255m 5248 S 27.2  0.1   6338:00 /opt/app/IBM/ITM/lx8266/lz/bin/klzagent

29115 oraccbs1  18   0 18008 6392  812 R 27.2  0.0   0:53.76 top -c

32090 oraccbs1  25   0 63.6g  69m  67m R 26.7  0.0   0:05.92 oracleCUST01 (LOCAL=NO)

31332 oraccbs1  18   0 63.6g  26m  18m S 23.9  0.0   0:08.28 ora_p171_CUST01

從程序來看,出現了幾個kswapd的top程序還有一些并行相關的程序。

從ipcs的情況來看,程序數從原來的3000多個增長到了5000多個,這個是由于一些背景的job和daemon啟動了的原因,除此之外沒有發現其它的不同。

0xdb22d1bc 252182538  xxxxx    660        3340763136 32

0x91442618 252248075  xxxxxxx  660        4096       0

0xba17ff18 252510220  oraccbs1  660        68067262464 5207

0xd9152b54 252379149  oraarcs1  660        3542089728 35

來看看奇怪的kswapd程序的說明。

Linux uses kswapd for virtual memory management such that pages that have been recently accessed are kept in memory and less active pages are paged out to disk.

這個和虛拟記憶體管理相關,存在着大量的頁面置換。如果驗證這一點,可以從vmstat來說明。

> vmstat 1 3

611  7 10799976 547000   1444 64194804    0    0   351   452    0    0  3  1 96  0  0

536  1 10799984 546716   1508 64194876  252  108   614   361 1062 108275  7 93  1  0  0

428  2 10800060 548112   1516 64195268   48  204   436   437 1052 111422  9 86  5  0  0

swpd的值在之前都是為0,說明存在着大量的置換操作。

從業務部門和開發部門的一些同僚回報,資料庫已經連不上了。

這個時候我趕快發送了一封郵件抄給客戶的dba組,讓他們趕緊檢視一些記憶體異常的問題,同時我在遠端也在看。這樣問題就不會很被動,同步一些資訊給客戶,可能他們已經在關注或者在查了,能避免很多的誤解。

我比對了核心參數的設定發現,核心參數沒有任何的變化。

主要的核心參數通過cat /etc/sysctl.conf來檢視

排除了核心參數變更帶來的影響,來看看并行程序,檢視此時系統中并行程序大概有170多個,這對系統确實是比較高的負載,但是從近這些天的負載來看,每天都有一個時間段内會啟用一些Job,daemon。有幾個job在啟動的時候會消耗大量的cpu,io資源,已經在産品級做了優化,但是持續的時間不會太長,大概10多分鐘就正常了,這個問題從發現到現在已經持續了将近半個多小時了。

而且設定了較大的buffer cache,shared pool已經效果更好才對。是以從程式的角度來說,沒有任何變化,不會有明确的原因是由于程式中的并行導緻的。

這個時候問題陷入了僵局,但是需要快速給出一些解決方案。

從頭開始來看,出現kswapd3的的原因是由于記憶體使用緊張導緻的,那麼300G左右的記憶體,設定了60G左右的Hugepage,怎麼還不夠用呢,從Hugepage的情況來看一下。

> cat /proc/meminfo | grep -i page

AnonPages:    21223132 kB

PageTables:   136301560 kB

HugePages_Total: 30000

HugePages_Free:  27284

HugePages_Rsvd:    566

Hugepagesize:     2048 kB

這一看确實讓人奇怪,設定了那麼大的hugepage怎麼還剩餘這麼多呢,基本都沒有用到。

怎麼能夠證明在hugepage的設定出現問題呢,

一個原因就是客戶發送的變更清單,HugePage from 60 GB to 120GB ,清單上說需要變更為60G到120G,但是從目前的情況來看,似乎這個變更沒有設定或是沒有生效。

如果放開一步說,60G的變更沒有設定為120G,怎麼能夠證明60G是錯誤的呢。

這個時候還是得靠日志,資料庫啟動的時候會産生一些hugepage相關的資訊。

正常情況下,如果hugepage設定正常,可以從資料庫的日志中我們發現如下的一段内容。

Starting ORACLE instance (normal)

****************** Huge Pages Information *****************

Huge Pages memory pool detected (total: 30000 free: 28822)

DFLT Huge Pages allocation successful (allocated: 17025)

***********************************************************

但是從昨天查到的資料庫日志内容如下:

Instance terminated by USER, pid = 6885

Tue Jan 27 01:03:18 2015

Huge Pages memory pool detected (total: 30000 free: 27287)

Huge Pages allocation failed (free: 29431 required: 32457)

Allocation will continue with default/smaller page size

**********************************************************

這樣一來問題就很明顯了,我們來做一個簡單的演算。

昨晚的變更如下:

HugePage from 60 GB to 120GB 

那麼SGA為20+40G+(large_pool+stream_pool+java_pool.....) >60G

而根據錯誤日志的推算每個hugepage大小為2M,需要32457個,那麼大小就是32457*2M=64914M

而設定的最大值為60G,是以無法啟用進而導緻了系統的嚴重問題。

最後和客戶商量,他們把SGA,PGA的大小都恢複到原有的值,保證能夠穩定運作的前提下,稍後再安排做hugepage的優化。最後把這個庫failover到另外一台server中,再次檢視就沒有問題了。

使用top指令的結果如下:

Tasks: 5238 total,  14 running, 5218 sleeping,   0 stopped,   6 zombie

Cpu(s): 14.2%us,  4.1%sy,  0.0%ni, 80.1%id,  0.1%wa,  0.2%hi,  1.3%si,  0.0%st

Mem:  363033360k total, 97577104k used, 265456256k free,   770016k buffers

Swap: 377487328k total,        0k used, 377487328k free, 13109108k cached

這個問題帶給大家的反思就是任何細小的問題都可能帶來嚴重的系統影響,需要認真評估,才能把問題扼殺在搖籃裡。