重啟大法失效？詳述Oracle11g因JDBC bug引發異常Library Cache Lock等待處理事件

墨墨導讀：在Oracle 11g 版本中可能出現由於JDBC bug導致sql繫結變數無法共享，過期遊標過多的情況，此時如果發生大量併發業務，很有可能造成異常library cache lock等待事件，造成資料庫突發效能問題。在此，我們分享一次由jdbc bug和繫結變數長度問題共同“作案”引發資料庫效能故障的案例。

本文節選自《雲和恩墨技術通訊》（12月刊）
下載連結：

library cache lock等待事件是Oracle資料庫較為常見的等待事件之一，在之前的幾次月刊中，我們也提到過產生library cache lock等待出現的原因有很多，如登入密碼錯誤嘗試過多、熱表收集統計資訊和SQL解析失敗等。

在Oracle 11g 版本中可能出現由於JDBC bug導致sql繫結變數無法共享，過期遊標過多的情況，此時如果發生大量併發業務，很有可能造成異常library cache lock等待事件，造成資料庫突發效能問題。在此，我們分享一次由jdbc bug和繫結變數長度問題共同“作案”引發資料庫效能故障的案例，供各位參考。

問題描述

---

2019年10月11號晚22:00分左右，運維人員對生產系統資料庫進行清理歷史分割槽操作，執行近100個分割槽刪除操作後（22:05左右）發現該資料庫壓力飆升，維護人員緊急停止歷史分割槽清理操作，發現大量業務資料插入（INSERT）緩慢。

檢視故障期間資料庫發現大量library cache lock等待，資料庫活動會話飆升至1000以上，資料庫響應非常緩慢，業務受到嚴重影響。

問題分析

---

從故障期間ASH的整體執行情況看：

從22:00開始，資料庫的活動會話飆升，每秒活動會話飆升至1000以上。故障時間段內的TOP EVENT主要表現在library cache lock和library cache: mutex X等待上。

檢視故障期間資料庫活動會話情況：

從10:00:08的ash資訊來看，多個library cache lock被4276會話阻塞，4276會話被4374會話 “cursor : mutex S”阻塞，同時4374會話被8168“library cache lock”阻塞。從ash分析來看，大量的library cache lock會話的p3值都是5373954和5373955。5373954指的是mode=2，5373955的mode=3，只是持有的方式不同mode=3就是exclusive獨佔鎖。

而4276會話library cache lock的p3值是5373955，對應的namespace HEX:52 —>DEC:82，mode=3。

SQL AREA BUILD說明library cache lock是在SQL解析上或SQL AREA上的問題。

發生等待是會話都是在執行g14zxrn7wyaxh  INSERT SQL語句：

/** PayOrderMapper.insert */
INSERT INTO TxxxxxxT T
  (T.ID,……T.SxxxO)
VALUES
  (SEQ_xxx.nextval,
   :1,:2,:3,:4,:5,:6,:7,:8,:9,:10,:11,:12,:13,:14,:15,:16,:17,:18,:19,:20,:21,:22,:23,:24,:25,:26,:27,:28,:29,:30,:31,:32,:33,:34,:35,:36,:37,:38,:39,:40,:41,:42,:43,:44,:45,:46,SYSDATE,:47,SYSDATE,:48,:49,:50,:51)

該SQL中有51個繫結變數，多個繫結變數可能會導致bind variable graduation問題出現，繼而導致cursor無法被shared。

從ASH和DBA_HIST_SQLSTAT中可以看出21:45分之後SQL頻繁load到cursor cache中，其中invalidations有120次，這是從DASH中取的資料，實際數值比取樣還要大，另外SQL的LOADED_VERSION從原來的2431個在短時間內增長到5411個，實際的version count由於11.2.0.3的隱含引數_cursor_obsolete_threshold的關係，version count超過100會重新開始。

這個時候就懷疑是由於SQL的子游標過多引起SQL解析時遍歷library cache object handle連結串列需要很長時間，造成了library cache: mutex x等待。

在資料庫中可以看出大量loaded_version超過1000的SQL語句，並且其中有大量遊標是過期的。其中SQL_ID：g14zxrn7wyaxh就是此次library cache lock等待最為嚴重的SQL。

導致SQL不共享的原因很多，一部分是由於SQL中繫結變數長度不一致導致。

採集故障期間的AWR，發現當時DB TIME接近2w，平均活動會話達到1200+。

排在前五的等待事件都屬於併發類的等待事件，其中cursor：mutex S等待次數最多。

從ASH中分析library cache lock可以得出，多個會話等待library cache lock主要發生在SQL AREA BUILD的mutex持有爭用上。Library cache: mutex X 是10.2.0.2之後library cache latch衍生出來等待。

以下是部分等待事件的含義：

此類等待事件往往都是發生在SQL解析前遍歷library cache object handle連結串列找到shared cursor。

檢視AWR中的Mutex Sleep資訊發現：Mutex主要有三個函式的sleep是非常高的，kgllkal3 82、kkshGetNextChild[KKSHBKLOC1]、kglUpgradeLock 119。

函式-kgllkal3 82:kglkal的意思就是kernel generic library cache management library cache lock allocate 82的意思就是SQL AREA BUILD的意思。

函式-kkshGetNextChild [KKSHBKLOC1]:kksh的意思是kernel compile shared objects (cursor) cursor hash table，就是shared cursor的hash連結串列。持有mutex從library cache 的handle的hash連結串列上找出可共享的遊標。

檢視library cache中namespace的命中：

從AWR中可以看出SQL AREA BUILD被請求次數是最多的，這跟ASH中大量library cache lock是吻合的，SQL AREA中cursro reloads次數也達到10740次。Invali_dations達到1170次，說明有很多cursor失效了。

造成library cache lock等一系列嚴重等待事件的原因是大量的過期遊標導致sql解析前花了大量時間去遍歷library cache object handle，問題SQL的5415個cursor中有5367個是標記為過期的，檢視遊標不能被共享的原因：

造成遊標不能被共享的原因中有5257個遊標的原因是Bind Mismatch(22)，也就是繫結變數的字元長度發生變化，從32位升級到128位。

其中Bind mismatch(14)的也有3294個，這個主要是繫結變數TIMESTAMP型別傳值到DATE型別導致的問題。Bind mismatch(14)多發生在第6個繫結變數上，對應表中第7個欄位，該欄位正好的DATE型別。

綜合以上分析,造成大量遊標過期的原因有以下兩個：
1、繫結變數長度導致遊標無法共享
2、JDBC的bug導致日期型別透過TIMESTAMP傳值，繼而導致繫結變數無法共享

相關bug：

Bug 18617175 : JDBC THIN SENDS SCALE VALUE OF 0 OR 9 FOR BINDS CAUSING MANY CHILD CURSORS
Bug 12596686 : JDBC THIN APP SENDS SCALE VALUE OF 0 OR 9 FOR BINDS CAUSING MANY CHILD CURSORS
Patch 12596686: JDBC THIN APP SENDS SCALE VALUE OF 0 OR 9 FOR BINDS CAUSING MANY CHILD CURSORS

從上面截圖的MOS文件來看，JDBC版本升級到11203或11204仍有發生此例繫結變數傳值問題。

為什麼重啟應用無法解決？

1、kill session：故障發生後資料庫端進行kill session操作，但是因為有連線池，所以連線池會嘗試重連資料庫，kill 後的重連在連線池上幾乎是併發的，因此負載也很高，所以kill session不行；

2、重啟應用：重啟應用前資料庫端的latch競爭一直都有，大量的活動會話並沒有釋放。如果這個時候重啟應用還是會有新的連線進來，這些新進的連線依然會進入到佇列中等待，繼而加劇爭用，因為重啟並不會中止資料庫上之前的連線，所以重啟應用也不行；

3、關閉應用並kill session：應該關閉應用，然後資料庫端kill session，再啟動應用。

問題解決

---

建議一：後期進行歷史分割槽清理的操作（DDL操作同類）時，需提前查詢表上SQL的遊標是否超過200，如超過這個閾值，應主動使用DBMS_SHARED_POOL.PURGE的方式將過期的遊標清理出記憶體，儘可能的減少遍歷遊標HASH連結串列時間較長的現象；

查詢並清理過期遊標的SQL：

select q'[exec sys.dbms_shared_pool.purge(']' || address || ',' ||
        hash_value || q'[','C');]' as flush_sql
  from v$sql t
 where t.sql_id = '&sqlid'
   and t.is_obsolete = 'Y'
   group by address,hash_value;

建議二：從應用層面，建議將前述同一個SQLID(g14zxrn7wyaxh)的SQL文字，透過在原SQL文字中，加入不同的註釋，從而將其變為若干個不同SQLID，但功能相同的SQL。其目的也是業務峰期時，將訪問分散到不同的父遊標上。

其他建議：
1、將單個SQL遊標總數加入到監控告警中，前提是v$sql_shared_cursor中的遊標總量在閾值內，目前根據測試和經驗總結建議閾值設定為200；

2、資料庫分割槽維護操作屬於DDL操作，影響較大，應選擇業務最低峰期進行操作；

3、資料庫上執行DDL操作時，應實時監控資料庫的活動會話等待事件，如果出現mutex或latch等待持續上升，應立即取消DDL操作，並持續監控資料庫效能。