子游標過多導致大量mutex爭用故障分析

jason_yehua發表於2023-12-25
Mutex

問題處理

背景：

2017 / 04/02 日中 午11 點 30 左右 ，接到 jzdb3 庫 節點 1 資料庫 效能差， awr 中出現 嚴重 的 cursor: mutex S\ cursor: mutex X 爭用 。

SR 3-14602160331 :   A Large number of child cursor caused the 'cursor: mutex S' and 'cursor: mutex X'

SSC 透過現場對 DB 、 RAC 、 OS 、 SQLHC 、 SQL version_rpt 等資料做了詳細的原因分析。

救援 過程

1 、 AWR 報告分析

現場 抓取了 今天 一整天的AWR 日誌， 從 AWR 追溯到從凌晨 1 點 TOP Events 中 開始出現cursor: mutex S 、 cursor: mutex X 爭用：  

下一個半個小時 的awr 開始 持續 處於 event 的前列：

分析 造成 該 event 衝高的 SQL為 下面兩條 SQL導致 的：

SQL ID:  au0v7hv343q45\

具體 的 SQL TEXT:

SQL ID : au0v7hv343q45:

select  to_char(account_id),

       acctbk_id,

       to_char(last_balance),

       to_char(current_balance),

       status,

       to_char(start_date, 'yyyymmddhh24miss' ),

       to_char(end_date, 'yyyymmddhh24miss' ),

       unit,

       to_char(expire_date, 'yyyymmddhh24miss' ),

       to_char(join_id),

       to_char( version )

   from  acctbk

  where  account_id = to_number(:v_account_id)

    and  acctbk_id = :v_acctbk_id

 

SQL ID:

select  to_char(account_id),

       acctbk_id,

       to_char(last_balance),

       to_char(current_balance),

       status,

       to_char(start_date, 'yyyymmddhh24miss' ),

       to_char(end_date, 'yyyymmddhh24miss' ),

       unit,

       to_char(expire_date, 'yyyymmddhh24miss' ),

       to_char(join_id),

       to_char( version )

   from  acctbk

  where  account_id = to_number(:v_account_id)

    and  acctbk_id = :v_acctbk_id

    for   update   nowait

 

  均為 對acctbk 表 的 查詢 操作 。

2 、 Version Count Report 分析

分析 SQL C ount ：

au0v7hv343q45 ：

 

發現造成子游標不能共享的原因主要有 LANGUAGE_MISMATCH 、 ROLL_INVALID_MISMATCH 子游標 數目比較高，而且一直沒有age out 出去 。

於是 我們使用下面命令收集統計資訊：

exec dbms_stats.gather_table_stats(ownname => 'accounting',tabname => 'acctbk',estimate_percent => 5,degree => 4,cascade => true, no_invalidate => false )

 

PL/SQL procedure successfully completed.

 

Elapsed: 00:07:47.44

該命令 執行了 7 分 多鍾， no_invalidate 引數 設定為false ， 目的 是 讓表 acctbk 對應 的 SQL 的 所有子游標 立即 失效，並age out 出 share pool 。

執行 完該 命令 之後，再取awr 報告， c ursor: mutex S 、 cursor: mutex X 消失 ，系統恢復正常。

分析過程

該故障分析 的焦點問題為：

1、  大量 LANGUAGE_MISMATCH 、 ROLL_INVALID_MISMATCH 、 BIND_MISMATCH 如何產生 的。

2、  為什麼產生 了這麼多的 mismatch 的子游標又不能及時 的 被age out 出去 。

針對第一個 問題，我們逐個做了分析：

1、  產生 原因

【 LANGUAGE_MISMATCH 】

LANGUAGE_MISMATCH 與 環境設定 NLS_* 有關係 ， 比如 客戶端session 中 使用 了不同的NLS_SORT 等。  

TEST CASE:

a lter system flush shared_pool;

create table X as select * from dba_tables;

set time on pages 1000 lin 200

col FIRST_LOAD_TIME format a20

col last_load_time format a20

var b1 varchar2(128);

var b2 varchar2(128);

exec :b1 := '0';         

exec :b2 := '0';

nls_sort

alter session set = 'SCHINESE_RADICAL_M';

select count(*) from X where table_name=:b1 and OWNER=:b2;

--- 修改 nls_sort

alter session set nls_sort = 'SCHINESE_STROKE_M';

select count(*) from X where table_name=:b1 and OWNER=:b2;

-- 修改 nls_sort

alter session set nls_sort = 'SCHINESE_PINYIN_M';

select count(*) from X where table_name=:b1 and OWNER=:b2;

-- 查詢 SQL id ：

09:12:41 SQL> select sql_id from v$sql where sql_text='select count(*) from X where table_name=:b1 and OWNER=:b2';

SQL_ID

-------------

1uk1h0wuzcuaf

 

09:14:53 SQL> select sql_id,child_address,language_mismatch,roll_invalid_mismatch,BIND_MISMATCH from v$sql_shared_cursor where sql_id='1uk1h0wuzcuaf';

SQL_ID        CHILD_ADDRESS    L R B

------------- ---------------- - - -

1uk1h0wuzcuaf 00000000750EDBB0 N N N

1uk1h0wuzcuaf 0000000079F0C748 Y N N

1uk1h0wuzcuaf 0000000075F5F6A0 Y N N

  【 ROLL_INVALID_MISMATCH 】

在統計資訊收集的時候，預設情況下 dbms_stats 的 no_invalidate 引數為 auto_invalidate ，意思 是 收集 完統計資訊之後， 不 立即失效 統計 物件 相關 的cursor ，而是 採用滾動 失效 的方式 。這種做法 是為了 避免 統計資訊收集之後產生大量的硬解析 。資料庫會隨機 的取一個小於_optimizer_invalidation_period 值來判斷子游標的 INVALIDATE 時間，預設情況下是 18000 秒，即 5 個小時。

18000s 並不是從統計資訊收集開始（下圖 中的 T0 ），而是從統計資訊收集之後該 SQL 的第一次解析時間開始（ T1 ）， 然後隨機的取一個時間，該時間小於_optimizer_invalidation_period 設定 的時間 ，我們 可以定義為下圖的 T max 。

下次 執行的時候 （ T2 ）， 如果 T2 小於 T max ，就會複用以前的子游標，如果 T2 大於 T max ， 則 會執行硬解析 。

 

TEST CASE:

alter system flush shared_pool;

create table X as select * from dba_tables;

set time on pages 1000 lin 200

col FIRST_LOAD_TIME format a20

col last_load_time format a20

alter system set "_optimizer_invalidation_period"=120;

09:38:56 SQL> select child_number,parse_calls,executions,first_load_time, last_load_time,last_active_time from v$sql where sql_id='95rckg79jgshh';

CHILD_NUMBER PARSE_CALLS EXECUTIONS FIRST_LOAD_TIME      LAST_LOAD_TIME       LAST_ACTIVE_TIME

------------ ----------- ---------- -------------------- -------------------- -----------------

0           3          3 2017-04-06/09:35:47  2017-04-06/09:35:47  06/04/2017 09:38:55

09:39:00 SQL>  exec dbms_stats.gather_table_stats(null,'X');

PL/SQL procedure successfully completed.

09:39:23 SQL> select last_analyzed from dba_tables where table_name='X';

LAST_ANALYZED

-------------------

06/04/2017 09:39:23

09:39:38 SQL> select count(*) from X;

COUNT(*)

----------

2341

 

09:43:58 SQL> select child_number,parse_calls,executions,first_load_time, last_load_time,last_active_time from v$sql where sql_id='95rckg79jgshh';

CHILD_NUMBER PARSE_CALLS EXECUTIONS FIRST_LOAD_TIME      LAST_LOAD_TIME       LAST_ACTIVE_TIME

------------ ----------- ---------- -------------------- -------------------- -------------------

0           4          4 2017-04-06/09:35:47  2017-04-06/09:35:47  06/04/2017 09:39:46

1           1          1 2017-04-06/09:35:47  2017-04-06/09:43:57  06/04/2017 09:43:57

 

09:44:01 SQL> select sql_id,child_address,language_mismatch,roll_invalid_mismatch,BIND_MISMATCH from v$sql_shared_cursor where sql_id='95rckg79jgshh';

SQL_ID        CHILD_ADDRESS    L R B

------------- ---------------- - - -

95rckg79jgshh 00000000748609A0 N N N

95rckg79jgshh 00000000751A7820 N Y N

【 BIND_MISMATCH 】

一般是由於bind value 的長度不同導致 bind buffer 無法重用，最終導致 cursor 無法重用。

2 、 為什麼不被清理

經過分析 和多輪測試發現：

ROLL_INVALID_MISMATCH 為 Y 的子 遊標， 在統計資訊 收集之後， 如果使用 預設的NO_INVALIDATE=   AUTO_INVALIDATE ， 過 一段時間 之後，會被置 為 invalidations ， 並有 特 定 的 機制保 證 它及時的age out 出去。 在 12 c 中 ，未發現無法清理 的bug 存在 ，假設 有，那麼acctbk 表所 涉及到的所有 SQL 都應該會 出現該 問題 ，從 記賬庫 3 查詢的情況來看，是可以排除該可能性的。

、 BIND_MISMATCH 為 客戶端 編碼 導致的， 當 一個 子 遊標的LANGUAGE_MISMATCH/ BIND_MISMATCH 被標記成 Y 之後， 在 的object_status 就 一直為valid 狀態 ， 資料庫 認為他還是有可能被重新 複用 的， 只有當該物件在 統計資訊收集的時候 ， 使用NO_INVALIDATE=>false 引數，該 狀態才能變成INVALID_UNAUTH ， 在下次 SQL 被 執行之後 才能 age  out 出去 。

另外 從 目前記賬庫上 查詢的情況來看 ，大部分子 cursor 的 ROLL_INVALID_MISMATCH 、 LANGUAGE_MISMATCH 欄位 同時為 Y ， V $SQL 的 object_status 為 valid ， 這 就能解釋了 ROLL_INVALID_MISMATCH 不能 被age out 的 原因 ：

SQL>select sql_id,child_address,language_mismatch,roll_invalid_mismatch,BIND_MISMATCH from v$sql_shared_cursor where sql_id='6uvmkxmcvbc6t';

    SQL_ID            CHILD_ADDRESS        LANGUAGE_MISMATCH ROLL_INVALID_MISMATCH BIND_MISMATCH    

    6uvmkxmcvbc6t     C000002357553CE8            Y            N                     Y    

    6uvmkxmcvbc6t     C00000235749AC10            Y            N                     Y    

    6uvmkxmcvbc6t     C000002353906DA0            Y            N                     Y    

    6uvmkxmcvbc6t     C000002354557798            Y            N                     Y    

    6uvmkxmcvbc6t     C0000021BFEDCC50            Y            Y                     N    

    6uvmkxmcvbc6t     C0000021BF661238            Y            Y                     N    

    6uvmkxmcvbc6t     C0000021BE4973D8            Y            Y                     Y    

    6uvmkxmcvbc6t     C0000021BDF0F488            Y            Y                     N    

    6uvmkxmcvbc6t     C0000020DBE75628            Y            Y                     N    

    6uvmkxmcvbc6t     C0000020DB9FA1A8            Y            Y                     N    

    6uvmkxmcvbc6t     C0000020DB9F2FC8            Y            Y                     N    

    6uvmkxmcvbc6t     C0000020DB7E7C60            Y            Y                     N    

    6uvmkxmcvbc6t     C00000226B498B18            Y            Y                     N    

    6uvmkxmcvbc6t     C000001FEC10BE90            Y            Y                     N    

    6uvmkxmcvbc6t     C000002269971508            Y            Y                     N    

    6uvmkxmcvbc6t     C000002265912D38            Y            Y                     N    

    6uvmkxmcvbc6t     C0000020D32857D8            Y            Y                     N    

    6uvmkxmcvbc6t     C0000020D3C625B8            Y            Y                     Y    

    6uvmkxmcvbc6t     C0000020D01DF1D0            Y            Y                     N    

    6uvmkxmcvbc6t     C0000020CFE39790            Y            Y                     N    

    6uvmkxmcvbc6t     C00000226A5A8D80            Y            Y                     N    

    6uvmkxmcvbc6t     C00000226B529B90            Y            Y                     N    

    6uvmkxmcvbc6t     C00000226B53B440            Y            Y                     N    

    6uvmkxmcvbc6t     C000002268732578            Y            Y                     N    

    6uvmkxmcvbc6t     C0000020CD03B6C8            Y            Y                     Y    

    6uvmkxmcvbc6t     C0000020C6D79578            Y            Y                     N    

    6uvmkxmcvbc6t     C000002351AFBB78            Y            Y                     Y    

    6uvmkxmcvbc6t     C0000020C4E37F08            Y            Y                     N

 

SQL>select child_number,LAST_ACTIVE_TIME,LAST_LOAD_TIME,OBJECT_STATUS from v$sql where sql_id='6uvmkxmcvbc6t' order by LAST_ACTIVE_TIME;

      CHILD_NUMBER    LAST_ACTIVE_TIME         LAST_LOAD_TIME            OBJECT_STATUS      

      1               2017/4/1 17:04:57        2017-04-01/17:04:57            VALID      

      2               2017/4/2 9:01:35         2017-04-01/17:06:01            VALID      

      3               2017/4/2 9:02:27         2017-04-01/17:06:01            VALID      

      0               2017/4/2 11:19:38        2017-04-01/17:04:57            VALID      

      6               2017/4/3 1:53:15         2017-04-02/11:20:01            VALID      

      5               2017/4/3 1:54:21         2017-04-02/09:55:21            VALID      

      7               2017/4/3 3:48:58         2017-04-02/12:39:23            VALID      

      4               2017/4/3 6:00:42         2017-04-02/09:02:28            VALID      

      11              2017/4/3 23:16:10        2017-04-03/06:17:07            VALID      

      10              2017/4/4 0:30:47         2017-04-03/05:16:42            VALID      

      9               2017/4/4 0:42:46         2017-04-03/02:57:43            VALID      

      8               2017/4/4 2:08:32         2017-04-03/01:54:22            VALID      

      14              2017/4/4 23:08:15        2017-04-04/01:14:50            VALID      

      12              2017/4/4 23:08:15        2017-04-04/00:30:47            VALID      

      15              2017/4/5 1:44:24         2017-04-04/02:08:56            VALID      

      13              2017/4/5 1:45:39         2017-04-04/01:08:46            VALID      

      17              2017/4/5 23:31:41        2017-04-05/00:32:06            VALID      

      16              2017/4/6 0:33:06         2017-04-05/00:32:06            VALID      

      18              2017/4/6 2:26:54         2017-04-05/01:45:39            VALID      

      19              2017/4/6 2:27:46         2017-04-05/03:34:29            VALID      

      20              2017/4/6 23:26:48        2017-04-06/00:33:07            VALID      

      23              2017/4/6 23:46:55        2017-04-06/03:31:30            VALID      

      21              2017/4/7 0:34:21         2017-04-06/02:19:02            VALID      

      22              2017/4/7 1:54:16         2017-04-06/02:27:47            VALID      

      24              2017/4/7 1:55:31         2017-04-06/23:49:10            VALID      

      27              2017/4/7 10:34:12        2017-04-07/02:15:01            VALID      

      25              2017/4/7 10:37:39        2017-04-07/00:34:21            VALID      

      26              2017/4/7 10:39:15        2017-04-07/01:55:32            VALID  

 

故障 分析 總結

基於 上述分析， 客戶端環境 變數 、 遊標使用不規範導致了mismatch 的子游標過多，進而導致了 cursor: mutex S 、 cursor: mutex X 爭用， 效能出現問題， 因為 客戶端環境比較複雜，修改起來需要一個過程，目前 資料庫 端能做的workaround 有如下 ：

1、  定期 監控遊標過多的 SQL ，子游標 超過 200 的， 收集統計資訊的時候 使用 no_invalidate=false 引數。

或者為有 上述 問題 的 表 特別的指 定 統計資訊收集屬性， 設定 no_invalidate => false ， 方法 如下 ：

SQL> SELECT DBMS_STATS.GET_PREFS('NO_INVALIDATE','SYS','X') FROM DUAL;

 

DBMS_STATS.GET_PREFS('NO_INVALIDATE','SYS','X')

--------------------------------------------------------------------------------

DBMS_STATS.AUTO_INVALIDATE

 

SQL>

 

PL/SQL procedure successfully completed.

 

SQL> SELECT DBMS_STATS.GET_PREFS('NO_INVALIDATE','SYS','X') FROM DUAL;

 

DBMS_STATS.GET_PREFS('NO_INVALIDATE','SYS','X')

--------------------------------------------------------------------------------

FALSE

2、  當 出現子游標過多的時候，執行如下命令將該 SQL 的所有 子游標清除出去

SQL> alter session set events '5614566 trace name context forever'  --oracle10g 需要執行  

 

SQL>select address,hash_value,executions,parse_calls from v$sql where sql_id='3yr4fwqux2buz';

 

SQL> . e('00000000749AF8B8,3050385247','C');

 

- -   引數 1 ： SQL address ；引數 2 ：  hash_value ；引數 3 ： C 表示 PURGE 的物件是 CURSOR

 

3、  修改每個 sql 允許生成子游標 的總個數 （ 12 c 版本預設值為 1024 ）

SQL>alter system set " _cursor_obsolete_threshold  "=200;

 


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

相關文章