[20240828]分析为什么出现library cache lock等待事件5.txt

[20240828]分析为什么出现library cache lock等待事件5.txt --//前几天测试遇到的问题,假如表不存在的情况下,如果密集执行这类sql语句,不理解为什么出现library cache lock等待事件. --//验证如果有1个会话,是否会持有mode=3的情况出现. --//上午使用gdb设置断点来验证,这次直接密集执行看看. 1.环境: SCOTT@book01p> @ver2 ============================== PORT_STRING                   : x86_64/Linux 2.4.xx VERSION                       : 21.0.0.0.0 BANNER                        : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production BANNER_FULL                   : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production Version 21.3.0.0.0 BANNER_LEGACY                 : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production CON_ID                        : 0 PL/SQL procedure successfully completed. 2.首先定位该对象handle address: --//换一个方式验证: $ sql_idz.sh 'select count(1) from deptxxx' 0 sql_text = select count(1) from deptxxx\0 full_hash_value(16) = AA0B8A5E997323CE2D65F9B7AF91ED4F or aa0b8a5e997323ce2d65f9b7af91ed4f hash_value(10) = 2945576271 sql_id(32) = 2utgtqyrt3vag sql_id(32) = 2utgtqyrt3vag sql_id(32) = 2utgtqyrt3vag SYS@book> @nmsp '' x52 @ nmsp table -1 @ nmsp '' 74  or @ @ nmsp '' 0x4a|x4a KGLSTDSC       KGLSTIDN KGLSTIDN_HEX -------------- -------- ------------ SQL AREA BUILD       82 52 --//阻塞的对象在aa0b8a5e997323ce2d65f9b7af91ed4f.$BUILD$.BOOK01P\x52\0\0\0 $ sql_idz.sh 'aa0b8a5e997323ce2d65f9b7af91ed4f.$BUILD$.BOOK01P\x52\0\0\0' 3 sql_text = aa0b8a5e997323ce2d65f9b7af91ed4f.$BUILD$.BOOK01P\x52\0\0\0 full_hash_value(16) = 21DBAB24066F9561659DE3D1D5F8B304 or 21dbab24066f9561659de3d1d5f8b304 xxxxx_matching_signature(10) = 7322259059551810308 or  25769003133261361924 hash_value(10) = 3589845764 sql_id(32) = 6b7g3u7azjcs4 sql_id(32) = 6b7g3u7azjcs4 sql_id(32) = 6b7g3u7azjcs4 --//hash_value(10) = 3589845764 SCOTT@book01p> select count(1) from deptxxx; select count(1) from deptxxx                      * ERROR at line 1: ORA-00942: table or view does not exist --//执行多次。 SYS@book> @ kglob 0 3589845764 ============================== INST_ID                       : 1 OWNER                         : $BUILD$ NAME                          : aa0b8a5e997323ce2d65f9b7af91ed4f DB_LINK                       : NAMESPACE                     : SQL AREA BUILD TYPE                          : CURSOR NAMESPACE_NUM                 : 82 NAMESPACE_HEX                 : 52 SHARABLE_MEM                  : 0 LOADS                         : 0 EXECUTIONS                    : 0 LOCKS                         : 0 PINS                          : 0 KEPT                          : NO CHILD_LATCH                   : 45828 INVALIDATIONS                 : 0 HASH_VALUE                    : 3589845764 LOCK_MODE                     : NONE PIN_MODE                      : NONE STATUS                        : UNKOWN TIMESTAMP                     : PREVIOUS_TIMESTAMP            : LOCKED_TOTAL                  : 5 PINNED_TOTAL                  : 0 PROPERTY                      : FULL_HASH_VALUE               : 21dbab24066f9561659de3d1d5f8b304 CON_ID                        : 3 CON_NAME                      : BOOK01P ADDR                          : 0000000062E09BD0 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ EDITION                       : SQL_ID                        : OBJECT_STR                    : aa0b8a5e997323ce2d65f9b7af91ed4f.$BUILD$.BOOK01P\x52\0\0\0 PL/SQL procedure successfully completed. --//其handle address=0000000062E09BD0 --//建立bbb.txt包含50000个/ --//$ rm bbb.txt $ seq 50000 | xargs -IQ echo / >> bbb.txt $ uniq -c bbb.txt   50000 / 3.开始测试： --//session 1: SCOTT@book01p> select count(1) from deptxxx; select count(1) from deptxxx                      * ERROR at line 1: ORA-00942: table or view does not exist --//session 2: SYS@book> spool /tmp/lk1.txt SYS@book> column KGLNAOBJ format a32 SYS@book> select KGLLKSNM sid ,KGLLKMOD,KGLLKREQ,KGLNAOBJ,KGLLKHDL from x$kgllk where KGLLKHDL=hextoraw(upper('0000000062E09BD0')); no rows selected --//两边同时调用bbb.txt执行,等待执行完成.我的测试在执行session 2执行,然后快速切换到session 1执行. $ egrep "0000000062E09BD0$|---| KGLLKHDL$" /tmp/lk1.txt | sort |uniq -c     959 ---------- ---------- ---------- -------------------------------- ----------------       1        268          0          0 aa0b8a5e997323ce2d65f9b7af91ed4f 0000000062E09BD0       9        268          2          0 aa0b8a5e997323ce2d65f9b7af91ed4f 0000000062E09BD0     949        268          3          0 aa0b8a5e997323ce2d65f9b7af91ed4f 0000000062E09BD0     959        SID   KGLLKMOD   KGLLKREQ KGLNAOBJ                         KGLLKHDL --//可以看出出现9次KGLLKMOD=3的情况,奇怪这样抓不到KGLLKMOD=0,KGLLKREQ=3的情况.也许这样的状态阻塞查询. 4.最后一个问题为什么这么多对象,最容易阻塞的在这里呢? $ cat lcl.gdb set pagination off set logging file /tmp/lkpn.log set logging overwrite on set logging on set $lk  = 0 set $pn  = 0 set $lock  = 0 #break kgllkal if ( $rdx==0x0000000062E09BD0) break kgllkal commands silent printf "kgllkal count %02d -- handle address: %016x, mode: %d ", ++$lk ,$rdx ,$rcx echo kglnaobj address: x/s $rdx+0x1c8 c #finish end #break kglpnal if $rcx==3 break kglpnal commands  silent  printf "kglpnal count %02d -- handle address: %016x, mode: %d ", ++$pn ,$rdx ,$rcx  echo kglnaobj address:  x/s $rdx+0x1c8  c  end break kglLock commands silent #printf "kglLock count %02d -- handle address: %016x, mode: %d \n", ++$lock ,$rdx ,$rcx printf "kglLock count %02d -- mode: %d \n", ++$lock ,$rcx c finish end Breakpoint 1 at 0x15367e90 Breakpoint 2 at 0x1536c020 Breakpoint 3 at 0x15363530 (gdb) c Continuing. kglLock count 01 ---------------------- kgllkal count 01 -- handle address: 0000000062e0b100, mode: 1 kglnaobj address:0x62e0b2c8:      "select count(1) from deptxxx" ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ kglLock count 02 ---------------------- kgllkal count 02 -- handle address: 0000000062e09bd0, mode: 2 kglnaobj address:0x62e09d98:      "aa0b8a5e997323ce2d65f9b7af91ed4f$BUILD$BOOK01P" kgllkal count 03 -- handle address: 0000000062e099a0, mode: 1 kglnaobj address:0x62e09b68:      "" kglpnal count 01 -- handle address: 0000000062e099a0, mode: 3 kglnaobj address:0x62e09b68:      "" kglLock count 03 ---------------------- ++++++++++++++++++++++++++++++++++++++ kgllkal count 04 -- handle address: 00000000702c73a0, mode: 2 kglnaobj address:0x702c7568:      "bookSYSCDB$ROOT" kglLock count 04 ---------------------- kgllkal count 05 -- handle address: 000000006b57c9f8, mode: 2 kglnaobj address:0x6b57cbc0:      "1073777561SYSCDB$ROOT" kglLock count 05 ---------------------- kgllkal count 06 -- handle address: 0000000062e08570, mode: 1 kglnaobj address:0x62e08738:      "aa0b8a5e997323ce2d65f9b7af91ed4fChild:0BOOK01P" kglpnal count 02 -- handle address: 0000000062e08570, mode: 3 kglnaobj address:0x62e08738:      "aa0b8a5e997323ce2d65f9b7af91ed4fChild:0BOOK01P" kglLock count 06 ---------------------- kgllkal count 07 -- handle address: 000000006e1370d8, mode: 1 kglnaobj address:0x6e1372a0:      "SCOTTBOOK01P" kglLock count 07 ---------------------- kglLock count 08 ---------------------- kgllkal count 08 -- handle address: 00000000702c73a0, mode: 2 kglnaobj address:0x702c7568:      "bookSYSCDB$ROOT" kglLock count 09 ---------------------- kgllkal count 09 -- handle address: 000000006b57c9f8, mode: 2 kglnaobj address:0x6b57cbc0:      "1073777561SYSCDB$ROOT" kglLock count 10 ---------------------- kgllkal count 10 -- handle address: 0000000062e07040, mode: 2 kglnaobj address:0x62e07208:      "DEPTXXXSCOTTBOOK01P" kglpnal count 03 -- handle address: 0000000062e07040, mode: 2 kglnaobj address:0x62e07208:      "DEPTXXXSCOTTBOOK01P" kglLock count 11 ---------------------- kgllkal count 11 -- handle address: 0000000062e055e0, mode: 2 kglnaobj address:0x62e057a8:      "DEPTXXXPUBLICBOOK01P" kglpnal count 04 -- handle address: 0000000062e055e0, mode: 2 kglnaobj address:0x62e057a8:      "DEPTXXXPUBLICBOOK01P" --//为什么没有出现在下划线位置呢? SYS@book> select KGLLKSNM sid ,KGLLKMOD,KGLLKREQ,KGLNAOBJ,KGLLKHDL from x$kgllk where KGLLKHDL=hextoraw(upper('0000000062e0b100'));        SID   KGLLKMOD   KGLLKREQ KGLNAOBJ                         KGLLKHDL ---------- ---------- ---------- -------------------------------- ----------------        268          1          0 select count(1) from deptxxx     0000000062E0B100 --//在语句的父游标句柄上KGLLKMOD=1.重新前面的测试. $ egrep "0000000062E0B100$|---| KGLLKHDL$" /tmp/lk2.txt | sort |uniq -c       1 ---------- ---------- ---------- -------------------------------- ----------    6247 ---------- ---------- ---------- -------------------------------- ----------------       1        268          0          0 select count(1) from deptxxx     0000000062E0B100    6246        268          1          0 select count(1) from deptxxx     0000000062E0B100    6248        SID   KGLLKMOD   KGLLKREQ KGLNAOBJ                         KGLLKHDL --//KGLLKMOD=1,NULL模式,表示易碎解析锁,表示是否有效,失效的状态.根本不存在阻塞. --//在+++++++位置出现阻塞，就很容易理解，不知道是否与前面的kglpnal mode=3,不过对象不同. kglpnal count 01 -- handle address: 0000000062e099a0, mode: 3 kglnaobj address:0x62e09b68:      ""  --//子游标句柄有关。 --//现在想想oracle从12c开始在alter日志中记录执行超过100次以上的有问题的sql语句，有其道理的。  $ grep deptxxx alert_book.log |uniq -c    7006 BOOK01P(3):select count(1) from deptxxx