資料庫伺服器記憶體資源消耗100%問題處理案例

paulyibinyi發表於2010-09-05

問題簡述:資料庫外面應用程式經常連線不上,導致業務受到中斷

作業系統:HP-Unix 實體記憶體24G,交換分割槽20G

資料庫:oracle 10.2.0.4

2010-9-2下午四點鐘趕到使用者現場,登入到資料庫主機,檢查監聽和資料庫日誌。

   監聽日誌從2010-9-2下午1423分開始報如下錯誤:

     02-SEP-2010 14:23:25 * (CONNECT_DATA=(SID=ora10g)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=))) * (ADDRESS=(PROTOCOL=tcp)(HOST=*.*.*.*)(PORT=2024)) * establish * ora10g * 12518

TNS-12518: TNS:listener could not hand off client connection

 TNS-12549: TNS:operating system resource quota exceeded

  TNS-12560: TNS:protocol adapter error

   TNS-00519: Operating system resource quota exceeded

    HPUX Error: 12: Not enough space

   資料庫日誌從2010-9-2下午14點也報如下錯誤:

   這裡取的是17點多的一段日誌

kkjcre1p: unable to spawn jobq slave process

Thu Sep  2 17:06:15 2010

Errors in file /oracle/app/oracle/admin/ora10g/bdump/ora10g_cjq0_2922.trc:

Thu Sep  2 17:06:20 2010

Process startup failed, error stack:

Thu Sep  2 17:06:20 2010

Errors in file /oracle/app/oracle/admin/ora10g/bdump/ora10g_psp0_2906.trc:

ORA-27300: Message 27300 not found; No message file for product=RDBMS, facility=

ORA; arguments: [fork] [11]

ORA-27301: Message 27301 not found; No message file for product=RDBMS, facility=

ORA; arguments: [Resource temporarily unavailable]

ORA-27302: Message 27302 not found; No message file for product=RDBMS, facility=

ORA; arguments: [skgpspawn5]

ORA-27303: Message 27303 not found; No message file for product=RDBMS, facility=

ORA; arguments: [skgpspawn5]

Thu Sep  2 17:06:21 2010

Process J002 died, see its trace file

Thu Sep  2 17:06:21 2010

kkjcre1p: unable to spawn jobq slave process

Thu Sep  2 17:06:21 2010

Errors in file /oracle/app/oracle/admin/ora10g/bdump/ora10g_cjq0_2922.trc:

Thu Sep  2 17:06:46 2010

Errors in file /oracle/app/oracle/admin/ora10g/bdump/ora10g_psp0_2906.trc:

ORA-27300: Message 27300 not found; No message file for product=RDBMS, facility=

ORA; arguments: [fork] [12]

ORA-27301: Message 27301 not found; No message file for product=RDBMS, facility=

ORA; arguments: [Not enough space]

ORA-27302: Message 27302 not found; No message file for product=RDBMS, facility=

ORA; arguments: [skgpspawn3]

Thu Sep  2 17:06:47 2010

Process J002 died, see its trace file

Thu Sep  2 17:06:47 2010

kkjcre1p: unable to spawn jobq slave process

Thu Sep  2 17:06:47 2010

Errors in file /oracle/app/oracle/admin/ora10g/bdump/ora10g_cjq0_2922.trc:

Thu Sep  2 17:07:30 2010

Errors in file /oracle/app/oracle/admin/ora10g/udump/ora10g_ora_21196.trc:

ORA-27102: out of memory

HPUX-ia64 Error: 12: Not enough space

Additional information: 108

Additional information: 458752

 

1.   檢查cpu佔用資源

top cpu空閒率90%多,沒有相關oracle程式佔用cpu資源

      procs           memory                   page

 faults       cpu

 r     b     w      avm    free   re   at    pi   po    fr   de    sr     in

 sy    cs  us sy id

 1     1     0   190706   25014    0    0     0    0     0    0     0   9422

573  4068   5  1 94

 1     1     0   190706   24897    0    0     0    0     0    0     0   3686

721   379   8  0 92

 2     1     0   179575   24897    0    0     0    0     0    0     0   3681

852   379   8  0 92

 2     1     0   179575   24896    0    0     0    0     0    0     0   3682

149   381   8  0 91

 2     1     0   179575   24896    0    0     0    0     0    0     0   3777

240   454   8  0 92

 2     1     0   179575   24898    0    0     0    0     0    0     0   3662

492   343   0  0 100

 2     1     0   179575   24898    0    0     0    0     0    0     0   3578

100   262   0  0 100

 1     0     0   196811   24898    0    0     0    0     0    0     0   3539

758   212   0  0 100

 1     0     0   196811   24897    0    0     0    0     0    0     0   3499

193   180   1  0 99

 1     0     0   196811   24897    0    0     0    0     0    0     0   3475

274   165   8  0 92

2.   檢查實體記憶體和交換分割槽使用情況

       rx8640a:[/var/adm/syslog]#swapinfo -atm

             Mb      Mb      Mb   PCT  START/      Mb

TYPE      AVAIL    USED    FREE  USED   LIMIT RESERVE  PRI  NAME

dev       20480     342   20138    2%       0       -    1  /dev/vg00/lvol2

reserve       -   20138  -20138

memory    23251   23164      87  100%

total     43731   43644      87  100%       -       0    -

     可以看到實體記憶體全部用完,交換分割槽只佔用2%

3.   檢查作業系統日誌

dmesg

Pid 21214 was killed due to failure in writing the signal context - possible stack overflow.

Deferred swap reservation failure pid: 21910

Deferred swap reservation failure pid: 21908

Deferred swap reservation failure pid: 21912

Deferred swap reservation failure pid: 21912

Deferred swap reservation failure pid: 21912

Deferred swap reservation failure pid: 21909

報很多程式ID失敗的資訊

4.   檢視資料庫連線數

su - oracle

ps -ef|grep LOCAL|wc -l

924  諮詢庫開發人員,這個連線數正常。

5.   檢查作業系統程式連線引數

sam

kernel configure

maxuprc  1500

連線數沒有超過程式連線引數值

2    處理過程

6.   重啟作業系統和重啟資料庫

7.   啟動資料庫後,應用訪問正常,但連線數又突然增加到920

  su - oracle

ps -ef|grep LOCAL|wc -l

 920

         透過glance工具,發現每個LOCAL=NO的程式平均佔用20M

                                  PROCESS LIST                      Users=    3

                         User      CPU %    Thrd Disk        Memory       Block

Process Name     PID     Name   (1200% max) Cnt  IOrate      RSS/VSS      On

--------------------------------------------------------------------------------

ora_j001_ora       13731 oracle       41.9     1 334.2   685.4mb  701.9mb    IO

glance             13896 root          3.0     1   0.0     2.7mb    8.2mb STRMS

vxfsd                133 root          2.7    16   1.1     1.6mb    1.8mb SLEEP

midaemon            1975 root          0.0     8   0.0   263.4mb  268.1mb SLEEP

oracleora10g        4581 oracle        0.0     1   0.0    21.3mb   28.3mb SOCKT

oracleora10g        4687 oracle        0.0     1   0.0    22.3mb   25.3mb SOCKT

oracleora10g        4983 oracle        0.0     1   0.0    23.4mb   24.3mb SOCKT

oracleora10g        4482 oracle        0.0     1   0.0    25.2mb   27.2mb SOCKT

oracleora10g        4482 oracle        0.0     1   0.0    26.4mb   29.5mb SOCKT

oracleora10g        4482 oracle        0.0     1   0.0    27.5mb   32.3mb SOCKT7

ora_cjq0_ora       13704 oracle        0.0     1   0.0   656.1mb  695.5mb OTHER

      C - cum/interval toggle                                       Page 1 of 2

  大概估算下,900多個連線數大概佔用物理18000M,根據swapinfo –atm

命令檢視實體記憶體已經使用91%,一旦到100%,外面應用可能又無法連線。

               繼續分析程式ID,查到大部分是由機器名為db的應用連進來,狀態為inactive,

sql全部為select 1 from dual;

   但這時不知道hzdb機器的ip地址,和使用者一起協商,

把資料庫啟動後的這段時間根據listener.log全部列舉出來,

主要是由以下三個ip連線進來:

        192.168.0.55,192.168.0.213,192.168.3.26 

          使用者感覺192.168.0.55 ip有問題,透過溝通,確認是這個IP引起。

       臨時解決方法:把192.168.0.55應用連線到資料庫使用者鎖住。

9.   使用者鎖住後,重起資料庫 實體記憶體佔用66% 應用恢復正常

rx8640a:[/opt]#swapinfo -atm

             Mb      Mb      Mb   PCT  START/      Mb

TYPE      AVAIL    USED    FREE  USED   LIMIT RESERVE  PRI  NAME

dev       20480       0   20480    0%       0       -    1  /dev/vg00/lvol2

reserve       -   13238  -13238

memory    23251   15413    7838   66%

total     43731   28651   15080   66%       -       0    -

3          總結

主要是應用自動連線造成的,並且連線屬於C/S架構,一對一,而且設定成自動連線,一起就是900多個連線,所以消耗大量實體記憶體。

前面諮詢開發人員說是900多連線,其實開發人員說的不準確,導致我們誤判,這也就告訴我們在解決問題的時候全部要靠自己去檢查,不能相信任何人說的話。

oracle公司的人也說過,不能相信客戶說的話。

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/7199859/viewspace-672751/,如需轉載,請註明出處,否則將追究法律責任。

相關文章