天天看点

由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

这个问题带给大家的反思就是任何细小的问题都可能带来严重的系统影响,需要认真评估,才能把问题扼杀在摇篮里。