[20240920]跟踪library cache lock library cache pin使用gdb.txt
–//前一阵子，写的使用gdb跟踪library cache lock library cache pin的脚本有一个小问题，无法获得lock address以及pin address
–//地址,有一点点小缺陷，尝试修改完善看看。
–//按照https://nenadnoveljic.com/blog/tracing-library-cache-locks/介绍：
In order to close this gap I, first, examined the following two Oracle C functions on the release 19.6.0.0.200114:
kgllkal and kglGetSO.
kgllkal allocates a library cache lock. It receives the following arguments:
rdx: handle address
rcx: lock mode
Further, it calls kglGetSO to allocate the library cache state object. kglGetSO returns the lock address.
–//按照介绍调用kglGetSO返回lock address.我猜测 library cache pind的pin地址也是类似的情况。
$ ./lookup.awk kglGetSO
kglGetSO : kernel generic library cache management get state object
–//如何使用gdb实现，自己尝试看看。
–//仔细看链接https://nenadnoveljic.com/blog/tracing-library-cache-locks/
pid$target:oracle:kglGetSO:return
/ self->kglGetSO /
{
printf(“\n”);
printf(“KGLLKHDL KGLLKMOD KGLLKADR\n”);
printf(“——– ——– ——–\n”);
printf(“%X %8d %X\n” , self->kgllkhdl, self->kgllkmod, arg1 );
printf(“\n”);
printf(“==========================\n”);
printf(“\n”);
self->kglGetSO = 0;
}
–//dtrace可以设置在kglGetSO return获取arg1就是KGLLKADR，gdb如何实现呢？想起测试学习使用的方法，建立一个过程lcp加入sleep 3600，
–//先执行它，然后打开另外一个会话编译它，就会出现library cache pin，再打开另外的会话编译它，就会出现library cache lock，使用它
–//测试看看。
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.
SYS@book> @ sed “library cache pin”
SYS@book> @ pr
==============================
SED_EVENT# : 375
SED_NAME : library cache pin
SED_WAIT_CLASS : Concurrency
SED_P1 : handle address
SED_P2 : pin address
SED_P3 : 100*mode+namespace
SED_EQ_NAME :
SED_REQ_REASON :
SED_REQ_DESCRIPTION :
PL/SQL procedure successfully completed.
–//library cache lock类似
–//grant execute on sys.dbms_lock to scott;
create procedure lcp
is
begin
sys.dbms_lock.sleep(3600);
end;
/
2.测试1：
–//session 1:
SCOTT@book01p(412,5770)> exec lcp
–//session 2:
SCOTT@book01p(148,4168)> set timing on
SCOTT@book01p(148,4168)> alter procedure lcp compile;
–//挂起!!
SYS@book> @ ashtop event,p1hex,p2hex,p2,p3hex 1=1 &10s
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1HEX P2HEX P2 P3HEX FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
——— ——- ——- —————————————— —————– —————– ———- —————– ——————- ——————- ———- ——– ———–
10 1.0 83% | library cache pin 00000000635F4DA0 000000006C0DCDD8 1812843992 00012A0300010003 2024-09-20 16:59:23 2024-09-20 16:59:32 1 10 1
2 .2 17% | 0 2024-09-20 16:59:23 2024-09-20 16:59:31 1 2 2
–//出现library cache pin等待事件，P1hex=00000000635F4DA0就是对象句柄。
$ source ext_kglobj.sh 00000000635F4DA0
(gdb) 0x635f4f68: “LCPSCOTTBOOK01P”
(gdb) quit
–//使用我前面写的抽取对象脚本ext_kglobj.sh，可以发现就是对象lcp。中断上面的执行。
3.编写脚本如下：
$ cat lkpn.gdb2
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 kglpnal if $rcx==3
break kglpnal if ($rcx=3 && $rdx=0x00000000635F4DA0)
commands
silent
printf “kglpnal count %02d — handle address: %016x, mode: %d “, ++$pn ,$rdx ,$rcx
echo kglnaobj address:
x/s $rdx+0x1c8
c
end
break kglGetSO
commands
silent
finish
end
–//注：设置断点在句柄$rdx=0x00000000635F4DA0，kglGetSO执行最后是finish，这样停止在该函数kglGetSO的返回。
4.继续测试：
–//session 2:
SCOTT@book01p(148,4168)> @ spid
SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50
———- ———- ———————— ——— —————————— ——- ———- ————————————————–
148 4168 5283 DEDICATED 5285 69 14 alter system kill session ‘148,4168’ immediate;
–//获得session 2的spid=5285。
–//window 1：
$ rlgdb -f -p 5285 -x lkpn.gdb2
…
/usr/src/debug/glibc-2.17-c758a686/sysdeps/unix/syscall-template.S:81:3374:beg:0x7f35cf359480
Breakpoint 1 at 0x1536c020
Breakpoint 2 at 0x1536f9c0
–//重复前面的测试：
–//window 1,不停按c继续，直到出现：
(gdb) c
Continuing.
0x0000000015367fbe in kgllkal ()
(gdb) c
Continuing.
0x0000000015367fbe in kgllkal ()
(gdb) c
Continuing.
0x000000001536c16a in kglpnal ()
(gdb) c
….
(gdb) c
Continuing.
kglpnal count 01 — handle address: 00000000635f4da0, mode: 3 kglnaobj address:0x635f4f68: “LCPSCOTTBOOK01P”
0x000000001536c16a in kglpnal ()
–//session 3:
SYS@book> @ ashtop event,p1hex,p2hex,p2,p3hex 1=1 &10s
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1HEX P2HEX P2 P3HEX FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
——— ——- ——- —————————————— —————– —————– ———- —————– ——————- ——————- ———- ——– ———–
10 1.0 77% | 1 2024-09-20 18:00:02 2024-09-20 18:00:11 1 10 1
3 .3 23% | 0 2024-09-20 18:00:03 2024-09-20 18:00:08 1 2 2
–//没有获得相应等待事件。
–//window 1:
(gdb) c
Continuing.
kglpnal count 01 — handle address: 00000000635f4da0, mode: 3 kglnaobj address:0x635f4f68: “LCPSCOTTBOOK01P”
0x000000001536c16a in kglpnal ()
–//现在停在函数kglGetSO的返回处。记住停止在地址：0x000000001536c16a
(gdb) info regi
rax 0x6c09abb8 1812573112
rbx 0x0 0
rcx 0x71fa9128 1912246568
rdx 0x6c09abb8 1812573112
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
rsi 0x71fbca40 1912326720
rdi 0x3 3
rbp 0x7ffd091a1540 0x7ffd091a1540
rsp 0x7ffd091a1120 0x7ffd091a1120
r8 0x7f35d2e33570 139869148099952
r9 0x6fb37c20 1874033696
r10 0x76c84268 1992835688
r11 0x3 3
r12 0x6c297cc8 1814658248
r13 0x7f35d2dee060 139869147816032
r14 0x635f4da0 1667190176
r15 0x3 3
rip 0x1536c16a 0x1536c16a <kglpnal+330>
eflags 0x246 [ PF ZF IF ]
cs 0x33 51
ss 0x2b 43
ds 0x0 0
es 0x0 0
fs 0x0 0
gs 0x0 0
(gdb) c
Continuing.
Program received signal SIGUSR2, User defined signal 2.
0x00007f35cee68fca in semtimedop () at ../sysdeps/unix/syscall-template.S:81
/usr/src/debug/glibc-2.17-c758a686/sysdeps/unix/syscall-template.S:81:3374:beg:0x7f35cee68fca
–//session 3:
SYS@book> @ ashtop event,p1hex,p2hex,p2,p3hex 1=1 &10s
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1HEX P2HEX P2 P3HEX FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
——— ——- ——- —————————————— —————– —————– ———- —————– ——————- ——————- ———- ——– ———–
9 .9 64% | 1 2024-09-20 18:02:13 2024-09-20 18:02:22 2 9 2
2 .2 14% | library cache pin 00000000635F4DA0 000000006C09ABB8 1812573112 00012A0300010003 2024-09-20 18:02:21 2024-09-20 18:02:22 1 2 1
2 .2 14% | 0 2024-09-20 18:02:14 2024-09-20 18:02:17 1 2 2
–//P2hex=000000006C09ABB8,正好是前面rdx=0x6c09abb8对上，实际上这个就是pin address地址。
–//p3hex=00012A0300010003,100*mode+namespace,这里稍微有点不同，前面8位，00012A03 = 76291对应lcp的object_id.
–//mode=0003，namespace=0001。
SCOTT@book01p> @ o2 lcp
owner object_name object_type SEG_PART_NAME status OID D_OID CREATED LAST_DDL_TIME
—– ———– ———– ————- ——— —– —– ——————- ——————-
SCOTT LCP PROCEDURE VALID 76291 2024-08-18 11:51:35 2024-09-21 12:07:05
SYS@book> @nmsp procedure -1
@ nmsp table -1
@ nmsp ” 74 or @ nmsp ” 0x4a|x4a
KGLSTDSC KGLSTIDN KGLSTIDN_HEX
————— ——– ————
TABLE/PROCEDURE 1 1
–//有了前面的信息，改写脚本如下：
$ cat lkpn.gdb2
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 $rcx==3
#break kgllkal if ( $rcx==3 && $rdx==0x00000000670C9E58 )
#break kgllkal if $rdx==0x00000000670C9E58
break kgllkal
condition 1
commands
silent
printf “kgllkal count %02d — handle address: %016x, mode: %d “, ++$lk ,$rdx ,$rcx
echo kglnaobj address:
x/s $rdx+0x1c8
c
end
#break kglpnal if $rcx==3
#break kglpnal if $rdx==0x00000000635F4DA0
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 kglGetSO
#commands
# silent
# finish
#end
break *0x0000000015367fbe
commands
silent
printf “kglGetS0 return lock address : %016x\n”, $rdx
c
end
break *0x1536c16a
commands
silent
printf “kglGetS0 return pin address : %016x\n”, $rdx
c
end
–//注：调用kgllkal在调用kglGetS0的返回停止在0x15367fbe地址时，对应寄存器rdx的就是lock地址(猜测)。
4.继续测试，验证lock address是否正确。
–//session 3,再打开新的会话：
SCOTT@book01p(272,12390)> @spid
SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50
———- ———- ———————— ——— —————————— ——- ———- ————————————————–
272 12390 6427 DEDICATED 6429 70 20 alter system kill session ‘272,12390’ immediate;
–//window 1：
$ rlgdb -f -p 6429 -x lkpn.gdb2
…
/usr/src/debug/glibc-2.17-c758a686/sysdeps/unix/syscall-template.S:81:3374:beg:0x7f931703e480
Breakpoint 1 at 0x15367e90
Breakpoint 2 at 0x1536c020
Breakpoint 3 at 0x15367fbe
Breakpoint 4 at 0x1536c16a
(gdb) c
–//重复前面的测试，只不过这次是3个会话。
–//session 1:
SCOTT@book01p(412,5770)> exec lcp
–//session 2:
SCOTT@book01p(148,4168)> set timing on
SCOTT@book01p(148,4168)> alter procedure lcp compile;
–//挂起!!
–//session 4:
SCOTT@book01p(272,12390)> set timing on
SCOTT@book01p(272,12390)> alter procedure lcp compile;
–//挂起!!
–//window 1：
(gdb) c
Continuing.
kgllkal count 01 — handle address: 0000000063cb7b20, mode: 1 kglnaobj address:0x63cb7ce8: “alter procedure lcp compile”
kglGetS0 lock address : 0000000063634090
kgllkal count 02 — handle address: 000000006134f840, mode: 1 kglnaobj address:0x6134fa08: “”
kglGetS0 lock address : 00000000610c6b90
kglpnal count 01 — handle address: 000000006134f840, mode: 3 kglnaobj address:0x6134fa08: “”
kglGetS0 pin address : 00000000610c6d70
kgllkal count 03 — handle address: 00000000702d5908, mode: 2 kglnaobj address:0x702d5ad0: “bookSYSCDB$ROOT”
kglGetS0 lock address : 00000000610c6c80
kgllkal count 04 — handle address: 000000006b97c9f8, mode: 2 kglnaobj address:0x6b97cbc0: “1073777561SYSCDB$ROOT”
kglGetS0 lock address : 0000000063633eb0
kgllkal count 05 — handle address: 0000000069c6b610, mode: 1 kglnaobj address:0x69c6b7d8: “e985fc239b919877f25909e8f398a456Child:2BOOK01P”
kglGetS0 lock address : 0000000063633dc0
kglpnal count 02 — handle address: 0000000069c6b610, mode: 3 kglnaobj address:0x69c6b7d8: “e985fc239b919877f25909e8f398a456Child:2BOOK01P”
kglGetS0 pin address : 00000000610c6aa0
kgllkal count 06 — handle address: 0000000060d45130, mode: 1 kglnaobj address:0x60d452f8: “SCOTTBOOK01P”
kglGetS0 lock address : 0000000063633dc0
kgllkal count 07 — handle address: 00000000702d5908, mode: 2 kglnaobj address:0x702d5ad0: “bookSYSCDB$ROOT”
kglGetS0 lock address : 00000000610c6d70
kgllkal count 08 — handle address: 000000006b97c9f8, mode: 2 kglnaobj address:0x6b97cbc0: “1073777561SYSCDB$ROOT”
kglGetS0 lock address : 00000000610c6c80
kglpnal count 03 — handle address: 00000000697c1220, mode: 2 kglnaobj address:0x697c13e8: “DATABASESYSBOOK01P”
kglGetS0 pin address : 00000000610c6d70
kglpnal count 04 — handle address: 00000000697c1220, mode: 2 kglnaobj address:0x697c13e8: “DATABASESYSBOOK01P”
kglGetS0 pin address : 00000000610c6d70
kgllkal count 09 — handle address: 0000000067570378, mode: 1 kglnaobj address:0x67570540: “LOGMNRGGC_TRIGGERSYSBOOK01P”
kglGetS0 lock address : 00000000610c6c80
kglpnal count 05 — handle address: 0000000067570378, mode: 2 kglnaobj address:0x67570540: “LOGMNRGGC_TRIGGERSYSBOOK01P”
kglGetS0 pin address : 0000000063633eb0
kgllkal count 10 — handle address: 00000000674b5f50, mode: 1 kglnaobj address:0x674b6118: “NO_VM_DDLWMSYSBOOK01P”
kglGetS0 lock address : 00000000610c6c80
kglpnal count 06 — handle address: 00000000674b5f50, mode: 2 kglnaobj address:0x674b6118: “NO_VM_DDLWMSYSBOOK01P”
kglGetS0 pin address : 0000000063633eb0
kgllkal count 11 — handle address: 0000000066fe8790, mode: 1 kglnaobj address:0x66fe8958: “LBAC$BEFORE_ALTERLBACSYSBOOK01P”
kglGetS0 lock address : 00000000610c6c80
kglpnal count 07 — handle address: 0000000066fe8790, mode: 2 kglnaobj address:0x66fe8958: “LBAC$BEFORE_ALTERLBACSYSBOOK01P”
kglGetS0 pin address : 0000000063633eb0
kgllkal count 12 — handle address: 00000000635f4da0, mode: 1 kglnaobj address:0x635f4f68: “LCPSCOTTBOOK01P”
kglGetS0 lock address : 00000000610c6d70
kgllkal count 13 — handle address: 00000000635f4da0, mode: 3 kglnaobj address:0x635f4f68: “LCPSCOTTBOOK01P”
kglGetS0 lock address : 00000000610c6d70
–//对象LCPSCOTTBOOK01P ，session 4先调用kgllkal mode=1，因为session 2出现library cache pin的mode=3，无法获取，出现
–//library cache lock等待事件，mode=3.
Program received signal SIGUSR2, User defined signal 2.
0x00007f9316b4dfca in semtimedop () at ../sysdeps/unix/syscall-template.S:81
/usr/src/debug/glibc-2.17-c758a686/sysdeps/unix/syscall-template.S:81:3374:beg:0x7f9316b4dfca
–//进入休眠，每3秒探测1次。
SYS@book> @ ashtop event,p1hex,p2hex,p2,p3hex 1=1 &10s
Total Distinct Distinct Distinct
Seconds AAS %This EVENT P1HEX P2HEX P2 P3HEX FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
——— ——- ——- —————————————— —————– —————– ———- —————– ——————- ——————- ———- ——– ———–
10 1.0 48% | library cache lock 00000000635F4DA0 00000000610C6D70 1628204400 00012A0300010003 2024-09-20 18:22:19 2024-09-20 18:22:28 1 10 1
10 1.0 48% | library cache pin 00000000635F4DA0 000000006198F7B0 1637414832 00012A0300010003 2024-09-20 18:22:19 2024-09-20 18:22:28 1 10 1
1 .1 5% | 0 2024-09-20 18:22:20 2024-09-20 18:22:20 1 1 1
–//可以发现等待事件library cache lock的P2的信息完全可以对上。
5.简单小结：
–//通过调用kglGetSO的返回获得library cache lock/library cache pin的lock pin address。
–//gdb不知道如何写在kglGetSO的返回处获得相应地址，只能使用硬代码获得相应寄存器信息，那位知道gdb如何写。
如有侵犯您的版权，请及时联系3500663466#qq.com(#换@)，我们将第一时间删除本站数据。
暂无评论内容