[20210220]gdb跟踪逻辑读2.txt
--//有了昨天的测试,链接如下:
--//http://blog.itpub.net/267265/viewspace-2757857/ =>[20210219]全表扫描逻辑读问题.txt
--//http://blog.itpub.net/267265/viewspace-2757859/ => [20210220]全索引扫描快速索引扫描的逻辑读.txt
--//知道这些函数,就可以写出gdb脚本,跟踪那些逻辑读.查看register,以及某些寄存器的地址就可以知道带入的参数,我主要想知道读那
--//些数据块. 过程略.我仅仅贴出gdb脚本,肯定存在许多错误.
1.环境:
SYS@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 gdb/fetch.gdb
break sntpread
set pagination off
commands
silent
set var a=0x0
set var b=0x0
continue
end
break kteinpscan
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kteinpscan 0x%x\n", *($rdi+4)
continue
end
break kdst_fetch if *($rsi+28) != 0
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kdst_fetch 0x%x\n", *($rsi+28)
continue
end
break kteinmap
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kteinmap 0x%x\n", *($rdi+4)
continue
end
#set var a=0x0
break kdifxs if *($rdi+28) != a
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kdifxs 0x%x\n", *($rdi+28)
set var a= *($rdi+28)
continue
end
#set var b=0x0
break kdsgrp if *($rdi+28) != b
set pagination off
commands
silent
shell echo -n $( date +"%Y/%m/%d %T.%N : ")
printf "kdsgrp 0x%x\n", *($rdi+28)
set var b= *($rdi+28)
continue
end
#break kdircys
#set pagination off
# commands
# silent
# shell echo -n $( date +"%Y/%m/%d %T.%N : ")
# printf "kdircys 0x%x\n", *($rdi+4)
# continue
# end
#break qeilbk
#set pagination off
# commands
# silent
# shell echo -n $( date +"%Y/%m/%d %T.%N : ")
# printf "qeilbk 0x%x\n", *($rsi+28)
# continue
# end
--//说明:qeilbk,kdircys函数无法跟踪,我不知道为什么? kdifxs 视乎每取1行调用1次,改写成上面的样子.逻辑读统计肯定有问题的.特
--//别是设置array很小的情况.另外kdsgrp类似,估计临近的块算1个逻辑读.
--//另外我还遇到kdst_fetch *($rsi+28) = 0的情况.我不跟踪这样的情况.
--//我多设置断点break sntpread,主要目的是为了初始话a,b变量值为0,不然下次执行的sql记录的是新的值,这样可能会漏掉一些信息.
3.测试前准备与说明:
--//注意测试前sql语句最好多次避免一些递归,还有一些大表可能采用直接路径读,绕过了oracle的数据缓存,自然看不到.
--//还有唯一索引,索引root节点,分支节点跟踪不到,或者使用的函数我不知道暂时放弃.
--//另外测试没有考虑读undo的情况,先暂时放弃.
--//sesion 1:
SCOTT@book> @ spid
SID SERIAL# PROCESS SERVER SPID PID P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
295 5 46722 DEDICATED 46723 21 3 alter system kill session '295,5' immediate;
--//sesion 2:
$ gdb -p 46723 -x ~/gdb/fetch.gdb
...
Breakpoint 1 at 0x994df72
Breakpoint 2 at 0xfcafda
Breakpoint 3 at 0x947da78
Breakpoint 4 at 0xfc97f0
Breakpoint 5 at 0x95ed0ca
Breakpoint 6 at 0x94471a4
(gdb)
4.测试:
--//测试结果以后面的gdb脚本为准.
--//全表扫描:
select * from emp;
--//跟踪文件:
*** 2021-02-20 15:34:21.723
pin ktewh26: kteinpscan dba 0x1000092:4 time 2565022127
pin kdswh11: kdst_fetch dba 0x1000093:1 time 2565028245
pin kdswh11: kdst_fetch dba 0x1000094:1 time 2565033596
pin kdswh11: kdst_fetch dba 0x1000095:1 time 2565038986
pin kdswh11: kdst_fetch dba 0x1000096:1 time 2565044408
pin kdswh11: kdst_fetch dba 0x1000097:1 time 2565049667
pin kdswh11: kdst_fetch dba 0x1000097:1 time 2565070280
--//gdb:
2021/02/20 15:34:57.544337510 :kteinpscan 0x1000092
2021/02/20 15:34:57.549826022 :kteinmap 0x1000092
2021/02/20 15:34:57.555883105 :kdst_fetch 0x1000093
2021/02/20 15:34:57.561262392 :kdst_fetch 0x1000094
2021/02/20 15:34:57.566930570 :kdst_fetch 0x1000095
2021/02/20 15:34:57.572255586 :kdst_fetch 0x1000096
2021/02/20 15:34:57.591945115 :kdst_fetch 0x1000097
2021/02/20 15:34:57.597271327 :kdst_fetch 0x1000097
--//注extent仅仅1个的情况下,"_trace_pin_time"=1跟踪看不到kteinmap,实际逻辑读是7.
--//INDEX FULL SCAN:
select count(*) from emp;
--//跟踪文件:
*** 2021-02-20 15:35:35.428
pin qeilwhrp: qeilbk dba 0x100009b:1 time 2638727352
--//gdb:
2021/02/20 15:36:05.752024571 :kdifxs 0x100009b
--//INDEX FAST FULL SCAN
select /*+ index_ffs(emp) */ count(*) from emp;
--//跟踪文件:
*** 2021-02-20 15:36:45.413
pin ktewh26: kteinpscan dba 0x100009a:4 time 2708712237
pin kdiwh100: kdircys dba 0x100009b:1 time 2708717602
--//gdb显示:
2021/02/20 15:36:45.400717820 :kteinpscan 0x100009a
2021/02/20 15:36:45.406515456 :kteinmap 0x100009a
2021/02/20 15:36:45.411622200 :kteinpscan 0x100009a
2021/02/20 15:36:45.416993772 :kteinmap 0x100009a
--// TABLE ACCESS BY USER ROWID
select * from emp where rowid='AAAVREAAEAAAACXAAA';
--//跟踪文件:
*** 2021-02-20 15:38:29.342
pin kdswh05: kdsgrp dba 0x1000097:1 time 2812641841
--//gdb显示:
2021/02/20 15:38:29.334660926 :kdsgrp 0x1000097
--//这个结果使用上面的gdb脚本:
--//INDEX RANGE SCAN
SCOTT@book> select * from emp where empno between 7788 and 7900;
EMPNO ENAME JOB MGR HIREDATE SAL COMM DEPTNO
---------- ---------- --------- ---------- ------------------- ---------- ---------- ----------
7788 SCOTT ANALYST 7566 1987-04-19 00:00:00 3000 20
7839 KING PRESIDENT 1981-11-17 00:00:00 5000 10
7844 TURNER SALESMAN 7698 1981-09-08 00:00:00 1500 0 30
7876 ADAMS CLERK 7788 1987-05-23 00:00:00 1100 20
7900 JAMES CLERK 7698 1981-12-03 00:00:00 950 30
--//跟踪文件:
*** 2021-02-20 15:46:16.744
pin qeilwhrp: qeilbk dba 0x100009b:1 time 3280043412
pin kdswh05: kdsgrp dba 0x1000097:1 time 3280070000
pin kdiwh16: kdifxs dba 0x100009b:1 time 3280096298
pin kdswh05: kdsgrp dba 0x1000097:1 time 3280108554
--//gdb显示:
2021/02/20 15:46:16.749466318 :kdifxs 0x100009b
2021/02/20 15:46:16.762301302 :kdsgrp 0x1000097
2021/02/20 15:46:16.788847316 :kdifxs 0x100009b
2021/02/20 15:46:16.801327592 :kdsgrp 0x1000097
Plan hash value: 169057108
--------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 2 (100)| | 5 |00:00:00.03 | 4 |
| 1 | TABLE ACCESS BY INDEX ROWID| EMP | 1 | 5 | 190 | 2 (0)| 00:00:01 | 5 |00:00:00.03 | 4 |
|* 2 | INDEX RANGE SCAN | PK_EMP | 1 | 5 | | 1 (0)| 00:00:01 | 5 |00:00:00.01 | 2 |
--------------------------------------------------------------------------------------------------------------------------------
--//再找一条sql语句测试看看.
SCOTT@book> select /*+ index(t) */ CREATED from t where owner='SCOTT';
Plan hash value: 3696261165
--------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 2237 (100)| | 22 |00:00:00.20 | 18 |
| 1 | TABLE ACCESS BY INDEX ROWID| T | 1 | 2923 | 40922 | 2237 (0)| 00:00:27 | 22 |00:00:00.20 | 18 |
|* 2 | INDEX RANGE SCAN | I_T_OWNER_OBJ_NAME | 1 | 2923 | | 19 (0)| 00:00:01 | 22 |00:00:00.02 | 4 |
--------------------------------------------------------------------------------------------------------------------------------------------
--//跟踪文件:
*** 2021-02-20 15:51:01.925
pin qeilwhnp: qeilbk dba 0x1000e8f:1 time 3565224759
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565254780
pin kdiwh16: kdifxs dba 0x1000e8f:1 time 3565290060
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565302136
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565314752
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565327400
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565340047
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565354194
pin kdswh05: kdsgrp dba 0x100074d:1 time 3565367977
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565380604
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565394572
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565409295
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565423088
pin kdswh05: kdsgrp dba 0x100074d:1 time 3565436764
pin kdswh05: kdsgrp dba 0x100074c:1 time 3565450436
pin kdswh05: kdsgrp dba 0x1000755:1 time 3565463067
--//gdb显示:
2021/02/20 15:51:26.825408913 :kdifxs 0x1000e8f
2021/02/20 15:51:26.837967584 :kdsgrp 0x100074c
2021/02/20 15:51:26.864101083 :kdifxs 0x1000e8f
2021/02/20 15:51:26.876209013 :kdsgrp 0x1000755
2021/02/20 15:51:26.888767163 :kdsgrp 0x100074c
2021/02/20 15:51:26.901400712 :kdsgrp 0x1000755
2021/02/20 15:51:26.913979815 :kdsgrp 0x100074c
2021/02/20 15:51:26.928021294 :kdsgrp 0x1000755
2021/02/20 15:51:26.941792597 :kdsgrp 0x100074d
2021/02/20 15:51:26.954469410 :kdsgrp 0x1000755
2021/02/20 15:51:26.968166227 :kdsgrp 0x100074c
2021/02/20 15:51:26.982954562 :kdsgrp 0x1000755
2021/02/20 15:51:26.996717134 :kdsgrp 0x100074c
2021/02/20 15:51:27.015716039 :kdsgrp 0x100074d
2021/02/20 15:51:27.029494844 :kdsgrp 0x100074c
2021/02/20 15:51:27.042042161 :kdsgrp 0x1000755
--//这样看到的逻辑读就很接近了.
--//0x1000e8f = set dba 4,3727 = alter system dump datefile 4 block 3727 = 16780943
SYS@book> @ which_obj 4 3727
SYS@book> @ prxx
==============================
OWNER : SCOTT
SEGMENT_NAME : I_T_OWNER_OBJ_NAME
PARTITION_NAME :
SEGMENT_TYPE : INDEX
TABLESPACE_NAME : USERS
EXTENT_ID : 17
FILE_ID : 4
BLOCK_ID : 3712
BYTES : 1048576
BLOCKS : 128
RELATIVE_FNO : 4
PL/SQL procedure successfully completed.
总结:
--//纯粹无聊,自己也不熟悉gdb,不要在生产系统做这样的测试与操作!!
--//写这么长,主要记录自己学习和分析的过程,实际上的测试过程远比上面写的要曲折复杂的多,经过多次反复.
来自 “ ITPUB博客 ” ，链接：https://blog.itpub.net/267265/viewspace-2757990/ ，如需转载，请注明出处，否则将追究法律责任。
最新文章
- [20261008]验证Shared Memory Segments key以及Semaphore Arrays Key(11g).txt
- [20261008]gdb引入结构体是否可行.txt
- [20261008]bpftrace定义结构体例子.txt
- [20261007]关于oracle sskgph2函数.txt
- [20261007]oracle Semaphore Arrays Key值的冲突.txt
- [20261004]oracle sskgph2函数等价c以及python脚本.txt
- [20261004]bpftrace查看oracle函数调用堆栈问题.txt
- [20261002]验证sskgphpjw函数参与运算的字符串是否存在规律.txt
- [20261002]oracle Semaphore Arrays Key值的计算2.txt
- [20261001]oracle Semaphore Arrays Key值的计算.txt
