IT评测·应用市场-qidao123.com技术社区

标题: [20240920]跟踪library cache lock library cache pin使用gdb.txt [打印本页]

---

作者: 三尺非寒    时间: 2024-9-22 21:14
标题: [20240920]跟踪library cache lock library cache pin使用gdb.txt
[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$targetracle: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
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如何写。
免责声明：如果侵犯了您的权益，请联系站长，我们会及时删除侵权内容，谢谢合作！更多信息从访问主页：qidao123.com:ToB企服之家，中国第一个企服评测及商务社交产业平台。

---

欢迎光临 IT评测·应用市场-qidao123.com技术社区 (https://dis.qidao123.com/)

Powered by Discuz! X3.4