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

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

資料庫：oracle 10.2.0.4

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

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

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: 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的程式平均佔用20多M

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公司的人也說過，不能相信客戶說的話。

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

2 處理過程

3 總結

相關文章