[20260718]跟踪带dblink的sql语句的library cache lock/library cache pin的使用情况.txt

--//还从来没有使用自己写的gdb或者其他脚本跟踪带dblink的sql语句，看看相应sql语句使用library cache lock/library cache pin的情况.
--//为了测试比较符合实际情况，使用2个数据库，版本都是21c。

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个测试库，版本相同。

--//测试环境如下
ip_address     hostanme  oracle
192.168.56.103 centos    21c
192.168.56.101 centtest  21c

--//192.168.56.103 centos
SCOTT@book01p> CREATE PUBLIC DATABASE LINK CENTTEST CONNECT TO SCOTT IDENTIFIED BY 'book' USING '192.168.56.101/book01p';
Database link created.

2.测试使用bpftrace脚本:

# cat /home/oracle/sqllaji/bt/lkpn21x.bt
#!/usr/bin/env bpftrace

BEGIN
{
    printf("Tracing Oracle kgllkal/kglpnal... Target PID: %d\n", $1);
    printf("Hit Ctrl-C to stop.\n\n");
}

uprobe:/u01/app/oracle/product/21.0.0/dbhome_1/bin/oracle:kgllkal
/ $1 == 0 || pid == $1 /
{
    @lk++;
    printf("[%s] kgllkal #%02d pid=%d handle=%016lx mode=%d obj=%s\n",
        strftime("%H:%M:%S", nsecs),
        @lk, pid, arg2, arg3,
        str(arg2 + 0x1c8, 256));
}

uprobe:/u01/app/oracle/product/21.0.0/dbhome_1/bin/oracle:kglpnal
/ $1 == 0 || pid == $1 /
{
    @pn++;
    printf("[%s] kglpnal #%02d pid=%d handle=%016lx mode=%d obj=%s\n",
        strftime("%H:%M:%S", nsecs),
        @pn, pid, arg2, arg3,
        str(arg2 + 0x1c8, 256));
}

END
{
    printf("\nTotal kgllkal: %d, Total kglpnal: %d\n", @lk, @pn);
    delete(@lk);
    delete(@pn);
}

3.测试:
--//测试前先执行类似语句多次,select * from emp@centtest where empno=7369;避免出现大量递归sql语句.

SCOTT@book01p> @ spid
==============================
SID                           : 29
SERIAL#                       : 58292
PROCESS                       : 3095
SERVER                        : DEDICATED
SPID                          : 3097
PID                           : 8
P_SERIAL#                     : 7
KILL_COMMAND                  : alter system kill session '29,58292' immediate;
PL/SQL procedure successfully completed.

--//Select * from emp@centtest where empno=7369; 4次.

--//window 1:
# bpftrace /home/oracle/sqllaji/bt/lkpn21x.bt 3097
Attached 4 probes
Tracing Oracle kgllkal/kglpnal... Target PID: 3097
Hit Ctrl-C to stop.
--//第1次
[10:48:37] kgllkal #01 pid=3097 handle=00000000709d5398 mode=1 obj=Select * from emp@centtest where empno=7369
[10:48:37] kglpnal #01 pid=3097 handle=00000000709d5398 mode=2 obj=Select * from emp@centtest where empno=7369
[10:48:37] kgllkal #02 pid=3097 handle=000000007279f060 mode=2 obj=bookSYSCDB$ROOT
[10:48:37] kgllkal #03 pid=3097 handle=000000006f1c6c38 mode=2 obj=1847639831SYSCDB$ROOT
[10:48:37] kgllkal #04 pid=3097 handle=0000000070a53db8 mode=2 obj=c175744146ba6be2f882e6701a42d2bb$BUILD$BOOK01P
[10:48:37] kgllkal #05 pid=3097 handle=00000000709d0748 mode=1 obj=
[10:48:37] kglpnal #02 pid=3097 handle=00000000709d0748 mode=3 obj=
[10:48:37] kgllkal #06 pid=3097 handle=000000007279f060 mode=2 obj=bookSYSCDB$ROOT
[10:48:37] kgllkal #07 pid=3097 handle=000000006f1c6c38 mode=2 obj=1847639831SYSCDB$ROOT
[10:48:37] kgllkal #08 pid=3097 handle=00000000709db328 mode=1 obj=c175744146ba6be2f882e6701a42d2bbChild:0BOOK01P
[10:48:37] kglpnal #03 pid=3097 handle=00000000709db328 mode=3 obj=c175744146ba6be2f882e6701a42d2bbChild:0BOOK01P
[10:48:37] kgllkal #09 pid=3097 handle=0000000069a0a270 mode=1 obj=SCOTTBOOK01P
[10:48:37] kgllkal #10 pid=3097 handle=000000007279f060 mode=2 obj=bookSYSCDB$ROOT
[10:48:37] kgllkal #11 pid=3097 handle=000000006f1c6c38 mode=2 obj=1847639831SYSCDB$ROOT
[10:48:37] kgllkal #12 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:37] kgllkal #13 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:37] kgllkal #14 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:37] kgllkal #15 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:37] kgllkal #16 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:37] kgllkal #17 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:37] kgllkal #18 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:37] kgllkal #19 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:37] kgllkal #20 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:37] kgllkal #21 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:37] kgllkal #22 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:37] kgllkal #23 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:37] kgllkal #24 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:37] kgllkal #25 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:37] kgllkal #26 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:37] kgllkal #27 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST

--//第2次
[10:48:43] kgllkal #28 pid=3097 handle=00000000709d5398 mode=1 obj=Select * from emp@centtest where empno=7369
[10:48:43] kgllkal #29 pid=3097 handle=00000000709d0748 mode=1 obj=
[10:48:43] kgllkal #30 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:43] kgllkal #31 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:43] kgllkal #32 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:43] kgllkal #33 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:43] kgllkal #34 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:43] kgllkal #35 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:43] kgllkal #36 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:43] kgllkal #37 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST

--//第3次
[10:48:47] kgllkal #38 pid=3097 handle=00000000709d5398 mode=1 obj=Select * from emp@centtest where empno=7369
[10:48:47] kgllkal #39 pid=3097 handle=00000000709d0748 mode=1 obj=
[10:48:47] kgllkal #40 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:47] kgllkal #41 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:47] kgllkal #42 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:47] kgllkal #43 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:47] kgllkal #44 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:47] kgllkal #45 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:47] kgllkal #46 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:47] kgllkal #47 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST

--//第4次
[10:48:52] kgllkal #48 pid=3097 handle=00000000709d5398 mode=1 obj=Select * from emp@centtest where empno=7369
[10:48:52] kgllkal #49 pid=3097 handle=00000000709d0748 mode=1 obj=
[10:48:52] kgllkal #50 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:52] kgllkal #51 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:52] kgllkal #52 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:52] kgllkal #53 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:52] kgllkal #54 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:52] kgllkal #55 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:48:52] kgllkal #56 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:48:52] kgllkal #57 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
Total kgllkal: 57, Total kglpnal: 3

--//可以发现执行第4次后依旧存在使用library cache lock的情况.每个dblink对象访问4次,注意存在2个handle
--//00000000726c3ee0,00000000726f9ea0.
--//而且sql语句的父子句柄也存在1次library cache lock的访问(mode=1 易碎锁,主要检查该对象是否存在)，子光标obj显示为空，因
--//为信息保存在父游标的句柄里面。
--//顺便提一下如果sql语句仅仅存在访问dblink，不存在本地表。使用dbms_xplan.display_cursor查询执行计划会报错。

--//可以想象如果大量频繁地执行这类带dblink的语句,会在对应dblink对象上存在library cache lock的争用.
--//而且如果语句不使用绑定变量,即使执行语句不同并且都是带相同dblink,都会存在对带dblink对象的library cache lock的访问.

4.继续:
--//前面的测试sql语句没有本地表,加入本地表看看.
select * from emp@centtest a ,dept where empno=7369 and dept.deptno = a.deptno ;
--//执行以上sql语句多次。

# bpftrace /home/oracle/sqllaji/bt/lkpn21x.bt 3097
Attached 4 probes
Tracing Oracle kgllkal/kglpnal... Target PID: 3097
Hit Ctrl-C to stop.
--//第1次
[10:57:46] kgllkal #01 pid=3097 handle=000000006fc99e70 mode=1 obj=SElect * from emp@centtest a ,dept where empno=7369 and dept.deptno = a.deptno
[10:57:46] kglpnal #01 pid=3097 handle=000000006fc99e70 mode=2 obj=SElect * from emp@centtest a ,dept where empno=7369 and dept.deptno = a.deptno
[10:57:46] kgllkal #02 pid=3097 handle=000000007279f060 mode=2 obj=bookSYSCDB$ROOT
[10:57:46] kgllkal #03 pid=3097 handle=000000006f1c6c38 mode=2 obj=1847639831SYSCDB$ROOT
[10:57:46] kgllkal #04 pid=3097 handle=000000006fcccec0 mode=2 obj=efd6d593623e4725c4132dd0944e4756$BUILD$BOOK01P
[10:57:46] kgllkal #05 pid=3097 handle=000000006fcbbb90 mode=1 obj=
[10:57:46] kglpnal #02 pid=3097 handle=000000006fcbbb90 mode=3 obj=
[10:57:46] kgllkal #06 pid=3097 handle=000000007279f060 mode=2 obj=bookSYSCDB$ROOT
[10:57:46] kgllkal #07 pid=3097 handle=000000006f1c6c38 mode=2 obj=1847639831SYSCDB$ROOT
[10:57:46] kgllkal #08 pid=3097 handle=000000006fc93150 mode=1 obj=efd6d593623e4725c4132dd0944e4756Child:0BOOK01P
[10:57:46] kglpnal #03 pid=3097 handle=000000006fc93150 mode=3 obj=efd6d593623e4725c4132dd0944e4756Child:0BOOK01P
[10:57:46] kgllkal #09 pid=3097 handle=0000000069a0a270 mode=1 obj=SCOTTBOOK01P
[10:57:46] kgllkal #10 pid=3097 handle=000000007279f060 mode=2 obj=bookSYSCDB$ROOT
[10:57:46] kgllkal #11 pid=3097 handle=000000006f1c6c38 mode=2 obj=1847639831SYSCDB$ROOT
[10:57:46] kgllkal #12 pid=3097 handle=00000000709443d8 mode=2 obj=DEPTSCOTTBOOK01P.kr
[10:57:46] kglpnal #04 pid=3097 handle=00000000709443d8 mode=2 obj=DEPTSCOTTBOOK01P.kr
[10:57:46] kgllkal #13 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:46] kgllkal #14 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:57:46] kgllkal #15 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:46] kgllkal #16 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:57:46] kgllkal #17 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:46] kgllkal #18 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:57:46] kgllkal #19 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:46] kgllkal #20 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:57:46] kgllkal #21 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:46] kgllkal #22 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:57:46] kgllkal #23 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:46] kgllkal #24 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST

--//第2次
[10:57:53] kgllkal #25 pid=3097 handle=000000006fc99e70 mode=1 obj=SElect * from emp@centtest a ,dept where empno=7369 and dept.deptno = a.deptno
[10:57:53] kgllkal #26 pid=3097 handle=000000006fcbbb90 mode=1 obj=
[10:57:53] kgllkal #27 pid=3097 handle=00000000709443d8 mode=2 obj=DEPTSCOTTBOOK01P.kr
[10:57:53] kglpnal #05 pid=3097 handle=00000000709443d8 mode=2 obj=DEPTSCOTTBOOK01P.kr
[10:57:53] kgllkal #28 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:53] kgllkal #29 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:57:53] kgllkal #30 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:53] kgllkal #31 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:57:53] kgllkal #32 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:53] kgllkal #33 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST

--//第3次
[10:57:57] kgllkal #34 pid=3097 handle=000000006fc99e70 mode=1 obj=SElect * from emp@centtest a ,dept where empno=7369 and dept.deptno = a.deptno
[10:57:57] kgllkal #35 pid=3097 handle=000000006fcbbb90 mode=1 obj=
[10:57:57] kgllkal #36 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:57] kgllkal #37 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:57:57] kgllkal #38 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:57] kgllkal #39 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:57:57] kgllkal #40 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:57:57] kgllkal #41 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST

--//第4次
[10:58:01] kgllkal #42 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:58:01] kgllkal #43 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
[10:58:01] kgllkal #44 pid=3097 handle=00000000726c3ee0 mode=2 obj=CENTTESTm
[10:58:01] kgllkal #45 pid=3097 handle=00000000726f9ea0 mode=2 obj=CENTTEST
^C
Total kgllkal: 45, Total kglpnal: 5
--//可以发现执行第4次后依旧存在使用library cache lock的情况.只不过每个对象访问2次。

--//想象如果应该存在大量对dblink的访问，一定会在dblink对象上存在争用，可以执行的sql语句不同，而且如果语句使用大量文字变
--//量会更加加重这种情况的出现。另外写一篇测试说明该问题。