關於ORA-12801,ORA-27090的簡單分析

jeanron100發表於2015-02-26
今天下午收到客戶的郵件,說有一個job在執行的時候報錯了,希望我們能幫忙看看是什麼原因。
ERROR: Caught en exception: ORA-12801: error signaled in parallel query server P130 
ORA-27090: Unable to reserve kernel resources for asynchronous disk I/O 
Linux-x86_64 Error: 2: No such file or directory 
Additional information: 3 
Additional information: 128 
Additional information: 1 
ORA-27090: Unable to reserve kernel resources for asynchronous disk I/O 
Linux-x86_64 Error: 2: No such file or directory 
Additional information: 3 
Additional information: 128 
Additional information: 1 
ORA-27090: Unable to reserve kernel resources for asynchronous disk I/O 
Linux-x86_64 Error: 2: No such file or directory 
Additional information: 3 
Additional information: 128 
Additional information: 1 
ORA-27090: Unable to reserve kernel resources for asynchronous disk I/O 
Additional information: 3 
Additional information: 128 
Additional information: 2113522240 
ORA-27090: Unable to reserve kernel resources for asynchronous disk I/O 
Additional information: 3 
Additional information: 128 
Additional information: 2113522240 
從錯誤資訊來看是由於並行程式引起的,檢視了客戶提供的日誌,這個job是一個每天都會執行的job,每次回啟用幾個獨立的process來並行跑,每個process裡面的sql語句都走了並行,並行度是8,所以佔用的session數不會太多,在100個以內是肯定的。
這個時候檢視awr只能在報告頭看到session的資料,得到不一些具體的session佔用情況,檢視ash也得不到,因為得到的都是active session的資訊。
這些資訊可以自己使用指令碼來自動採集,也會有所側重,得到的資料也更有意義和說服力。
我抓取了下午的報告,報告的時間在錯誤發生前幾分鐘。
可以看到session數已經用了不少了,而且絕大多數的session都在JDBC的程式上。
STATUS          CNT
-------- ----------
ACTIVE          165
INACTIVE       9879
         ----------
sum           10044
.
PROGRAM                                    CNT STATUS
----------------------------------- ---------- --------
JDBC Thin Client                          9113 INACTIVE
extract@ccbdbpr  (TNS V1-V3)                90 INACTIVE

Session_count osuser   hash_value   sql_id

         1       truwl71     1443142349 bhm5y9tb096qd

      4844       pcmwrk01    3361273624 5vxmncv45jxss

        42       truwl15      941869720 f6hcnghw27kns

         4       pcowrk01    3359590350 fa311gg43yjyf

        15       pcmwrk01    2311663385 27uaksf4wkbst

        65       parwrk01    1950821498 459f3z9u4fb3u

         2       truwl74     1443142349 bhm5y9tb096qd

        15       truwl35      941869720 f6hcnghw27kns

         1       truwl35     3428812084 bwjxuug65z19n

        30       truwl22      941869720 f6hcnghw27kns

         1       truwl41     4042609743 bg0xgs3sgap2g

         9       pcmwrk01    1204453754 frvwp893wp0bu

         2       truwl74     4042609743 bg0xgs3sgap2g

         1       truwl71     1488663547 b26tu71cbqczv

       192       pcmwrk01      20635029 byd95500mprcp

         1       truwl71     2397213050 26b628u7f54bu

        64       pcmwrk01    2555678015 6vf0fzkc5939z

       425       pcmwrk01    1950821498 459f3z9u4fb3u

        36       truwl32      941869720 f6hcnghw27kns

         5       parwrk01    1209197086 07h65fd415shy

         1       truwl25     1605399126 g1p5bjdgv0wkq

        32       truwl71      941869720 f6hcnghw27kns

        32       truwl14      941869720 f6hcnghw27kns

       449       pcmwrk01    3203606695 dm03006zg6a57

        40       truwl65      941869720 f6hcnghw27kns

        33       truwl43      941869720 f6hcnghw27kns

         2       truwl53      647050378 f9mmq7sm92d4a

可以很明顯看到sql_id(5vxmncv45jxss)佔用了相當多的session,可以斷定這些session都是inactive的。這個可以透過如下的資訊來驗證。
STATUS          CNT
-------- ----------
ACTIVE          165
INACTIVE       9879
         ----------
sum           10044
檢視問題語句對應的系統使用者竟然是另外一個模組的。根據sql_id抓取了對應的sql語句,是一個很簡單的select 語句。
/* CM9_ServiceAgreement_selectServiceAgreement_1 */ SELECT xxxxx FROM SERVICE_AGREEMENT WHERE   SERVICE_AGREEMENT.AGREEMENT_NO = :1  AND  SERVICE_AGREEMENT.EXPI
RATION_DATE IS NULL
和開發做了確認,發現這是一個客戶化的job導致的問題,已經做了修復,打了補丁到生產環境,時間是今天凌晨,所以客戶就希望能夠確認一下那些佔用很多的session不是幾天前的session,
這個問題看似挺容易,但是卻是無處可查,
v$session中的資訊早就被刷掉了,要得到哪些session的登入時間來判斷是很難的,除非自己做了更多細緻的監控。
這個時候我是透過另外一個思路來推的。
我抓取了幾個報告。
問題發生一個小時前的報告,在2點左右,session數在9000左右,pcmwrk佔用的session是2000多。
然後抓取了上午11點的報告,pcmwrk佔用的session在4000多。
透過這些資訊還不能推論是否有大量的歷史session.
我又抓取了一個問題發生1個小時後的報告,大概在5點左右,pcmwrk佔用的session在15個左右。
透過這個就可以很自信的告訴客戶,這些session都是今天的,至於為什麼佔用這麼多的session,和補丁的修復也有關係,開發還在繼續排查和分析。

這個問題告訴我們,一個看似簡單的問題可能是由另外一個問題導致的。問題的背後都有一定的原因,需要我們留心,可能在排查的時候就會輕鬆很多。
         


         

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

相關文章