ITPub博客
首页 博客 专栏 学院 社区 IT新媒体评选
发博

首页 > 数据库 > Oracle > [20260707]验证跟踪library cache lock library cache pin使用bpftrace的脚本

[20260707]验证跟踪library cache lock library cache pin使用bpftrace的脚本

原创 Oracle 作者：lfree 时间：2026-07-09 21:01:33 0 删除 编辑

[20260707]验证跟踪library cache lock library cache pin使用bpftrace的脚本是否执行正确.txt

--//跟踪[library cache lock library cache pin使用bpftrace的脚本增加获得library cache lock address以及library cache pin
--//address，不知道是否正确，通过例子验证看看。

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.测试脚本：
create procedure lcp
is
begin
sys.dbms_lock.sleep(3600);
end;
/

3.测试：
--//session 1:
SCOTT@book01p( 119,35876,@1 spid=3228 )> exec lcp

--//session 2:
SCOTT@book01p( 218,25361,@1 spid=3299 )> alter procedure lcp compile;
--//挂起!!

--//session 3:
SCOTT@book01p( 207,39071,@1 spid=3446 )>

--//在执行前window 1执行：
# bpftrace /home/oracle/study/202606/lkpn21z.bt 3446
Attached 5 probes
Tracing Oracle kgllkal/kglpnal... Target PID: 3446
Hit Ctrl-C to stop.

--//session 3:
SCOTT@book01p( 207,39071,@1 spid=3446 )> alter procedure lcp compile;
--//挂起!!

--//这样会出现library cache pin ,library cache lock等待事件.
SYS@book> @ ashtop sid,BLOCKING_SESSION,event,p1raw,p2raw,p3raw 1=1 &30s
    Total                                                                                                                                                                Distinct Distinct    Distinct
  Seconds     AAS %This          SID BLOCKING_SESSION EVENT              P1RAW             P2RAW             P3RAW             FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1
--------- ------- ------- ---------- ---------------- ------------------ ----------------- ----------------- ----------------- ------------------- ------------------- ---------- -------- -----------
       30     1.0   45% |        207              218 library cache lock 0000000069A3BF40  0000000066FDF628  000129ED00010003  2026-07-07 15:19:15 2026-07-07 15:19:44          1       30           1
       30     1.0   45% |        218              119 library cache pin  0000000069A3BF40  000000006922B598  000129ED00010003  2026-07-07 15:19:15 2026-07-07 15:19:44          1       30           1
        4      .1    6% |          5                                                                                           2026-07-07 15:19:16 2026-07-07 15:19:44          1        4           4
        2      .1    3% |        216                                                                                           2026-07-07 15:19:31 2026-07-07 15:19:36          1        2           2

book> @ ev_namezpr '^library cache lock$'
==============================
EVENT#                        : 376
EVENT_ID                      : 916468430
NAME                          : library cache lock
PARAMETER1                    : handle address
PARAMETER2                    : lock address
PARAMETER3                    : 100*mode+namespace
WAIT_CLASS_ID                 : 3875070507
WAIT_CLASS#                   : 4
WAIT_CLASS                    : Concurrency
DISPLAY_NAME                  : library cache lock
CON_ID                        : 0
PL/SQL procedure successfully completed.

SYS@book> @ ev_namezpr '^library cache pin$'
==============================
EVENT#                        : 375
EVENT_ID                      : 2802704141
NAME                          : library cache pin
PARAMETER1                    : handle address
PARAMETER2                    : pin address
PARAMETER3                    : 100*mode+namespace
WAIT_CLASS_ID                 : 3875070507
WAIT_CLASS#                   : 4
WAIT_CLASS                    : Concurrency
DISPLAY_NAME                  : library cache pin
CON_ID                        : 0
PL/SQL procedure successfully completed.
--//P2 对应的就是 lock address 或者 pin address  地址。

--//sid=207 阻塞 sid=218,出现library cache lock等待事件,而sid=218阻塞sid=119 出现library cache pin等待事件.

--//session 1:
SCOTT@book01p( 119,35876,@1 spid=3228 )> exec lcp
BEGIN lcp; END;

*
ERROR at line 1:
ORA-01013: user requested cancel of current operation
ORA-06512: at "SYS.DBMS_LOCK", line 215
ORA-06512: at "SCOTT.LCP", line 4
ORA-06512: at line 1

--//window 1:
# bpftrace /home/oracle/study/202606/lkpn21z.bt 3446
Attached 5 probes
Tracing Oracle kgllkal/kglpnal... Target PID: 3446
Hit Ctrl-C to stop.

[15:15:51] kgllkal #01 pid=3446 handle=0000000066fc9b40 mode=1 obj=alter procedure lcp compile
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fe0908
[15:15:51] kgllkal #02 pid=3446 handle=0000000066a15f58 mode=1 obj=
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdf020
[15:15:51] kglpnal #01 pid=3446 handle=0000000066a15f58 mode=3 obj=
[15:15:51] kglGetSO   pid=3446 return PIN ADDRESS=0000000066fdf628
[15:15:51] kgllkal #03 pid=3446 handle=000000007288c250 mode=2 obj=bookSYSCDB$ROOT
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdec60
[15:15:51] kgllkal #04 pid=3446 handle=000000006ddc26b0 mode=2 obj=1847639831SYSCDB$ROOT
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdeb70
[15:15:51] kgllkal #05 pid=3446 handle=0000000066a14b28 mode=1 obj=e985fc239b919877f25909e8f398a456Child:1BOOK01P
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdea80
[15:15:51] kglpnal #02 pid=3446 handle=0000000066a14b28 mode=3 obj=e985fc239b919877f25909e8f398a456Child:1BOOK01P
[15:15:51] kglGetSO   pid=3446 return PIN ADDRESS=0000000066fde990
[15:15:51] kgllkal #06 pid=3446 handle=00000000694d0038 mode=1 obj=SCOTTBOOK01P
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdea80
[15:15:51] kgllkal #07 pid=3446 handle=000000007288c250 mode=2 obj=bookSYSCDB$ROOT
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdf628
[15:15:51] kgllkal #08 pid=3446 handle=000000006ddc26b0 mode=2 obj=1847639831SYSCDB$ROOT
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdec60
[15:15:51] kglpnal #03 pid=3446 handle=000000006b25c0b8 mode=2 obj=DATABASESYSBOOK01P
[15:15:51] kglGetSO   pid=3446 return PIN ADDRESS=0000000066fdf628
[15:15:51] kglpnal #04 pid=3446 handle=000000006b25c0b8 mode=2 obj=DATABASESYSBOOK01P
[15:15:51] kglGetSO   pid=3446 return PIN ADDRESS=0000000066fdf628
[15:15:51] kgllkal #09 pid=3446 handle=0000000069c06c40 mode=1 obj=LOGMNRGGC_TRIGGERSYSBOOK01P
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdec60
[15:15:51] kglpnal #05 pid=3446 handle=0000000069c06c40 mode=2 obj=LOGMNRGGC_TRIGGERSYSBOOK01P
[15:15:51] kglGetSO   pid=3446 return PIN ADDRESS=0000000066fdeb70
[15:15:51] kgllkal #10 pid=3446 handle=0000000069bb4d58 mode=1 obj=NO_VM_DDLWMSYSBOOK01P
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdec60
[15:15:51] kglpnal #06 pid=3446 handle=0000000069bb4d58 mode=2 obj=NO_VM_DDLWMSYSBOOK01P
[15:15:51] kglGetSO   pid=3446 return PIN ADDRESS=0000000066fdeb70
[15:15:51] kgllkal #11 pid=3446 handle=0000000066db3e68 mode=1 obj=LBAC$BEFORE_ALTERLBACSYSBOOK01P
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdec60
[15:15:51] kglpnal #07 pid=3446 handle=0000000066db3e68 mode=2 obj=LBAC$BEFORE_ALTERLBACSYSBOOK01P
[15:15:51] kglGetSO   pid=3446 return PIN ADDRESS=0000000066fdeb70
[15:15:51] kgllkal #12 pid=3446 handle=0000000069a3bf40 mode=1 obj=LCPSCOTTBOOK01P
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdf628
[15:15:51] kgllkal #13 pid=3446 handle=0000000069a3bf40 mode=3 obj=LCPSCOTTBOOK01P
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ --//对应对象lcp。
[15:15:51] kglGetSO  pid=3446 return LOCK ADDRESs=0000000066fdf628
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
.......
--//如果这时中断session 1 sid=119的执行,session 2 sid=218可以正常执行,接着session 3也可以正常执行.
--//注意看下划线
--//handle=0000000069a3bf40 mode=3 obj=LCPSCOTTBOOK01P 对应就是lcp存储过程。
--//LOCK ADDRESs=0000000066fdf628 与前面ashtop的输出library cache lock那行的P2raw对应。

4.继续：
--//session 1:
SCOTT@book01p( 119,35876,@1 spid=3228 )> exec lcp

--//session 2:
SCOTT@book01p( 218,25361,@1 spid=3299 )>

--//在执行前window 1执行：
# bpftrace /home/oracle/study/202606/lkpn21z.bt 3299
Attached 5 probes
Tracing Oracle kgllkal/kglpnal... Target PID: 3299
Hit Ctrl-C to stop.

SCOTT@book01p( 218,25361,@1 spid=3299 )> alter procedure lcp compile;
--//挂起!!

# bpftrace /home/oracle/study/202606/lkpn21z.bt 3299
Attached 5 probes
Tracing Oracle kgllkal/kglpnal... Target PID: 3299
Hit Ctrl-C to stop.

[15:40:30] kgllkal #01 pid=3299 handle=0000000066fc9b40 mode=1 obj=alter procedure lcp compile
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000069239120
[15:40:30] kgllkal #02 pid=3299 handle=0000000066bfb488 mode=1 obj=
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=000000006922b8d0
[15:40:30] kglpnal #01 pid=3299 handle=0000000066bfb488 mode=3 obj=
[15:40:30] kglGetSO   pid=3299 return PIN ADDRESS=0000000066fd0358
[15:40:30] kgllkal #03 pid=3299 handle=000000007288c250 mode=2 obj=bookSYSCDB$ROOT
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000066fd0110
[15:40:30] kgllkal #04 pid=3299 handle=000000006ddc26b0 mode=2 obj=1847639831SYSCDB$ROOT
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000069239030
[15:40:30] kgllkal #05 pid=3299 handle=0000000066db4398 mode=1 obj=e985fc239b919877f25909e8f398a456Child:0BOOK01P
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000061ec6b30
[15:40:30] kglpnal #02 pid=3299 handle=0000000066db4398 mode=3 obj=e985fc239b919877f25909e8f398a456Child:0BOOK01P
[15:40:30] kglGetSO   pid=3299 return PIN ADDRESS=0000000061f5d290
[15:40:30] kgllkal #06 pid=3299 handle=00000000694d0038 mode=1 obj=SCOTTBOOK01P
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000061ec6b30
[15:40:30] kgllkal #07 pid=3299 handle=000000007288c250 mode=2 obj=bookSYSCDB$ROOT
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000066fd0358
[15:40:30] kgllkal #08 pid=3299 handle=000000006ddc26b0 mode=2 obj=1847639831SYSCDB$ROOT
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000066fd0110
[15:40:30] kglpnal #03 pid=3299 handle=000000006b25c0b8 mode=2 obj=DATABASESYSBOOK01P
[15:40:30] kglGetSO   pid=3299 return PIN ADDRESS=0000000066fd0358
[15:40:30] kglpnal #04 pid=3299 handle=000000006b25c0b8 mode=2 obj=DATABASESYSBOOK01P
[15:40:30] kglGetSO   pid=3299 return PIN ADDRESS=0000000066fd0358
[15:40:30] kgllkal #09 pid=3299 handle=0000000069c06c40 mode=1 obj=LOGMNRGGC_TRIGGERSYSBOOK01P
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000066fd0110
[15:40:30] kglpnal #05 pid=3299 handle=0000000069c06c40 mode=2 obj=LOGMNRGGC_TRIGGERSYSBOOK01P
[15:40:30] kglGetSO   pid=3299 return PIN ADDRESS=0000000061d39150
[15:40:30] kgllkal #10 pid=3299 handle=0000000069bb4d58 mode=1 obj=NO_VM_DDLWMSYSBOOK01P
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000066fd0110
[15:40:30] kglpnal #06 pid=3299 handle=0000000069bb4d58 mode=2 obj=NO_VM_DDLWMSYSBOOK01P
[15:40:30] kglGetSO   pid=3299 return PIN ADDRESS=0000000061d39150
[15:40:30] kgllkal #11 pid=3299 handle=0000000066db3e68 mode=1 obj=LBAC$BEFORE_ALTERLBACSYSBOOK01P
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000066fd0110
[15:40:30] kglpnal #07 pid=3299 handle=0000000066db3e68 mode=2 obj=LBAC$BEFORE_ALTERLBACSYSBOOK01P
[15:40:30] kglGetSO   pid=3299 return PIN ADDRESS=0000000061d39150
[15:40:30] kgllkal #12 pid=3299 handle=0000000069ae70e0 mode=1 obj=select count(*)                                      from user$ u                                         where bitand(u.spare1, 256) = 256                      and u.type#               = 1                        and u.name                = :1
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000066fd0358
[15:40:30] kgllkal #13 pid=3299 handle=00000000699d92a0 mode=1 obj=
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000066fd0110
[15:40:30] kgllkal #14 pid=3299 handle=0000000069a3bf40 mode=1 obj=LCPSCOTTBOOK01P
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000061d39150
[15:40:30] kgllkal #15 pid=3299 handle=0000000069a3bf40 mode=3 obj=LCPSCOTTBOOK01P
[15:40:30] kglGetSO  pid=3299 return LOCK ADDRESs=0000000061d39150
[15:40:30] kglpnal #08 pid=3299 handle=0000000069a3bf40 mode=3 obj=LCPSCOTTBOOK01P
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
[15:40:30] kglGetSO   pid=3299 return PIN ADDRESS=0000000061d39060
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

SYS@book> @ ashtop sid,BLOCKING_SESSION,event,p1raw,p2raw,p3raw 1=1 &30s
    Total                                                                                                                                                               Distinct Distinct    Distinct
  Seconds     AAS %This          SID BLOCKING_SESSION EVENT             P1RAW             P2RAW             P3RAW             FIRST_SEEN          LAST_SEEN           Execs Seen  Tstamps Execs Seen1
--------- ------- ------- ---------- ---------------- ----------------- ----------------- ----------------- ----------------- ------------------- ------------------- ---------- -------- -----------
       30     1.0   97% |        218              119 library cache pin 0000000069A3BF40  0000000061D39060  000129ED00010003  2026-07-07 15:40:47 2026-07-07 15:41:16          1       30           1
        1      .0    3% |        103                                                                                          2026-07-07 15:41:15 2026-07-07 15:41:15          1        1           1

--//注意看下划线,相关信息完成对上。

5.附上相关源代码：

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

//uprobe:oracle:kgllkal
uprobe:/u01/app/oracle/product/21.0.0/dbhome_1/bin/oracle:kgllkal
/ $1 == 0 || pid == $1 /
{
    @lk++;
    @is_lock[pid] = 1;
    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++;
    @is_pin[pid] = 1;
    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));
}

uretprobe:/u01/app/oracle/product/21.0.0/dbhome_1/bin/oracle:kglGetSO
/ $1 == 0 || pid == $1 /
{
    if (@is_lock[pid] == 1) {
        printf("[%s] kglGetSO  pid=%d return LOCK ADDRESs=%016lx\n",
            strftime("%H:%M:%S", nsecs), pid, retval);
        delete(@is_lock[pid]);
    }
    if (@is_pin[pid] == 1) {
        printf("[%s] kglGetSO   pid=%d return PIN ADDRESS=%016lx\n",
            strftime("%H:%M:%S", nsecs), pid, retval);
        delete(@is_pin[pid]);
    }
}

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

来自 “ ITPUB博客 ” ，链接：https://blog.itpub.net/267265/viewspace-3175592/ ，如需转载，请注明出处，否则将追究法律责任。

0
0
上一篇： [20260703]完善跟踪library cache lock library cache pin使用bpftrace.txt
下一篇： [20260708]vim字符集以及寄存器问题.txt
请登录后发表评论 登录
全部评论
lfree
专家姓名：张文胜
熟悉oracle相关技术，擅长sql优化，rman备份与恢复，熟悉linux shell编程。

注册时间：2008-01-03

  • 博文量
    4006
  • 访问量
    7969285

最新文章

支持我们 作者招募 用户协议 FAQ Contact Us

北京盛拓优讯信息技术有限公司. 版权所有  京ICP备16024965号-8 北京市公安局海淀分局网监中心备案编号：11010802021510 niuxiaotong@pcpop.com 17352615567 未成年人举报专区

广播电视节目制作经营许可证(京) 字第1234号 中国互联网协会会员

违法和不良信息举报电话:18101376593