[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脚本编写也不是自己的特长,放弃!!
[20210207]使用gdb查看等待事件11g.txt
来源:这里教程网
时间:2026-03-03 16:26:51
作者:
编辑推荐:
下一篇:
相关推荐
-
雷神推出 MIX PRO II 迷你主机:基于 Ultra 200H,玻璃上盖 + ARGB 灯效
2 月 9 日消息,雷神 (THUNDEROBOT) 现已宣布推出基于英
-
制造商 Musnap 推出彩色墨水屏电纸书 Ocean C:支持手写笔、第三方安卓应用
2 月 10 日消息,制造商 Musnap 现已在海外推出一款 Oce
热文推荐
- Oracle 账号 EXPIRED(GRACE) 意义-拾亿
Oracle 账号 EXPIRED(GRACE) 意义-拾亿
26-03-03 - 主备数据库状态手工比对(一)
主备数据库状态手工比对(一)
26-03-03 - 多表连接的三种方式详解 hash join、merge join、 nested loop
- Oracle 12c SCN推进方法汇总(四)之修改控制文件
Oracle 12c SCN推进方法汇总(四)之修改控制文件
26-03-03 - 从Oracle数据库故障到AIX内存管理
从Oracle数据库故障到AIX内存管理
26-03-03 - 苏宁有货:为“轻创业”而来
苏宁有货:为“轻创业”而来
26-03-03 - Oracle 10g 增删节点
Oracle 10g 增删节点
26-03-03 - 【BUILD_ORACLE】Oracle 19c RAC搭建(六)创建RAC数据库
- 【BUILD_ORACLE】Oracle 19c RAC搭建(五)DB软件安装
- update误操作后 通过undo记录的scn找回原纪录
update误操作后 通过undo记录的scn找回原纪录
26-03-03
