一個SQL語句引發的ORA-00600錯誤排查

一個SQL語句引發的ORA-00600錯誤排查

最近有一個同事問我一個問題，說他運行一個SQL語句拋出了ORA-00600的錯誤，想讓我幫忙分析一下，這種問題聽了確實有興趣，瞭解了問題的大體情況之後，發現這個問題還是值得分析分析的，因為只是用戶端調用拋出異常，沒有給伺服器端帶來什麼致命的影響，這樣的問題還是很耐人尋味的。

簡單溝通後，我得到了同事提供的SQL語句和執行環境，語句類似下面的形式：

MERGE INTO (SELECT * FROM TEST_SERVER_LOG WHERE BUY_TIME>=TO_DATE(:1 ,'YYYY-MM-DD HH24:MI:SS')
                                AND BUY_TIME<to_date(:2 ,'yyyy-mm-dd="" hh24:mi:ss')                                AND PUT_DATE=TO_DATE(:3 ,'YYYY-MM-DD')) T
                    USING(SELECT
                            TO_CHAR(:4 ) AS SN,
                            TO_NUMBER(:5 ) AS GROUP_ID,
                            TO_NUMBER(:6 ) AS SERVER_IP,
                            TO_CHAR(:7 ) AS SERVER_NAME,
                            TO_NUMBER(:8 ) AS WORD,
                            TO_NUMBER(:9 ) AS SERVER,
                            TO_NUMBER(:10 ) AS SCENE,
                            TO_CHAR(:11 ) AS CN_GUID,
                            TO_DATE(:12 ,'YYYY-MM-DD HH24:MI:SS') AS BUY_TIME,
                            TO_NUMBER(:13 ) AS JEWEL_TOTAL,
                            TO_CHAR(:14 ) AS CN,
                            TO_CHAR(:15 ) AS CHARACTER_PUT,
                            TO_CHAR(:16 ) AS IP,
                            TO_NUMBER(:17 ) AS WEAPONID,
                            TO_DATE(:18 ,'YYYY-MM-DD') AS PUT_DATE,
                            TO_NUMBER(:19 ) AS WEAPONID_NEW,
                            TO_NUMBER(:20 ) AS COUNT,
                            TO_NUMBER(:21 ) AS USER_CLASS,
                            TO_CHAR(:22 ) AS CONSUME_WAY,
                            TO_NUMBER(:23 ) AS CLIENT_STYLE,
                            TO_CHAR(:24 ) AS GAME_TYPE
                          FROM DUAL) A
                    ON (T.SN=A.SN)
                    WHEN NOT MATCHED THEN
                    INSERT(T.SN,T.GROUP_ID,T.SERVER_IP,T.SERVER_NAME,T.WORD,T.SERVER,T.SCENE,T.CN_GUID,T.BUY_TIME,T.JEWEL_TOTAL,T.CN,T.CHARACTER_PUT,
                    T.IP,T.WEAPONID,T.PUT_DATE,T.WEAPONID_NEW,T.COUNT,T.USER_CLASS,T.CONSUME_WAY,T.CLIENT_STYLE,T.GAME_TYPE)
                    VALUES(A.SN,A.GROUP_ID,A.SERVER_IP,A.SERVER_NAME,A.WORD,A.SERVER,A.SCENE,A.CN_GUID,A.BUY_TIME,A.JEWEL_TOTAL,A.CN,A.CHARACTER_PUT,
                    A.IP,A.WEAPONID,A.PUT_DATE,A.WEAPONID_NEW,A.COUNT,A.USER_CLASS,A.CONSUME_WAY,A.CLIENT_STYLE,A.GAME_TYPE)
這樣一個語句看起來結構挺複雜，細看邏輯其實倒不複雜。最近處理了幾個效能問題，其實有不少都是和Merge的使用有關，這個語句有什麼問題呢，目前來看沒有直接的問題，唯一的感覺是綁定變數不少啊，另外需要補充一下，資料庫版本是11.2.0.3
    拿到語句要分析的時候，能夠複現問題是非常難得的機遇，有很多的ORA-00600錯誤要複現需要上下文環境觸發一定的條件才可以複現，這個問題讓我省了不少事，我在alert日誌中也發現了對應的trace檔案。當然這類的trace檔案說實話還是蠻枯燥的，看起來基本都是朦朦朧朧。
    我沒有花太多時間在這個trace上，轉而嘗試去複現這個問題，
 首先我通過v$sql去資料庫中查看這個SQL語句，結果尋找的很仔細，竟然沒有任何的資訊，彷彿這個語句沒有執行過一般。
 然後我切換到屬主使用者下，嘗試產生執行計畫。慶幸的是這個時候問題可以複現出來了。
SQL> @600.sql
 explain plan for MERGE INTO (SELECT * FROM TEST_SERVER_LOG WHERE BUY_TIME>=TO_DATE(:1 ,'YYYY-MM-DD HH24:MI:SS')
 *
 ERROR at line 1:
 ORA-00600: internal error code, arguments: [qcsfbdnp:1], [4], [], [25], [], [],
 [], [], [], [], [], []
由此可見，這個語句在SQL解析的時候就會拋出問題。對於這個報錯，在MetaLink上進行一番尋找，發現相關的bug還真不少，鎖定了一個較為符合的bug.
 Bug 13496884  ORA-600 [qcsfbdnp:1] from Merge Statement with Bind Variables
是和執行Merge相關的，但是查看裡面的解釋，就是打補丁，沒有其它的解決方案。
 其實對於ORA-00600的錯誤，就類似開發中的NULLPointerException，這類問題的邊界比較模糊，排查需要花費一些精力。
 我的初步感覺就是問題可能出現在兩個方面。
1.一個是TEST_SERVER_LOG這個表資料量非常大，是否在Merge中有一定的影響導致
2.語句中含有大量的綁定變數，是否綁定變數數過多導致了Merge的支援出現了問題
 於是我朝著這個方向進行了分析和排查。我逐個替換了綁定變數，把它暫時替換為常量，發現錯誤依舊出現，只是錯誤的參數部分會有下標的變化。
 直到我把整個using部分的綁定變數全部替換掉，最後竟然拋出了一個看起來不大相關的錯誤。
                  T.IP,T.WEAPONID,T.PUT_DATE,T.WEAPONID_NEW,T.COUNT,T.USER_CLASS,T.CONSUME_WAY,T.CLIENT_STYLE,T.GAME_TYPE)
                                                                                                                *
 ERROR at line 30:
 ORA-00904: "T"."GAME_TYPE": invalid identifier
看這個問題，是欄位不存在，仔細查看源表中的欄位資訊，發現這個欄位還真是不存在，我是如獲至寶，好像找到了問題的原因。
select game_type from TEST_SERVER_LOG where rownum<2
        *
 ERROR at line 1:
 ORA-00904: "GAME_TYPE": invalid identifier
臨時修複了這個問題，把這個欄位先去掉，語句就可以正常解析了，但是問題的原因是什麼呢，這個時候還是稀裡糊塗。我嘗試在using子句中再次添加一個綁定變數，問題再次出現。
ERROR at line 1:
 ORA-00600: internal error code, arguments: [qcsfbdnp:1], [7], [], [2], [], [],
 [], [], [], [], [], []
所以這個時候我的一個初步結論是，這個錯誤和綁定變數的個數沒有關係，這個問題的直接原因還是因為語句中的一個欄位不匹配導致。
 那麼這個問題是否和資料量有關呢，在諮詢了開發的同事之後，發現欄位不匹配的問題還是存在一些誤解，因為開發提供的使用者是另外一個，屬主和我測試的也完全不一樣。測試的使用者中的這個TEST_SERVER_LOG的資料量情況如下：
SQL> select count(*)from dystat_bg.TEST_SERVER_LOG ;
  COUNT(*)
 ----------
          1
所以可以證明，這個bug和TEST_SERVER_LOG的資料量無關，和綁定變數的個數無關。
 明白了這兩點我們再來看看trace檔案中的內容：
 看到了這麼一段，對我們分析這個ORA-00600的錯誤還是有一些協助的。
----- Incident Context Dump -----
Address: 0x7fff07bebbc0
 Incident ID: 324423
 Problem Key: ORA 600 [qcsfbdnp:1]
 Error: ORA-600 [qcsfbdnp:1] [4] [] [7] [] [] [] [] [] [] [] []
 [00]: dbgexProcessError [diag_dde]
 [01]: dbgeExecuteForError [diag_dde]
 [02]: dbgePostErrorKGE [diag_dde]
 [03]: dbkePostKGE_kgsf [rdbms_dde]
 [04]: kgeadse []
 [05]: kgerinv_internal []
 [06]: kgerinv []
 [07]: kgeasnmierr []
 [08]: qcsfbdnp [SQL_Parser]<-- Signaling
 [09]: qcpibva []
 [10]: qcpiapr []
 [11]: qcpiafa []
 [12]: qcpiaex []
 [13]: qcpifn1 []
 [14]: qcpifun []
 [15]: qcpiapr []
 [16]: qcpiafa []
 [17]: qcpiaex []
 [18]: qcpiexl []

報錯編碼是[qcsfbdnp:1], [7], [], [2], [], [],  這個代表的含義在這個日誌中可以看到是熟悉SQL解析器的部分調用出現了問題。

而我們分析問題的時候就可以重新審視這個語句，看看是否存在一些隱患。後續我們繼續補充。

更多詳情見請繼續閱讀下一頁的精彩內容：

1 2 下一頁