前言
編者注,本文的知識點較多,請補充足夠正能量后閱讀,看完會讓你質疑你的DBA生涯,作者的水平代表著國內Oracle TroubleShooting最高水平。
很早就想把ORA-1000的問題,總結成一個話題。機緣巧合,最近恰好遇上幾個此類問題,特分享分析過程出來供大家參考。
首先,ORA-1000報錯是什么意思呢?我們來看看官方的解釋:

非常簡單,單個進程打開的游標數超過了最大值,也就是超過了數據庫設置的open_cursos參數的值;面對這樣的情況,不同的DBA會有不同的解決方案:調整open_cursors參數?還是直接把問題拋給開發人員?
今天老貓就來給大家分享一個處理ORA-1000的經典案例,看看大家的處理方式和我們的處理方式有什么不一樣?在處理過程中老貓又用到了什么不一樣的處理技巧?處理完能收獲什么樣的心得體會?
2
來活啦
客戶來電求助,系統周期性地報ORA-1000的錯誤,之前客戶已經多次調整open_cursors參數,目前已經調整到了2000了,難道還是接著一直往上調?open_cursors是針對一個單個進程打開cursor數的限制,對于一般應用來說,如果能及時關閉cursor,2000個已經足夠使用,那么這里是客戶沒有正確關閉游標還是其本身就需要同時打開大量游標抑或是其他原因呢,這已經極大地勾起了我的興趣!找出根因,并提供解決方案,是我們在服務客戶過程中的一貫態度。
3
捕捉信息
面對ORA-1000這種應用級的錯誤,我們一般可以通過設置errorstack時收集報錯進程的process dump來進行分析;而如果報錯沒那么容易出現,我們就會選擇在之前拋錯業務頻繁執行的時段做個systemstate dump,主要目的是可以看看這類業務執行時server process中都open了哪些cursor,然后根據現象進行進一步的分析,判斷問題的原因;
這里客戶系統是周期性的報ORA-1000錯誤,于是建議客戶開errorstack,收集trace文件進行分析。
4
開始分析
首先是設置1000的errorstack;

ORA-1000錯誤發生時,會生成一個trace,通過觀察trace發現在,確實打開了2000個cursor,在trace中搜索cursor#可以看到,發現cursor都是打開的同一個SQL:SELECT activityno,ruleno FROM T_RM_COUPONINF;

那么問題來了,為什么對同一個SQL會打開這么多cursor呢?仔細觀察一下我們就會發現這個SQL的特別之處,Excutioncount=0&LoadCount=299&InvalidationCount=300,還記得老貓分享的第十二期的故事么,這是典型的解析錯誤的問題!

不過這里我們就不用設置10035事件去確認了,我們試圖來解析SQL:SELECT activityno,ruleno FROM T_RM_COUPONINF;很快我們就發現了問題,T_RM_COUPONINF這個對象根本就不存在!
到這里,看起來我們發現了兩個問題:
1. 進程中打開了一條錯誤SQL的cursor;
2. 在遇到編譯錯誤后,進程沒有及時關閉cursor,似乎對這段代碼的處理過程沒有加catchexecption或者finally的過程;
那么是誰發起了這條SQL,在沒有編譯成功的情況下,沒有關閉cursor呢?模擬這樣的代碼一點都不難,腦子里閃過無數個草泥馬…罵誰還不好說,先冷靜,由于這個問題可以在測試環境重現。
5
定位來源
通常來說,數據庫中運行的SQL可以分為兩種,普通SQL和遞歸SQL;由于這里,sql本身存在錯誤,所以我們無法直接定位SQL到底是來自外部(普通SQL)還是數據庫(遞歸SQL);這時,我們就可以使用10046事件來幫忙了;

可以看到10046的trace中有如上一條解析錯誤的記錄,err=942即拋錯ORA-942,意味著表或視圖不存在;同時還有另一關鍵的點:dep=0,即SQL的遞歸深度為0,也就是非遞歸SQL!所以,只能找開發來確認了,開發給出明確的答復卻讓人沮喪:這條SQL不是應用發出來的!
不是應用寫的,也不是數據庫自己產生的,那么這SQL來自于哪里呢?我再仔細捋了捋思路,發現我們在日常處理問題的過程中,經常忽略的一個環節,那就是JDBC包;一般認為,JDBC主要是為了維護應用與數據庫的連接的,但實際上,JDBC在這個過程中也是有可能執行一些SQL的,甚至可以通過一些配置重新封裝應用程序發到數據庫服務器的SQL語句,在這個過程中,出現一些問題也是可能的。
至此,我們暫時將問題定位到JDBC上;查看JDBC版本,是12.1.0.2數據庫自帶的。OK,范圍縮小到JDBC。下一步debug JDBC。
6
不一樣的trace
前面初步懷疑到了JDBC上,接下來需要做的就是通過在應用代碼中打開JDBC的trace即可,增加的代碼如下:

觀察結果JDBC trace文件:

沒錯,我們看到了那條SQL的身影,看來錯誤SQL確實是來自于JDBC;
7
原因確認
原來,應用持久化框架里為了取得SQL的綁定變量信息,調用Oracle JDBC的PreparedStatement.getParameterMetaData()函數, 在這個方法里,JDBC取得parameter metadata的方法是:生成一條SQL:SELECT activityno, ruleno FROM T_RM_COUPONINFO,通過編譯這條SQL,取得activityno, ruleno兩個列的metadata信息,然后返回給客戶應用。
不幸的是:在生成這條SQL時,出現了錯誤----丟掉了一個字母O,導致ORA-942的錯誤。錯就錯了吧,你至少要關掉cursor呀。JDBC的開發疏忽了。
正確sql:
SELECT activityno, ruleno FROM T_RM_COUPONINFO
目前解析成的sql:
SELECT activityno, ruleno FROM T_RM_COUPONINF
這是JDBC遞歸SQL引發的一個問題,其實是JDBC12.1.0.2的一個BUG。
8
解決問題
將收集的errorstack和JDBC trace提交到oracle support;GCS還是蠻給力的,不長時間就提供了一個patch。
9
老貓小提示
大家可能會疑惑,為什么老貓開的SR反饋這么快,我開的SR卻遲遲沒有進展呢?
其實,老貓作為從原廠出來的老司機,就這個CASE而言,你要了解下面兩點:
1. JDBC在Oracle內部是個很跨界的產品,它的support其實是負責中間件的工程師,而不是Oracle Database工程師。當你開一個ORA-1000的問題給Database工程師時,你實在不能指望他會java;當你開給中間件工程師,又不能指望他對Database有多深的了解,勢必扯皮。老貓在原廠時,遇上這類問題,通常是在五樓陽臺抽煙時,互相溝通一小會兒的。大家工作壓力都很大,還沒到自己手里的問題,沒人真的上心。
2. 能重現的問題,盡量作一個test case給Oracle support,把能提供的信息提供好。在這個案例中,我們把現象,問題發生的函數,trace證據全都提供給support,減少了交互,減少了扯皮。所以,問題解決得很快。
總而言之,對于每個自己的SR,我們盡量提供自己所了解的所有信息,SR的進展就會更順利。
10
問題總結
這個問題,我們看到,作為一個好的DBA,絕對不能只是改改參數,或者是將看起來與數據庫無關的問題一手推給開發人員;我們可以做的是,把問題定位到最小范圍內,至于確確實實涉及到數據庫內層不公開的部分,只要提供足夠的信息,我們相信SR也能幫助我們定位到數據庫底層的問題。
免責聲明:本站發布的內容(圖片、視頻和文字)以原創、轉載和分享為主,文章觀點不代表本網站立場,如果涉及侵權請聯系站長郵箱:is@yisu.com進行舉報,并提供相關證據,一經查實,將立刻刪除涉嫌侵權內容。