Oracle mechanics

25.03.2018

TM — Library Cache Deadlock на этапе Parsing и Optimizer Finding

Filed under: Oracle,shared pool — Игорь Усольцев @ 19:21
Tags: ,

При выполнении ALTER TABLE DROP CONSTRAINT случился TM — library cache deadlock распределённого (RAC) вида, отразившийся в ASH следующим образом:

12.1.0.2@ SQL> @ash_sql_wait_tree "(session_id,session_serial#) in ((4460,16750)) and sample_time > trunc(sysdate,'hh24')" 0
 
LVL INST_ID BLOCKING_TREE   EVENT                 WAIT_CLASS   DATA_OBJECT_P1RAW  IN_PARSE SQL_CHILD_NUMBER WAITS_COUNT EXECS_COUNT AVG_WA SESS_COUNT BLOCK_SID  MIN_STIME                  MAX_STIME                  SQL_ID        SQL_PLAN_HASH_VALUE SQL_EXEC_ID SQL_TEXT
--- ------- --------------- --------------------- ------------ ------------------ -------- ---------------- ----------- ----------- ------ ---------- ---------- -------------------------- -------------------------- ------------- ------------------- ----------- ----------------------------------------------------------------------------------------------------
  1       1 (USER)          enq: TM - contention  Application  MY.PAYMENT_Z.      N                       0          11           1      0          1 GLOBAL i#  26-JUN-17 04.06.39.431 PM  26-JUN-17 04.06.49.451 PM  7kpzqksdg4wu8                   0           1 
  1       1 (USER)          enq: TM - contention  Application  MY.PAYMENT_Z.      N                       0           2           1      0          1 VALID i#2  26-JUN-17 04.06.50.451 PM  26-JUN-17 04.06.51.451 PM  7kpzqksdg4wu8                   0           1 
  1       1 (USER)          library cache pin     Concurrency  000000261138EA48   Y                       0           1           0      1          1 GLOBAL i#  26-JUN-17 04.06.37.431 PM  26-JUN-17 04.06.37.431 PM  73f85gf8qvb34          2024994732           0 select NULL AS TABLE_CAT, OWNER AS TABLE_SCHEM, 'NO' as IS_AUTOINCREMENT, cc.COMMENTS AS REMARKS,OWN
  1       1 (USER)          library cache pin     Concurrency  000000274A98AEE0   Y                       0           1           0      0          1 GLOBAL i#  26-JUN-17 04.06.36.431 PM  26-JUN-17 04.06.36.431 PM  6196bjzyj6dv7          2050374072           0 SELECT null as TABLE_CAT, a.OWNER as TABLE_SCHEM, a.TABLE_NAME as TABLE_NAME, a.TEMPORARY as TEMPORA
  2       2   (USER)        library cache lock    Concurrency  00000027E6E364A8   Y                      -1           4           0   6807          1 VALID i#1  26-JUN-17 04.06.50.574 PM  26-JUN-17 04.06.51.574 PM  0w12fswfwtrdv          3054558131           0 UPDATE payment_z SET ...
  2       2   (USER)        library cache lock    Concurrency  00000027E6E364A8   Y                      -1           1           0      0          1 GLOBAL i#  26-JUN-17 04.06.49.564 PM  26-JUN-17 04.06.49.564 PM  0w12fswfwtrdv          3054558131           0 UPDATE payment_z SET ...
  3       1     (USER)      enq: TM - contention  Application  MY.PAYMENT_Z.      N                       0           4           1      0          1 VALID i#2  26-JUN-17 04.06.50.451 PM  26-JUN-17 04.06.51.451 PM  7kpzqksdg4wu8                   0           1 
  3       1     (USER)      enq: TM - contention  Application  MY.PAYMENT_Z.      N                       0           2           1      0          1 GLOBAL i#  26-JUN-17 04.06.49.451 PM  26-JUN-17 04.06.49.451 PM  7kpzqksdg4wu8                   0           1 
  4       2       (USER)    library cache lock    Concurrency  00000027E6E364A8   Y                      -1           4           0   6807          1 VALID i#1  26-JUN-17 04.06.50.574 PM  26-JUN-17 04.06.51.574 PM  0w12fswfwtrdv          3054558131           0 UPDATE payment_z SET ...
  4       2       (USER)    library cache lock    Concurrency  00000027E6E364A8   Y                      -1           2           0      0          1 GLOBAL i#  26-JUN-17 04.06.49.564 PM  26-JUN-17 04.06.49.564 PM  0w12fswfwtrdv          3054558131           0 UPDATE payment_z SET ...
  5       1         (USER)  enq: TM - contention  Application  MY.PAYMENT_Z.      N                       0           2           1      0          1 GLOBAL i#  26-JUN-17 04.06.49.451 PM  26-JUN-17 04.06.49.451 PM  7kpzqksdg4wu8                   0           1 
 
11 rows selected

где:

1) стартовые условия (session_id,session_serial#) in ((4460,16750)) относятся к сессии, выполняющей DDL sql_id=’7kpzqksdg4wu8′ и ожидающей TM-блокировки на целевой пользовательской таблице MY.PAYMENT_Z, при этом столбец DATA_OBJECT_P1RAW отражает название ASH.CURRENT_OBJ#, либо приведённое к RAW значение параметра P1 для ожиданий library cache

2) заметна циклическая блокировка между этой DDL сессией и ещё одной сессией (SESS_COUNT=1) в процессе HARD PARSE (EXECS_COUNT=0 — sql_exec_id для запроса ещё не назначен, плюс ASH.IN_PARSE=Y, плюс необычный SQL_CHILD_NUMBER=-1) ожидающей library cache lock на объекте Library Cache инстанса 2:

SQL> select * from x$kglob where kglhdadr = '00000027E6E364A8';
 
      INDX INST_ID KGLHDADR         KGLHDPAR           KGLHDCLT KGLNAOWN KGLNAOBJ    KGLHDNSD         KGLOBTYD
---------- ------- ---------------- ---------------- ---------- -------- ----------  ---------------- --------
    423464       2 00000027E6E364A8 00000027E6E364A8     109810 MY       PAYMENT_Z   TABLE/PROCEDURE  TABLE

— что ожидаемо, за исключением того что TM — library cache Deadlock в этом случае наблюдался между DDL и процессом разбора курсора / Cursor Parsing

3) более интересно, что у сессии, выполняющей ALTER TABLE зафиксированы ожидания library cache pin на объектах инстанса 1:

SQL> select * from x$kglob where kglhdadr in ('000000261138EA48','000000274A98AEE0');
 
      INDX INST_ID KGLHDADR         KGLHDPAR           KGLHDCLT KGLNAOWN KGLNAOBJ              KGLFNOBJ                KGLHDNSP KGLHDNSD             KGLOBTYP KGLOBTYD
---------- ------- ---------------- ---------------- ---------- -------- --------------------- --------------------- ---------- ------------------ ---------- -----------------
     47504       1 000000261138EA48 000000261138EA48      15302          3322112584808065312   3322112584808065312          103 OPTIMIZER FINDING         126 Optimizer Finding
    219488       1 000000274A98AEE0 000000274A98AEE0      70810          13603158093822877684  13603158093822877684         103 OPTIMIZER FINDING         126 Optimizer Finding

типа Optimizer Finding, очевидно (из KGLNAOBJ) относящихся к следующим SQL Plan Directives:

SQL> @spd_id "3322112584808065312, 13603158093822877684"
 
FINDING_ID             DIRECTIVE_ID           TYPE             ENABLED INT_STATE        STATE      REASON                                  TAB_CNT REDUNDANT TAB_COL_LIST                                                                                         EQ_PRED_ONLY  SIMPLE_COL_PRED_ONLY  IND_ACCESS_BY_JOIN_PRED  FILTER_ON_JOIN_OBJ  CREATED             LAST_MODIFIED       LAST_USED
---------------------- ---------------------- ---------------- ------- ---------------- ---------- ------------------------------------ ---------- --------- ---------------------------------------------------------------------------------------------------- ------------- --------------------- ------------------------ ------------------- ------------------- ------------------- -------------------
  13603158093822877684    5764885248441622424 DYNAMIC_SAMPLING YES     HAS_STATS        SUPERSEDED JOIN CARDINALITY MISESTIMATE                 11 NO        #0 SYS.ICOL$.; #0 SYS.IND$.; #0 SYS.OBJ$.; #0 SYS.SEG$.; #0 SYS.TS$.; #0 SYS.USER$.; #0 SYS.USER$.   NO            NO                    NO                       YES                 06.09.16 13:52:49   06.09.16 18:26:19   06.09.16 18:26:19
   3322112584808065312    2822799616343712739 DYNAMIC_SAMPLING YES     HAS_STATS        SUPERSEDED JOIN CARDINALITY MISESTIMATE                 19 NO        #0 SYS.COL$.; #0 SYS.COLTYPE$.; #0 SYS.OBJ$.; #0 SYS.OBJ$.; #0 SYS.SEG$.; #0 SYS.TAB$.; #0 SYS.TS$.; NO            NO                    NO                       YES                 31.01.17 16:07:21   11.02.17 17:28:40   11.02.17 17:28:40

— в статусе SUPERSEDED (т.е. уже неиспользуемым для целей компиляции) по системным таблицам, которые несмотря на статус потребовались для компиляции рекурсивных курсоров:

SQL> select sql_text from gv$sqlarea where sql_id in ('73f85gf8qvb34','6196bjzyj6dv7');
 
SQL_TEXT
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
SELECT null as TABLE_CAT, a.OWNER as TABLE_SCHEM, a.TABLE_NAME as TABLE_NAME, a.TEMPORARY as TEMPORARY, a.DURATION as DURATION, 'TABLE' as TABLE_TYPE, c.COMMENTS as REMARKS from ALL_TABLES a join ALL_
TAB_COMMENTS c on a.TABLE_NAME=c.table_name and a.owner=c.owner WHERE a.OWNER='MY' AND a.TABLE_NAME='DATABASECHANGELOG'
 
select NULL AS TABLE_CAT, OWNER AS TABLE_SCHEM, 'NO' as IS_AUTOINCREMENT, cc.COMMENTS AS REMARKS,OWNER, TABLE_NAME, COLUMN_NAME, DATA_TYPE AS DATA_TYPE_NAME, DATA_TYPE_MOD, DATA_TYPE_OWNER, DECODE (c.
data_type, 'CHAR', 1, 'VARCHAR2', 12, 'NUMBER', 3, 'LONG', -1, 'DATE', 93, 'RAW', -3, 'LONG RAW', -4, 'BLOB', 2004, 'CLOB', 2005, 'BFILE', -13, 'FLOAT', 6, 'TIMESTAMP(6)', 93, 'TIMESTAMP(6) WITH TIME
ZONE', -101, 'TIMESTAMP(6) WITH LOCAL TIME ZONE', -102, 'INTERVAL YEAR(2) TO MONTH', -103, 'INTERVAL DAY(2) TO SECOND(6)', -104, 'BINARY_FLOAT', 100, 'BINARY_DOUBLE', 101, 'XMLTYPE', 2009, 1111) AS da
ta_type, DECODE( CHAR_USED, 'C',CHAR_LENGTH, DATA_LENGTH ) as DATA_LENGTH, DATA_PRECISION, DATA_SCALE, NULLABLE, COLUMN_ID as ORDINAL_POSITION, DEFAULT_LENGTH, DATA_DEFAULT, NUM_BUCKETS, CHARACTER_SET
_NAME, CHAR_COL_DECL_LENGTH, CHAR_LENGTH, CHAR_USED, VIRTUAL_COLUMN FROM ALL_TAB_COLS c JOIN ALL_COL_COMMENTS cc USING ( OWNER, TABLE_NAME, COLUMN_NAME ) WHERE OWNER='MY' AND hidden_column='NO' AND TA

, используемых в процессе DDL

В обзоре DBA_KGLLOCK (x$kgllk + x$kglpn) отображения Library Cache объектов типа Optimizer Finding заметить пока не удалось (не отражаются?):

SQL> select *
       from dba_kgllock l
        join x$kglob w
         on l.kgllkhdl = w.kglhdadr
        and KGLHDNSD = 'OPTIMIZER FINDING'
/
no rows

, несмотря на изрядное кол-во объектов этого типа в library cache:

SQL> select count(*) from x$kglob w where KGLOBTYD = 'Optimizer Finding';
 
  COUNT(*)
----------
     11692

P.S. Собственно глобальный TM — library cache Deadlock и метод решения (*) подробно описан в трейсах 12c:

$ less orcl1_ora_29653.trc

*** 2017-06-26 16:06:49.764
-------------------------------------------------------------------------------
HUNG PROCESS DIAGNOSTIC DUMP BEGIN:

  dump requested by process (pid: 12, osid: 10292, DIA0)
    trace file: orcl1_dia0_10292.trc
-------------------------------------------------------------------------------
----- Current SQL Statement for this session (sql_id=7kpzqksdg4wu8) -----
alter table my.payment_z  drop constraint SYS_C001741749                       -- DDL

$ less orcl2_ora_12486.trc
*** 2017-06-26 16:06:49.763
-------------------------------------------------------------------------------

DEADLOCK DETECTED (id=0xae15e421)

Chain Signature: 'enq: TM - contention'<='library cache lock' (cycle)          -- Deadlock type
Chain Signature Hash: 0x8c262a57

The following deadlock is not an Oracle error. Deadlocks of
this type can be expected if certain SQL statements are
issued. The following information may aid in determining the
cause of the deadlock.

Resolving deadlock by signaling ORA-00060 to 'instance: 1, os id: 29653, session id: 4460' -- DDL fate (*)
  dump location: orcl1_ora_29653.trc

Performing diagnostic dump on 'instance: 2, os id: 12486, session id: 236'
  dump location: orcl2_ora_12486.trc

-------------------------------------------------------------------------------
    Oracle session identified by:
    {
                instance: 2 (orcl.orcl2)
                   os id: 12486
              process id: 1665, oracle@host2.orcl
              session id: 236
        session serial #: 18729
    }
    is waiting for 'library cache lock' with wait info:
    {
                      p1: 'handle address'=0x27e6e364a8
                      p2: 'lock address'=0x26ecc22270
                      p3: '100*mode+namespace'=0x24178600010002
            time in wait: 11.051326 sec
           timeout after: 14 min 48 sec
                 wait id: 275
                blocking: 20 sessions
             current sql: UPDATE payment_z SET ...                              -- the parsed query
Реклама

Добавить комментарий »

Комментариев нет.

RSS feed for comments on this post. TrackBack URI

Добавить комментарий

Заполните поля или щелкните по значку, чтобы оставить свой комментарий:

Логотип WordPress.com

Для комментария используется ваша учётная запись WordPress.com. Выход /  Изменить )

Google+ photo

Для комментария используется ваша учётная запись Google+. Выход /  Изменить )

Фотография Twitter

Для комментария используется ваша учётная запись Twitter. Выход /  Изменить )

Фотография Facebook

Для комментария используется ваша учётная запись Facebook. Выход /  Изменить )

Connecting to %s

Создайте бесплатный сайт или блог на WordPress.com.

%d такие блоггеры, как: