系统内存突然耗尽

boinicke

   终于闲下来了，有时间整理。前段时间一位客户问我，为什么他们的系统内存资源紧张，刚开始我还在乎这事（呵呵，太忙了。。。），后来感觉越来越不对劲，登录很慢，经过跟过分析发现有一个进程尽然占用了14GB内存，很了不起哦。下面十分过程，与大家分享。

一、检查正常运行系统的可用内存
系统正常运行时可用内存（fre）大约为：4068000*4K/1024/1024=15.5GB左右。
test:oracle> vmstat 1 4
System configuration: lcpu=20 mem=40959MB ent=10.00
kthr    memory              page              faults              cpu         
----- ----------- ------------------------ ------------ -----------------------
r  b   avm   fre  re  pi  po  fr   sr  cy  in   sy  cs us sy id wa    pc    ec
4  0 6191894 4068731   0   0   0   0    0   0 2094 4164 7135 32  2 51 15  3.61  36.1
3  0 6198004 4062621   0   0   0   0    0   0 1830 7905 7808 40  2 48 10  4.36  43.6
6  0 6185600 4075010   0   0   0   0    0   0 1767 24146 8807 38  4 51  7  4.35  43.5
4  0 6186090 4074520   0   0   0   0    0   0 1585 16186 7492 32  2 62  4  3.56  35.6
二、异常时系统内存使用情况   
1.当时系统内存情况   
2008年9月1日下午16：00～17：30左右发现系统test内存吃紧，存大量的pin，pout和memory scan(sy),可用内存不足30M，当时系统级查到有 oracle进程（14188576）消耗约14GB。
test:oracle > vmstat 1 5
System configuration: lcpu=20 mem=40959MB ent=10.00
kthr    memory              page              faults              cpu
----- ----------- ------------------------ ------------ -----------------------
r  b   avm   fre  re  pi  po  fr   sr  cy  in   sy  cs us sy id wa    pc    ec
11 21 12167794 10333   0 668   0   0    0   0 1024 2747 2510  3  1 92  5  0.38   3.8
4 24 12167793  9783   0 564 249 774 1335   0 920 2109 1987  1  1 94  4  0.21   2.1
9 20 12167793 10075   0 471 503   0    0   0 1008 1789 1970  1  1 93  5  0.27   2.7
2 26 12167795  9663   0 467 362 775 1571   0 897 1223 1840  1  0 95  4  0.16   1.6
9 20 12167795 10473   0 277 704 387  563   0 1065 2214 1647  1  1 93  5  0.28   2.8
test:oracle> lsps -s
Total Paging Space   Percent Used
      20480MB              58%
2.获取消耗内存资源的最大50个进程
下面是当前消耗内存最大的50个进程（PGIN、TSIZ、TRS ）
GVSHB502:orahb5 15> ps gv|head -n 1; ps gv|egrep -v "RSS" | sort +6b -7 -n -r |head -n 50
      PID    TTY STAT  TIME PGIN  SIZE   RSS   LIM  TSIZ   TRS %CPU %MEM COMMAND
14188576      - A    153:27 35914 16145100 14028012    xx 80736 42844  2.6 34.0 oracle
20148354      - A    16:12 24603 776616 792420    xx 42163 24096  1.3  2.0 dw.sap
20410412      - A    1452:16 435024 768576 453712    xx  2353  1852  3.4  1.0 /usr/s
20381946      - A     0:40 4909 52452 94392    xx 80736 42844  0.1  0.0 oracle
19103872      - A     0:52 5125 27392 69364    xx 80736 42844  0.1  0.0 oracle
19783736      - A     2:53 9686 29612 62576    xx 80736 42844  0.0  0.0 ora_db
18898978      - A     0:00  835 19556 62264    xx 80736 42844  0.0  0.0 oracle
19431576      - A     0:01 1369 19568 62008    xx 80736 42844  0.0  0.0 oracle
19771456      - A     1:18 4233 19780 61860    xx 80736 42844  0.1  0.0 oracle
18309288      - A     8:44 28840 138156 61532    xx  2353  1852  0.0  0.0 /usr/s
  2601126      - A     0:51 21278 22040 61304    xx 80736 42844  0.1  0.0 oracle
19271680      - A     0:21 2165 19164 61220    xx 80736 42844  0.0  0.0 oracle
  2043974      - A     0:01  125 17824 60668    xx 80736 42844  0.0  0.0 oracle
20246534      - A     0:00  153 19532 59800    xx 80736 42844  0.0  0.0 oracle
19726464      - A     0:06 4357 18824 59572    xx 80736 42844  0.0  0.0 oracle
  2166838      - A     0:42 2391 21864 59344    xx 80736 42844  0.1  0.0 oracle
19734782      - A     1:37 2556 19340 58492    xx 80736 42844  0.2  0.0 oracle
19730472      - A     2:27 7943 21376 57972    xx 80736 42844  0.0  0.0 ora_db
  2031690      - A     1:46 2977 19072 57252    xx 80736 42844  0.0  0.0 ora_ck
19918876      - A     2:36 8262 21376 56568    xx 80736 42844  0.0  0.0 ora_db
19415206      - A     2:14 120392 19484 55724    xx 80736 42844  0.0  0.0 ora_ar
20332722      - A     2:15 121319 19484 55476    xx 80736 42844  0.0  0.0 ora_ar
20144252      - A     0:05 16185 12088 54680    xx 80736 42844  0.0  0.0 oracle
19239092      - A     0:06 15865 11404 54068    xx 80736 42844  0.0  0.0 oracle
20123770      - A     0:12 2641 11084 53144    xx 80736 42844  0.0  0.0 oracle
18632850      - A     0:20 6542 10988 53116    xx 80736 42844  0.1  0.0 oracle
  2437330      - A     0:32  144 14608 53068    xx 80736 42844  0.0  0.0 oracle
20279360      - A     0:18 1390 11012 52800    xx 80736 42844  0.0  0.0 oracle
20431078      - A     0:00  646  9312 52004    xx 80736 42844  0.0  0.0 oracle
20353248      - A     0:10  373 11316 51908    xx 80736 42844  0.0  0.0 oracle
18980952      - A     0:14 1716 10156 51888    xx 80736 42844  0.0  0.0 oracle
19746918      - A     0:25 7366  9760 51172    xx 80736 42844  0.1  0.0 oracle
18649274      - A     0:02 6206  8788 51124    xx 80736 42844  0.0  0.0 oracle
  1986740      - A     0:22 9737  8244 50984    xx 80736 42844  0.1  0.0 oracle
18608190      - A     0:08 1392  9676 50896    xx 80736 42844  0.0  0.0 oracle
19644460      - A     2:41 7294 35912 50576    xx 80736 42844  0.0  0.0 ora_lg
19419168      - A     0:19  708  7856 50472    xx 80736 42844  0.1  0.0 oracle
20267130      - A     0:39 6370  7516 50200    xx 80736 42844  0.3  0.0 oracle
  2416824      - A     0:02   22 11380 49960    xx 80736 42844  0.0  0.0 oracle
20201500      - A     0:17  255  9132 49772    xx 80736 42844  0.0  0.0 oracle
  2994404      - A     0:00  489  6852 49688    xx 80736 42844  0.0  0.0 oracle
18858118      - A     0:01 1294  6972 49600    xx 80736 42844  0.0  0.0 oracle
20172874      - A     0:00  577  6740 49576    xx 80736 42844  0.0  0.0 oracle
19984630      - A     0:01   58  8032 49448    xx 80736 42844  0.0  0.0 oracle
19534072      - A     0:00  184  7160 49252    xx 80736 42844  0.0  0.0 oracle
19538052      - A     0:03 4672  6900 49140    xx 80736 42844  0.0  0.0 oracle
19452068      - A     0:00 1114  7164 48984    xx 80736 42844  0.0  0.0 oracle
20398264      - A     0:10 1278  7300 48980    xx 80736 42844  0.0  0.0 oracle
18841792      - A     0:00   94  6176 48968    xx 80736 42844  0.0  0.0 oracle
20459558      - A     0:00  228  6116 48960    xx 80736 42844  0.0  0.0 oracle
  很可怕哦，14188576进程尽然消耗掉了14GB内存！！！是吃内存的么。。。。
3.跟踪14188576进程发现是个oracle进程，oracle在干嘛？呵呵，可惜，太忙，执行sql语句没反应，当时没抓住这个进程。
4.分析AWR报告
    经检查数据发现pga的最大内存限制在16GB（aggregate PGA target parameter：16384M），本人认为这个参数是有问题的，一般1个session在消耗内存在2M左右，即使1000个session，也设置不了这么大（数据库仓库一般设置为sga（9GB）的50%，一般应用SGA 的30%~40%。).
    从oracle AWR分析报告看，存在latch wait event,如latch( library cache)和db file sequential read  wait event很高,出现这种状况的话一般由sql语句造成的，比如 重复parse,（db file sequential read）大量顺序读写。同样，从SQL ordered by Gets也能看到：dk20996p06y2p号语句执行一次得从buffer 中gets 34,898,074个block,也就是(34,898,074*8K =266 GB)，一条语句读了266GB的数据量，这肯定会消耗大量pga内存，加上pga的最大内存限制在16GB，故出oracle进程（14188576）消耗约14GB，导致9月1日下午16：00～17：30左右发现BW系统GVSHB502内存吃紧。
  
Top 5 Timed Events
Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class
latch: library cache 31,671 8,955 283 9.1 Concurrency
db file sequential read 1,971,957 8,822 4 9.0 User I/O
latch: cache buffers chains 31,943 8,583 269 8.7 Concurrency
CPU time   6,999   7.1  
latch: cache buffers lru chain 12,605 3,651 290 3.7 Other
SQL ordered by Gets
Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code.
Total Buffer Gets: 82,891,476
Captured SQL account for 65.9% of Total Buffer Gets  Executions  Gets per Exec  %Total CPU Time (s) Elapsed Time (s) SQL Id SQL Module SQL Text
34,898,074 1 34,898,074.00 42.10 118.62 140.68 dk20996p06y2p CL_SQL_STATEMENT==============CP  SELECT /*+ FACT(F) */ LPAD("...
3,146,031 37 85,027.86 3.80 10.53 13.79 43ujv6a8yr2v3 CL_SQL_STATEMENT==============CP  BEGIN DBMS_STATS.FLUSH_DATABAS...
2,742,715 37 74,127.43 3.31 7.20 8.15 gw2bhyz0skbfu    delete from sys.col_usage$ c w...
2,684,851 13,674 196.35 3.24 12.73 12.81 bsa0wjtftg3uw    select file# from file$ where ...
1,689,065 1 1,689,065.00 2.04 25.16 30.47 a8xyhp3c2xstz CL_SQL_STATEMENT==============CP  SELECT /*+ STAR_TRANSFORMATIO...
1,688,771 1 1,688,771.00 2.04 25.63 27.91 6s51d7rrg5jx3 CL_SQL_STATEMENT==============CP  SELECT /*+ STAR_TRANSFORMATIO...
1,186,604 1 1,186,604.00 1.43 16.82 743.06 d19n788n1hs4p
[email=korcoll@test]korcoll@test[/email]
(TNS V1-V3)  SELECT /*+RULE*/ COUNT(*) EXTE...
3.oracle parameter
SQL> show parameter sga
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
lock_sga                             boolean     FALSE
pre_page_sga                         boolean     FALSE
sga_max_size                         big integer 9072M
sga_target                           big integer 0

SQL> SELECT NAME, VALUE/1024/1024 MB  FROM v$pgastat;
NAME                                                                     MB
---------------------------------------------------------------- ----------
aggregate PGA target parameter                                        16384
aggregate PGA auto target                                         14603.291
global memory bound                                                    1024
total PGA inuse                                                  183.635742
total PGA allocated                                              400.712891
maximum PGA allocated                                            5277.14258
total freeable PGA memory                                            93.625
process count                                                    .000161171
max processes count                                              .000256538
PGA memory freed back to OS                                      394925.813
total PGA used for auto workareas                                25.4267578
NAME                                                                     MB
---------------------------------------------------------------- ----------
maximum PGA used for auto workareas                              1441.70215
total PGA used for manual workareas                                       0
maximum PGA used for manual workareas                            .517578125
over allocation count                                                     0
bytes processed                                                  1261966.91
extra bytes read/written                                         101328.126
cache hit percentage                                             .000088272
recompute count (total)                                          .072263718


本文来自ChinaUnix博客，如果查看原文请点：http://blog.chinaunix.net/u2/76762/showart_1200091.html