[20210207]使用gdb查看等待事件11g.txt

来源:这里教程网 时间:2026-03-03 16:26:51 作者:

[20210207]使用gdb查看等待事件11g.txt https://nenadnoveljic.com/blog/wait-events-dtrace/ Before jumping to the DTrace script, I'd like summarize (and partially paraphrase) the most relevant information in Stefan's article. 1. Oracle function kslwtbctx represents the start of a wait event. 2. Oracle function kslwtbctx calls the function kskthbwt to get/store the corresponding wait event (number). 3. Oracle function kslwtectx represents the end of a wait event. 4. The Solaris kernel function get_cur_hrtime returns the current time in nanoseconds relative to some arbitrary point    in the past. 5. The Solaris kernel function get_cur_hrtime gets called before and after the wait event. Subsequently, the difference --//无聊看了一下dtrace,我也没有soalris,好奇使用gdb写一个测试看看,我不知道如何使用时间戳,使用shell调用,这样误差很大. --//抛砖引玉,那位有更好的方法. 1.环境: SCOTT@book> @ ver1 PORT_STRING                    VERSION        BANNER ------------------------------ -------------- -------------------------------------------------------------------------------- x86_64/Linux 2.4.xx            11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production 2.建立gdb脚本: $ cat wait.gdb break kslwtbctx set pagination off   commands     silent     shell echo -n $( date +"%Y/%m/%d %T.%N : ")     printf "kslwtbctx %d\n", *($rdi+104)     continue   end break kslwtectx set pagination off   commands     silent     shell echo -n $( date +"%Y/%m/%d %T.%N : ")     printf "kslwtectx %d\n", *($rdi+104)     continue   end 3.测试: --//session 1: SCOTT@book> @ spid        SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50 ---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------         44      17325 16254                    DEDICATED 16255       27         31 alter system kill session '44,17325' immediate; SCOTT@book> select rowid,dept.* from dept; ROWID                  DEPTNO DNAME          LOC ------------------ ---------- -------------- ------------- AAAVRCAAEAAAACHAAA         10 ACCOUNTING     NEW YORK AAAVRCAAEAAAACHAAB         20 RESEARCH       DALLAS AAAVRCAAEAAAACHAAC         30 SALES          CHICAGO AAAVRCAAEAAAACHAAD         40 OPERATIONS     BOSTON SCOTT@book> @ rowid AAAVRCAAEAAAACHAAA     OBJECT       FILE      BLOCK        ROW ROWID_DBA            DBA                  TEXT ---------- ---------- ---------- ---------- -------------------- -------------------- ----------------------------------------      87106          4        135          0  0x1000087           4,135                alter system dump datafile 4 block 135 ; --//session 2: $ gdb -p 16255 -x ~/sqllaji/gdb/wait.gdb --//session 1: SCOTT@book> select * from dept where rowid='AAAVRCAAEAAAACHAAA'; --//session 2: (gdb) c Continuing. 2021/02/07 16:47:23.548676089 :kslwtectx 354 2021/02/07 16:47:23.554744212 :kslwtbctx 350 2021/02/07 16:47:23.560578464 :kslwtectx 350 2021/02/07 16:47:23.566160107 :kslwtbctx 354 2021/02/07 16:47:23.571898349 :kslwtectx 354 2021/02/07 16:47:23.577223148 :kslwtbctx 350 2021/02/07 16:47:23.582679122 :kslwtectx 350 2021/02/07 16:47:23.588008331 :kslwtbctx 354 --//session 3: SYS@book> select * from v$event_name where event# in (354,350);     EVENT#   EVENT_ID NAME                                     PARAMETER1           PARAMETER2           PARAMETER3           WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS ---------- ---------- ---------------------------------------- -------------------- -------------------- -------------------- ------------- ----------- --------------------        350 2067390145 SQL*Net message to client                driver id            #bytes                                       2000153315           7 Network        354 1421975091 SQL*Net message from client              driver id            #bytes                                       2723168908           6 Idle --//可以发现第1个等待事件SQL*Net message from client是它的结束,就是等待输入SQL语句执行. SYS@book> alter system flush buffer_cache; System altered. --//session 1: SCOTT@book> select * from dept where rowid='AAAVRCAAEAAAACHAAA';     DEPTNO DNAME          LOC ---------- -------------- -------------         10 ACCOUNTING     NEW YORK --//session 2: 2021/02/07 16:51:09.465856590 :kslwtectx 354 2021/02/07 16:51:09.471628314 :kslwtbctx 350 2021/02/07 16:51:09.476914617 :kslwtectx 350 2021/02/07 16:51:09.482343684 :kslwtbctx 147 2021/02/07 16:51:09.487629492 :kslwtectx 147 2021/02/07 16:51:09.493093759 :kslwtbctx 354 2021/02/07 16:51:09.498740145 :kslwtectx 354 2021/02/07 16:51:09.504203935 :kslwtbctx 350 2021/02/07 16:51:09.509550913 :kslwtectx 350 2021/02/07 16:51:09.514826023 :kslwtbctx 354 SYS@book> select * from v$event_name where event# in (354,350,147);     EVENT#   EVENT_ID NAME                                     PARAMETER1           PARAMETER2           PARAMETER3           WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS ---------- ---------- ---------------------------------------- -------------------- -------------------- -------------------- ------------- ----------- --------------------        147 2652584166 db file sequential read                  file#                block#               blocks                  1740759767           8 User I/O        350 2067390145 SQL*Net message to client                driver id            #bytes                                       2000153315           7 Network        354 1421975091 SQL*Net message from client              driver id            #bytes                                       2723168908           6 Idle --//再次重复: --//session 2: SYS@book> alter system flush buffer_cache; System altered. SYS@book> select * from v$session_event where sid=44;        SID EVENT                                    TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT   MAX_WAIT TIME_WAITED_MICRO   EVENT_ID WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS ---------- ---------------------------------------- ----------- -------------- ----------- ------------ ---------- ----------------- ---------- ------------- ----------- --------------------         44 Disk file operations I/O                           2              0         666        332.8        666           6655904  166678035    1740759767           8 User I/O         44 latch: cache buffers chains                        2              0        9134      4566.96       7166          91339244 2779959231    3875070507           4 Concurrency         44 db file sequential read                           89              0        6389        71.79       6387          63893115 2652584166    1740759767           8 User I/O         44 db file scattered read                             1              0           0            0          0                31  506183215    1740759767           8 User I/O         44 SQL*Net message to client                         97              0        6493        66.94       2781          64932466 2067390145    2000153315           7 Network         44 SQL*Net message from client                       96              0      439391      4576.99      56085        4393908646 1421975091    2723168908           6 Idle 6 rows selected. --//session 1: SCOTT@book> select * from dept where rowid='AAAVRCAAEAAAACHAAA';     DEPTNO DNAME          LOC ---------- -------------- -------------         10 ACCOUNTING     NEW YORK --//session 2: SYS@book> select * from v$session_event where sid=44;        SID EVENT                                    TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT   MAX_WAIT TIME_WAITED_MICRO   EVENT_ID WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS ---------- ---------------------------------------- ----------- -------------- ----------- ------------ ---------- ----------------- ---------- ------------- ----------- --------------------         44 Disk file operations I/O                           2              0         666        332.8        666           6655904  166678035    1740759767           8 User I/O         44 latch: cache buffers chains                        2              0        9134      4566.96       7166          91339244 2779959231    3875070507           4 Concurrency         44 db file sequential read                           90              0        6390           71       6387          63898432 2652584166    1740759767           8 User I/O         44 db file scattered read                             1              0           0            0          0                31  506183215    1740759767           8 User I/O         44 SQL*Net message to client                         99              0        6494         65.6       2781          64943292 2067390145    2000153315           7 Network         44 SQL*Net message from client                       98              0      451908      4611.31      56085        4519080888 1421975091    2723168908           6 Idle 6 rows selected. --//注意看TOTAL_WAITS计数,db file sequential read 增1, SQL*Net message to client, SQL*Net message from client计数增加2. 4.继续测试: --//人为产生cbc latch. --//session 2: SYS@book> @ bh 4 135    INST_ID HLADDR              DBARFIL     DBABLK      CLASS CLASS_TYPE         STATE             TCH CR_SCN_BAS CR_SCN_WRP CR_UBA_FIL CR_UBA_BLK CR_UBA_SEQ BA               LE_ADDR          OBJECT_NAME ---------- ---------------- ---------- ---------- ---------- ------------------ ---------- ---------- ---------- ---------- ---------- ---------- ---------- ---------------- ---------------- --------------------          1 0000000084D25320          4        135          1 data block         xcur                1          0          0          0          0          0 000000006CF8E000 00               DEPT SYS@book> oradebug setmypid Statement processed. SYS@book> oradebug peek 0x0000000084D25320 8 [084D25320, 084D25328) = 00000000 00000000 SYS@book> oradebug poke 0x0000000084D25320 8 0x2000000000000000 BEFORE: [084D25320, 084D25328) = 00000000 00000000 AFTER:  [084D25320, 084D25328) = 00000000 20000000 --//session 1: SCOTT@book> select * from dept where rowid='AAAVRCAAEAAAACHAAA'; --//session 1,取消cbc latch: SYS@book> oradebug poke 0x0000000084D25320 8 0x0000000000000000 BEFORE: [084D25320, 084D25328) = 00000000 20000000 AFTER:  [084D25320, 084D25328) = 00000000 00000000 --//session 2,gdb界面: 2021/02/07 16:58:17.429107633 :kslwtectx 354 2021/02/07 16:58:17.434651886 :kslwtbctx 350` 2021/02/07 16:58:17.439885967 :kslwtectx 350 2021/02/07 16:58:17.445169457 :kslwtbctx 88 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 2021/02/07 16:58:29.017377562 :kslwtectx 88 2021/02/07 16:58:29.022706668 :kslwtbctx 354 2021/02/07 16:58:29.028331485 :kslwtectx 354 2021/02/07 16:58:29.033839150 :kslwtbctx 350 2021/02/07 16:58:29.039043786 :kslwtectx 350 2021/02/07 16:58:29.044309059 :kslwtbctx 354 --//session 2: SYS@book> select * from v$event_name where event# in (354,350,147,88);     EVENT#   EVENT_ID NAME                                     PARAMETER1           PARAMETER2           PARAMETER3           WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS ---------- ---------- ---------------------------------------- -------------------- -------------------- -------------------- ------------- ----------- --------------------         88 2779959231 latch: cache buffers chains              address              number               tries                   3875070507           4 Concurrency        147 2652584166 db file sequential read                  file#                block#               blocks                  1740759767           8 User I/O        350 2067390145 SQL*Net message to client                driver id            #bytes                                       2000153315           7 Network        354 1421975091 SQL*Net message from client              driver id            #bytes                                       2723168908           6 Idle --//event# = 88,对应latch: cache buffers chains. --//v$session_event执行前后对比. SYS@book> select * from v$session_event where sid=44;        SID EVENT                                    TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT   MAX_WAIT TIME_WAITED_MICRO   EVENT_ID WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS ---------- ---------------------------------------- ----------- -------------- ----------- ------------ ---------- ----------------- ---------- ------------- ----------- --------------------         44 Disk file operations I/O                           2              0         666        332.8        666           6655904  166678035    1740759767           8 User I/O         44 latch: cache buffers chains                        4              0       13187      3296.72       7166         131868697 2779959231    3875070507           4 Concurrency         44 db file sequential read                           90              0        6390           71       6387          63898432 2652584166    1740759767           8 User I/O         44 db file scattered read                             1              0           0            0          0                31  506183215    1740759767           8 User I/O         44 SQL*Net message to client                        103              0        6496        63.07       2781          64964428 2067390145    2000153315           7 Network         44 SQL*Net message from client                      102              0      479279      4698.81      56085        4792789306 1421975091    2723168908           6 Idle 6 rows selected. SYS@book> select * from v$session_event where sid=44;        SID EVENT                                    TOTAL_WAITS TOTAL_TIMEOUTS TIME_WAITED AVERAGE_WAIT   MAX_WAIT TIME_WAITED_MICRO   EVENT_ID WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS ---------- ---------------------------------------- ----------- -------------- ----------- ------------ ---------- ----------------- ---------- ------------- ----------- --------------------         44 Disk file operations I/O                           2              0         666        332.8        666           6655904  166678035    1740759767           8 User I/O         44 latch: cache buffers chains                        5              0       14344      2868.82       7166         143441219 2779959231    3875070507           4 Concurrency         44 db file sequential read                           90              0        6390           71       6387          63898432 2652584166    1740759767           8 User I/O         44 db file scattered read                             1              0           0            0          0                31  506183215    1740759767           8 User I/O         44 SQL*Net message to client                        105              0        6498        61.88       2781          64975517 2067390145    2000153315           7 Network         44 SQL*Net message from client                      104              0      493138      4741.71      56085        4931378816 1421975091    2723168908           6 Idle 6 rows selected. --//做一个全表扫描: --//session 2: SYS@book> alter system flush buffer_cache; System altered. --//session 1: SCOTT@book> select rowid,dept.* from dept; ROWID                  DEPTNO DNAME          LOC ------------------ ---------- -------------- ------------- AAAVRCAAEAAAACHAAA         10 ACCOUNTING     NEW YORK AAAVRCAAEAAAACHAAB         20 RESEARCH       DALLAS AAAVRCAAEAAAACHAAC         30 SALES          CHICAGO AAAVRCAAEAAAACHAAD         40 OPERATIONS     BOSTON --//session 3: 2021/02/07 17:07:21.308298655 :kslwtectx 354 2021/02/07 17:07:21.314106317 :kslwtbctx 350 2021/02/07 17:07:21.319513842 :kslwtectx 350 2021/02/07 17:07:21.324941069 :kslwtbctx 147 2021/02/07 17:07:21.330333334 :kslwtectx 147 2021/02/07 17:07:21.335758381 :kslwtbctx 148 2021/02/07 17:07:21.341103117 :kslwtectx 148 2021/02/07 17:07:21.346587995 :kslwtbctx 354 2021/02/07 17:07:21.352430245 :kslwtectx 354 2021/02/07 17:07:21.357701504 :kslwtbctx 350 2021/02/07 17:07:21.363057556 :kslwtectx 350 2021/02/07 17:07:21.368542079 :kslwtbctx 354 --//session 2: SYS@book> select * from v$event_name where event# in (354,350,147,88,148);     EVENT#   EVENT_ID NAME                                     PARAMETER1           PARAMETER2           PARAMETER3           WAIT_CLASS_ID WAIT_CLASS# WAIT_CLASS ---------- ---------- ---------------------------------------- -------------------- -------------------- -------------------- ------------- ----------- --------------------         88 2779959231 latch: cache buffers chains              address              number               tries                   3875070507           4 Concurrency        147 2652584166 db file sequential read                  file#                block#               blocks                  1740759767           8 User I/O        148  506183215 db file scattered read                   file#                block#               blocks                  1740759767           8 User I/O        350 2067390145 SQL*Net message to client                driver id            #bytes                                       2000153315           7 Network        354 1421975091 SQL*Net message from client              driver id            #bytes                                       2723168908           6 Idle 总结: --//如何获得时间戳或者差值,那位知道.找到一个链接https://unix.stackexchange.com/questions/312086/elapsed-time-in-gdb,感觉也不是很好. --//gdb脚本编写也不是自己的特长,放弃!!

相关推荐