本文已经发表在ITPUB优化技术丛书,未经许可,不得转载。
1. 问题发现
一大早,接到通知说现网数据库(RAC中的一个节点)出现异常,现象是大量的业务拥堵,系统可用内存很低,经常徘徊在100m左右,随着业务高峰期的时间就要到了,眼看系统的内存已经处在极其危险的状态。
2. 解决过程
2.1. 环境介绍
硬件和软件环境:
HP 7410 ,16G内存,8个CPU,存储是HP XP128
OS版本,HPUX 11.11 + MC 11.15
2节点RAC,oracle版本9.2.0.4
2.2. 问题现象
首先看一下进程的内存情况(HPUX 11.11):
oracle@db02:/oracle > vmstat 2 10
procs memory page faults cpu
r b w avm free re at pi po fr de sr in sy cs us sy id
8 5 0 2659897 54987 127 13 0 0 0 0 23 17401 114389 6145 21 6 73
8 5 0 2659897 54365 4 0 4 0 0 0 0 16032 126259 7605 35 5 60
8 5 0 2659897 54232 2 0 3 0 0 0 0 16043 139904 7705 38 11 51
2 5 0 2664805 53921 0 0 32 0 0 0 0 16252 141213 7843 33 6 60
2 5 0 2664805 56209 0 0 20 0 0 0 0 15828 136485 7592 30 6 65
2 5 0 2664805 55701 0 0 56 0 0 0 0 16330 137069 7952 38 7 54
2 5 0 2664805 55685 0 0 35 0 0 0 0 16819 141478 8098 32 6 62
2 5 0 2664805 53749 0 0 22 0 0 0 0 16855 139303 8003 34 7 59
7 1 0 2620255 51536 172 0 41 0 0 0 0 16521 136507 8093 44 6 50
7 1 0 2620255 51323 109 0 28 0 0 0 0 17859 151458 8623 43 7 50
oracle@db02:/oracle >
我们知道,一般来说,系统的Page out(po)可以有一些,但如果Page in(pi)一般很高,并间歇性的还在逐渐上升,这就要引起注意。总得来说,正常系统的paging 可以有一些,但不能太多。
而这里,很明显,我们可以看见运行队列(r)很高,系统可用的空闲内存极少,并切伴随大量的page in,已经出现了明显的内存不足。同时我们也可以看到用户进程的CPU使用率(us)几乎没有异常,并且他们的cpu的使用率都在合理的范围内(抛除wait-io意味的CPU使用率)。
再使用top观察,是否有大量的极其耗费CPU的进程在操作:
oracle@db02:/oracle > top
System: db02 Fri Mar 4 12:14:47 2005
Load averages: 0.56, 0.57, 0.58
966 processes: 951 sleeping, 15 running
Cpu states:
CPU LOAD USER NICE SYS IDLE BLOCK SWAIT INTR SSYS
0 0.65 30.0% 0.0% 5.7% 64.3% 0.0% 0.0% 0.0% 0.0%
1 0.77 95.7% 0.0% 1.0% 3.4% 0.0% 0.0% 0.0% 0.0%
2 0.64 24.9% 0.0% 11.6% 63.5% 0.0% 0.0% 0.0% 0.0%
3 0.40 36.5% 0.0% 7.3% 56.2% 0.0% 0.0% 0.0% 0.0%
4 0.59 27.2% 0.0% 7.7% 65.1% 0.0% 0.0% 0.0% 0.0%
5 0.54 26.4% 0.0% 7.3% 66.3% 0.0% 0.0% 0.0% 0.0%
6 0.60 17.8% 0.0% 11.4% 70.8% 0.0% 0.0% 0.0% 0.0%
7 0.29 36.3% 0.0% 3.6% 60.2% 0.0% 0.0% 0.0% 0.0%
--- ---- ----- ----- ----- ----- ----- ----- ----- -----
avg 0.56 36.9% 0.0% 6.9% 56.2% 0.0% 0.0% 0.0% 0.0%
Memory: 14829952K (8998976K) real, 20328344K (10419100K) virtual, 227036K free Page# 1/35
CPU TTY PID USERNAME PRI NI SIZE RES STATE TIME %WCPU %CPU COMMAND
7 ? 8946 oracle 241 20 7328M 2148K run 13:56 99.14 98.97 ora_j002_cmc2
4 ? 11551 oracle 241 20 7344M 14384K run 148:31 22.84 22.80 oraclecmc2
0 ? 22315 oracle 221 20 7358M 5668K run 294:01 18.22 18.19 ora_lms0_cmc2
3 ? 22317 oracle 154 20 7358M 5668K sleep 307:13 17.89 17.86 ora_lms1_cmc2
1 ? 9108 oracle 241 20 7328M 2820K run 0:06 17.31 17.28 oraclecmc2
0 ? 9106 oracle 154 20 7328M 2928K sleep 0:22 10.87 10.85 oraclecmc2
1 ? 7044 oracle 154 20 7333M 5720K sleep 0:45 7.25 7.24 oraclecmc2
2 ? 11591 oracle 154 20 7328M 864K sleep 183:59 7.25 7.24 oraclecmc2
4 ? 7235 root 152 20 43172K 7236K run 4:03 7.04 7.02 nco_m_ssmagent
6 ? 11687 oracle 156 20 7328M 852K sleep 86:09 6.27 6.26 oraclecmc2
4 ? 3650 oracle 154 20 7328M 816K sleep 7:11 5.54 5.53 oraclecmc2
0 ? 11384 oracle 154 20 7328M 844K sleep 79:19 5.47 5.46 oraclecmc2
5 ? 8772 oracle 154 20 7328M 2420K sleep 1:00 5.02 5.01 oraclecmc2
3 ? 10083 oracle 154 20 7328M 1052K sleep 71:55 5.00 4.99 oraclecmc2
3 ? 22335 oracle 156 20 7335M 2604K sleep 67:37 4.94 4.94 ora_lgwr_cmc2
2 ? 8836 root -16 10 39044K 18820K run 0:36 3.02 3.01 midaemon
4 ? 3225 oracle 154 20 7328M 844K sleep 3:55 2.95 2.95 oraclecmc2
6 ? 22339 oracle 148 20 7328M 1560K sleep 47:11 2.60 2.60 ora_smon_cmc2
6 ? 0 root 127 20 32K 0K sleep 48:24 2.34 2.34 swapper
2 ? 5115 oracle 154 20 7332M 2072K sleep 4:06 1.73 1.72 oraclecmc2
2 ? 7607 oracle 154 20 7353M 1548K sleep 1:39 1.67 1.67 oraclecmc2
4 ? 22313 oracle 154 20 7334M 3992K sleep 22:38 1.65 1.65 ora_lmd0_cmc2
3 ? 4824 oracle 154 20 7332M 3160K sleep 3:12 1.53 1.53 oraclecmc2
3 ? 4896 oracle 154 20 7332M 3168K sleep 4:05 1.50 1.50 oraclecmc2
1 ? 9697 oracle 154 20 7332M 3460K sleep 4:06 1.50 1.50 oraclecmc2
5 ? 9733 oracle 154 20 7332M 2672K sleep 4:25 1.39 1.39 oraclecmc2
4 ? 11487 oracle 154 20 7328M 1064K sleep 9:46 1.34 1.34 oraclecmc2
oracle@db02:/oracle >
2.3. 对比分析
这里可以清楚的看到空闲内存只有200M,并且几乎每个进程伴随都有很高的wait-io。于是想到对比以前的系统性能记录:
oracle@db02:/oracle > sar -u 2 10
HP-UX db02 B.11.11 U 9000/800 02/08/05
18:32:24 %usr %sys %wio %idle
18:32:26 34 5 19 43
18:32:28 39 7 18 37
18:32:30 37 6 15 42
18:32:32 31 5 12 51
18:32:34 29 4 9 57
18:32:36 28 4 10 57
18:32:38 31 4 14 52
18:32:40 35 5 12 48
18:32:42 39 3 10 49
18:32:44 42 5 16 37
Average 35 5 14 47
oracle@db02:/oracle >
使用sar –u 命令我们看到,那时的系统状态是非常良好的,CPU的idel平均值(%idle)在47%,而系统的wait io(%wio)的平均值在14%,这是一个比较理想的状态。
再来看系统正常时候的内存使用情况:
oracle@db02:/oracle > vmstat 2 10
procs memory page faults cpu
r b w avm free re at pi po fr de sr in sy cs us sy id
5 2 0 930013 1008560 127 9 0 0 0 0 0 17382 114792 6110 21 6 73
6 2 0 988914 1007728 208 40 0 0 0 0 0 15703 128093 7582 47 7 46
6 2 0 988914 1007665 203 50 0 0 0 0 0 15603 127244 7496 42 6 52
6 2 0 988914 1007664 213 63 0 0 0 0 0 15444 126853 7647 48 6 45
6 2 0 988914 1007552 136 40 0 0 0 0 0 15592 133625 7417 39 4 56
6 2 0 988914 1007265 163 54 0 0 0 0 0 15733 140186 7161 40 5 54
4 1 0 1004118 1007248 104 34 0 0 0 0 0 15356 137336 6836 44 5 51
4 1 0 1004118 1006640 130 46 1 0 0 0 0 15461 138396 6926 38 5 57
4 1 0 1004118 1006641 163 59 1 0 0 0 0 16366 148071 7617 42 6 51
4 1 0 1004118 1006640 104 37 1 0 0 0 0 15761 136805 7334 40 4 55
oracle@db02:/oracle >
我们看到,虽然也存在有一些等待队列,但是系统的可用内存在4G左右(free*page size=1008560*4096=4131061760 byte)。系统的几乎没有page in。
情急之下,请业务人员停掉一个应用,以便系统稳定在free memory在200M左右,然后开始进一步定位问题的原因。
现在,检查一下当前的oracle进程数目,是否由于今天的业务太多,或者连接的用户太多造成的压力呢?
oracle@db02:/oracle > ps -ef | grep oracle| wc -l
842
oracle@db02:/oracle >
这个数值和平时相比,是一个非常正常的值,系统曾经在并发连接数目达到1200以上仍然正常工作,因此排除了业务过量导致系统资源不足的可能性。
现在需要尽快找到入手的线索,既然内存不足,存在大量的page in操作,那么看一下交换分区的使用状态:
oracle@db02:/oracle > swapinfo
Kb Kb Kb PCT START/ Kb
TYPE AVAIL USED FREE USED LIMIT RESERVE PRI NAME
dev 32768000 4058864 28709136 12% 0 - 1 /dev/vg00/lvol2
reserve - 15057520 -15057520
memory 12954600 1303496 11651104 10%
oracle@db02:/oracle >
我们看见,一个正常的系统,交换分区的使用应该在5%以内,这里交换区使用率已经达到了12%,远远超过这个一般HP系统的常规值。
2.4. 假设和分析
联系所有上面的现象,我们已经基本可以断定,系统今天的现象绝对不是由于某些单纯的用户进程引起的,应该有几种可能:
1,Oracle 的SGA设置不合理
2,Oracle 的 PGA使用有异常
3,有可能某些僵死的进程不能正常释放内存
4,有某些认为的操作造成了内存泄漏
5,遇到了HP 或者Oracle某些bug
我们逐步检查上述原因,继续寻找线索。首先,考虑到既然操作系统上连接的Oracle用户进程数目正常,会不会oracle的SGA设置不合理呢?
SQL> show sga
Total System Global Area 7391385520 bytes
Fixed Size 747440 bytes
Variable Size 3070230528 bytes
Database Buffers 4294967296 bytes
Redo Buffers 25440256 bytes
SQL>
使用show sga可以清楚的看见,Oracle的SGA区仅仅的占用了物理内存7.3G左右,其中,Data buffer 使用了4G。对于这是一个有着16G物理内存的HP 7410来说,专门的作为Oracle 数据库服务器,并且没有任何的用户应用跑在上面,那么这个设置显然没有什么异常(在正常情况下,我们甚至曾经预计将再将1G到2G的系统空闲内存的分给Oracle的Data buffer来是用的)。
排除了SGA设置过大的可能性,接下来看看,用户进程的时候是否有什么异常现象?这里我新建立一个连接,在不作任何操作的情况下,看看一个空的连接对系统PGA的使用情况,以观察是否有系统的bug导致的每个Oracle用户进程过渡消耗内存的可能性:
SQL> select distinct sid from v$mystat;
SID
----------
206
Elapsed: 00:00:00.01
SQL> l
1 select b.PGA_USED_MEM PGA_USED_MEM, b.PGA_ALLOC_MEM PGA_ALLOC_MEM,
2 b.PGA_FREEABLE_MEM PGA_FREEABLE_MEM,b.PGA_MAX_MEM PGA_MAX_MEM
3 from v$session a, v$process b
4* where a.PADDR=b.ADDR and a.sid =&sid
SQL> /
Enter value for sid: 206
old 4: where a.PADDR=b.ADDR and a.sid =&sid
new 4: where a.PADDR=b.ADDR and a.sid =206
PGA_USED_MEM PGA_ALLOC_MEM PGA_FREEABLE_MEM PGA_MAX_MEM
------------ ------------- ---------------- -----------
330201 612345 0 11884537
Elapsed: 00:00:00.02
很明显,一个空的进程只需要300k的内存,这是非常正常的状态。现在再观察,系统总的PGA的使用情况,看看有什么发现:
SQL> select sum(PGA_USED_MEM) from v$process;
SUM(PGA_USED_MEM)
-----------------
561546135
Elapsed: 00:00:00.08
SQL>
SQL> select sum(PGA_USED_MEM) from v$process;
SUM(PGA_USED_MEM)
-----------------
409176749
Elapsed: 00:00:00.00
SQL>
这里,我们观察到,系统总的PGA的使用基本上稳定在400M到700M之间(系统设置的PGA的最大值是1G),与往常相比也是一个非常合理的状态。
2.5. 找到根源
到这里,我们可以作个简单的加减法计算,总的物理内存16G,减去Oracle SGA 占用的7.3G,再减去PGA占用的400M到700M(每时每刻根据使用情况在变话,最大为1G),再减去系统使用的和系统上显示的空闲内存,还应该有至少6个多G的内存去了哪里?
这台主机只用于数据库服务器,因此没有跑任何应用的情况下,因此不存在某些应用服务异常而占用过量共享内存段导致的内存不足(这样的案例是存在的),那么我在这里做过大胆的假设,应该是有某些异常的进程,异常的使用了将近6个多G的共享内存段,如果可以找到哪个共享内存段被谁异常使用,应该就可以找到上述种种问题的答案。
按照这个假设,我们使用ipcs观察共享内存段的使用情况:
oracle@db02:/oracle/app/oracle/admin/cmc/udump > ipcs -mb
IPC status from /dev/kmem as of Fri Mar 4 15:57:17 2005
T ID KEY MODE OWNER GROUP SEGSZ
Shared Memory:
m 0 0x411c5552 --rw-rw-rw- root root 348
m 1 0x4e0c0002 --rw-rw-rw- root root 61760
m 2 0x412040ba --rw-rw-rw- root root 8192
m 15875 0x5e1003c9 --rw------- root root 512
m 260612 0x00000000 D-rw-r----- oracle dba 6267330560
m 8103429 0x00000000 --rw-r----- oracle dba 6442450944
m 6 0x06347849 --rw-rw-rw- root dba 77384
m 7 0xffffffff --rw-r--rw- root dba 22908
m 6940680 0x320fb498 --rw-r----- oracle dba 982507520
oracle@db02:/oracle/app/oracle/admin/cmc/udump >
我们注意到了确实有一个异常的共享内存段(Share Memory ID 为260612),而它也刚好占用了6.2G左右的内存。这是一个Oracle用户占用的共享内存段,由于状态为D的共享内存段本身就是没有正常使用的内存段,所以满以为使用ipcrm –m 260612删除这个共享内存段,应该就可以解决问题,但是,当时上述做法的结果是系统报告找不到找个ID。
再看一下共享内存的详细使用信息:
oracle@db02:/oracle/app/oracle/product/920/bin > ipcs -ma
IPC status from /dev/kmem as of Fri Mar 4 16:25:19 2005
T ID KEY MODE CREATOR CGROUP NATTCH SEGSZ CPID LPID ATIME DTIME CTIME
Shared Memory:
m 0 0x411c5552 --rw-rw-rw- root root 0 348 528 528 4:35:46 4:35:46 4:35:39
m 1 0x4e0c0002 --rw-rw-rw- root root 2 61760 528 530 4:36:40 4:35:46 4:35:39
m 2 0x412040ba --rw-rw-rw- root root 2 8192 528 530 4:36:40 4:35:39 4:35:39
m 15875 0x5e1003c9 --rw------- root root 1 512 1323 1323 4:37:10 no-entry 4:37:10
m 260612 0x00000000 D-rw-r----- oracle dba 1 6267330560 15316 17931 2:27:03 2:29:53 2:29:41
m 8103429 0x00000000 --rw-r----- oracle dba 738 6442450944 22305 17897 16:24:24 16:25:15 2:53:58
m 6 0x06347849 --rw-rw-rw- root dba 0 77384 12170 18503 16:21:41 16:21:41 10:20:38
m 7 0xffffffff --rw-r--rw- root dba 0 22908 12169 12169 10:20:40 10:20:40 10:20:40
m 6940680 0x320fb498 --rw-r----- oracle dba 738 982507520 22305 17897 16:24:24 16:25:15 2:53:58
m 6833161 0x0c6629c9 --rw-r----- root dba 2 17602880 18503 18502 16:21:41 no-entry 16:21:41
oracle@db02:/oracle/app/oracl
这里有一个误解,CPID是指创建这个共享内存段的进程号,常见时间是2:29分,LPID是最后一次获取和使用这个共享内存段的进程号,使用时间是2:29分。因为Oracle在创建了这个段之后这个进程的使命也就完成了,可以简单的理解为类似一个sh脚本执行完成后正常退出的过程,通理,最后一次使用这个共享内存段的LPID的值也是这个道理。所以,如果试图通过这两个进程号来查找进程信息或者kill这两个进程的时候,是不会有什么结果的(kill这两个进程的时候,系统确报告说找不到这个进程)。
这里我们观察到他两个正常的Oracle共享内存段 的创建时间分别都似乎2:53分。联想起几天前由于修改业务而曾经重新启动过数据库。那么这里再做一个假设,这块内存被oracle系统进程异常占用,或者是数据库shutdown时没有正常释放所有的共享内存段。换个角度说,在数据库shutdown时,操作系统没有正常的收回所有的共享内存段。
2.6. 解决问题
现在我们使用shminfo(需要使用root权限)查看一下当前到底哪个进程在使用找个共享内存段:
db02#[/]./shminfo -s 260612
libp4 (7.0): Opening /stand/vmunix /dev/kmem
Loading symbols from /stand/vmunix
shminfo (3.6)
Shmid 260612:
struct shmid_ds at 0xf468e8
Pseudo vas at 0x594fd900
Pseudo pregion at 0x624a1d00
Shared region at 0x788a53c0
Segment at 0xd8d3400.0xc000000040000000
Segment allocated out of "Global 64-bit quadrant 4"
Processes using this segment:
proc=0x6d635040 (pid 17927 "oracle"): vas=0x61faee00, SHMEM preg=0x7dc32180
db02#[/]
现在,很清楚的看到,进程 17927 正在使用该共享内存段。接着,再使用ps查看 17927 的进程信息:
db02#[/]ps -ef|grep 17927
root 18107 18038 1 16:13:25 pts/tn 0:00 grep 17927
oracle 17927 1 0 Feb 6 ? 93:09 ora_diag_cmc2
db02#[/]
请注意,进程名称是 ora_diag_cmc2,这是一个后台诊断进程(Diagnosability Daemon),一般出现在OPS和RAC系统中,多用于在实例crash前生长大量的系统跟踪文件和SYSTEM DUMP信息(生成的所有进程跟踪信息一般存放在bdump目录下一个以故障时间点命名的core目录中)。
通过该进程的时间可以看到,这是2月6号 创建的进程,事实上,我在3月3号晚上重起了数据库,这个进程的创建时间和上面的共享内存段的创建时间和最后使用时间存在出入。由于是现网数据库,在确定删除该进程前我们特意对比了一下RAC中的另一个正常节点:
db02#[/]ps -ef |grep ora_diag_cmc
root 19117 18855 0 16:36:24 pts/to 0:00 grep ora_diag_cmc
oracle 22309 1 0 Mar 3 ? 0:19 ora_diag_cmc2
oracle 17927 1 1 Feb 6 ? 93:09 ora_diag_cmc2
db02#[/]
oracle@cs_db01:/oracle > ps -ef | grep ora_diag_cmc
oracle 3494 3457 0 16:37:11 pts/te 0:00 grep ora_diag_cmc
oracle 14718 1 1 Mar 3 ? 6:20 ora_diag_cmc1
oracle@cs_db01:/oracle >
经过对比,我们发现节点1(正常的节点)只有一个3月3号创建的后台诊断进程,而节点2(异常的节点)存在两个后台诊断进程,一个是3月3号创建的,一个是2月6号创建的。
至此,已经可以确定,进程 17927 就是异常占用6G以上的异常Oracle 后台(系统)进程,可以删除,于是kill它:
db02#[/]kill 17927
db02#[/]ps -ef |grep ora_diag_cmc
oracle 22309 1 0 Mar 3 ? 0:19 ora_diag_cmc2
root 19661 18855 2 16:45:53 pts/to 0:00 grep ora_diag_cmc
db02#[/]
现在,再来看看系统性能:
db02#[/]vmstat 2 5
procs memory page faults cpu
r b w avm free re at pi po fr de sr in sy cs us sy id
2 0 0 933372 1544205 127 13 0 0 0 0 31 17401 114427 6148 21 6 73
2 0 0 933372 1544193 8 0 4 0 0 0 0 12975 95961 5599 15 4 81
2 0 0 933372 1543328 4 0 3 0 0 0 0 12989 94187 5522 14 4 82
2 0 0 933372 1542944 2 0 2 0 0 0 0 13600 96823 5848 14 5 81
2 0 0 933372 1540620 1 0 6 0 0 0 0 13216 90131 5740 22 5 73
db02#[/]
几乎立竿见影,删除这个进程后,系统的运行队列(r)几乎没有了,和阻塞队列(b)一下子消失了,操作系统的page in导致的页交换骤减到一个非常正常的可接受值,系统的可用内存升高到free*page size=1544205*4096=6325063680 byte)左右。
再次使用top,可以看到:
db02#[/]top
。。。。。。
Memory: 7744752K (2796296K) real, 13421176K (4155264K) virtual, 6105600K free Page# 1/36
。。。。。
系统的可用内存确实已经升高到6G左右了。
再来看看CPU的使用:
db02#[/]sar -u 2 10
HP-UX db02 B.11.11 U 9000/800 03/04/05
16:39:31 %usr %sys %wio %idle
16:39:33 15 8 20 56
16:39:35 14 7 20 59
16:39:37 12 4 18 66
16:39:39 20 5 22 54
16:39:41 17 8 12 63
16:39:43 11 4 13 73
16:39:45 15 4 17 64
16:39:47 13 4 13 70
16:39:49 17 9 22 51
16:39:51 14 5 15 65
Average 15 6 17 62
db02#[/]
我们看到,CPU的idel平均值(%idle)在62%,而系统的wait io(%wio)的平均值在17%,这已经是一个非常理想的状态。系统性能恢复正常了。
后记
总结下来,解决这个问题的关键其实就在于如何释放掉那个操作系统不能正常回收而浪费的(Oracle异常占用的)6G的内存。虽然,可以通过shminfo找到进程号杀死进程,也可以通过重起主机解决(当然,很少有人选择后者,尤其是现网数据库),但是继续跟踪这个问题的话,我们发现了这是一个HP MC 11.15的bug,需要通过打PATCH PHSS_28926来解决这种内存不能正常回收的问题。
最后请记住,在一个安装在HP MC 11.15环境下的ORACLE RAC系统中,要想正常使用数据库,必须至少安装3个相应的HP MC 11.15的patch:
PHSS_28926
PHSS_30370
PHSS_29096
作者介绍 张大鹏:
网名Lunar2000(Lunar),ITPUB资深会员。现任职于某大型外资企业,服务于电信增值业务,从事专职DBA工作。主要负责Oracle数据库日常管理,包括备份和恢复,性能优化,故障诊断等。实践经验丰富,长于数据库故障诊断、性能优化和备份恢复。