2010年6月25日 星期五

Oracle Server CPU 100% utilization debug memo

先說明,這是學習筆記,只供自己備忘用途!
之前在工作上曾經碰過Oracle主機CPU使用率跑到100﹪,造成大部份系統都連不上線,即使連上了,也是跑很慢的情況。後來,透過同事一同努力,終於找到問題點。解決了,但當時匆匆忙忙,也沒仔細把過程記錄下來,現在要回想都有困難。
為了以防之後再遇到同樣問題,花了一些時間,再重新再現當時的情況,並找了一些資料,做了一些測試,記錄如下:

有一支程式(寫得不好)會檢查某個表格的某筆記錄,如果該記錄的locked欄位值為‘Y’,就會一直查重複這個查詢過程,直到值變為不是‘Y’為止。當然,可以猜想這個程式是利用locked欄位當做和其他程式的溝通的機制,當它要做事時,就會先看是否有人在做事,若沒有則先修改locked欄位值,告訴大家我要做事了,其他人看到就會先等待,等做完事再註記locked欄位,其他人看到就知道可以做事了。模擬程式如下:

declare
locked varchar2(1);
begin
loop
select locked into locked from test1.demotab where id=6;
exit when locked <> 'Y';
end loop;
dbms_output.put_line('quit loop');
end;


不幸的是,程式出錯了,有一支程式在做事時當掉了,所以沒有再把locked欄位註記回來。所以,所有程式都一直卡在查詢階段,沒有辦法做事。但是使用者只看到系統卡住,等待之後就會嘗試再開一次程式,如此一直開,一直試。結果,就有很多程式一直在查詢。如此就造成了CPU使用率高到100﹪的情況。(其實只要跑一次模擬程式,記得先將locked值設為‘Y’,CPU就100﹪了)

這個時候要如何查問題?
1.可以下如下SQL:

select sid, program, event, final_blocking_session_status
from v$session
order by time_since_last_wait_micro desc

查看前幾筆記錄的SID值,記下來。

2.再下如下SQL:

select sid,event,p1,p1text from v$session_wait order by event

找出奇怪的event,或者直接找SID和第一個SQL找出相同者。看久了,你會知道那些event是正常的,那些是不正常的。由這些異常的event找其對照的SID。

3.以上兩個方法找到的SID,就代表可疑的session。我們逐一的查詢其目前正在執行的SQL,使用以下指令:

SELECT sql_text
FROM v$sqltext a
WHERE a.hash_value = (SELECT sql_hash_value
FROM v$session b
WHERE b.SID = :sid)
ORDER BY piece ASC

當然是要把:sid替換成剛才找出的那些可疑SID值。
這樣可以看到這些可疑session目前正在執行的SQL,請多跑幾次,多觀察幾個SID。就會發現,真得有問題的那支程式,會被我們找出來。
張貼留言